Bug in rosbag_storage: can't reuse the same instance or rosbag::Bag

[facontidavide]

In my application I used to create a single instance or rosbag::Bag and use it as follows

1. open a file
2. parse using rosbag::View
3. close()
4. repeat from point 1.

This is not possible anymore. Running the code with Valgrind, it seems that something odd is happening.

Invalid read of size 8
1: rosbag::View::iterator::increment() in /opt/ros/indigo/lib/librosbag_storage.so
2: void boost::iterator_core_access::incrementrosbag::View::iterator(rosbag::View::iterator&) in /usr/include/boost/iterator/iterator_facade.hpp:520
3: boost::iterator_facade<rosbag::View::iterator, rosbag::MessageInstance, boost::forward_traversal_tag, rosbag::MessageInstance&, long>::operator++() in /usr/include/boost/iterator/iterator_facade.hpp:660
4: DataLoadROS::readDataFromFile(QString const&, QString&) in /home/dfaconti/ws_plotjuggler/src/PlotJuggler/plugins/ROS/DataLoadROS/dataload_ros.cpp:129

....

Address 0x1baa01b0 is 16 bytes before a block of size 16 alloc'd 1: operator new(unsigned long) in /usr/lib/valgrind/vgpreload_memcheck-amd64-linux.so
2: std::vector<rosbag::ViewIterHelper, std::allocatorrosbag::ViewIterHelper >::_M_insert_aux(__gnu_cxx::__normal_iterator<rosbag::ViewIterHelper*, std::vector<rosbag::ViewIterHelper, std::allocatorrosbag::ViewIterHelper > >, rosbag::ViewIterHelper const&) in /opt/ros/indigo/lib/librosbag_storage.so
3: rosbag::View::iterator::populate() in /opt/ros/indigo/lib/librosbag_storage.so
4: rosbag::View::iterator::iterator(rosbag::View*, bool) in /opt/ros/indigo/lib/librosbag_storage.so
5: rosbag::View::begin() in /opt/ros/indigo/lib/librosbag_storage.so
6: DataLoadROS::readDataFromFile(QString const&, QString&) in /home/dfaconti/ws_plotjuggler/src/PlotJuggler/plugins/ROS/DataLoadROS/dataload_ros.cpp:129

[racko]

I tried to reproduce this issue (ignoring the valgrind part): #1188

I modified an existing test case that did points 1 through 3 as you listed them by simply adding a loop. The test still works.

Did you find the issue only through valgrind or did your application actually fail somehow? Can you provide a failing test?

[racko]

I also ran the test with valgrind:

valgrind /home/racko/ros_ws/devel/.private/test_rosbag_storage/lib/test_rosbag_storage/create_and_iterate_bag 
==1402== Memcheck, a memory error detector
==1402== Copyright (C) 2002-2017, and GNU GPL'd, by Julian Seward et al.
==1402== Using Valgrind-3.13.0 and LibVEX; rerun with -h for copyright info
==1402== Command: /home/racko/ros_ws/devel/.private/test_rosbag_storage/lib/test_rosbag_storage/create_and_iterate_bag
==1402== 
[==========] Running 3 tests from 1 test case.
[----------] Global test environment set-up.
[----------] 3 tests from rosbag_storage
[ RUN      ] rosbag_storage.iterator_copy_constructor
[       OK ] rosbag_storage.iterator_copy_constructor (121 ms)
[ RUN      ] rosbag_storage.iterator_copy_assignment
[       OK ] rosbag_storage.iterator_copy_assignment (7 ms)
[ RUN      ] rosbag_storage.iterate_bag
Successfully checked string foo
Successfully checked value 42
Successfully checked string foo
Successfully checked value 42
[       OK ] rosbag_storage.iterate_bag (22 ms)
[----------] 3 tests from rosbag_storage (155 ms total)

[----------] Global test environment tear-down
[==========] 3 tests from 1 test case ran. (173 ms total)
[  PASSED  ] 3 tests.
==1402== 
==1402== HEAP SUMMARY:
==1402==     in use at exit: 0 bytes in 0 blocks
==1402==   total heap usage: 988 allocs, 988 frees, 4,400,783 bytes allocated
==1402== 
==1402== All heap blocks were freed -- no leaks are possible
==1402== 
==1402== For counts of detected and suppressed errors, rerun with: -v
==1402== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 0 from 0)

[facontidavide]

Thanks. I will check it out and see if I can create a failing test

[facontidavide]

I found a way to recreate the error.

https://gist.github.com/facontidavide/80fa6e2b7a6328f63d88f1c333b4c796

before you look deeper into it, it seems that what trigger the problem is reduce_overlap = true in robag::View.

[facontidavide]

To be specific, this examples does recreate the memory error in Valgrind but not the exception. In my application, PlotJuggler, I additionally get an exception at the second bag.open.

[racko]

• The valgrind warning is triggered in your test case even if you don't loop twice. Bag::close() is not the cause of that (which is not to say that it might not cause other issues in you application.)
• I was able to fix a bug and get rid of the valgrind warning: Fixed an out of bounds read in void rosbag::View::iterator::increment() #1191
• I can't see this out-of-bounds read crashing you application. Could you provide more information on the exception you get?

[facontidavide]

Update:

1. Your code fix the valgrind issue but not the exception. The good news is that I am able to reproduce it now.

https://gist.github.com/facontidavide/80fa6e2b7a6328f63d88f1c333b4c796

2. Apparently this happen NOT when you try to read twice the same rosbag, but when you first read a rosbag file and then a different one. Ant it is NOT related to reduce_overlap = true

3. This is error message (rosbag::BagFormatException)

   Error: Received an invalid TCPROS header. Each element must be prepended by a 4-byte length.
   at line 82 in /tmp/binarydeb/ros-kinetic-cpp-common-0.6.2/src/header.cpp

[dirk-thomas]

Apparently this happen NOT when you try to read twice the same rosbag, but when you first read a rosbag file and then a different one. Ant it is NOT related to reduce_overlap = true

Can you please update #1188 to cover this case.

[racko]

Huh ... it took me three attempts to reproduce this. I had actually given up. First I used your code with the test bag (written to two different files on disk) from the test. Then I ran it with two different bags I had lying around, each with thousands of messages of one message type each. No exception. Then I only refactored the test a bit to clean it up and added a few more topics and message types, and voila! I had a beautiful "invalid TCPROS header" message :)

I updated #1188 with the failing test.

Luckily I already played around with simply cleaning up more state in Bag::close() and ChunkedFile::close(), trying to find some obvious issue in Bag::close(), but failing.

But somehow these changes already fixed the bug: #1192 :)

[facontidavide]

I just want to confirm that PR #1192 did solve the problem in my program. Shall we close this issue?

[dirk-thomas]

The issue can be closed once the PR has been merged.

[dirk-thomas]

Addressed by #1192.