[mythtv-users] External recorder command flow

Wed Aug 10 16:35:47 UTC 2016

On Wed, Aug 3, 2016 at 8:52 PM, Marc Rawji <mrawji at gmail.com> wrote:

> On Wed, Aug 3, 2016 at 7:19 PM, John P Poet <jppoet at gmail.com> wrote:
>
>> On Tue, Aug 2, 2016 at 10:26 PM Marc Rawji <mrawji at gmail.com> wrote:
>>
>>> Hello (again),
>>>
>>> I am trying to write an external recorder. I don't quite understand the
>>> message flow that I am seeing in my recorder. I am seeing a StartStreaming,
>>> followed by a StropStreaming, then a StartStreaming, then it streams to the
>>> frontend.
>>>
>>> See my annotated and trimmed logs (removed Calls with no impact on the
>>> streaming, and the many many SendBytes):
>>> 2016-08-01 22:13:01,922 root        : DEBUG received TuneChannel:2
>>> 2016-08-01 22:13:01,975 root        : DEBUG received StartStreaming
>>> 2016-08-01 22:13:04,788 root        : DEBUG returning OK:Started  //Took
>>> approx 3 seconds to start getting data
>>> 2016-08-01 22:13:04,790 root        : DEBUG received SendBytes
>>> 2016-08-01 22:13:04,877 root        : DEBUG returning OK
>>>  //Sending 1 SendBytes of data to STDOUT
>>> 2016-08-01 22:13:04,895 root        : DEBUG received StopStreaming // as
>>> soon as i start sending data, i get a StopStreaming
>>> 2016-08-01 22:13:05,899 root        : DEBUG returning OK:Stopped
>>> 2016-08-01 22:13:06,007 root        : DEBUG received StartStreaming //
>>> as soon as it stops, then it asks me to start it again
>>> 2016-08-01 22:13:08,423 root        : DEBUG returning OK:Started //
>>> takes 2.5 seconds to start getting data
>>> 2016-08-01 22:13:08,430 root        : DEBUG received SendBytes  // we
>>> now send data
>>> 2016-08-01 22:13:08,602 root        : DEBUG returning OK
>>> <send bytes is repeated and I see data on frontend>
>>>
>>> [...]
>>>
>>> Does anyone know why I get a Start, followed by a Stop, then another
>>> Start?
>>>
>>>
>>> Mythbackend first checks to make sure the 'signal' is valid.  I have a
>> dream of changing it to hand off the stream from the SignalMonitor to the
>> Recorder, where it would not Start/Stop/Restart, but that is a major
>> architecture change.
>>
>> When running mythbackend, I would recommend using `-v channel,record` to
>> see more useful information.
>>
>> John
>>
>>
> Thanks so much for the reply. With the more verbose logging, I don't see
> anything worrisome between the Start and Stop:
>
> 2016-08-03 20:36:57.213675 I  ExternSH(/home/mrawji/recorder/record.sh):
> ProcessCommand('StartStreaming') = 'OK:Started'
> 2016-08-03 20:36:57.213695 I  ExternSH(/home/mrawji/recorder/record.sh):
> Streaming started
> 2016-08-03 20:36:57.213708 I  ExternSH(/home/mrawji/recorder/record.sh):
> StartStreaming 1 listeners
> 2016-08-03 20:36:57.414768 I  TVRec[1]: TuningSignalCheck: Good signal
> 2016-08-03 20:36:57.414809 I  TVRec[1]: SetRecordingStatus(Unknown->Recording)
> on line 4023
> 2016-08-03 20:36:57.414913 I  TVRec[1]: TeardownSignalMonitor() -- begin
> 2016-08-03 20:36:57.414934 I  ExternSigMon(/home/mrawji/recorder/record.sh):
> dtor
> 2016-08-03 20:36:57.414947 I  ExternSigMon(/home/mrawji/recorder/record.sh):
> Stop() -- begin
> 2016-08-03 20:36:57.414964 I  ExternSH(/home/mrawji/recorder/record.sh):
> StopStreaming 1 listeners
> 2016-08-03 20:36:57.414976 I  ExternSH(/home/mrawji/recorder/record.sh):
> StopStreaming
> 2016-08-03 20:36:57.424594 I  ExternSH(/home/mrawji/recorder/record.sh):
> ProcessCommand('Version?') = 'OK:1.0'
> 2016-08-03 20:36:58.432030 I  ExternSH(/home/mrawji/recorder/record.sh):
> ProcessCommand('StopStreaming') = 'OK:Stopped'
> 2016-08-03 20:36:58.434253 I  ExternSH(/home/mrawji/recorder/record.sh):
> Streaming stopped
> 2016-08-03 20:36:58.474514 I  SH(/home/mrawji/recorder/record.sh):
> RemoveListener(0x7f4574023420) -- begin
> 2016-08-03 20:36:58.474537 I  SH(/home/mrawji/recorder/record.sh):
> RemoveListener(0x7f4574023420) -- locked
> 2016-08-03 20:36:58.475340 I  ExternSH(/home/mrawji/recorder/record.sh):
> run(): shutdown
> 2016-08-03 20:36:58.475405 I  ExternSH(/home/mrawji/recorder/record.sh):
> run(): end
> 2016-08-03 20:36:58.475540 I  SH(/home/mrawji/recorder/record.sh):
> RemoveListener(0x7f4574023420) -- end
> 2016-08-03 20:36:58.475555 I  ExternSigMon(/home/mrawji/recorder/record.sh):
> Stop() -- end
>
> The only error I see before that is:
> 2016-08-03 20:36:54.493505 E  TVRec[1]: Profile 'Live TV' not found, and
> unable to load fallback profile 'Default'.  Results may be unpredicable
>
> But, i also see with the second "startStreaming" and then everything "just
> works".
>
>
>
For anyone who's interested in this topic, I pushed stopping the stream
into another thread and then waiting for a small delay in that new thread
before stopping the stream. If no "StartStreaming" message comes during
that delay, then the stream is killed. If I do get a "StartStreaming", I
abort the pending StopStreaming. Results have been good where I don't get a
studder on the start of the Stream. I've been able to record and watch Live
TV with this setup.

Marc
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.mythtv.org/pipermail/mythtv-users/attachments/20160810/90c92bd3/attachment.html>