SuccessConsole Output

Skipping 475 KB.. Full Log
ange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:143) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:132) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547) [c3p0-0.9.1.jar:0.9.1]
13:56:21.396 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'harvestdefinitions' from version '2' to version '4'.
13:56:21.397 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'harvestdefinitions' to version 3
13:56:21.426 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'harvestdefinitions' to version 4
13:56:21.465 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'jobs' from version '8' to version '10'.
13:56:21.470 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'jobs' to version 9
13:56:21.488 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'jobs' to version 10
13:56:22.116 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'extendedfield' from version '1' to version '2'.
13:56:22.118 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'extendedfield' to version 2
13:56:22.166 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'extendedfieldvalue' from version '1' to version '2'.
13:56:22.196 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'extendedfieldvalue' to version 2
13:56:22.414 [main] WARN  dk.netarkivet.common.utils.DBUtils - As yet unknown tablename 'harvestchannel' in table schemaversions. The table should be automatically created in the database when it is first needed.
13:56:22.415 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'harvestchannel' from version '0' to version '1'.
13:56:22.416 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'harvestchannel' to version 1
13:56:24.207 [main] WARN  dk.netarkivet.harvester.datamodel.DatabaseTestUtils - Expected SQL-exception when shutting down database:
java.sql.SQLNonTransientConnectionException: Database './tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' shutdown.
	at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection40.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver20.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.AutoloadedDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at java.sql.DriverManager.getConnection(DriverManager.java:664) ~[na:1.8.0_11]
	at java.sql.DriverManager.getConnection(DriverManager.java:270) ~[na:1.8.0_11]
	at dk.netarkivet.harvester.datamodel.DatabaseTestUtils.dropDatabase(DatabaseTestUtils.java:178) [harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.harvester.datamodel.DatabaseTestUtils.dropHDDB(DatabaseTestUtils.java:210) [harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.harvester.datamodel.DataModelTestCase.tearDown(DataModelTestCase.java:116) [test-classes/:na]
	at dk.netarkivet.harvester.datamodel.DomainDAOTester.tearDown(DomainDAOTester.java:67) [test-classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_11]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_11]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_11]
	at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0_11]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) [junit-4.11.jar:na]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [junit-4.11.jar:na]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) [junit-4.11.jar:na]
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:33) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:127) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:26) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:160) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138) [junit-4.11.jar:na]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:113) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:85) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:54) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:134) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103) [surefire-booter-2.17.jar:2.17]
Caused by: org.apache.derby.impl.jdbc.EmbedSQLException: Database './tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' shutdown.
	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(Unknown Source) ~[derby-10.10.1.1.jar:na]
	... 51 common frames omitted
Caused by: org.apache.derby.iapi.error.StandardException: Database './tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' shutdown.
	at org.apache.derby.iapi.error.StandardException.newException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.shutdownDatabaseException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	... 46 common frames omitted
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 12.835 sec - in dk.netarkivet.harvester.datamodel.DomainDAOTester
Running dk.netarkivet.harvester.datamodel.HeritrixTemplateTester
13:56:27.142 [main] DEBUG dk.netarkivet.harvester.datamodel.HeritrixTemplate - ARC format selected to be used by Heritrix
13:56:27.322 [main] DEBUG dk.netarkivet.harvester.datamodel.HeritrixTemplate - WARC format selected to be used by Heritrix
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.748 sec - in dk.netarkivet.harvester.datamodel.HeritrixTemplateTester
Running dk.netarkivet.harvester.datamodel.JobStatusTester
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.573 sec - in dk.netarkivet.harvester.datamodel.JobStatusTester
Running dk.netarkivet.harvester.scheduler.HarvesterStatusReceiverTest
13:56:35.865 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.replicas.replica.replicaId
13:56:35.871 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: ONE,TWO,THREE
13:56:35.924 [main] WARN  dk.netarkivet.harvester.distribute.HarvesterMessageHandler - Error processing message 'TestObjectMessage: NO ID: To DEV_COMMON_HARVESTMON ReplyTo DEV_COMMON_ERROR OK'
dk.netarkivet.common.exceptions.PermissionDenied: 'dk.netarkivet.harvester.scheduler.HarvesterStatusReceiver@6f4a47c7' provides no handling for NO ID: To DEV_COMMON_HARVESTMON ReplyTo DEV_COMMON_ERROR OK of type dk.netarkivet.harvester.harvesting.distribute.CrawlProgressMessage and should not be invoked!
	at dk.netarkivet.harvester.distribute.HarvesterMessageHandler.deny(HarvesterMessageHandler.java:83) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.harvester.distribute.HarvesterMessageHandler.visit(HarvesterMessageHandler.java:119) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.harvester.harvesting.distribute.CrawlProgressMessage.accept(CrawlProgressMessage.java:336) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.harvester.distribute.HarvesterMessageHandler.onMessage(HarvesterMessageHandler.java:69) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.harvester.scheduler.HarvesterStatusReceiverTest.testInvalidMessageType(HarvesterStatusReceiverTest.java:66) [test-classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_11]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_11]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_11]
	at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0_11]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) [junit-4.11.jar:na]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [junit-4.11.jar:na]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) [junit-4.11.jar:na]
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) [junit-4.11.jar:na]
	at org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:127) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:26) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:160) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138) [junit-4.11.jar:na]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:113) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:85) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:54) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:134) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103) [surefire-booter-2.17.jar:2.17]
Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.157 sec - in dk.netarkivet.harvester.scheduler.HarvesterStatusReceiverTest
Running dk.netarkivet.harvester.scheduler.HarvestJobGeneratorTest
13:56:47.821 [main] INFO  com.mchange.v2.log.MLog - MLog clients using log4j logging.
13:56:47.867 [main] INFO  com.mchange.v2.c3p0.C3P0Registry - Initializing c3p0-0.9.1 [built 16-January-2007 14:46:42; debug? true; trace: 10]
13:56:47.991 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Connection pool initialized with the following values:
- minPoolSize=5
- maxPoolSize=10
- acquireIncrement=5
- maxStatements=0
- maxStatementsPerConnection=0
- idleConnTestPeriod=0
- idleConnTestQuery='null'
- idleConnTestOnCheckin=false
13:56:48.072 [main] INFO  com.mchange.v2.c3p0.impl.AbstractPoolBackedDataSource - Initializing c3p0 pool... com.mchange.v2.c3p0.ComboPooledDataSource [ acquireIncrement -> 5, acquireRetryAttempts -> 30, acquireRetryDelay -> 1000, autoCommitOnClose -> false, automaticTestTable -> null, breakAfterAcquireFailure -> false, checkoutTimeout -> 0, connectionCustomizerClassName -> null, connectionTesterClassName -> com.mchange.v2.c3p0.impl.DefaultConnectionTester, dataSourceName -> 10bbezp9417mft64dskamv|25bc0606, debugUnreturnedConnectionStackTraces -> false, description -> null, driverClass -> org.apache.derby.jdbc.EmbeddedDriver, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 10bbezp9417mft64dskamv|25bc0606, idleConnectionTestPeriod -> 0, initialPoolSize -> 3, jdbcUrl -> jdbc:derby:/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb;create=true, lastAcquisitionFailureDefaultUser -> null, maxAdministrativeTaskTime -> 0, maxConnectionAge -> 0, maxIdleTime -> 0, maxIdleTimeExcessConnections -> 0, maxPoolSize -> 10, maxStatements -> 0, maxStatementsPerConnection -> 0, minPoolSize -> 5, numHelperThreads -> 3, numThreadsAwaitingCheckoutDefaultUser -> 0, preferredTestQuery -> null, properties -> {}, propertyCycle -> 0, testConnectionOnCheckin -> false, testConnectionOnCheckout -> false, unreturnedConnectionTimeout -> 0, usesTraditionalReflectiveProxies -> false ]
13:56:48.098 [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#2] INFO  com.mchange.v2.c3p0.SQLWarnings - Database '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' not created, connection made to existing database instead.
java.sql.SQLWarning: Database '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' not created, connection made to existing database instead.
	at org.apache.derby.iapi.error.SQLWarningFactory.newSQLWarning(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.iapi.error.SQLWarningFactory.newSQLWarning(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection40.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver20.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.AutoloadedDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:120) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:143) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:132) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547) [c3p0-0.9.1.jar:0.9.1]
13:56:48.161 [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0] INFO  com.mchange.v2.c3p0.SQLWarnings - Database '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' not created, connection made to existing database instead.
java.sql.SQLWarning: Database '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' not created, connection made to existing database instead.
	at org.apache.derby.iapi.error.SQLWarningFactory.newSQLWarning(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.iapi.error.SQLWarningFactory.newSQLWarning(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection40.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver20.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.AutoloadedDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:120) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:143) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:132) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547) [c3p0-0.9.1.jar:0.9.1]
13:56:48.166 [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1] INFO  com.mchange.v2.c3p0.SQLWarnings - Database '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' not created, connection made to existing database instead.
java.sql.SQLWarning: Database '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' not created, connection made to existing database instead.
	at org.apache.derby.iapi.error.SQLWarningFactory.newSQLWarning(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.iapi.error.SQLWarningFactory.newSQLWarning(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection40.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver20.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.AutoloadedDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:120) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:143) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:132) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547) [c3p0-0.9.1.jar:0.9.1]
