User@VB:~/Project/barefoot$ mvn clean test [INFO] Scanning for projects... [INFO] [INFO] ------------------------------------------------------------------------ [INFO] Building barefoot 0.1.3 [INFO] ------------------------------------------------------------------------ [INFO] [INFO] --- maven-clean-plugin:2.6.1:clean (default-clean) @ barefoot --- [INFO] Deleting /home/pinzel/Cartox/barefoot/target [INFO] Deleting /home/pinzel/Cartox/barefoot (includes = [**/*.bfmap, **/*.log, **/.DS_Store], excludes = []) [INFO] [INFO] --- maven-resources-plugin:2.6:resources (default-resources) @ barefoot --- [WARNING] Using platform encoding (UTF-8 actually) to copy filtered resources, i.e. build is platform dependent! [INFO] Copying 1 resource [INFO] [INFO] --- maven-compiler-plugin:3.1:compile (default-compile) @ barefoot --- [INFO] Changes detected - recompiling the module! [WARNING] File encoding has not been set, using platform encoding UTF-8, i.e. build is platform dependent! [INFO] Compiling 78 source files to /home/pinzel/Cartox/barefoot/target/classes [INFO] [INFO] --- maven-resources-plugin:2.6:testResources (default-testResources) @ barefoot --- [WARNING] File encoding has not been set, using platform encoding UTF-8, i.e. build is platform dependent! [WARNING] Using platform encoding (UTF-8 actually) to copy filtered resources, i.e. build is platform dependent! [INFO] Copying 0 resource [INFO] Copying 6 resources [INFO] [INFO] --- maven-compiler-plugin:3.1:testCompile (default-testCompile) @ barefoot --- [INFO] Changes detected - recompiling the module! [WARNING] File encoding has not been set, using platform encoding UTF-8, i.e. build is platform dependent! [INFO] Compiling 31 source files to /home/pinzel/Cartox/barefoot/target/test-classes [INFO] [INFO] --- maven-surefire-plugin:2.20.1:test (default-test) @ barefoot --- [INFO] [INFO] ------------------------------------------------------- [INFO] T E S T S [INFO] ------------------------------------------------------- [INFO] Running com.bmwcarit.barefoot.matcher.MatcherTest 16:50:38,013 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback.groovy] 16:50:38,019 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Could NOT find resource [logback-test.xml] 16:50:38,020 |-INFO in ch.qos.logback.classic.LoggerContext[default] - Found resource [logback.xml] at [file:/home/pinzel/Cartox/barefoot/target/test-classes/logback.xml] 16:50:38,021 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs multiple times on the classpath. 16:50:38,021 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [file:/home/pinzel/Cartox/barefoot/target/classes/logback.xml] 16:50:38,021 |-WARN in ch.qos.logback.classic.LoggerContext[default] - Resource [logback.xml] occurs at [file:/home/pinzel/Cartox/barefoot/target/test-classes/logback.xml] 16:50:38,231 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - debug attribute not set 16:50:38,251 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.ConsoleAppender] 16:50:38,283 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [CONSOLE] 16:50:38,413 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 16:50:38,529 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - About to instantiate appender of type [ch.qos.logback.core.FileAppender] 16:50:38,537 |-INFO in ch.qos.logback.core.joran.action.AppenderAction - Naming appender as [FILE] 16:50:38,545 |-INFO in ch.qos.logback.core.joran.action.NestedComplexPropertyIA - Assuming default type [ch.qos.logback.classic.encoder.PatternLayoutEncoder] for [encoder] property 16:50:38,545 |-INFO in ch.qos.logback.core.FileAppender[FILE] - File property is set to [test-trace.log] 16:50:38,548 |-INFO in ch.qos.logback.classic.joran.action.LoggerAction - Setting level of logger [com.bmwcarit.barefoot.tracker.TrackerServer] to DEBUG 16:50:38,548 |-INFO in ch.qos.logback.classic.joran.action.RootLoggerAction - Setting level of ROOT logger to INFO 16:50:38,548 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [CONSOLE] to Logger[ROOT] 16:50:38,550 |-INFO in ch.qos.logback.classic.joran.action.ConfigurationAction - End of configuration. 16:50:38,552 |-INFO in ch.qos.logback.classic.joran.JoranConfigurator@4883b407 - Registering current configuration as safe fallback point 2018-01-26 16:50:38,745 INFO [main] RoadMap: inserting roads ... 2018-01-26 16:50:38,749 INFO [main] RoadMap: inserted 6 (9) roads and finished 2018-01-26 16:50:38,763 INFO [main] RoadMap: ~0 megabytes used for road data (estimate) 2018-01-26 16:50:38,794 INFO [main] RoadMap: index and topology constructing ... 2018-01-26 16:50:38,826 INFO [main] RoadMap: index and topology constructed 2018-01-26 16:50:38,865 INFO [main] RoadMap: ~0 megabytes used for spatial index (estimate) 2018-01-26 16:50:39,020 INFO [main] RoadMap: inserting roads ... 2018-01-26 16:50:39,021 INFO [main] RoadMap: inserted 6 (9) roads and finished 2018-01-26 16:50:39,055 INFO [main] RoadMap: ~0 megabytes used for road data (estimate) 2018-01-26 16:50:39,096 INFO [main] RoadMap: index and topology constructing ... 2018-01-26 16:50:39,097 INFO [main] RoadMap: index and topology constructed 2018-01-26 16:50:39,135 INFO [main] RoadMap: ~0 megabytes used for spatial index (estimate) [INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 1.537 s - in com.bmwcarit.barefoot.matcher.MatcherTest [INFO] Running com.bmwcarit.barefoot.matcher.MinsetTest 2018-01-26 16:50:39,343 INFO [main] RoadMap: inserting roads ... 2018-01-26 16:50:39,345 INFO [main] RoadMap: inserted 6 (6) roads and finished 2018-01-26 16:50:39,431 INFO [main] RoadMap: ~0 megabytes used for road data (estimate) 2018-01-26 16:50:39,485 INFO [main] RoadMap: index and topology constructing ... 2018-01-26 16:50:39,486 INFO [main] RoadMap: index and topology constructed 2018-01-26 16:50:39,560 INFO [main] RoadMap: ~0 megabytes used for spatial index (estimate) 2018-01-26 16:50:39,645 INFO [main] RoadMap: inserting roads ... 2018-01-26 16:50:39,651 INFO [main] RoadMap: inserted 6 (9) roads and finished 2018-01-26 16:50:39,741 INFO [main] RoadMap: ~0 megabytes used for road data (estimate) 2018-01-26 16:50:39,828 INFO [main] RoadMap: index and topology constructing ... 2018-01-26 16:50:39,829 INFO [main] RoadMap: index and topology constructed 2018-01-26 16:50:39,894 INFO [main] RoadMap: ~0 megabytes used for spatial index (estimate) [INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.576 s - in com.bmwcarit.barefoot.matcher.MinsetTest [INFO] Running com.bmwcarit.barefoot.matcher.ServerTest 2018-01-26 16:50:39,979 INFO [Thread-1] ServerControl: initialize server 2018-01-26 16:50:39,981 INFO [Thread-1] ServerControl: read database properties from file config/oberbayern.properties 2018-01-26 16:50:39,983 INFO [Thread-1] Loader: load map from database oberbayern 2018-01-26 16:50:39,993 INFO [Thread-1] Loader: open road reader for database oberbayern at localhost:5432 2018-01-26 16:50:39,994 INFO [Thread-1] Loader: database.host=localhost 2018-01-26 16:50:40,019 INFO [Thread-1] Loader: database.port=5432 2018-01-26 16:50:40,023 INFO [Thread-1] Loader: database.name=oberbayern 2018-01-26 16:50:40,024 INFO [Thread-1] Loader: database.table=bfmap_ways 2018-01-26 16:50:40,027 INFO [Thread-1] Loader: database.user=osmuser 2018-01-26 16:50:40,027 INFO [Thread-1] Loader: database.road-types=./map/tools/road-types.json 2018-01-26 16:50:40,183 INFO [Thread-1] PostGISReader: open reader (standard) 2018-01-26 16:50:40,184 INFO [Thread-1] PostGISReader: open reader (parameterized) 2018-01-26 16:50:40,383 INFO [Thread-1] RoadMap: inserting roads ... 2018-01-26 16:50:40,386 INFO [Thread-1] PostGISReader: execute query 2018-01-26 16:50:44,804 INFO [Thread-1] RoadMap: inserted 100000 (192717) roads 2018-01-26 16:50:47,805 INFO [Thread-1] RoadMap: inserted 200000 (387977) roads 2018-01-26 16:50:50,280 INFO [Thread-1] RoadMap: inserted 300000 (582939) roads 2018-01-26 16:50:52,842 INFO [Thread-1] RoadMap: inserted 400000 (775221) roads 2018-01-26 16:50:54,955 INFO [Thread-1] RoadMap: inserted 500000 (968101) roads 2018-01-26 16:50:56,964 INFO [Thread-1] RoadMap: inserted 600000 (1157542) roads 2018-01-26 16:50:58,180 INFO [Thread-1] RoadMap: inserted 629051 (1214032) roads and finished 2018-01-26 16:50:58,185 INFO [Thread-1] PostGISReader: close reader 2018-01-26 16:50:58,583 INFO [Thread-1] RoadMap: ~221 megabytes used for road data (estimate) 2018-01-26 16:51:10,168 INFO [Thread-1] RoadMap: index and topology constructing ... 2018-01-26 16:51:14,545 INFO [Thread-1] RoadMap: index and topology constructed 2018-01-26 16:51:15,741 INFO [Thread-1] RoadMap: ~89 megabytes used for spatial index (estimate) 2018-01-26 16:51:15,741 INFO [Thread-1] ServerControl: read tracker properties from file config/server.properties 2018-01-26 16:51:15,768 INFO [Thread-1] MatcherServer: matcher.radius.max=200.0 2018-01-26 16:51:15,768 INFO [Thread-1] MatcherServer: matcher.distance.max=15000.0 2018-01-26 16:51:15,768 INFO [Thread-1] MatcherServer: matcher.lambda=0.0 2018-01-26 16:51:15,768 INFO [Thread-1] MatcherServer: matcher.sigma=4.5 2018-01-26 16:51:15,768 INFO [Thread-1] MatcherServer: matcher.threads=8 2018-01-26 16:51:15,768 INFO [Thread-1] MatcherServer: matcher.interval.min=1000 2018-01-26 16:51:15,768 INFO [Thread-1] MatcherServer: matcher.distance.min=0.0 2018-01-26 16:51:15,768 INFO [Thread-1] AbstractServer: server.port=1234 2018-01-26 16:51:15,769 INFO [Thread-1] AbstractServer: server.timeout.request=1500000 2018-01-26 16:51:15,769 INFO [Thread-1] AbstractServer: server.timeout.response=6000000 2018-01-26 16:51:15,769 INFO [Thread-1] AbstractServer: server.connections=20 2018-01-26 16:51:15,784 INFO [Thread-1] ServerControl: starting server on port 1234 with map oberbayern 2018-01-26 16:51:15,785 INFO [Thread-1] AbstractServer: listening on port 1234 ... 2018-01-26 16:51:36,203 INFO [pool-2-thread-2] MatcherServer: response processed in 19907 ms 2018-01-26 16:51:36,469 INFO [main] ServerControl: stopping server 2018-01-26 16:51:36,469 INFO [main] AbstractServer: received shutdown signal 2018-01-26 16:51:36,470 INFO [main] AbstractServer: closing server ... 2018-01-26 16:51:36,470 INFO [Thread-1] AbstractServer: closed 2018-01-26 16:51:36,471 INFO [Thread-1] ServerControl: server stopped [INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 56.516 s - in com.bmwcarit.barefoot.matcher.ServerTest [INFO] Running com.bmwcarit.barefoot.matcher.MatcherKStateTest 2018-01-26 16:51:37,348 INFO [main] RoadMap: inserting roads ... 2018-01-26 16:51:37,349 INFO [main] RoadMap: inserted 6 (9) roads and finished 2018-01-26 16:51:38,424 INFO [main] RoadMap: ~0 megabytes used for road data (estimate) 2018-01-26 16:51:39,123 INFO [main] RoadMap: index and topology constructing ... 2018-01-26 16:51:39,124 INFO [main] RoadMap: index and topology constructed 2018-01-26 16:51:40,306 INFO [main] RoadMap: ~0 megabytes used for spatial index (estimate) [INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 3.909 s - in com.bmwcarit.barefoot.matcher.MatcherKStateTest [INFO] Running com.bmwcarit.barefoot.matcher.MatcherSampleTest [INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.011 s - in com.bmwcarit.barefoot.matcher.MatcherSampleTest [INFO] Running com.bmwcarit.barefoot.road.PostGISReaderTest 2018-01-26 16:51:40,440 INFO [main] Loader: open road reader for database oberbayern at localhost:5432 2018-01-26 16:51:40,447 INFO [main] Loader: database.host=localhost 2018-01-26 16:51:40,448 INFO [main] Loader: database.port=5432 2018-01-26 16:51:40,448 INFO [main] Loader: database.name=oberbayern 2018-01-26 16:51:40,449 INFO [main] Loader: database.table=bfmap_ways 2018-01-26 16:51:40,451 INFO [main] Loader: database.user=osmuser 2018-01-26 16:51:40,455 INFO [main] Loader: database.road-types=./map/tools/road-types.json 2018-01-26 16:51:40,501 INFO [main] PostGISReader: open reader (parameterized) 2018-01-26 16:51:40,542 INFO [main] PostGISReader: execute query 2018-01-26 16:51:41,050 INFO [main] PostGISReader: close reader 2018-01-26 16:51:41,054 INFO [main] Loader: open road reader for database oberbayern at localhost:5432 2018-01-26 16:51:41,054 INFO [main] Loader: database.host=localhost 2018-01-26 16:51:41,054 INFO [main] Loader: database.port=5432 2018-01-26 16:51:41,055 INFO [main] Loader: database.name=oberbayern 2018-01-26 16:51:41,055 INFO [main] Loader: database.table=bfmap_ways 2018-01-26 16:51:41,055 INFO [main] Loader: database.user=osmuser 2018-01-26 16:51:41,055 INFO [main] Loader: database.road-types=./map/tools/road-types.json 2018-01-26 16:51:41,056 INFO [main] PostGISReader: open reader (parameterized) 2018-01-26 16:51:41,077 INFO [main] PostGISReader: execute query 2018-01-26 16:51:41,264 INFO [main] PostGISReader: close reader 2018-01-26 16:51:41,270 INFO [main] Loader: open road reader for database oberbayern at localhost:5432 2018-01-26 16:51:41,272 INFO [main] Loader: database.host=localhost 2018-01-26 16:51:41,272 INFO [main] Loader: database.port=5432 2018-01-26 16:51:41,272 INFO [main] Loader: database.name=oberbayern 2018-01-26 16:51:41,272 INFO [main] Loader: database.table=bfmap_ways 2018-01-26 16:51:41,273 INFO [main] Loader: database.user=osmuser 2018-01-26 16:51:41,273 INFO [main] Loader: database.road-types=./map/tools/road-types.json 2018-01-26 16:51:41,274 INFO [main] PostGISReader: open reader (standard) 2018-01-26 16:51:41,275 INFO [main] PostGISReader: open reader (parameterized) 2018-01-26 16:51:41,286 INFO [main] PostGISReader: execute query 2018-01-26 16:51:41,316 INFO [main] PostGISReader: close reader [INFO] Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.896 s - in com.bmwcarit.barefoot.road.PostGISReaderTest [INFO] Running com.bmwcarit.barefoot.road.BfmapReaderTest 2018-01-26 16:51:41,318 INFO [main] Loader: load map from file /home/pinzel/Cartox/barefoot/oberbayern.bfmap 2018-01-26 16:51:42,188 INFO [main] RoadMap: inserting roads ... 2018-01-26 16:51:46,992 INFO [main] RoadMap: inserted 100000 (192717) roads 2018-01-26 16:51:49,401 INFO [main] RoadMap: inserted 200000 (387977) roads 2018-01-26 16:51:52,165 INFO [main] RoadMap: inserted 300000 (582939) roads 2018-01-26 16:51:54,825 INFO [main] RoadMap: inserted 400000 (775221) roads 2018-01-26 16:51:57,486 INFO [main] RoadMap: inserted 500000 (968101) roads 2018-01-26 16:52:00,711 INFO [main] RoadMap: inserted 600000 (1157542) roads 2018-01-26 16:52:01,446 INFO [main] RoadMap: inserted 629051 (1214032) roads and finished 2018-01-26 16:52:03,093 INFO [main] RoadMap: ~217 megabytes used for road data (estimate) 2018-01-26 16:52:04,219 INFO [main] RoadMap: index and topology constructing ... 2018-01-26 16:52:07,740 INFO [main] RoadMap: index and topology constructed 2018-01-26 16:52:09,675 INFO [main] RoadMap: ~92 megabytes used for spatial index (estimate) [INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 57.212 s - in com.bmwcarit.barefoot.road.BfmapReaderTest [INFO] Running com.bmwcarit.barefoot.tracker.TrackerServerTest 2018-01-26 16:52:38,569 INFO [Thread-12] TrackerControl: initialize server 2018-01-26 16:52:38,584 INFO [Thread-12] TrackerControl: read database properties from file config/oberbayern.properties 2018-01-26 16:52:38,585 INFO [Thread-12] Loader: load map from file /home/pinzel/Cartox/barefoot/oberbayern.bfmap 2018-01-26 16:52:40,248 INFO [Thread-12] RoadMap: inserting roads ... 2018-01-26 16:52:43,330 INFO [Thread-12] RoadMap: inserted 100000 (192717) roads 2018-01-26 16:52:45,673 INFO [Thread-12] RoadMap: inserted 200000 (387977) roads 2018-01-26 16:52:47,986 INFO [Thread-12] RoadMap: inserted 300000 (582939) roads 2018-01-26 16:52:50,292 INFO [Thread-12] RoadMap: inserted 400000 (775221) roads 2018-01-26 16:52:54,744 INFO [Thread-12] RoadMap: inserted 500000 (968101) roads 2018-01-26 16:52:57,047 INFO [Thread-12] RoadMap: inserted 600000 (1157542) roads 2018-01-26 16:52:57,858 INFO [Thread-12] RoadMap: inserted 629051 (1214032) roads and finished 2018-01-26 16:53:00,292 INFO [Thread-12] RoadMap: ~214 megabytes used for road data (estimate) 2018-01-26 16:53:02,285 INFO [Thread-12] RoadMap: index and topology constructing ... 2018-01-26 16:53:29,386 INFO [Thread-12] RoadMap: index and topology constructed 2018-01-26 16:53:32,631 INFO [Thread-12] RoadMap: ~91 megabytes used for spatial index (estimate) 2018-01-26 16:53:32,631 INFO [Thread-12] TrackerControl: read tracker properties from file config/tracker.properties 2018-01-26 16:53:32,859 INFO [Thread-12] TrackerServer: tracker.state.ttl=60 2018-01-26 16:53:32,864 INFO [Thread-12] TrackerServer: tracker.port=1235 2018-01-26 16:53:32,869 INFO [Thread-12] TrackerServer: tracker.monitor.sensitive=0.0 2018-01-26 16:53:32,928 INFO [Thread-12] TrackerServer: matcher.radius.max=200.0 2018-01-26 16:53:32,928 INFO [Thread-12] TrackerServer: matcher.distance.max=5000.0 2018-01-26 16:53:32,928 INFO [Thread-12] TrackerServer: matcher.lambda=0.0 2018-01-26 16:53:32,928 INFO [Thread-12] TrackerServer: matcher.sigma=5.0 2018-01-26 16:53:32,928 INFO [Thread-12] TrackerServer: matcher.threads=8 2018-01-26 16:53:32,929 INFO [Thread-12] TrackerServer: matcher.interval.min=1000 2018-01-26 16:53:32,929 INFO [Thread-12] TrackerServer: matcher.distance.min=0.0 2018-01-26 16:53:32,929 INFO [Thread-12] AbstractServer: server.port=1234 2018-01-26 16:53:32,929 INFO [Thread-12] AbstractServer: server.timeout.request=5000 2018-01-26 16:53:32,929 INFO [Thread-12] AbstractServer: server.timeout.response=10000 2018-01-26 16:53:32,929 INFO [Thread-12] AbstractServer: server.connections=100 2018-01-26 16:53:32,929 INFO [Thread-12] TrackerControl: starting server on port 1234 with map oberbayern 2018-01-26 16:53:32,930 INFO [Thread-12] AbstractServer: listening on port 1234 ... 2018-01-26 16:53:33,243 DEBUG [Thread-21] TrackerServer: state update of object \x0001 processed in 43 ms 2018-01-26 16:53:36,680 DEBUG [Thread-21] TrackerServer: state update of object \x0001 processed in 3348 ms 2018-01-26 16:53:42,697 DEBUG [Thread-19] TrackerServer: state update of object \x0001 processed in 5753 ms 2018-01-26 16:53:47,102 DEBUG [Thread-18] TrackerServer: state update of object \x0001 processed in 3705 ms 2018-01-26 16:53:54,103 DEBUG [Thread-21] TrackerServer: state update of object \x0001 processed in 3406 ms 2018-01-26 16:54:01,633 DEBUG [Thread-22] TrackerServer: state update of object \x0001 processed in 7157 ms 2018-01-26 16:54:10,617 DEBUG [Thread-16] TrackerServer: state update of object \x0001 processed in 8641 ms 2018-01-26 16:54:17,092 DEBUG [Thread-19] TrackerServer: state update of object \x0001 processed in 5917 ms 2018-01-26 16:54:23,296 DEBUG [Thread-16] TrackerServer: state update of object \x0001 processed in 5556 ms 2018-01-26 16:54:29,059 DEBUG [Thread-15] TrackerServer: state update of object \x0001 processed in 5387 ms 2018-01-26 16:54:32,531 DEBUG [Thread-20] TrackerServer: state update of object \x0001 processed in 3134 ms 2018-01-26 16:54:40,090 DEBUG [Thread-22] TrackerServer: state update of object \x0001 processed in 3587 ms 2018-01-26 16:54:43,443 DEBUG [Thread-17] TrackerServer: state update of object \x0001 processed in 579 ms 2018-01-26 16:54:48,828 DEBUG [Thread-15] TrackerServer: state update of object \x0001 processed in 2732 ms 2018-01-26 16:54:51,913 DEBUG [Thread-20] TrackerServer: state update of object \x0001 processed in 330 ms 2018-01-26 16:54:54,917 DEBUG [Thread-22] TrackerServer: state update of object \x0001 processed in 453 ms 2018-01-26 16:55:00,045 DEBUG [Thread-21] TrackerServer: state update of object \x0001 processed in 2645 ms 2018-01-26 16:55:03,248 DEBUG [Thread-15] TrackerServer: state update of object \x0001 processed in 492 ms 2018-01-26 16:55:08,558 DEBUG [Thread-20] TrackerServer: state update of object \x0001 processed in 2721 ms 2018-01-26 16:55:11,613 DEBUG [Thread-17] TrackerServer: state update of object \x0001 processed in 271 ms 2018-01-26 16:55:20,119 DEBUG [Thread-19] TrackerServer: state update of object \x0001 processed in 4183 ms 2018-01-26 16:55:26,904 DEBUG [Thread-20] TrackerServer: state update of object \x0001 processed in 3013 ms 2018-01-26 16:55:33,038 DEBUG [Thread-17] TrackerServer: state update of object \x0001 processed in 2946 ms 2018-01-26 16:55:36,316 DEBUG [Thread-16] TrackerServer: state update of object \x0001 processed in 319 ms 2018-01-26 16:55:42,310 DEBUG [Thread-22] TrackerServer: state update of object \x0001 processed in 406 ms 2018-01-26 16:55:51,281 DEBUG [Thread-18] TrackerServer: state update of object \x0001 processed in 3285 ms 2018-01-26 16:55:57,174 DEBUG [Thread-15] TrackerServer: state update of object \x0001 processed in 3178 ms 2018-01-26 16:56:04,499 DEBUG [Thread-18] TrackerServer: state update of object \x0001 processed in 2904 ms 2018-01-26 16:56:11,001 DEBUG [Thread-20] TrackerServer: state update of object \x0001 processed in 3121 ms 2018-01-26 16:56:14,210 DEBUG [Thread-19] TrackerServer: state update of object \x0001 processed in 383 ms 2018-01-26 16:56:21,021 DEBUG [Thread-21] TrackerServer: state update of object \x0001 processed in 665 ms 2018-01-26 16:56:29,931 DEBUG [Thread-22] TrackerServer: state update of object \x0001 processed in 2680 ms 2018-01-26 16:56:39,510 DEBUG [Thread-16] TrackerServer: state update of object \x0001 processed in 4219 ms 2018-01-26 16:56:42,919 DEBUG [Thread-22] TrackerServer: state update of object \x0001 processed in 547 ms 2018-01-26 16:56:48,220 DEBUG [Thread-16] TrackerServer: state update of object \x0001 processed in 2528 ms 2018-01-26 16:56:51,311 DEBUG [Thread-22] TrackerServer: state update of object \x0001 processed in 175 ms 2018-01-26 16:56:56,376 DEBUG [Thread-20] TrackerServer: state update of object \x0001 processed in 363 ms 2018-01-26 16:57:03,917 DEBUG [Thread-15] TrackerServer: state update of object \x0001 processed in 2661 ms 2018-01-26 16:57:04,144 DEBUG [Thread-21] TrackerServer: state update of object \x0001 processed in 108 ms 2018-01-26 16:57:09,258 DEBUG [Thread-16] TrackerServer: state update of object \x0001 processed in 2494 ms 2018-01-26 16:57:14,669 DEBUG [Thread-19] TrackerServer: state update of object \x0001 processed in 2657 ms 2018-01-26 16:57:20,570 DEBUG [Thread-16] TrackerServer: state update of object \x0001 processed in 2786 ms 2018-01-26 16:57:26,424 DEBUG [Thread-20] TrackerServer: state update of object \x0001 processed in 2843 ms 2018-01-26 16:57:31,905 DEBUG [Thread-20] TrackerServer: state update of object \x0001 processed in 2633 ms 2018-01-26 16:57:37,423 DEBUG [Thread-22] TrackerServer: state update of object \x0001 processed in 2451 ms 2018-01-26 16:57:37,555 DEBUG [Thread-22] TrackerServer: state update of object \x0001 processed in 71 ms 2018-01-26 16:57:40,134 DEBUG [Thread-22] TrackerServer: state update of object \x0001 processed in 2341 ms 2018-01-26 16:57:40,479 DEBUG [Thread-19] TrackerServer: state update of object \x0001 processed in 112 ms 2018-01-26 16:57:42,972 DEBUG [Thread-21] TrackerServer: state update of object \x0001 processed in 76 ms 2018-01-26 16:57:45,652 DEBUG [Thread-22] TrackerServer: state update of object \x0001 processed in 58 ms 2018-01-26 16:57:48,537 DEBUG [Thread-15] TrackerServer: state update of object \x0001 processed in 111 ms 2018-01-26 16:57:51,204 DEBUG [Thread-20] TrackerServer: state update of object \x0001 processed in 63 ms 2018-01-26 16:57:53,883 DEBUG [Thread-16] TrackerServer: state update of object \x0001 processed in 63 ms 2018-01-26 16:57:53,978 DEBUG [Thread-17] TrackerServer: state update of object \x0001 processed in 54 ms 2018-01-26 16:57:56,487 DEBUG [Thread-19] TrackerServer: state update of object \x0001 processed in 2475 ms 2018-01-26 16:57:56,582 DEBUG [Thread-19] TrackerServer: state update of object \x0001 processed in 50 ms 2018-01-26 16:57:56,691 DEBUG [Thread-21] TrackerServer: state update of object \x0001 processed in 52 ms 2018-01-26 16:57:56,751 DEBUG [Thread-18] TrackerServer: state update of object \x0001 processed in 35 ms 2018-01-26 16:57:59,218 DEBUG [Thread-18] TrackerServer: state update of object \x0001 processed in 1 ms 2018-01-26 16:57:59,277 DEBUG [Thread-20] TrackerServer: state update of object \x0001 processed in 44 ms 2018-01-26 16:57:59,324 DEBUG [Thread-22] TrackerServer: state update of object \x0001 processed in 26 ms 2018-01-26 16:57:59,416 DEBUG [Thread-15] TrackerServer: state update of object \x0001 processed in 55 ms 2018-01-26 16:58:02,075 DEBUG [Thread-15] TrackerServer: state update of object \x0001 processed in 86 ms 2018-01-26 16:58:07,249 DEBUG [Thread-17] TrackerServer: state update of object \x0001 processed in 2363 ms 2018-01-26 16:58:13,213 DEBUG [Thread-18] TrackerServer: state update of object \x0001 processed in 334 ms 2018-01-26 16:58:23,930 DEBUG [Thread-20] TrackerServer: state update of object \x0001 processed in 2565 ms 2018-01-26 16:58:32,172 ERROR [Thread-88] AbstractServer: 127.0.0.1:39172 response handler timeout [ERROR] Tests run: 1, Failures: 1, Errors: 0, Skipped: 0, Time elapsed: 353.665 s <<< FAILURE! - in com.bmwcarit.barefoot.tracker.TrackerServerTest [ERROR] testTrackerServer(com.bmwcarit.barefoot.tracker.TrackerServerTest) Time elapsed: 353.652 s <<< FAILURE! org.junit.ComparisonFailure: expected:<[SUCCESS]> but was:<[TIMEOUT]> at com.bmwcarit.barefoot.tracker.TrackerServerTest.sendSample(TrackerServerTest.java:90) at com.bmwcarit.barefoot.tracker.TrackerServerTest.testTrackerServer(TrackerServerTest.java:152) [INFO] Running com.bmwcarit.barefoot.tracker.TemporaryMemoryTest 2018-01-26 16:59:23,933 DEBUG [Thread-14] TrackerServer: delete object \x0001 ...