Box schaltet ab bei 2 überlappenden Aufnahmen und Zapping

[xenonart]

Hallo,
ich habe nichts darüber gefunden, inwiefern das hier ein bekanntes Phänomen ist:

Habe seit einigen Tagen das IDE-Interface von dbox2.com in meiner Sagem dbox eingebaut, 2,5"HDD intern mit Strom versorgt, normale Aufnahmen und auch das Abspielen funktionieren wunderbar, nur bei einer bestimmten Konstellation taucht immer das gleiche Problem auf - folgendes Szenario:

- 2 Aufnahmetimer, spätere Sendung beginnt theoretisch noch, bevor Sendung 1 beendet ist
- Box ist auf einem Sender, auf dem nicht Sendung 1 beginnt, es wird also vor der Aufnahme automatisch umgeschaltet
- Aufnahme 1 ist vollständig auf der Platte, bis auf die letzten Minuten, mit denen die Sendungen überlappen (soweit alles normal)
- Box schaltet zurück auf den Anfangssender, auf dem sie vor der Sendung 1 war
- Aufnahme der Sendung 2 beginnt, es wurde aber nicht auf den passenden Kanal für Sendung 2 geschaltet (zumindest steht noch der erste Anfangssender im Display)
- die TS-Datei für Aufnahme 2 wird kontinuierlich größer, irgendwas wird aufgenommen, die Aufnahme zu Sendung 2 endet aber nie, und versucht man, die Aufnahme irgendwie manuell zu beenden, startet die Box einfach neu.

Ist das Problem eventuell bekannt / normal, und ich muss damit einfach leben und kucken, dass der Fall einfach nicht eintritt? Oder doch nicht?

Das ganze hat reproduzierbar 3x nacheinander geklappt, habe kein serielles Kabel hier momentan und deswegen auch kein Log, würde hierfür ein setconsole Log reichen und mehr Informationen preisgeben? Dann versuch ich mal herauszufinden, wie ich hier auf dem Mac ein setconsole-Log bekomme und das Problem nochmal zu provozieren...

/edit
Image ist das aktuelle JtG Snapshot
/edit

Gruß,
xenonart

[Stingray]

Wenn ich das richtig verstehe, überschneiden sich beide Timer.
Das dürfte eigentlich nicht funktionieren.
Zumal die Linuxsoftware dich bei der Timerprogrammierung drauf hinweist, dass eine Überschneidung vorhanden ist.

Laut meinen Infos muß zwischen den Timern eine kleine Pause vorhanden sein.
So z.B.

1. Sendung
Start: 20:15 Uhr
Stop: 21:59 Uhr

2. Sendung
Start: 22:00 Uhr
Stop: 23:19 Uhr

3. Sendung
Start: 23:20 Uhr
Stop: 01:15 Uhr

usw.

Gruß Basti

[xenonart]

Okay, vielen Dank erst einmal für die Info.

Ich hatte die Neutrino-Meldung über die Überschneidung so verstanden, dass ich mir einfach im Klaren darüber sein soll, dass nicht beide Aufnahmen vollständig sein werden - habe nicht daran gedacht, dass noch weitere Probleme auftreten können.

Hab mittlerweile das setconsole-Log sogar hinbekommen, wie der Teufel es so will, trat der Fehler natürlich diesmal nicht auf, alles lief glatt:

Code: Alles auswählen

14:42:26.383 dmxCN: waking up again - requested from .change()
14:42:26.661 dmxCN: going to sleep...
14:42:26.662 eit_set_update_filter, servicekey = 0x44da4016f3b, current version 20
14:42:34.995 dmxCN: waking up again - requested from .change()
14:42:35.946 dmxCN: going to sleep...
14:42:35.950 eit_set_update_filter, servicekey = 0x43700016d6e, current version 10
[controld] VIDEO_EVENT_SIZE_CHANGED 720x576 (4:3 -> 16:9)
14:44:01.020 EIT Update Filter: Activate cnThread
14:44:01.025 dmxCN: waking up again - requested from .change()
14:44:03.887 dmxCN: going to sleep...
14:44:03.919 eit_set_update_filter, servicekey = 0x44da4016f3b, current version 20
14:44:47.506 [sectionsd] DMX::readNbytes received POLLERR, pid 0x12, filter[5] filter 0x61 mask 0xf1
[neutrino] no file /var/tuxbox/config/recording.timer was found
[neutrino] no file /var/tuxbox/config/recording.start was found
[neutrino.cpp] getFreeDiscSpaceGB 18
[neutrino.cpp] trying to mount /hdd/filme
[neutrino.cpp] recording to /hdd/filme
Record channel_id: 43700016d6b epg: 43700016d6b178f, apids 0x0 mode 1
fsk:0, Genre:35, Dauer: 43
[stream2file]: ringbuffersize 4194304
[stream2file] allocated ringbuffer size: 4194303
[stream2file] filename: '/hdd/filme/ZDFinfokanal_Tierische_Kumpel__9__2009-06-07_150102.001.ts'
            myfilename: '/hdd/filme/ZDFinfokanal_Tierische_Kumpel__9__2009-06-07_150102'
