Mailing List Archive

mythbackend Start-up issue - possible race with dvb device firmware loading
After power on, about 1 in 20 mythbackend startups are failing for me.

Symptoms are that the backend is running, as reported by *systemctl status,*
but is unresponsive. The mythbackend logfile starts normally but stops
after about 10 seconds with no error

Recordings and frontend connections fail and manual intervention is
required to recover.

*systemctl restart mythbackend* succeeds after a long delay (more than a
minute) and the backend then starts normally.


The best clue I have is this, from the system journal

...
Nov 16 21:09:57 localhost.localdomain kernel: si2168 4-0064: downloading
firmware from file 'dvb-demod-si2168-b40-01.fw'
Nov 16 21:09:58 localhost.localdomain kernel: si2168 4-0064: firmware
version: B 4.0.11
Nov 16 21:09:58 localhost.localdomain kernel: si2157 5-0060: firmware
version: 3.0.5
...

is happening at the same time as this, in the mythbackend log
...
2020-11-16 21:09:58.235627 I [2496/2496] CoreContext cardutil.cpp:1189
(SetDeliverySystem) - CardUtil[2]: Set delivery system: DVB-T2
2020-11-16 21:09:58.296591 D [2496/2496] CoreContext
recorders/dtvchannel.cpp:295 (SetChannelByString) -
DTVChan[2](/dev/dvb/adapter292e/frontend0): SetChannelByString(1):
Initialize multiplex options m_tunerType:34 mplexid:8
2020-11-16 21:09:58.321345 D [2496/2558] TVRecEvent portchecker.cpp:75
(checkPort) - PortChecker::checkPort(): host 127.0.0.1 port 3306 timeLimit
30000 linkLocalOnly 1

...which is where the backend log stops.

On successful startups the firmware load appears to complete during the
second before the mythbacked access.

I have a udev rule on the usb DVB capture device to create a meaningful
name as below.

