[mythtv-users] Problems with ExternalRecorder and streamlink

Peter Carlsson maillist.peter at home.se
Fri Feb 12 11:34:42 UTC 2021


On Thu, Feb 11, 2021 at 04:12:40PM -0700, John P Poet wrote:
> On Thu, Feb 11, 2021 at 3:00 PM Peter Carlsson <maillist.peter at home.se>
> wrote:
> 
> >
> > <trimmed>
> >
> >   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
> >
> 
> 
> You don't have a mythtv user and group?  I strongly recommend having
> mythbackend, etc, run as mythtv:mythtv instead of root. You would need to
> change the ownership of /var/log/mythtv accordingly.  It is very possible
> that is your whole problem. If mythexternrecorder does not have permission
> to write its log files to the same directory as mythbackend, it will refuse
> to run.
> That being said, I don't use syslog for mythbackend logs and have never
> tried to use mythexternrecorder that way. I guess it should work, I just
> can't be sure.

I was under the impression that I always run the backend as user mythtv
and I think I still does. But you were right about the permissions of
/var/log/mythtv which I have now fixed. So all logs end up there. Thanks!

But fixing that did not fix the problem with mythexternrecorder.

Below you can see part of the log files. I can provide the full log
files but was not sure I could send attachments to the mailing list.

Will these excerpts give any clues?

Thanks again for all your help!

Best regards,
Peter Carlsson

cat /tmp/mythexternrecorder.20210212104722.32675.log
  2021-02-12 11:47:22.145760 C [32675/32675] thread_unknown mythcommandlineparser.cpp:2611 (ConfigureLogging) - mythexternrecorder version:  [v31.0] www.mythtv.org
  2021-02-12 11:47:22.145793 C [32675/32675] thread_unknown mythcommandlineparser.cpp:2613 (ConfigureLogging) - Qt version: compile: 5.11.3, runtime: 5.11.3
  2021-02-12 11:47:22.145847 I [32675/32675] thread_unknown mythcommandlineparser.cpp:2615 (ConfigureLogging) - Debian GNU/Linux 10 (buster) (i386)
  2021-02-12 11:47:22.145851 N [32675/32675] thread_unknown mythcommandlineparser.cpp:2617 (ConfigureLogging) - Enabled verbose msgs:  general channel record
  2021-02-12 11:47:22.145947 N [32675/32675] thread_unknown logging.cpp:725 (logStart) - Setting Log Level to LOG_INFO
  2021-02-12 11:47:22.156735 I [32675/32678] Logger logging.cpp:280 (run) - Added logging to the console
  2021-02-12 11:47:22.157080 I [32675/32679] thread_unknown MythExternControl.cpp:565 (Run) - : Buffer: Ready for data.
  2021-02-12 11:47:22.157268 I [32675/32680] thread_unknown MythExternControl.cpp:450 (Run) - : Command parser ready.
  2021-02-12 11:47:22.157356 I [32675/32677] LogForward loggingserver.cpp:129 (FileLogger) - Added logging to /var/log/mythtv/mythexternrecorder.20210212104722.32675.log
  2021-02-12 11:47:22.157410 I [32675/32680] thread_unknown MythExternControl.cpp:215 (SendStatus) - : Processing 'APIVersion?' --> 'OK:2'
  2021-02-12 11:47:22.157636 I [32675/32680] thread_unknown MythExternControl.cpp:240 (SendStatus) - : Processing '1:APIVersion:2' --> '1:OK:2'
  2021-02-12 11:47:22.157763 I [32675/32680] thread_unknown MythExternControl.cpp:240 (SendStatus) - : Processing '2:Version?' --> '2:OK:0.6'
  2021-02-12 11:47:22.157880 I [32675/32680] thread_unknown MythExternControl.cpp:240 (SendStatus) - : Processing '3:Description?' --> '3:WARN:Not set'
  2021-02-12 11:47:22.163536 I [32675/32675] thread_unknown MythExternRecApp.cpp:50 (MythExternRecApp) -  Channels in '/home/peter/delat/script/mythtv-svtplay-external-recorder-channels.conf', Tuner: '', Scanner: ''
  2021-02-12 11:47:26.167121 I [32675/32675] thread_unknown MythExternControl.cpp:240 (SendStatus) - : Processing 'HasTuner' --> '5:OK:Yes'
  2021-02-12 11:47:26.177351 I [32675/32675] thread_unknown MythExternControl.cpp:240 (SendStatus) - : Processing 'HasPictureAttributes' --> '6:OK:No'
  2021-02-12 11:47:26.177552 I [32675/32680] thread_unknown MythExternControl.cpp:240 (SendStatus) - : Processing '7:FlowControl?' --> '7:OK:XON/XOFF'
  2021-02-12 11:47:26.187588 I [32675/32675] thread_unknown MythExternControl.cpp:240 (SendStatus) - : Processing 'BlockSize' --> '8:OK'
  2021-02-12 11:52:27.189668 N [32675/32679] thread_unknown MythExternControl.cpp:591 (Run) - : Not streaming.

