[mythtv-users] mythbackend Start-up issue - possible race with dvb device firmware loading

[Stephen Worthington]

On Thu, 19 Nov 2020 16:13:49 +0000, you wrote:

>On 19/11/2020 10:11, John Pilkington wrote:
>> On 18/11/2020 15:14, John Pilkington wrote:
>>> On 18/11/2020 10:40, John Pilkington wrote:
>>>> On 18/11/2020 09:46, David Watkins wrote:
>>>>> A bit more googling suggests it may be the backend testing the card 
>>>>> which is triggering the firmware load, in which case I'm back to 
>>>>> square one with trying to identify the problem.
>>>>>
>>>>> I'll try increasing the timeouts on the card to see if that helps.
>>>>>
>>>>
>>>> I start myth manually.  On my  MythTV master/Fedora 32 box I have 
>>>> recently noticed a pause, and sometimes a hang, between the setting 
>>>> of delivery systems for DVB-T and DVB-T2.  On quitting and restarting 
>>>> after a hang everything seems to work as normal.
>>>>
>>>> On seeing your post I ran 'dmesg | grep firmware' - and got 
>>>> screensful of reports of downloads for si5128.  Usually, IIRC, it's 
>>>> done on boot; now it appears to be happening in short bursts at 
>>>> around 200 s intervals...
>>>>
>>>
>>> After Stephen's post mentioning filesystem status links I fired up and 
>>> mounted my NAS which had been offline recently after an RCD power trip 
>>> caused by a defective pizza-oven element.  The firmware oddity is 
>>> still happening.  The DVD-T pci card checks firmware status and is 
>>> satisfied.   The dvb-tuner-si2158 for the MyGica device says it 
>>> downloads the firmware every time.  I have had occasional failure to 
>>> lock on a low-power DVB-T2 multiplex too, although once locked the 
>>> recordings seem ok.
>> 
>> I don't see this regular checking (?) of the firmware versions in el7 at 
>> much the same Myth release; only in Fedora 32.  Maybe it's a kernel thing?
>> 
>> 5.9.8-100.fc32.x86_64
>
>Snippet from 'dmesg -T :  the DVB-T2 usb tuner was recording from 1433 
>to 1549 and EIT data collection is active.
>
>{{{
>
>[Thu Nov 19 14:18:59 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 14:29:25 2020] tda1004x: setting up plls for 48MHz sampling 
>clock
>[Thu Nov 19 14:29:26 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 14:32:31 2020] si2157 1-0060: found a 'Silicon Labs Si2158-A20'
>[Thu Nov 19 14:32:31 2020] si2157 1-0060: downloading firmware from file 
>'dvb-tuner-si2158-a20-01.fw'
>[Thu Nov 19 14:32:33 2020] si2157 1-0060: firmware version: 2.1.9
>[Thu Nov 19 14:33:00 2020] si2157 1-0060: found a 'Silicon Labs Si2158-A20'
>[Thu Nov 19 14:33:00 2020] si2157 1-0060: downloading firmware from file 
>'dvb-tuner-si2158-a20-01.fw'
>[Thu Nov 19 14:33:01 2020] si2157 1-0060: firmware version: 2.1.9
>[Thu Nov 19 14:34:38 2020] tda1004x: setting up plls for 48MHz sampling 
>clock
>[Thu Nov 19 14:34:38 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 14:39:51 2020] tda1004x: setting up plls for 48MHz sampling 
>clock
>[Thu Nov 19 14:39:51 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 14:45:04 2020] tda1004x: setting up plls for 48MHz sampling 
>clock
>[Thu Nov 19 14:45:04 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 15:00:42 2020] tda1004x: setting up plls for 48MHz sampling 
>clock
>[Thu Nov 19 15:00:43 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 15:11:08 2020] tda1004x: setting up plls for 48MHz sampling 
>clock
>[Thu Nov 19 15:11:08 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 15:16:21 2020] tda1004x: setting up plls for 48MHz sampling 
>clock
>[Thu Nov 19 15:16:21 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 15:21:33 2020] tda1004x: setting up plls for 48MHz sampling 
>clock
>[Thu Nov 19 15:21:33 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 15:26:46 2020] tda1004x: setting up plls for 48MHz sampling 
>clock
>[Thu Nov 19 15:26:46 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 15:31:58 2020] tda1004x: setting up plls for 48MHz sampling 
>clock
>[Thu Nov 19 15:31:59 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 15:37:11 2020] tda1004x: setting up plls for 48MHz sampling 
>clock
>[Thu Nov 19 15:37:11 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 15:42:24 2020] tda1004x: setting up plls for 48MHz sampling 
>clock
>[Thu Nov 19 15:42:24 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 15:50:24 2020] si2157 1-0060: found a 'Silicon Labs Si2158-A20'
>[Thu Nov 19 15:50:24 2020] si2157 1-0060: downloading firmware from file 
>'dvb-tuner-si2158-a20-01.fw'
>[Thu Nov 19 15:50:25 2020] si2157 1-0060: firmware version: 2.1.9
>[Thu Nov 19 15:52:50 2020] tda1004x: setting up plls for 48MHz sampling 
>clock
>[Thu Nov 19 15:52:50 2020] tda1004x: found firmware revision 29 -- ok
>[Thu Nov 19 15:55:41 2020] si2157 1-0060: found a 'Silicon Labs Si2158-A20'
>[Thu Nov 19 15:55:41 2020] si2157 1-0060: downloading firmware from file 
>'dvb-tuner-si2158-a20-01.fw'
>[Thu Nov 19 15:55:42 2020] si2157 1-0060: firmware version: 2.1.9
>
>
>}}}
>>>  > John P

That "si2157 1-0060: found a 'Silicon Labs Si2158-A20'" message is
what you expect when the drivers find a tuner that has been reset for
some reason.  I get a similar message if I bump the USB 3 cable
carrying the PCIe x1 connection from my motherboard to my external
TBS6209 8 tuner DVB-T2 card, only I get 8 of the messages, one for
each tuner on the card.  If your tuner is a USB one, I would normally
also expect to see USB disconnect and USB connect messages before each
of those "found" messages.  Not having the disconnect/connect messages
suggests that the tuner may be faulty internally, rather than having a
cable connection problem.  It may be that the tuner is self resetting
for some reason.  Another possibility is that the USB cable is damaged
and has high resistance in the power wires, so it is not providing the
proper voltage to the tuner, and when the tuner does something that
requires more energy or higher voltage than the cable is providing, it
goes into reset.

The "found firmware revision 29 -- ok" messages are also interesting.
They are the sort of thing you might see if the tuner was warm
starting.  A warm start is where the tuner CPU has its firmware loaded
and running, but the driver was unable to talk to the tuner hardware
for a while.  Then the driver becomes able to talk to the hardware
again and goes through its initialisation procedure, to the point
where the driver talks to the CPU.  It sees the CPU is already running
and checks the firmware version.  The firmware version is the expected
version, so it logs that message and continues initialising the tuner
without reloading the firmware.

So the overall impression I would form from those messages is that you
have a hardware problem with that tuner, and, following the basic rule
for troublesome USB tuners, you should first try a different cable
and/or a different USB port.

If it really was recording normally from that tuner during all those
messages, then they must be just an oddity of how its drivers work.
But I would recommend playing that recording to make sure it is OK -
those messages really do look like hardware problems.