[mythtv-users] Problems with ExternalRecorder and streamlink
John P Poet
jppoet at gmail.com
Fri Feb 12 17:20:04 UTC 2021
On Fri, Feb 12, 2021 at 4:35 AM Peter Carlsson <maillist.peter at home.se>
wrote:
> 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
>
Are you running v31 or v31-latest (v31-fixes)? If you are not running the
latest version of v31 you may be hitting a bug preventing it from handling
the situation where there are channels but no tuner. I had forgotten about
that because it was fixed so long ago.
John
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.mythtv.org/pipermail/mythtv-users/attachments/20210212/f7abde84/attachment.htm>
More information about the mythtv-users
mailing list