[mythtv-users] Debugging problem with ExternalRecorder and streamlink
Peter Carlsson
peter.jm.carlsson at gmail.com
Thu Jun 24 21:32:24 UTC 2021
On Tue, May 18, 2021 at 04:26:56PM +0200, Peter Carlsson wrote:
> On Sat, May 15, 2021 at 04:50:51PM +0000, Gary Buhrmaster wrote:
> > On Sat, May 15, 2021 at 3:45 PM Peter Carlsson
> > <peter.jm.carlsson at gmail.com> wrote:
> >
> > > I have previously written about these problems but I wonder if the
> > > ExternalRecorder can be run independently without the involvement
> > > of the mythtv backend?
> >
> > Yes (at least on a system with the required MythTV
> > support libraries, such as your backend). On the
> > recent development branch, something like (add
> > additional options as configured in your capturecard):
> >
> > /usr/bin/mythexternalrecorder --logpath /tmp --verbose all
> > --loglevel debug --conf XXXXX >/dev/null
> >
> > and then you will need to enter commands that
> > are appropriate/understood to the external recorder.
> >
> > Such as:
> >
> > 0:HasTuner?
> > 0:TuneChannel:1234
> > 0:HasLock?
> > 0:HasLock?
> > 0:StartStreaming
> > 0:CloseRecorder
> >
> > The 0 is a serial number (previous versions may
> > not use API version 2, with a serial number, so
> > if the recorder complains, eliminate the '0:'), and
> > would normally increment for serialization
> > purposes, but for manual testing you can just
> > use zero.
> >
> > The redirect of stdout to /dev/null just throws
> > away the transport stream, so if you want to
> > keep that, redirect it to someplace useful.
> > As it is a raw binary stream, you will not want
> > it sent to your terminal.
> >
> > The external recorder will respond as it would to
> > the backend, and also produce additional
> > information in the logfile which will be in the
> > logpath directory (named something like
> > mythexternalrecorder.DATETIME.PID.log).
> >
> > The commands are documented in the wiki at:
> >
> > https://www.mythtv.org/wiki/ExternalRecorder
> >
> > and you may be able to use a previous
> > BE log to suggest the commands you
> > want to issue for your testing.
>
> Hello and thanks for the help. I have done this previously but did not
> know how much the backend was involved.
>
> Here is the output from a debug session. From what I can tell HasLock
> never returns Yes. Is it possible to debug this part even further?
>
> Since it works directly with streamlink there seems to be a difference
> in how it locks to the stream?
>
> peter at server:~$ mythexternrecorder --logpath /tmp --verbose all --loglevel debug --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf
> 2021-05-18 16:17:34.556339 C mythexternrecorder version: [v31.0] www.mythtv.org
> 2021-05-18 16:17:34.556354 C Qt version: compile: 5.11.3, runtime: 5.11.3
> 2021-05-18 16:17:34.556374 I Debian GNU/Linux 10 (buster) (x86_64)
> 2021-05-18 16:17:34.556379 N Enabled verbose msgs: all
> 2021-05-18 16:17:34.556456 N Setting Log Level to LOG_DEBUG
> 2021-05-18 16:17:34.566832 I Added logging to the console
> 2021-05-18 16:17:34.567035 D New Logging Client: ID: (#1)
> 2021-05-18 16:17:34.567068 I Added logging to /tmp/mythexternrecorder.20210518141734.22509.log
> 2021-05-18 16:17:34.567081 I : Command parser ready.
> 2021-05-18 16:17:34.567157 I : Buffer: Ready for data.
> 2021-05-18 16:17:34.567404 I Channels in '/home/peter/delat/script/mythtv-svtplay-external-recorder-channels.conf', Tuner: '', Scanner: ''
> 0:HasTuner?
> 0:OK:Yes
> 0:HasTuner?'6:17:46.205687 D : Processing '
> 0:OK:Yes'8 16:17:46.205888 I : Processing 'HasTuner' --> '
> 0:TuneChannel:1
> 2021-05-18 16:17:57.283790 D : Processing '0:TuneChannel:1'
> 0:OK:Tuned to 1
> 2021-05-18 16:17:57.290625 D streamlink "%URL%" "%CHANNUM%" "%CHANNAME%" "%CALLSIGN%" : '%URL%' replaced with 'https://www.svtplay.se/kanaler/svt1?start=auto' in cmd: '/usr/bin/streamlink --player=vlc --stdout "https://www.svtplay.se/kanaler/svt1?start=auto" best'
> 2021-05-18 16:17:57.290671 I streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing 'TuneChannel' --> '0:OK:Tuned to 1'
> 0:HasLock?
> 0:OK:No
> 2021-05-18 16:18:34.847504 D streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing '0:HasLock?'
> 2021-05-18 16:18:34.847520 I streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing '0:HasLock?' --> '0:OK:No'
> 0:HasLock?
> 0:OK:No
> 2021-05-18 16:18:44.517351 D streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing '0:HasLock?'
> 2021-05-18 16:18:44.517369 I streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing '0:HasLock?' --> '0:OK:No'
> 0:HasLock?
> 0:OK:No
> 2021-05-18 16:18:51.663488 D streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing '0:HasLock?'
> 2021-05-18 16:18:51.663504 I streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing '0:HasLock?' --> '0:OK:No'
> 0:HasLock?
> 0:OK:No
> 2021-05-18 16:18:58.295381 D streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing '0:HasLock?'
> 2021-05-18 16:18:58.295398 I streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing '0:HasLock?' --> '0:OK:No'
> 0:StartStreaming
> 0:OK:Streaming Started
> 2021-05-18 16:19:06.487610 D streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing '0:StartStreaming'
> 2021-05-18 16:19:06.490527 I (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Starting process '/usr/bin/streamlink' args: '--player=vlc --stdout https://www.svtplay.se/kanaler/svt1?start=auto best'
> 2021-05-18 16:19:06.541807 I (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Started process '/usr/bin/streamlink' PID 22644
> 2021-05-18 16:19:06.541859 I (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing 'StartStreaming' --> '0:OK:Streaming Started'
> 2021-05-18 16:19:07.455385 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 65536 bytes
> 2021-05-18 16:19:07.465725 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 90112 bytes
> 2021-05-18 16:19:07.475982 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 73728 bytes
> 2021-05-18 16:19:07.486180 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 65536 bytes
> 2021-05-18 16:19:07.496488 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 131072 bytes
> 2021-05-18 16:19:07.506757 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 131072 bytes
> 2021-05-18 16:19:07.516955 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 73728 bytes
> 2021-05-18 16:19:10.535648 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 65536 bytes
> 2021-05-18 16:19:10.545940 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 131072 bytes
> 2021-05-18 16:19:10.556175 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 81920 bytes
> 2021-05-18 16:19:10.566454 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 131072 bytes
> 2021-05-18 16:19:10.576627 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 57344 bytes
> 2021-05-18 16:19:10.586881 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 32768 bytes
> 2021-05-18 16:19:10.597117 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 65536 bytes
> 2021-05-18 16:19:10.607417 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Adding 114688 bytes
> 0:CloseRecorder
> 0:OK:Terminating
> 2021-05-18 16:19:13.117330 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing '0:CloseRecorder'
> 2021-05-18 16:19:13.117357 I (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing '0:CloseRecorder' --> '0:OK:Terminating'
> 2021-05-18 16:19:13.134619 I (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" Sending SIGINT to App(22644)
>
> 0:0:ERR:Version 2 API expects serial_no:msg format. Saw '' instead
> 2021-05-18 16:19:13.827020 D (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing ''
> 0:STATUS:Streaming Stopped
> 2021-05-18 16:19:16.906314 I streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : External application terminated.
> 2021-05-18 16:19:16.906334 I (pid 22644) streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Processing 'StopStreaming' --> '0:STATUS:Streaming Stopped'
> 2021-05-18 16:19:16.906359 I streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Closing application.
> 2021-05-18 16:19:16.906487 I streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Buffer: shutting down
> 2021-05-18 16:19:17.080015 I streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Command parser: shutting down
> 2021-05-18 16:19:17.080055 C streamlink "https://www.svtplay.se/kanaler/svt1?start=auto" "1" "SVT1 HD" "SVT1HD" : Terminated.
> 2021-05-18 16:19:17.170509 I Removed logging to /tmp/mythexternrecorder.20210518141734.22509.log
> peter at server:~$
According to the log above it receive data from streamlink but fails to
find the start of the stream to sync/lock on.
I have no knowledge about how this is working but it feels that MythTV
and VLC have different ways of finding the start of a stream.
Could someone explain how this works in MythTV?
I can build MythTV and add more logging but am not sure where to put it
and what I should log to best find out what is failing.
Best regards,
Peter Carlsson
More information about the mythtv-users
mailing list