Discussion:
[vdr] Recording does not stop
(too old to reply)
brian
2012-05-01 05:50:37 UTC
Permalink
Hi,
doing some pretty heavy testing of VDR 1.7.21 as part of gen2vdr V3 and
have now twice had the case
that a recording did not end. Supposed to end at 23:10 yesterday, still
going strong at 06:00 this
morning. Can't find anything in the history file of VDR that this is a
know problem and has been fixed in
later versions.
Here is some of the log:

Apr 30 21:59:00 [vdr] [2496] timer 1 (1 2159-2310 'Silent Witness') start
Apr 30 21:59:00 [vdr] [2496] Title: 'Silent Witness' Subtitle: 'Fear -
Part Two'
Apr 30 21:59:00 [vdr] [2496] executing '/tmp/vdr/vdr_record before
"/video/Silent_Witness/2012-04-30.21.59.1-0.rec"'
Apr 30 21:59:00 [logger] BJD g2v_record.sh Called: 0 = /tmp/vdr/vdr_record
Apr 30 21:59:00 [logger] 2012-04-30 21:59 /tmp/vdr/vdr_record before
/video/Silent_Witness/2012-04-30.21.59.1-0.rec
Apr 30 21:59:00 [logger] /usr/sbin/mailtext: Started Start 2012-04-30
21.59 Silent Witness.
Apr 30 21:59:00 [logger] [g2v_rec_msg.sh] Silent Witness: Warte auf
Verzeichnis
- Last output repeated 2 times -
Apr 30 21:59:01 [sSMTP] Sent mail for ***@t-online.de (221
2.0.0 fwd22.t-online.de closing. / Verbindung wird getrennt.) u
Apr 30 21:59:01 [logger] Apr 30 21:59:01 gen2vdr sendemail[3863]: Email
was sent successfully!
Apr 30 21:59:01 [logger] /usr/sbin/mailtext: Done
Apr 30 21:59:01 [vdr] [2496] record
/video/Silent_Witness/2012-04-30.21.59.1-0.rec
Apr 30 21:59:01 [vdr] [2496] creating directory
/video/Silent_Witness/2012-04-30.21.59.1-0.rec
Apr 30 21:59:02 [vdr] [2496] recording to
'/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00001.ts'


Doesn't seem to try to end at 23:10

Apr 30 22:59:50 [vdr] [2738] channel 1 (BBC 1 London) event Mon
30.04.2012 23:00-23:25 'BBC News' status 4
Apr 30 23:00:01 [cron] (root) CMD (rm -f
/var/spool/cron/lastrun/cron.hourly)
Apr 30 23:01:59 [vdr] [2734] read incomplete section - len = 428, r = 214
Apr 30 23:12:36 [ntpd] peer 213.198.55.2 now valid
Apr 30 23:12:39 [ntpd] peer 129.70.132.36 now valid
Apr 30 23:12:48 [ntpd] peer 178.63.99.230 now valid
Apr 30 23:14:41 [vdr] [3935] recording to
'/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00002.ts'
Apr 30 23:18:11 [kernel] lirc_serial: ignoring spike: 1 1 4f9f0193
4f9f0190 87401 aa74b
Apr 30 23:20:41 [ntpd] skew change -36.162 exceeds limit
Apr 30 23:20:41 [ntpd] clock is now synced


Still going strong:

May 01 00:07:37 [vdr] [2738] channel 1 (BBC 1 London) event Tue
01.05.2012 00:05-00:35 'Late Kick Off' status 4
May 01 00:19:30 [vdr] [3935] recording to
'/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00003.ts'
May 01 00:24:40 [vdr] [2779] TVTV: Packed String: DKVxHLuoiXDxsDu98Eavvg==
....
May 01 01:23:04 [vdr] [3935] recording to
'/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00004.ts'


Deleted the timer manually:

