[mythtv-users] mythbackend channel change issues

Fri Jun 10 13:09:40 UTC 2022

On Sun, Jun 5, 2022 at 10:12 AM John Hoyt <john.hoyt at gmail.com> wrote:

> Recently I've been having a random error where my STB records the wrong
> channel.  I thought the error was on the STB side and tried to modify my
> channel change script to accommodate new STB features (unsuccessfully of
> late).
>
> Upon digging into the problem deeper, I've discovered that mythtv seems to
> be semi-randomly sending 8 digits to the channel change script vs the 4
> I've set it up to (caught by logging looking at the lirc logging in
> syslog).  For example, if the channel was supposed to be 0685, mythbackend
> would provide 00668855.
>

Digging into this further this morning, I've eliminated the channel change
script by adding syslog outputs to the script.  Running as a user, the
script only ever sends commands once.  The only time I see the double send
is when mythbackend commands it.

What I've found is that the channel change script is somehow getting called
twice as I'm seeing two messages indicating that the script was called in
syslog (see "Attempting to change channels lines").

If I've tracked the issue down (if I am guessing right) to lirc trying to
perform both commands interleaved.  In the log output below, the two
"Sending: SEND_ONCE Motorola_QIP6200-2 KEY_EXIT" demonstrate this as I send
the "EXIT" key to way up the STB from it's standby state.  In the script, I
only issue "EXIT" once then move on to channel changes.

Could this be a bg in mythbackend?  If not, any thoughts on what could be
issuing the second channel change command?

Any thoughts on a way to lockout lirc / irsend to only accepting one
command at a time?

In the log below, I've highlighted what I believe to be the repeated /
interleaved irsend requests.

Thanks as always for the help!
John

*Jun 10 08:51:04 mythtv mythtv: Attempting to change channels to 685*

Jun 10 08:51:04 mythtv lircd[1460]: lircd-0.10.1[1460]: Notice: accepted
new client on /var/run/lirc/lircd
Jun 10 08:51:04 mythtv lircd-0.10.1[1460]: Notice: accepted new client on
/var/run/lirc/lircd
Jun 10 08:51:04 mythtv irsend: lirc_command_run: Sending: SEND_ONCE
Motorola_QIP6200-2 KEY_EXIT

*Jun 10 08:51:04 mythtv mythtv: Attempting to change channels to 685*

