rethink-imcmahon
commented
9 years ago +1 on this issue. I'm investigating a core with a very similar stack trace. It's incredibly difficult to reproduce, but I've managed to get two instances of the dump now:
Program terminated with signal 11, Segmentation fault.
(gdb) bt full
#0 atomic_conditional_increment (pw=0x3241) at /usr/include/boost/smart_ptr/detail/sp_counted_base_gcc_x86.hpp:92
rv = <optimized out>
#1 add_ref_lock (this=0x3239) at /usr/include/boost/smart_ptr/detail/sp_counted_base_gcc_x86.hpp:139
No locals.
#2 shared_count (r=..., this=0x7f37ab7fdb18) at /usr/include/boost/smart_ptr/detail/shared_count.hpp:589
No locals.
#3 boost::shared_ptr<ros::Subscription>::shared_ptr<ros::Subscription> (this=0x7f37ab7fdb10, r=...) at /usr/include/boost/smart_ptr/shared_ptr.hpp:414
No locals.
#4 0x00007f37b900b7b0 in lock (this=0x7f376c0275b8) at /usr/include/boost/smart_ptr/weak_ptr.hpp:178
No locals.
#5 ros::TransportPublisherLink::onRetryTimer (this=0x7f376c0275a0) at /var/tmp/portage/sci-ros/ros-indigo-roscpp-1.11.8.0-r2/work/ros-indigo-roscpp-1.11.8.0/src/libros/transport_publisher_link.cpp:204
parent = {
px = 0x0,
pn = {
pi_ = 0x3239
}
}
__PRETTY_FUNCTION__ = "void ros::TransportPublisherLink::onRetryTimer(const ros::WallTimerEvent&)"
#6 0x00007f37b8fc1e56 in operator() (a0=..., this=<optimized out>) at /usr/include/boost/function/function_template.hpp:767
No locals.
#7 ros::TimerManager<ros::WallTime, ros::WallDuration, ros::WallTimerEvent>::TimerQueueCallback::call (this=0x7f371c000eb0)
at /var/tmp/portage/sci-ros/ros-indigo-roscpp-1.11.8.0-r2/work/ros-indigo-roscpp-1.11.8.0/include/ros/timer_manager.h:184
tracked = {
px = 0x0,
pn = {
pi_ = 0x0
}
}
event = {
last_expected = {
<ros::TimeBase<ros::WallTime, ros::WallDuration>> = {
sec = 1430265753,
nsec = 727748844
}, <No data fields>},
last_real = {
<ros::TimeBase<ros::WallTime, ros::WallDuration>> = {
sec = 1430265753,
nsec = 727984536
}, <No data fields>},
current_expected = {
<ros::TimeBase<ros::WallTime, ros::WallDuration>> = {
sec = 1430265753,
nsec = 827748844
}, <No data fields>},
current_real = {
<ros::TimeBase<ros::WallTime, ros::WallDuration>> = {
sec = 1430265753,
nsec = 828038627
}, <No data fields>},
profile = {
last_duration = {
<ros::DurationBase<ros::WallDuration>> = {
sec = 0,
nsec = 424
}, <No data fields>}
}
}
#8 0x00007f37b8fea4ef in ros::CallbackQueue::callOneCB (this=this@entry=0x24eb900, tls=tls@entry=0x7f37a40008c0)
at /var/tmp/portage/sci-ros/ros-indigo-roscpp-1.11.8.0-r2/work/ros-indigo-roscpp-1.11.8.0/src/libros/callback_queue.cpp:382
rw_lock = {
m = 0x7f371c0014f8,
is_locked = true
}
last_calling = 18446744073709551615
result = ros::CallbackInterface::Invalid
info = {
callback = {
px = 0x7f371c000eb0,
pn = {
pi_ = 0x7f371c000910
}
},
removal_id = 139877086151072,
marked_for_removal = false
}
cb = @0x7f37ab7fdd00: {
px = 0x7f371c000eb0,
pn = {
pi_ = 0x7f371c000910
}
}
id_info = {
px = 0x7f371c0014f0,
pn = {
pi_ = 0x7f371c000a80
}
}
#9 0x00007f37b8fea843 in ros::CallbackQueue::callAvailable (this=0x24eb900, timeout=...)
at /var/tmp/portage/sci-ros/ros-indigo-roscpp-1.11.8.0-r2/work/ros-indigo-roscpp-1.11.8.0/src/libros/callback_queue.cpp:333
tls = <optimized out>
called = 0
#10 0x00007f37b90162cc in ros::internalCallbackQueueThreadFunc () at /var/tmp/portage/sci-ros/ros-indigo-roscpp-1.11.8.0-r2/work/ros-indigo-roscpp-1.11.8.0/src/libros/init.cpp:282
queue = {
px = 0x24eb900,
pn = {
pi_ = 0x24e7cd0
}
}
#11 0x00007f37bb4b594d in boost::(anonymous namespace)::thread_proxy (param=<optimized out>) at libs/thread/src/pthread/thread.cpp:164
thread_info = {
px = 0x24eeac0,
pn = {
pi_ = 0x24eb860
}
}
#12 0x00007f37b8ce41da in start_thread () from /lib64/libpthread.so.0
No symbol table info available.
#13 0x00007f37b6e11d7d in clone () from /lib64/libc.so.6
No symbol table info available.
The only useful piece of information that I can provide in reproducing the dump is that it happens (sometimes) as I kill a node that published / subscribed to the same topics that the dumping node subscribed / published to respectively.
Poking around in frame 8 (died @ line 382 of /src/libros/callback_queue.cpp), I see that the TLS is not being marked_for_removal, which causes the cb->call() to get executed on a subscription that has already been destroyed:
│362 CallbackInfo info = *tls->cb_it;
...
│375 if (info.marked_for_removal)
│376 {
│377 tls->cb_it = tls->callbacks.erase(tls->cb_it);
│378 }
│379 else
│380 {
│381 tls->cb_it = tls->callbacks.erase(tls->cb_it);
>│382 result = cb->call();
│383 } Should / how would this callback be marked for removal?
(gdb) print info
$50 = {
callback = {
px = 0x7f371c000eb0,
pn = {
pi_ = 0x7f371c000910
}
},
removal_id = 139877086151072,
marked_for_removal = false
}
wjwwood
dirk-thomas
stwirth
jasonimercer
jacquelinekay
jeffadamsc
We witnessed a crash of
diagnostic_agregator/aggregator_nodeon one of our robots, that is what i could find:Unfortunately that happened only once on one robot. No way to reproduce it. Has anybody seen something like that or can give me a hint on how to debug this further?