[mythtv-users] ExternalRecorder - Errno 11

Marc Rawji mrawji at gmail.com
Thu Nov 23 23:59:07 UTC 2017


On Thu, Nov 23, 2017 at 7:40 AM, Peter Bennett <pb.mythtv at gmail.com> wrote:

>
>
> On 11/23/2017 12:50 AM, Marc Rawji wrote:
>
> On Wed, Nov 22, 2017 at 4:41 PM, Stephen Worthington <
> stephen_agent at jsw.gen.nz> wrote:
>
>> On Wed, 22 Nov 2017 10:28:39 -0800, you wrote:
>>
>> >On Tue, Nov 21, 2017 at 11:11 PM, Stephen Worthington <
>> >stephen_agent at jsw.gen.nz> wrote:
>> >
>> >> On Wed, 22 Nov 2017 06:03:31 +0000, you wrote:
>> >>
>> >> >Hi Everyone,
>> >> >
>> >> >I've been working on an external recorder for a while. It works most
>> of
>> >> the
>> >> >time, but recently i've been getting new errors.
>> >> >
>> >> <snip>
>> >> >My problem below is that I am getting a "Resource temporarily
>> unavailable
>> >> >(11)" when mythtv is trying to read from the stdin (the stdout of my
>> >> >program with the video stream)
>> >> >
>> >> >This seems to happen from this call:
>> >> >https://github.com/MythTV/mythtv/blob/master/mythtv/
>> >> libs/libmythtv/recorders/ExternalStreamHandler.cpp#L125
>> >> >
>> >> >The STDIN stream is configured to be non blocking, so the errno 11
>> isn't
>> >> >unexpected:
>> >> >https://github.com/MythTV/mythtv/blob/master/mythtv/
>> >> libs/libmythtv/recorders/ExternalStreamHandler.cpp#L343
>> >> >
>> >> >I am not sure what to change to keep this from happening.... it fails
>> >> about
>> >> >50% of the time, which is annoying.
>> >> >
>> >> >I am looking for advice on a fix, or how to troubleshoot. I am running
>> >> 0.29
>> >> >on Ubuntu 16.04.
>> >> >
>> >> >Thanks!
>> >> >Marc
>> >> >
>> >> <snip>
>> >>
>> >> If I am reading the ExternalStreamHandler.cpp.ExternIO::Read function
>> >> correctly, then the only way that can happen is if your stdout stream
>> >> indicates that it has data buffered and available to be read (the
>> >> poll() call from the Ready() call says there is data there), but then
>> >> your stdout fails to provide that data when it is called from read().
>> >> The most obvious reason I can think of for that would be if your code
>> >> was slow in responding to the read(), due to some unforeseen
>> >> circumstance such as garbage collection or being swapped out at the
>> >> time.  But I would have thought that your stdout buffer would have
>> >> been there waiting to be read, rather than any higher code needing to
>> >> be run to provide the data.  Are you using buffered I/O on your
>> >> stdout?
>> >>
>> >>
>> >Thanks for the quick reply Stephen. I am going to very quickly expose my
>> >ignorance on how these FDs work. (just setting expectations)
>> >
>> >Yes, I am using buffered output, specifically a BufferedWriter in Python
>> (
>> >https://docs.python.org/2/library/io.html#io.BufferedWriter). I added
>> >explicit "flush" commands after the 'write' command, but it didn't help.
>> >
>> >I'll try dropping the buffered output tonight and see what happens. I
>> >didn't think that using a buffered writer would affect how data is
>> present
>> >in the stream.
>> >
>> >Thanks,
>> >Marc
>>
>> I would have hoped that using a BufferedWriter would have provided
>> more buffering rather than less, but it would be useful to try a
>> normal file instead, using the normal buffering, to see if it makes a
>> difference.  The problem with this situation is that the
>> ExternalStreamHandler.cpp code needs to be able to read the data from
>> the pipe buffer instantly, as it has been told that there is data
>> waiting.  So if the buffer the data is coming from is not locked in
>> RAM, it may not be instantly available.  The normal file I/O buffers
>> in Python are handled in the underlying C library and should work the
>> way ExternalStreamHandler.cpp expects them to, but it is vaguely
>> possible that BufferedWriter changes that and accessing its buffers
>> requires running the Python interpreter, which could cause this
>> problem.  The documentation of BufferedWriter is not specific enough
>> about how it works to know exactly how its low level buffering works,
>> but it is suggestive that the data may be lying in a higher level
>> buffer.
>>
>>
> Just gave it a go and no joy, same behavior as before...
>
> In my Python code, the salient part is:
> data = fd.read(256)
> if data:
>     if (self.last_write_time is None):
>         self.logger.debug("First bytes written to stdout")
>     self.__bin_stdout.write(data)
>     self.__bin_stdout.flush()
>     self.last_write_time = time.time()
> self.writer_control.wait(0.5)
>
> and self.__bin_stdout is equal to sys.stdout.
>
> Would it have to do with:
> http://pubs.opengroup.org/onlinepubs/9699919799/functions/poll.html
>
> It indicates that for streams, the POLLIN is set even if the message is of
> zero length.
>
> Thanks,
> Marc
>
>
>
> I suggest creating a ticket for this.
>
> You may want to look at the import recorder. I recently committed a fix
> that allows it to be used for recordings. See the fix at
> https://code.mythtv.org/trac/ticket/13114 and documentation at
> https://www.mythtv.org/wiki/Import_recorder . Currently the fix is only
> available in master, scheduled for v30.
>
> Peter
>


Thanks for the suggestion, Peter. I'll look at possibly using the import
recorder...

Stephen, I grabbed the latest V30 (master) and hacked
up ExternalStreamHandler.cpp with extra log messages. I replaced the Ready
function to use select instead of poll and still had the same behavior. I
then commented out this line:
-        m_error = "Failed to read from External Recorder: " + ENO;
+        //m_error = "MR: Failed to read from External Recorder: " + ENO;
preventing the hard failure, and got a functioning video stream.

In the snippet below, FD 62 is the "stdout" with the transport stream.
The "Checking for data" line comes from the Ready function: 1 indicates
there's data to read.
The empty line in the log is the from the commented out m_error... It's
when we get the unexpected "erno 11".

We can see there's data before and after the error... I am not sure it's a
problem with the Ready function, but with the 'read'

2017-11-23 15:07:35.517510 I  ExternalRec(/home/mrawji/recorder/record.sh):
ProcessCommand('StopStreaming') = 'OK:Stopped'
2017-11-23 15:07:35.517516 E  ExternIO::Read '256' bytes, buffer size 312
2017-11-23 15:07:35.517690 E  MR:  Checking for data, return value was:
'1', for FD '62'
2017-11-23 15:07:35.517693 E  MR:  Checking for data, return value was:
'1', for FD '62'
2017-11-23 15:07:35.517700 E
2017-11-23 15:07:35.517709 E  ExternIO::Read '256' bytes, buffer size 380
2017-11-23 15:07:35.517822 E  MR:  Checking for data, return value was:
'1', for FD '62'
2017-11-23 15:07:35.517842 E  ExternIO::Read '256' bytes, buffer size 260
2017-11-23 15:07:35.517879 E  MR:  Checking for data, return value was:
'1', for FD '62'
2017-11-23 15:07:35.517901 E  ExternIO::Read '256' bytes, buffer size 328

I am thinking that I could possibly add a counter on the failed reads and
if we hit 2 (or n) in row, then fail... It also looks like it'll read "0
bytes" a few times despite the Ready function returning True. In the trace
above, I see 2 0 byte reads, followed by the "erno 11". Then, everything
keeps working again (9 microseconds after the error).

I am writing 256 bytes at a time from my python app... not sure if that
means anything.

Thanks
Marc
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.mythtv.org/pipermail/mythtv-users/attachments/20171123/db111532/attachment-0001.html>


More information about the mythtv-users mailing list