Posted by
dgmiller on
URL: http://official-rtab-map-forum.206.s1.nabble.com/rtabmap-process-error-tp1031p1050.html
Hi Mathieu,
I've pulled the latest updates from github and recompiled rtabmap. I have then ran again, and the mapping was crashing when a function that had to do with laser scan matching was crashing. however, i disabled laser scan matching and ran again, and this time I got the mapping to be active for a few longer seconds and with robot movement. the output from the following crash is below.
however I would like to say that I am using 3 machines and their clocks may not be perfectly synchronized. would this be a possible cause of error?
best,
daniel
[DEBUG] (2016-02-05 16:22:57.192) Rtabmap.cpp:1445::process() nt=34 m=1 immunized=1
[DEBUG] (2016-02-05 16:22:57.192) Rtabmap.cpp:1445::process() nt=40 m=1 immunized=1
[DEBUG] (2016-02-05 16:22:57.192) Rtabmap.cpp:1445::process() nt=33 m=2 immunized=1
[DEBUG] (2016-02-05 16:22:57.192) Rtabmap.cpp:1445::process() nt=41 m=2 immunized=1
[DEBUG] (2016-02-05 16:22:57.192) Rtabmap.cpp:1445::process() nt=31 m=3 immunized=1
[DEBUG] (2016-02-05 16:22:57.192) Rtabmap.cpp:1445::process() nt=42 m=3 immunized=1
[DEBUG] (2016-02-05 16:22:57.193) Rtabmap.cpp:1445::process() nt=30 m=4 immunized=1
[DEBUG] (2016-02-05 16:22:57.193) Rtabmap.cpp:1445::process() nt=29 m=5 immunized=1
[DEBUG] (2016-02-05 16:22:57.193) Rtabmap.cpp:1445::process() nt=27 m=6 immunized=1
[DEBUG] (2016-02-05 16:22:57.193) Rtabmap.cpp:1445::process() nt=26 m=7 immunized=1
[DEBUG] (2016-02-05 16:22:57.193) Rtabmap.cpp:1445::process() nt=25 m=8 immunized=1
[DEBUG] (2016-02-05 16:22:57.193) Rtabmap.cpp:1445::process() nt=24 m=9 immunized=1
[DEBUG] (2016-02-05 16:22:57.193) Rtabmap.cpp:1445::process() nt=23 m=10 immunized=1
[DEBUG] (2016-02-05 16:22:57.193) Rtabmap.cpp:1445::process() nt=22 m=11 immunized=1
[DEBUG] (2016-02-05 16:22:57.193) Rtabmap.cpp:1445::process() nt=21 m=12 immunized=1
[DEBUG] (2016-02-05 16:22:57.193) Rtabmap.cpp:1445::process() nt=20 m=13 immunized=1
[DEBUG] (2016-02-05 16:22:57.193) Rtabmap.cpp:1445::process() nt=1 m=14 immunized=1
[DEBUG] (2016-02-05 16:22:57.193) Rtabmap.cpp:1460::process() In SPACE
[DEBUG] (2016-02-05 16:22:57.193) Rtabmap.cpp:1468::process() neighbors of 36 in space = 28
[ INFO] (2016-02-05 16:22:57.193) Rtabmap.cpp:1515::process() neighborhoodSize=17, reactivatedIds.size=18, nbLoadedFromDb=0, nbDirectNeighborsInDb=0, time=0.001120s (0.000000s 0.000000s)
[DEBUG] (2016-02-05 16:22:57.193) Graph.cpp:2780::findNearestNode() Nearest node = 27: 5.437055
[DEBUG] (2016-02-05 16:22:57.194) Rtabmap.cpp:1632::process() local node 27 on path immunized=1
[DEBUG] (2016-02-05 16:22:57.194) Rtabmap.cpp:1632::process() local node 29 on path immunized=1
[DEBUG] (2016-02-05 16:22:57.194) Rtabmap.cpp:1632::process() local node 30 on path immunized=1
[DEBUG] (2016-02-05 16:22:57.194) Rtabmap.cpp:1632::process() local node 31 on path immunized=1
[DEBUG] (2016-02-05 16:22:57.194) Rtabmap.cpp:1632::process() local node 33 on path immunized=1
[DEBUG] (2016-02-05 16:22:57.194) Rtabmap.cpp:1632::process() local node 34 on path immunized=1
[DEBUG] (2016-02-05 16:22:57.194) Rtabmap.cpp:1632::process() local node 36 on path immunized=1
[DEBUG] (2016-02-05 16:22:57.194) Rtabmap.cpp:1632::process() local node 40 on path immunized=1
[DEBUG] (2016-02-05 16:22:57.194) Rtabmap.cpp:1632::process() local node 41 on path immunized=1
[DEBUG] (2016-02-05 16:22:57.194) Rtabmap.cpp:1632::process() local node 42 on path immunized=1
[DEBUG] (2016-02-05 16:22:57.194) Graph.cpp:2832::getNodesInRadius() Inlier 47: 0.045553
[DEBUG] (2016-02-05 16:22:57.194) Graph.cpp:2832::getNodesInRadius() Inlier 56: 0.097870
[DEBUG] (2016-02-05 16:22:57.194) Graph.cpp:2832::getNodesInRadius() Inlier 48: 0.268702
[DEBUG] (2016-02-05 16:22:57.194) Graph.cpp:2832::getNodesInRadius() Inlier 46: 0.293229
[DEBUG] (2016-02-05 16:22:57.194) Graph.cpp:2832::getNodesInRadius() Inlier 55: 0.372869
[DEBUG] (2016-02-05 16:22:57.194) Graph.cpp:2832::getNodesInRadius() Inlier 49: 0.495991
[DEBUG] (2016-02-05 16:22:57.194) Graph.cpp:2832::getNodesInRadius() Inlier 45: 1.060669
[DEBUG] (2016-02-05 16:22:57.194) Graph.cpp:2832::getNodesInRadius() Inlier 44: 1.784922
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 27: 2.331749
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 29: 2.439999
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 43: 2.527321
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 30: 2.554784
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 26: 2.601842
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 31: 2.641206
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 33: 2.759153
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 42: 2.780928
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 36: 2.810022
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 34: 2.850865
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 25: 2.859104
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 40: 2.879664
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 41: 2.952356
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 24: 3.176341
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 23: 3.518435
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 22: 3.677536
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 21: 3.854294
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 20: 3.958724
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2832::getNodesInRadius() Inlier 1: 4.058193
[DEBUG] (2016-02-05 16:22:57.195) Graph.cpp:2837::getNodesInRadius() found nodes=27
[ INFO] (2016-02-05 16:22:57.195) Rtabmap.cpp:1652::process() near nodes=27, max local immunized=4, ratio=0.250000 WM=19
[DEBUG] (2016-02-05 16:22:57.195) Rtabmap.cpp:1678::process() local node 27 (5.437055 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.195) Rtabmap.cpp:1678::process() local node 29 (5.953593 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 30 (6.526919 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 26 (6.769581 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 31 (6.975970 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 33 (7.612926 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 42 (7.733559 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 36 (7.896225 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 34 (8.127434 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 25 (8.174479 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 40 (8.292466 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 41 (8.716405 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 24 (10.089140 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 23 (12.379388 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 22 (13.524271 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 21 (14.855586 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 20 (15.671494 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Rtabmap.cpp:1678::process() local node 1 (16.468933 m) immunized=1
[DEBUG] (2016-02-05 16:22:57.196) Memory.cpp:4547::reactivateSignatures()
[DEBUG] (2016-02-05 16:22:57.196) Memory.cpp:4563::reactivateSignatures() idsToLoad = 0
[DEBUG] (2016-02-05 16:22:57.196) DBDriver.cpp:409::loadSignatures()
[DEBUG] (2016-02-05 16:22:57.196) DBDriver.cpp:449::loadSignatures()
[DEBUG] (2016-02-05 16:22:57.196) Memory.cpp:4439::enableWordsRef() size=0
[DEBUG] (2016-02-05 16:22:57.196) Memory.cpp:4466::enableWordsRef() oldWordIds.size()=0, getOldIds time=0.000000s
[DEBUG] (2016-02-05 16:22:57.196) Memory.cpp:4475::enableWordsRef() loading words(0) time=0.000038s
[DEBUG] (2016-02-05 16:22:57.196) Memory.cpp:4538::enableWordsRef() 0 words total ref added from 0 signatures, time=0.000041s...
[DEBUG] (2016-02-05 16:22:57.197) Memory.cpp:4579::reactivateSignatures() time = 0.000274s
[ INFO] (2016-02-05 16:22:57.197) Rtabmap.cpp:1727::process() retrieval of 0 (db time = 0.000110s)
[ INFO] (2016-02-05 16:22:57.197) Rtabmap.cpp:1730::process() total timeRetrievalDbAccess=0.000110s
[ INFO] (2016-02-05 16:22:57.197) Rtabmap.cpp:1736::process() timeReactivations=0.004597s
[ INFO] (2016-02-05 16:22:57.197) Rtabmap.cpp:1840::process() timeAddLoopClosureLink=0.000038s
[DEBUG] (2016-02-05 16:22:57.197) Rtabmap.cpp:1871::process() Proximity detection (local loop closure in SPACE using matching images)
[DEBUG] (2016-02-05 16:22:57.197) Rtabmap.cpp:1881::process() nearestIds=28/28
[DEBUG] (2016-02-05 16:22:57.197) Rtabmap.cpp:1890::process() nearestPoses=18
[DEBUG] (2016-02-05 16:22:57.197) Rtabmap.cpp:1894::process() nearestPaths=1
[DEBUG] (2016-02-05 16:22:57.197) Graph.cpp:2780::findNearestNode() Nearest node = 27: 5.437055
[DEBUG] (2016-02-05 16:22:57.197) Rtabmap.cpp:2007::process() Proximity detection (local loop closure in SPACE with scan matching)
[DEBUG] (2016-02-05 16:22:57.197) Graph.cpp:2780::findNearestNode() Nearest node = 27: 5.437055
[DEBUG] (2016-02-05 16:22:57.197) Rtabmap.cpp:2027::process() Path 27 distance=2.331749m
[DEBUG] (2016-02-05 16:22:57.197) Rtabmap.cpp:2123::process() Path 27 ignored
[ INFO] (2016-02-05 16:22:57.197) Rtabmap.cpp:2131::process() timeLocalSpaceDetection=0.000791s
[ INFO] (2016-02-05 16:22:57.198) Rtabmap.cpp:2302::process() timeMapOptimization=0.000053s
[ INFO] (2016-02-05 16:22:57.198) Rtabmap.cpp:2329::process() sending stats...
[ INFO] (2016-02-05 16:22:57.198) Rtabmap.cpp:2338::process() send all stats...
[ INFO] (2016-02-05 16:22:57.198) Rtabmap.cpp:2367::process() Set map correction = xyz=0.000000,0.000000,0.000000 rpy=0.000000,-0.000000,0.000000
[ INFO] (2016-02-05 16:22:57.198) Rtabmap.cpp:2421::process() Time creating stats = 0.000427...
[DEBUG] (2016-02-05 16:22:57.198) Memory.cpp:1654::cleanup()
[ INFO] (2016-02-05 16:22:57.198) Rtabmap.cpp:2457::process() Ignoring location 57 because the displacement is too small! (d=0.100000 a=0.100000)
[DEBUG] (2016-02-05 16:22:57.198) Memory.cpp:2069::deleteLocation() Deleting location 57
[DEBUG] (2016-02-05 16:22:57.198) Memory.cpp:1853::moveToTrash() id=57
[DEBUG] (2016-02-05 16:22:57.199) Signature.cpp:138::removeLink() Removed link 57 from 56
[DEBUG] (2016-02-05 16:22:57.199) Memory.cpp:4391::disableWordsRef() id=57
[DEBUG] (2016-02-05 16:22:57.200) Memory.cpp:4407::disableWordsRef() 400 words total ref removed from signature 57... (total active ref = 10800)
[DEBUG] (2016-02-05 16:22:57.200) DBDriver.cpp:293::asyncSave() s=57
[ INFO] (2016-02-05 16:22:57.200) Rtabmap.cpp:2468::process() timeMemoryCleanup = 0.002412s... 1 signatures removed
[ INFO] (2016-02-05 16:22:57.200) Rtabmap.cpp:2481::process() Total time processing = 0.290038s...
[DEBUG] (2016-02-05 16:22:57.200) Memory.cpp:1969::getLastWorkingSignature()
[DEBUG] (2016-02-05 16:22:57.200) Memory.cpp:1969::getLastWorkingSignature()
[DEBUG] (2016-02-05 16:22:57.201) Rtabmap.cpp:2523::process() Refresh local map from 56
[DEBUG] (2016-02-05 16:22:57.201) Rtabmap.cpp:2537::process() Removed 57 from local map
[ INFO] (2016-02-05 16:22:57.201) Rtabmap.cpp:2575::process() Time limit reached processing = 0.000362...
[DEBUG] (2016-02-05 16:22:57.204) DBDriver.cpp:222::emptyTrashes() Async emptying, start the trash thread
[DEBUG] (2016-02-05 16:22:57.204) Rtabmap.cpp:2718::process() End process
[DEBUG] (2016-02-05 16:22:57.204) CoreWrapper.cpp:2040::publishStats() Publishing stats...
[DEBUG] (2016-02-05 16:22:57.204) MapsManager.cpp:169::updateMapCaches() Updating map caches...
[ INFO] (2016-02-05 16:22:57.204) Graph.cpp:2024::radiusPosesFiltering() Cloud filtered In = 28, Out = 9
[ INFO] [1454707377.206842907]: Odom: quality=203, std dev=0.070186m, update time=0.289239s
[DEBUG] (2016-02-05 16:22:57.213) DBDriver.cpp:234::emptyTrashes() signatures=1, visualWords=0
[DEBUG] (2016-02-05 16:22:57.214) DBDriver.cpp:200::beginTransaction()
[DEBUG] (2016-02-05 16:22:57.214) DBDriverSqlite3.cpp:433::executeNoResultQuery() Time=0.000036s
[DEBUG] (2016-02-05 16:22:57.215) DBDriver.cpp:316::saveOrUpdate()
[DEBUG] (2016-02-05 16:22:57.215) DBDriverSqlite3.cpp:2254::saveQuery()
[DEBUG] (2016-02-05 16:22:57.216) DBDriverSqlite3.cpp:2526::stepNode() Save node 57
[DEBUG] (2016-02-05 16:22:57.216) DBDriverSqlite3.cpp:2276::saveQuery() Time=0.000756s
[DEBUG] (2016-02-05 16:22:57.217) DBDriverSqlite3.cpp:2295::saveQuery() Time=0.000507s
[DEBUG] (2016-02-05 16:22:57.227) DBDriverSqlite3.cpp:2326::saveQuery() Time=0.010031s
[DEBUG] (2016-02-05 16:22:57.227) DBDriverSqlite3.cpp:2334::saveQuery() Saving 1 images
[DEBUG] (2016-02-05 16:22:57.228) DBDriverSqlite3.cpp:2760::stepSensorData() Save sensor data 57 (image=193269 depth=671217) depth2d = 703
[DEBUG] (2016-02-05 16:22:57.230) DBDriverSqlite3.cpp:2351::saveQuery() Time=0.003126s
[DEBUG] (2016-02-05 16:22:57.230) DBDriverSqlite3.cpp:2392::saveQuery() Time=0.000376s
[DEBUG] (2016-02-05 16:22:57.231) DBDriver.cpp:262::emptyTrashes() Time emptying memory signatures trash = 0.015811...
[DEBUG] (2016-02-05 16:22:57.231) DBDriver.cpp:206::commit()
[DEBUG] (2016-02-05 16:22:57.240) DBDriverSqlite3.cpp:433::executeNoResultQuery() Time=0.009079s
[DEBUG] (2016-02-05 16:22:57.241) DBDriver.cpp:284::emptyTrashes() Total time emptying trashes = 0.027147s...
[DEBUG] (2016-02-05 16:22:57.311) MapsManager.cpp:453::publishMaps() Publishing maps...
[DEBUG] (2016-02-05 16:22:57.311) util3d_mapping.cpp:135::create2DMapFromOccupancyLocalMaps() cellSize=0.050000 m, minMapSize=0.000000 m, erode=0
[DEBUG] (2016-02-05 16:22:57.311) util3d_mapping.cpp:239::create2DMapFromOccupancyLocalMaps() timer=0.000412s
[DEBUG] (2016-02-05 16:22:57.311) util3d_mapping.cpp:259::create2DMapFromOccupancyLocalMaps() map min=(-0.059772, -6.022515) max=(10.173406,5.584777)
[DEBUG] (2016-02-05 16:22:57.312) util3d_mapping.cpp:377::create2DMapFromOccupancyLocalMaps() timer=0.001008s
[ INFO] [1454707377.312881562]: rtabmap: Rate=1.00s, Limit=0.000s, RTAB-Map=0.2943s, Pub=0.1083s (local map=27, WM=27)
[ INFO] [1454707377.507231683]: Odom: quality=266, std dev=0.061314m, update time=0.283608s
[ INFO] [1454707377.759420923]: Odom: quality=284, std dev=0.059339m, update time=0.237182s
[ INFO] [1454707377.990609068]: Odom: quality=220, std dev=0.067420m, update time=0.198672s
[DEBUG] (2016-02-05 16:22:58.001) Rtabmap.cpp:833::process()
[ INFO] (2016-02-05 16:22:58.002) Rtabmap.cpp:887::process() getting data...
[DEBUG] (2016-02-05 16:22:58.003) Memory.cpp:1969::getLastWorkingSignature()
[DEBUG] (2016-02-05 16:22:58.003) Memory.cpp:1969::getLastWorkingSignature()
[ INFO] (2016-02-05 16:22:58.003) Rtabmap.cpp:943::process() Updating memory...
[DEBUG] (2016-02-05 16:22:58.003) Memory.cpp:577::update()
[DEBUG] (2016-02-05 16:22:58.003) Memory.cpp:586::update() pre-updating...
[DEBUG] (2016-02-05 16:22:58.003) Memory.cpp:4416::cleanUnusedWords() Removing 0 words (dictionary size=6196)...
[DEBUG] (2016-02-05 16:22:58.003) Memory.cpp:590::update() time preUpdate=0.088930 ms
[DEBUG] (2016-02-05 16:22:58.003) Memory.cpp:3775::createSignature()
[DEBUG] (2016-02-05 16:22:58.003) Memory.cpp:3847::createSignature() Start dictionary update thread
[DEBUG] (2016-02-05 16:22:58.003) Memory.cpp:3861::createSignature() convert to grayscale...
[DEBUG] (2016-02-05 16:22:58.005) VWDictionary.cpp:530::update()
[DEBUG] (2016-02-05 16:22:58.005) VWDictionary.cpp:682::update() Dictionary has not changed, so no need to update it! (size=6196)
[DEBUG] (2016-02-05 16:22:58.005) VWDictionary.cpp:686::update()
[DEBUG] (2016-02-05 16:22:58.007) Memory.cpp:3868::createSignature() Set ROI...
[DEBUG] (2016-02-05 16:22:58.007) Features2d.cpp:291::computeRoi() roi ratios = 0.000000, 0.000000, 0.000000, 0.000000
[DEBUG] (2016-02-05 16:22:58.007) Features2d.cpp:292::computeRoi() roi = 0, 0, 1280, 720
[DEBUG] (2016-02-05 16:22:58.007) Features2d.cpp:319::computeRoi() roi = 0, 0, 1280, 720
[DEBUG] (2016-02-05 16:22:58.007) Memory.cpp:3967::createSignature() Generating keypoints...
[DEBUG] (2016-02-05 16:22:58.020) Features2d.cpp:418::generateKeypoints() Keypoints extraction time = 0.012243 s, keypoints extracted = 400
[DEBUG] (2016-02-05 16:22:58.020) Memory.cpp:3971::createSignature() time keypoints (400) = 0.016570s
[DEBUG] (2016-02-05 16:22:58.059) Features2d.cpp:449::generateDescriptors() Descriptors extracted = 400, remaining kpts=400
[DEBUG] (2016-02-05 16:22:58.059) Memory.cpp:4013::createSignature() time descriptors (400) = 0.039032s
[DEBUG] (2016-02-05 16:22:58.059) Memory.cpp:4022::createSignature() time keypoints 3D (400) = 0.000310s
[DEBUG] (2016-02-05 16:22:58.059) Memory.cpp:4063::createSignature() ratio=0.500000, meanWordsPerLocation=385
[DEBUG] (2016-02-05 16:22:58.059) Memory.cpp:4149::createSignature() Joining dictionary update thread...
[DEBUG] (2016-02-05 16:22:58.059) Memory.cpp:4151::createSignature() Joining dictionary update thread... thread finished!
[DEBUG] (2016-02-05 16:22:58.059) Memory.cpp:4161::createSignature() time descriptor and memory update (400 of size=32) = 0.000320s
[DEBUG] (2016-02-05 16:22:58.059) VWDictionary.cpp:760::addNewWords() id=58 descriptors=400
[DEBUG] (2016-02-05 16:22:58.060) VWDictionary.cpp:816::addNewWords() newPts.total()=400
[ INFO] [1454707378.193526472]: Odom: quality=347, std dev=0.053683m, update time=0.188384s
[DEBUG] (2016-02-05 16:22:58.217) VWDictionary.cpp:875::addNewWords() Time to find nn = 0.157604 s
[DEBUG] (2016-02-05 16:22:58.226) VWDictionary.cpp:994::addNewWords() naive search and add ref/words time = 0.008575 s
[DEBUG] (2016-02-05 16:22:58.226) VWDictionary.cpp:996::addNewWords() 259 new words added...
[DEBUG] (2016-02-05 16:22:58.226) VWDictionary.cpp:998::addNewWords() 141 duplicated words added (from current image = 29)...
[DEBUG] (2016-02-05 16:22:58.226) VWDictionary.cpp:999::addNewWords() total time 0.166387s
[DEBUG] (2016-02-05 16:22:58.226) Memory.cpp:4171::createSignature() time addNewWords 0.166733s
[DEBUG] (2016-02-05 16:22:58.227) Memory.cpp:4280::createSignature() Bin data kept: rgb=1, depth=1, scan=1, userData=0
[DEBUG] (2016-02-05 16:22:58.294) Memory.cpp:4381::createSignature() time compressing data (id=58) 0.067764s
[DEBUG] (2016-02-05 16:22:58.294) Memory.cpp:604::update() time creating signature=291.250946 ms
[DEBUG] (2016-02-05 16:22:58.295) Memory.cpp:722::addSignatureToStm() adding 58
[DEBUG] (2016-02-05 16:22:58.295) Signature.cpp:99::addLink() Add link 58 to 56 (type=0)
[DEBUG] (2016-02-05 16:22:58.295) Signature.cpp:99::addLink() Add link 56 to 58 (type=0)
[DEBUG] (2016-02-05 16:22:58.295) Memory.cpp:742::addSignatureToStm() Min STM id = 43
[DEBUG] (2016-02-05 16:22:58.295) Memory.cpp:776::addSignatureToStm() 400 words ref for the signature 58
[DEBUG] (2016-02-05 16:22:58.295) Memory.cpp:784::addSignatureToStm() time = 0.000231s
[DEBUG] (2016-02-05 16:22:58.295) Memory.cpp:3330::rehearsal() Comparing with signature (56)...
[DEBUG] (2016-02-05 16:22:58.295) Memory.cpp:3353::rehearsal() merged=0, sim=0.027500 t=0.000313s
[DEBUG] (2016-02-05 16:22:58.295) Memory.cpp:625::update() time rehearsal=0.885010 ms
[DEBUG] (2016-02-05 16:22:58.295) Memory.cpp:678::update() totalTimer = 0.292280s
[DEBUG] (2016-02-05 16:22:58.295) Memory.cpp:1969::getLastWorkingSignature()
[ INFO] (2016-02-05 16:22:58.295) Rtabmap.cpp:965::process() Processing signature 58 w=0
[ INFO] (2016-02-05 16:22:58.295) Rtabmap.cpp:967::process() timeMemoryUpdate=0.292854s
[ INFO] (2016-02-05 16:22:58.295) Rtabmap.cpp:1232::process() timeLocalTimeDetection=0.000094s
[ INFO] (2016-02-05 16:22:58.296) Rtabmap.cpp:1251::process() computing likelihood...
[DEBUG] (2016-02-05 16:22:58.296) Memory.cpp:1517::computeLikelihood() processing...
[DEBUG] (2016-02-05 16:22:58.296) Memory.cpp:1552::computeLikelihood() compute likelihood (tf-idf) 0.000608 s
[DEBUG] (2016-02-05 16:22:58.296) Rtabmap.cpp:3074::adjustLikelihood() likelihood.size()=19
[DEBUG] (2016-02-05 16:22:58.296) Rtabmap.cpp:3093::adjustLikelihood() values.size=17
[DEBUG] (2016-02-05 16:22:58.296) Rtabmap.cpp:3140::adjustLikelihood() mean=0.028060, stdDev=0.039780, max=0.124545, maxId=40, time=0.000035s
[ INFO] (2016-02-05 16:22:58.296) Rtabmap.cpp:1281::process() timeLikelihoodCalculation=0.001006s
[ INFO] (2016-02-05 16:22:58.297) Rtabmap.cpp:1287::process() getting posterior...
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:132::computePosterior()
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:411::updatePrediction()
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:439::updatePrediction() time creating id-index maps = 0.000051s
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:451::updatePrediction() time getting removed ids = 0.000036s
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:498::updatePrediction() time getting 0 ids to update = 0.000028s
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:544::updatePrediction() time updating modified/added 0 ids = 0.000026s
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:575::updatePrediction() time copying = 0.000036s
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:595::updatePrediction() time updating virtual place = 0.000027s
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:597::updatePrediction() Modified=0, Added=0, Copied=18
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:164::computePosterior() STEP1-generate prior=0.000274s, rows=19, cols=19
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:603::updatePosterior()
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:176::computePosterior() STEP1-update posterior=0.000274s, posterior=19, _posterior size=19
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:182::computePosterior() STEP1-matrix mult time=0.000146s
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:185::computePosterior() STEP1-matrix mult time=0.000027s
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:204::computePosterior() STEP2-likelihood time=0.000028s
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:208::computePosterior() sum=1.624898
[DEBUG] (2016-02-05 16:22:58.297) BayesFilter.cpp:216::computePosterior() normalize time=0.000050s
[ INFO] (2016-02-05 16:22:58.297) Rtabmap.cpp:1292::process() timePosteriorCalculation=0.000648s
[ INFO] (2016-02-05 16:22:58.297) Rtabmap.cpp:1303::process() creating hypotheses...
[ INFO] (2016-02-05 16:22:58.297) Rtabmap.cpp:1317::process() Highest hypothesis=40, value=0.118921, timeHypothesesCreation=0.000096s
[ INFO] (2016-02-05 16:22:58.297) Rtabmap.cpp:1352::process() timeHypothesesValidation=0.000029s
[DEBUG] (2016-02-05 16:22:58.297) Memory.cpp:1683::joinTrashThread()
[DEBUG] (2016-02-05 16:22:58.297) Memory.cpp:1685::joinTrashThread()
[ INFO] (2016-02-05 16:22:58.297) Rtabmap.cpp:1379::process() Time emptying memory trash = 0.027147s, joining (actual overhead) = 0.000080s
[ INFO] (2016-02-05 16:22:58.297) Rtabmap.cpp:1393::process() Retrieving locations... around id=40
[DEBUG] (2016-02-05 16:22:58.297) Rtabmap.cpp:1396::process() margin=17 maxRetieved=2
[DEBUG] (2016-02-05 16:22:58.297) Rtabmap.cpp:1406::process() In TIME
[DEBUG] (2016-02-05 16:22:58.298) Rtabmap.cpp:1414::process() neighbors of 40 in time = 28
[DEBUG] (2016-02-05 16:22:58.298) Rtabmap.cpp:1445::process() nt=40 m=0 immunized=1
[DEBUG] (2016-02-05 16:22:58.298) Rtabmap.cpp:1445::process() nt=36 m=1 immunized=1
[DEBUG] (2016-02-05 16:22:58.298) Rtabmap.cpp:1445::process() nt=41 m=1 immunized=1
[DEBUG] (2016-02-05 16:22:58.298) Rtabmap.cpp:1445::process() nt=34 m=2 immunized=1
[DEBUG] (2016-02-05 16:22:58.298) Rtabmap.cpp:1445::process() nt=42 m=2 immunized=1
[DEBUG] (2016-02-05 16:22:58.298) Rtabmap.cpp:1445::process() nt=33 m=3 immunized=1
[DEBUG] (2016-02-05 16:22:58.298) Rtabmap.cpp:1445::process() nt=31 m=4 immunized=1
[DEBUG] (2016-02-05 16:22:58.298) Rtabmap.cpp:1445::process() nt=30 m=5 immunized=1
[DEBUG] (2016-02-05 16:22:58.298) Rtabmap.cpp:1445::process() nt=29 m=6 immunized=1
[DEBUG] (2016-02-05 16:22:58.298) Rtabmap.cpp:1445::process() nt=27 m=7 immunized=1
[DEBUG] (2016-02-05 16:22:58.299) Rtabmap.cpp:1445::process() nt=26 m=8 immunized=1
[DEBUG] (2016-02-05 16:22:58.299) Rtabmap.cpp:1445::process() nt=25 m=9 immunized=1
[DEBUG] (2016-02-05 16:22:58.299) Rtabmap.cpp:1445::process() nt=24 m=10 immunized=1
[DEBUG] (2016-02-05 16:22:58.300) Rtabmap.cpp:1445::process() nt=23 m=11 immunized=1
[DEBUG] (2016-02-05 16:22:58.300) Rtabmap.cpp:1445::process() nt=22 m=12 immunized=1
[DEBUG] (2016-02-05 16:22:58.300) Rtabmap.cpp:1445::process() nt=21 m=13 immunized=1
[DEBUG] (2016-02-05 16:22:58.301) Rtabmap.cpp:1445::process() nt=20 m=14 immunized=1
[DEBUG] (2016-02-05 16:22:58.301) Rtabmap.cpp:1445::process() nt=1 m=15 immunized=1
[DEBUG] (2016-02-05 16:22:58.302) Rtabmap.cpp:1460::process() In SPACE
[DEBUG] (2016-02-05 16:22:58.302) Rtabmap.cpp:1468::process() neighbors of 40 in space = 28
[ INFO] (2016-02-05 16:22:58.302) Rtabmap.cpp:1515::process() neighborhoodSize=17, reactivatedIds.size=18, nbLoadedFromDb=0, nbDirectNeighborsInDb=0, time=0.004778s (0.000000s 0.000000s)
[DEBUG] (2016-02-05 16:22:58.303) Graph.cpp:2780::findNearestNode() Nearest node = 27: 4.615780
[DEBUG] (2016-02-05 16:22:58.303) Rtabmap.cpp:1632::process() local node 27 on path immunized=1
[DEBUG] (2016-02-05 16:22:58.303) Rtabmap.cpp:1632::process() local node 29 on path immunized=1
[DEBUG] (2016-02-05 16:22:58.303) Rtabmap.cpp:1632::process() local node 30 on path immunized=1
[DEBUG] (2016-02-05 16:22:58.303) Rtabmap.cpp:1632::process() local node 31 on path immunized=1
[DEBUG] (2016-02-05 16:22:58.303) Rtabmap.cpp:1632::process() local node 33 on path immunized=1
[DEBUG] (2016-02-05 16:22:58.303) Rtabmap.cpp:1632::process() local node 34 on path immunized=1
[DEBUG] (2016-02-05 16:22:58.303) Rtabmap.cpp:1632::process() local node 36 on path immunized=1
[DEBUG] (2016-02-05 16:22:58.303) Rtabmap.cpp:1632::process() local node 40 on path immunized=1
[DEBUG] (2016-02-05 16:22:58.303) Rtabmap.cpp:1632::process() local node 41 on path immunized=1
[DEBUG] (2016-02-05 16:22:58.303) Rtabmap.cpp:1632::process() local node 42 on path immunized=1
[DEBUG] (2016-02-05 16:22:58.303) Graph.cpp:2832::getNodesInRadius() Inlier 46: 0.399292
[DEBUG] (2016-02-05 16:22:58.303) Graph.cpp:2832::getNodesInRadius() Inlier 47: 0.559962
[DEBUG] (2016-02-05 16:22:58.303) Graph.cpp:2832::getNodesInRadius() Inlier 56: 0.668242
[DEBUG] (2016-02-05 16:22:58.303) Graph.cpp:2832::getNodesInRadius() Inlier 45: 0.798520
[DEBUG] (2016-02-05 16:22:58.303) Graph.cpp:2832::getNodesInRadius() Inlier 48: 0.839496
[DEBUG] (2016-02-05 16:22:58.303) Graph.cpp:2832::getNodesInRadius() Inlier 55: 0.942765
[DEBUG] (2016-02-05 16:22:58.303) Graph.cpp:2832::getNodesInRadius() Inlier 49: 1.064885
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 44: 1.474444
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 27: 2.148437
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 43: 2.185949
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 29: 2.244993
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 30: 2.321928
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 31: 2.369849
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 26: 2.394682
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 42: 2.433072
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 33: 2.450686
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 36: 2.495930
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 34: 2.509407
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 40: 2.540558
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 41: 2.596975
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 25: 2.633628
[DEBUG] (2016-02-05 16:22:58.304) Graph.cpp:2832::getNodesInRadius() Inlier 24: 2.923449
[DEBUG] (2016-02-05 16:22:58.305) Graph.cpp:2832::getNodesInRadius() Inlier 23: 3.243119
[DEBUG] (2016-02-05 16:22:58.305) Graph.cpp:2832::getNodesInRadius() Inlier 22: 3.378526
[DEBUG] (2016-02-05 16:22:58.305) Graph.cpp:2832::getNodesInRadius() Inlier 21: 3.542946
[DEBUG] (2016-02-05 16:22:58.305) Graph.cpp:2832::getNodesInRadius() Inlier 20: 3.634623
[DEBUG] (2016-02-05 16:22:58.305) Graph.cpp:2832::getNodesInRadius() Inlier 1: 3.728130
[DEBUG] (2016-02-05 16:22:58.305) Graph.cpp:2837::getNodesInRadius() found nodes=27
[ INFO] (2016-02-05 16:22:58.305) Rtabmap.cpp:1652::process() near nodes=27, max local immunized=4, ratio=0.250000 WM=19
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 27 (4.615780 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 29 (5.039992 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 30 (5.391348 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 31 (5.616186 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 26 (5.734500 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 42 (5.919838 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 33 (6.005863 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 36 (6.229667 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 34 (6.297126 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 40 (6.454437 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 41 (6.744281 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 25 (6.935998 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 24 (8.546553 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.305) Rtabmap.cpp:1678::process() local node 23 (10.517818 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.306) Rtabmap.cpp:1678::process() local node 22 (11.414437 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.306) Rtabmap.cpp:1678::process() local node 21 (12.552465 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.306) Rtabmap.cpp:1678::process() local node 20 (13.210485 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.306) Rtabmap.cpp:1678::process() local node 1 (13.898954 m) immunized=1
[DEBUG] (2016-02-05 16:22:58.306) Memory.cpp:4547::reactivateSignatures()
[DEBUG] (2016-02-05 16:22:58.306) Memory.cpp:4563::reactivateSignatures() idsToLoad = 0
[DEBUG] (2016-02-05 16:22:58.306) DBDriver.cpp:409::loadSignatures()
[DEBUG] (2016-02-05 16:22:58.306) DBDriver.cpp:449::loadSignatures()
[DEBUG] (2016-02-05 16:22:58.306) Memory.cpp:4439::enableWordsRef() size=0
[DEBUG] (2016-02-05 16:22:58.306) Memory.cpp:4466::enableWordsRef() oldWordIds.size()=0, getOldIds time=0.000001s
[DEBUG] (2016-02-05 16:22:58.306) Memory.cpp:4475::enableWordsRef() loading words(0) time=0.000045s
[DEBUG] (2016-02-05 16:22:58.306) Memory.cpp:4538::enableWordsRef() 0 words total ref added from 0 signatures, time=0.000044s...
[DEBUG] (2016-02-05 16:22:58.306) Memory.cpp:4579::reactivateSignatures() time = 0.000291s
[ INFO] (2016-02-05 16:22:58.306) Rtabmap.cpp:1727::process() retrieval of 0 (db time = 0.000114s)
[ INFO] (2016-02-05 16:22:58.306) Rtabmap.cpp:1730::process() total timeRetrievalDbAccess=0.000114s
[ INFO] (2016-02-05 16:22:58.306) Rtabmap.cpp:1736::process() timeReactivations=0.008860s
[DEBUG] (2016-02-05 16:22:58.307) Memory.cpp:401::parseParameters()
[DEBUG] (2016-02-05 16:22:58.307) Memory.cpp:514::parseParameters() new detector strategy 4
[DEBUG] (2016-02-05 16:22:58.307) Memory.cpp:3567::getNodeData() nodeId=40
[rtabmap/rtabmap-7] process has died [pid 6700, exit code -7, cmd /home/ubuntu/catkin_ws/devel/lib/rtabmap_ros/rtabmap --delete_db_on_start --udebug rgb/image:=/rgb/image_raw depth/image:=/depth/image_raw rgb/camera_info:=/camera/rgb/camera_info scan:=/scan __name:=rtabmap __log:=/home/ubuntu/.ros/log/a71f3b9a-cc4b-11e5-b59a-0005b7e12d1d/rtabmap-rtabmap-7.log].
log file: /home/ubuntu/.ros/log/a71f3b9a-cc4b-11e5-b59a-0005b7e12d1d/rtabmap-rtabmap-7*.log
[ INFO] [1454707378.394237521]: Odom: quality=342, std dev=0.054074m, update time=0.187915s
[ INFO] [1454707378.534514817]: Odom: quality=334, std dev=0.054718m, update time=0.129443s
[ INFO] [1454707378.728520970]: Odom: quality=405, std dev=0.049690m, update time=0.183319s
[ INFO] [1454707378.912258789]: Odom: quality=403, std dev=0.049814m, update time=0.168548s
[ INFO] [1454707379.070483479]: Odom: quality=381, std dev=0.051232m, update time=0.136154s
[ INFO] [1454707379.225048372]: Odom: quality=399, std dev=0.050063m, update time=0.143603s
[ INFO] [1454707379.379068162]: Odom: quality=410, std dev=0.049386m, update time=0.142383s
[ INFO] [1454707379.529646753]: Odom: quality=419, std dev=0.048853m, update time=0.140042s
[ INFO] [1454707379.678159824]: Odom: quality=353, std dev=0.053225m, update time=0.133526s
[ INFO] [1454707379.832144769]: Odom: quality=376, std dev=0.051571m, update time=0.142882s
[ INFO] [1454707379.981077423]: Odom: quality=382, std dev=0.051164m, update time=0.136779s
[ INFO] [1454707380.128997259]: Odom: quality=372, std dev=0.051848m, update time=0.137246s
[ INFO] [1454707380.267136937]: Odom: quality=314, std dev=0.056433m, update time=0.126558s
[ INFO] [1454707380.410864636]: Odom: quality=335, std dev=0.054636m, update time=0.133045s
[ INFO] [1454707380.550735877]: Odom: quality=358, std dev=0.052852m, update time=0.128001s
[ INFO] [1454707380.683518160]: Odom: quality=358, std dev=0.052852m, update time=0.122253s
[ INFO] [1454707380.823460182]: Odom: quality=352, std dev=0.053300m, update time=0.129094s
[ INFO] [1454707380.954454027]: Odom: quality=273, std dev=0.060523m, update time=0.118953s
[ INFO] [1454707381.085613755]: Odom: quality=302, std dev=0.057544m, update time=0.120510s
[ INFO] [1454707381.214491188]: Odom: quality=294, std dev=0.058321m, update time=0.116093s
[ INFO] [1454707381.343312266]: Odom: quality=295, std dev=0.058222m, update time=0.116206s
[ INFO] [1454707381.469435012]: Odom: quality=269, std dev=0.060971m, update time=0.114061s
[ INFO] [1454707381.585843488]: Odom: quality=250, std dev=0.063246m, update time=0.104583s
[ INFO] [1454707381.702107225]: Odom: quality=212, std dev=0.068680m, update time=0.104052s