cat /tmp/mythbackend.20210212104435.32334.log
  2021-02-12 11:47:21.885916 I [32334/32405] TVRecEvent tv_rec.cpp:1057 (HandleStateChange) - TVRec[21]: Changing from None to WatchingLiveTV
  2021-02-12 11:47:21.885970 I [32334/32405] TVRecEvent tv_rec.cpp:4434 (ClearFlags) - TVRec[21]: ClearFlags(FrontendReady,CancelNextRecording,) -> RunMainLoop, @ tv_rec.cpp:1291
  2021-02-12 11:47:21.885996 I [32334/32405] TVRecEvent tv_rec.cpp:3502 (HandleTuning) - TVRec[21]: HandleTuning Request: Program(NULL) channel() input() flags(LiveTV,)
  2021-02-12 11:47:21.886014 I [32334/32405] TVRecEvent cardutil.cpp:2055 (GetConflictingInputs) - CardUtil[21]: GetConflictingInputs() input 21
  2021-02-12 11:47:21.887648 I [32334/32405] TVRecEvent cardutil.cpp:2087 (GetConflictingInputs) - CardUtil[21]: GetConflictingInputs() got input 22
  2021-02-12 11:47:21.887683 I [32334/32405] TVRecEvent cardutil.cpp:2087 (GetConflictingInputs) - CardUtil[21]: GetConflictingInputs() got input 23
  2021-02-12 11:47:21.887694 I [32334/32405] TVRecEvent cardutil.cpp:2087 (GetConflictingInputs) - CardUtil[21]: GetConflictingInputs() got input 24
  2021-02-12 11:47:21.887741 I [32334/32405] TVRecEvent recorders/channelbase.cpp:259 (IsInputAvailable) - ChannelBase[21]: Input is free on 0/0
  2021-02-12 11:47:21.889052 I [32334/32405] TVRecEvent tv_rec.cpp:3571 (TuningShutdowns) - TVRec[21]: TuningShutdowns(Program(NULL) channel(1) input() flags(LiveTV,))
  2021-02-12 11:47:21.889071 I [32334/32405] TVRecEvent tv_rec.cpp:4434 (ClearFlags) - TVRec[21]: ClearFlags(PENDINGACTIONS,) -> RunMainLoop, @ tv_rec.cpp:3640
  2021-02-12 11:47:21.889083 I [32334/32405] TVRecEvent tv_rec.cpp:3524 (HandleTuning) - TVRec[21]: No recorder yet, calling TuningFrequency
  2021-02-12 11:47:21.889092 I [32334/32405] TVRecEvent tv_rec.cpp:3662 (TuningFrequency) - TVRec[21]: TuningFrequency
  2021-02-12 11:47:21.889728 I [32334/32405] TVRecEvent recorders/ExternalChannel.cpp:21 (Open) - ExternChan[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): Open()
  2021-02-12 11:47:21.891806 I [32334/32405] TVRecEvent recorders/channelbase.cpp:618 (InitializeInput) - ChannelBase[21]: Input #21: 'MPEG2TS' schan(1) sourceid(4)
  2021-02-12 11:47:21.891880 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:550 (ExternalStreamHandler) - ExternSH[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): args "--conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf --verbose general,channel,record --logpath /var/log/mythtv --loglevel info --quiet --inputid 21"
  2021-02-12 11:47:21.891942 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:913 (OpenApp) - ExternSH[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): Spawn '/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf'
  2021-02-12 11:47:21.891950 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:231 (Run) - ExternIO::Run()
  2021-02-12 11:47:21.910956 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:321 (Fork) - ExternIO::Fork 'mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf --verbose general,channel,record --logpath /var/log/mythtv --loglevel info --quiet --inputid 21'
  2021-02-12 11:47:21.914682 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:379 (Fork) - Spawned
  2021-02-12 11:47:22.157517 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:1319 (ProcessVer1) - ExternSH[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): ProcessCommand('APIVersion?') = 'OK:2' took 232ms
  2021-02-12 11:47:22.157678 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:1460 (ProcessVer2) - ExternSH[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): ProcessV2('1:APIVersion:2') = 'OK:2' took 0ms
  2021-02-12 11:47:22.157785 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:1460 (ProcessVer2) - ExternSH[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): ProcessV2('2:Version?') = 'OK:0.6' took 0ms
  2021-02-12 11:47:22.157917 W [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:1460 (ProcessVer2) - ExternSH[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): ProcessV2('3:Description?') = 'WARN:Not set' took 0ms <-- NOTE
  2021-02-12 11:47:26.161611 E [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:1423 (ProcessVer2) - ExternSH[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): ProcessVer2: Giving up waiting for response for command '4:HasTuner?'
  2021-02-12 11:47:26.167204 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:1460 (ProcessVer2) - ExternSH[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): ProcessV2('5:HasTuner?') = 'OK:Yes' took 5ms
  2021-02-12 11:47:26.177405 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:1460 (ProcessVer2) - ExternSH[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): ProcessV2('6:HasPictureAttributes?') = 'OK:No' took 10ms
  2021-02-12 11:47:26.177584 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:1460 (ProcessVer2) - ExternSH[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): ProcessV2('7:FlowControl?') = 'OK:XON/XOFF' took 0ms
  2021-02-12 11:47:26.177599 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:970 (OpenApp) - ExternSH[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): App opened successfully
  2021-02-12 11:47:26.177615 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:978 (OpenApp) - ExternSH[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): Capabilities: tuner(yes) Picture attributes(no) Flow control(XON/XOFF)
  2021-02-12 11:47:26.187687 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:1460 (ProcessVer2) - ExternSH[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): ProcessV2('8:BlockSize:1540096') = 'OK' took 10ms
  2021-02-12 11:47:26.187718 I [32334/32405] TVRecEvent recorders/ExternalStreamHandler.cpp:470 (Get) - ExternSH[21]: Creating new stream handler 21 for /usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf
  2021-02-12 11:47:26.187734 I [32334/32405] TVRecEvent recorders/ExternalChannel.cpp:52 (Open) - ExternChan[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): Opened
  2021-02-12 11:47:26.187748 I [32334/32405] TVRecEvent recorders/dtvchannel.cpp:159 (SetChannelByString) - DTVChan[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): SetChannelByString(1):
  2021-02-12 11:47:26.187759 I [32334/32405] TVRecEvent cardutil.cpp:2055 (GetConflictingInputs) - CardUtil[21]: GetConflictingInputs() input 21
  2021-02-12 11:47:26.188661 I [32334/32405] TVRecEvent cardutil.cpp:2087 (GetConflictingInputs) - CardUtil[21]: GetConflictingInputs() got input 22
  2021-02-12 11:47:26.188682 I [32334/32405] TVRecEvent cardutil.cpp:2087 (GetConflictingInputs) - CardUtil[21]: GetConflictingInputs() got input 23
  2021-02-12 11:47:26.188698 I [32334/32405] TVRecEvent cardutil.cpp:2087 (GetConflictingInputs) - CardUtil[21]: GetConflictingInputs() got input 24
  2021-02-12 11:47:26.188765 I [32334/32405] TVRecEvent recorders/channelbase.cpp:259 (IsInputAvailable) - ChannelBase[21]: Input is free on 0/0
  2021-02-12 11:47:26.190694 E [32334/32405] TVRecEvent dtvmultiplex.cpp:412 (ParseTuningParams) - DTVMux: ParseTuningParams -- Unknown tuner type = 0xffffffff80000000
  2021-02-12 11:47:26.190750 E [32334/32405] TVRecEvent recorders/dtvchannel.cpp:290 (SetChannelByString) - DTVChan[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): SetChannelByString(1): Failed to initialize multiplex options
  2021-02-12 11:47:26.190761 I [32334/32405] TVRecEvent recorders/dtvchannel.cpp:320 (SetChannelByString) - DTVChan[21](/usr/bin/mythexternrecorder --conf /home/peter/delat/script/mythtv-svtplay-external-recorder.conf): SetChannelByString(1): failure
  2021-02-12 11:47:26.190774 E [32334/32405] TVRecEvent tv_rec.cpp:3737 (TuningFrequency) - TVRec[21]: Failed to set channel to 1. Reverting to kState_None
  2021-02-12 11:47:26.190803 I [32334/32405] TVRecEvent tv_rec.cpp:1057 (HandleStateChange) - TVRec[21]: Changing from WatchingLiveTV to None



More information about the mythtv-users mailing list