streamdev: Verbindung stirbt, wenn anderer Client zappt

owagner · 22. März 2011

Ein Zapvorgang ohne Nebenwirkungen:

Mar 22 19:58:28 tvserver vdr: [1905] TS buffer on device 2 thread ended (pid=1051, tid=1905)
Mar 22 19:58:28 tvserver vdr: [1904] buffer stats: 185556 (4%) used
Mar 22 19:58:28 tvserver vdr: [1904] receiver on device 2 thread ended (pid=1051, tid=1904)
Mar 22 19:58:28 tvserver vdr: [2095] receiver on device 2 thread started (pid=1051, tid=2095)
Mar 22 19:58:28 tvserver vdr: [2096] TS buffer on device 2 thread started (pid=1051, tid=2096)
Mar 22 19:58:31 tvserver vdr: [1903] streamdev-livestreaming thread ended (pid=1051, tid=1903)
Mar 22 19:58:31 tvserver kernel: [ 3794.797378] stb6100_set_bandwidth: Bandwidth=61262500
Mar 22 19:58:31 tvserver kernel: [ 3794.800672] stb6100_get_bandwidth: Bandwidth=62000000
Mar 22 19:58:31 tvserver kernel: [ 3794.811831] stb6100_get_bandwidth: Bandwidth=62000000
Mar 22 19:58:31 tvserver vdr: [2096] TS buffer on device 2 thread ended (pid=1051, tid=2096)
Mar 22 19:58:31 tvserver vdr: [2095] buffer stats: 92872 (2%) used
Mar 22 19:58:31 tvserver vdr: [2095] receiver on device 2 thread ended (pid=1051, tid=2095)
Mar 22 19:58:31 tvserver vdr: [1902] streamdev-writer thread ended (pid=1051, tid=1902)
Mar 22 19:58:31 tvserver vdr: [1080] buffer stats: 185932 (4%) used
Mar 22 19:58:31 tvserver vdr: [1080] buffer stats: 0 (0%) used
Mar 22 19:58:31 tvserver vdr: [1080] buffer stats: 0 (0%) used
Mar 22 19:58:31 tvserver vdr: [1080] Streamdev: Setting data connection to 192.168.0.7:53566
Mar 22 19:58:31 tvserver vdr: [2097] streamdev-writer thread started (pid=1051, tid=2097)
Mar 22 19:58:31 tvserver vdr: [2098] streamdev-livestreaming thread started (pid=1051, tid=2098)
Mar 22 19:58:31 tvserver vdr: [2099] receiver on device 2 thread started (pid=1051, tid=2099)
Mar 22 19:58:31 tvserver vdr: [2100] TS buffer on device 2 thread started (pid=1051, tid=2100)
Mar 22 19:58:31 tvserver kernel: [ 3794.888922] stb6100_set_frequency: Frequency=1236000
Mar 22 19:58:31 tvserver kernel: [ 3794.891203] stb6100_get_frequency: Frequency=1235988
Mar 22 19:58:31 tvserver kernel: [ 3794.900040] stb6100_get_bandwidth: Bandwidth=62000000
Mar 22 19:58:34 tvserver vdr: [1051] connect from 192.168.0.215, port 50172 - accepted
Mar 22 19:58:34 tvserver vdr: [2100] TS buffer on device 2 thread ended (pid=1051, tid=2100)
Mar 22 19:58:34 tvserver vdr: [2099] buffer stats: 51700 (1%) used
Mar 22 19:58:34 tvserver vdr: [2099] receiver on device 2 thread ended (pid=1051, tid=2099)
Mar 22 19:58:34 tvserver vdr: [2102] receiver on device 2 thread started (pid=1051, tid=2102)
Mar 22 19:58:34 tvserver vdr: [2103] TS buffer on device 2 thread started (pid=1051, tid=2103)
Mar 22 19:58:34 tvserver vdr: [1051] ERROR: no OSD provider available - using dummy OSD!
Mar 22 19:58:34 tvserver vdr: [1051] closing SVDRP connection

schmirl · 23. März 2011

Die frontends sind gleichwertig. Nun wäre noch ein Log vom Umschalten mit Nebenwirkung und -l3 spannend. Am besten ab dem Zeitpunkt zu dem sich der erste der beiden Clients verbindet, damit sich die Thread-IDs im Log dem jeweiligen Client eindeutig zuordnen lassen.

owagner · 27. März 2011

Gerade gab es Nebenwirkungen. Ich habe mit dem VLC den Kanal gewechselt (vulgo: Verbindung beendet und neu aufgerufen), danach stand dann der vdr-client.

192.168.0.7 ist der vdr-client
192.168.0.215 ist VLC

Log des Servers

Verbindungsaufbau

VDR:

Code

Mar 27 20:05:23 tvserver vdr: [1049] Streamdev: Accepted new client (VTP) 192.168.0.7:47641
Mar 27 20:05:23 tvserver vdr: [1049] streamdev-server TUNE S19.2E-1-1101-28106: Priority unknown - using 0
Mar 27 20:05:23 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 20:05:23 tvserver vdr: [1049] buffer stats: 0 (0%) used

