SuccessConsole Output

Skipping 468 KB.. Full Log
n 2
10:48:01.238 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'extendedfieldvalue' from version '1' to version '2'.
10:48:01.254 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'extendedfieldvalue' to version 2
10:48:01.348 [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.
10:48:01.349 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'harvestchannel' from version '0' to version '1'.
10:48:01.350 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'harvestchannel' to version 1
10:48:02.076 [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: 7.849 sec - in dk.netarkivet.harvester.datamodel.DomainDAOTester
Running dk.netarkivet.harvester.datamodel.HeritrixTemplateTester
10:48:04.231 [main] DEBUG dk.netarkivet.harvester.datamodel.HeritrixTemplate - ARC format selected to be used by Heritrix
10:48:04.277 [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: 1.765 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.633 sec - in dk.netarkivet.harvester.datamodel.JobStatusTester
Running dk.netarkivet.harvester.scheduler.HarvesterStatusReceiverTest
10:48:11.831 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.replicas.replica.replicaId
10:48:11.837 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: ONE,TWO,THREE
10:48:11.891 [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.163 sec - in dk.netarkivet.harvester.scheduler.HarvesterStatusReceiverTest
Running dk.netarkivet.harvester.scheduler.HarvestJobGeneratorTest
10:48:18.986 [main] INFO  com.mchange.v2.log.MLog - MLog clients using log4j logging.
10:48:19.038 [main] INFO  com.mchange.v2.c3p0.C3P0Registry - Initializing c3p0-0.9.1 [built 16-January-2007 14:46:42; debug? true; trace: 10]
10:48:19.151 [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
10:48:19.239 [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 -> 10bbezp94xfmgk2hqgpgf|25bc0606, debugUnreturnedConnectionStackTraces -> false, description -> null, driverClass -> org.apache.derby.jdbc.EmbeddedDriver, factoryClassLocation -> null, forceIgnoreUnresolvedTransactions -> false, identityToken -> 10bbezp94xfmgk2hqgpgf|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 ]
10:48:19.277 [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]
10:48:19.286 [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]
10:48:19.291 [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]
10:48:19.292 [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]
10:48:19.366 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'domains' from version '2' to version '3'.
10:48:19.368 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'domains' to version 3
10:48:19.477 [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]
10:48:19.661 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'harvestdefinitions' from version '2' to version '4'.
10:48:19.669 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'harvestdefinitions' to version 3
10:48:19.705 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'harvestdefinitions' to version 4
10:48:19.782 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'jobs' from version '8' to version '10'.
10:48:19.787 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'jobs' to version 9
10:48:19.801 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'jobs' to version 10
10:48:20.093 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'extendedfield' from version '1' to version '2'.
10:48:20.095 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'extendedfield' to version 2
10:48:20.122 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'extendedfieldvalue' from version '1' to version '2'.
10:48:20.125 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'extendedfieldvalue' to version 2
10:48:20.235 [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.
10:48:20.246 [main] INFO  dk.netarkivet.harvester.datamodel.DBSpecifics - Trying to migrate table 'harvestchannel' from version '0' to version '1'.
10:48:20.248 [main] INFO  dk.netarkivet.harvester.datamodel.HarvestDBConnection - Updating table 'harvestchannel' to version 1
10:48:20.668 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Reading harvestdefinition w/ id 42
10:48:21.023 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Partialharvest found w/ id 42
10:48:21.468 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (2,true,1,null,null,null,null,)
10:48:21.470 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a DAILY frequency.
10:48:21.600 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (2,true,1,null,null,null,null,)
10:48:21.600 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a DAILY frequency.
10:48:21.660 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - 1 partialharvests records updated
10:48:21.714 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - Harvester  registered on channel FOCUSED
10:48:21.715 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - HarvestChannelRegistry status:
	- FOCUSED {  }
10:48:22.852 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.topLevelDomains.tld
10:48:22.932 [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
10:48:23.149 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (1,false,1,0,null,null,null,)
10:48:23.149 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a HOURLY frequency.
10:48:23.153 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (1,false,1,0,null,null,null,)
10:48:23.153 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a HOURLY frequency.
10:48:23.189 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (2,false,1,0,4,null,null,)
10:48:23.189 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a DAILY frequency.
10:48:23.193 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (2,false,1,0,4,null,null,)
10:48:23.193 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a DAILY frequency.
10:48:23.236 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - Harvester  registered on channel FOCUSED
10:48:23.236 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - HarvestChannelRegistry status:
	- FOCUSED {  }
10:48:24.254 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - Harvester  registered on channel FOCUSED
10:48:24.255 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - HarvestChannelRegistry status:
	- FOCUSED {  }
10:48:24.258 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Reading harvestdefinition w/ id 44
10:48:24.259 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Partialharvest found w/ id 44
10:48:24.281 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (1,false,1,0,null,null,null,)
10:48:24.281 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a HOURLY frequency.
10:48:24.283 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (1,false,1,0,null,null,null,)
10:48:24.284 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a HOURLY frequency.
10:48:24.305 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Starting to create jobs for harvest definition #44(Hele time)
10:48:24.308 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Reading harvestdefinition w/ id 45
10:48:24.309 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Partialharvest found w/ id 45
10:48:24.323 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (2,false,1,0,4,null,null,)
10:48:24.323 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a DAILY frequency.
10:48:24.326 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (2,false,1,0,4,null,null,)
10:48:24.326 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a DAILY frequency.
10:48:24.329 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Starting to create jobs for harvest definition #45(Kl. 4)
10:48:24.339 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - Generating jobs for harvestdefinition #44
10:48:24.341 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.scheduler.jobgen.DefaultJobGenerator - Adding domainconfigs with the same order.xml for harvest #44
10:48:24.354 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - No channel mapping registered for harvest id 44, will use default.
10:48:24.363 [JobGeneratorTask-45] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - Generating jobs for harvestdefinition #45
10:48:24.365 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.scheduler.jobgen.DefaultJobGenerator - Adding domainconfigs with the same order.xml for harvest #45
10:48:24.370 [JobGeneratorTask-45] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - No channel mapping registered for harvest id 45, will use default.
10:48:24.593 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.HeritrixTemplate - ARC format selected to be used by Heritrix
10:48:24.703 [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 15 10:48:24 CEST 2014)
10:48:24.983 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.datamodel.HeritrixTemplate - ARC format selected to be used by Heritrix
10:48:25.021 [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
10:48:25.023 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.Job - Applying the default ArchiveFileNaming class 'dk.netarkivet.harvester.harvesting.LegacyNamingConvention'.
10:48:25.023 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.Job - The harvestPrefix of this job is: 2-44
10:48:25.410 [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 15 10:48:25 CEST 2014)
10:48:25.412 [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
10:48:25.412 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.datamodel.Job - Applying the default ArchiveFileNaming class 'dk.netarkivet.harvester.harvesting.LegacyNamingConvention'.
10:48:25.412 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.datamodel.Job - The harvestPrefix of this job is: 3-45
10:48:25.473 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.scheduler.jobgen.DefaultJobGenerator - Created 1 jobs for harvest #45
10:48:25.474 [JobGeneratorTask-45] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - Finished generating 1 jobs for harvestdefinition #45
10:48:25.474 [JobGeneratorTask-45] INFO  dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Created 1 jobs for harvest definition (Kl. 4)
10:48:25.484 [JobGeneratorTask-45] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - 1 partialharvests records updated
10:48:25.501 [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]
10:48:25.502 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.scheduler.jobgen.DefaultJobGenerator - Created 1 jobs for harvest #44
10:48:25.511 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - Finished generating 1 jobs for harvestdefinition #44
10:48:25.512 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Created 1 jobs for harvest definition (Hele time)
10:48:25.561 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - 1 partialharvests records updated
10:48:25.570 [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: []
10:48:26.580 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - Harvester  registered on channel FOCUSED
10:48:26.580 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestChannelRegistry - HarvestChannelRegistry status:
	- FOCUSED {  }
10:48:26.597 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Reading harvestdefinition w/ id 44
10:48:26.606 [main] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - Partialharvest found w/ id 44
10:48:26.614 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (1,false,1,0,null,null,null,)
10:48:26.614 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a HOURLY frequency.
10:48:26.617 [main] DEBUG dk.netarkivet.harvester.datamodel.ScheduleDBDAO - Creating frequency for (timeunit,anytime,numtimeunits,hour, minute, dayofweek, dayofmonth) = (1,false,1,0,null,null,null,)
10:48:26.617 [main] DEBUG dk.netarkivet.harvester.datamodel.Frequency - Creating a HOURLY frequency.
10:48:26.620 [main] INFO  dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Starting to create jobs for harvest definition #44(Hele time)
10:48:26.621 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - Generating jobs for harvestdefinition #44
10:48:26.621 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.scheduler.jobgen.DefaultJobGenerator - Adding domainconfigs with the same order.xml for harvest #44
10:48:26.623 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - No channel mapping registered for harvest id 44, will use default.
10:48:26.682 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.HeritrixTemplate - ARC format selected to be used by Heritrix
10:48:27.075 [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 15 10:48:27 CEST 2014)
10:48:27.094 [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
10:48:27.095 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.Job - Applying the default ArchiveFileNaming class 'dk.netarkivet.harvester.harvesting.LegacyNamingConvention'.
10:48:27.095 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.Job - The harvestPrefix of this job is: 4-44
10:48:27.141 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.scheduler.jobgen.DefaultJobGenerator - Created 1 jobs for harvest #44
10:48:27.141 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.jobgen.AbstractJobGenerator - Finished generating 1 jobs for harvestdefinition #44
10:48:27.142 [JobGeneratorTask-44] INFO  dk.netarkivet.harvester.scheduler.HarvestJobGenerator - Created 1 jobs for harvest definition (Hele time)
10:48:27.146 [JobGeneratorTask-44] DEBUG dk.netarkivet.harvester.datamodel.HarvestDefinitionDBDAO - 1 partialharvests records updated
10:48:27.150 [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: []
10:48:28.104 [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: 14.808 sec - in dk.netarkivet.harvester.scheduler.HarvestJobGeneratorTest
Running dk.netarkivet.harvester.webinterface.SnapshotHarvestDefinitionTester
10:48:33.513 [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.462 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.964 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.002 sec - in dk.netarkivet.harvester.webinterface.ScheduleDefinitionTester
Running dk.netarkivet.common.webinterface.HTMLUtilsTester
10:48:37.506 [main] DEBUG dk.netarkivet.common.webinterface.HTMLUtils - Loaded URL '/HarvestDefinition/Definitions-selective-harvests.jsp' with title 'TestTitle'
10:48:37.521 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:37.574 [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
10:48:37.676 [main] DEBUG dk.netarkivet.common.webinterface.HTMLUtils - Loaded URL 'HarvestDefinition/Definitions-selective-harvests.jsp' with title 'TestTitle'
10:48:37.677 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:37.685 [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
10:48:37.704 [main] DEBUG dk.netarkivet.common.webinterface.HTMLUtils - Loaded URL 'http://foo.bar/History/Harveststatus-jobdetails.jsp' with title 'Details for Job'
10:48:37.727 [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.294 sec - in dk.netarkivet.common.webinterface.HTMLUtilsTester
Running dk.netarkivet.common.webinterface.GUIWebServerTester
10:48:39.473 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:39.481 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:39.482 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:39.493 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.webapplication
10:48:39.495 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: tests/dk/netarkivet/common/webinterface/data/jsp
10:48:39.495 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:39.496 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: dk.netarkivet.common.webinterface.TestSiteSection
10:48:39.496 [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'
10:48:39.545 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:39.546 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: dk.netarkivet.common.webinterface.TestSiteSection
10:48:39.619 [main] INFO  dk.netarkivet.common.webinterface.GUIWebServer - The web application 'tests/dk/netarkivet/common/webinterface/data/jsp' is now deployed at '/jsp'
10:48:40.251 [main] INFO  dk.netarkivet.common.webinterface.GUIWebServer - HTTP server has been stopped.
10:48:40.252 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.264 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:40.265 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:40.273 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.282 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:40.282 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:40.288 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.webapplication
10:48:40.289 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: /not_found_because_it_doesnt_exist
10:48:40.289 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:40.290 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: dk.netarkivet.common.webinterface.TestSiteSection
10:48:40.290 [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'
10:48:40.291 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.301 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:40.301 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:40.305 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.webapplication
10:48:40.306 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: tests/dk/netarkivet/common/webinterface/data/jsp
10:48:40.306 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:40.307 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: dk.netarkivet.common.webinterface.TestSiteSection
10:48:40.307 [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'
10:48:40.308 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:40.309 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: dk.netarkivet.common.webinterface.TestSiteSection
10:48:40.311 [main] INFO  dk.netarkivet.common.webinterface.GUIWebServer - The web application 'tests/dk/netarkivet/common/webinterface/data/jsp' is now deployed at '/jsp'
10:48:40.494 [main] INFO  dk.netarkivet.common.webinterface.GUIWebServer - HTTP server has been stopped.
10:48:40.495 [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: 1.983 sec - in dk.netarkivet.common.webinterface.GUIWebServerTester
10:48:40.520 [Thread-30] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.522 [Thread-30] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:40.522 [Thread-30] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.523 [Thread-30] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.524 [Thread-16] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.527 [Thread-16] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:40.527 [Thread-16] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.528 [Thread-16] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.529 [Thread-14] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.529 [Thread-14] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:40.530 [Thread-14] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.530 [Thread-14] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.531 [Thread-12] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.531 [Thread-12] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:40.531 [Thread-12] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.532 [Thread-12] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.533 [Thread-29] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.533 [Thread-29] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:40.534 [Thread-29] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:40.535 [Thread-29] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
Running dk.netarkivet.common.webinterface.SiteSectionTester
10:48:42.138 [Thread-0] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:42.323 [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
10:48:42.404 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:42.405 [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
10:48:42.421 [Thread-1000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:42.422 [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
10:48:42.514 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:42.516 [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
10:48:42.543 [Thread-2000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:42.545 [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
10:48:42.593 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:42.595 [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
10:48:42.616 [Thread-3000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:42.618 [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
10:48:42.750 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:42.757 [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
10:48:42.811 [Thread-4000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:42.814 [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
10:48:42.901 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:42.904 [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
10:48:42.981 [Thread-5000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:42.983 [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
10:48:43.072 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:43.075 [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
10:48:43.087 [Thread-6000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:43.184 [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
10:48:43.199 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:43.202 [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
10:48:43.216 [Thread-7000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:43.219 [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
10:48:43.267 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:43.270 [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
10:48:43.274 [Thread-8000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:43.276 [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
10:48:43.359 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:43.361 [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
10:48:43.368 [Thread-9000] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:43.372 [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
10:48:43.426 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.webinterface.siteSection.class
10:48:43.431 [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
10:48:43.491 [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]
10:48:43.520 [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]
10:48:43.527 [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: 2.379 sec - in dk.netarkivet.common.webinterface.SiteSectionTester
Running dk.netarkivet.viewerproxy.URIObserverTester
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.005 sec - in dk.netarkivet.viewerproxy.URIObserverTester
Running dk.netarkivet.viewerproxy.CrawlLogLinesMatchingRegexpTester
10:48:45.784 [main] INFO  dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing archive file: 1-metadata-1.warc
10:48:45.811 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Starting processing records in archive file '1-metadata-1.warc'.
10:48:45.882 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #0 in archive file '1-metadata-1.warc'.
10:48:45.938 [main] INFO  dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing archive file: 1-metadata-1.arc
10:48:45.942 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Starting processing records in archive file '1-metadata-1.arc'.
10:48:45.952 [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.131 sec - in dk.netarkivet.viewerproxy.CrawlLogLinesMatchingRegexpTester
Running dk.netarkivet.viewerproxy.distribute.HTTPControllerServerTester
10:48:47.413 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:47.423 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:47.423 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:47.463 [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.
10:48:47.465 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.replicas.replica.replicaId
10:48:47.468 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: ONE,TWO,THREE
10:48:47.491 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:47.493 [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']'
10:48:47.579 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/startRecordingURIs?returnURL=http%3A%2F%2Ffoo.bar
10:48:47.581 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/startRecordingURIs?returnURL=http%3A%2F%2Ffoo.bar
10:48:47.582 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
10:48:47.587 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:47.587 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:47.591 [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.
10:48:47.592 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:47.592 [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']'
10:48:47.597 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
10:48:47.598 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:47.599 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:47.602 [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.
10:48:47.604 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:47.605 [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']'
10:48:47.608 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/startRecordingURIs?returnURL=http%3A%2F%2Ffoo.bar
10:48:47.608 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/stopRecordingURIs?returnURL=http%3A%2F%2Ffoo.bar
10:48:47.609 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/clearRecordedURIs
10:48:47.609 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/getRecordedURIs
10:48:47.610 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?jobID=1&label=myTestLabel&returnURL=http%3A%2F%2Ffoo.bar
10:48:47.610 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?jobID=1&label=myTestLabel&returnURL=http%3A%2F%2Ffoo.bar
10:48:47.612 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/startRecordingURIs?fnidder=fnadder
10:48:47.612 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/stopRecordingURIs?fnidder=fnadder
10:48:47.612 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/clearRecordedURIs?fnidder=fnadder
10:48:47.613 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?returnURL=http%3A%2F%2Ffoo.bar
10:48:47.613 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?jobID=1
10:48:47.613 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?label=foobar
10:48:47.614 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?label=foobar&returnURL=http%3A%2F%2Ffoo.bar
10:48:47.614 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?label=foobar&jobID=1
10:48:47.615 [main] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?returnURL=http%3A%2F%2Ffoo.bar&jobID=1
10:48:47.619 [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: 1.074 sec - in dk.netarkivet.viewerproxy.distribute.HTTPControllerServerTester
10:48:47.645 [Thread-3] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:47.646 [Thread-3] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:47.647 [Thread-3] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:47.652 [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.549 sec - in dk.netarkivet.viewerproxy.distribute.HTTPControllerClientTester
Running dk.netarkivet.viewerproxy.GetDataResolverTester
10:48:50.715 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:50.723 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:50.724 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:50.724 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:50.791 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getFile?arcFile=fyensdk.arc
10:48:50.802 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.replicas.replica.replicaId
10:48:50.805 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: ONE,TWO,THREE
10:48:50.946 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getFile?arcFile=dummyNotFound
10:48:50.958 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getRecord?arcFile=fyensdk.arc&arcOffset=104
10:48:50.986 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getRecord?arcFile=fyensdk.arc&arcOffset=136
10:48:51.004 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.BitarchiveRecord - Bytes stored in objectBuffer: 6669
10:48:51.016 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.BitarchiveRecord - Reading 6669 bytes from objectBuffer
10:48:51.017 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getMetadata?jobID=2
10:48:51.437 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getMetadata?jobID=3
10:48:51.438 [main] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/getMetadata?jobID=2
10:48:51.440 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:51.441 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.668 sec - in dk.netarkivet.viewerproxy.GetDataResolverTester
10:48:51.525 [Thread-13] INFO  dk.netarkivet.common.distribute.HTTPRemoteFileRegistry - Cleaning up dk.netarkivet.common.distribute.HTTPRemoteFileRegistry
10:48:51.605 [Thread-2] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:51.605 [Thread-2] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:51.606 [Thread-2] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:51.607 [Thread-2] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:51.609 [Thread-1] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:51.609 [Thread-1] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:51.609 [Thread-1] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:51.610 [Thread-1] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
Cleaned up dk.netarkivet.common.distribute.HTTPRemoteFileRegistry
10:48:51.612 [Thread-13] INFO  dk.netarkivet.common.distribute.HTTPRemoteFileRegistry - Cleaned up dk.netarkivet.common.distribute.HTTPRemoteFileRegistry
Running dk.netarkivet.viewerproxy.DelegatingControllerTester
10:48:53.008 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:53.017 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:53.017 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:53.110 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:53.111 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:53.112 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:53.129 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:53.130 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:53.131 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:53.138 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:53.138 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:53.139 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:53.142 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:53.142 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:53.143 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:53.153 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:53.153 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:53.153 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:53.160 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:53.161 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:53.161 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:53.164 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:53.164 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:53.165 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:53.168 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:53.169 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:53.169 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:53.174 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:53.174 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:53.174 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:53.181 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:53.181 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:53.181 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:53.198 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:53.199 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:53.199 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Tests run: 6, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.002 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
10:48:55.728 [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.603 sec - in dk.netarkivet.viewerproxy.UnknownCommandResolverTester
Running dk.netarkivet.viewerproxy.ViewerProxyTester
10:48:57.240 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:57.248 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:57.249 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:57.375 [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.
10:48:57.376 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.replicas.replica.replicaId
10:48:57.380 [main] DEBUG dk.netarkivet.common.utils.Settings - Value found in loaded data: ONE,TWO,THREE
10:48:57.398 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:57.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']'
10:48:57.411 [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'
10:48:57.506 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
10:48:57.792 [qtp1961945640-13] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?returnURL=http://foo/&label=hest&jobID=2&jobID=3
10:48:57.798 [qtp1961945640-13] 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
10:48:57.798 [qtp1961945640-13] 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-13)
10:48:57.799 [qtp1961945640-13] DEBUG dk.netarkivet.harvester.indexserver.FileBasedCache - release lock on filechannel sun.nio.ch.FileChannelImpl@4f404a55
10:48:57.800 [qtp1961945640-13] 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]'
10:48:58.037 [qtp1961945640-14] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://foo/
10:48:58.038 [qtp1961945640-14] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://foo/
10:48:58.038 [qtp1961945640-14] DEBUG dk.netarkivet.viewerproxy.ARCArchiveAccess - Missing URL: 'http://foo/'
10:48:58.052 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
10:48:58.053 [main] DEBUG httpclient.wire.content - << "5"
10:48:58.053 [main] DEBUG httpclient.wire.content - << "A"
10:48:58.053 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.054 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.054 [main] DEBUG httpclient.wire.content - << "<html><head><title>Not found</title></head><body>Can't find URL: http://foo/</body></html>"
10:48:58.054 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.055 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.055 [main] DEBUG httpclient.wire.content - << "0"
10:48:58.056 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.056 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.056 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.057 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.062 [qtp1961945640-16] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/startRecordingURIs?returnURL=/
10:48:58.072 [qtp1961945640-17] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/
10:48:58.073 [qtp1961945640-17] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/
10:48:58.074 [qtp1961945640-17] DEBUG dk.netarkivet.viewerproxy.UnknownCommandResolver - Blocking unknown command http://netarchivesuite.viewerproxy.invalid/
10:48:58.085 [qtp1961945640-17] 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]
10:48:58.086 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
10:48:58.088 [main] DEBUG httpclient.wire.content - << "4"
10:48:58.088 [main] DEBUG httpclient.wire.content - << "E"
10:48:58.089 [main] DEBUG httpclient.wire.content - << "3"
10:48:58.089 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.090 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.091 [main] DEBUG httpclient.wire.content - << "<html><head><title>Internal Server Error</title><body>Internal server error for: http://netarchivesuite.viewerproxy.invalid/[\n]"
10:48:58.092 [main] DEBUG httpclient.wire.content - << "<pre>dk.netarkivet.common.exceptions.IOFailure: Bad request: 'http://netarchivesuite.viewerproxy.invalid/':[\n]"
10:48:58.092 [main] DEBUG httpclient.wire.content - << "Unknown command[\n]"
10:48:58.093 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.UnknownCommandResolver.executeCommand(UnknownCommandResolver.java:63)[\n]"
10:48:58.093 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:72)[\n]"
10:48:58.093 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
10:48:58.094 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
10:48:58.094 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.WebProxy.handle(WebProxy.java:123)[\n]"
10:48:58.094 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[\n]"
10:48:58.095 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.Server.handle(Server.java:485)[\n]"
10:48:58.095 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:290)[\n]"
10:48:58.096 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:248)[\n]"
10:48:58.096 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)[\n]"
10:48:58.097 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:606)[\n]"
10:48:58.099 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:535)[\n]"
10:48:58.099 [main] DEBUG httpclient.wire.content - << "[0x9]at java.lang.Thread.run(Thread.java:745)[\n]"
10:48:58.100 [main] DEBUG httpclient.wire.content - << "</pre></body></html>"
10:48:58.100 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.101 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.101 [main] DEBUG httpclient.wire.content - << "0"
10:48:58.101 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.102 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.103 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.106 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.114 [qtp1961945640-13] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://www.nonexistingdomain.test/nonexistingfile.html
10:48:58.115 [qtp1961945640-13] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://www.nonexistingdomain.test/nonexistingfile.html
10:48:58.115 [qtp1961945640-13] DEBUG dk.netarkivet.viewerproxy.ARCArchiveAccess - Missing URL: 'http://www.nonexistingdomain.test/nonexistingfile.html'
10:48:58.117 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
10:48:58.117 [main] DEBUG httpclient.wire.content - << "8"
10:48:58.117 [main] DEBUG httpclient.wire.content - << "5"
10:48:58.118 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.118 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.118 [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>"
10:48:58.120 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.121 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.122 [main] DEBUG httpclient.wire.content - << "0"
10:48:58.122 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.123 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.123 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.123 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.127 [qtp1961945640-14] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/getRecordedURIs
10:48:58.129 [main] DEBUG httpclient.wire.content - << "http://www.nonexistingdomain.test/nonexistingfile.html[\n]"
10:48:58.140 [qtp1961945640-13] WARN  org.eclipse.jetty.server.HttpChannel - complete failed
java.lang.IllegalStateException: Closed with pending callback org.eclipse.jetty.server.HttpConnection$SendCallback@48d13a75[CLOSED][i=null,cb=SharedBlockingCallback@7c1ddf08{null}]
	at org.eclipse.jetty.util.IteratingCallback.close(IteratingCallback.java:397) ~[jetty-util-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.server.HttpConnection.onClose(HttpConnection.java:429) ~[jetty-server-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.io.SelectorManager.connectionClosed(SelectorManager.java:277) ~[jetty-io-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.io.SelectorManager$ManagedSelector.destroyEndPoint(SelectorManager.java:690) ~[jetty-io-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.io.SelectChannelEndPoint.close(SelectChannelEndPoint.java:169) ~[jetty-io-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.io.AbstractConnection.close(AbstractConnection.java:225) ~[jetty-io-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.io.SelectorManager$ManagedSelector.closeNoExceptions(SelectorManager.java:654) ~[jetty-io-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.io.SelectorManager$ManagedSelector.access$600(SelectorManager.java:353) ~[jetty-io-9.2.2.v20140723.jar:9.2.2.v20140723]
	at org.eclipse.jetty.io.SelectorManager$ManagedSelector$EndPointCloser.run(SelectorManager.java:959) ~[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]
10:48:58.166 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
10:48:58.199 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:58.200 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:58.240 [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.
10:48:58.249 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:58.250 [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']'
10:48:58.251 [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'
10:48:58.253 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
10:48:58.296 [qtp40075281-27] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/unknown
10:48:58.297 [qtp40075281-27] DEBUG dk.netarkivet.viewerproxy.GetDataResolver - Executing command http://netarchivesuite.viewerproxy.invalid/unknown
10:48:58.297 [qtp40075281-27] DEBUG dk.netarkivet.viewerproxy.UnknownCommandResolver - Blocking unknown command http://netarchivesuite.viewerproxy.invalid/unknown
10:48:58.298 [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]
10:48:58.308 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
10:48:58.309 [main] DEBUG httpclient.wire.content - << "4"
10:48:58.309 [main] DEBUG httpclient.wire.content - << "F"
10:48:58.310 [main] DEBUG httpclient.wire.content - << "1"
10:48:58.310 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.310 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.310 [main] DEBUG httpclient.wire.content - << "<html><head><title>Internal Server Error</title><body>Internal server error for: http://netarchivesuite.viewerproxy.invalid/unknown[\n]"
10:48:58.311 [main] DEBUG httpclient.wire.content - << "<pre>dk.netarkivet.common.exceptions.IOFailure: Bad request: 'http://netarchivesuite.viewerproxy.invalid/unknown':[\n]"
10:48:58.311 [main] DEBUG httpclient.wire.content - << "Unknown command[\n]"
10:48:58.311 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.UnknownCommandResolver.executeCommand(UnknownCommandResolver.java:63)[\n]"
10:48:58.312 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:72)[\n]"
10:48:58.312 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
10:48:58.312 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
10:48:58.312 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.WebProxy.handle(WebProxy.java:123)[\n]"
10:48:58.313 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[\n]"
10:48:58.313 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.Server.handle(Server.java:485)[\n]"
10:48:58.313 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:290)[\n]"
10:48:58.313 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:248)[\n]"
10:48:58.314 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)[\n]"
10:48:58.314 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:606)[\n]"
10:48:58.315 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:535)[\n]"
10:48:58.315 [main] DEBUG httpclient.wire.content - << "[0x9]at java.lang.Thread.run(Thread.java:745)[\n]"
10:48:58.316 [main] DEBUG httpclient.wire.content - << "</pre></body></html>"
10:48:58.316 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.317 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.317 [main] DEBUG httpclient.wire.content - << "0"
10:48:58.318 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.318 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.318 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.319 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.336 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
10:48:58.361 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:58.361 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:58.402 [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.
10:48:58.409 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:58.410 [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']'
10:48:58.411 [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'
10:48:58.413 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
10:48:58.497 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
10:48:58.498 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Removing listener from channel 'DEV_COMMON_THIS_REPOS_CLIENT_130_225_27_165_IS_XXX'
10:48:58.520 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:58.521 [main] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
10:48:58.559 [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.
10:48:58.566 [main] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Creating instance of dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:58.567 [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']'
10:48:58.568 [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'
10:48:58.570 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
10:48:58.613 [qtp794075965-53] 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]
10:48:58.617 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
10:48:58.618 [main] DEBUG httpclient.wire.content - << "5"
10:48:58.618 [main] DEBUG httpclient.wire.content - << "F"
10:48:58.619 [main] DEBUG httpclient.wire.content - << "5"
10:48:58.619 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.619 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.620 [main] DEBUG httpclient.wire.content - << "<html><head><title>Internal Server Error</title><body>Internal server error for: http://www.nonexistingdomain.test/nonexistingfile.html[\n]"
10:48:58.621 [main] DEBUG httpclient.wire.content - << "<pre>dk.netarkivet.common.exceptions.IOFailure: No index set while searching for 'http://www.nonexistingdomain.test/nonexistingfile.html'[\n]"
10:48:58.621 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.common.distribute.arcrepository.ARCLookup.luceneLookup(ARCLookup.java:190)[\n]"
10:48:58.621 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.common.distribute.arcrepository.ARCLookup.lookup(ARCLookup.java:141)[\n]"
10:48:58.622 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.ARCArchiveAccess.lookup(ARCArchiveAccess.java:124)[\n]"
10:48:58.623 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.NotifyingURIResolver.lookup(NotifyingURIResolver.java:71)[\n]"
10:48:58.623 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
10:48:58.624 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
10:48:58.624 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.CommandResolver.lookup(CommandResolver.java:74)[\n]"
10:48:58.625 [main] DEBUG httpclient.wire.content - << "[0x9]at dk.netarkivet.viewerproxy.WebProxy.handle(WebProxy.java:123)[\n]"
10:48:58.625 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)[\n]"
10:48:58.625 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.Server.handle(Server.java:485)[\n]"
10:48:58.626 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:290)[\n]"
10:48:58.626 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:248)[\n]"
10:48:58.627 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)[\n]"
10:48:58.627 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:606)[\n]"
10:48:58.628 [main] DEBUG httpclient.wire.content - << "[0x9]at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:535)[\n]"
10:48:58.628 [main] DEBUG httpclient.wire.content - << "[0x9]at java.lang.Thread.run(Thread.java:745)[\n]"
10:48:58.628 [main] DEBUG httpclient.wire.content - << "</pre></body></html>"
10:48:58.629 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.629 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.630 [main] DEBUG httpclient.wire.content - << "0"
10:48:58.630 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.630 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.631 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.631 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.650 [qtp794075965-55] DEBUG dk.netarkivet.viewerproxy.distribute.HTTPControllerServer - Executing command http://netarchivesuite.viewerproxy.invalid/changeIndex?returnURL=http://foo/&label=hest&jobID=2&jobID=3
10:48:58.651 [qtp794075965-55] 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
10:48:58.652 [qtp794075965-55] 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-55)
10:48:58.674 [qtp794075965-55] DEBUG dk.netarkivet.harvester.indexserver.FileBasedCache - release lock on filechannel sun.nio.ch.FileChannelImpl@1d9920cd
10:48:58.675 [qtp794075965-55] 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]'
10:48:58.685 [qtp794075965-57] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://foo/
10:48:58.685 [qtp794075965-57] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://foo/
10:48:58.686 [qtp794075965-57] DEBUG dk.netarkivet.viewerproxy.ARCArchiveAccess - Missing URL: 'http://foo/'
10:48:58.687 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
10:48:58.687 [main] DEBUG httpclient.wire.content - << "5"
10:48:58.688 [main] DEBUG httpclient.wire.content - << "A"
10:48:58.688 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.688 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.689 [main] DEBUG httpclient.wire.content - << "<html><head><title>Not found</title></head><body>Can't find URL: http://foo/</body></html>"
10:48:58.689 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.689 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.689 [main] DEBUG httpclient.wire.content - << "0"
10:48:58.690 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.690 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.690 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.690 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.694 [qtp794075965-53] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://www.nonexistingdomain.test/nonexistingfile.html
10:48:58.695 [qtp794075965-53] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://www.nonexistingdomain.test/nonexistingfile.html
10:48:58.695 [qtp794075965-53] DEBUG dk.netarkivet.viewerproxy.ARCArchiveAccess - Missing URL: 'http://www.nonexistingdomain.test/nonexistingfile.html'
10:48:58.697 [main] WARN  org.apache.commons.httpclient.HttpMethodBase - Going to buffer response body of large or unknown size. Using getResponseBodyAsStream instead is recommended.
10:48:58.697 [main] DEBUG httpclient.wire.content - << "8"
10:48:58.698 [main] DEBUG httpclient.wire.content - << "5"
10:48:58.698 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.699 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.699 [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>"
10:48:58.699 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.700 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.700 [main] DEBUG httpclient.wire.content - << "0"
10:48:58.701 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.701 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.701 [main] DEBUG httpclient.wire.content - << "[\r]"
10:48:58.702 [main] DEBUG httpclient.wire.content - << "[\n]"
10:48:58.807 [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.525 sec - in dk.netarkivet.viewerproxy.ViewerProxyTester
10:48:58.854 [Thread-39] INFO  dk.netarkivet.common.distribute.JMSConnectionMockupMQ - Cleaning up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:58.855 [Thread-39] INFO  dk.netarkivet.common.distribute.JMSConnection - Starting cleanup
10:48:58.857 [Thread-39] INFO  dk.netarkivet.common.distribute.JMSConnection - Cleanup finished
Cleaned up dk.netarkivet.common.distribute.JMSConnectionMockupMQ
10:48:58.858 [Thread-39] 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.006 sec - in dk.netarkivet.viewerproxy.NotifyingURIResolverTester
Running dk.netarkivet.viewerproxy.ARCArchiveAccessTester
10:49:01.264 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 2 hits for uri: http://netarkivet.dk/netarchive_alm/billeder/spacer.gif
10:49:01.275 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found document with origin: 2-2-20060731110420-00000-sb-test-har-001.statsbiblioteket.dk.arc,73269
10:49:01.313 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.BitarchiveRecord - Bytes stored in objectBuffer: 162
10:49:01.314 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.BitarchiveRecord - Reading 162 bytes from objectBuffer
10:49:01.421 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://does.not.exist
10:49:01.421 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 0 hits for uri: http://does.not.exist
10:49:01.422 [main] DEBUG dk.netarkivet.viewerproxy.ARCArchiveAccess - Missing URL: 'http://does.not.exist'
10:49:01.496 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found 2 hits for uri: http://netarkivet.dk/netarchive_alm/billeder/spacer.gif
10:49:01.497 [main] DEBUG dk.netarkivet.common.distribute.arcrepository.ARCLookup - Found document with origin: 2-2-20060731110420-00000-sb-test-har-001.statsbiblioteket.dk.arc,73269
10:49:01.497 [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: 1.43 sec - in dk.netarkivet.viewerproxy.ARCArchiveAccessTester
Running dk.netarkivet.viewerproxy.WebProxyTester
10:49:03.493 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
10:49:03.659 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
10:49:03.726 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
10:49:04.046 [main] DEBUG httpclient.wire.content - << "Test"
10:49:04.053 [main] DEBUG httpclient.wire.content - >> "a=x&a=y"
10:49:04.126 [main] DEBUG httpclient.wire.content - << "Test"
10:49:04.136 [main] DEBUG httpclient.wire.content - << "Test"
10:49:04.144 [main] INFO  dk.netarkivet.viewerproxy.WebProxy - Starting viewerproxy jetty on port 7076
Tests run: 7, Failures: 0, Errors: 0, Skipped: 1, Time elapsed: 1.959 sec - in dk.netarkivet.viewerproxy.WebProxyTester
Running dk.netarkivet.viewerproxy.webinterface.ReportingTester
10:49:06.220 [main] INFO  dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing archive file: 2-metadata-1.arc
10:49:06.295 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Starting processing records in archive file '2-metadata-1.arc'.
10:49:06.313 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #0 in archive file '2-metadata-1.arc'.
10:49:06.313 [main] INFO  d.n.viewerproxy.webinterface.HarvestedUrlsForDomainBatchJob - looking for crawl-log lines for domain: netarkivet.dk
10:49:06.331 [main] DEBUG dk.netarkivet.common.utils.Settings - Searching for a setting for key: settings.common.topLevelDomains.tld
10:49:06.367 [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
10:49:06.529 [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/temp522338807312453057617951707-8c63-45e3-a78d-6926a4afa235.txt -o /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/commontempdir/temp769312237669160364517951707-8c63-45e3-a78d-6926a4afa235-sorted.txt with environment LANG=C
10:49:06.562 [main] INFO  dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing archive file: 2-metadata-1.arc
10:49:06.563 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Starting processing records in archive file '2-metadata-1.arc'.
10:49:06.566 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #0 in archive file '2-metadata-1.arc'.
10:49:06.567 [main] INFO  d.n.viewerproxy.webinterface.HarvestedUrlsForDomainBatchJob - looking for crawl-log lines for domain: kaarefc.dk
10:49:06.640 [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/temp75367662191590937245c37cbba-153a-48ee-a270-79d346ffecf6.txt -o /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/commontempdir/temp29705373770471020215c37cbba-153a-48ee-a270-79d346ffecf6-sorted.txt with environment LANG=C
10:49:06.686 [main] INFO  dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing archive file: 2-metadata-1.arc
10:49:06.687 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Starting processing records in archive file '2-metadata-1.arc'.
10:49:06.695 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #0 in archive file '2-metadata-1.arc'.
10:49:06.695 [main] INFO  d.n.viewerproxy.webinterface.HarvestedUrlsForDomainBatchJob - looking for crawl-log lines for domain: doesnotexist.dk
10:49:06.724 [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/temp6817576292176848551e3d84ad0-4fcf-4b9a-b3ef-d2f0227f7656.txt -o /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/commontempdir/temp814963054660023628e3d84ad0-4fcf-4b9a-b3ef-d2f0227f7656-sorted.txt with environment LANG=C
10:49:06.788 [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/temp45143890386496675967f07c0ab-286e-4ea2-bb0d-9bd1ad85e640.txt -o /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/tests/dk/netarkivet/viewerproxy/data/working/commontempdir/temp17055513258833338087f07c0ab-286e-4ea2-bb0d-9bd1ad85e640-sorted.txt with environment LANG=C
10:49:06.852 [main] INFO  dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing archive file: 2-metadata-1.arc
10:49:06.852 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Starting processing records in archive file '2-metadata-1.arc'.
10:49:06.853 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #0 in archive file '2-metadata-1.arc'.
10:49:06.856 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #1 in archive file '2-metadata-1.arc'.
10:49:06.857 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #2 in archive file '2-metadata-1.arc'.
10:49:06.857 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #3 in archive file '2-metadata-1.arc'.
10:49:06.858 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #4 in archive file '2-metadata-1.arc'.
10:49:06.858 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #5 in archive file '2-metadata-1.arc'.
10:49:06.859 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #6 in archive file '2-metadata-1.arc'.
10:49:06.859 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #7 in archive file '2-metadata-1.arc'.
10:49:06.859 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #8 in archive file '2-metadata-1.arc'.
10:49:06.860 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #9 in archive file '2-metadata-1.arc'.
10:49:06.860 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #10 in archive file '2-metadata-1.arc'.
10:49:06.861 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #11 in archive file '2-metadata-1.arc'.
10:49:06.863 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #12 in archive file '2-metadata-1.arc'.
10:49:06.864 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #13 in archive file '2-metadata-1.arc'.
10:49:06.864 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #14 in archive file '2-metadata-1.arc'.
10:49:06.865 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #15 in archive file '2-metadata-1.arc'.
10:49:06.865 [main] DEBUG dk.netarkivet.common.utils.archive.ArchiveBatchJob - Processing record #16 in archive file '2-metadata-1.arc'.
10:49:06.865 [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.134 sec - in dk.netarkivet.viewerproxy.webinterface.ReportingTester
10:49:06.902 [Thread-9] INFO  dk.netarkivet.common.distribute.HTTPRemoteFileRegistry - Cleaning up dk.netarkivet.common.distribute.HTTPRemoteFileRegistry
Cleaned up dk.netarkivet.common.distribute.HTTPRemoteFileRegistry
10:49:07.479 [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] Building jar: /home/cibuild02/workspace/NetarchiveSuite-template/harvester/harvester-test/target/harvester-test-5.0-SNAPSHOT.jar
[INFO] 
[INFO] --- maven-source-plugin:2.2.1:jar-no-fork (attach-sources) @ harvester-test ---
[INFO] No sources in project. Archive not created.
[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
[JENKINS] Archiving disabled