Jun 10 08:51:04 mythtv irsend: lirc_command_run: Sending: SEND_ONCE
Motorola_QIP6200-2 KEY_EXIT
Jun 10 08:51:04 mythtv lircd[1460]: lircd-0.10.1[1460]: Notice: accepted
new client on /var/run/lirc/lircd
Jun 10 08:51:04 mythtv lircd-0.10.1[1460]: Notice: accepted new client on
/var/run/lirc/lircd
Jun 10 08:51:04 mythtv irsend: lirc_command_run, state: 0, input: "BEGIN"
Jun 10 08:51:04 mythtv irsend: lirc_command_run, state: 1, input:
"SEND_ONCE Motorola_QIP6200-2 KEY_EXIT"
Jun 10 08:51:04 mythtv irsend: lirc_command_run, state: 2, input: "SUCCESS"
Jun 10 08:51:04 mythtv irsend: lirc_command_run, state: 3, input: "END"
Jun 10 08:51:04 mythtv irsend: lirc_command_run: data:END, status:0
Jun 10 08:51:05 mythtv lircd[1460]: lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:05 mythtv lircd[1460]: lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:05 mythtv irsend: lirc_command_run, state: 0, input: "BEGIN"
Jun 10 08:51:05 mythtv lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:05 mythtv irsend: lirc_command_run, state: 1, input:
"SEND_ONCE Motorola_QIP6200-2 KEY_EXIT"
Jun 10 08:51:05 mythtv irsend: lirc_command_run, state: 2, input: "SUCCESS"
Jun 10 08:51:05 mythtv irsend: lirc_command_run, state: 3, input: "END"
Jun 10 08:51:05 mythtv irsend: lirc_command_run: data:END, status:0
Jun 10 08:51:05 mythtv lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:05 mythtv kernel: [  128.828600] usb 3-1: reset high-speed USB
device number 2 using xhci_hcd
Jun 10 08:51:05 mythtv mythbackend: message repeated 3 times: [
mythbackend[1617]: E ProcessRequest programinfo.cpp:2619 (GetPlaybackURL)
ProgramInfo(20685_20220610125100.ts): GetPlaybackURL:
'20685_20220610125100.ts' should be local, but it can not be found.]
Jun 10 08:51:05 mythtv mythtv: lirc sending key 0
Jun 10 08:51:05 mythtv irsend: lirc_command_run: Sending: SEND_ONCE
Motorola_QIP6200-2 KEY_0
Jun 10 08:51:05 mythtv lircd[1460]: lircd-0.10.1[1460]: Notice: accepted
new client on /var/run/lirc/lircd
Jun 10 08:51:05 mythtv lircd-0.10.1[1460]: Notice: accepted new client on
/var/run/lirc/lircd
Jun 10 08:51:05 mythtv irsend: lirc_command_run, state: 0, input: "BEGIN"
Jun 10 08:51:05 mythtv irsend: lirc_command_run, state: 1, input:
"SEND_ONCE Motorola_QIP6200-2 KEY_0"
Jun 10 08:51:05 mythtv lircd[1460]: lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:05 mythtv irsend: lirc_command_run, state: 2, input: "SUCCESS"
Jun 10 08:51:05 mythtv irsend: lirc_command_run, state: 3, input: "END"
Jun 10 08:51:05 mythtv irsend: lirc_command_run: data:END, status:0
Jun 10 08:51:05 mythtv lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:05 mythtv mythtv: lirc sending key 0
Jun 10 08:51:05 mythtv irsend: lirc_command_run: Sending: SEND_ONCE
Motorola_QIP6200-2 KEY_0
Jun 10 08:51:05 mythtv lircd-0.10.1[1460]: Notice: accepted new client on
/var/run/lirc/lircd
Jun 10 08:51:05 mythtv lircd[1460]: lircd-0.10.1[1460]: Notice: accepted
new client on /var/run/lirc/lircd
Jun 10 08:51:05 mythtv irsend: lirc_command_run, state: 0, input: "BEGIN"
Jun 10 08:51:05 mythtv irsend: lirc_command_run, state: 1, input:
"SEND_ONCE Motorola_QIP6200-2 KEY_0"
Jun 10 08:51:05 mythtv lircd[1460]: lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:05 mythtv irsend: lirc_command_run, state: 2, input: "SUCCESS"
Jun 10 08:51:05 mythtv irsend: lirc_command_run, state: 3, input: "END"
Jun 10 08:51:05 mythtv irsend: lirc_command_run: data:END, status:0
Jun 10 08:51:05 mythtv lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:06 mythtv mythtv: lirc sending key 6
Jun 10 08:51:06 mythtv irsend: lirc_command_run: Sending: SEND_ONCE
Motorola_QIP6200-2 KEY_6
Jun 10 08:51:06 mythtv lircd[1460]: lircd-0.10.1[1460]: Notice: accepted
new client on /var/run/lirc/lircd
Jun 10 08:51:06 mythtv lircd-0.10.1[1460]: Notice: accepted new client on
/var/run/lirc/lircd
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 0, input: "BEGIN"
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 1, input:
"SEND_ONCE Motorola_QIP6200-2 KEY_6"
Jun 10 08:51:06 mythtv lircd[1460]: lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 2, input: "SUCCESS"
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 3, input: "END"
Jun 10 08:51:06 mythtv irsend: lirc_command_run: data:END, status:0
Jun 10 08:51:06 mythtv lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:06 mythtv mythtv: lirc sending key 6
Jun 10 08:51:06 mythtv lircd[1460]: lircd-0.10.1[1460]: Notice: accepted
new client on /var/run/lirc/lircd
Jun 10 08:51:06 mythtv lircd-0.10.1[1460]: Notice: accepted new client on
/var/run/lirc/lircd
Jun 10 08:51:06 mythtv irsend: lirc_command_run: Sending: SEND_ONCE
Motorola_QIP6200-2 KEY_6
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 0, input: "BEGIN"
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 1, input:
"SEND_ONCE Motorola_QIP6200-2 KEY_6"
Jun 10 08:51:06 mythtv lircd[1460]: lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 2, input: "SUCCESS"
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 3, input: "END"
Jun 10 08:51:06 mythtv irsend: lirc_command_run: data:END, status:0
Jun 10 08:51:06 mythtv lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:06 mythtv mythtv: lirc sending key 8
Jun 10 08:51:06 mythtv irsend: lirc_command_run: Sending: SEND_ONCE
Motorola_QIP6200-2 KEY_8
Jun 10 08:51:06 mythtv lircd[1460]: lircd-0.10.1[1460]: Notice: accepted
new client on /var/run/lirc/lircd
Jun 10 08:51:06 mythtv lircd-0.10.1[1460]: Notice: accepted new client on
/var/run/lirc/lircd
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 0, input: "BEGIN"
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 1, input:
"SEND_ONCE Motorola_QIP6200-2 KEY_8"
Jun 10 08:51:06 mythtv lircd[1460]: lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 2, input: "SUCCESS"
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 3, input: "END"
Jun 10 08:51:06 mythtv irsend: lirc_command_run: data:END, status:0
Jun 10 08:51:06 mythtv lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:06 mythtv mythtv: lirc sending key 8
Jun 10 08:51:06 mythtv irsend: lirc_command_run: Sending: SEND_ONCE
Motorola_QIP6200-2 KEY_8
Jun 10 08:51:06 mythtv lircd-0.10.1[1460]: Notice: accepted new client on
/var/run/lirc/lircd
Jun 10 08:51:06 mythtv lircd[1460]: lircd-0.10.1[1460]: Notice: accepted
new client on /var/run/lirc/lircd
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 0, input: "BEGIN"
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 1, input:
"SEND_ONCE Motorola_QIP6200-2 KEY_8"
Jun 10 08:51:06 mythtv lircd[1460]: lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 2, input: "SUCCESS"
Jun 10 08:51:06 mythtv irsend: lirc_command_run, state: 3, input: "END"
Jun 10 08:51:06 mythtv irsend: lirc_command_run: data:END, status:0
Jun 10 08:51:06 mythtv lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:07 mythtv mythtv: lirc sending key 5
Jun 10 08:51:07 mythtv irsend: lirc_command_run: Sending: SEND_ONCE
Motorola_QIP6200-2 KEY_5
Jun 10 08:51:07 mythtv lircd[1460]: lircd-0.10.1[1460]: Notice: accepted
new client on /var/run/lirc/lircd
Jun 10 08:51:07 mythtv lircd-0.10.1[1460]: Notice: accepted new client on
/var/run/lirc/lircd
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 0, input: "BEGIN"
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 1, input:
"SEND_ONCE Motorola_QIP6200-2 KEY_5"
Jun 10 08:51:07 mythtv lircd[1460]: lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 2, input: "SUCCESS"
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 3, input: "END"
Jun 10 08:51:07 mythtv irsend: lirc_command_run: data:END, status:0
Jun 10 08:51:07 mythtv lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:07 mythtv mythtv: lirc sending key 5
Jun 10 08:51:07 mythtv irsend: lirc_command_run: Sending: SEND_ONCE
Motorola_QIP6200-2 KEY_5
Jun 10 08:51:07 mythtv lircd-0.10.1[1460]: Notice: accepted new client on
/var/run/lirc/lircd
Jun 10 08:51:07 mythtv lircd[1460]: lircd-0.10.1[1460]: Notice: accepted
new client on /var/run/lirc/lircd
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 0, input: "BEGIN"
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 1, input:
"SEND_ONCE Motorola_QIP6200-2 KEY_5"
Jun 10 08:51:07 mythtv lircd[1460]: lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 2, input: "SUCCESS"
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 3, input: "END"
Jun 10 08:51:07 mythtv irsend: lirc_command_run: data:END, status:0
Jun 10 08:51:07 mythtv lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:07 mythtv irsend: lirc_command_run: Sending: SEND_ONCE
Motorola_QIP6200-2 KEY_EXIT
Jun 10 08:51:07 mythtv lircd[1460]: lircd-0.10.1[1460]: Notice: accepted
new client on /var/run/lirc/lircd
Jun 10 08:51:07 mythtv lircd-0.10.1[1460]: Notice: accepted new client on
/var/run/lirc/lircd
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 0, input: "BEGIN"
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 1, input:
"SEND_ONCE Motorola_QIP6200-2 KEY_EXIT"
Jun 10 08:51:07 mythtv lircd[1460]: lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 2, input: "SUCCESS"
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 3, input: "END"
Jun 10 08:51:07 mythtv irsend: lirc_command_run: data:END, status:0
Jun 10 08:51:07 mythtv lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:07 mythtv irsend: lirc_command_run: Sending: SEND_ONCE
Motorola_QIP6200-2 KEY_EXIT
Jun 10 08:51:07 mythtv lircd[1460]: lircd-0.10.1[1460]: Notice: accepted
new client on /var/run/lirc/lircd
Jun 10 08:51:07 mythtv lircd-0.10.1[1460]: Notice: accepted new client on
/var/run/lirc/lircd
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 0, input: "BEGIN"
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 1, input:
"SEND_ONCE Motorola_QIP6200-2 KEY_EXIT"
Jun 10 08:51:07 mythtv lircd[1460]: lircd-0.10.1[1460]: Info: removed client
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 2, input: "SUCCESS"
Jun 10 08:51:07 mythtv irsend: lirc_command_run, state: 3, input: "END"
Jun 10 08:51:07 mythtv irsend: lirc_command_run: data:END, status:0
Jun 10 08:51:07 mythtv lircd-0.10.1[1460]: Info: removed client
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.mythtv.org/pipermail/mythtv-users/attachments/20220610/12fdb927/attachment.htm>