May 01 06:37:39 [vdr] [2496] timer 1 (1 2159-2310 'Silent Witness') stop
May 01 06:37:39 [vdr] [2496] executing '/tmp/vdr/vdr_record after
"/video/Silent_Witness/2012-04-30.21.59.1-0.rec"'
May 01 06:37:39 [logger] BJD g2v_record.sh Called: 0 = /tmp/vdr/vdr_record
May 01 06:37:39 [logger] 2012-05-01 06:37 /tmp/vdr/vdr_record after
/video/Silent_Witness/2012-04-30.21.59.1-0.rec
May 01 06:37:39 [logger] /usr/sbin/mailtext: Started End 2012-04-30
21.59 Silent Witness.
May 01 06:37:39 [vdr] [3939] TS buffer on device 3 thread ended
(pid=2496, tid=3939)
May 01 06:37:39 [vdr] [3936] buffer stats: 95316 (4%) used
May 01 06:37:39 [vdr] [3936] receiver on device 3 thread ended
(pid=2496, tid=3936)

Any ideas?

Cheers Brian
Klaus Schmidinger
2012-05-01 09:54:33 UTC
Permalink
Hi,
doing some pretty heavy testing of VDR 1.7.21 as part of gen2vdr V3 and have now twice had the case
that a recording did not end. Supposed to end at 23:10 yesterday, still going strong at 06:00 this
morning. Can't find anything in the history file of VDR that this is a know problem and has been fixed in
later versions.
Apr 30 21:59:00 [vdr] [2496] timer 1 (1 2159-2310 'Silent Witness') start
Apr 30 21:59:00 [vdr] [2496] Title: 'Silent Witness' Subtitle: 'Fear - Part Two'
Apr 30 21:59:00 [vdr] [2496] executing '/tmp/vdr/vdr_record before "/video/Silent_Witness/2012-04-30.21.59.1-0.rec"'
Apr 30 21:59:00 [logger] BJD g2v_record.sh Called: 0 = /tmp/vdr/vdr_record
Apr 30 21:59:00 [logger] 2012-04-30 21:59 /tmp/vdr/vdr_record before /video/Silent_Witness/2012-04-30.21.59.1-0.rec
Apr 30 21:59:00 [logger] /usr/sbin/mailtext: Started Start 2012-04-30 21.59 Silent Witness.
Apr 30 21:59:00 [logger] [g2v_rec_msg.sh] Silent Witness: Warte auf Verzeichnis
- Last output repeated 2 times -
Apr 30 21:59:01 [logger] Apr 30 21:59:01 gen2vdr sendemail[3863]: Email was sent successfully!
Apr 30 21:59:01 [logger] /usr/sbin/mailtext: Done
Apr 30 21:59:01 [vdr] [2496] record /video/Silent_Witness/2012-04-30.21.59.1-0.rec
Apr 30 21:59:01 [vdr] [2496] creating directory /video/Silent_Witness/2012-04-30.21.59.1-0.rec
Apr 30 21:59:02 [vdr] [2496] recording to '/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00001.ts'
Doesn't seem to try to end at 23:10
Apr 30 22:59:50 [vdr] [2738] channel 1 (BBC 1 London) event Mon 30.04.2012 23:00-23:25 'BBC News' status 4
Apr 30 23:00:01 [cron] (root) CMD (rm -f /var/spool/cron/lastrun/cron.hourly)
Apr 30 23:01:59 [vdr] [2734] read incomplete section - len = 428, r = 214
Apr 30 23:12:36 [ntpd] peer 213.198.55.2 now valid
Apr 30 23:12:39 [ntpd] peer 129.70.132.36 now valid
Apr 30 23:12:48 [ntpd] peer 178.63.99.230 now valid
Apr 30 23:14:41 [vdr] [3935] recording to '/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00002.ts'
Apr 30 23:18:11 [kernel] lirc_serial: ignoring spike: 1 1 4f9f0193 4f9f0190 87401 aa74b
Apr 30 23:20:41 [ntpd] skew change -36.162 exceeds limit
Apr 30 23:20:41 [ntpd] clock is now synced
May 01 00:07:37 [vdr] [2738] channel 1 (BBC 1 London) event Tue 01.05.2012 00:05-00:35 'Late Kick Off' status 4
May 01 00:19:30 [vdr] [3935] recording to '/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00003.ts'
May 01 00:24:40 [vdr] [2779] TVTV: Packed String: DKVxHLuoiXDxsDu98Eavvg==
....
May 01 01:23:04 [vdr] [3935] recording to '/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00004.ts'
May 01 06:37:39 [vdr] [2496] timer 1 (1 2159-2310 'Silent Witness') stop
May 01 06:37:39 [vdr] [2496] executing '/tmp/vdr/vdr_record after "/video/Silent_Witness/2012-04-30.21.59.1-0.rec"'
May 01 06:37:39 [logger] BJD g2v_record.sh Called: 0 = /tmp/vdr/vdr_record
May 01 06:37:39 [logger] 2012-05-01 06:37 /tmp/vdr/vdr_record after /video/Silent_Witness/2012-04-30.21.59.1-0.rec
May 01 06:37:39 [logger] /usr/sbin/mailtext: Started End 2012-04-30 21.59 Silent Witness.
May 01 06:37:39 [vdr] [3939] TS buffer on device 3 thread ended (pid=2496, tid=3939)
May 01 06:37:39 [vdr] [3936] buffer stats: 95316 (4%) used
May 01 06:37:39 [vdr] [3936] receiver on device 3 thread ended (pid=2496, tid=3936)
Any ideas?
Did this happen only once, or is it reproducible?