VLC:

Code

Mar 27 21:43:40 tvserver vdr: [1049] Streamdev: Accepted new client (HTTP) 192.168.0.215:53464
Mar 27 21:43:41 tvserver vdr: [3326] streamdev-writer thread started (pid=1020, tid=3326)
Mar 27 21:43:41 tvserver vdr: [3327] streamdev-livestreaming thread started (pid=1020, tid=3327)
Mar 27 21:43:41 tvserver vdr: [3329] receiver on device 4 thread started (pid=1020, tid=3329)
Mar 27 21:43:41 tvserver vdr: [3330] TS buffer on device 4 thread started (pid=1020, tid=3330)
Mar 27 21:43:41 tvserver vdr: [3328] ecmhandler 3 filter thread started (pid=1020, tid=3328)

Vorfall:

Code

Mar 27 21:50:29 tvserver vdr: [2409] TS buffer on device 2 thread ended (pid=1020, tid=2409)
Mar 27 21:50:29 tvserver vdr: [2408] buffer stats: 137804 (3%) used
Mar 27 21:50:29 tvserver vdr: [2408] receiver on device 2 thread ended (pid=1020, tid=2408)
Mar 27 21:50:29 tvserver vdr: [1049] streamdev-server TUNE S19.2E-1-1101-28106: Priority unknown - using 0
Mar 27 21:50:29 tvserver vdr: [2407] streamdev-livestreaming thread ended (pid=1020, tid=2407)
Mar 27 21:50:29 tvserver vdr: [2406] streamdev-writer thread ended (pid=1020, tid=2406)
Mar 27 21:50:29 tvserver vdr: [1049] buffer stats: 206800 (5%) used
Mar 27 21:50:29 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:50:30 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:50:30 tvserver vdr: [1049] Streamdev: Setting data connection to 192.168.0.7:49495
Mar 27 21:50:30 tvserver vdr: [3414] streamdev-writer thread started (pid=1020, tid=3414)
Mar 27 21:50:30 tvserver vdr: [3415] streamdev-livestreaming thread started (pid=1020, tid=3415)
Mar 27 21:50:30 tvserver vdr: [3416] ecmhandler 2 filter thread started (pid=1020, tid=3416)
Mar 27 21:50:41 tvserver vdr: [1053] [general.error] action logger 0/7 read: Buffer overflow
Mar 27 21:50:41 tvserver vdr: [1087] [general.error] action logger 3/3 read: Buffer overflow
Mar 27 21:50:41 tvserver vdr: [1087] [general.error] action logger 3/4 read: Buffer overflow
Mar 27 21:50:41 tvserver vdr: [1087] [general.error] action logger 3/1 read: Buffer overflow
Mar 27 21:50:41 tvserver vdr: [1053] [general.error] action logger 0/8 read: Buffer overflow
Mar 27 21:50:41 tvserver vdr: [1053] [general.error] action logger 0/5 read: Buffer overflow
Mar 27 21:50:45 tvserver vdr: [1020] connect from 192.168.0.215, port 53622 - accepted
Mar 27 21:50:45 tvserver vdr: [1020] ERROR: no OSD provider available - using dummy OSD!
Mar 27 21:50:45 tvserver vdr: [1020] closing SVDRP connection
Mar 27 21:50:46 tvserver vdr: [1020] connect from 192.168.0.215, port 53623 - accepted
Mar 27 21:50:46 tvserver vdr: [1020] closing SVDRP connection
Mar 27 21:50:54 tvserver vdr: [1087] [general.error] action logger 3/3 read: Buffer overflow
Mar 27 21:50:54 tvserver vdr: [1087] [general.error] action logger 3/4 read: Buffer overflow
Mar 27 21:50:54 tvserver vdr: [1087] [general.error] action logger 3/1 read: Buffer overflow
Mar 27 21:50:55 tvserver vdr: [1086] [general.error] action logger 2/3 read: Buffer overflow
Mar 27 21:50:55 tvserver vdr: [1086] [general.error] action logger 2/4 read: Buffer overflow
Mar 27 21:50:55 tvserver vdr: [1086] [general.error] action logger 2/1 read: Buffer overflow
Mar 27 21:50:55 tvserver vdr: [1053] [general.error] action logger 0/7 read: Buffer overflow
Mar 27 21:50:55 tvserver vdr: [1053] [general.error] action logger 0/8 read: Buffer overflow
Mar 27 21:50:55 tvserver vdr: [1053] [general.error] action logger 0/5 read: Buffer overflow
Mar 27 21:51:02 tvserver vdr: [1086] [general.error] action logger 2/3 read: Buffer overflow
Mar 27 21:51:02 tvserver vdr: [1086] [general.error] action logger 2/4 read: Buffer overflow
Mar 27 21:51:02 tvserver vdr: [1086] [general.error] action logger 2/1 read: Buffer overflow
Mar 27 21:51:02 tvserver vdr: [1087] [general.error] action logger 3/3 read: Buffer overflow
Mar 27 21:51:02 tvserver vdr: [1087] [general.error] action logger 3/4 read: Buffer overflow
Mar 27 21:51:02 tvserver vdr: [1087] [general.error] action logger 3/1 read: Buffer overflow
Mar 27 21:51:03 tvserver vdr: [1020] connect from 192.168.0.7, port 33501 - accepted
Mar 27 21:51:03 tvserver vdr: [1020] closing SVDRP connection
Mar 27 21:51:06 tvserver vdr: [1020] connect from 192.168.0.215, port 53631 - accepted
Mar 27 21:51:07 tvserver vdr: [1020] closing SVDRP connection
Mar 27 21:51:09 tvserver vdr: [1086] [general.error] action logger 2/3 read: Buffer overflow
Mar 27 21:51:09 tvserver vdr: [1086] [general.error] action logger 2/4 read: Buffer overflow
Mar 27 21:51:09 tvserver vdr: [1086] [general.error] action logger 2/1 read: Buffer overflow
Mar 27 21:51:09 tvserver vdr: [1053] [general.error] action logger 0/7 read: Buffer overflow
Mar 27 21:51:09 tvserver vdr: [1087] [general.error] action logger 3/3 read: Buffer overflow
Mar 27 21:51:09 tvserver vdr: [1053] [general.error] action logger 0/8 read: Buffer overflow
Mar 27 21:51:09 tvserver vdr: [1087] [general.error] action logger 3/4 read: Buffer overflow
Mar 27 21:51:09 tvserver vdr: [1053] [general.error] action logger 0/5 read: Buffer overflow
Mar 27 21:51:09 tvserver vdr: [1087] [general.error] action logger 3/1 read: Buffer overflow
Mar 27 21:51:10 tvserver vdr: [1020] connect from 192.168.0.215, port 53632 - accepted
Mar 27 21:51:10 tvserver vdr: [1020] ERROR: no OSD provider available - using dummy OSD!
Mar 27 21:51:10 tvserver vdr: [1020] closing SVDRP connection
Mar 27 21:51:14 tvserver vdr: [1049] streamdev-server TUNE S19.2E-133-2-20: Priority unknown - using 0
Mar 27 21:51:16 tvserver vdr: [1087] [general.error] action logger 3/3 read: Buffer overflow
Mar 27 21:51:16 tvserver vdr: [1053] [general.error] action logger 0/7 read: Buffer overflow
Mar 27 21:51:16 tvserver vdr: [1087] [general.error] action logger 3/4 read: Buffer overflow
Mar 27 21:51:16 tvserver vdr: [1053] [general.error] action logger 0/8 read: Buffer overflow
Mar 27 21:51:16 tvserver vdr: [1087] [general.error] action logger 3/1 read: Buffer overflow
Mar 27 21:51:16 tvserver vdr: [1053] [general.error] action logger 0/5 read: Buffer overflow
Mar 27 21:51:16 tvserver vdr: [3415] streamdev-livestreaming thread ended (pid=1020, tid=3415)
Mar 27 21:51:16 tvserver vdr: [3414] streamdev-writer thread ended (pid=1020, tid=3414)
Mar 27 21:51:16 tvserver vdr: [1049] buffer stats: 144384 (3%) used
Mar 27 21:51:16 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:51:17 tvserver vdr: [1049] CAM 3: assigned to device 2
Mar 27 21:51:17 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:51:17 tvserver vdr: [1049] Streamdev: Setting data connection to 192.168.0.7:51125
Mar 27 21:51:17 tvserver vdr: [3421] streamdev-writer thread started (pid=1020, tid=3421)
Mar 27 21:51:17 tvserver vdr: [3422] streamdev-livestreaming thread started (pid=1020, tid=3422)
Mar 27 21:51:17 tvserver vdr: [3423] ecmhandler 1 filter thread started (pid=1020, tid=3423)
Mar 27 21:51:17 tvserver vdr: [3424] receiver on device 2 thread started (pid=1020, tid=3424)
Mar 27 21:51:17 tvserver vdr: [3425] TS buffer on device 2 thread started (pid=1020, tid=3425)
Mar 27 21:51:20 tvserver vdr: [3425] TS buffer on device 2 thread ended (pid=1020, tid=3425)
Mar 27 21:51:20 tvserver vdr: [3424] buffer stats: 30268 (0%) used
Mar 27 21:51:20 tvserver vdr: [3424] receiver on device 2 thread ended (pid=1020, tid=3424)
Mar 27 21:51:21 tvserver vdr: [3422] streamdev-livestreaming thread ended (pid=1020, tid=3422)
Mar 27 21:51:21 tvserver vdr: [3421] streamdev-writer thread ended (pid=1020, tid=3421)
Mar 27 21:51:21 tvserver vdr: [1049] buffer stats: 54520 (1%) used
Mar 27 21:51:21 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:51:23 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:51:23 tvserver vdr: [1049] Streamdev: Setting data connection to 192.168.0.7:52964
Mar 27 21:51:23 tvserver vdr: [3428] streamdev-livestreaming thread started (pid=1020, tid=3428)
Mar 27 21:51:23 tvserver vdr: [3427] streamdev-writer thread started (pid=1020, tid=3427)
Mar 27 21:51:23 tvserver vdr: [3429] receiver on device 2 thread started (pid=1020, tid=3429)
Mar 27 21:51:23 tvserver vdr: [3430] TS buffer on device 2 thread started (pid=1020, tid=3430)
Mar 27 21:51:23 tvserver vdr: [1086] [general.error] action logger 2/3 read: Buffer overflow
Mar 27 21:51:23 tvserver vdr: [1086] [general.error] action logger 2/4 read: Buffer overflow
Mar 27 21:51:23 tvserver vdr: [1086] [general.error] action logger 2/1 read: Buffer overflow
Mar 27 21:51:29 tvserver vdr: [1049] ERROR: read from client (HTTP) 192.168.0.215:53464 failed: Connection reset by peer
Mar 27 21:51:29 tvserver vdr: [1049] streamdev: closing streamdev connection to 192.168.0.215:53464
Mar 27 21:51:29 tvserver vdr: [3327] streamdev-livestreaming thread ended (pid=1020, tid=3327)
Mar 27 21:51:30 tvserver vdr: [1087] [general.error] action logger 3/3 read: Buffer overflow
Mar 27 21:51:30 tvserver vdr: [1087] [general.error] action logger 3/4 read: Buffer overflow
Mar 27 21:51:30 tvserver vdr: [1087] [general.error] action logger 3/1 read: Buffer overflow
Mar 27 21:51:30 tvserver vdr: [1086] [general.error] action logger 2/3 read: Buffer overflow
Mar 27 21:51:30 tvserver vdr: [1086] [general.error] action logger 2/4 read: Buffer overflow
Mar 27 21:51:30 tvserver vdr: [1053] [general.error] action logger 0/7 read: Buffer overflow
Mar 27 21:51:30 tvserver vdr: [1086] [general.error] action logger 2/1 read: Buffer overflow
Mar 27 21:51:30 tvserver vdr: [1053] [general.error] action logger 0/8 read: Buffer overflow
Mar 27 21:51:30 tvserver vdr: [1053] [general.error] action logger 0/5 read: Buffer overflow
Mar 27 21:51:30 tvserver vdr: [3330] TS buffer on device 4 thread ended (pid=1020, tid=3330)
Mar 27 21:51:30 tvserver vdr: [3329] buffer stats: 115808 (2%) used
Mar 27 21:51:30 tvserver vdr: [3329] receiver on device 4 thread ended (pid=1020, tid=3329)
Mar 27 21:51:33 tvserver vdr: [1049] ERROR: streamdev-writer thread 3326 won't end (waited 3 seconds) - canceling it...
Mar 27 21:51:33 tvserver vdr: [1049] buffer stats: 179164 (4%) used
Mar 27 21:51:33 tvserver vdr: [1049] Streamdev: Accepted new client (VTP) 192.168.0.7:53627
Mar 27 21:51:33 tvserver vdr: [1049] Streamdev: Accepted new client (HTTP) 192.168.0.215:53639
Mar 27 21:51:33 tvserver vdr: [1049] client (VTP) 192.168.0.7:52745 has closed connection
Mar 27 21:51:33 tvserver vdr: [1049] streamdev: closing streamdev connection to 192.168.0.7:52745
Mar 27 21:51:33 tvserver vdr: [3428] streamdev-livestreaming thread ended (pid=1020, tid=3428)
Mar 27 21:51:33 tvserver vdr: [3430] TS buffer on device 2 thread ended (pid=1020, tid=3430)
Mar 27 21:51:33 tvserver vdr: [3427] streamdev-writer thread ended (pid=1020, tid=3427)
Mar 27 21:51:33 tvserver vdr: [1049] buffer stats: 54520 (1%) used
Mar 27 21:51:33 tvserver vdr: [3429] buffer stats: 32712 (0%) used
Mar 27 21:51:33 tvserver vdr: [3429] receiver on device 2 thread ended (pid=1020, tid=3429)
Mar 27 21:51:33 tvserver vdr: [2185] streamdev-filterstreaming thread ended (pid=1020, tid=2185)
Mar 27 21:51:33 tvserver vdr: [2184] streamdev-writer thread ended (pid=1020, tid=2184)
Mar 27 21:51:33 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:51:33 tvserver vdr: [1049] client (VTP) 192.168.0.7:53627 has closed connection
Mar 27 21:51:33 tvserver vdr: [1049] streamdev: closing streamdev connection to 192.168.0.7:53627
Mar 27 21:51:33 tvserver vdr: [3433] streamdev-livestreaming thread started (pid=1020, tid=3433)
Mar 27 21:51:33 tvserver vdr: [3432] streamdev-writer thread started (pid=1020, tid=3432)
Mar 27 21:51:33 tvserver vdr: [3434] receiver on device 4 thread started (pid=1020, tid=3434)
Mar 27 21:51:33 tvserver vdr: [3435] TS buffer on device 4 thread started (pid=1020, tid=3435)
Mar 27 21:51:34 tvserver vdr: [1049] Streamdev: Accepted new client (VTP) 192.168.0.7:56379
Mar 27 21:51:34 tvserver vdr: [1049] streamdev-server TUNE S19.2E-1-1107-17506: Priority unknown - using 0
Mar 27 21:51:34 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:51:34 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:51:35 tvserver vdr: [1049] client (HTTP) 192.168.0.215:53639 has closed connection
Mar 27 21:51:35 tvserver vdr: [1049] streamdev: closing streamdev connection to 192.168.0.215:53639
Mar 27 21:51:35 tvserver vdr: [3433] streamdev-livestreaming thread ended (pid=1020, tid=3433)
Mar 27 21:51:35 tvserver vdr: [3435] TS buffer on device 4 thread ended (pid=1020, tid=3435)
Mar 27 21:51:35 tvserver vdr: [3434] buffer stats: 28012 (0%) used
Mar 27 21:51:35 tvserver vdr: [3434] receiver on device 4 thread ended (pid=1020, tid=3434)
Mar 27 21:51:35 tvserver vdr: [3432] streamdev-writer thread ended (pid=1020, tid=3432)
Mar 27 21:51:35 tvserver vdr: [1049] buffer stats: 67680 (1%) used
Mar 27 21:51:35 tvserver vdr: [1049] Streamdev: Accepted new client (HTTP) 192.168.0.215:53651
Mar 27 21:51:35 tvserver vdr: [3436] streamdev-writer thread started (pid=1020, tid=3436)
Mar 27 21:51:35 tvserver vdr: [3437] streamdev-livestreaming thread started (pid=1020, tid=3437)
Mar 27 21:51:35 tvserver vdr: [3438] receiver on device 4 thread started (pid=1020, tid=3438)
Mar 27 21:51:35 tvserver vdr: [3439] TS buffer on device 4 thread started (pid=1020, tid=3439)
Mar 27 21:51:37 tvserver vdr: [1049] streamdev-server TUNE S19.2E-1-1107-17506: Priority unknown - using 0
Mar 27 21:51:37 tvserver vdr: [1049] streamdev-server TUNE S19.2E-1-1107-17506: Priority unknown - using 0
Mar 27 21:51:37 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:51:37 tvserver vdr: [1049] CAM 3: unassigned
ar 27 21:51:37 tvserver vdr: [1049] CAM 3: unassigned
Mar 27 21:51:37 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:51:37 tvserver vdr: [1049] Streamdev: Setting data connection to 192.168.0.7:60214
Mar 27 21:51:37 tvserver vdr: [3440] streamdev-writer thread started (pid=1020, tid=3440)
Mar 27 21:51:37 tvserver vdr: [3441] streamdev-filterstreaming thread started (pid=1020, tid=3441)
Mar 27 21:51:37 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:51:37 tvserver vdr: [1049] Streamdev: Setting data connection to 192.168.0.7:56703
Mar 27 21:51:37 tvserver vdr: [3442] streamdev-writer thread started (pid=1020, tid=3442)
Mar 27 21:51:37 tvserver vdr: [3443] streamdev-livestreaming thread started (pid=1020, tid=3443)
Mar 27 21:51:37 tvserver vdr: [3444] receiver on device 2 thread started (pid=1020, tid=3444)
Mar 27 21:51:37 tvserver vdr: [3445] TS buffer on device 2 thread started (pid=1020, tid=3445)
Mar 27 21:51:39 tvserver vdr: [3445] TS buffer on device 2 thread ended (pid=1020, tid=3445)
Mar 27 21:51:39 tvserver vdr: [3444] buffer stats: 40420 (0%) used
Mar 27 21:51:39 tvserver vdr: [3444] receiver on device 2 thread ended (pid=1020, tid=3444)
Mar 27 21:51:39 tvserver vdr: [1049] streamdev-server TUNE S19.2E-1-1089-12003: Priority unknown - using 0
Mar 27 21:51:39 tvserver vdr: [3443] streamdev-livestreaming thread ended (pid=1020, tid=3443)
Mar 27 21:51:39 tvserver vdr: [3442] streamdev-writer thread ended (pid=1020, tid=3442)
Mar 27 21:51:39 tvserver vdr: [1049] buffer stats: 44744 (1%) used
Mar 27 21:51:39 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:51:39 tvserver vdr: [1049] CAM 3: assigned to device 2
Mar 27 21:51:39 tvserver vdr: [1049] buffer stats: 0 (0%) used
Mar 27 21:51:39 tvserver vdr: [1049] Streamdev: Setting data connection to 192.168.0.7:41170
Mar 27 21:51:39 tvserver vdr: [3447] streamdev-writer thread started (pid=1020, tid=3447)
Mar 27 21:51:39 tvserver vdr: [3448] streamdev-livestreaming thread started (pid=1020, tid=3448)
Mar 27 21:51:39 tvserver vdr: [3449] receiver on device 2 thread started (pid=1020, tid=3449)
Mar 27 21:51:39 tvserver vdr: [3450] TS buffer on device 2 thread started (pid=1020, tid=3450)