15:01:03.591 dmxCN: waking up again - requested from .change()
15:01:05.303 dmxCN: going to sleep...
15:01:05.307 eit_set_update_filter, servicekey = 0x43700016d6b, current version 26
15:02:19.508 EIT Update Filter: Activate cnThread
15:02:19.519 dmxCN: waking up again - requested from .change()
15:02:21.407 dmxCN: going to sleep...
15:02:21.408 eit_set_update_filter, servicekey = 0x43700016d6b, current version 27
[timeThread] - 07.06.2009 15:11:15, tim: Sun Jun  7 15:11:15 2009
[timeThread] Time set via DVB, going to sleep for 1800 seconds.
15:19:03.120 EIT Update Filter: Activate cnThread
15:19:03.134 dmxCN: waking up again - requested from .change()
15:19:39.092 dmxCN: going to sleep...
15:19:39.093 eit_set_update_filter, servicekey = 0x43700016d6b, current version 28
[neutrino] no file /var/tuxbox/config/recording.timer was found
[neutrino] no file /var/tuxbox/config/recording.start was found
[timeThread] - 07.06.2009 15:41:21, tim: Sun Jun  7 15:41:21 2009
[timeThread] Time set via DVB, going to sleep for 1800 seconds.
[timerd] timer_wakeup = false; a.time: 1244381160 now: 1244382360
[timerd] not scheduling shutdown event
Stop
record time: 2698 
[mi] saveXml: /hdd/filme/ZDFinfokanal_Tierische_Kumpel__9__2009-06-07_150102.xml
saveFile:1074 saving TS movieinfo: ZDFinfokanal_Tierische_Kumpel__9__2009-06-07_150102.xml
[stream2file]: pthreads exit code: 1, dir: '/hdd/filme', filename: 'ZDFinfokanal_Tierische_Kumpel__9__2009-06-07_150102' myfilename: '/hdd/filme'
[neutrino.cpp] getFreeDiscSpaceGB 17
[neutrino.cpp] trying to mount /hdd/filme
[neutrino.cpp] recording to /hdd/filme
Record channel_id: 41ba4017034 epg: 41ba4017034b09c, apids 0x0 mode 1
fsk:0, Genre:191, Dauer: 30
[stream2file]: ringbuffersize 4194304
[stream2file] allocated ringbuffer size: 4194303
[stream2file] filename: '/hdd/filme/arte_X_enius_2009-06-07_154604.001.ts'
            myfilename: '/hdd/filme/arte_X_enius_2009-06-07_154604'
