With some modifications to the code:
package org.apache.roller.weblogger.business.startup;
import ...;
public final class WebloggerStartup {
// ...
public static void prepare() throws StartupException {
// setup database provider
try {
dbProvider = new DatabaseProvider();
LOG.info(">>> setup database provider");
} catch(StartupException ex) {
dbProviderException = ex;
throw ex;
}
// setup mail provider, if configured
try {
mailProvider = new MailProvider();
LOG.info(">>> setup mail provider");
} catch(StartupException ex) {
LOG.warn("Failed to setup mail provider, continuing anyways.\n"
+ "Reason: " + ex.getMessage());
LOG.info("The cause of setting up mail provider error was: ",
ex);
}
LOG.info(">>> installation.type: " +
WebloggerConfig.getProperty("installation.type"));
// now we need to deal with database install/upgrade logic
if("manual".equals(WebloggerConfig.getProperty("installation.type"))) {
LOG.info(">>> manual install mode");
// if we are doing manual install then all that is needed is the
// app handled database upgrade work, not the db scripts
DatabaseInstaller dbInstaller = getDatabaseInstaller();
if (dbInstaller.isUpgradeRequired()) {
dbInstaller.upgradeDatabase(false);
}
prepared = true;
} else {
LOG.info(">>> auto install mode");
// we are in auto install mode, so see if there is any work to
do
DatabaseInstaller dbInstaller = getDatabaseInstaller();
if (!dbInstaller.isCreationRequired() &&
!dbInstaller.isUpgradeRequired()) {
prepared = true;
}
}
}
}
I think I've found the root cause. It appears to failed silently while
setting up the mail provider as seen in the logs::
INFO 2020-02-09 15:33:42,464 DatabaseProvider:successMessage - SUCCESS:
loaded JDBC driver class [org.mariadb.jdbc.Driver]
INFO 2020-02-09 15:33:42,826 DatabaseProvider:<init> - >>> testcon
succeeded.
INFO 2020-02-09 15:33:42,826 WebloggerStartup:prepare - >>> setup database
provider
DEBUG 2020-02-09 15:33:42,831 WebloggerConfig:getProperty - Fetching
property [mail.configurationType=properties]
DEBUG 2020-02-09 15:33:42,832 WebloggerConfig:getProperty - Fetching
property [mail.jndi.name=mail/Session]
DEBUG 2020-02-09 15:33:42,833 WebloggerConfig:getProperty - Fetching
property [mail.hostname=x.x.x]
DEBUG 2020-02-09 15:33:42,833 WebloggerConfig:getProperty - Fetching
property [mail.username=null]
DEBUG 2020-02-09 15:33:42,833 WebloggerConfig:getProperty - Fetching
property [mail.password=null]
DEBUG 2020-02-09 15:33:42,834 WebloggerConfig:getProperty - Fetching
property [mail.port=null]
DEBUG 2020-02-09 15:33:43,007 Digester:register - register('-//Apache
Software Foundation//DTD Tiles Configuration 3.0//EN',
'jar:file:/usr/local/www/apache-tomcat/webapps/blog/WEB-INF/lib/tiles-core-3.0.8.jar!/org/apache/tiles/resources/tiles-config_3_0.dtd'
INFO 2020-02-09 15:33:43,446 TilesAccess:setContainer - Publishing
TilesContext for context:
org.apache.struts2.tiles.StrutsWildcardServletApplicationContext
INFO 2020-02-09 15:33:43,458 TilesAccess:setContainer - Removing
TilesContext for context:
org.apache.struts2.tiles.StrutsWildcardServletApplicationContext
To be more precise with more code modification:
package org.apache.roller.weblogger.business;
import ...;
public class MailProvider {
public MailProvider() throws StartupException {
String connectionTypeString =
WebloggerConfig.getProperty("mail.configurationType");
if ("properties".equals(connectionTypeString)) {
type = ConfigurationType.MAIL_PROPERTIES;
}
String jndiName = WebloggerConfig.getProperty("mail.jndi.name");
mailHostname = WebloggerConfig.getProperty("mail.hostname");
mailUsername = WebloggerConfig.getProperty("mail.username");
mailPassword = WebloggerConfig.getProperty("mail.password");
try {
String portString = WebloggerConfig.getProperty("mail.port");
if (portString != null) {
mailPort = Integer.parseInt(portString);
}
} catch (Exception e) {
LOG.warn("mail server port not a valid integer, ignoring");
}
// init and connect now so we fail early
if (type == ConfigurationType.JNDI_NAME) {
LOG.info(">>> ConfigurationType.JNDI_NAME");
if (jndiName != null && !jndiName.startsWith("java:")) {
jndiName = "java:comp/env/" + jndiName;
}
try {
Context ctx = new InitialContext();
session = (Session) ctx.lookup(jndiName);
LOG.info(">>> ConfigurationType.JNDI_NAME session created");
} catch (NamingException ex) {
throw new StartupException("ERROR looking up mail-session
with JNDI name: " + jndiName);
}
} else {
LOG.info(">>> ConfigurationType.MAIL_PROPERTIES");
Properties props = new Properties();
props.put("mail.smtp.host", mailHostname);
if (mailUsername != null && mailPassword != null) {
props.put("mail.smtp.auth", "true");
}
if (mailPort != -1) {
props.put("mail.smtp.port", ""+mailPort);
}
session = Session.getDefaultInstance(props, null);
LOG.info(">>> ConfigurationType.MAIL_PROPERTIES session
created");
}
try {
Transport transport = getTransport();
transport.close();
LOG.info(">>> test transport succeeded.");
} catch (Exception e) {
throw new StartupException("ERROR connecting to mail server",
e);
}
}
}
and the resulting logs:
INFO 2020-02-09 15:49:35,586 DatabaseProvider:successMessage - SUCCESS:
loaded JDBC driver class [org.mariadb.jdbc.Driver]
INFO 2020-02-09 15:49:35,900 DatabaseProvider:<init> - >>> testcon
succeeded.
INFO 2020-02-09 15:49:35,900 WebloggerStartup:prepare - >>> setup database
provider
DEBUG 2020-02-09 15:49:35,904 WebloggerConfig:getProperty - Fetching
property [mail.configurationType=properties]
DEBUG 2020-02-09 15:49:35,905 WebloggerConfig:getProperty - Fetching
property [mail.jndi.name=mail/Session]
DEBUG 2020-02-09 15:49:35,905 WebloggerConfig:getProperty - Fetching
property [mail.hostname=x.x.x]
DEBUG 2020-02-09 15:49:35,906 WebloggerConfig:getProperty - Fetching
property [mail.username=null]
DEBUG 2020-02-09 15:49:35,906 WebloggerConfig:getProperty - Fetching
property [mail.password=null]
DEBUG 2020-02-09 15:49:35,907 WebloggerConfig:getProperty - Fetching
property [mail.port=null]
INFO 2020-02-09 15:49:35,907 MailProvider:<init> - >>>
ConfigurationType.MAIL_PROPERTIES
DEBUG 2020-02-09 15:49:36,063 Digester:register - register('-//Apache
Software Foundation//DTD Tiles Configuration 3.0//EN',
'jar:file:/usr/local/www/apache-tomcat/webapps/blog/WEB-INF/lib/tiles-core-3.0.8.jar!/org/apache/tiles/resources/tiles-config_3_0.dtd'
INFO 2020-02-09 15:49:36,485 TilesAccess:setContainer - Publishing
TilesContext for context:
org.apache.struts2.tiles.StrutsWildcardServletApplicationContext
INFO 2020-02-09 15:49:36,503 TilesAccess:setContainer - Removing
TilesContext for context:
org.apache.struts2.tiles.StrutsWildcardServletApplicationContext
It seems to fail silently during getting a Session of the MailProvider
creation. The mail server FQDN is resolvable to IP in the same private
subnet and is also configured, without authentication required, to allow
any connection on the same subnet to send e-mail.
Thanks,
Tommy
On Sun, Feb 9, 2020 at 1:48 PM Tommy Pham <[email protected]> wrote:
> Hi Dave,
>
> Thanks for the clarification regarding the "make this work" and trying to
> duplicate the issue.
>
> Hi Anil,
>
> The Tomcat log was from catalina.out. I'll try to increase the log level
> for Tomcat as you suggested to see if it would provide some insight.
>
> @All,
>
> I've just tried a new install of the older version 5.2.4 and the context
> was able to startup. I was able to access the initial startup page for the
> New User Registration and etc.. even though there are a lot of
> IllegalArgumentException (null) for "unable to read class ..." in Tomcat:
>
> https://pastebin.com/n6wyutPk
>
> I've double check for file system permissions. All files are either 640
> or 644 and the directories are 755. Both files and directories are owned
> by the www:www (user:group) recursively which was used to start the
> Tomcat service. The roller log is clean with more verbose information:
>
> INFO 2020-02-09 12:59:54,363 ContinuousWorkerThread:run -
> HitCountQueueProcessor Started.
> INFO 2020-02-09 12:59:54,364 ContinuousWorkerThread:run -
> HitCountQueueProcessor Done.
> INFO 2020-02-09 13:00:33,796 DatabaseProvider:successMessage - SUCCESS:
> Got parameters. Using configuration type JDBC_PROPERTIES
> INFO 2020-02-09 13:00:33,802 DatabaseProvider:successMessage - -- Using
> JDBC driver class: org.mariadb.jdbc.Driver
> INFO 2020-02-09 13:00:33,803 DatabaseProvider:successMessage - -- Using
> JDBC connection URL:
> jdbc:mysql://x.x.x.x:3306/roller?autoReconnect=true&useUnicode=true&characterEncoding=utf-8&mysqlEncoding=utf8
> INFO 2020-02-09 13:00:33,804 DatabaseProvider:successMessage - -- Using
> JDBC username: roller
> INFO 2020-02-09 13:00:33,804 DatabaseProvider:successMessage - -- Using
> JDBC password: [hidden]
> INFO 2020-02-09 13:00:33,811 DatabaseProvider:successMessage - SUCCESS:
> loaded JDBC driver class [org.mariadb.jdbc.Driver]
> INFO 2020-02-09 13:00:35,911 WebloggerFactory:bootstrap - Bootstrapping
> Roller Weblogger business tier
> INFO 2020-02-09 13:00:35,912 WebloggerFactory:bootstrap - Weblogger
> Provider = org.apache.roller.weblogger.business.GuiceWebloggerProvider
> INFO 2020-02-09 13:00:35,944 DatabaseProvider:successMessage - SUCCESS:
> Got parameters. Using configuration type JDBC_PROPERTIES
> INFO 2020-02-09 13:00:35,945 DatabaseProvider:successMessage - -- Using
> JDBC driver class: org.mariadb.jdbc.Driver
> INFO 2020-02-09 13:00:35,948 DatabaseProvider:successMessage - -- Using
> JDBC connection URL:
> jdbc:mysql://x.x.x.x:3306/roller?autoReconnect=true&useUnicode=true&characterEncoding=utf-8&mysqlEncoding=utf8
> INFO 2020-02-09 13:00:35,948 DatabaseProvider:successMessage - -- Using
> JDBC username: roller
> INFO 2020-02-09 13:00:35,951 DatabaseProvider:successMessage - -- Using
> JDBC password: [hidden]
> INFO 2020-02-09 13:00:35,966 DatabaseProvider:successMessage - SUCCESS:
> loaded JDBC driver class [org.mariadb.jdbc.Driver]
> INFO 2020-02-09 13:00:36,088 JPAPersistenceStrategy:<init> -
> hibernate.transaction.factory_class:
> org.hibernate.transaction.JTATransactionFactory
> INFO 2020-02-09 13:00:36,089 JPAPersistenceStrategy:<init> -
> eclipselink.persistence-context.flush-mode: auto
> INFO 2020-02-09 13:00:36,093 JPAPersistenceStrategy:<init> -
> hibernate.transaction.manager_lookup_class:
> org.hibernate.transaction.JBossTransactionManagerLookup
> INFO 2020-02-09 13:00:40,137 IndexManagerImpl:<init> - search enabled:
> true
> INFO 2020-02-09 13:00:40,142 IndexManagerImpl:<init> - index dir:
> /usr/local/www/_apps_/java/roller5_data/search-index
> INFO 2020-02-09 13:00:40,201 ThreadManagerImpl:<init> - Instantiating
> Thread Manager
> INFO 2020-02-09 13:00:40,212 WebloggerFactory:bootstrap - Roller
> Weblogger business tier successfully bootstrapped
> INFO 2020-02-09 13:00:40,213 WebloggerFactory:bootstrap - Version:
> 5.2.4
> INFO 2020-02-09 13:00:40,213 WebloggerFactory:bootstrap - Revision:
> r8de816ea5bb8a2391855ec95192781669008927d
> INFO 2020-02-09 13:00:40,214 WebloggerImpl:initialize - Initializing
> Roller Weblogger business tier
> INFO 2020-02-09 13:00:41,565 ThemeManagerImpl:loadAllThemesFromDisk -
> Loading themes from /usr/local/www/apache-tomcat/webapps/blog5/themes...
> INFO 2020-02-09 13:00:41,606 ThemeManagerImpl:loadAllThemesFromDisk -
> Loaded theme 'basic'
> INFO 2020-02-09 13:00:41,651 ThemeManagerImpl:loadAllThemesFromDisk -
> Loaded theme 'basicmobile'
> INFO 2020-02-09 13:00:41,681 ThemeManagerImpl:loadAllThemesFromDisk -
> Loaded theme 'gaurav'
> INFO 2020-02-09 13:00:41,697 ThemeManagerImpl:loadAllThemesFromDisk -
> Loaded theme 'fauxcoly'
> INFO 2020-02-09 13:00:41,716 ThemeManagerImpl:loadAllThemesFromDisk -
> Loaded theme 'frontpage'
> INFO 2020-02-09 13:00:41,717 ThemeManagerImpl:initialize - Successfully
> loaded 5 themes from disk.
> ...
>
> I think I'll modify the code cloned from github to see if I can narrow
> down the point of failure.
>
> Thank you,
> Tommy
>
>
>
> On Sun, Feb 9, 2020 at 8:00 AM Anil Gangolli <[email protected]> wrote:
>
>>
>> Tommy,
>>
>> Some suggestions that might help:
>> * If you have a catalina.out file, check it.
>> * You might need to adjust the Catalina log level. Catalina is the
>> "container" mentioned in the SEVERE listener startup error message.
>> This tip is old, but I think the config is the same in Tomcat 9:
>>
>> https://stackoverflow.com/questions/36617732/how-to-check-container-log-of-tomcat
>>
>>
>> --a.
>>
>> On 2/8/20 1:57 PM, Dave wrote:
>> > Hi Tommy,
>> >
>> > I tried to reproduce this problem by using the same Tomcat, MariaDB
>> server
>> > and client versions as you are using and could not. I used the
>> > installation.type=auto and database.configurationType=jdbc and started
>> with
>> > a fresh (empty) database.
>> >
>> > OS: MacOS 10.15.3
>> > JDK: java version "11" 2018-09-25
>> > Web Container: Tomcat 9.0.30
>> > DB: MariaDB 10.4.12
>> > JDBC client: MariaDB Java client 2.5.4
>> >
>> > I guess there could be some problem that only occurs on OpenJDK but not
>> on
>> > Oracle JDK? But then again, I run my Roller site on Kubernetes using
>> Docker
>> > image created from tomcat:9.0.20-jre11-slim, which is OpenJDK.
>> >
>> > What's really odd is that you are getting no exceptions. Are there any
>> > exceptions in any of the other log files under tomcat/logs?
>> >
>> > Are you able to login to the MariaDB database using the mysql client
>> from
>> > the host that is running Tomcat?
>> >
>> > Dave
>> >
>> >
>> >
>> >
>> > On Fri, Feb 7, 2020 at 6:36 PM Dave <[email protected]> wrote:
>> >
>> >> That "make this work" comment is about the @AllowedMethods annotation.
>> >> Because the annotation did not work (at that time), we had to use
>> >> struts.xml to specify allowed methods. The comment does not mean the
>> class
>> >> does not work :-)
>> >>
>> >> The installation process should be working unless there is a new bug,
>> or
>> >> there is some issue with MariaDB vs MySQL. Let's get to the bottom of
>> this.
>> >> I will give MariaDB a try over the weekend.
>> >>
>> >> Thanks,
>> >> Dave
>> >>
>> >>
>> >> On Fri, Feb 7, 2020 at 6:07 PM Tommy Pham <[email protected]> wrote:
>> >>
>> >>> After some review of the source code, I'm unable to locate where or
>> the
>> >>> conditions which would instantiate:
>> >>>
>> >>> org.apache.roller.weblogger.ui.struts2.core.Install
>> >>>
>> >>> Would you or someone else please confirm? Also, looking that the
>> source
>> >>> code for that same class:
>> >>>
>> >>> /**
>> >>> * Walk user through install process.
>> >>> */
>> >>> // TODO: make this work
>> >>> @AllowedMethods({"execute","create","upgrade","bootstrap"})
>> >>> public class Install extends UIAction {
>> >>>
>> >>> Am I correct to assume that the installation process isn't quite
>> complete?
>> >>>
>> >>> Thank you,
>> >>> Tommy
>> >>>
>> >>>
>> >>> On Fri, Feb 7, 2020 at 2:12 PM Tommy Pham <[email protected]> wrote:
>> >>>
>> >>>> Hi Dave,
>> >>>>
>> >>>> After some more thought about the application startup process, I
>> decided
>> >>>> to change the DB password to an invalid one to force an expected
>> error
>> >>>> which it did. I also tried changing the installation type from auto
>> to
>> >>>> manual and use the provided MySQL script in dbscripts to create the
>> >>>> schema. It still failed with the same error in Tomcat and no error
>> >>> within
>> >>>> the roller's log. I suspect that either or both of the:
>> >>>>
>> >>>> org.apache.roller.weblogger.business.startup.WebloggerStartup
>> >>>> org.apache.roller.weblogger.business.startup.DatabaseInstaller
>> >>>>
>> >>>> is/are failing because the schema was not created for auto
>> installation
>> >>>> type or it failed to detect the schema for manual despite the
>> successful
>> >>>> test DB connection within:
>> >>>>
>> >>>> org.apache.roller.weblogger.business.DatabaseProvider
>> >>>>
>> >>>> Thanks,
>> >>>> Tommy
>> >>>>
>> >>>>
>> >>>> On Fri, Feb 7, 2020 at 1:13 PM Tommy Pham <[email protected]>
>> wrote:
>> >>>>
>> >>>>> Hi Dave,
>> >>>>>
>> >>>>> Thanks for the feedback. Here is the log for both Tomcat and
>> Roller:
>> >>>>> https://pastebin.com/PCjF024T
>> >>>>>
>> >>>>> I've just tried a clone from the current github with the same
>> result.
>> >>>>> The only thing I could think of is roller failing silently somewhere
>> >>> but I
>> >>>>> don't know where to start checking.
>> >>>>>
>> >>>>> Thanks,
>> >>>>> Tommy
>> >>>>>
>> >>>>> On Fri, Feb 7, 2020 at 5:03 AM Dave <[email protected]> wrote:
>> >>>>>
>> >>>>>> Hi Tommy,
>> >>>>>>
>> >>>>>> I don't think this mailing list allows attachments. Can you please
>> >>> make
>> >>>>>> your logs available somewhere, like a GitHib gist or a past bin so
>> we
>> >>> can
>> >>>>>> see them. Both the Tomcat and roller.log logs might be useful.
>> >>>>>>
>> >>>>>> Thanks,
>> >>>>>> Dave
>> >>>>>>
>> >>>>>>
>> >>>>>> On Fri, Feb 7, 2020 at 1:52 AM Tommy Pham <[email protected]>
>> wrote:
>> >>>>>>
>> >>>>>>> Hello everyone,
>> >>>>>>>
>> >>>>>>> I'm having problems installing Roller 6 in the new Tomcat
>> >>> environment:
>> >>>>>>> OS: FreeBSD 12.1-RELEASE
>> >>>>>>> JDK: OpenJDK 11.0.6
>> >>>>>>> Web Container: Tomcat 9.0.30
>> >>>>>>> DB: MariaDB 10.4.12
>> >>>>>>> JDBC client: MariaDB Java client 2.5.4
>> >>>>>>>
>> >>>>>>> My roller-custom.properties:
>> >>>>>>>
>> >>>>>>> installation.type=auto
>> >>>>>>> database.configurationType=jdbc
>> >>>>>>> database.jndi.name=jdbc/rollerdb
>> >>>>>>> database.jdbc.driverClass=org.mariadb.jdbc.Driver
>> >>>>>>>
>> >>>>>>>
>> >>>
>> database.jdbc.connectionURL=jdbc:mysql://x.x.x.x:3306/roller?autoReconnect=true&useUnicode=true&characterEncoding=utf-8&mysqlEncoding=utf8
>> >>>>>>> database.jdbc.username=roller
>> >>>>>>> database.jdbc.password=xxx
>> >>>>>>> mail.configurationType=properties
>> >>>>>>> mail.jndi.name=mail/Session
>> >>>>>>> mail.hostname=x.x.x
>> >>>>>>>
>> >>>
>> mediafiles.storage.dir=/usr/local/www/_apps_/java/roller6_data/mediafiles
>> >>> search.index.dir=/usr/local/www/_apps_/java/roller6_data/search-index
>> >>>>>>> log4j.rootLogger=DEBUG, roller
>> >>>>>>> log4j.logger.org.apache.roller=DEBUG
>> >>>>>>> log4j.logger.net.java.roller=DEBUG
>> >>>>>>>
>> >>>>>>> (log4j were added to troubleshoot this which didn't provide any
>> >>>>>> insight).
>> >>>>>>> Attached is the Tomcat + roller logs. Tomcat reports SEVERE error
>> >>>>>> starting
>> >>>>>>> context /blogger and suggested to look inside the container's log.
>> >>>>>>> However, roller's log didn't show any error. I've also check the
>> >>>>>> database
>> >>>>>>> logs for any errors but none found. Does anyone have any
>> >>> suggestions
>> >>>>>> on
>> >>>>>>> where I can look to investigate further?
>> >>>>>>>
>> >>>>>>> TIA,
>> >>>>>>> Tommy
>> >>>>>>>
>>
>>