Alles anzeigen

Log des VDR-Clients:

Code

Mar 27 21:50:28 bedpcu vdr: [2070] ERROR (device.c,1671): Bad file descriptor
Mar 27 21:50:28 bedpcu vdr: [2070] TS buffer on device 10 thread ended (pid=1544, tid=2070)
Mar 27 21:50:28 bedpcu vdr: [2071] buffer stats: 232556 (11%) used
Mar 27 21:50:28 bedpcu vdr: [2071] receiver on device 10 thread ended (pid=1544, tid=2071)
Mar 27 21:50:29 bedpcu vdr: [2443] TS buffer on device 10 thread started (pid=1544, tid=2443)
Mar 27 21:50:29 bedpcu vdr: [2444] receiver on device 10 thread started (pid=1544, tid=2444)
Mar 27 21:50:29 bedpcu vdr: [2442] EnigmaNG effects thread ended (pid=1544, tid=2442)
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] PMT changed, resetting demuxer
Mar 27 21:50:29 bedpcu vdr: [2445] EnigmaNG effects thread started (pid=1544, tid=2445)
Mar 27 21:50:29 bedpcu vdr: [1544] EnigmaNG: cPluginSkinEnigma::LoadChannelLogo: LOGO "Channel.xpm" NOT FOUND in ./plugins/skinenigmang/logos
Mar 27 21:50:29 bedpcu vdr: [1544] EnigmaNG: cPluginSkinEnigma::LoadXpm(./plugins/skinenigmang/logos/no_logo.xpm) LOGO NOT FOUND
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: payload not PES ?
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: dropping broken PES packet
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: payload not PES ?
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: dropping broken PES packet
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: payload not PES ?
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: dropping broken PES packet
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: payload not PES ?
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: dropping broken PES packet
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: payload not PES ?
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: dropping broken PES packet
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: payload not PES ?
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: payload not PES ?
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: dropping broken PES packet
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: dropping broken PES packet
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: payload not PES ?
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: dropping broken PES packet
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: payload not PES ?
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: dropping broken PES packet
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: payload not PES ?
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: dropping broken PES packet
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: payload not PES ?
Mar 27 21:50:29 bedpcu vdr: [1556] [demux_vdr] ts2es: dropping broken PES packet