Is this "plain vanilla" VDR or are there any patches involved.
I never had this problem with plain vanilla VDR.

Klaus
brian
2012-05-01 11:07:00 UTC
Permalink
Post by Klaus Schmidinger
Post by brian
Hi,
doing some pretty heavy testing of VDR 1.7.21 as part of gen2vdr V3
and have now twice had the case
that a recording did not end. Supposed to end at 23:10 yesterday,
still going strong at 06:00 this
morning. Can't find anything in the history file of VDR that this is
a know problem and has been fixed in
later versions.
Apr 30 21:59:00 [vdr] [2496] timer 1 (1 2159-2310 'Silent Witness') start
Apr 30 21:59:00 [vdr] [2496] Title: 'Silent Witness' Subtitle: 'Fear - Part Two'
Apr 30 21:59:00 [vdr] [2496] executing '/tmp/vdr/vdr_record before
"/video/Silent_Witness/2012-04-30.21.59.1-0.rec"'
Apr 30 21:59:00 [logger] BJD g2v_record.sh Called: 0 =
/tmp/vdr/vdr_record
Apr 30 21:59:00 [logger] 2012-04-30 21:59 /tmp/vdr/vdr_record before
/video/Silent_Witness/2012-04-30.21.59.1-0.rec
Apr 30 21:59:00 [logger] /usr/sbin/mailtext: Started Start 2012-04-30
21.59 Silent Witness.
Apr 30 21:59:00 [logger] [g2v_rec_msg.sh] Silent Witness: Warte auf Verzeichnis
- Last output repeated 2 times -
2.0.0 fwd22.t-online.de closing. / Verbindung wird getrennt.) u
Email was sent successfully!
Apr 30 21:59:01 [logger] /usr/sbin/mailtext: Done
Apr 30 21:59:01 [vdr] [2496] record
/video/Silent_Witness/2012-04-30.21.59.1-0.rec
Apr 30 21:59:01 [vdr] [2496] creating directory
/video/Silent_Witness/2012-04-30.21.59.1-0.rec
Apr 30 21:59:02 [vdr] [2496] recording to
'/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00001.ts'
Doesn't seem to try to end at 23:10
Apr 30 22:59:50 [vdr] [2738] channel 1 (BBC 1 London) event Mon
30.04.2012 23:00-23:25 'BBC News' status 4
Apr 30 23:00:01 [cron] (root) CMD (rm -f
/var/spool/cron/lastrun/cron.hourly)
Apr 30 23:01:59 [vdr] [2734] read incomplete section - len = 428, r = 214
Apr 30 23:12:36 [ntpd] peer 213.198.55.2 now valid
Apr 30 23:12:39 [ntpd] peer 129.70.132.36 now valid
Apr 30 23:12:48 [ntpd] peer 178.63.99.230 now valid
Apr 30 23:14:41 [vdr] [3935] recording to
'/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00002.ts'
Apr 30 23:18:11 [kernel] lirc_serial: ignoring spike: 1 1 4f9f0193 4f9f0190 87401 aa74b
Apr 30 23:20:41 [ntpd] skew change -36.162 exceeds limit
Apr 30 23:20:41 [ntpd] clock is now synced
May 01 00:07:37 [vdr] [2738] channel 1 (BBC 1 London) event Tue
01.05.2012 00:05-00:35 'Late Kick Off' status 4
May 01 00:19:30 [vdr] [3935] recording to
'/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00003.ts'
DKVxHLuoiXDxsDu98Eavvg==
....
May 01 01:23:04 [vdr] [3935] recording to
'/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00004.ts'
May 01 06:37:39 [vdr] [2496] timer 1 (1 2159-2310 'Silent Witness') stop
May 01 06:37:39 [vdr] [2496] executing '/tmp/vdr/vdr_record after
"/video/Silent_Witness/2012-04-30.21.59.1-0.rec"'
May 01 06:37:39 [logger] BJD g2v_record.sh Called: 0 =
/tmp/vdr/vdr_record
May 01 06:37:39 [logger] 2012-05-01 06:37 /tmp/vdr/vdr_record after
/video/Silent_Witness/2012-04-30.21.59.1-0.rec
May 01 06:37:39 [logger] /usr/sbin/mailtext: Started End 2012-04-30 21.59 Silent Witness.
May 01 06:37:39 [vdr] [3939] TS buffer on device 3 thread ended (pid=2496, tid=3939)
May 01 06:37:39 [vdr] [3936] buffer stats: 95316 (4%) used
May 01 06:37:39 [vdr] [3936] receiver on device 3 thread ended (pid=2496, tid=3936)
Any ideas?
Did this happen only once, or is it reproducible?
Is this "plain vanilla" VDR or are there any patches involved.
I never had this problem with plain vanilla VDR.
Klaus
_______________________________________________
vdr mailing list
http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
Moin,