15:46:06.487 dmxCN: waking up again - requested from .change()
15:46:42.057 dmxCN: going to sleep...
15:46:42.059 eit_set_update_filter, servicekey = 0x44da4016f3b, current version 255
[timerd] timer_wakeup = false; a.time: 0 now: 1244383260
[timerd] not scheduling shutdown event
Stop
record time: 895 
[mi] saveXml: /hdd/filme/arte_X_enius_2009-06-07_154604.xml
saveFile:1074 saving TS movieinfo: arte_X_enius_2009-06-07_154604.xml
[stream2file]: pthreads exit code: 1, dir: '/hdd/filme', filename: 'arte_X_enius_2009-06-07_154604' myfilename: '/hdd/filme'
[neutrino] no file /var/tuxbox/config/recording.end was found
16:01:00.853 dmxCN: waking up again - requested from .change()
16:01:27.824 dmxCN: going to sleep...
16:01:27.853 eit_set_update_filter, servicekey = 0x41ba4017034, current version 16
16:01:38.753 [sectionsd] DMX::readNbytes received POLLERR, pid 0x12, filter[4] filter 0x60 mask 0xf1
16:01:43.230 [sectionsd] DMX::readNbytes received POLLERR, pid 0x12, filter[4] filter 0x60 mask 0xf1
16:01:49.439 [sectionsd] DMX::readNbytes received POLLERR, pid 0x12, filter[4] filter 0x60 mask 0xf1
16:01:54.732 [sectionsd] DMX::readNbytes received POLLERR, pid 0x12, filter[4] filter 0x60 mask 0xf1
16:01:59.790 [sectionsd] DMX::readNbytes received POLLERR, pid 0x12, filter[4] filter 0x60 mask 0xf1
16:02:10.051 [sectionsd] DMX::readNbytes received POLLERR, pid 0x12, filter[4] filter 0x60 mask 0xf1
16:02:20.178 [sectionsd] DMX::readNbytes received POLLERR, pid 0x12, filter[4] filter 0x60 mask 0xf1
16:02:52.791 [sectionsd] DMX::readNbytes received POLLERR, pid 0x12, filter[5] filter 0x61 mask 0xf1
[timeThread] - 07.06.2009 16:11:27, tim: Sun Jun  7 16:11:27 2009
[timeThread] Time set via DVB, going to sleep for 1800 seconds.

Dafür ist mir aber auch aufgefallen, dass die Box jetzt nach der zweiten Aufnahme auch nicht mehr auf dem _allerersten_ Sender, dem vor der ersten Aufnahme, war, sondern diesmal nach der Aufnahme einfach auf dem Sender der späteren Aufnahme geblieben ist. Vielleicht hatte die Software hier diesmal keine Zeit, noch zwischendurch zu zappen und damit einen Fehler zu verursachen...

Ich werd das mal im Auge behalten, eventuell kann ich ja nochmal mit einem mitgeloggten Auftreten dieses Fehlers dienen.

Gruß, xenonart

[xenonart]

Ich vermute, ich hab den Grund nun gefunden:

Bei Aufnahme 1 zeigt die Box ja nur noch die Sender in der Kanalliste, die kompatibel zum Aufnahmetransponder sind.

Wenn Aufnahme 2 nun direkt im Anschluss anfängt wegen Überschneidung, wird mit etwas Glück zwar richtig aufgenommen, aber die Box zappt, wenn Zeit genug ist, nach Aufnahme 1 auf den Sender, der vorher eingestellt war, evtl. sieht/hört man hier einfach nix, wenn der Transponder nicht passt, die Aufnahme ist dafür aber in Ordnung.

Ruft man jetzt aber die Kanalliste (während Aufnahme 2) auf, sieht man hier evtl. die für Aufnahme 1 passenden Kanäle, nicht die für Aufnahme 2 (hatte hier jetzt extra mal 2 verschiedene Transponder gewählt im unten gezeigten Fall). Will ich jetzt auf einen der (scheinbar) passenden Sender zappen während der Aufnahme, geht die Box einfach kommentarlos aus / startet neu - im Log steht nur:

18:19:43.441 dmxCN: waking up again - requested from .change()
zap failed!
showing epgid: 0x19d1 (6609)
Segmentation fault
zapit shot down
[eventserver]: connect (/tmp/neutrino.sock): Connection refused
[timerd] timer_wakeup = false; a.time: 0 now: 1244391600
[timerd] not scheduling shutdown event
Waiting for timerd (max. 5 seconds)
Waiting for timerd (max. 4 seconds)
Waiting for timerd (max. 3 seconds)
Waiting for timerd (max. 2 seconds)
Waiting for timerd (max. 1 seconds)
Going to halt system now ...

Diesen Fehler kann ich nun glaube ich wirklich relativ reproduzierbar erzeugen. Im Grunde stimmt bei einer Überlappung von zwei Aufnahmetimern bei mir einfach nicht mehr immer die Kanalliste in Aufgabe 2.

Komplettes Log hier:

Code: Alles auswählen