Alles anzeigen

schmirl · 28. März 2011

Zu welchem Zeitpunkt im langen "Vorfall"-Log schaltet VLC denn um? Ich vermute, das hier ist der richtige Zeitraum?

Zitat

Mar 27 21:51:29 tvserver vdr: [1049] ERROR: read from client (HTTP) 192.168.0.215:53464 failed: Connection reset by peer
...
Mar 27 21:51:33 tvserver vdr: [1049] Streamdev: Accepted new client (HTTP) 192.168.0.215:53639

Zwischen den beiden Zeilen werden nur Threads mit IDs zwischen 3326 und 3330 beendet. Das sind genau die Threads die nach dem Verbindungsaufbau von VLC gestartet wurden. Passt also soweit.

Der mögliche Verursacher des Problems könnte in dieser Zeile liegen:

Zitat

Mar 27 21:51:33 tvserver vdr: [1049] ERROR: streamdev-writer thread 3326 won't end (waited 3 seconds) - canceling it...

Der streamdev-server ist 3 Sekunden blockiert, da er auf das Beenden der HTTP-Netzwerk-Verbindung wartet. Sollte nun innerhalb dieser Zeit der VDR-Client irgendetwas vom Server anfordern, läuft dieser Befehl wegen des Timeouts von 1,5 Sekunden auf einen Fehler und beendet die Verbindung.

