Hi all,
I've managed to import EPG data for 2-3 weeks in advance. The trouble is I use epgsearch to automatically create timers to record a couple of series. This leads me to have around 20 active timers.
It seems that the more timers you have the slower VDR (1.3.21) becomes. I normally get "max. latency time 2 seconds" in my syslog, however when I have 20 timers, I get "max. latency time 17 seconds". What's causing it to slow down so much?
I've tried removing all plugins but if I leave the timers, I still get this long latency and the OSD becomes really slow.
Any ideas?
Chris
On Thursday 24 February 2005 20:40, Chris Warren wrote:
Hi all,
I've managed to import EPG data for 2-3 weeks in advance. The trouble is I use epgsearch to automatically create timers to record a couple of series. This leads me to have around 20 active timers.
It seems that the more timers you have the slower VDR (1.3.21) becomes. I normally get "max. latency time 2 seconds" in my syslog, however when I have 20 timers, I get "max. latency time 17 seconds". What's causing it to slow down so much?
I've tried removing all plugins but if I leave the timers, I still get this long latency and the OSD becomes really slow.
You could do some profiling with gprof. To that you need to link vdr with -- hmm -- I think gp (read: add -lgp when linking), then run it inside gprof (gprof vdr ....).
--Stefan
Basically the larger your epg.data is, the more cpu vdr will take up.
VDR runs the SetEvents and GetMatch functions pretty much each time thru the main loop. These functions are fairly "expensive" to run, because they will traverse the full events/epg data trying to match them up with timers.
--- Stefan Taferner taferner@kde.org wrote:
On Thursday 24 February 2005 20:40, Chris Warren wrote:
Hi all,
I've managed to import EPG data for 2-3 weeks in
advance. The trouble is I
use epgsearch to automatically create timers to
record a couple of series.
This leads me to have around 20 active timers.
It seems that the more timers you have the slower
VDR (1.3.21) becomes. I
normally get "max. latency time 2 seconds" in my
syslog, however when I
have 20 timers, I get "max. latency time 17
seconds". What's causing it to
slow down so much?
I've tried removing all plugins but if I leave the
timers, I still get this
long latency and the OSD becomes really slow.
You could do some profiling with gprof. To that you need to link vdr with -- hmm -- I think gp (read: add -lgp when linking), then run it inside gprof (gprof vdr ....).
--Stefan
vdr mailing list vdr@linuxtv.org http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
You could do some profiling with gprof. To that you need to link vdr with -- hmm -- I think gp (read: add -lgp when linking), then run it inside gprof (gprof vdr ....).
--Stefan
84.78% 51.92 51.92 70436 0.00 0.00 cSchedule::GetEvent(unsigned short, long) const
That's the culprit...
I wonder if it would be worth rewriting cSchedule to store events in a binary tree based on time. A double-linked list could be included in the nodes pointing to allow for scanning through the schedule in the conventional way (for(cEvent *p = events.First()...)
This would cut down the amount of work required to find an event based on time (used for timers, finding now/next events and probably numerous other places). Another tree of pointers could be built based on event id, to speed up searching based on IDs too.
What do people think, would it be worth me writing a patch?
Chris
Chris Warren wrote:
You could do some profiling with gprof. To that you need to link vdr with -- hmm -- I think gp (read: add -lgp when linking), then run it inside gprof (gprof vdr ....).
--Stefan
84.78% 51.92 51.92 70436 0.00 0.00 cSchedule::GetEvent(unsigned short, long) const
That's the culprit...
I wonder if it would be worth rewriting cSchedule to store events in a binary tree based on time. A double-linked list could be included in the nodes pointing to allow for scanning through the schedule in the conventional way (for(cEvent *p = events.First()...)
This would cut down the amount of work required to find an event based on time (used for timers, finding now/next events and probably numerous other places). Another tree of pointers could be built based on event id, to speed up searching based on IDs too.
What do people think, would it be worth me writing a patch?
I don't think we should make things more complicated than necessary.
My VDR has over 30 timers and I don't have any problems with excessive latency.
Klaus
Chris Warren wrote:
You could do some profiling with gprof. To that you need to link vdr with -- hmm -- I think gp (read: add -lgp when linking), then run it inside gprof (gprof vdr ....).
--Stefan
84.78% 51.92 51.92 70436 0.00 0.00 cSchedule::GetEvent(unsigned short, long) const
That's the culprit...
I wonder if it would be worth rewriting cSchedule to store events in a binary tree based on time. A double-linked list could be included in the nodes pointing to allow for scanning through the schedule in the conventional way (for(cEvent *p = events.First()...)
This would cut down the amount of work required to find an event based on time (used for timers, finding now/next events and probably numerous other places). Another tree of pointers could be built based on event id, to speed up searching based on IDs too.
What do people think, would it be worth me writing a patch?
Have you noticed that the show summaries (Recordings descriptions) are wrong on recorded events when you use a timer? I am curious if this behavior has to do with what you are describing. The only way I can get the summaries to display the correct information is if I record a minute longer after the show ends. For example, lets say a show starts at 1:00 and ends at 2:00. If you set a timer for 1:00 to 2:00, then in the schedule will show a little "t" next to the show you have set to record. But, if you set a timer for 1:00 to 2:01, then the schedule shows a capital "T" next to the show being recorded and two little "t"'s before and after the scheduled show. The first method will use the Summary of the previously scheduled show and the second method seems to use the correct information.
Best Regards,
-----Original Message----- From: vdr-bounces@linuxtv.org [mailto:vdr-bounces@linuxtv.org] On Behalf Of C.Y.M
Have you noticed that the show summaries (Recordings descriptions) are wrong on recorded events when you use a timer? I am curious if this behavior has to do with what you are describing. The only way I can get the summaries to display the correct information is if I record a minute longer after the show ends. For example, lets say a show starts at 1:00 and ends at 2:00. If you set a timer for 1:00 to 2:00, then in the schedule will show a little "t" next to the show you have set to record. But, if you set a timer for 1:00 to 2:01, then the schedule shows a capital "T" next to the show being recorded and two little "t"'s before and after the scheduled show. The first method will use the Summary of the previously scheduled show and the second method seems to use the correct information.
Yes, I get this too - it's because of the following line in cTimer::Matches(time_t, bool) of timers.c:
return startTime <= t && t < stopTime; // must stop *before* stopTime to allow adjacent timers
If your end time is exactly the same as the end of the event, it will match the start time, but not the end time. It'll only get marked as a partial match.
Chris
Chris Warren wrote:
-----Original Message----- From: vdr-bounces@linuxtv.org [mailto:vdr-bounces@linuxtv.org] On Behalf Of C.Y.M
Have you noticed that the show summaries (Recordings descriptions) are wrong on recorded events when you use a timer? I am curious if this behavior has to do with what you are describing. The only way I can get the summaries to display the correct information is if I record a minute longer after the show ends. For example, lets say a show starts at 1:00 and ends at 2:00. If you set a timer for 1:00 to 2:00, then in the schedule will show a little "t" next to the show you have set to record. But, if you set a timer for 1:00 to 2:01, then the schedule shows a capital "T" next to the show being recorded and two little "t"'s before and after the scheduled show. The first method will use the Summary of the previously scheduled show and the second method seems to use the correct information.
Yes, I get this too - it's because of the following line in cTimer::Matches(time_t, bool) of timers.c:
return startTime <= t && t < stopTime; // must stop *before* stopTime
to allow adjacent timers
If your end time is exactly the same as the end of the event, it will match the start time, but not the end time. It'll only get marked as a partial match.
Since I always add a few minutes before and after a recording I guess I don't have that problem. I'll look into this when I refine the VPS handling, for which I also need to improve the event assignment.
Klaus
I demand that Chris Warren may or may not have written...
[snip]
It seems that the more timers you have the slower VDR (1.3.21) becomes. I normally get "max. latency time 2 seconds" in my syslog, however when I have 20 timers, I get "max. latency time 17 seconds". What's causing it to slow down so much?
[snip]
The attached patch (which is in my vdr package) should help.
I wonder if it would be worth rewriting cSchedule to store events in a binary tree based on time. A double-linked list could be included in the nodes pointing to allow for scanning through the schedule in the conventional way (for(cEvent *p = events.First()...)
The right data structure for this (or rather, the canonical data structure for any sort of timer queue) is a binary heap. Guaranteed O(log n) time for insert and delete(first) operation and O(1) for lookup(first), zero memory overhead and much easier to implement than all other sorts of balanced tree.
What do people think, would it be worth me writing a patch?
Definitely.
Olaf
What do people think, would it be worth me writing a patch?
I don't think we should make things more complicated than necessary.
My VDR has over 30 timers and I don't have any problems with excessive latency.
I just did a (very quick and hacky) comparason - I added 2 std::maps to cSchedule: std::map<u_int16_t,cEvent*> eventIDMap; std::map<time_t,cEvent*> eventStartTimeMap;
By modifying cSchedule::AddEvent and cSchedule::GetEvent as described below, I managed to cut the most CPU intensive function's execution time to an 80th of the original! (from 83.79% of CPU time down to 1.12%!)
% cumulative self self total time seconds seconds calls s/call s/call vdr_orig.profile: 83.79 51.93 51.93 70436 0.00 0.00 cSchedule::GetEvent(unsigned short, long) const vdr_mod.profile: 1.12 7.98 0.11 70436 0.00 0.00 cSchedule::GetEvent(unsigned short, long) const
I know it adds a little complexity to things, but with such an improvement in lookup speed, maybe its worth looking at replacing the lists with a tree?
Chris
---
cEvent *cSchedule::AddEvent(cEvent *Event) { events.Add(Event); eventIDMap[Event->EventID()] = Event; eventStartTimeMap[Event->StartTime()] = Event; return Event; }
const cEvent *cSchedule::GetEvent(u_int16_t EventID, time_t StartTime) const { std::map<u_int16_t,cEvent*>::const_iterator it = eventIDMap.find(EventID); if(it != eventIDMap.end()) return it->second; std::map<u_int16_t,cEvent*>::const_iterator it2 = eventStartTimeMap.find(StartTime); if(it2 != eventStartTimeMap.end()) return it2->second; return NULL; }
Klaus Schmidinger wrote:
Chris Warren wrote:
-----Original Message----- From: vdr-bounces@linuxtv.org [mailto:vdr-bounces@linuxtv.org] On Behalf Of C.Y.M
Have you noticed that the show summaries (Recordings descriptions) are wrong on recorded events when you use a timer? I am curious if this behavior has to do with what you are describing. The only way I can get the summaries to display the correct information is if I record a minute longer after the show ends. For example, lets say a show starts at 1:00 and ends at 2:00. If you set a timer for 1:00 to 2:00, then in the schedule will show a little "t" next to the show you have set to record. But, if you set a timer for 1:00 to 2:01, then the schedule shows a capital "T" next to the show being recorded and two little "t"'s before and after the scheduled show. The first method will use the Summary of the previously scheduled show and the second method seems to use the correct information.
Yes, I get this too - it's because of the following line in cTimer::Matches(time_t, bool) of timers.c:
return startTime <= t && t < stopTime; // must stop *before*
stopTime to allow adjacent timers
If your end time is exactly the same as the end of the event, it will match the start time, but not the end time. It'll only get marked as a partial match.
Since I always add a few minutes before and after a recording I guess I don't have that problem. I'll look into this when I refine the VPS handling, for which I also need to improve the event assignment.
Yes, if you have more than one DVB card then its not a problem to record a few minutes before and after the event. But, if your system is a single DVB card, then adjacent timers is a must. Thanks for looking at this.
Best Regards,
Olaf Titz wrote:
I wonder if it would be worth rewriting cSchedule to store events in a binary tree based on time. A double-linked list could be included in the nodes pointing to allow for scanning through the schedule in the conventional way (for(cEvent *p = events.First()...)
The right data structure for this (or rather, the canonical data structure for any sort of timer queue) is a binary heap. Guaranteed O(log n) time for insert and delete(first) operation and O(1) for lookup(first), zero memory overhead and much easier to implement than all other sorts of balanced tree.
What do people think, would it be worth me writing a patch?
Definitely.
Come one, guys, you must be kidding!
For a few dozen timers even the simplest data structure has to perform extremely well, unless there is a bug.
So I suggest keeping the data structure and fixing the bug (which is propably exactly what Darren's patch does).
Carsten.
-----Original Message----- From: vdr-bounces@linuxtv.org [mailto:vdr-bounces@linuxtv.org] On Behalf Of Carsten Koch
Come one, guys, you must be kidding!
For a few dozen timers even the simplest data structure has to perform extremely well, unless there is a bug.
So I suggest keeping the data structure and fixing the bug (which is propably exactly what Darren's patch does).
Carsten.
The problem is not with the data-structure of the timers, it's with the data structure used to store epg events in a schedule (of which I have over 70,000 for around 100 channels.)
Having to serially scan the whole list of events for a channel to find an event is not good. My quick and dirty testing shows using a tree speeds this up by over 80 times on my data.
For timers, yes - just keeping them in a linked list is fine as we're only talking about small amounts of data.
Chris
Hello,
Does this function only get called at startup? If so, then vdr could only reliably run for 48 hours, right?
_J
In the new year, Darren Salt wrote:
I demand that Chris Warren may or may not have written...
[snip]
It seems that the more timers you have the slower VDR (1.3.21) becomes. I normally get "max. latency time 2 seconds" in my syslog, however when I have 20 timers, I get "max. latency time 17 seconds". What's causing it to slow down so much?
[snip]
The attached patch (which is in my vdr package) should help.
-- | Darren Salt | nr. Ashington, | d youmustbejoking,demon,co,uk | Debian, | Northumberland | s zap,tartarus,org | RISC OS | Toon Army | @ | Retrocomputing: a PC card in a Risc PC
Ever shoot an elephant in your pyjamas?
[Attachment, skipping...]
vdr mailing list vdr@linuxtv.org http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
Klaus Schmidinger wrote:
Chris Warren wrote:
-----Original Message----- From: vdr-bounces@linuxtv.org [mailto:vdr-bounces@linuxtv.org] On Behalf Of C.Y.M
Have you noticed that the show summaries (Recordings descriptions) are wrong on recorded events when you use a timer? I am curious if this behavior has to do with what you are describing. The only way I can get the summaries to display the correct information is if I record a minute longer after the show ends. For example, lets say a show starts at 1:00 and ends at 2:00. If you set a timer for 1:00 to 2:00, then in the schedule will show a little "t" next to the show you have set to record. But, if you set a timer for 1:00 to 2:01, then the schedule shows a capital "T" next to the show being recorded and two little "t"'s before and after the scheduled show. The first method will use the Summary of the previously scheduled show and the second method seems to use the correct information.
Yes, I get this too - it's because of the following line in cTimer::Matches(time_t, bool) of timers.c:
return startTime <= t && t < stopTime; // must stop *before*
stopTime to allow adjacent timers
If your end time is exactly the same as the end of the event, it will match the start time, but not the end time. It'll only get marked as a partial match.
Since I always add a few minutes before and after a recording I guess I don't have that problem. I'll look into this when I refine the VPS handling, for which I also need to improve the event assignment.
This seems to fix setting adjacent timers..
Regards,
--- vdr-1.3.21/timers.c.orig 2005-02-26 08:09:45.000000000 -0800 +++ vdr-1.3.21/timers.c 2005-02-26 08:11:59.000000000 -0800 @@ -348,7 +348,7 @@ stopTime = event->EndTime(); return event->IsRunning(true); } - return startTime <= t && t < stopTime; // must stop *before* stopTime to allow adjacent timers + return startTime <= t && t <= stopTime; // must stop *before* stopTime to allow adjacent timers } return false; }
Chris Warren wrote:
What do people think, would it be worth me writing a patch?
I don't think we should make things more complicated than necessary.
My VDR has over 30 timers and I don't have any problems with excessive latency.
I just did a (very quick and hacky) comparason - I added 2 std::maps to cSchedule: std::map<u_int16_t,cEvent*> eventIDMap; std::map<time_t,cEvent*> eventStartTimeMap;
By modifying cSchedule::AddEvent and cSchedule::GetEvent as described below, I managed to cut the most CPU intensive function's execution time to an 80th of the original! (from 83.79% of CPU time down to 1.12%!)
% cumulative self self total time seconds seconds calls s/call s/call
vdr_orig.profile: 83.79 51.93 51.93 70436 0.00 0.00 cSchedule::GetEvent(unsigned short, long) const vdr_mod.profile: 1.12 7.98 0.11 70436 0.00 0.00 cSchedule::GetEvent(unsigned short, long) const
I know it adds a little complexity to things, but with such an improvement in lookup speed, maybe its worth looking at replacing the lists with a tree?
Chris
The cSchedule::GetEvent() function is only called from eit.c, which AFAICS should be independent of the number of timers you have defined.
Since you are only observing these long latency times if there are many timers, I would assume that the actual problem must be somewhere else. Could you put a few debug outputs into the main loop of VDR to see where exactly it spends all that time?
Klaus
Chris Warren wrote:
84.78% 51.92 51.92 70436 0.00 0.00 cSchedule::GetEvent(unsigned short, long) const
That's the culprit...
I wonder if it would be worth rewriting cSchedule to store events in a binary tree based on time. A double-linked list could be included in the nodes pointing to allow for scanning through the schedule in the conventional way (for(cEvent *p = events.First()...)
I've not looked at the code but am I right in thinking it scans trhough the list to find the next event?
surely in that case you only need to scan the list once, and remember the time of the next event, only rescanning when the next event is reached?
dvb@ixalon.net(Chris Warren) 25.02.05 17:27
-----Original Message----- From: vdr-bounces@linuxtv.org [mailto:vdr-bounces@linuxtv.org] On Behalf Of C.Y.M
Have you noticed that the show summaries (Recordings descriptions) are wrong on recorded events when you use a timer? I am curious if this behavior has to do with what you are describing. The only way I can get the summaries to display the correct information is if I record a minute longer after the show ends. For example, lets say a show starts at 1:00 and ends at 2:00. If you set a timer for 1:00 to 2:00, then in the schedule will show a little "t" next to the show you have set to record. But, if you set a timer for 1:00 to 2:01, then the schedule shows a capital "T" next to the show being recorded and two little "t"'s before and after the scheduled show. The first method will use the Summary of the previously scheduled show and the second method seems to use the correct information.
Yes, I get this too - it's because of the following line in cTimer::Matches(time_t, bool) of timers.c:
return startTime <= t && t < stopTime; // must stop *before*
stopTime to allow adjacent timers
If your end time is exactly the same as the end of the event, it will match the start time, but not the end time. It'll only get marked as a partial match.
That's an old vdr specific problem too. It's caused by using only minute stamps, it's a quantization, under sampling/aliasing problem, if you like to call it that way ;-)
The solution is to use a higher sampling rate or, as we "know" the "clock" and can synchronize to the foreign "data" stream, a phase shift. (Currently VDR is low pass "filtering" the input "data": one timer can one match approx 2..3 minutes)
That means, a recording printed out "2:00-2:59" must actually start at 1:59:50 and stop at 2:59:49(*), givin a 10sec "phase shift" margin. That would ensure that VDR records what the user expected. Of cource VDR is fooling the user. But as long as he gets what he expected it's OK. IMHO it not OK to expect the user to subtract/add these technically required margins. If one likes he may set cutting marks automatically to the "real" start/stop points (detected by VPS?). (BTW: Meanwhile i removed allmost all VPS timers. Klaus is right: it does not work. I missed recordings because the VPS time was changed or no card was tuned to the right transceiver/polarization (i have to turn EPG scan of as it is not compatible with my singel LNB setup), but worse: VDR often missed the VPS stop points and make an xx hour long recording causing all other timers to fail because of disk full and nothing left to delete. (It not easy to find that big recordings) Many VPS recordings where "duping": Immediately after the recoding stops (at the right moment!) a record of the following programm is started wasting further space on disk.)
(*) It might be worth a discussion if the margin should be 10 or 5 sec. But it's not OK to start a recording at 2:00:00 as this is impossible to do. When VDR started 4 years ago there was no way to "synchonize" the clock so the 1..2min margin was required and OK, talking about "seconds" would have been rediculous. But meanwhile clock synchronization possible and works quite well. (At least the programs i see use the same time. Maybe it's required to add a "time zone" or "time offset" for other programs on other time zones and a non synchronized clock?)