Bug #5230
Same adapter repeatedly chosen on error
0%
Description
My adapter had some problem.
I expected my recording to failover to the next adapter until it found one that was working. Instead the log suggests it was only trying the same adapter repeatedly.
I have "restart on error" enabled and "switch to another service" enabled; preferred service "HD"; different services from different adapters/sources all mapped to the same channel; multiple adapters with different priorities.
I believe the log is showing that I have multiple services available to choose from for the recording.
I don't know if it's my combination of options?
(I have different adapter priorities since some channels are shown on all adapters and some only on a subset).
2018-09-29 20:10:17.336 [ INFO]:mpegts: 545.833MHz in DVB-T Network - tuning on Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) 2018-09-29 20:10:17.336 [ DEBUG]:linuxdvb: Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) - starting 545.833MHz in DVB-T Network 2018-09-29 20:10:17.337 [WARNING]:subscription: 0002: restarting channel BBC ONE 2018-09-29 20:10:19.353 [ DEBUG]:service: 6: BBC ONE si 0x8102e9000 Technisat SkyStar USB HD (DVB-S/S2) #4 : DVB-S #0 weight 0 prio 55 error 0 2018-09-29 20:10:19.353 [ DEBUG]:service: 6: BBC ONE si 0x8102e90c0 Technisat SkyStar USB HD (DVB-S/S2) #4 : DVB-S #0 weight 0 prio 57 error 0 2018-09-29 20:10:19.353 [ DEBUG]:service: 3: BBC ONE si 0x8102e9180 Panasonic MN88473 #2 : DVB-T #0 (astrometa) weight 0 prio 90 error 0 2018-09-29 20:10:19.354 [ DEBUG]:service: 3: BBC ONE si 0x80febf640 Panasonic MN88473 #2 : DVB-T #0 (astrometa) weight 0 prio 90 error 0 2018-09-29 20:10:19.354 [ DEBUG]:service: 7: BBC ONE si 0x80fab53c0 Technisat SkyStar USB HD (DVB-S/S2) #5 : DVB-S #0 weight 0 prio 199 error 0 2018-09-29 20:10:19.354 [ DEBUG]:service: 7: BBC ONE si 0x80febd9c0 Technisat SkyStar USB HD (DVB-S/S2) #5 : DVB-S #0 weight 0 prio 201 error 0 2018-09-29 20:10:19.354 [ DEBUG]:service: 9: BBC ONE si 0x80fab5240 Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) weight 0 prio 270 error 0 2018-09-29 20:10:19.354 [ DEBUG]:service: 9: BBC ONE si 0x80fab5300 Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) weight 0 prio 270 error 0 2018-09-29 20:10:19.355 [ INFO]:mpegts: 545.833MHz in DVB-T Network - tuning on Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) 2018-09-29 20:10:19.355 [ DEBUG]:linuxdvb: Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) - starting 545.833MHz in DVB-T Network 2018-09-29 20:10:19.355 [WARNING]:subscription: 0002: restarting channel BBC ONE 2018-09-29 20:10:21.363 [ DEBUG]:service: 6: BBC ONE si 0x8102e90c0 Technisat SkyStar USB HD (DVB-S/S2) #4 : DVB-S #0 weight 0 prio 55 error 0 2018-09-29 20:10:21.363 [ DEBUG]:service: 6: BBC ONE si 0x80febf640 Technisat SkyStar USB HD (DVB-S/S2) #4 : DVB-S #0 weight 0 prio 57 error 0 2018-09-29 20:10:21.364 [ DEBUG]:service: 3: BBC ONE si 0x80febd9c0 Panasonic MN88473 #2 : DVB-T #0 (astrometa) weight 0 prio 90 error 0 2018-09-29 20:10:21.364 [ DEBUG]:service: 3: BBC ONE si 0x80fab5300 Panasonic MN88473 #2 : DVB-T #0 (astrometa) weight 0 prio 90 error 0 2018-09-29 20:10:21.364 [ DEBUG]:service: 7: BBC ONE si 0x8102e9000 Technisat SkyStar USB HD (DVB-S/S2) #5 : DVB-S #0 weight 0 prio 199 error 0 2018-09-29 20:10:21.364 [ DEBUG]:service: 7: BBC ONE si 0x8102e9180 Technisat SkyStar USB HD (DVB-S/S2) #5 : DVB-S #0 weight 0 prio 201 error 0 2018-09-29 20:10:21.365 [ DEBUG]:service: 9: BBC ONE si 0x80fab53c0 Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) weight 0 prio 270 error 0 2018-09-29 20:10:21.365 [ DEBUG]:service: 9: BBC ONE si 0x80fab5240 Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) weight 0 prio 270 error 0 2018-09-29 20:10:21.365 [ INFO]:mpegts: 545.833MHz in DVB-T Network - tuning on Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) 2018-09-29 20:10:21.365 [ DEBUG]:linuxdvb: Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) - starting 545.833MHz in DVB-T Network 2018-09-29 20:10:21.365 [WARNING]:subscription: 0002: restarting channel BBC ONE 2018-09-29 20:10:23.374 [ DEBUG]:service: 6: BBC ONE si 0x80febf640 Technisat SkyStar USB HD (DVB-S/S2) #4 : DVB-S #0 weight 0 prio 55 error 0 2018-09-29 20:10:23.374 [ DEBUG]:service: 6: BBC ONE si 0x80fab5300 Technisat SkyStar USB HD (DVB-S/S2) #4 : DVB-S #0 weight 0 prio 57 error 0 2018-09-29 20:10:23.375 [ DEBUG]:service: 3: BBC ONE si 0x8102e9180 Panasonic MN88473 #2 : DVB-T #0 (astrometa) weight 0 prio 90 error 0 2018-09-29 20:10:23.375 [ DEBUG]:service: 3: BBC ONE si 0x80fab5240 Panasonic MN88473 #2 : DVB-T #0 (astrometa) weight 0 prio 90 error 0 2018-09-29 20:10:23.375 [ DEBUG]:service: 7: BBC ONE si 0x8102e90c0 Technisat SkyStar USB HD (DVB-S/S2) #5 : DVB-S #0 weight 0 prio 199 error 0 2018-09-29 20:10:23.375 [ DEBUG]:service: 7: BBC ONE si 0x80febd9c0 Technisat SkyStar USB HD (DVB-S/S2) #5 : DVB-S #0 weight 0 prio 201 error 0 2018-09-29 20:10:23.376 [ DEBUG]:service: 9: BBC ONE si 0x8102e9000 Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) weight 0 prio 270 error 0 2018-09-29 20:10:23.376 [ DEBUG]:service: 9: BBC ONE si 0x80fab53c0 Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) weight 0 prio 270 error 0 2018-09-29 20:10:23.376 [ INFO]:mpegts: 545.833MHz in DVB-T Network - tuning on Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) 2018-09-29 20:10:23.376 [ DEBUG]:linuxdvb: Panasonic MN88472 #1 : DVB-T #0 (xbox tuner) - starting 545.833MHz in DVB-T Network 2018-09-29 20:10:23.376 [WARNING]:subscription: 0002: restarting channel BBC ONE
Files
History
Updated by Em Smith about 6 years ago
I retried on my test system which has same priority across all adapters and managed to replicate.
I've done a bit more testing by running a w_scan on my two adapters (to make the adapters busy), then doing a recording with different streaming settings in Tvheadend.
With restartonerror=0, switchtootherservice=1, tvheadend chose service 5 (error 203), service 8 (error 203), then would never reset the error codes to retry them so would report "no source available."
With restartonerror=1, switchtootherservice=1, it started service 5, then service 8, then kept repeating service 5, rather than going 5, 8, 5, 8. This is what appeared to happen last night except in that case I had more adapters available and it only chose adapters 1,2,1,1,1,1 and not adapters 1,2,3,4,5,1,2,3,4,5.
restart on error=0, switch to to other service=1
2018-09-30 11:19:20.891 [ INFO] dvr: entry 479ff216bbd30b0ec3fa2ef78626110b "Police Interceptors" on "5Spike" starting at 2018-09-30 10:34:30, with broadcast id "crid://www.five .tv/V4LTU", scheduled for recording by "192.168.1.217" 2018-09-30 11:19:20.891 [ INFO] dvr: "Police Interceptors" on "5Spike" recorder starting 2018-09-30 11:19:20.901 [ INFO] service: 8: 5Spike si 0x81459bb40 Realtek RTL2832 (DVB-T) #3 : master for #0 weight 0 prio 10 error 0 2018-09-30 11:19:20.902 [ INFO] service: 5: 5Spike si 0x81459bcc0 Panasonic MN88473 #2 : master for #0 weight 0 prio 10 error 0 2018-09-30 11:19:20.902 [ INFO] service: will start new instance 5 2018-09-30 11:19:20.902 [ INFO] mpegts: 529.833MHz in DVB-T Network - tuning on Panasonic MN88473 #2 : master for #0 2018-09-30 11:19:20.902 [ INFO] spawn: Executing "/usr/local/bin/tvhmeta" 2018-09-30 11:19:20.903 [ ERROR] service: tuning failed with error 203 (0) 2018-09-30 11:19:22.920 [ INFO] service: 8: 5Spike si 0x81459bb40 Realtek RTL2832 (DVB-T) #3 : master for #0 weight 0 prio 10 error 0 2018-09-30 11:19:22.920 [ INFO] service: 5: 5Spike si 0x81459bcc0 Panasonic MN88473 #2 : master for #0 weight 0 prio 10 error 203 2018-09-30 11:19:22.920 [ INFO] service: will start new instance 8 2018-09-30 11:19:22.920 [ INFO] mpegts: 529.833MHz in DVB-T Network - tuning on Realtek RTL2832 (DVB-T) #3 : master for #0 2018-09-30 11:19:22.920 [ ERROR] service: tuning failed with error 203 (0) 2018-09-30 11:19:22.920 [ NOTICE] subscription: 0004: No input source available for subscription "DVR: Police Interceptors" to channel "5Spike" 2018-09-30 11:19:22.921 [ ERROR] dvr: Recording unable to start: "Police Interceptors": Tuning failed 2018-09-30 11:19:24.932 [ INFO] service: ****Enlist all instances 2018-09-30 11:19:24.933 [ INFO] service: 8: 5Spike si 0x81459bb40 Realtek RTL2832 (DVB-T) #3 : master for #0 weight 0 prio 10 error 203 2018-09-30 11:19:24.933 [ INFO] service: 5: 5Spike si 0x81459bcc0 Panasonic MN88473 #2 : master for #0 weight 0 prio 10 error 203 2018-09-30 11:19:24.933 [ INFO] service: ****!si 2018-09-30 11:19:26.952 [ INFO] service: ****Enlist all instances 2018-09-30 11:19:26.953 [ INFO] service: 8: 5Spike si 0x81459bb40 Realtek RTL2832 (DVB-T) #3 : master for #0 weight 0 prio 10 error 203 2018-09-30 11:19:26.953 [ INFO] service: 5: 5Spike si 0x81459bcc0 Panasonic MN88473 #2 : master for #0 weight 0 prio 10 error 203 2018-09-30 11:19:26.953 [ INFO] service: ****!si 2018-09-30 11:19:26.953 [ NOTICE] subscription: 0004: No input source available for subscription "DVR: Police Interceptors" to channel "5Spike" 2018-09-30 11:19:26.953 [ ERROR] dvr: Recording unable to start: "Police Interceptors": No free adapter
restartonerror=1, switch to other service=1
2018-09-30 11:27:40.790 [ INFO] dvr: entry 969ca798d3f0a8aea32f9ad71f95f12e "Police Interceptors" on "5Spike" starting at 2018-09-30 10:34:30, with broadcast id "crid://www.five .tv/V4LTU", scheduled for recording by "192.168.1.217" 2018-09-30 11:27:40.790 [ INFO] dvr: "Police Interceptors" on "5Spike" recorder starting 2018-09-30 11:27:40.800 [ INFO] spawn: Executing "/usr/local/bin/tvhmeta" 2018-09-30 11:27:40.801 [ INFO] service: 8: 5Spike si 0x8145db000 Realtek RTL2832 (DVB-T) #3 : master for #0 weight 0 prio 10 error 0 2018-09-30 11:27:40.801 [ INFO] service: 5: 5Spike si 0x81459db80 Panasonic MN88473 #2 : master for #0 weight 0 prio 10 error 0 2018-09-30 11:27:40.801 [ INFO] service: will start new instance 5 2018-09-30 11:27:40.801 [ INFO] mpegts: 529.833MHz in DVB-T Network - tuning on Panasonic MN88473 #2 : master for #0 2018-09-30 11:27:40.802 [ ERROR] service: tuning failed with error 203 (0) 2018-09-30 11:27:41.083 [ ERROR] spawn: 2018-09-30 11:27:41,083:INFO:tvhmeta:67:grabber_args={} 2018-09-30 11:27:41.279 [ ERROR] spawn: 2018-09-30 11:27:41,278:INFO:tvhmeta:376:Got movie modules: [tv_meta_az_sd,tv_meta_tmdb] tv modules [tv_meta_az_sd] 2018-09-30 11:27:41.279 [ ERROR] spawn: 2018-09-30 11:27:41,279:INFO:tvhmeta:138:Sending grid=1&list=uuid%2Cimage%2Cfanart_image%2Ctitle%2Ccopyright_year%2Cepisode_disp%2Curi&uuid=969ca798d 3f0a8aea32f9ad71f95f12e to http://localhost:9985/api/idnode/load 2018-09-30 11:27:41.386 [ ERROR] spawn: 2018-09-30 11:27:41,386:INFO:tvhmeta:228:Trying title Police Interceptors year None uri crid://www.five.tv/V4LTU in language eng with client tv_meta_ az_sd 2018-09-30 11:27:41.396 [ ERROR] spawn: 2018-09-30 11:27:41,395:INFO:tv_meta_az_sd:80:Searching for V4LTU 2018-09-30 11:27:41.402 [ ERROR] spawn: 2018-09-30 11:27:41,402:ERROR:tvhmeta:264:Lookup success, but still no artwork 2018-09-30 11:27:41.403 [ ERROR] spawn: 2018-09-30 11:27:41,402:INFO:tvhmeta:278:Lookup success for title Police Interceptors year None with results {'fanart': None, 'poster': None} 2018-09-30 11:27:41.403 [ ERROR] spawn: 2018-09-30 11:27:41,403:INFO:tvhmeta:280:No artwork found 2018-09-30 11:27:42.811 [ INFO] service: 8: 5Spike si 0x8145db000 Realtek RTL2832 (DVB-T) #3 : master for #0 weight 0 prio 10 error 0 2018-09-30 11:27:42.811 [ INFO] service: 5: 5Spike si 0x81459db80 Panasonic MN88473 #2 : master for #0 weight 0 prio 10 error 203 2018-09-30 11:27:42.811 [ INFO] service: will start new instance 8 2018-09-30 11:27:42.811 [ INFO] mpegts: 529.833MHz in DVB-T Network - tuning on Realtek RTL2832 (DVB-T) #3 : master for #0 2018-09-30 11:27:42.811 [ ERROR] service: tuning failed with error 203 (0) 2018-09-30 11:27:42.811 [WARNING] subscription: 0007: restarting channel 5Spike 2018-09-30 11:27:44.820 [ INFO] service: 8: 5Spike si 0x8145db000 Realtek RTL2832 (DVB-T) #3 : master for #0 weight 0 prio 10 error 0 2018-09-30 11:27:44.820 [ INFO] service: 5: 5Spike si 0x81459db80 Panasonic MN88473 #2 : master for #0 weight 0 prio 10 error 0 2018-09-30 11:27:44.820 [ INFO] service: will start new instance 5 2018-09-30 11:27:44.820 [ INFO] mpegts: 529.833MHz in DVB-T Network - tuning on Panasonic MN88473 #2 : master for #0 2018-09-30 11:27:44.820 [ ERROR] service: tuning failed with error 203 (0) 2018-09-30 11:27:44.820 [WARNING] subscription: 0007: restarting channel 5Spike 2018-09-30 11:27:46.832 [ INFO] service: 8: 5Spike si 0x8145db000 Realtek RTL2832 (DVB-T) #3 : master for #0 weight 0 prio 10 error 0 2018-09-30 11:27:46.832 [ INFO] service: 5: 5Spike si 0x81459db80 Panasonic MN88473 #2 : master for #0 weight 0 prio 10 error 0 2018-09-30 11:27:46.832 [ INFO] service: will start new instance 5 2018-09-30 11:27:46.832 [ INFO] mpegts: 529.833MHz in DVB-T Network - tuning on Panasonic MN88473 #2 : master for #0 2018-09-30 11:27:46.832 [ ERROR] service: tuning failed with error 203 (0) 2018-09-30 11:27:46.833 [WARNING] subscription: 0007: restarting channel 5Spike 2018-09-30 11:27:48.853 [ INFO] service: 8: 5Spike si 0x8145db000 Realtek RTL2832 (DVB-T) #3 : master for #0 weight 0 prio 10 error 0 2018-09-30 11:27:48.853 [ INFO] service: 5: 5Spike si 0x81459db80 Panasonic MN88473 #2 : master for #0 weight 0 prio 10 error 0 2018-09-30 11:27:48.853 [ INFO] service: will start new instance 5 2018-09-30 11:27:48.853 [ INFO] mpegts: 529.833MHz in DVB-T Network - tuning on Panasonic MN88473 #2 : master for #0 2018-09-30 11:27:48.853 [ ERROR] service: tuning failed with error 203 (0)
Updated by Jaroslav Kysela about 6 years ago
Fixed in v4.3-1396-ge316c7677 . Thanks for the logs and description.