Ich werden in den nächsten Tagen auf jeden Fall den Fehler beheben, dass sich der streamdev-writer thread nicht zeitnah beendet. Falls Du schon vorher experimentieren willst, könntest Du den Timeout auf dem Client von 1,5 auf 4 Sekunden erhöhen. Du musst folgende Zeile in der Datei client/socket.h anpassen:

Code

bool Command(const std::string &Command, uint Expected = 0, uint TimeoutMs = 1500);

woz · 29. März 2011

Hallo Schmirl,

... das war's! Es funktioniert!!!

Ich hab die Änderung eingebracht und es funzt. Dann nochmal zurück und Fehler ist wieder da!

Es ist nachvollziehbar: Immer wenn am Server:

Code

Mar 29 16:14:59 debian vdr: [8432] ERROR: read from client (HTTP) 192.168.6.145:1132 failed: Die Verbindung wurde vom Kommunikationspartner zurÃ¼ckgesetzt
Mar 29 16:14:59 debian vdr: [8432] streamdev: closing streamdev connection to 192.168.6.145:1132
Mar 29 16:14:59 debian vdr: [8962] streamdev-livestreaming thread ended (pid=8400, tid=8962)
Mar 29 16:15:00 debian vdr: [8964] TS buffer on device 3 thread ended (pid=8400, tid=8964)
Mar 29 16:15:00 debian vdr: [8963] buffer stats: 146452 (3%) used
Mar 29 16:15:00 debian vdr: [8963] receiver on device 3 thread ended (pid=8400, tid=8963)
Mar 29 16:15:02 debian vdr: [8432] ERROR: streamdev-writer thread 8961 won't end (waited 3 seconds) - canceling it...