18:15:56.732 [sectionsd] DMX::readNbytes received POLLERR, pid 0x12, filter[4] filter 0x60 mask 0xf1
[neutrino] no file /var/tuxbox/config/recording.timer was found
no response from sectionsd
[neutrino] no file /var/tuxbox/config/recording.timer was found
[neutrino] no file /var/tuxbox/config/recording.start was found
[neutrino.cpp] getFreeDiscSpaceGB 16
[neutrino.cpp] trying to mount /hdd/filme
[neutrino.cpp] recording to /hdd/filme
Record channel_id: 43700016d66 epg: 43700016d66577b, apids 0x0 mode 1
fsk:0, Genre:32, Dauer: 75
[stream2file]: ringbuffersize 4194304
[stream2file] allocated ringbuffer size: 4194303
[stream2file] filename: '/hdd/filme/ZDF_Europawahl_2009_2009-06-07_181702.001.ts'
            myfilename: '/hdd/filme/ZDF_Europawahl_2009_2009-06-07_181702'
18:17:03.876 dmxCN: waking up again - requested from .change()
18:17:04.664 dmxCN: going to sleep...
18:17:04.668 eit_set_update_filter, servicekey = 0x43700016d66, current version 8
[neutrino] no file /var/tuxbox/config/recording.start was found
18:18:03.185 EIT Update Filter: Activate cnThread
18:18:03.191 dmxCN: waking up again - requested from .change()
18:18:39.032 dmxCN: going to sleep...
18:18:39.033 eit_set_update_filter, servicekey = 0x43700016d66, current version 9
[timerd] timer_wakeup = false; a.time: 1244391300 now: 1244391540
[timerd] not scheduling shutdown event
Stop
record time: 117 
[mi] saveXml: /hdd/filme/ZDF_Europawahl_2009_2009-06-07_181702.xml
saveFile:1074 saving TS movieinfo: ZDF_Europawahl_2009_2009-06-07_181702.xml
[stream2file]: pthreads exit code: 1, dir: '/hdd/filme', filename: 'ZDF_Europawahl_2009_2009-06-07_181702' myfilename: '/hdd/filme'
[neutrino.cpp] getFreeDiscSpaceGB 16
[neutrino.cpp] trying to mount /hdd/filme
[neutrino.cpp] recording to /hdd/filme
Record channel_id: 41ba4016f47 epg: 41ba4016f47b557, apids 0x0 mode 1
fsk:0, Genre:128, Dauer: 45
[stream2file]: ringbuffersize 4194304
[stream2file] allocated ringbuffer size: 4194303
[stream2file] filename: '/hdd/filme/BR-alpha_Omas_K_che_2009-06-07_181904.001.ts'
            myfilename: '/hdd/filme/BR-alpha_Omas_K_che_2009-06-07_181904'
18:19:05.909 dmxCN: waking up again - requested from .change()
zap failed!
18:19:41.629 dmxCN: going to sleep...
18:19:41.631 eit_set_update_filter, servicekey = 0x41ba4016f47, current version 1
18:19:43.441 dmxCN: waking up again - requested from .change()
zap failed!
showing epgid: 0x19d1 (6609)
Segmentation fault
zapit shot down :)
[eventserver]: connect (/tmp/neutrino.sock): Connection refused
[timerd] timer_wakeup = false; a.time: 0 now: 1244391600
[timerd] not scheduling shutdown event
Waiting for timerd (max. 5 seconds)
Waiting for timerd (max. 4 seconds)
Waiting for timerd (max. 3 seconds)
Waiting for timerd (max. 2 seconds)
Waiting for timerd (max. 1 seconds)
Going to halt system now ...
starting pid 357, tty '': '/etc/init.d/halt'
CXA2126 found
CXA2126 found
Unmounting 'ext2' on '/mnt/mmc'
Unmounting 'ext2' on '/hdd'
Unmounting 'tmpfs' on '/tmp'
umount: can't umount /tmp: Device or resource busy
Unmounting 'jffs2' on '/var'
umount: can't forcibly umount /var: Device or resource busy
Oops: umount failed :-(  --  trying to remount readonly...
Ready to shutdown system...
Connection closed by foreign host.

[Stingray]

Wie bereits erwähnt ist zwischen 2 Aufnahmen zwingend eine Pause zwischen den beiden Timern erforderlich.

[seife]

...zumindest anscheinend so lange, bis dieser Bug gefixt wird

Technisch gibt es keinen Grund, warum eine Pause notwendig wäre...

[schufti]

... und zumal es lange Zeit so funktioniert hat.

Dass jetzt eine Pause sein müßte, ist neu ....

[seife]

Ich vermute ja eine race-Condition und früher hat es "aus Versehen" funktioniert.