[ros-users] roscpp and valgrind's helgrind
Blaise Gassend
blaise at willowgarage.com
Wed Oct 13 16:29:20 UTC 2010
For other folks reading this, here are snippets from the halgrind
output. (I didn't keep non-errors or duplicates):
During startup:
{{{
==24117== Thread #1: lock order "0xA333CB0 before 0xA333D50" violated
==24117== at 0x4C29B0C: pthread_mutex_lock (hg_intercepts.c:465)
==24117== by 0x804592B: apr_thread_mutex_lock (in /usr/lib/libapr-1.so.0.3.8)
==24117== by 0x5B664C3:
log4cxx::helpers::synchronized::synchronized(log4cxx::helpers::Mutex
const&) (in /usr/lib/liblog4cxx.so.10.0.0)
==24117== by 0x5B0E1A4: log4cxx::Hierarchy::setConfigured(bool) (in
/usr/lib/liblog4cxx.so.10.0.0)
==24117== by 0x5B11459:
log4cxx::Hierarchy::fireAddAppenderEvent(log4cxx::helpers::ObjectPtrT<log4cxx::Logger>
const&, log4cxx::helpers::ObjectPtrT<log4cxx::Appe
nder> const&) (in /usr/lib/liblog4cxx.so.10.0.0)
==24117== by 0x5B22133:
log4cxx::Logger::addAppender(log4cxx::helpers::ObjectPtrT<log4cxx::Appender>
const&) (in /usr/lib/liblog4cxx.so.10.0.0)
==24117== by 0x55DB379: ros::console::do_initialize() (rosconsole.cpp:421)
==24117== by 0x55DBFE3: ros::console::initialize() (rosconsole.cpp:430)
==24117== by 0x55E6115: ??? (in
/opt/ros/cturtle/ros/core/rosconsole/lib/librosconsole.so)
==24117== by 0x55D909A: ??? (in
/opt/ros/cturtle/ros/core/rosconsole/lib/librosconsole.so)
==24117== Required order was established by acquisition of lock at 0xA333CB0
==24117== at 0x4C29B0C: pthread_mutex_lock (hg_intercepts.c:465)
==24117== by 0x804592B: apr_thread_mutex_lock (in /usr/lib/libapr-1.so.0.3.8)
==24117== by 0x5B664C3:
log4cxx::helpers::synchronized::synchronized(log4cxx::helpers::Mutex
const&) (in /usr/lib/liblog4cxx.so.10.0.0)
==24117== by 0x5B10BED: log4cxx::Hierarchy::getLogger(std::string
const&, log4cxx::helpers::ObjectPtrT<log4cxx::spi::LoggerFactory>
const&) (in /usr/lib/liblog4c
xx.so.10.0.0)
==24117== by 0x5B4A874:
log4cxx::PropertyConfigurator::parseCatsAndRenderers(log4cxx::helpers::Properties&,
log4cxx::helpers::ObjectPtrT<log4cxx::spi::LoggerRepo
sitory>&) (in /usr/lib/liblog4cxx.so.10.0.0)
==24117== by 0x5B4AF5A:
log4cxx::PropertyConfigurator::doConfigure(log4cxx::helpers::Properties&,
log4cxx::helpers::ObjectPtrT<log4cxx::spi::LoggerRepository>&)
(in /usr/lib/liblog4cxx.so.10.0.0)
==24117== by 0x5B4B385:
log4cxx::PropertyConfigurator::doConfigure(log4cxx::File const&,
log4cxx::helpers::ObjectPtrT<log4cxx::spi::LoggerRepository>&) (in
/usr/
lib/liblog4cxx.so.10.0.0)
==24117== by 0x5B4B683:
log4cxx::PropertyConfigurator::configure(log4cxx::File const&) (in
/usr/lib/liblog4cxx.so.10.0.0)
==24117== by 0x55DABFE: ros::console::do_initialize() (rosconsole.cpp:400)
==24117== by 0x55DBFE3: ros::console::initialize() (rosconsole.cpp:430)
==24117== by 0x55E6115: ??? (in
/opt/ros/cturtle/ros/core/rosconsole/lib/librosconsole.so)
==24117== by 0x55D909A: ??? (in
/opt/ros/cturtle/ros/core/rosconsole/lib/librosconsole.so)
==24117== followed by a later acquisition of lock at 0xA333D50
==24117== at 0x4C29B0C: pthread_mutex_lock (hg_intercepts.c:465)
==24117== by 0x804592B: apr_thread_mutex_lock (in /usr/lib/libapr-1.so.0.3.8)
==24117== by 0x5B664C3:
log4cxx::helpers::synchronized::synchronized(log4cxx::helpers::Mutex
const&) (in /usr/lib/liblog4cxx.so.10.0.0)
==24117== by 0x5B21954:
log4cxx::Logger::Logger(log4cxx::helpers::Pool&, std::string const&)
(in /usr/lib/liblog4cxx.so.10.0.0)
==24117== by 0x5AF38BB:
log4cxx::DefaultLoggerFactory::makeNewLoggerInstance(log4cxx::helpers::Pool&,
std::string const&) const (in /usr/lib/liblog4cxx.so.10.0.0
)
==24117== by 0x5B10CE7: log4cxx::Hierarchy::getLogger(std::string
const&, log4cxx::helpers::ObjectPtrT<log4cxx::spi::LoggerFactory>
const&) (in /usr/lib/liblog4c
xx.so.10.0.0)
==24117== by 0x5B4A874:
log4cxx::PropertyConfigurator::parseCatsAndRenderers(log4cxx::helpers::Properties&,
log4cxx::helpers::ObjectPtrT<log4cxx::spi::LoggerRepo
sitory>&) (in /usr/lib/liblog4cxx.so.10.0.0)
==24117== by 0x5B4AF5A:
log4cxx::PropertyConfigurator::doConfigure(log4cxx::helpers::Properties&,
log4cxx::helpers::ObjectPtrT<log4cxx::spi::LoggerRepository>&)
(in /usr/lib/liblog4cxx.so.10.0.0)
==24117== by 0x5B4B385:
log4cxx::PropertyConfigurator::doConfigure(log4cxx::File const&,
log4cxx::helpers::ObjectPtrT<log4cxx::spi::LoggerRepository>&) (in
/usr/
lib/liblog4cxx.so.10.0.0)
==24117== by 0x5B4B683:
log4cxx::PropertyConfigurator::configure(log4cxx::File const&) (in
/usr/lib/liblog4cxx.so.10.0.0)
==24117== by 0x55DABFE: ros::console::do_initialize() (rosconsole.cpp:400)
==24117== by 0x55DBFE3: ros::console::initialize() (rosconsole.cpp:430)
==24117== Possible data race during read of size 8 at 0x57ee700 by thread #2
==24117== at 0x55DC4AA:
ros::console::print(ros::console::FilterBase*, log4cxx::Logger*,
ros::console::levels::Level, char const*, int, char const*, char
const*,
...) (shared_ptr.hpp:424)
==24117== by 0x4EAEE53: ros::TransportTCP::accept() (transport_tcp.cpp:534)
==24117== by 0x4EAF7A7: ros::TransportTCP::socketUpdate(int)
(transport_tcp.cpp:568)
==24117== by 0x4E9BE1E: ros::PollSet::update(int)
(function_template.hpp:1013)
==24117== by 0x4EDDEE4: ros::PollManager::threadFunc() (poll_manager.cpp:95)
==24117== by 0x57FAB6F: thread_proxy (in /usr/lib/libboost_thread.so.1.40.0)
==24117== by 0x4C2D558: mythread_wrapper (hg_intercepts.c:202)
==24117== by 0x6BED9C9: start_thread (pthread_create.c:300)
==24117== by 0x6EEA6FC: clone (clone.S:112)
==24117== This conflicts with a previous write of size 8 by thread #1
==24117== at 0x55DC845:
ros::console::print(ros::console::FilterBase*, log4cxx::Logger*,
ros::console::levels::Level, char const*, int, char const*, char
const*,
...) (move.h:83)
==24117== by 0x4ECCA2D: ros::start() (init.cpp:382)
==24117== by 0x4F427FF: ros::NodeHandle::construct() (node_handle.cpp:153)
==24117== by 0x4F4478D: ros::NodeHandle::NodeHandle(std::string
const&, std::map<std::string, std::string, std::less<std::string>,
std::allocator<std::pair<std::
string const, std::string> > > const&) (node_handle.cpp:75)
==24117== by 0x4066D5: main (add_two_ints_server.cpp:43)
}}}
This is a cool tool!
On Wed, Oct 13, 2010 at 9:06 AM, Blaise Gassend <blaise at willowgarage.com> wrote:
> I'm sure it would be much easier to answer your question if you
> provided the helgrind output. (Does helgrind have an ubuntu package?)
>
> 2010/10/13 Stéphane Magnenat <stephane.magnenat at mavt.ethz.ch>:
>> Hello,
>>
>> Running any ros program under valgrind's helgrind [1] results in a lot
>> of detected threading errors. For instance, just running
>> add_two_ints_server from roscpp_tutorials:
>> valgrind --tool=helgrind ./add_two_ints_server
>> ...leads to many errors from helgrind, mostly related to debug output
>> and callback management.
>>
>> Are you aware of this? Is it helgrind that is not able to understand
>> correctly what ROS is doing, or are there some nasty threading problems
>> which have remained hidden until now?
>>
>> Thank you, kind regards,
>>
>> Stéphane
>>
>> [1] http://valgrind.org/docs/manual/hg-manual.html
>>
>> --
>> Dr Stéphane Magnenat
>> http://stephane.magnenat.net
>> _______________________________________________
>> ros-users mailing list
>> ros-users at code.ros.org
>> https://code.ros.org/mailman/listinfo/ros-users
>>
>
More information about the ros-users
mailing list