Project

General

Profile

Bug #5230

Same adapter repeatedly chosen on error

Added by Em Smith about 3 years ago. Updated about 3 years ago.

Status:
Fixed
Priority:
Normal
Assignee:
-
Category:
-
Target version:
-
Start date:
2018-09-29
Due date:
% Done:

0%

Estimated time:
Found in version:
4.3 2c83aa4
Affected Versions:

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

services.jpg (44.8 KB) services.jpg Services mapped to same channel Em Smith, 2018-09-29 21:50

Associated revisions

Revision e316c767 (diff)
Added by Jaroslav Kysela about 3 years ago

subscription: try to iterate through all adapters on tuning failed error, fixes #5230

Revision a5180013 (diff)
Added by Jaroslav Kysela about 3 years ago

subscription: try to iterate through all adapters on tuning failed error, fixes #5230

History

#1

Updated by Em Smith about 3 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)

#2

Updated by Jaroslav Kysela about 3 years ago

Fixed in v4.3-1396-ge316c7677 . Thanks for the logs and description.

#3

Updated by Jaroslav Kysela about 3 years ago

  • Status changed from New to Fixed
#4

Updated by Em Smith about 3 years ago

Works great, thanks.

Also available in: Atom PDF