Sources Bugzilla – Bug 14789
stale thread slowdown
Last modified: 2013-02-22 16:12:16 UTC
Created attachment 6712 [details]
> I am trying to debug a multithreaded program with gdb but get unexpected side effects.
> Test case code is attached.
> Basically, main() is an endless loop that
> - creates two threads t1 & t2
> - joins t2
> - increments an iteration counter i.
> t2 shall wait until t1 exists, then cancel and join t1.
> t1 does nothing, but has a cleanup handler that increments a counter c.
> When running without gdb, the output is as expected:
> i=1, c=1, dt=0.000848
> i=1001, c=1001, dt=0.095550
> i=2001, c=2001, dt=0.081302
> i=3001, c=3001, dt=0.089316
> i=4001, c=4001, dt=0.088792
> i=5001, c=5001, dt=0.086609
> i=6001, c=6001, dt=0.086388
> i=7001, c=7001, dt=0.090560
> [ i: iteration, c: cancellation handler calls, dt: time ]
> When running inside gdb (4.5 and master), I get:
> i=1, c=1, dt=0.005421
> i=1001, c=1000, dt=2.675437
> i=2001, c=2000, dt=5.822094
> i=3001, c=3000, dt=9.502770
> i=4001, c=4000, dt=15.998418
> i=5001, c=4999, dt=30.724420
> i=6001, c=5999, dt=57.917127
> i=7001, c=6999, dt=109.575370
> i=8001, c=7999, dt=162.559419
> i=9001, c=8999, dt=187.046422
> First, c is not incremented for every iteration.
> Maybe gdb inserts a cancellation point before the cleanup handler gets pushed ? Is this expected behavior ?
> Second, the time per 1000 iterations increases rapidly.
> I cannot figure a reason for that. Do you see this too ?
> I am running this on ubuntu 12.04 64bit with eglibc-2.15 and gcc-4.6.3.
Thanks. I've tried this with current mainline, and I see the same.
I suspect that the issue is GDB's inferior thread list just keeps
growing, and linear walks over the list cost more and more.
If you ctrl-c, and do "info threads; c", you'll see dt= coming back
down, as that cleans up stale thread entries.
gprof seems to confirm it:
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls ms/call ms/call name
66.55 39.01 39.01 1323158 0.03 0.03 find_thread_ptid
9.35 44.49 5.48 85368 0.06 0.07 set_executing
6.07 48.05 3.56 3310723008 0.00 0.00 ptid_equal
3.89 50.33 2.28 42684 0.05 0.07 set_running
3.60 52.44 2.11 149391 0.01 0.03 iterate_over_threads
3.54 54.52 2.08 227719151 0.00 0.00
1.57 55.44 0.92 272137 0.00 0.00 ptid_get_tid