dann kommt am Client:

Code

Mar 29 16:15:01 ubuntu vdr: [1974] Streamdev: Lost connection to 192.168.6.15:2004: Die Wartezeit fÃ¼r die Verbindung ist abgelaufen

vG
WoZ

owagner · 29. März 2011

Ich habe den Patch mal eingebaut. Vielen lieben Dank!

Mein zweites Problem -- dass der VLC-Client nach einiger Zeit ständig Ring Buffer Overflows hat und diese irgendwann als Decoding-Fehler sichtbar werden, hat damit dann wahrscheinlich nichts zu tun. Vielleicht habe ich mir hier auch den Zusammenhang zwischen Umschalten und Eintreten des Fehlers eingebildet. Ich werde das weiter beobachten.

Viele Grüße,
Olli

schmirl · 12. April 2011

Habe gestern den Bugfix für den Server eingecheckt. Der verlängerte Timeout im Client kann damit wieder raus.

woz · 14. April 2011

Hallo Schmirl,

viene Dank! Ich werde dann mal den Compiler anwerfen!
Willst Du eigentlich auch das suspend - Verhalten (dieser Patch) über das setup konfigurierbar machen?

vG
Wolfgang

decembersoul · 11. Mai 2011

Ich weiß nicht ob es das selbe Problem ist aber zumindest der Titel passt.
Ich habe streamdev server mit git von heute und zwei Streamdev Clients.