13:56:48.168 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'domains' from version '2' to version '3'.
13:56:48.184 [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#0] INFO  com.mchange.v2.c3p0.SQLWarnings - Database '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' not created, connection made to existing database instead.
java.sql.SQLWarning: Database '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' not created, connection made to existing database instead.
	at org.apache.derby.iapi.error.SQLWarningFactory.newSQLWarning(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.iapi.error.SQLWarningFactory.newSQLWarning(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection40.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver20.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.AutoloadedDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:120) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:143) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:132) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547) [c3p0-0.9.1.jar:0.9.1]
13:56:48.185 [com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread-#1] INFO  com.mchange.v2.c3p0.SQLWarnings - Database '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' not created, connection made to existing database instead.
java.sql.SQLWarning: Database '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' not created, connection made to existing database instead.
	at org.apache.derby.iapi.error.SQLWarningFactory.newSQLWarning(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.iapi.error.SQLWarningFactory.newSQLWarning(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection40.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver20.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.AutoloadedDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at com.mchange.v2.c3p0.DriverManagerDataSource.getConnection(DriverManagerDataSource.java:120) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:143) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.WrapperConnectionPoolDataSource.getPooledConnection(WrapperConnectionPoolDataSource.java:132) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.c3p0.impl.C3P0PooledConnectionPool$1PooledConnectionResourcePoolManager.acquireResource(C3P0PooledConnectionPool.java:137) ~[c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool.doAcquire(BasicResourcePool.java:1014) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool.access$800(BasicResourcePool.java:32) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.resourcepool.BasicResourcePool$AcquireTask.run(BasicResourcePool.java:1810) [c3p0-0.9.1.jar:0.9.1]
	at com.mchange.v2.async.ThreadPoolAsynchronousRunner$PoolThread.run(ThreadPoolAsynchronousRunner.java:547) [c3p0-0.9.1.jar:0.9.1]
13:56:48.186 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'domains' to version 3
13:56:48.849 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'harvestdefinitions' from version '2' to version '4'.
13:56:48.851 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'harvestdefinitions' to version 3
13:56:48.956 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'harvestdefinitions' to version 4
13:56:49.019 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'jobs' from version '8' to version '10'.
13:56:49.030 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'jobs' to version 9
13:56:49.064 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'jobs' to version 10
13:56:49.687 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'extendedfield' from version '1' to version '2'.
13:56:49.690 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'extendedfield' to version 2
13:56:49.764 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'extendedfieldvalue' from version '1' to version '2'.
13:56:49.767 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'extendedfieldvalue' to version 2
13:56:50.039 [main] WARN  dk.netarkivet.common.utils.DBUtils - As yet unknown tablename 'harvestchannel' in table schemaversions. The table should be automatically created in the database when it is first needed.
13:56:50.040 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'harvestchannel' from version '0' to version '1'.
13:56:50.043 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'harvestchannel' to version 1
13:56:51.140 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Reading harvestdefinition w/ id 42
13:56:52.035 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Partialharvest found w/ id 42
13:56:52.261 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (2,true,1,null,null,null,null,)
13:56:52.262 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a DAILY frequency.
13:56:52.402 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (2,true,1,null,null,null,null,)
13:56:52.402 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a DAILY frequency.
13:56:52.465 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - 1 partialharvests records updated
13:56:52.492 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - Harvester  registered on channel FOCUSED
13:56:52.492 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - HarvestChannelRegistry status:
	- FOCUSED {  }
13:56:54.377 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.topLevelDomains.tld
13:56:54.546 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: ac,ad,ae,aero,af,ag,ai,al,am,an,ao,aq,ar,arpa,as,gv.at,ac.at,or.at,co.at,biz.at,info.at,priv.at,at,au,aw,ax,az,ba,bb,bd,be,bf,bg,bh,bi,biz,bj,bm,bn,bo,br,bs,bt,bv,bw,by,bz,ca,cat,cc,cd,cf,cg,ch,ci,ck,cl,cm,cn,co,com,coop,cr,cs,cu,cv,cx,cy,cz,de,dj,dk,dm,do,dz,ec,edu,ee,eg,eh,er,es,et,eu,fi,fj,fk,fm,fo,aeroport.fr,asso.fr,avoues.fr,chambagri.fr,com.fr,gouv.fr,medecin.fr,nom.fr,pharmacien.fr,port.fr,prd.fr,presse.fr,tm.fr,fr,ga,gb,gd,ge,gf,gg,gh,gi,gl,gm,gn,gov,gp,gq,gr,gs,gt,gu,gw,gy,hk,hm,hn,hr,ht,hu,id,ie,il,im,in,info,int,io,iq,ir,is,it,je,jm,jo,jobs,jp,ke,kg,kh,ki,km,kn,kp,kr,kw,ky,kz,la,lb,lc,li,lk,lr,ls,lt,lu,lv,ly,ma,mc,md,me,mg,mh,mil,mk,ml,mm,mn,mo,mobi,mp,mq,mr,ms,mt,mu,museum,mv,mw,mx,my,mz,na,name,nc,ne,net,nf,ng,ni,nl,no,np,nr,nt,nu,nz,om,org,pa,pe,pf,pg,ph,pk,pl,pm,pn,pr,pro,ps,pt,pw,py,qa,asso.re,com.re,re,ro,ru,rw,sa,sb,sc,sd,se,sg,sh,si,sj,sk,sl,sm,sn,so,sr,st,su,sv,sy,sz,tc,td,at.tf,net.tf,tf,tg,th,tj,tk,tl,tm,tn,to,tp,tr,travel,tt,tv,tw,tz,ua,ug,ac.uk,co.uk,gov.uk,ltd.uk,me.uk,mod.uk,net.uk,nic.uk,nhs.uk,org.uk,plc.uk,police.uk,sch.uk,govt.uk,orgn.uk,lea.uk,mil.uk,nel.uk,uk,us,uy,uz,va,vc,ve,vg,vi,vn,vu,wien,wf,ws,ye,yt,yu,za,zm,zw
13:56:55.034 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (1,false,1,0,null,null,null,)
13:56:55.034 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a HOURLY frequency.
13:56:55.048 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (1,false,1,0,null,null,null,)
13:56:55.048 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a HOURLY frequency.
13:56:55.134 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (2,false,1,0,4,null,null,)
13:56:55.134 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a DAILY frequency.
13:56:55.149 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (2,false,1,0,4,null,null,)
13:56:55.149 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a DAILY frequency.
13:56:55.241 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - Harvester  registered on channel FOCUSED
13:56:55.241 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - HarvestChannelRegistry status:
	- FOCUSED {  }
13:56:56.262 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - Harvester  registered on channel FOCUSED
13:56:56.262 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - HarvestChannelRegistry status:
	- FOCUSED {  }
13:56:56.268 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Reading harvestdefinition w/ id 44
13:56:56.270 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Partialharvest found w/ id 44
13:56:56.285 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (1,false,1,0,null,null,null,)
13:56:56.286 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a HOURLY frequency.
13:56:56.313 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (1,false,1,0,null,null,null,)
13:56:56.314 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a HOURLY frequency.
13:56:56.339 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Starting to create jobs for harvest definition #44(Hele time)
13:56:56.344 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Reading harvestdefinition w/ id 45
13:56:56.347 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Partialharvest found w/ id 45
13:56:56.374 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (2,false,1,0,4,null,null,)
13:56:56.375 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a DAILY frequency.
13:56:56.379 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (2,false,1,0,4,null,null,)
13:56:56.380 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a DAILY frequency.
13:56:56.387 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Starting to create jobs for harvest definition #45(Kl. 4)
13:56:56.406 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - Generating jobs for harvestdefinition #44
13:56:56.410 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.scheduler.jobgen.DefaultJobGenerator - Adding domainconfigs with the same order.xml for harvest #44
13:56:56.432 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - No channel mapping registered for harvest id 44, will use default.
13:56:56.541 [JobGeneratorTask-45] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - Generating jobs for harvestdefinition #45
13:56:56.543 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.scheduler.jobgen.DefaultJobGenerator - Adding domainconfigs with the same order.xml for harvest #45
13:56:56.546 [JobGeneratorTask-45] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - No channel mapping registered for harvest id 45, will use default.
13:56:56.876 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.HeritrixTemplate - ARC format selected to be used by Heritrix
13:56:57.068 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.JobDBDAO - Creating Job 2 (state = NEW, HD = 44, channel = FOCUSED, snapshot = false, forcemaxcount = 0, forcemaxbytes = 500000000, forcemaxrunningtime = 0, orderxml = FullSite-order, numconfigs = 1, created = Mon Sep 22 13:56:57 CEST 2014)
13:56:57.231 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.datamodel.HeritrixTemplate - ARC format selected to be used by Heritrix
13:56:57.301 [JobGeneratorTask-44] WARN  dk.netarkivet.harvester.datamodel.Job - HarvestnamePrefix not yet set for job 2. Set it by using the naming scheme. This should only happen for old jobs being read
13:56:57.304 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.Job - Applying the default ArchiveFileNaming class 'dk.netarkivet.harvester.harvesting.LegacyNamingConvention'.
13:56:57.321 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.Job - The harvestPrefix of this job is: 2-44
13:56:57.925 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.datamodel.JobDBDAO - Creating Job 3 (state = NEW, HD = 45, channel = FOCUSED, snapshot = false, forcemaxcount = 0, forcemaxbytes = 500000000, forcemaxrunningtime = 0, orderxml = FullSite-order, numconfigs = 1, created = Mon Sep 22 13:56:57 CEST 2014)
13:56:57.928 [JobGeneratorTask-45] WARN  dk.netarkivet.harvester.datamodel.Job - HarvestnamePrefix not yet set for job 3. Set it by using the naming scheme. This should only happen for old jobs being read
13:56:57.929 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.datamodel.Job - Applying the default ArchiveFileNaming class 'dk.netarkivet.harvester.harvesting.LegacyNamingConvention'.
13:56:57.929 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.datamodel.Job - The harvestPrefix of this job is: 3-45
13:56:57.993 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.scheduler.jobgen.DefaultJobGenerator - Created 1 jobs for harvest #44
13:56:57.995 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - Finished generating 1 jobs for harvestdefinition #44
13:56:58.008 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Created 1 jobs for harvest definition (Hele time)
13:56:58.537 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.scheduler.jobgen.DefaultJobGenerator - Created 1 jobs for harvest #45
13:56:58.537 [JobGeneratorTask-45] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - Finished generating 1 jobs for harvestdefinition #45
13:56:58.537 [JobGeneratorTask-45] INFO  dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Created 1 jobs for harvest definition (Kl. 4)
13:56:58.541 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - 1 partialharvests records updated
13:56:58.566 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - 1 partialharvests records updated
13:56:58.591 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Removed HD #45(Kl. 4) from list of harvestdefinitions to be scheduled. Harvestdefinitions still to be scheduled: [44]
13:56:58.607 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Removed HD #44(Hele time) from list of harvestdefinitions to be scheduled. Harvestdefinitions still to be scheduled: []
13:56:59.039 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - Harvester  registered on channel FOCUSED
13:56:59.039 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - HarvestChannelRegistry status:
	- FOCUSED {  }
13:56:59.053 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Reading harvestdefinition w/ id 44
13:56:59.063 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Partialharvest found w/ id 44
13:56:59.089 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (1,false,1,0,null,null,null,)
13:56:59.091 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a HOURLY frequency.
13:56:59.096 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (1,false,1,0,null,null,null,)
13:56:59.096 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a HOURLY frequency.
13:56:59.102 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Starting to create jobs for harvest definition #44(Hele time)
13:56:59.104 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - Generating jobs for harvestdefinition #44
13:56:59.105 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.scheduler.jobgen.DefaultJobGenerator - Adding domainconfigs with the same order.xml for harvest #44
13:56:59.109 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - No channel mapping registered for harvest id 44, will use default.
13:56:59.602 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.HeritrixTemplate - ARC format selected to be used by Heritrix
13:56:59.680 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.JobDBDAO - Creating Job 4 (state = NEW, HD = 44, channel = FOCUSED, snapshot = false, forcemaxcount = 0, forcemaxbytes = 500000000, forcemaxrunningtime = 0, orderxml = FullSite-order, numconfigs = 1, created = Mon Sep 22 13:56:59 CEST 2014)
13:56:59.719 [JobGeneratorTask-44] WARN  dk.netarkivet.harvester.datamodel.Job - HarvestnamePrefix not yet set for job 4. Set it by using the naming scheme. This should only happen for old jobs being read
13:56:59.721 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.Job - Applying the default ArchiveFileNaming class 'dk.netarkivet.harvester.harvesting.LegacyNamingConvention'.
13:56:59.722 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.Job - The harvestPrefix of this job is: 4-44
13:56:59.811 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.scheduler.jobgen.DefaultJobGenerator - Created 1 jobs for harvest #44
13:56:59.812 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - Finished generating 1 jobs for harvestdefinition #44
13:56:59.813 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Created 1 jobs for harvest definition (Hele time)
13:56:59.821 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - 1 partialharvests records updated
13:56:59.841 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Removed HD #44(Hele time) from list of harvestdefinitions to be scheduled. Harvestdefinitions still to be scheduled: []
13:57:01.344 [main] WARN  dk.netarkivet.harvester.datamodel.DatabaseTestUtils - Expected SQL-exception when shutting down database:
java.sql.SQLNonTransientConnectionException: Database './tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' shutdown.
	at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.EmbedConnection40.<init>(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.Driver20.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.jdbc.AutoloadedDriver.connect(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at java.sql.DriverManager.getConnection(DriverManager.java:664) ~[na:1.8.0_11]
	at java.sql.DriverManager.getConnection(DriverManager.java:270) ~[na:1.8.0_11]
	at dk.netarkivet.harvester.datamodel.DatabaseTestUtils.dropDatabase(DatabaseTestUtils.java:178) [harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.harvester.datamodel.DatabaseTestUtils.dropHDDB(DatabaseTestUtils.java:210) [harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.harvester.datamodel.DataModelTestCase.tearDown(DataModelTestCase.java:116) [test-classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_11]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_11]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_11]
	at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0_11]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) [junit-4.11.jar:na]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [junit-4.11.jar:na]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) [junit-4.11.jar:na]
	at org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:33) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:127) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:26) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:160) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138) [junit-4.11.jar:na]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:113) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:85) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:54) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:134) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103) [surefire-booter-2.17.jar:2.17]
