[04-22 21:06:27,587, 172] main - INFO launch.c : Current process id from jvm name = 3896[04-22 21:06:27,587, 172] main - INFO launch.c : Starting server at revision 390809 (RC_4.0.02)[04-22 21:06:27,587, 172] main - INFO launch.c : Starting server of client net version 8455[04-22 21:06:27,587, 172] main - INFO launch.c : Starting server of client-account net version 73[04-22 21:06:27,587, 172] main - INFO launch.c : Starting server of account-frontEnd net version 48[04-22 21:06:27,649, 234] main - INFO launch.c : loading config from ../cfg/shard_local.xml[04-22 21:06:48,826, 21411] main - INFO launch.c : loading from cfg "../cfg/shard_local.xml", server "accountServer", deploy = 127.0.0.1[04-22 21:06:48,826, 21411] main - INFO launch.c : Server type is "accountServer"[04-22 21:06:48,826, 21411] main - INFO launch.c : Server name "test_trunk_shard"[04-22 21:06:48,857, 21442] main - INFO tools.reflection.classLoading.l : Using URLClassLoader classpath[04-22 21:06:48,873, 21458] main - INFO tools.reflection.classLoading.h : Loading classes from [L:\USGala\server_bin\accountServer\cfg\server\bin|[[DEBUG:^(?=.*(vendor)).*$], [WARN:.*]], L:\USGala\server_bin\accountServer\cfg\jars|[[DEBUG:^(?=.*(vendor)).*$], [WARN:.*]], L:\USGala\server_bin\accountServer\cfg\vendor|[[DEBUG:^(?=.*(vendor)).*$], [WARN:.*]], L:\USGala\server_bin\accountServer\cfg\target\test-classes|[[WARN:.*]], L:\USGala\server_bin\accountServer\cfg\target\test|[[WARN:.*]], L:\USGala\server_bin\accountServer\cfg\target\classes|[[WARN:.*]], L:\USGala\server_bin\accountServer\cfg\target\production|[[WARN:.*]], L:\USGala\server_bin\accountServer\cfg\classes\production|[[WARN:.*]], L:\USGala\server_bin\accountServer\cfg\classes\test|[[WARN:.*]], L:\USGala\server_bin\accountServer\cfg\jars_local|[[WARN:.*]], L:\USGala\server_bin\accountServer\cfg\server_bin\jars|[[DEBUG:^(?=.*(vendor)).*$], [WARN:.*]], L:\USGala\server_bin\accountServer\cfg\server_bin\jars_local|[[WARN:.*]]](cp = [L:\USGala\server_bin\jars\accountserver.AccountServerMain.jar])...[04-22 21:06:48,873, 21458] main - INFO tools.reflection.classLoading.h : Current base path: L:\USGala\server_bin\accountServer\cfg[04-22 21:06:49,420, 22005] main - WARN tools.reflection.classLoading.h : Duplicated 19 classes in [L:\USGala\server_bin\jars\vendors\commons-beanutils-1.8.0.jar, L:\USGala\server_bin\jars\vendors\commons-beanutils-bean-collections-1.8.0.jar], for example 'org.apache.commons.beanutils.BeanMap$Entry"[04-22 21:06:49,420, 22005] main - WARN tools.reflection.classLoading.h : Duplicated 108 classes in [L:\USGala\server_bin\jars\vendors\commons-beanutils-1.8.0.jar, L:\USGala\server_bin\jars\vendors\commons-beanutils-core-1.8.0.jar], for example 'org.apache.commons.beanutils.locale.converters.DateLocaleConverter"[04-22 21:06:49,420, 22005] main - WARN tools.reflection.classLoading.h : Duplicated 10 classes in [L:\USGala\server_bin\jars\vendors\commons-beanutils-1.8.0.jar, L:\USGala\server_bin\jars\vendors\commons-beanutils-core-1.8.0.jar, L:\USGala\server_bin\jars\vendors\commons-collections-3.1.jar], for example 'org.apache.commons.collections.FastHashMap$KeySet"[04-22 21:06:49,420, 22005] main - WARN tools.reflection.classLoading.h : Duplicated 21 classes in [L:\USGala\server_bin\jars\vendors\hamcrest-core-1.1.jar, L:\USGala\server_bin\jars\vendors\junit-4.8.2.jar], for example 'org.hamcrest.internal.SelfDescribingValueIterator"[04-22 21:06:49,420, 22005] main - WARN tools.reflection.classLoading.h : Duplicated 256 classes in [L:\USGala\server_bin\jars\vendors\log4j-1.2.14.jar, L:\USGala\server_bin\jars\vendors\log4j-1.2.16.jar], for example 'org.apache.log4j.lf5.viewer.LogBrokerMonitor$LogBrokerMonitorWindowAdaptor"[04-22 21:06:49,420, 22005] main - WARN tools.reflection.classLoading.h : Duplicated 16 classes in [L:\USGala\server_bin\jars\vendors\log4jdbc3-1.2beta2.jar, L:\USGala\server_bin\jars\vendors\log4jdbc4-1.2beta2.jar], for example 'net.sf.log4jdbc.ConnectionSpy"[04-22 21:06:49,420, 22005] main - WARN tools.reflection.classLoading.h : Duplicated 42 classes in [L:\USGala\server_bin\jars\vendors\servlet-api-2.5-20081211.jar, L:\USGala\server_bin\jars\vendors\servlet-api-2.5-6.1.3.jar], for example 'javax.servlet.Filter"[04-22 21:06:49,420, 22005] main - WARN tools.reflection.classLoading.h : Duplicated 29 classes in [L:\USGala\server_bin\jars\vendors\uncommons-math-1.0.2.jar, L:\USGala\server_bin\jars\vendors\uncommons-maths-1.0.2.jar], for example 'org.uncommons.maths.statistics.EmptyDataSetException"[04-22 21:06:49,764, 22349] main - INFO tools.reflection.classLoading.m : Loading 23632 classes...[04-22 21:07:00,876, 33461] Task1 - WARN tools.reflection.classLoading.m : Can not load class codegen.test.SourceCodeStaticTest. class java.lang.NoClassDefFoundError: testsSupport/baseTestsRunners/BaseTester[04-22 21:07:01,392, 33977] Task0 - WARN tools.reflection.classLoading.m : Can not load class linksstorage.tests.LinksStorageTest. class java.lang.NoClassDefFoundError: system/base/tester/SystemTester[04-22 21:07:04,642, 37227] Task1 - WARN tools.reflection.classLoading.m : Can not load class codegen.test.SourceCodeTest. class java.lang.NoClassDefFoundError: testsSupport/baseTestsRunners/BaseTester[04-22 21:07:06,548, 39133] Task1 - WARN tools.reflection.classLoading.m : Can not load class codegen.test.JavaSourceCodeTest. class java.lang.NoClassDefFoundError: testsSupport/baseTestsRunners/BaseTester[04-22 21:07:06,610, 39195] main - INFO tools.reflection.classLoading.m : Finished in 16.831 sec[04-22 21:07:06,610, 39195] main - INFO tools.reflection.classLoading.m : Checking class dependencies[04-22 21:07:06,944, 39529] Task2 - WARN tools.reflection.classLoading.m : Coud not load class class linksstorage.SqlXdbLinksImpl. excluding from loading : dbcommons/exception/DatabaseException[04-22 21:07:07,894, 40479] Task1 - WARN tools.reflection.classLoading.m : Coud not load class class linksstorage.ProjectFilesLinksImpl. excluding from loading : Ltools/containers/hashMaps/MultiHashMap;[04-22 21:07:07,941, 40526] main - INFO tools.reflection.classLoading.m : Finished in 1.331 sec[04-22 21:07:07,941, 40526] main - INFO tools.reflection.classLoading.m : 6 classes loading errors[04-22 21:07:08,175, 40760] main - INFO tools.reflection.classLoading.h : 23655 classes loaded in 19.302 sec[04-22 21:07:09,032, 41617] main - INFO accountserver.bc : starting account server...[04-22 21:07:09,094, 41679] main - INFO accountserver.bc : loading build from builds/standard.xml[04-22 21:07:09,204, 41789] main - INFO accountserver.bc : configuration loaded[04-22 21:07:09,204, 41789] main - INFO logging.init.Logging : About to shutdown channel engines: [][04-22 21:07:09,204, 41789] main - INFO logging.init.Logging : Completed shutdown of channel engines [][04-22 21:07:09,204, 41789] main - WARN verify : Using dummy channel engine. All statistics data will be discarded.[04-22 21:07:09,766, 42351] main - INFO dbcommons.hibernate.r : **** b Database connected. Connection url: jdbc
ostgresql://127.0.0.1/allods_account_rc_4_0_02 username: postgres[04-22 21:07:09,907, 42492] main - WARN org.hibernate.ejb.Ejb3Configuration : hibernate.connection.autocommit = false break the EJB3 specification[04-22 21:07:09,907, 42492] main - WARN org.hibernate.ejb.Ejb3Configuration : hibernate.connection.autocommit = false break the EJB3 specification[04-22 21:07:10,001, 42586] main - INFO com.mchange.v2.log.MLog : MLog clients using log4j logging.[04-22 21:07:10,172, 42757] main - INFO com.mchange.v2.c3p0.C3P0Registry : Initializing c3p0-0.9.2-pre4 [built 16-June-2012 20:16:37 -0400; debug? true; trace: 10][04-22 21:07:10,268, 42853] main - INFO com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource : Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@f436906e [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@c85d7634 [ acquireIncrement -> 3, acquireRetryAttempts -> 1, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 1hge143981qfpiovz3bqwi|7b0f04f, idleConnectionTestPeriod -> 60, initialPoolSize -> 3, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 600, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 15, maxStatements -> 50, maxStatementsPerConnection -> 0, minPoolSize -> 3, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@fd57edd1 [ description -> null, driverClass -> null, factoryClassLocation -> null, identityToken -> 1hge143981qfpiovz3bqwi|106dc141, jdbcUrl -> jdbc
ostgresql://127.0.0.1/allods_account_rc_4_0_02, properties -> {user=******, password=******, autocommit=false, release_mode=after_statement} ], preferredTestQuery -> SELECT 1, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, factoryClassLocation -> null, identityToken -> 1hge143981qfpiovz3bqwi|607f2c34, numHelperThreads -> 3 ][04-22 21:07:10,550, 43135] main - WARN org.hibernate.cfg.SettingsFactory : Overriding release mode as connection provider does not support 'after_statement'[04-22 21:07:10,550, 43135] main - WARN org.hibernate.cfg.SettingsFactory : Overriding release mode as connection provider does not support 'after_statement'[04-22 21:07:10,784, 43369] main - WARN org.hibernate.impl.SessionFactoryImpl : JTASessionContext being used with JDBCTransactionFactory; auto-flush will not operate correctly with getCurrentSession()[04-22 21:07:10,784, 43369] main - WARN org.hibernate.impl.SessionFactoryImpl : JTASessionContext being used with JDBCTransactionFactory; auto-flush will not operate correctly with getCurrentSession()[04-22 21:07:10,831, 43416] main - INFO TextLogger : Create logger `QueryStatitstics`, file `../statistics/System/Performance/Database/QueryStatitstics.txt`, without rolling[04-22 21:07:11,518, 44103] main - INFO databaseServer : Database structure checked[04-22 21:07:11,534, 44119] main - INFO databaseServer : Database time: 2015.04.22 21.07.10.925 +0900, local server time: 2015.04.22 21.07.11.534 +0900, delta: 0 sec.[04-22 21:07:11,581, 44166] main - INFO dbcommons.hibernate.r : Scheme baker dbcommons.jdbc.schemebaker.e is created for accountserver.accountdb.jdbcimpl.b[04-22 21:07:11,659, 44244] main - INFO dbcommons.hibernate.r : **** b Database connected. Connection url: jdbc
ostgresql://127.0.0.1/allods_account_rc_4_0_02 username: postgres[04-22 21:07:11,675, 44260] main - WARN org.hibernate.ejb.Ejb3Configuration : hibernate.connection.autocommit = false break the EJB3 specification[04-22 21:07:11,675, 44260] main - WARN org.hibernate.ejb.Ejb3Configuration : hibernate.connection.autocommit = false break the EJB3 specification[04-22 21:07:11,753, 44338] main - INFO com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource : Initializing c3p0 pool... com.mchange.v2.c3p0.PoolBackedDataSource@727d99d1 [ connectionPoolDataSource -> com.mchange.v2.c3p0.WrapperConnectionPoolDataSource@7d543a89 [ acquireIncrement -> 3, acquireRetryAttempts -> 1, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, debugUnreturnedConnectionStackTraces -> false, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 1hge143981qfpiovz3bqwi|5606c3c, idleConnectionTestPeriod -> 60, initialPoolSize -> 3, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 600, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 15, maxStatements -> 50, maxStatementsPerConnection -> 0, minPoolSize -> 3, nestedDataSource -> com.mchange.v2.c3p0.DriverManagerDataSource@d806ea27 [ description -> null, driverClass -> null, factoryClassLocation -> null, identityToken -> 1hge143981qfpiovz3bqwi|14fb67df, jdbcUrl -> jdbc
ostgresql://127.0.0.1/allods_account_rc_4_0_02, properties -> {user=******, password=******, autocommit=false, release_mode=after_statement} ], preferredTestQuery -> SELECT 1, propertyCycle -> 0, statementCacheNumDeferredCloseThreads -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false; userOverrides: {} ], dataSourceName -> null, factoryClassLocation -> null, identityToken -> 1hge143981qfpiovz3bqwi|29a87aa1, numHelperThreads -> 3 ][04-22 21:07:11,831, 44416] main - WARN org.hibernate.cfg.SettingsFactory : Overriding release mode as connection provider does not support 'after_statement'[04-22 21:07:11,831, 44416] main - WARN org.hibernate.cfg.SettingsFactory : Overriding release mode as connection provider does not support 'after_statement'[04-22 21:07:11,847, 44432] main - WARN org.hibernate.impl.SessionFactoryImpl : JTASessionContext being used with JDBCTransactionFactory; auto-flush will not operate correctly with getCurrentSession()[04-22 21:07:11,847, 44432] main - WARN org.hibernate.impl.SessionFactoryImpl : JTASessionContext being used with JDBCTransactionFactory; auto-flush will not operate correctly with getCurrentSession()[04-22 21:07:12,236, 44821] main - INFO databaseServer : Database structure checked[04-22 21:07:12,236, 44821] main - INFO databaseServer : Database time: 2015.04.22 21.07.11.847 +0900, local server time: 2015.04.22 21.07.12.236 +0900, delta: 0 sec.[04-22 21:07:12,268, 44853] main - INFO dbcommons.hibernate.r : Scheme baker dbcommons.jdbc.schemebaker.e is created for accountserver.accountdb.jdbcimpl.b[04-22 21:07:12,283, 44868] main - INFO accountserver.authenticator.Authenticator : Using "accountserver.authenticator.nivalimpl.AuthenticatorNivalImpl" authenticator.[04-22 21:07:12,315, 44900] main - INFO accountserver.authenticator.api.AuthenticatorService : AuthenticatorService started at 127.0.0.1:9398[04-22 21:07:12,315, 44900] main - INFO accountserver.context.LoginPlugin : Using "accountserver.plugins.login.nivalimpl.NivalLoginPlugin" login plugin.[04-22 21:07:12,330, 44915] main - INFO accountserver.c : Starting account api at 127.0.0.1:9356[04-22 21:07:12,330, 44915] main - INFO tools.commons.logs.LogToLog4jHandler : Redirecting java.util.logging to Log4J...[04-22 21:07:12,361, 44946] main - INFO tools.commons.logs.LogToLog4jHandler : Redirection of java.util.logging to Log4J started[04-22 21:07:12,393, 44978] main - INFO org.mortbay.log : Logging to org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog[04-22 21:07:12,565, 45150] main - INFO org.mortbay.log : jetty-6.1.26[04-22 21:07:12,611, 45196] main - INFO org.mortbay.log : Started SelectChannelConnector@127.0.0.1:9356[04-22 21:07:12,611, 45196] main - INFO accountserver.c : Account api started[04-22 21:07:12,611, 45196] main - INFO accountserver.c : initializing RSA keys...[04-22 21:07:12,846, 45431] main - INFO accountserver.c : rsa keys initialized[04-22 21:07:12,877, 45462] main - INFO accountserver.c : creating server for client authentification 127.0.0.1:9339[04-22 21:07:12,893, 45478] main - INFO accountserver.c : client authentification server created[04-22 21:07:12,893, 45478] main - INFO accountserver.c : creating server for session approvement 127.0.0.1:9346[04-22 21:07:12,908, 45493] main - INFO accountserver.c : session approvement server created[04-22 21:07:12,908, 45493] main - INFO accountserver.c : account server started, client <-> account server version = 73, shard <-> account server version = 48[04-22 21:07:12,908, 45493] main - INFO accountserver.context.e : Using NONE statistics exporter.