Nach ein paar Minuten bleibt das Bild beim Client stehen.

Server

Code

May 11 23:16:07 server vdr: [8995] frontend 3/0 timed out while tuning to channel 146, tp 112574
May 11 23:16:07 server vdr: [9006] client (VTP) 192.168.1.111:57719 has closed connection
May 11 23:16:07 server vdr: [9006] streamdev: closing streamdev connection to 192.168.1.111:57719
May 11 23:16:07 server vdr: [9263] streamdev-livestreaming thread ended (pid=8986, tid=9263)
May 11 23:16:07 server vdr: [9262] streamdev-writer thread ended (pid=8986, tid=9262)
May 11 23:16:07 server vdr: [9006] buffer stats: 126712 (3%) used
May 11 23:16:07 server vdr: [9261] streamdev-filterstreaming thread ended (pid=8986, tid=9261)
May 11 23:16:07 server vdr: [9266] TS buffer on device 2 thread ended (pid=8986, tid=9266)
May 11 23:16:07 server vdr: [9265] buffer stats: 93060 (2%) used
May 11 23:16:07 server vdr: [9265] receiver on device 2 thread ended (pid=8986, tid=9265)
May 11 23:16:07 server vdr: [9260] streamdev-writer thread ended (pid=8986, tid=9260)
May 11 23:16:07 server vdr: [9006] buffer stats: 0 (0%) used
May 11 23:16:07 server vdr: [9006] Streamdev: Accepted new client (VTP) 192.168.1.111:36566
May 11 23:16:08 server vdr: [9006] streamdev-server TUNE S19.2E-133-2-11: Priority unknown - using 0
May 11 23:16:08 server vdr: [9006] LNB 2: Request for channel 55 on device 2. MaxBadPriority is -2
May 11 23:16:08 server vdr: [9006] LNB 2: ProvidesChannel 55 on device 2. Priority is 0, hasPriority is 1
May 11 23:16:08 server vdr: [9006] LNB 2: Request for channel 55 on device 2. MaxBadPriority is -2

Alles anzeigen

Client

Code

