KB Article #177667

automotiveServer process does not start after server (not application) restart

Problem

Customer restarted the server (HP), not WebEDI 3.6.1 application, because is was running slow.

After server restart, when trying to start WebEDI ajas, the 'automotiveServer' process was not running, therefore the application was down:

webedi36@blablabla:~/WebEDI_Portal/spool/runtime> ajas status
0 -- Application status

Java Application Server

DBIPool: used:133 current-poolsize:152

Installed applications:
adminApp (running)
automotiveServer
certificatemanager (running)
DBServer (running)
desktop (running)
httpserver (running)
jcontrollerAjasApp
MDBApplication (running)
passportadapter
RCBApplication
ResourceManager (running)
sentinelrouter
slaveApplication (running)


LOGS FROM WEAS Stack trace:

INFO 2016-01-19 10:26:52,411 Server [main] - ***************************************************
INFO 2016-01-19 10:26:52,411 Server [main] - * AJAS Startup Environment:
INFO 2016-01-19 10:26:52,411 Server [main] - *
INFO 2016-01-19 10:26:52,411 Server [main] - * Java Runtime : Java(TM) SE Runtime Environment
INFO 2016-01-19 10:26:52,411 Server [main] - * Java Version : 16.0-b13
INFO 2016-01-19 10:26:52,411 Server [main] - * Java Vendor : Sun Microsystems Inc.
INFO 2016-01-19 10:26:52,412 Server [main] - * Java Boot Lib: /home/webedi36/Java/linux-x86/jre6_64/lib/amd64
INFO 2016-01-19 10:26:52,412 Server [main] - * OS : Linux
INFO 2016-01-19 10:26:52,412 Server [main] - * ACTISEDI : /home/webedi36/WebEDI_Portal/
INFO 2016-01-19 10:26:52,412 Server [main] - * J2EE : false
INFO 2016-01-19 10:26:52,412 Server [main] - * User name : webedi36
INFO 2016-01-19 10:26:52,412 Server [main] - * file.encoding: ISO8859-1
INFO 2016-01-19 10:26:52,412 Server [main] - ***************************************************
INFO 2016-01-19 10:26:52,576 MLog [main] - MLog clients using log4j logging.
INFO 2016-01-19 10:26:52,623 C3P0Registry [main] - Initializing c3p0-0.9.1.2 [built 21-May-2007 15:04:56; debug? true; trace: 10]
INFO 2016-01-19 10:26:52,730 AbstractPoolBackedDataSource [main] - Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [ acquireIncrement -> 3, acquireRetryAttempts -> 30, a
cquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 120000, connectionCustomizerClassName -> de.axway.lib.
db.DataSourceConnectionCustomizer, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName -> 2w84r89eor2rb11veyi9h|7971f189, debugUnreturnedConnectionS
tackTraces -> false, description -> null, driverClass -> oracle.jdbc.driver.OracleDriver, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 2w84r89eo
r2rb11veyi9h|7971f189, idleConnectionTestPeriod -> 0, initialPoolSize -> 20, jdbcUrl -> jdbc:oracle:thin:@10.111.50.31:1522:VWSU, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxId
leTime -> 600, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 900, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 3, numHelperThreads -> 10, numThreadsAwaitingCheckou
tDefaultUser -> 0, preferredTestQuery -> null, properties -> {user=******, password=******}, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturn
edConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false ]
INFO 2016-01-19 10:26:53,594 Server [main] - Cannot inject optional datasource: 'dataSource1' Can't find resource for bundle java.util.PropertyResourceBundle, key dataSource1.jdbc_driver
INFO 2016-01-19 10:26:53,594 Server [main] - Cannot inject optional datasource: 'dataSource2' Can't find resource for bundle java.util.PropertyResourceBundle, key dataSource2.jdbc_driver
INFO 2016-01-19 10:26:53,594 Server [main] - Cannot inject optional datasource: 'dataSource3' Can't find resource for bundle java.util.PropertyResourceBundle, key dataSource3.jdbc_driver
INFO 2016-01-19 10:26:53,594 EdiEcServer [main] - ServerSocket started on port 9002
INFO 2016-01-19 10:26:53,671 EdiEcServer [pool-1-thread-1] - Loading application: de.axway.ajas.desktop.application.DesktopApplication
INFO 2016-01-19 10:26:54,224 DesktopApplication [pool-1-thread-1] - No entry in AppConf.properties for serverId = 95
INFO 2016-01-19 10:26:54,278 DesktopApplication [pool-1-thread-1] - desktop (1.33): Copyright (c) 1985-2016 Axway GmbH
ERROR 2016-01-19 10:26:55,288 DBDriver [pool-1-thread-1] - SessionDBDriver error: - javax.naming.NameNotFoundException: java:comp/tsim/IUserService not found
ERROR 2016-01-19 10:26:55,288 Server [pool-1-thread-1] - javax.naming.NameNotFoundException: java:comp/tsim/IUserService not found
ERROR 2016-01-19 10:26:55,289 Server [pool-1-thread-1] - at de.axway.common.jndi.AbstractContext.lookup(AbstractContext.java:66)
ERROR 2016-01-19 10:26:55,289 Server [pool-1-thread-1] - at javax.naming.InitialContext.lookup(Unknown Source)
ERROR 2016-01-19 10:26:55,289 Server [pool-1-thread-1] - at de.axway.lib.jndi.NamingUtils.lookupCL(NamingUtils.java:724)
ERROR 2016-01-19 10:26:55,289 Server [pool-1-thread-1] - at de.axway.lib.jndi.NamingUtils.access$300(NamingUtils.java:246)
ERROR 2016-01-19 10:26:55,289 Server [pool-1-thread-1] - at de.axway.lib.jndi.NamingUtils$4.run(NamingUtils.java:696)
ERROR 2016-01-19 10:26:55,289 Server [pool-1-thread-1] - at de.axway.lib.jndi.NamingUtils.runInClassLoader(NamingUtils.java:1007)
ERROR 2016-01-19 10:26:55,289 Server [pool-1-thread-1] - at de.axway.lib.jndi.NamingUtils.lookup(NamingUtils.java:690)
ERROR 2016-01-19 10:26:55,289 Server [pool-1-thread-1] - at de.axway.lib.jndi.NamingUtils.lookup(NamingUtils.java:668)
ERROR 2016-01-19 10:26:55,289 Server [pool-1-thread-1] - at de.axway.lib.ec.lib.driver.session.SessionDBDriver.getUserService(SessionDBDriver.java:545)
ERROR 2016-01-19 10:26:55,289 Server [pool-1-thread-1] - at de.axway.lib.ec.lib.driver.session.SessionDBDriver.getSession(SessionDBDriver.java:313)
ERROR 2016-01-19 10:26:55,289 Server [pool-1-thread-1] - at de.axway.lib.ec.lib.driver.session.NewSessionDBDriver.getSession(NewSessionDBDriver.java:135)
ERROR 2016-01-19 10:26:55,289 Server [pool-1-thread-1] - at de.axway.lib.ec.lib.driver.session.SessionDBDriver.getSessions(SessionDBDriver.java:227)
ERROR 2016-01-19 10:26:55,290 Server [pool-1-thread-1] - at de.axway.ajas.application.Application.initializeSessionsImpl(Application.java:1246)
ERROR 2016-01-19 10:26:55,290 Server [pool-1-thread-1] - at de.axway.ajas.application.Application.initializeSessions(Application.java:1235)
ERROR 2016-01-19 10:26:55,290 Server [pool-1-thread-1] - at de.axway.ajas.application.Application.<init>(Application.java:1219)
ERROR 2016-01-19 10:26:55,290 Server [pool-1-thread-1] - at de.axway.ajas.dsp.application.Application.<init>(Application.java:30)


Resolution

From the error messages we focus now on Oracle DB log sessions:

sqlplus $ORACLE_CONNECT

SQL> select count (*) from log_sessions;

Noticed there were 34404 active log_sessions.

Deleting them solves the problem.

Ajas started with all services in 20 seconds.