second time now. Its the standard gen2vdr distribution so various
patches and plugins I guess.

I am not trying to use VPS, can I rule that out due to the messages shown?
Post by Klaus Schmidinger
Post by brian
Apr 30 23:01:59 [vdr] [2734] read incomplete section - len = 428, r = 214
Is the above message important?

I'll try to strip it down then and see if it reoccurs.

Cheers Brian
Klaus Schmidinger
2012-05-01 11:28:26 UTC
Permalink
Post by Klaus Schmidinger
Hi,
doing some pretty heavy testing of VDR 1.7.21 as part of gen2vdr V3 and have now twice had the case
that a recording did not end. Supposed to end at 23:10 yesterday, still going strong at 06:00 this
morning. Can't find anything in the history file of VDR that this is a know problem and has been fixed in
later versions.
Apr 30 21:59:00 [vdr] [2496] timer 1 (1 2159-2310 'Silent Witness') start
Apr 30 21:59:00 [vdr] [2496] Title: 'Silent Witness' Subtitle: 'Fear - Part Two'
Apr 30 21:59:00 [vdr] [2496] executing '/tmp/vdr/vdr_record before "/video/Silent_Witness/2012-04-30.21.59.1-0.rec"'
Apr 30 21:59:00 [logger] BJD g2v_record.sh Called: 0 = /tmp/vdr/vdr_record
Apr 30 21:59:00 [logger] 2012-04-30 21:59 /tmp/vdr/vdr_record before /video/Silent_Witness/2012-04-30.21.59.1-0.rec
Apr 30 21:59:00 [logger] /usr/sbin/mailtext: Started Start 2012-04-30 21.59 Silent Witness.
Apr 30 21:59:00 [logger] [g2v_rec_msg.sh] Silent Witness: Warte auf Verzeichnis
- Last output repeated 2 times -
Apr 30 21:59:01 [logger] Apr 30 21:59:01 gen2vdr sendemail[3863]: Email was sent successfully!
Apr 30 21:59:01 [logger] /usr/sbin/mailtext: Done
Apr 30 21:59:01 [vdr] [2496] record /video/Silent_Witness/2012-04-30.21.59.1-0.rec
Apr 30 21:59:01 [vdr] [2496] creating directory /video/Silent_Witness/2012-04-30.21.59.1-0.rec
Apr 30 21:59:02 [vdr] [2496] recording to '/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00001.ts'
Doesn't seem to try to end at 23:10
Apr 30 22:59:50 [vdr] [2738] channel 1 (BBC 1 London) event Mon 30.04.2012 23:00-23:25 'BBC News' status 4
Apr 30 23:00:01 [cron] (root) CMD (rm -f /var/spool/cron/lastrun/cron.hourly)
Apr 30 23:01:59 [vdr] [2734] read incomplete section - len = 428, r = 214
Apr 30 23:12:36 [ntpd] peer 213.198.55.2 now valid
Apr 30 23:12:39 [ntpd] peer 129.70.132.36 now valid
Apr 30 23:12:48 [ntpd] peer 178.63.99.230 now valid
Apr 30 23:14:41 [vdr] [3935] recording to '/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00002.ts'
Apr 30 23:18:11 [kernel] lirc_serial: ignoring spike: 1 1 4f9f0193 4f9f0190 87401 aa74b
Apr 30 23:20:41 [ntpd] skew change -36.162 exceeds limit
Apr 30 23:20:41 [ntpd] clock is now synced
May 01 00:07:37 [vdr] [2738] channel 1 (BBC 1 London) event Tue 01.05.2012 00:05-00:35 'Late Kick Off' status 4
May 01 00:19:30 [vdr] [3935] recording to '/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00003.ts'
May 01 00:24:40 [vdr] [2779] TVTV: Packed String: DKVxHLuoiXDxsDu98Eavvg==
....
May 01 01:23:04 [vdr] [3935] recording to '/video/Silent_Witness/2012-04-30.21.59.1-0.rec/00004.ts'
May 01 06:37:39 [vdr] [2496] timer 1 (1 2159-2310 'Silent Witness') stop
May 01 06:37:39 [vdr] [2496] executing '/tmp/vdr/vdr_record after "/video/Silent_Witness/2012-04-30.21.59.1-0.rec"'
May 01 06:37:39 [logger] BJD g2v_record.sh Called: 0 = /tmp/vdr/vdr_record
May 01 06:37:39 [logger] 2012-05-01 06:37 /tmp/vdr/vdr_record after /video/Silent_Witness/2012-04-30.21.59.1-0.rec
May 01 06:37:39 [logger] /usr/sbin/mailtext: Started End 2012-04-30 21.59 Silent Witness.
May 01 06:37:39 [vdr] [3939] TS buffer on device 3 thread ended (pid=2496, tid=3939)
May 01 06:37:39 [vdr] [3936] buffer stats: 95316 (4%) used
May 01 06:37:39 [vdr] [3936] receiver on device 3 thread ended (pid=2496, tid=3936)
Any ideas?
Did this happen only once, or is it reproducible?
Is this "plain vanilla" VDR or are there any patches involved.
I never had this problem with plain vanilla VDR.
Klaus
_______________________________________________
vdr mailing list
http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
Moin,
second time now. Its the standard gen2vdr distribution so various patches and plugins I guess.
I am not trying to use VPS, can I rule that out due to the messages shown?
Since there is no VPS keyword in the timer line at

Apr 30 21:59:00 [vdr] [2496] timer 1 (1 2159-2310 'Silent Witness') start

it's safe to assume that VPS is not being used.
Post by Klaus Schmidinger
Apr 30 23:01:59 [vdr] [2734] read incomplete section - len = 428, r = 214
Is the above message important?
No.
I'll try to strip it down then and see if it reoccurs.
Try to get rid of as many patches as possible (preferably all of them ;-).
And use only the plugin necessary for output, nothing else.

Klaus

Continue reading on narkive:
Loading...