May 11 23:15:57 zen2vdr-r2 user.err vdr: [874] cStreamdevFilter::PutSection socket overflow, Pid   18 Tid  64
May 11 23:15:57 zen2vdr-r2 user.err vdr: [874] cStreamdevFilter::PutSection socket overflow, Pid   18 Tid  64
May 11 23:15:57 zen2vdr-r2 user.err vdr: [874] cStreamdevFilter::PutSection socket overflow, Pid   18 Tid  64
May 11 23:16:02 zen2vdr-r2 user.err vdr: [479] Streamdev: Lost connection to 192.168.1.2:2004: Connection timed out
May 11 23:16:03 zen2vdr-r2 user.err vdr: [876] cStreamDevice::GetTSPacket: GetChecked: NOTHING (0)
May 11 23:16:03 zen2vdr-r2 user.err vdr: [874] Streamdev: Connected to server 192.168.1.2:2004 using capabilities TSPIDS,FILTERS
May 11 23:16:03 zen2vdr-r2 user.err vdr: [874] Streamdev: Filter 101, 2, 255 not available from 192.168.1.111:36566
May 11 23:16:03 zen2vdr-r2 user.err vdr: [876] cStreamDevice::GetTSPacket: GetChecked: NOTHING (1)
May 11 23:16:03 zen2vdr-r2 user.err vdr: [876] cStreamDevice::GetTSPacket: GetChecked: NOTHING (2)
May 11 23:16:03 zen2vdr-r2 user.err vdr: [876] cStreamDevice::GetTSPacket: GetChecked: NOTHING (3)
May 11 23:16:03 zen2vdr-r2 user.err vdr: [876] cStreamDevice::GetTSPacket: GetChecked: NOTHING (4)
May 11 23:16:03 zen2vdr-r2 user.err vdr: [876] cStreamDevice::GetTSPacket: GetChecked: NOTHING (5)
May 11 23:16:03 zen2vdr-r2 user.err vdr: [876] cStreamDevice::GetTSPacket: GetChecked: NOTHING (6)
May 11 23:16:03 zen2vdr-r2 user.err vdr: [876] cStreamDevice::GetTSPacket: GetChecked: NOTHING (7)
May 11 23:16:04 zen2vdr-r2 user.err vdr: [876] cStreamDevice::GetTSPacket: GetChecked: NOTHING (8)
May 11 23:16:04 zen2vdr-r2 user.err vdr: [876] cStreamDevice::GetTSPacket: GetChecked: NOTHING (9)
May 11 23:16:04 zen2vdr-r2 user.err vdr: [876] cStreamDevice::GetTSPacket: GetChecked: NOTHING (10)
May 11 23:16:04 zen2vdr-r2 user.err vdr: [876] cStreamdevDevice::GetTSPacket(): disconnected
May 11 23:16:04 zen2vdr-r2 user.err vdr: [874] cStreamdevFilters::Action(): stream disconnected ?

Alles anzeigen

setup.conf vom Server

Code

..
Card1usesLNBnr = 1
Card2usesLNBnr = 2
Card3usesLNBnr = 3
Card4usesLNBnr = 4
..
DiSEqC = 1
..
LnbFrequHi = 10600
LnbFrequLo = 9750
LnbSLOF = 11700
..
UpdateChannels = 3
..
VerboseLNBlog = 1
..


streamdev-server.AllowSuspend = 0
streamdev-server.HTTPBindIP = 0.0.0.0
streamdev-server.HTTPServerPort = 3000
streamdev-server.HTTPStreamType = 4
streamdev-server.IGMPBindIP = 0.0.0.0
streamdev-server.IGMPClientPort = 1234
streamdev-server.IGMPStreamType = 0
streamdev-server.MaxClients = 99
streamdev-server.ServerPort = 2004
streamdev-server.StartHTTPServer = 1
streamdev-server.StartIGMPServer = 0
streamdev-server.StartServer = 1
streamdev-server.SuspendMode = 1
streamdev-server.VTPBindIP = 0.0.0.0

Alles anzeigen

Der Client in diesem Beispiel ist ein 0.5.0-pre aber ich habe das selbe Problem mit einem yavdr Client der eine recht aktuelle Version hat.

Jemand eine Idee?

decembersoul · 12. Mai 2011

Ich habe nun erst mal den EPG Scan Timer auf 0 gesetzt

Code

EPGScanTimeout = 0

Scheinbar keine Aussetzer mehr.
Ist aber auch keine echte Lösung.
Kann zwar nun den EPG Scan per Cron Job machen aber so toll finde ich das nicht.

schmirl · 16. Mai 2011

Wie - Dein Client startet einen epgscan über streamdev-client während Du über streamdev-client Live-TV schaust?

Ob Dein yavdr schon den in diesem Thread diskutierten Fix beinhaltet, weiß ich nicht. Wenn die Meldungen exakt die selben sind, dann eher nicht. Auch die Server-Version spielt eine Rolle. Um auf Nummer sicher zu gehen, könntest Du im Client mal den Workaround aus meinem Posting von oben versuchen. Setze den Timeout aber gleich auf 10000 Millisekunden.

decembersoul · 16. Mai 2011

Nein der Client startet keinen EPG Scan.
Die oben genannten Einstellungen habe ich beim Server gemacht.

Der Server von Yavdr war relativ aktuell, es fehlt nur noch die letzte Änderung die jedoch nur noch den Patch etwas optimiert. Aber wie gesagt, der Server ist jetzt auf den neusten git Stand.
Ich werde heute noch mal ein Wireshark trace machen. Mal sehen welche Seite zuerst aufhört Daten zu senden.
Das Problem ist wohl immer noch da jedoch nicht mehr so Häufig.

decembersoul · 16. Mai 2011

So ich habe nun mal einen Wireshark Trace gemacht.
Für mich sieht es so aus als wenn alles OK läuft.

Kennt sich da jemand besser aus und hat Lust den Trace zu analysieren?
Könnte mit Syslog auf Client und Server Seite + Wireshare Trace dienen.

schmirl · 17. Mai 2011

Nur her mit Log und Trace (kann aber ein wenig dauern bis ich dafür Zeit finde)

streamdev: Verbindung stirbt, wenn anderer Client zappt

Jetzt mitmachen!

Teilen