[mythtv-users] Debugging problem with ExternalRecorder and streamlink

Tue May 18 14:26:56 UTC 2021

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:~$