[Live-devel] bug when clock is reset back in time
Sébastien Escudier
sebastien-devel at celeos.eu
Fri Sep 3 00:02:42 PDT 2010
On Thu, 2010-09-02 at 21:07 -0700, Ross Finlayson wrote:
> If you're still seeing this, and manage to figure out what part(s) of
> the code is causing this, please let us know.
I am using gprof to detect what live555 is doing when I reset the clock
one hour back in time.
I found that the dTimeNow function in RTCP.cpp is called way to often
after that (hundreds of time per seconds).
I can also give you the number of calls of each function, the call graph
of these function, and the gdb backtrace of dTimeNow when it happens :
See attached file gprof_output.txt
Please let me know if it helps you or not.
Regards,
Sebastien.
-------------- next part --------------
gdb :
#0 dTimeNow () at RTCP.cpp:112
#1 0x0805157b in RTCPInstance::schedule (this=0x86f6ef0, nextTime=1283499945.7241356) at RTCP.cpp:871
#2 0x080515ef in Schedule (nextTime=1283499945.7241356, e=0x86f6ef0) at RTCP.cpp:924
#3 0x080532ea in OnExpire (e=0x86f6ef0, members=2, senders=0, rtcp_bw=160, we_sent=0, avg_rtcp_size=0x86f706c, initial=0x86f7074, tc=1283496344.625545,
tp=0x86f7078, pmembers=0x86f7088) at rtcp_from_spec.c:223
#4 0x08051534 in RTCPInstance::onExpire1 (this=0x86f6ef0) at RTCP.cpp:899
#5 0x08051558 in RTCPInstance::onExpire (instance=0x86f6ef0) at RTCP.cpp:673
#6 0x0807b86a in AlarmHandler::handleTimeout (this=0x86f5550) at BasicTaskScheduler0.cpp:34
#7 0x0807a3c1 in DelayQueue::handleAlarm (this=0x86eb00c) at DelayQueue.cpp:180
#8 0x080799db in BasicTaskScheduler::SingleStep (this=0x86eb008, maxDelayTime=0) at BasicTaskScheduler.cpp:150
#9 0x0807b00c in BasicTaskScheduler0::doEventLoop (this=0x86eb008, watchVariable=0x0) at BasicTaskScheduler0.cpp:76
#10 0x0804c55d in main (argc=2, argv=0xb778c0b0) at playCommon.cpp:510
Each sample counts as 0.01 seconds.
% cumulative self self total
time seconds seconds calls s/call s/call name
17.08 0.77 0.77 7562157 0.00 0.00 BasicTaskScheduler::SingleStep(unsigned int)
15.07 1.44 0.68 7561236 0.00 0.00 RTCPInstance::schedule(double)
7.25 1.76 0.33 67814062 0.00 0.00 Timeval::operator>=(Timeval const&) const
7.25 2.09 0.33 7561236 0.00 0.00 RTCPInstance::onExpire1()
6.25 2.37 0.28 7561240 0.00 0.00 rtcp_interval
4.80 2.58 0.21 15122488 0.00 0.00 dTimeNow()
4.24 2.77 0.19 7561236 0.00 0.00 OnExpire
3.91 2.95 0.17 45377614 0.00 0.00 HandlerIterator::next()
3.68 3.12 0.17 30000480 0.00 0.00 Timeval::operator-=(DelayInterval const&)
3.12 3.25 0.14 7561236 0.00 0.00 BasicTaskScheduler0::scheduleDelayedTask(long long, void (*)(void*), void*)
2.68 3.38 0.12 7561234 0.00 0.00 AlarmHandler::handleTimeout()
2.23 3.48 0.10 1 0.10 1.40 BasicTaskScheduler0::doEventLoop(char*)
2.01 3.56 0.09 7561236 0.00 0.00 DelayQueue::addEntry(DelayQueueEntry*)
1.79 3.65 0.08 15122474 0.00 0.00 TypeOfEvent
1.56 3.71 0.07 7561236 0.00 0.00 AlarmHandler::~AlarmHandler()
1.45 3.78 0.07 7563096 0.00 0.00 DelayQueue::synchronize()
1.45 3.85 0.07 7561236 0.00 0.00 Schedule
1.34 3.90 0.06 15124313 0.00 0.00 DelayQueue::handleAlarm()
1.23 3.96 0.06 7563095 0.00 0.00 operator-(Timeval const&, Timeval const&)
1.12 4.01 0.05 7562171 0.00 0.00 HandlerIterator::HandlerIterator(HandlerSet&)
1.12 4.06 0.05 DelayQueue::timeToNextAlarm()
1.00 4.11 0.04 7565433 0.00 0.00 HandlerIterator::reset()
index % time self children called name
<spontaneous>
[1] 68.1 0.05 3.00 DelayQueue::timeToNextAlarm() [1]
0.12 2.83 7561234/7561234 AlarmHandler::handleTimeout() [2]
0.02 0.02 7561234/7561248 DelayQueue::removeEntry(DelayQueueEntry*) [27]
0.00 0.00 930/7563096 DelayQueue::synchronize() [13]
0.00 0.00 1860/67814062 Timeval::operator>=(Timeval const&) const [15]
-----------------------------------------------
0.12 2.83 7561234/7561234 DelayQueue::timeToNextAlarm() [1]
[2] 66.0 0.12 2.83 7561234 AlarmHandler::handleTimeout() [2]
0.04 2.68 7561234/7561236 RTCPInstance::onExpire(RTCPInstance*) [3]
0.01 0.10 7561234/7561234 DelayQueueEntry::handleTimeout() [20]
-----------------------------------------------
0.00 0.00 2/7561236 RTCPInstance::RTCPInstance(UsageEnvironment&, Groupsock*, unsigned int, unsigned char const*, RTPSink*, RTPSource const*, unsigned int) [72]
0.04 2.68 7561234/7561236 AlarmHandler::handleTimeout() [2]
[3] 60.8 0.04 2.68 7561236 RTCPInstance::onExpire(RTCPInstance*) [3]
0.33 2.36 7561236/7561236 RTCPInstance::onExpire1() [4]
-----------------------------------------------
0.33 2.36 7561236/7561236 RTCPInstance::onExpire(RTCPInstance*) [3]
[4] 59.9 0.33 2.36 7561236 RTCPInstance::onExpire1() [4]
0.19 2.02 7561236/7561236 OnExpire [5]
0.11 0.00 7561236/15122488 dTimeNow() [16]
0.04 0.00 7561236/7561250 RTCPInstance::numMembers() const [29]
-----------------------------------------------
0.19 2.02 7561236/7561236 RTCPInstance::onExpire1() [4]
[5] 49.4 0.19 2.02 7561236 OnExpire [5]
0.07 1.54 7561236/7561236 Schedule [6]
0.28 0.06 7561240/7561240 rtcp_interval [14]
0.08 0.00 15122472/15122474 TypeOfEvent [23]
0.00 0.00 4/4 SendRTCPReport [144]
0.00 0.00 4/4 SentPacketSize [145]
-----------------------------------------------
0.07 1.54 7561236/7561236 OnExpire [5]
[6] 35.8 0.07 1.54 7561236 Schedule [6]
0.68 0.86 7561236/7561236 RTCPInstance::schedule(double) [7]
-----------------------------------------------
0.68 0.86 7561236/7561236 Schedule [6]
[7] 34.3 0.68 0.86 7561236 RTCPInstance::schedule(double) [7]
0.14 0.61 7561236/7561236 BasicTaskScheduler0::scheduleDelayedTask(long long, void (*)(void*), void*) [11]
0.11 0.00 7561236/15122488 dTimeNow() [16]
More information about the live-devel
mailing list