[mythtv-users] Problems with ExternalRecorder and streamlink
Peter Carlsson
maillist.peter at home.se
Thu Feb 11 21:55:29 UTC 2021
On Wed, Feb 10, 2021 at 03:21:14PM -0700, John P Poet wrote:
> On Wed, Feb 10, 2021 at 2:30 PM Peter Carlsson <maillist.peter at home.se>
> wrote:
>
> > On Tue, Feb 02, 2021 at 01:13:23PM -0700, John P Poet wrote:
> > > On Sun, Jan 31, 2021 at 3:10 PM Peter Carlsson <maillist.peter at home.se>
> > > wrote:
> > >
> > > > On Sat, Jan 30, 2021 at 03:01:02PM -0700, John P Poet wrote:
> > > > > On Tue, Jan 26, 2021 at 3:11 PM Peter Carlsson <
> > maillist.peter at home.se>
> > > > > wrote:
> > > > >
> > > > > > Hello!
> > > > > >
> > > > > > I had MythTV setup using the ExternalRecorder together with
> > streamlink.
> > > > > >
> > > > > > Last summer the svtplay plugin for streamlink stopped working and I
> > > > > > temporarily stopped using it by changing the recording priority to
> > use
> > > > > > another recorder.
> > > > > >
> > > > > > In streamlink version 1.6.0 (2020-09-22) it was fixed (by Ian
> > Cameron)
> > > > > > and I verified in streamlink that it worked but I never took the
> > time
> > > > to
> > > > > > change back the recording priority until recently.
> > > > > >
> > > > > > But I can not get it to work again. I don't remember to have done
> > > > > > anything else specific to the original problem but much has changed
> > > > > > since then.
> > > > > >
> > > > > > MythTV has been upgraded to version 31 and streamlink to version
> > 2.0.0
> > > > > > where streamlink has dropped support for Python 2 and Python 3.5
> > and
> > > > > > MythTV added support for Python 3.
> > > > > >
> > > > > > I use Debian Buster and have both Python 2.7 and 3.7 installed.
> > > > > >
> > > > > > I tried he following but it just stops at the last line below.
> > > > > >
> > > > > > mythexternrecorder --conf
> > > > > > /home/peter/delat/script/mythtv-svtplay-external-recorder.conf
> > > > --loglevel
> > > > > > debug --verbose all
> > > > > > 2021-01-26 22:55:35.201299 C mythexternrecorder version: [v31.0]
> > > > > > www.mythtv.org
> > > > > > 2021-01-26 22:55:35.201337 C Qt version: compile: 5.11.3, runtime:
> > > > 5.11.3
> > > > > > 2021-01-26 22:55:35.201391 I Debian GNU/Linux 10 (buster) (i386)
> > > > > > 2021-01-26 22:55:35.201394 N Enabled verbose msgs: all
> > > > > > 2021-01-26 22:55:35.201415 N Setting Log Level to LOG_DEBUG
> > > > > > 2021-01-26 22:55:35.212913 I : Buffer: Ready for data.
> > > > > > 2021-01-26 22:55:35.212956 I Added logging to the console
> > > > > > 2021-01-26 22:55:35.212986 I : Command parser ready.
> > > > > > 2021-01-26 22:55:35.213774 D New Logging Client: ID: (#1)
> > > > > > 2021-01-26 22:55:35.231943 I Channels in
> > > > > >
> > > >
> > '/home/peter/delat/script/mythtv-svtplay-external-recorder-channels.conf',
> > > > > > Tuner: '', Scanner: ''
> > > > > > ^C
> > > > > >
> > > > > > What can I do to debug this problem?
> > > > > >
> > > > > > Please let me know if I should provide additional information.
> > > > > >
> > > > > > cat /home/peter/delat/script/mythtv-svtplay-external-recorder.conf
> > > > > >
> > > > > > [RECORDER]
> > > > > > # The recorder command to execute. %URL% is optional, and
> > > > > > # will be replaced with the channel's "URL" as defined in the
> > > > > > # [TUNER/channels] (channel conf) configuration file
> > > > > > #command="cvlc \"%URL%\" --sout \"#std{mux=ts,access=file,dst=-}\""
> > > > > > command="streamlink --player=vlc --stdout \"%URL%\" best"
> > > > > >
> > > > > > # Used in logging events, %ARG% are replaced from the channel info
> > > > > > desc=streamlink \"%URL%\" \"%CHANNUM%\" \"%CHANNAME%\"
> > \"%CALLSIGN%\"
> > > > > >
> > > > > > [TUNER]
> > > > > > # An optional CONF file which provides channel details. If it
> > does not
> > > > > > # exist, then channel changes are not supported.
> > > > > > channels=mythtv-svtplay-external-recorder-channels.conf
> > > > > >
> > > > > > # If [TUNER/command] is provided, it will be executed to "tune" the
> > > > > > # channel. A %URL% parameter will be substituted with the "URL" as
> > > > > > # defined in the [TUNER/channels] configuration file
> > > > > > #command=
> > > > > >
> > > > > > # Timeout for changing channels in msecs
> > > > > > #timeout=
> > > > > >
> > > > > > [SCANNER]
> > > > > > # When MythTV scans for channels, The contents of the
> > [TUNER/channels]
> > > > > > # config file are used to populate MythTV's channel information.
> > > > > > # If a command is provided here, it will be executed first, so it
> > can
> > > > > > # populate the [TUNER/channels] config file
> > > > > > #command=/home/myth/bin/scan.sh "%CHANCONF%"
> > > > > >
> > > > > > # Timeout for scan command in msecs
> > > > > > #timeout=60000
> > > > > >
> > > > > >
> > > > > > cat
> > > > > >
> > /home/peter/delat/script/mythtv-svtplay-external-recorder-channels.conf
> > > > > >
> > > > > > [1]
> > > > > > NAME=SVT1 HD
> > > > > > CALLSIGN=SVT1HD
> > > > > > XMLTVID=svt1.svt.se
> > > > > > URL="https://www.svtplay.se/kanaler/svt1?start=auto"
> > > > > > ICON=/home/mythtv/.mythtv/channels/svt1.svt.se.png
> > > > > >
> > > > > > [2]
> > > > > > NAME=SVT2 HD
> > > > > > CALLSIGN=SVT2HD
> > > > > > XMLTVID=svt2.svt.se
> > > > > > URL="https://www.svtplay.se/kanaler/svt2?start=auto"
> > > > > > ICON=/home/mythtv/.mythtv/channels/svt2.svt.se.png
> > > > > >
> > > > > > [3]
> > > > > > NAME=Kunskapskanalen
> > > > > > CALLSIGN=Kunskapskanalen
> > > > > > XMLTVID=kunskapskanalen.svt.se
> > > > > > URL="https://www.svtplay.se/kanaler/kunskapskanalen?start=auto"
> > > > > > ICON=/home/mythtv/.mythtv/channels/kunskapskanalen.svt.se.png
> > > > > >
> > > > > > [4]
> > > > > > NAME=Barnkanalen
> > > > > > CALLSIGN=Barnkanalen
> > > > > > XMLTVID=barnkanalen.svt.se
> > > > > > URL="https://www.svtplay.se/kanaler/svtbarn?start=auto"
> > > > > > ICON=/home/mythtv/.mythtv/channels/barnkanalen.svt.se.png
> > > > > >
> > > > > > [5]
> > > > > > NAME=SVT24
> > > > > > CALLSIGN=SVT24
> > > > > > XMLTVID=svt24.svt.se
> > > > > > URL="https://www.svtplay.se/kanaler/svt24?start=auto"
> > > > > > ICON=/home/mythtv/.mythtv/channels/svt24.svt.se.png
> > > > > >
> > > > > >
> > > > > Hi Peter,
> > > > >
> > > > > The behavior you describe is correct. At that point
> > mythexternrecorder is
> > > > > expecting to be given commands from mythackend. For example, instead
> > of
> > > > > hitting CTRL-C where you did, you could type:
> > > > > APIVersion?
> > > > > and it should spit out something like
> > > > > OK:2
> > > > >
> > > > > If you look at https://www.mythtv.org/wiki/ExternalRecorder you can
> > see
> > > > the
> > > > > commands that are allowed. With APIVersion2, the serial number at the
> > > > > beginning of each command should be incremented.
> > > >
> > > > Hello John,
> > > >
> > > > Thanks for you answer. I tried to send some commands and they all seems
> > > > to work until I try to send TuneStatus? where I would have expected
> > > > '9:OK:Tuned to 1' or similar. Am I on the right track and is this
> > > > indicating that something is wrong?
> > > >
> > > > It seems that although I add arguments '--loglevel debug --verbose' I
> > > > don't get that much help of the output.
> > > >
> > > > I can call streamlink directly and get a stream that I can watch in
> > VLC.
> > > >
> > > > mythexternrecorder --conf
> > > > /home/peter/delat/script/mythtv-svtplay-external-recorder.conf
> > --loglevel
> > > > debug --verbose
> > > > 2021-01-31 22:58:06.872700 C mythexternrecorder version: [v31.0]
> > > > www.mythtv.org
> > > > 2021-01-31 22:58:06.872720 C Qt version: compile: 5.11.3, runtime:
> > 5.11.3
> > > > 2021-01-31 22:58:06.872748 I Debian GNU/Linux 10 (buster) (x86_64)
> > > > 2021-01-31 22:58:06.872750 N Enabled verbose msgs: general
> > > > 2021-01-31 22:58:06.872760 N Setting Log Level to LOG_DEBUG
> > > > 2021-01-31 22:58:06.883132 I Added logging to the console
> > > > 1::HasTuner?
> > > > 1:OK:Yes
> > > > 2::LoadChannels
> > > > 2:OK:5
> > > > 3::FirstChannel
> > > > 3:OK:1,SVT1 HD,SVT1HD,svt1.svt.se
> > > > ,/home/mythtv/.mythtv/channels/svt1.svt.se.png
> > > > 4:NextChannel
> > > > 4:OK:2,SVT2 HD,SVT2HD,svt2.svt.se
> > > > ,/home/mythtv/.mythtv/channels/svt2.svt.se.png
> > > > 5:NextChannel
> > > > 5:OK:3,Kunskapskanalen,Kunskapskanalen,kunskapskanalen.svt.se
> > > > ,/home/mythtv/.mythtv/channels/kunskapskanalen.svt.se.png
> > > > 6:NextChannel
> > > > 6:OK:4,Barnkanalen,Barnkanalen,barnkanalen.svt.se
> > > > ,/home/mythtv/.mythtv/channels/barnkanalen.svt.se.png
> > > > 7:NextChannel
> > > > 7:OK:5,SVT24,SVT24,svt24.svt.se
> > > > ,/home/mythtv/.mythtv/channels/svt24.svt.se.png
> > > > 8:TuneChannel:1
> > > > 8:OK:Tuned to 1
> > > > 9:TuneStatus?
> > > > 9:OK:Tuned to
> > > >
> > > > /Peter
> > > >
> > >
> > > Hi Peter,
> > >
> > > Sorry for the slow responses. I have some other things going on.
> > >
> > > As far as the TuneStatus? response, that could be a minor bug.
> > mythbackend
> > > will only issue that command if TuneChannel: returns "OK:InProgress". In
> > > your example it returned "OK:Tuned to 1" so mythbackend would never have
> > > issued "TuneStatus?", therefore I never noticed that the response was
> > poor.
> > > I will take a look at that.
> > >
> > > mythbackend will normally send the following commands after the channel
> > is
> > > tuned:
> > > Description?
> > > SignalStrengthPercent?
> > > HasLock?
> > > IsOpen?
> > > Those are just to gather information. It will then do:
> > > StartStreaming
> > > XON
> > > Which tells mythexternrecorder to actually start processing data. The
> > > transport stream will be parsed so mythtv can verify that it is valid.
> > Then
> > > the stream will be shut down:
> > > XOFF
> > > Version?
> > > StopStreaming
> > > ..
> > > Then mythbackend is finally ready to start recording, so it will start
> > the
> > > stream back up:
> > > ..
> > > StartStreaming
> > > XON
> > > and mythexternrecorder will pass the transport stream to mythbackend for
> > it
> > > to record.
> > >
> > > When mythbackend invokes mythexternrecorder it passes arguments such as
> > > --logpath to it. Wherever the mythbackend logs are stored (e.g.
> > > /var/log/mythtv) you should also find mythexternrecorder log files. If
> > > mythbackend is started up with "--logpath /var/log/mythtv -v
> > > channel,record" then mythexternrecorder will as well. When debugging
> > > recording issues make sure you have told mythbackend to run with "-v
> > > channel,record".
> >
> > Hello John,
> >
> > I very much appreciate your help!
> >
> > I added more logging as you suggested. Don't know why it is truncated in
> > the log messages.
> >
> > Do you make anything out of the log messages?
> >
> > What would be my next step?
> >
> > Best regards,
> > Peter Carlsson
> >
> > Feb 10 22:09:06 htpc mythbackend[1097]: 2021-02-10 22:09:06.285294 I
> > ExternChan[21](/usr/bin/mythexternrecorder --conf
> > /home/peter/delat/script/mythtv-svtplay-external-recorder.conf --loglevel
> > debug --verbose cha): Open()
> > Feb 10 22:09:06 htpc mythbackend[1097]: 2021-02-10 22:09:06.286900 I
> > ChannelBase[21]: Input #21: 'MPEG2TS' schan(1) sourceid(4)
> > Feb 10 22:09:06 htpc mythbackend[1097]: 2021-02-10 22:09:06.287222 I
> > ExternSH[21](/usr/bin/mythexternrecorder --conf
> > /home/peter/delat/script/mythtv-svtplay-external-recorder.conf --loglevel
> > debug --verbose cha): args "--conf
> > /home/peter/delat/script/mythtv-svtplay-external-recorder.conf --loglevel
> > debug --verbose cha --verbose general,channel,record --logpath
> > /var/log/mythtv --loglevel info --quiet --inputid 21"
> > Feb 10 22:09:06 htpc mythbackend[1097]: 2021-02-10 22:09:06.287275 I
> > ExternSH[21](/usr/bin/mythexternrecorder --conf
> > /home/peter/delat/script/mythtv-svtplay-external-recorder.conf --loglevel
> > debug --verbose cha): Spawn '/usr/bin/mythexternrecorder --conf
> > /home/peter/delat/script/mythtv-svtplay-external-recorder.conf --loglevel
> > debug --verbose cha'
> > Feb 10 22:09:06 htpc mythbackend[1097]: 2021-02-10 22:09:06.287281 I
> > ExternIO::Run()
> > Feb 10 22:09:06 htpc mythbackend[1097]: 2021-02-10 22:09:06.308616 I
> > ExternIO::Fork 'mythexternrecorder --conf
> > /home/peter/delat/script/mythtv-svtplay-external-recorder.conf --loglevel
> > debug --verbose cha --verbose general,channel,record --logpath
> > /var/log/mythtv --loglevel info --quiet --inputid 21'
> > Feb 10 22:09:06 htpc mythbackend[1097]: 2021-02-10 22:09:06.314137 I
> > Spawned
> > Feb 10 22:09:06 htpc mythbackend[1097]: 2021-02-10 22:09:06.567769 I
> > ExternSH[21](/usr/bin/mythexternrecorder --conf
> > /home/peter/delat/script/mythtv-svtplay-external-recorder.conf --loglevel
> > debug --verbose cha): ProcessCommand('APIVersion?') = 'OK:2' took 243ms
> > Feb 10 22:09:06 htpc mythbackend[1097]: 2021-02-10 22:09:06.567940 I
> > ExternSH[21](/usr/bin/mythexternrecorder --conf
> > /home/peter/delat/script/mythtv-svtplay-external-recorder.conf --loglevel
> > debug --verbose cha): ProcessV2('1:APIVersion:2') = 'OK:2' took 0ms
> > Feb 10 22:09:06 htpc mythbackend[1097]: 2021-02-10 22:09:06.568051 I
> > ExternSH[21](/usr/bin/mythexternrecorder --conf
> > /home/peter/delat/script/mythtv-svtplay-external-recorder.conf --loglevel
> > debug --verbose cha): ProcessV2('2:Version?') = 'OK:0.6' took 0ms
> > Feb 10 22:09:06 htpc mythbackend[1097]: 2021-02-10 22:09:06.568173 W
> > ExternSH[21](/usr/bin/mythexternrecorder --conf
> > /home/peter/delat/script/mythtv-svtplay-external-recorder.conf --loglevel
> > debug --verbose cha): ProcessV2('3:Description?') = 'WARN:Not set' took 0ms
> > <-- NOTE
> > Feb 10 22:09:10 htpc mythbackend[1097]: 2021-02-10 22:09:10.570731 E
> > ExternSH[21](/usr/bin/mythexternrecorder --conf
> > /home/peter/delat/script/mythtv-svtplay-external-recorder.conf --loglevel
> > debug --verbose cha): ProcessVer2: Giving up waiting for response for
> > command '4:HasTuner?'
> > <snip>
> >
>
> Is it possible that there is a wedged copy of mythexternrecorder running
> which is interfering?
ps aux | grep mythexternrecorder
root 15820 0.0 0.0 7868 676 pts/0 S+ 22:51 0:00 grep mythexternrecorder
> What does the mythexternrecorder log file have in it?
To be honest I have never really managed to have separate logs in
/var/log/mythtv/ even though I have tried to.
ls -ld /var/log/mythtv
drwxr-sr-x 2 root adm 20480 feb 11 20:36 /var/log/mythtv
ps ax | grep mythbackend | grep -v grep
15605 ? Ssl 0:00 /usr/bin/mythbackend --logpath /var/log/mythtv/ --verbose channel,record
systemctl status mythtv-backend
● mythtv-backend.service - MythTV Backend
Loaded: loaded (/lib/systemd/system/mythtv-backend.service; enabled; vendor preset: enabled)
Drop-In: /etc/systemd/system/mythtv-backend.service.d
└─override.conf
Active: active (running) since Thu 2021-02-11 22:42:27 CET; 1min 23s ago
Docs: https://www.mythtv.org/wiki/Mythbackend
https://www.mythtv.org/wiki/Mythbackend
Main PID: 15605 (mythbackend)
Tasks: 34 (limit: 4915)
Memory: 44.0M
CGroup: /system.slice/mythtv-backend.service
└─15605 /usr/bin/mythbackend --logpath /var/log/mythtv/ --verbose channel,record
cat /etc/rsyslog.d/mythtv-backend.conf
$FileOwner mythtv
$FileGroup mythtv
$FileCreateMode 0644
# Specify a log file name format. Ensure one of the following templates is
# uncommented.
# - Use a single log file for all logging from any MythTV application:
#$template mythtvFile,"/var/log/mythtv/mythtv.log"
# - Use a single log file per application:
$template mythtvFile,"/var/log/mythtv/%programname%.log"
# - Use a separate log file per process:
#$template mythtvFile,"/var/log/mythtv/%programname%.%syslogtag:R,ERE,1,ZERO:\[([[:digit:]]{1,})\]--end%.log"
# Send all logging on local6 facility to mythtvFile (filename created according
# to the template specified, above), then discard (so the message is not also
# written to system other log files).
# This should catch any output from MythTV applications, assuming they are
# started with:
# --syslog local6
local6.* ?mythtvFile
& ~
$FileOwner root
$FileGroup adm
$FileCreateMode 0640
Thanks again!
Best regards,
Peter Carlsson
More information about the mythtv-users
mailing list