SUBSYSTEM=="dvb", ATTRS{idProduct}=="025f", PROGRAM="/bin/sh -c 'K=%k;
K=$${K#dvb}; printf dvb/adapter292e/%%s $${K#*.}'", SYMLINK+="%c",
TAG+="systemd"

and the following wait commands in /etc/systemd/system/mythbackend.service

Wants=dev-dvb-adapter292e-frontend0.device
After=dev-dvb-adapter292e-frontend0.device

As far as I can tell this is not a problem. journalctl reports

Nov 16 21:09:12 localhost.localdomain systemd[1]: Found device
/dev/dvb/adapter292e/frontend0.

Which is 45s before mythbackend log starts and 55s before it stops (so the
udev wait is probably unnecessary and may not work if required?)

Assuming that this is the problem, how do I delay starting mythbackend
until the dvb device firmware has loaded?


I'm running Fedora FC32 with MythTV 32 on a Zotac Ion.

I have two usb dvb-t capture devices, a nanostick 290 and a nanostick
292e. The 290 does not appear to require a firmware download. It is the
292e which is apparently causing the trouble.

Thanks in advance,

D
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
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.
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
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.
>
> _______________________________________________
> mythtv-users mailing list
> mythtv-users@mythtv.org
> http://lists.mythtv.org/mailman/listinfo/mythtv-users
> http://wiki.mythtv.org/Mailing_List_etiquette
> MythTV Forums: https://forum.mythtv.org

Whats changed recently :- is it a new host machine or have you just
added a new DVB card.

When I went from a dual core Haswell box to a quad core NUC, udev rules
just went unreliable.

I would fit a single  WinTV-dualHD which gives you the same recording
capability without needing udev.
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
On Wed, 18 Nov 2020 09:34:06 +0000, you wrote:

>After power on, about 1 in 20 mythbackend startups are failing for me.
>
>Symptoms are that the backend is running, as reported by *systemctl status,*
>but is unresponsive. The mythbackend logfile starts normally but stops
>after about 10 seconds with no error
>
>Recordings and frontend connections fail and manual intervention is
>required to recover.
>
>*systemctl restart mythbackend* succeeds after a long delay (more than a
>minute) and the backend then starts normally.
>
>
>The best clue I have is this, from the system journal
>
>...
>Nov 16 21:09:57 localhost.localdomain kernel: si2168 4-0064: downloading
>firmware from file 'dvb-demod-si2168-b40-01.fw'
>Nov 16 21:09:58 localhost.localdomain kernel: si2168 4-0064: firmware
>version: B 4.0.11
>Nov 16 21:09:58 localhost.localdomain kernel: si2157 5-0060: firmware
>version: 3.0.5
>...
>
>is happening at the same time as this, in the mythbackend log
>...
>2020-11-16 21:09:58.235627 I [2496/2496] CoreContext cardutil.cpp:1189
>(SetDeliverySystem) - CardUtil[2]: Set delivery system: DVB-T2
>2020-11-16 21:09:58.296591 D [2496/2496] CoreContext
>recorders/dtvchannel.cpp:295 (SetChannelByString) -
>DTVChan[2](/dev/dvb/adapter292e/frontend0): SetChannelByString(1):
>Initialize multiplex options m_tunerType:34 mplexid:8
>2020-11-16 21:09:58.321345 D [2496/2558] TVRecEvent portchecker.cpp:75
>(checkPort) - PortChecker::checkPort(): host 127.0.0.1 port 3306 timeLimit
>30000 linkLocalOnly 1
>
>...which is where the backend log stops.
>
>On successful startups the firmware load appears to complete during the
>second before the mythbacked access.
>
>I have a udev rule on the usb DVB capture device to create a meaningful
>name as below.
>
>SUBSYSTEM=="dvb", ATTRS{idProduct}=="025f", PROGRAM="/bin/sh -c 'K=%k;
>K=$${K#dvb}; printf dvb/adapter292e/%%s $${K#*.}'", SYMLINK+="%c",
>TAG+="systemd"
>
>and the following wait commands in /etc/systemd/system/mythbackend.service
>
>Wants=dev-dvb-adapter292e-frontend0.device
>After=dev-dvb-adapter292e-frontend0.device
>
>As far as I can tell this is not a problem. journalctl reports
>
>Nov 16 21:09:12 localhost.localdomain systemd[1]: Found device
>/dev/dvb/adapter292e/frontend0.
>
>Which is 45s before mythbackend log starts and 55s before it stops (so the
>udev wait is probably unnecessary and may not work if required?)
>
>Assuming that this is the problem, how do I delay starting mythbackend
>until the dvb device firmware has loaded?
>
>
>I'm running Fedora FC32 with MythTV 32 on a Zotac Ion.
>
>I have two usb dvb-t capture devices, a nanostick 290 and a nanostick
>292e. The 290 does not appear to require a firmware download. It is the
>292e which is apparently causing the trouble.
>
>Thanks in advance,
>
>D

If you are correct about it being a problem with firmware loading,
then you probably want to trigger the firmware to be loaded before you
start mythbackend. To do that, you would want to make the tuner tune
to a channel and start playing from that channel. You can do that
using command line tools such as dvbv5-zap to tune, then copy data
from the tuner. So something like this might work:

dvbv5-zap -r -o /dev/null -t 2 -a <adapter no.> -c <channels file>
<channel name>

Then you could run that command in a systemd unit at startup and have
the mythtv-backend unit wait on that unit before starting. You would
need to check that the /usr/share/dvb/dvb-t files have file with a
channel you can use for this, or create your own file in that format
with the correct data for a channel. I am not sure where Fedora will
put those files, but if you search for a file "uk-Oxford" you should
find them ("locate uk-Oxford" if you have mlocate installed).

Note that I have never actually done this, so YMMV. Please ask if you
need more detailed help.

One thing you probably should also do is to fix the shutting down of
mythbackend. Like all MythTV programs, it suffers from a bug where it
fails to shut down properly when requested to do so externally using a
normal kill (= kill -15 = kill -SIGTERM), which is what systemd does.
One thread is left running, and systemd will then wait for 30 seconds
before finally killing it with a kill -9. But if you do two normal
kills with a short delay between them, it will shut down instantly
after the second kill. You can find instructions for my fix for this
in this thread:

https://lists.archive.carbon60.com/mythtv/users/627998

by searching for "mythbackendstop.sh".

Doing that fix should solve your problem where stopping mythbackend
takes >30 seconds. It normally shuts down for me in <2 seconds. This
fix also speeds up system shutdown and reboot times by 30 seconds if
mythbackend is running.
_______________________________________________
mythtv-users mailing list
mythtv-users@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-users
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
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...

John P
_______________________________________________
mythtv-users mailing list
mythtv-users@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-users
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
On Wed, 18 Nov 2020 10:45:20 +0000, you wrote:

>I'm more puzzled by the fact that the firmware load doesn't seem to be happening early enough in the
>startup sequence.
>
>On my plain Debian system, the firmware is loaded as a consequence of the tuner being detected by
>udev and long before any user program starts up.
>
>If what the OP is experiencing is indeed to do with the tuner, I would suspect that the tuner is
>reaching end of life. My 290e died under similar circumstances. In the end I got fed up with the
>tangle of USB and UHF cables behind my server and replaced the lot with a HDHR duo.

Firmware loading depends entirely on the drivers - each driver that
needs to load firmware does that itself, rather than the system
providing a service to do it. So each driver author makes different
decisions about how and when they will do it. It is often done only
on the first real use of a tuner - just getting its status is not
enough. So it often happens when mythbackend does its testing of
tuners when it starts up.

Your experience of having the firmware load when udev touches the
tuner is very unusual - I have never met a tuner that does that. I
suspect that the problem is that the tuner drivers are loaded well
before the filesystems are up and running, so they have to wait for
some signal that it is now OK to read a file with their firmware in
it. So they just wait for first use of the tuner, there being no easy
way for a driver to detect that the filesystems are up.
_______________________________________________
mythtv-users mailing list
mythtv-users@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-users
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
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.

> John P

_______________________________________________
mythtv-users mailing list
mythtv-users@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-users
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
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
>
> > John P
>

_______________________________________________
mythtv-users mailing list
mythtv-users@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-users
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
I'm running FC32 and, as far as I can tell, the device firmware is only
being loaded at startup. It's possible that it's loaded again whenever a
recording is started. It's hard to tell because that tuner is the second
in the list and is rarely used.

While playing around with capture card settings I did manage to get the
mythbackend startup to freeze without the firmware being loaded at the same
time, so maybe that's a red herring anyway.

I'm a bit concerned by John's comment about a pause and sometimes hang on
FC32/Master 32, since that's what I'm running and that's what I'm seeing.
(Although I have two DVB-T2 cards rather than one DVB-T and one DVB-T2.)

Just to answer some of the other questions. This is a recent re-build on
an old Zotac Ionitx B motherboard. I've re-used the Nanostick 290 from the
original system and replaced the Nova DVB-T USB capture device on the old
system with a Nanostick 292e that I bought years ago and never got round to
installing. In the days when all the HD channels were on the same
multiplex there wasn't much cause to.

With nothing in the myth logs to look at I'm a bit stuck for my next step.
I might remove the 292e card for a while to see if that makes a difference
and perhaps there's a watchdog script someshere that resets the backend if
it doesn't come up properly.

Thanks for all the help anyway and if I make any progress I'll update this
thread.

D
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
On Thu, 19 Nov 2020 12:28:14 +0000, you wrote:

>I'm running FC32 and, as far as I can tell, the device firmware is only
>being loaded at startup. It's possible that it's loaded again whenever a
>recording is started. It's hard to tell because that tuner is the second
>in the list and is rarely used.

I have never heard of a tuner where the firmware is ever reloaded. It
will likely be loading when mythbackend tests the tuner as it starts
up. If the firmware is actually being loaded more than once, that is
an indication that the tuner reset itself and is probably faulty -
check dmesg or kern.log and you will probably find messages about the
USB device disconnecting and reconnecting. Given that this is a USB
tuner, the usual rule applies - suspect the cable first. Make sure it
fits tightly in the PC socket - loose fit means that the slightest
jiggle on the cable (even a gust of air caused by the door being
opened) can be enough to cause the tuner to fault. Change to cable to
a better fitting one if necessary. Cats, kids and vacuuming are all
very hazardous to USB cables too, and bumping the aerial cable can
move the USB cable and cause trouble. One useful trick is to use a
longer cable and lay the tuner flat on a surface at the back of the PC
and tape it down over the cables on both sides to that surface, so
that the USB and aerial cables are not able to move the tuner around
and jiggle things.

I used to have one USB DVB-T tuner that caused me endless problems
like that, and I finally managed to make it reasonably reliable by
using a different cable that was a very tight fit. But even then, it
would still fail every few months, and just unplugging it an plugging
it in again made it start working again. So eventually, because of
that and also because I wanted more tuners, I bought an 8 tuner DVB-T2
PCIe card (TBS6209). That solved the problem!
_______________________________________________
mythtv-users mailing list
mythtv-users@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-users
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
On Thu, 19 Nov 2020 14:55:27 +0000, you wrote:

>On 19/11/2020 13:17, Stephen Worthington wrote:
>> On Thu, 19 Nov 2020 12:28:14 +0000, you wrote:
>>
>>> I'm running FC32 and, as far as I can tell, the device firmware is only
>>> being loaded at startup. It's possible that it's loaded again whenever a
>>> recording is started. It's hard to tell because that tuner is the second
>>> in the list and is rarely used.
>>
>> I have never heard of a tuner where the firmware is ever reloaded. It
>> will likely be loading when mythbackend tests the tuner as it starts
>> up. If the firmware is actually being loaded more than once, that is
>> an indication that the tuner reset itself and is probably faulty -
>> check dmesg or kern.log and you will probably find messages about the
>> USB device disconnecting and reconnecting. Given that this is a USB
>> tuner, the usual rule applies - suspect the cable first. Make sure it
>> fits tightly in the PC socket - loose fit means that the slightest
>> jiggle on the cable (even a gust of air caused by the door being
>> opened) can be enough to cause the tuner to fault. Change to cable to
>> a better fitting one if necessary. Cats, kids and vacuuming are all
>> very hazardous to USB cables too, and bumping the aerial cable can
>> move the USB cable and cause trouble. One useful trick is to use a
>> longer cable and lay the tuner flat on a surface at the back of the PC
>> and tape it down over the cables on both sides to that surface, so
>> that the USB and aerial cables are not able to move the tuner around
>> and jiggle things.
>>
>> I used to have one USB DVB-T tuner that caused me endless problems
>> like that, and I finally managed to make it reasonably reliable by
>> using a different cable that was a very tight fit. But even then, it
>> would still fail every few months, and just unplugging it an plugging
>> it in again made it start working again. So eventually, because of
>> that and also because I wanted more tuners, I bought an 8 tuner DVB-T2
>> PCIe card (TBS6209). That solved the problem!
>>
>Actually, there is a possible circumstance to the OP's problem. That occurs when, I forget the exact
>wording, but the tuner is not exclusively dedicated to myth but can be used by other programs, or
>hosts in the case of a network tuner.
>
>If that happens, when myth comes to take control of the tuner to make a recording, it has no way of
>knowing what state it has been left in by <something else>. Is it possible it then does a re-initialise?
>
>Is it possible that flag has been inadvertantly set?

No. MythTV does not reinitialise tuners - as far as I know, the Linux
DVBAPI has no call that allows you to reinitialise or reset a tuner.
When you open or close a tuner, you are just opening or closing access
to the existing tuner created by the driver. Initialisation of a
tuner is up to the driver, and happens at boot or when the tuner is
plugged into the PC. Firmware load happens when the driver decides it
happens. What they mostly seem to do is to wait until the tuner is
opened or even later when it is tuned to a channel. Getting an open
call tells the driver that the filesystems must be ready by then, as
the open call is the same one that is used by the filesystems. So
getting it means that the driver will be able to access the firmware
file and download it.

When you do the DVBAPI open call, you can select exclusive use, or
permit simultaneous use. When you open a tuner for exclusive use (as
MythTV does), nothing else can open it until you do a close call. The
close call puts the tuner back into a state where it is idle and able
to be opened by any program again. It clears the state of the tuner
so that it is ready to be opened. But it does not reset the hardware
or unload the firmware. So if there is a bug in the firmware which
has made the tuner unusable, unfortunately there is no way to reset
the tuner from software to work around the bug, except by rebooting or
unplugging it and plugging it in again. If a stray cosmic ray has
come along and temporarily messed up the tuner, you can not reset it
to fix that either. Hence the reason why it is a good idea to
occasionally power off a PC and do a full cold boot - that will
normally clear circuit lockups caused by stray radiation. If you just
do warm boots all the time, often tuner drivers do not bother to
reload the firmware as the CPU in the tuner has been running that
firmware right through the warm boot and the driver sees that when it
tries to talk to the tuner after the driver is loaded. But it depends
on the particular tuner - some get a hardware reset from a warm boot
and will be fully reset and have to load the firmware again.

Network tuners are completely different however - they do not have
kernel drivers, and there is no generic API like DVBAPI for running
them. Each manufacturer has their own network API. Some network
tuners may well have the ability to be reset by one of their API
calls.
_______________________________________________
mythtv-users mailing list
mythtv-users@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-users
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
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
>>
>

_______________________________________________
mythtv-users mailing list
mythtv-users@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-users
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
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.
_______________________________________________
mythtv-users mailing list
mythtv-users@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-users
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
On 19/11/2020 16:42, Stephen Worthington wrote:
> On Thu, 19 Nov 2020 16:13:49 +0000, you wrote:

>
> 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.


Hi Stephen: Thanks for your thoughts on this. The dmesg stuff is the
only indication I have that something may have changed. That recording
is fine (PBS America +1, channel 93, h264 544x576) and the failures to
lock that I mentioned earlier might have been weather-related, although
the TV had no problem then. I'll see how things progress.

John P

_______________________________________________
mythtv-users mailing list
mythtv-users@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-users
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
Hi John, Stephen,

On my system, Fedora 33 with the TBS version of the drivers, I get the
following for the MyGIca T230 USB tuner:
dmesg | grep si2157
[81708.931066] si2157 14-0060: found a 'Silicon Labs Si2158-A20'
[81708.931087] si2157 14-0060: downloading firmware from file
'dvb-tuner-si2158-a20-01.fw'
[81710.127330] si2157 14-0060: firmware version: 2.1.9
[81777.542157] si2157 14-0060: found a 'Silicon Labs Si2158-A20'
[81777.542214] si2157 14-0060: downloading firmware from file
'dvb-tuner-si2158-a20-01.fw'
[81778.737773] si2157 14-0060: firmware version: 2.1.9
[81846.110174] si2157 14-0060: found a 'Silicon Labs Si2158-A20'
[81846.110204] si2157 14-0060: downloading firmware from file
'dvb-tuner-si2158-a20-01.fw'
[81847.300054] si2157 14-0060: firmware version: 2.1.9
[81914.474541] si2157 14-0060: found a 'Silicon Labs Si2158-A20'
[81914.474565] si2157 14-0060: downloading firmware from file
'dvb-tuner-si2158-a20-01.fw'
[81915.647009] si2157 14-0060: firmware version: 2.1.9

I have EIT running with a one minute interval, and the "Open DVB Card on
Demand" option checked.
So it looks like that on each "open" the firmware is loaded again.
As said, this is outside the control of mythtv as this is something the
driver itself decides.
On startup the backend currently opens each virtual tuner once, so there
are a lot of these messages at startup if you have configured multirec for
many instances.

Last time I looked into this the firmware was only loaded once but I do not
look into this very often so I do not know when the behavior has changed.

Klaas.
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
On 19/11/2020 18:22, Klaas de Waal wrote:
> Hi John, Stephen,
>
> On my system, Fedora 33 with the TBS version of the drivers, I get the
> following for the MyGIca T230 USB tuner:
> dmesg | grep si2157
> [81708.931066] si2157 14-0060: found a 'Silicon Labs Si2158-A20'
> [81708.931087] si2157 14-0060: downloading firmware from file
> 'dvb-tuner-si2158-a20-01.fw'
> [81710.127330] si2157 14-0060: firmware version: 2.1.9
> [81777.542157] si2157 14-0060: found a 'Silicon Labs Si2158-A20'
> [81777.542214] si2157 14-0060: downloading firmware from file
> 'dvb-tuner-si2158-a20-01.fw'
> [81778.737773] si2157 14-0060: firmware version: 2.1.9
> [81846.110174] si2157 14-0060: found a 'Silicon Labs Si2158-A20'
> [81846.110204] si2157 14-0060: downloading firmware from file
> 'dvb-tuner-si2158-a20-01.fw'
> [81847.300054] si2157 14-0060: firmware version: 2.1.9
> [81914.474541] si2157 14-0060: found a 'Silicon Labs Si2158-A20'
> [81914.474565] si2157 14-0060: downloading firmware from file
> 'dvb-tuner-si2158-a20-01.fw'
> [81915.647009] si2157 14-0060: firmware version: 2.1.9
>
> I have EIT running with a one minute interval, and the "Open DVB Card on
> Demand" option checked.
> So it looks like that on each "open" the firmware is loaded again.
> As said, this is outside the control of mythtv as this is something the
> driver itself decides.
> On startup the backend currently opens each virtual tuner once, so there
> are a lot of these messages at startup if you have configured multirec
> for many instances.
>
> Last time I looked into this the firmware was only loaded once but I do
> not look into this very often so I do not know when the behavior has
> changed.
>
>  Klaas.

Hi Klaas. Thanks for this response. I just did 'all known' scans with,
first, the pci DVB-T tuner and then the MyGica DVB-T/T2. After closing
mythtv-setup and starting mythbackend I got a hang after the 'set
delivery system : DVB-T' line. After 'killall mythbackend' until 'no
process found' I ran 'mythbackend' again and it started as normal.

I think in kubuntu that would be 'mythtv-setup.real', 'mythbackend' and
'mythfrontend.real' in different konsole tabs.

iirc I have had this failure to start immediately after a rescan, or
perhaps after a reboot, several times recently, and it sounds as if
David, the OP here, might have been seeing much the same effect.

I'm still seeing whatever this firmware activity is on a timescale of
minutes in Fedora 32. In el7 at the same commit the tda1004x check is
much less frequent and the one below is do-and-forget.

{{{
DVB: registering new adapter (Kworld UB499-2T T09)
[Thu Nov 19 17:44:33 2020] af9033 6-0038: firmware version: LINK
12.54.14.0 - OFDM 2.47.14.0
[Thu Nov 19 17:44:33 2020] af9033 6-0038: Afatech AF9033 successfully
attached
[Thu Nov 19 17:44:33 2020] usb 1-3: DVB: registering adapter 1 frontend
0 (Afatech AF9033 (DVB-T))...
}}}

kernel there is 4.4.244-1.el7.elrepo.x86_64. That wants me to know
about CIFS VFS: key responses instead...

John P

_______________________________________________
mythtv-users mailing list
mythtv-users@mythtv.org
http://lists.mythtv.org/mailman/listinfo/mythtv-users
http://wiki.mythtv.org/Mailing_List_etiquette
MythTV Forums: https://forum.mythtv.org
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
On Fri, 20 Nov 2020 at 13:12, John Pilkington <johnpilk222@gmail.com> wrote:

>
> iirc I have had this failure to start immediately after a rescan, or
> perhaps after a reboot, several times recently, and it sounds as if
> David, the OP here, might have been seeing much the same effect.
>
>
>
I'm certainly seeing it after a reboot and, most recently, after running
mythtv-setup to fiddle with capture card settings. I haven't done a
channel scan recently so I don't think that's the issue for me.
Re: mythbackend Start-up issue - possible race with dvb device firmware loading [ In reply to ]
>
>>
> I'm certainly seeing it after a reboot and, most recently, after running
> mythtv-setup to fiddle with capture card settings. I haven't done a
> channel scan recently so I don't think that's the issue for me.
>

Just to report back on this issue.

I ran mythtv-setup and modified the capture card settings for both cards:
I changed:

Signal Timeout to 7000
Tuning Timeout to 10000

...and I unchecked 'Open DVB Card on Demand'.

I think that last setting is unchecked by default, but I had turned it on
the first time I set up my backend, because I read somewhere that this can
speed up booting. I never noticed any problems while I had a DVB-T card
and a DVB-T2 card. The problems appeared when I replaced the DVB-T card
with a second T2 one.

Since changing those parameters about three weeks ago I've had no backend
startup failures. So that's all good. I can't say I'm anywhere near
understanding what the problem was though.

D