Caused by: org.apache.derby.impl.jdbc.EmbedSQLException: Database './tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' shutdown.
	at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(Unknown Source) ~[derby-10.10.1.1.jar:na]
	... 50 common frames omitted
Caused by: org.apache.derby.iapi.error.StandardException: Database './tests/dk/netarkivet/harvester/datamodel/data/working/fullhddb' shutdown.
	at org.apache.derby.iapi.error.StandardException.newException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	at org.apache.derby.impl.jdbc.TransactionResourceImpl.shutdownDatabaseException(Unknown Source) ~[derby-10.10.1.1.jar:na]
	... 45 common frames omitted
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 24.141 sec - in dk.netarkivet.harvester.scheduler.HarvestJobGeneratorTest
Running dk.netarkivet.harvester.webinterface.SnapshotHarvestDefinitionTester
13:57:06.962 [main] WARN  dk.netarkivet.common.utils.I18n - I18n bundle 'dk.netarkivet.common.Translations' is missing label 'errormsg;harvest.definition.0.already.exists'
java.util.MissingResourceException: Can't find resource for bundle java.util.PropertyResourceBundle, key errormsg;harvest.definition.0.already.exists
	at java.util.ResourceBundle.getObject(ResourceBundle.java:450) ~[na:1.8.0_11]
	at java.util.ResourceBundle.getObject(ResourceBundle.java:444) ~[na:1.8.0_11]
	at java.util.ResourceBundle.getString(ResourceBundle.java:407) ~[na:1.8.0_11]
	at dk.netarkivet.common.utils.I18n.getString(I18n.java:95) [common-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.common.utils.I18n.getString(I18n.java:70) [common-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.common.webinterface.HTMLUtils.forwardWithErrorMessage(HTMLUtils.java:576) [common-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.harvester.webinterface.SnapshotHarvestDefinition.processRequest(SnapshotHarvestDefinition.java:122) [harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.harvester.webinterface.SnapshotHarvestDefinitionTester.testExistingHarvestDefinition(SnapshotHarvestDefinitionTester.java:107) [test-classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_11]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_11]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_11]
	at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0_11]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) [junit-4.11.jar:na]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [junit-4.11.jar:na]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) [junit-4.11.jar:na]
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:127) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:26) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:160) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138) [junit-4.11.jar:na]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:113) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:85) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:54) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:134) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103) [surefire-booter-2.17.jar:2.17]
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.272 sec - in dk.netarkivet.harvester.webinterface.SnapshotHarvestDefinitionTester
Running dk.netarkivet.harvester.webinterface.HistorySiteSectionTester
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.799 sec - in dk.netarkivet.harvester.webinterface.HistorySiteSectionTester
Running dk.netarkivet.harvester.webinterface.ScheduleDefinitionTester
Tests run: 1, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 0.001 sec - in dk.netarkivet.harvester.webinterface.ScheduleDefinitionTester
Running dk.netarkivet.common.webinterface.HTMLUtilsTester
13:57:10.819 [main] DEBUG dk.netarkivet.common.webinterface.HTMLUtils - Loaded URL '/HarvestDefinition/Definitions-selective-harvests.jsp' with title 'TestTitle'
13:57:10.829 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:10.880 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:10.983 [main] DEBUG dk.netarkivet.common.webinterface.HTMLUtils - Loaded URL 'HarvestDefinition/Definitions-selective-harvests.jsp' with title 'TestTitle'
13:57:10.984 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:10.985 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:10.996 [main] DEBUG dk.netarkivet.common.webinterface.HTMLUtils - Loaded URL 'http://foo.bar/History/Harveststatus-jobdetails.jsp' with title 'Details for Job'
13:57:11.004 [main] DEBUG dk.netarkivet.common.webinterface.HTMLUtils - Loaded URL 'http://foo.bar/History/Harveststatus-jobdetails.jsp' with title 'Jobdetaljer'
Tests run: 11, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.41 sec - in dk.netarkivet.common.webinterface.HTMLUtilsTester
Running dk.netarkivet.common.webinterface.GUIWebServerTester
13:57:12.885 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:12.905 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:12.906 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:12.970 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.webapplication
13:57:12.974 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: tests/dk/netarkivet/common/webinterface/data/jsp
13:57:12.974 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:12.977 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: dk.netarkivet.common.webinterface.TestSiteSection
13:57:12.978 [main] INFO  dk.netarkivet.common.webinterface.GUIWebServer - Starting webserver. Port: 4242 deployment directories: 'tests/dk/netarkivet/common/webinterface/data/jsp' classes: 'dk.netarkivet.common.webinterface.TestSiteSection'
13:57:13.182 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:13.184 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: dk.netarkivet.common.webinterface.TestSiteSection
13:57:13.395 [main] INFO  dk.netarkivet.common.webinterface.GUIWebServer - The web application 'tests/dk/netarkivet/common/webinterface/data/jsp' is now deployed at '/jsp'
13:57:14.271 [main] INFO  dk.netarkivet.common.webinterface.GUIWebServer - HTTP server has been stopped.
13:57:14.273 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.307 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:14.307 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:14.324 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.359 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:14.368 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:14.387 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.webapplication
13:57:14.387 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: /not_found_because_it_doesnt_exist
13:57:14.387 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:14.388 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: dk.netarkivet.common.webinterface.TestSiteSection
13:57:14.388 [main] INFO  dk.netarkivet.common.webinterface.GUIWebServer - Starting webserver. Port: 4242 deployment directories: '/not_found_because_it_doesnt_exist' classes: 'dk.netarkivet.common.webinterface.TestSiteSection'
13:57:14.390 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.434 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:14.435 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:14.444 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.webapplication
13:57:14.444 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: tests/dk/netarkivet/common/webinterface/data/jsp
13:57:14.445 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:14.445 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: dk.netarkivet.common.webinterface.TestSiteSection
13:57:14.445 [main] INFO  dk.netarkivet.common.webinterface.GUIWebServer - Starting webserver. Port: 4242 deployment directories: 'tests/dk/netarkivet/common/webinterface/data/jsp' classes: 'dk.netarkivet.common.webinterface.TestSiteSection'
13:57:14.447 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:14.447 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: dk.netarkivet.common.webinterface.TestSiteSection
13:57:14.450 [main] INFO  dk.netarkivet.common.webinterface.GUIWebServer - The web application 'tests/dk/netarkivet/common/webinterface/data/jsp' is now deployed at '/jsp'
13:57:14.558 [main] INFO  dk.netarkivet.common.webinterface.GUIWebServer - HTTP server has been stopped.
13:57:14.559 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.891 sec - in dk.netarkivet.common.webinterface.GUIWebServerTester
13:57:14.567 [Thread-31] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.569 [Thread-31] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:14.569 [Thread-31] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.570 [Thread-31] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.570 [Thread-16] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.571 [Thread-16] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:14.571 [Thread-16] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.572 [Thread-16] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.572 [Thread-14] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.573 [Thread-14] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:14.573 [Thread-14] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.573 [Thread-14] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.574 [Thread-12] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.574 [Thread-12] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:14.574 [Thread-12] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.575 [Thread-12] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.576 [Thread-30] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.577 [Thread-30] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:14.578 [Thread-30] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:14.581 [Thread-30] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
Running dk.netarkivet.common.webinterface.SiteSectionTester
13:57:16.854 [Thread-0] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.053 [Thread-0] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.116 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.118 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.133 [Thread-1000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.134 [Thread-1000] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.218 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.221 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.243 [Thread-2000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.245 [Thread-2000] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.295 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.298 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.322 [Thread-3000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.330 [Thread-3000] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.458 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.464 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.509 [Thread-4000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.511 [Thread-4000] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.578 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.580 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.589 [Thread-5000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.594 [Thread-5000] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.694 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.697 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.708 [Thread-6000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.714 [Thread-6000] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.820 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.824 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.913 [Thread-7000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.915 [Thread-7000] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:17.991 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:17.995 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:18.008 [Thread-8000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:18.010 [Thread-8000] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:18.055 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:18.057 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:18.065 [Thread-9000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:18.067 [Thread-9000] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:18.150 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
13:57:18.155 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: dk.netarkivet.harvester.webinterface.DefinitionsSiteSection,dk.netarkivet.harvester.webinterface.HistorySiteSection,dk.netarkivet.harvester.webinterface.HarvestChannelSiteSection,dk.netarkivet.archive.webinterface.BitPreservationSiteSection,dk.netarkivet.viewerproxy.webinterface.QASiteSection,dk.netarkivet.monitor.webinterface.StatusSiteSection
13:57:18.248 [main] WARN  dk.netarkivet.common.utils.I18n - I18n bundle 'dk.netarkivet.harvester.Translations' is missing label 'title1'
java.util.MissingResourceException: Can't find resource for bundle java.util.PropertyResourceBundle, key title1
	at java.util.ResourceBundle.getObject(ResourceBundle.java:450) ~[na:1.8.0_11]
	at java.util.ResourceBundle.getObject(ResourceBundle.java:444) ~[na:1.8.0_11]
	at java.util.ResourceBundle.getString(ResourceBundle.java:407) ~[na:1.8.0_11]
	at dk.netarkivet.common.utils.I18n.getString(I18n.java:95) ~[common-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.common.webinterface.SiteSection.getTitle(SiteSection.java:119) [common-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.common.webinterface.SiteSectionTester.testGetTitle(SiteSectionTester.java:60) [test-classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_11]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_11]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_11]
	at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0_11]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) [junit-4.11.jar:na]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [junit-4.11.jar:na]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) [junit-4.11.jar:na]
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:127) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:26) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:160) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138) [junit-4.11.jar:na]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:113) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:85) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:54) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:134) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103) [surefire-booter-2.17.jar:2.17]
13:57:18.275 [main] WARN  dk.netarkivet.common.utils.I18n - I18n bundle 'dk.netarkivet.harvester.Translations' is missing label 'title1'
java.util.MissingResourceException: Can't find resource for bundle java.util.PropertyResourceBundle, key title1
	at java.util.ResourceBundle.getObject(ResourceBundle.java:450) ~[na:1.8.0_11]
	at java.util.ResourceBundle.getObject(ResourceBundle.java:444) ~[na:1.8.0_11]
	at java.util.ResourceBundle.getString(ResourceBundle.java:407) ~[na:1.8.0_11]
	at dk.netarkivet.common.utils.I18n.getString(I18n.java:95) ~[common-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.common.webinterface.SiteSection.generateNavigationTree(SiteSection.java:154) [common-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.common.webinterface.SiteSectionTester.testGenerateNavigationTree(SiteSectionTester.java:308) [test-classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_11]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_11]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_11]
	at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0_11]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) [junit-4.11.jar:na]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [junit-4.11.jar:na]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) [junit-4.11.jar:na]
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:127) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:26) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:160) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138) [junit-4.11.jar:na]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:113) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:85) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:54) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:134) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103) [surefire-booter-2.17.jar:2.17]
13:57:18.278 [main] WARN  dk.netarkivet.common.utils.I18n - I18n bundle 'dk.netarkivet.harvester.Translations' is missing label 'title1'
java.util.MissingResourceException: Can't find resource for bundle java.util.PropertyResourceBundle, key title1
	at java.util.ResourceBundle.getObject(ResourceBundle.java:450) ~[na:1.8.0_11]
	at java.util.ResourceBundle.getObject(ResourceBundle.java:444) ~[na:1.8.0_11]
	at java.util.ResourceBundle.getString(ResourceBundle.java:407) ~[na:1.8.0_11]
	at dk.netarkivet.common.utils.I18n.getString(I18n.java:95) ~[common-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.common.webinterface.SiteSection.generateNavigationTree(SiteSection.java:154) [common-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.common.webinterface.SiteSectionTester.testGenerateNavigationTree(SiteSectionTester.java:320) [test-classes/:na]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_11]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_11]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_11]
	at java.lang.reflect.Method.invoke(Method.java:483) ~[na:1.8.0_11]
	at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:47) [junit-4.11.jar:na]
	at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) [junit-4.11.jar:na]
	at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:44) [junit-4.11.jar:na]
	at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:271) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:70) [junit-4.11.jar:na]
	at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:50) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:127) [junit-4.11.jar:na]
	at org.junit.runners.Suite.runChild(Suite.java:26) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$3.run(ParentRunner.java:238) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:63) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:236) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.access$000(ParentRunner.java:53) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:229) [junit-4.11.jar:na]
	at org.junit.runners.ParentRunner.run(ParentRunner.java:309) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:160) [junit-4.11.jar:na]
	at org.junit.runner.JUnitCore.run(JUnitCore.java:138) [junit-4.11.jar:na]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.createRequestAndRun(JUnitCoreWrapper.java:113) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.executeEager(JUnitCoreWrapper.java:85) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreWrapper.execute(JUnitCoreWrapper.java:54) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.junitcore.JUnitCoreProvider.invoke(JUnitCoreProvider.java:134) [surefire-junit47-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:200) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:153) [surefire-booter-2.17.jar:2.17]
	at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:103) [surefire-booter-2.17.jar:2.17]
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 3.15 sec - in dk.netarkivet.common.webinterface.SiteSectionTester
Running dk.netarkivet.viewerproxy.URIObserverTester
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.003 sec - in dk.netarkivet.viewerproxy.URIObserverTester
Running dk.netarkivet.viewerproxy.CrawlLogLinesMatchingRegexpTester
13:57:20.572 [main] INFO  dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing archive file: 1-metadata-1.warc
13:57:20.633 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Starting processing records in archive file '1-metadata-1.warc'.
13:57:20.674 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #0 in archive file '1-metadata-1.warc'.
13:57:20.731 [main] INFO  dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing archive file: 1-metadata-1.arc
13:57:20.734 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Starting processing records in archive file '1-metadata-1.arc'.
13:57:20.745 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #1 in archive file '1-metadata-1.arc'.
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.037 sec - in dk.netarkivet.viewerproxy.CrawlLogLinesMatchingRegexpTester
Running dk.netarkivet.viewerproxy.distribute.HTTPControllerServerTester
13:57:23.120 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:23.133 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:23.133 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:23.327 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepositoryClient will retry a store 3 times and timeout on each try after 3600000 milliseconds, and timeout on each getrequest after 2000 milliseconds.
13:57:23.331 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.replicas.replica.replicaId
13:57:23.337 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: ONE,TWO,THREE
13:57:23.398 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:23.400 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepository listens for replies on channel '[Queue 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX']'
13:57:23.454 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/startRecordingURIs?returnURL=http%3A%2F%2Ffoo.bar
13:57:23.457 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/startRecordingURIs?returnURL=http%3A%2F%2Ffoo.bar
13:57:23.458 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
13:57:23.465 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:23.465 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:23.471 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepositoryClient will retry a store 3 times and timeout on each try after 3600000 milliseconds, and timeout on each getrequest after 2000 milliseconds.
13:57:23.472 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:23.473 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepository listens for replies on channel '[Queue 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX']'
13:57:23.483 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
13:57:23.490 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:23.490 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:23.502 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepositoryClient will retry a store 3 times and timeout on each try after 3600000 milliseconds, and timeout on each getrequest after 2000 milliseconds.
13:57:23.505 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:23.506 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepository listens for replies on channel '[Queue 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX']'
13:57:23.510 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/startRecordingURIs?returnURL=http%3A%2F%2Ffoo.bar
13:57:23.511 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/stopRecordingURIs?returnURL=http%3A%2F%2Ffoo.bar
13:57:23.513 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/clearRecordedURIs
13:57:23.513 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/getRecordedURIs
13:57:23.514 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?jobID=1&label=myTestLabel&returnURL=http%3A%2F%2Ffoo.bar
13:57:23.515 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?jobID=1&label=myTestLabel&returnURL=http%3A%2F%2Ffoo.bar
13:57:23.527 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/startRecordingURIs?fnidder=fnadder
13:57:23.528 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/stopRecordingURIs?fnidder=fnadder
13:57:23.529 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/clearRecordedURIs?fnidder=fnadder
13:57:23.530 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?returnURL=http%3A%2F%2Ffoo.bar
13:57:23.530 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?jobID=1
13:57:23.532 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?label=foobar
13:57:23.533 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?label=foobar&returnURL=http%3A%2F%2Ffoo.bar
13:57:23.534 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?label=foobar&jobID=1
13:57:23.534 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?returnURL=http%3A%2F%2Ffoo.bar&jobID=1
13:57:23.536 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.155 sec - in dk.netarkivet.viewerproxy.distribute.HTTPControllerServerTester
13:57:23.544 [Thread-3] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:23.548 [Thread-3] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:23.548 [Thread-3] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:23.549 [Thread-3] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
Running dk.netarkivet.viewerproxy.distribute.HTTPControllerClientTester
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.586 sec - in dk.netarkivet.viewerproxy.distribute.HTTPControllerClientTester
Running dk.netarkivet.viewerproxy.GetDataResolverTester
13:57:26.684 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:26.707 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:26.708 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:26.710 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:26.865 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getFile?arcFile=fyensdk.arc
13:57:26.931 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.replicas.replica.replicaId
13:57:26.946 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: ONE,TWO,THREE
13:57:27.200 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getFile?arcFile=dummyNotFound
13:57:27.254 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getRecord?arcFile=fyensdk.arc&arcOffset=104
13:57:27.488 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getRecord?arcFile=fyensdk.arc&arcOffset=136
13:57:27.594 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.BitarchiveRecord - Bytes stored in objectBuffer: 6669
13:57:27.659 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.BitarchiveRecord - Reading 6669 bytes from objectBuffer
13:57:27.661 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getMetadata?jobID=2
13:57:28.480 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getMetadata?jobID=3
13:57:28.484 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getMetadata?jobID=2
13:57:28.515 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:28.516 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 3.129 sec - in dk.netarkivet.viewerproxy.GetDataResolverTester
13:57:28.622 [Thread-13] INFO  dk.netarkivet.common.distribute.HTTPRemoteFileRegistry - Cleaning up dk.netarkivet.common.distribute.HTTPRemoteFileRegistry
13:57:28.670 [Thread-2] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:28.670 [Thread-2] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:28.670 [Thread-2] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:28.671 [Thread-2] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:28.672 [Thread-1] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:28.672 [Thread-1] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:28.672 [Thread-1] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:28.673 [Thread-1] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
Cleaned up dk.netarkivet.common.distribute.HTTPRemoteFileRegistry
13:57:28.676 [Thread-13] INFO  dk.netarkivet.common.distribute.HTTPRemoteFileRegistry - Cleaned up dk.netarkivet.common.distribute.HTTPRemoteFileRegistry
Running dk.netarkivet.viewerproxy.DelegatingControllerTester
13:57:30.052 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:30.062 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:30.062 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:30.131 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:30.132 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:30.132 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:30.141 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:30.141 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:30.141 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:30.147 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:30.147 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:30.148 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:30.155 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:30.156 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:30.156 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:30.159 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:30.160 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:30.160 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:30.168 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:30.168 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:30.168 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:30.172 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:30.172 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:30.173 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:30.176 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:30.176 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:30.176 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:30.180 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:30.182 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:30.183 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:30.186 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:30.186 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:30.187 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:30.203 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:30.204 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:30.204 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.985 sec - in dk.netarkivet.viewerproxy.DelegatingControllerTester
Running dk.netarkivet.viewerproxy.CommandResolverTester
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.007 sec - in dk.netarkivet.viewerproxy.CommandResolverTester
Running dk.netarkivet.viewerproxy.MissingURIRecorderTester
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.006 sec - in dk.netarkivet.viewerproxy.MissingURIRecorderTester
Running dk.netarkivet.viewerproxy.UnknownCommandResolverTester
13:57:32.656 [main] DEBUG dk.netarkivet.viewerproxy.UnknownCommandResolver - Blocking unknown command http://netarchivesuite.viewerproxy.invalid/get
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.592 sec - in dk.netarkivet.viewerproxy.UnknownCommandResolverTester
Running dk.netarkivet.viewerproxy.ViewerProxyTester
13:57:34.097 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:34.106 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:34.106 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:34.243 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepositoryClient will retry a store 3 times and timeout on each try after 3600000 milliseconds, and timeout on each getrequest after 2000 milliseconds.
13:57:34.245 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.replicas.replica.replicaId
13:57:34.248 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: ONE,TWO,THREE
13:57:34.299 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:34.300 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepository listens for replies on channel '[Queue 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX']'
13:57:34.329 [main] INFO  dk.netarkivet.harvester.indexserver.FileBasedCache - Metadata cache for 'FULL_CRAWL_LOG' uses directory '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/cachedir/FULL_CRAWL_LOG'
13:57:34.415 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
13:57:34.679 [qtp1961945640-15] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?returnURL=http://foo/&label=hest&jobID=2&jobID=3
13:57:34.686 [qtp1961945640-15] DEBUG dk.netarkivet.harvester.indexserver.FileBasedCache - Waiting to enter synchronization on /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/cachedir/FULL_CRAWL_LOG/2-3-cache.working
13:57:34.687 [qtp1961945640-15] DEBUG dk.netarkivet.harvester.indexserver.FileBasedCache - locking filechannel for file '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/cachedir/FULL_CRAWL_LOG/2-3-cache.working' (thread = qtp1961945640-15)
13:57:34.688 [qtp1961945640-15] DEBUG dk.netarkivet.harvester.indexserver.FileBasedCache - release lock on filechannel sun.nio.ch.FileChannelImpl@7c9623db
13:57:34.689 [qtp1961945640-15] INFO  dk.netarkivet.harvester.indexserver.FileBasedCache - Generated index '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/cachedir/FULL_CRAWL_LOG/2-3-cache' of id '[2, 3]', request was for '[2, 3]'
13:57:34.870 [qtp1961945640-16] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://foo/
13:57:34.871 [qtp1961945640-16] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://foo/
13:57:34.872 [qtp1961945640-16] DEBUG dk.netarkivet.viewerproxy.ARCArchiveAccess - Missing URL: 'http://foo/'
13:57:34.890 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
13:57:34.890 [main] DEBUG httpclient.wire.content - << "5"
13:57:34.890 [main] DEBUG httpclient.wire.content - << "A"
13:57:34.891 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:34.891 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:34.892 [main] DEBUG httpclient.wire.content - << "<html><head><title>Not found</title></head><body>Can't find URL: http://foo/</body></html>"
13:57:34.892 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:34.892 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:34.892 [main] DEBUG httpclient.wire.content - << "0"
13:57:34.893 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:34.893 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:34.893 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:34.893 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:34.901 [qtp1961945640-14] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/startRecordingURIs?returnURL=/
13:57:34.928 [qtp1961945640-14] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/
13:57:34.929 [qtp1961945640-14] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/
13:57:34.929 [qtp1961945640-14] DEBUG dk.netarkivet.viewerproxy.UnknownCommandResolver - Blocking unknown command http://netarchivesuite.viewerproxy.invalid/
13:57:34.938 [qtp1961945640-14] WARN  dk.netarkivet.viewerproxy.WebProxy - Exception for : http://netarchivesuite.viewerproxy.invalid/
dk.netarkivet.common.exceptions.IOFailure: Bad request: 'http://netarchivesuite.viewerproxy.invalid/':
Unknown command
	at dk.netarkivet.viewerproxy.UnknownCommandResolver.executeCommand(UnknownCommandResolver.java:63) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:72) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.WebProxy.handle(WebProxy.java:123) ~[harvester-5.0-SNAPSHOT.jar:na]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) [jetty-server-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.server.Server.handle(Server.java:485) [jetty-server-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:290) [jetty-server-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:248) [jetty-server-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540) [jetty-io-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:606) [jetty-util-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:535) [jetty-util-9.2.2.v20140723.jar:9.2.2.v20140723]
	at java.lang.Thread.run(Thread.java:745) [na:1.8.0_11]
13:57:34.939 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
13:57:34.942 [main] DEBUG httpclient.wire.content - << "4"
13:57:34.942 [main] DEBUG httpclient.wire.content - << "E"
13:57:34.942 [main] DEBUG httpclient.wire.content - << "3"
13:57:34.942 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:34.943 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:34.944 [main] DEBUG httpclient.wire.content - << "<html><head><title>Internal Server Error</title><body>Internal server error for: http://netarchivesuite.viewerproxy.invalid/[\n]"
13:57:34.944 [main] DEBUG httpclient.wire.content - << "<pre>dk.netarkivet.common.exceptions.IOFailure: Bad request: 'http://netarchivesuite.viewerproxy.invalid/':[\n]"
13:57:34.944 [main] DEBUG httpclient.wire.content - << "Unknown command[\n]"
13:57:34.944 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.UnknownCommandResolver.executeCommand(UnknownCommandResolver.java:63)[\n]"
13:57:34.945 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:72)[\n]"
13:57:34.945 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
13:57:34.945 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
13:57:34.945 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.WebProxy.handle(WebProxy.java:123)[\n]"
13:57:34.946 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[\n]"
13:57:34.946 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.Server.handle(Server.java:485)[\n]"
13:57:34.948 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:290)[\n]"
13:57:34.949 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:248)[\n]"
13:57:34.949 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)[\n]"
13:57:34.952 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:606)[\n]"
13:57:34.952 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:535)[\n]"
13:57:34.952 [main] DEBUG httpclient.wire.content - << "[0x9]at java.lang.Thread.run(Thread.java:745)[\n]"
13:57:34.952 [main] DEBUG httpclient.wire.content - << "</pre></body></html>"
13:57:34.954 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:34.954 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:34.954 [main] DEBUG httpclient.wire.content - << "0"
13:57:34.954 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:34.954 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:34.955 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:34.958 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:34.964 [qtp1961945640-13] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://www.nonexistingdomain.test/nonexistingfile.html
13:57:34.965 [qtp1961945640-13] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://www.nonexistingdomain.test/nonexistingfile.html
13:57:34.965 [qtp1961945640-13] DEBUG dk.netarkivet.viewerproxy.ARCArchiveAccess - Missing URL: 'http://www.nonexistingdomain.test/nonexistingfile.html'
13:57:34.968 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
13:57:34.968 [main] DEBUG httpclient.wire.content - << "8"
13:57:34.968 [main] DEBUG httpclient.wire.content - << "5"
13:57:34.968 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:34.969 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:34.969 [main] DEBUG httpclient.wire.content - << "<html><head><title>Not found</title></head><body>Can't find URL: http://www.nonexistingdomain.test/nonexistingfile.html</body></html>"
13:57:34.969 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:34.969 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:34.970 [main] DEBUG httpclient.wire.content - << "0"
13:57:34.970 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:34.971 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:34.972 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:34.973 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:34.976 [qtp1961945640-18] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/getRecordedURIs
13:57:34.978 [main] DEBUG httpclient.wire.content - << "http://www.nonexistingdomain.test/nonexistingfile.html[\n]"
13:57:34.991 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
13:57:35.023 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:35.024 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:35.062 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepositoryClient will retry a store 3 times and timeout on each try after 3600000 milliseconds, and timeout on each getrequest after 2000 milliseconds.
13:57:35.068 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:35.068 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepository listens for replies on channel '[Queue 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX']'
13:57:35.069 [main] INFO  dk.netarkivet.harvester.indexserver.FileBasedCache - Metadata cache for 'FULL_CRAWL_LOG' uses directory '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/cachedir/FULL_CRAWL_LOG'
13:57:35.071 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
13:57:35.085 [qtp40075281-27] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/unknown
13:57:35.086 [qtp40075281-27] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/unknown
13:57:35.086 [qtp40075281-27] DEBUG dk.netarkivet.viewerproxy.UnknownCommandResolver - Blocking unknown command http://netarchivesuite.viewerproxy.invalid/unknown
13:57:35.087 [qtp40075281-27] WARN  dk.netarkivet.viewerproxy.WebProxy - Exception for : http://netarchivesuite.viewerproxy.invalid/unknown
dk.netarkivet.common.exceptions.IOFailure: Bad request: 'http://netarchivesuite.viewerproxy.invalid/unknown':
Unknown command
	at dk.netarkivet.viewerproxy.UnknownCommandResolver.executeCommand(UnknownCommandResolver.java:63) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:72) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.WebProxy.handle(WebProxy.java:123) ~[harvester-5.0-SNAPSHOT.jar:na]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) [jetty-server-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.server.Server.handle(Server.java:485) [jetty-server-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:290) [jetty-server-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:248) [jetty-server-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540) [jetty-io-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:606) [jetty-util-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:535) [jetty-util-9.2.2.v20140723.jar:9.2.2.v20140723]
	at java.lang.Thread.run(Thread.java:745) [na:1.8.0_11]
13:57:35.089 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
13:57:35.090 [main] DEBUG httpclient.wire.content - << "4"
13:57:35.090 [main] DEBUG httpclient.wire.content - << "F"
13:57:35.090 [main] DEBUG httpclient.wire.content - << "1"
13:57:35.090 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.091 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.091 [main] DEBUG httpclient.wire.content - << "<html><head><title>Internal Server Error</title><body>Internal server error for: http://netarchivesuite.viewerproxy.invalid/unknown[\n]"
13:57:35.092 [main] DEBUG httpclient.wire.content - << "<pre>dk.netarkivet.common.exceptions.IOFailure: Bad request: 'http://netarchivesuite.viewerproxy.invalid/unknown':[\n]"
13:57:35.093 [main] DEBUG httpclient.wire.content - << "Unknown command[\n]"
13:57:35.093 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.UnknownCommandResolver.executeCommand(UnknownCommandResolver.java:63)[\n]"
13:57:35.093 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:72)[\n]"
13:57:35.094 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
13:57:35.094 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
13:57:35.094 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.WebProxy.handle(WebProxy.java:123)[\n]"
13:57:35.094 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[\n]"
13:57:35.095 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.Server.handle(Server.java:485)[\n]"
13:57:35.095 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:290)[\n]"
13:57:35.095 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:248)[\n]"
13:57:35.095 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)[\n]"
13:57:35.096 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:606)[\n]"
13:57:35.096 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:535)[\n]"
13:57:35.097 [main] DEBUG httpclient.wire.content - << "[0x9]at java.lang.Thread.run(Thread.java:745)[\n]"
13:57:35.097 [main] DEBUG httpclient.wire.content - << "</pre></body></html>"
13:57:35.098 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.099 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.100 [main] DEBUG httpclient.wire.content - << "0"
13:57:35.100 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.101 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.101 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.101 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.136 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
13:57:35.158 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:35.158 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:35.194 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepositoryClient will retry a store 3 times and timeout on each try after 3600000 milliseconds, and timeout on each getrequest after 2000 milliseconds.
13:57:35.200 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:35.200 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepository listens for replies on channel '[Queue 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX']'
13:57:35.201 [main] INFO  dk.netarkivet.harvester.indexserver.FileBasedCache - Metadata cache for 'FULL_CRAWL_LOG' uses directory '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/cachedir/FULL_CRAWL_LOG'
13:57:35.204 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
13:57:35.252 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
13:57:35.254 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
13:57:35.273 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:35.273 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
13:57:35.306 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepositoryClient will retry a store 3 times and timeout on each try after 3600000 milliseconds, and timeout on each getrequest after 2000 milliseconds.
13:57:35.313 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:35.314 [main] INFO  d.n.archive.arcrepository.distribute.JMSArcRepositoryClient - JMSArcRepository listens for replies on channel '[Queue 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX']'
13:57:35.315 [main] INFO  dk.netarkivet.harvester.indexserver.FileBasedCache - Metadata cache for 'FULL_CRAWL_LOG' uses directory '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/cachedir/FULL_CRAWL_LOG'
13:57:35.316 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
13:57:35.365 [qtp794075965-54] WARN  dk.netarkivet.viewerproxy.WebProxy - Exception for : http://www.nonexistingdomain.test/nonexistingfile.html
dk.netarkivet.common.exceptions.IOFailure: No index set while searching for 'http://www.nonexistingdomain.test/nonexistingfile.html'
	at dk.netarkivet.common.distribute.arcrepository.ARCLookup.luceneLookup(ARCLookup.java:190) ~[common-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.common.distribute.arcrepository.ARCLookup.lookup(ARCLookup.java:141) ~[common-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.ARCArchiveAccess.lookup(ARCArchiveAccess.java:124) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.NotifyingURIResolver.lookup(NotifyingURIResolver.java:71) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74) ~[harvester-5.0-SNAPSHOT.jar:na]
	at dk.netarkivet.viewerproxy.WebProxy.handle(WebProxy.java:123) ~[harvester-5.0-SNAPSHOT.jar:na]
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) [jetty-server-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.server.Server.handle(Server.java:485) [jetty-server-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:290) [jetty-server-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:248) [jetty-server-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540) [jetty-io-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:606) [jetty-util-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:535) [jetty-util-9.2.2.v20140723.jar:9.2.2.v20140723]
	at java.lang.Thread.run(Thread.java:745) [na:1.8.0_11]
13:57:35.367 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
13:57:35.368 [main] DEBUG httpclient.wire.content - << "5"
13:57:35.368 [main] DEBUG httpclient.wire.content - << "F"
13:57:35.368 [main] DEBUG httpclient.wire.content - << "5"
13:57:35.368 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.368 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.369 [main] DEBUG httpclient.wire.content - << "<html><head><title>Internal Server Error</title><body>Internal server error for: http://www.nonexistingdomain.test/nonexistingfile.html[\n]"
13:57:35.369 [main] DEBUG httpclient.wire.content - << "<pre>dk.netarkivet.common.exceptions.IOFailure: No index set while searching for 'http://www.nonexistingdomain.test/nonexistingfile.html'[\n]"
13:57:35.369 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.common.distribute.arcrepository.ARCLookup.luceneLookup(ARCLookup.java:190)[\n]"
13:57:35.369 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.common.distribute.arcrepository.ARCLookup.lookup(ARCLookup.java:141)[\n]"
13:57:35.370 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.ARCArchiveAccess.lookup(ARCArchiveAccess.java:124)[\n]"
13:57:35.370 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.NotifyingURIResolver.lookup(NotifyingURIResolver.java:71)[\n]"
13:57:35.370 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
13:57:35.371 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
13:57:35.371 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
13:57:35.371 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.WebProxy.handle(WebProxy.java:123)[\n]"
13:57:35.371 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[\n]"
13:57:35.371 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.Server.handle(Server.java:485)[\n]"
13:57:35.372 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:290)[\n]"
13:57:35.373 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:248)[\n]"
13:57:35.373 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)[\n]"
13:57:35.373 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:606)[\n]"
13:57:35.374 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:535)[\n]"
13:57:35.374 [main] DEBUG httpclient.wire.content - << "[0x9]at java.lang.Thread.run(Thread.java:745)[\n]"
13:57:35.374 [main] DEBUG httpclient.wire.content - << "</pre></body></html>"
13:57:35.375 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.375 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.376 [main] DEBUG httpclient.wire.content - << "0"
13:57:35.376 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.376 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.377 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.377 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.392 [qtp794075965-56] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?returnURL=http://foo/&label=hest&jobID=2&jobID=3
13:57:35.410 [qtp794075965-56] DEBUG dk.netarkivet.harvester.indexserver.FileBasedCache - Waiting to enter synchronization on /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/cachedir/FULL_CRAWL_LOG/2-3-cache.working
13:57:35.411 [qtp794075965-56] DEBUG dk.netarkivet.harvester.indexserver.FileBasedCache - locking filechannel for file '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/cachedir/FULL_CRAWL_LOG/2-3-cache.working' (thread = qtp794075965-56)
13:57:35.411 [qtp794075965-56] DEBUG dk.netarkivet.harvester.indexserver.FileBasedCache - release lock on filechannel sun.nio.ch.FileChannelImpl@3e70182b
13:57:35.411 [qtp794075965-56] INFO  dk.netarkivet.harvester.indexserver.FileBasedCache - Generated index '/home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/cachedir/FULL_CRAWL_LOG/2-3-cache' of id '[2, 3]', request was for '[2, 3]'
13:57:35.422 [qtp794075965-58] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://foo/
13:57:35.423 [qtp794075965-58] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://foo/
13:57:35.423 [qtp794075965-58] DEBUG dk.netarkivet.viewerproxy.ARCArchiveAccess - Missing URL: 'http://foo/'
13:57:35.425 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
13:57:35.425 [main] DEBUG httpclient.wire.content - << "5"
13:57:35.426 [main] DEBUG httpclient.wire.content - << "A"
13:57:35.426 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.426 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.426 [main] DEBUG httpclient.wire.content - << "<html><head><title>Not found</title></head><body>Can't find URL: http://foo/</body></html>"
13:57:35.427 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.427 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.427 [main] DEBUG httpclient.wire.content - << "0"
13:57:35.427 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.427 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.428 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.428 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.435 [qtp794075965-54] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://www.nonexistingdomain.test/nonexistingfile.html
13:57:35.435 [qtp794075965-54] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://www.nonexistingdomain.test/nonexistingfile.html
13:57:35.436 [qtp794075965-54] DEBUG dk.netarkivet.viewerproxy.ARCArchiveAccess - Missing URL: 'http://www.nonexistingdomain.test/nonexistingfile.html'
13:57:35.438 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
13:57:35.438 [main] DEBUG httpclient.wire.content - << "8"
13:57:35.438 [main] DEBUG httpclient.wire.content - << "5"
13:57:35.438 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.439 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.439 [main] DEBUG httpclient.wire.content - << "<html><head><title>Not found</title></head><body>Can't find URL: http://www.nonexistingdomain.test/nonexistingfile.html</body></html>"
13:57:35.439 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.439 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.440 [main] DEBUG httpclient.wire.content - << "0"
13:57:35.440 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.440 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.440 [main] DEBUG httpclient.wire.content - << "[\r]"
13:57:35.441 [main] DEBUG httpclient.wire.content - << "[\n]"
13:57:35.460 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
Tests run: 4, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.223 sec - in dk.netarkivet.viewerproxy.ViewerProxyTester
13:57:35.514 [Thread-40] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:35.516 [Thread-40] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
13:57:35.516 [Thread-40] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
13:57:35.517 [Thread-40] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
Running dk.netarkivet.viewerproxy.NotifyingURIResolverTester
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.005 sec - in dk.netarkivet.viewerproxy.NotifyingURIResolverTester
Running dk.netarkivet.viewerproxy.ARCArchiveAccessTester
13:57:38.543 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 2 hits for uri: http://netarkivet.dk/netarchive_alm/billeder/spacer.gif
13:57:38.583 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found document with origin: 2-2-20060731110420-00000-sb-test-har-001.statsbiblioteket.dk.arc,73269
13:57:38.667 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.BitarchiveRecord - Bytes stored in objectBuffer: 162
13:57:38.669 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.BitarchiveRecord - Reading 162 bytes from objectBuffer
13:57:39.124 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://does.not.exist
13:57:39.130 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://does.not.exist
13:57:39.130 [main] DEBUG dk.netarkivet.viewerproxy.ARCArchiveAccess - Missing URL: 'http://does.not.exist'
13:57:39.314 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 2 hits for uri: http://netarkivet.dk/netarchive_alm/billeder/spacer.gif
13:57:39.315 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found document with origin: 2-2-20060731110420-00000-sb-test-har-001.statsbiblioteket.dk.arc,73269
13:57:39.316 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - ARC file '2-2-20060731110420-00000-sb-test-har-001.statsbiblioteket.dk.arc' mentioned in index file was not found by arc repository. This may mean we have a timeout, or that the index is wrong; or it may mean we have lost a record in the bitarchives.
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.822 sec - in dk.netarkivet.viewerproxy.ARCArchiveAccessTester
Running dk.netarkivet.viewerproxy.WebProxyTester
13:57:41.402 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
13:57:41.574 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
13:57:41.642 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
13:57:41.799 [main] DEBUG httpclient.wire.content - << "Test"
13:57:41.808 [main] DEBUG httpclient.wire.content - >> "a=x&a=y"
13:57:41.853 [main] DEBUG httpclient.wire.content - << "Test"
13:57:41.858 [main] DEBUG httpclient.wire.content - << "Test"
13:57:41.888 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
Tests run: 7, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 1.814 sec - in dk.netarkivet.viewerproxy.WebProxyTester
Running dk.netarkivet.viewerproxy.webinterface.ReportingTester
13:57:44.396 [main] INFO  dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing archive file: 2-metadata-1.arc
13:57:44.421 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Starting processing records in archive file '2-metadata-1.arc'.
13:57:44.437 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #0 in archive file '2-metadata-1.arc'.
13:57:44.437 [main] INFO  d.n.viewerproxy.webinterface.HarvestedUrlsForDomainBatchJob - looking for crawl-log lines for domain: netarkivet.dk
13:57:44.454 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.topLevelDomains.tld
13:57:44.501 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in classpath data: ac,ad,ae,aero,af,ag,ai,al,am,an,ao,aq,ar,arpa,as,gv.at,ac.at,or.at,co.at,biz.at,info.at,priv.at,at,au,aw,ax,az,ba,bb,bd,be,bf,bg,bh,bi,biz,bj,bm,bn,bo,br,bs,bt,bv,bw,by,bz,ca,cat,cc,cd,cf,cg,ch,ci,ck,cl,cm,cn,co,com,coop,cr,cs,cu,cv,cx,cy,cz,de,dj,dk,dm,do,dz,ec,edu,ee,eg,eh,er,es,et,eu,fi,fj,fk,fm,fo,aeroport.fr,asso.fr,avoues.fr,chambagri.fr,com.fr,gouv.fr,medecin.fr,nom.fr,pharmacien.fr,port.fr,prd.fr,presse.fr,tm.fr,fr,ga,gb,gd,ge,gf,gg,gh,gi,gl,gm,gn,gov,gp,gq,gr,gs,gt,gu,gw,gy,hk,hm,hn,hr,ht,hu,id,ie,il,im,in,info,int,io,iq,ir,is,it,je,jm,jo,jobs,jp,ke,kg,kh,ki,km,kn,kp,kr,kw,ky,kz,la,lb,lc,li,lk,lr,ls,lt,lu,lv,ly,ma,mc,md,me,mg,mh,mil,mk,ml,mm,mn,mo,mobi,mp,mq,mr,ms,mt,mu,museum,mv,mw,mx,my,mz,na,name,nc,ne,net,nf,ng,ni,nl,no,np,nr,nt,nu,nz,om,org,pa,pe,pf,pg,ph,pk,pl,pm,pn,pr,pro,ps,pt,pw,py,qa,asso.re,com.re,re,ro,ru,rw,sa,sb,sc,sd,se,sg,sh,si,sj,sk,sl,sm,sn,so,sr,st,su,sv,sy,sz,tc,td,at.tf,net.tf,tf,tg,th,tj,tk,tl,tm,tn,to,tp,tr,travel,tt,tv,tw,tz,ua,ug,ac.uk,co.uk,gov.uk,ltd.uk,me.uk,mod.uk,net.uk,nic.uk,nhs.uk,org.uk,plc.uk,police.uk,sch.uk,govt.uk,orgn.uk,lea.uk,mil.uk,nel.uk,uk,us,uy,uz,va,vc,ve,vg,vi,vn,vu,wien,wf,ws,ye,yt,yu,za,zm,zw
13:57:44.968 [main] DEBUG dk.netarkivet.common.utils.ProcessUtils - Running external program: sort /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/commontempdir/temp2602250608113191680d3bad64e-f9e5-4171-bcb0-a09c5b8a696c.txt -o /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/commontempdir/temp3100249636485066153d3bad64e-f9e5-4171-bcb0-a09c5b8a696c-sorted.txt with environment LANG=C
13:57:45.038 [main] INFO  dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing archive file: 2-metadata-1.arc
13:57:45.039 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Starting processing records in archive file '2-metadata-1.arc'.
13:57:45.042 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #0 in archive file '2-metadata-1.arc'.
13:57:45.042 [main] INFO  d.n.viewerproxy.webinterface.HarvestedUrlsForDomainBatchJob - looking for crawl-log lines for domain: kaarefc.dk
13:57:45.174 [main] DEBUG dk.netarkivet.common.utils.ProcessUtils - Running external program: sort /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/commontempdir/temp259697121465665927804662315-8add-4e7e-9b43-c87222e782d5.txt -o /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/commontempdir/temp588142438897329062804662315-8add-4e7e-9b43-c87222e782d5-sorted.txt with environment LANG=C
13:57:45.221 [main] INFO  dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing archive file: 2-metadata-1.arc
13:57:45.222 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Starting processing records in archive file '2-metadata-1.arc'.
13:57:45.224 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #0 in archive file '2-metadata-1.arc'.
13:57:45.224 [main] INFO  d.n.viewerproxy.webinterface.HarvestedUrlsForDomainBatchJob - looking for crawl-log lines for domain: doesnotexist.dk
13:57:45.350 [main] DEBUG dk.netarkivet.common.utils.ProcessUtils - Running external program: sort /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/commontempdir/temp13002906612555035567b801c3a-c9b7-424c-a6d8-9bd2039075f2.txt -o /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/commontempdir/temp70156173959800786787b801c3a-c9b7-424c-a6d8-9bd2039075f2-sorted.txt with environment LANG=C
13:57:45.369 [main] DEBUG dk.netarkivet.common.utils.ProcessUtils - Running external program: sort /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/commontempdir/temp7782137720006598035a3f5d401-c8f1-4f88-8962-cc3950e3c519.txt -o /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/commontempdir/temp3598712035880047176a3f5d401-c8f1-4f88-8962-cc3950e3c519-sorted.txt with environment LANG=C
13:57:45.454 [main] INFO  dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing archive file: 2-metadata-1.arc
13:57:45.455 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Starting processing records in archive file '2-metadata-1.arc'.
13:57:45.456 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #0 in archive file '2-metadata-1.arc'.
13:57:45.457 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #1 in archive file '2-metadata-1.arc'.
13:57:45.459 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #2 in archive file '2-metadata-1.arc'.
13:57:45.459 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #3 in archive file '2-metadata-1.arc'.
13:57:45.460 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #4 in archive file '2-metadata-1.arc'.
13:57:45.461 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #5 in archive file '2-metadata-1.arc'.
13:57:45.461 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #6 in archive file '2-metadata-1.arc'.
13:57:45.462 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #7 in archive file '2-metadata-1.arc'.
13:57:45.463 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #8 in archive file '2-metadata-1.arc'.
13:57:45.463 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #9 in archive file '2-metadata-1.arc'.
13:57:45.463 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #10 in archive file '2-metadata-1.arc'.
13:57:45.464 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #11 in archive file '2-metadata-1.arc'.
13:57:45.468 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #12 in archive file '2-metadata-1.arc'.
13:57:45.469 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #13 in archive file '2-metadata-1.arc'.
13:57:45.471 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #14 in archive file '2-metadata-1.arc'.
13:57:45.471 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #15 in archive file '2-metadata-1.arc'.
13:57:45.472 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #16 in archive file '2-metadata-1.arc'.
13:57:45.473 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #17 in archive file '2-metadata-1.arc'.
Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.786 sec - in dk.netarkivet.viewerproxy.webinterface.ReportingTester
13:57:45.582 [Thread-9] INFO  dk.netarkivet.common.distribute.HTTPRemoteFileRegistry - Cleaning up dk.netarkivet.common.distribute.HTTPRemoteFileRegistry
Cleaned up dk.netarkivet.common.distribute.HTTPRemoteFileRegistry
13:57:48.339 [Thread-9] INFO  dk.netarkivet.common.distribute.HTTPRemoteFileRegistry - Cleaned up dk.netarkivet.common.distribute.HTTPRemoteFileRegistry

Results :

Tests run: 325, Failures: 0, Errors: 0, Skipped: 29

[JENKINS] Recording test results
[INFO] 
[INFO] --- maven-jar-plugin:2.4:jar (default-jar) @ harvester-test ---
[WARNING] JAR will be empty - no content was marked for inclusion!
[INFO] 
[INFO] --- maven-source-plugin:2.2.1:jar-no-fork (attach-sources) @ harvester-test ---
[INFO] No sources in project. Archive not created.
[JENKINS] Archiving disabled
[INFO] 
[INFO] --- maven-javadoc-plugin:2.9.1:jar (attach-javadocs) @ harvester-test ---
[INFO] 
[INFO] --- maven-install-plugin:2.4:install (default-install) @ harvester-test ---
[INFO] Installing /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/target/harvester-test-5.0-SNAPSHOT.jar to /home/cibuild02/.m2/repository/org/netarchivesuite/harvester-test/5.0-SNAPSHOT/harvester-test-5.0-SNAPSHOT.jar
[INFO] Installing /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/pom.xml to /home/cibuild02/.m2/repository/org/netarchivesuite/harvester-test/5.0-SNAPSHOT/harvester-test-5.0-SNAPSHOT.pom