[mythtv-users] ExternalRecorder - Errno 11
Stephen Worthington
stephen_agent at jsw.gen.nz
Fri Nov 24 03:22:44 UTC 2017
On Thu, 23 Nov 2017 15:59:07 -0800, you wrote:
>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
That certainly seems like a valid workaround, but it would be nice to
be able to explain why it is happening when it should not be.
I have seen what look like a couple of bugs in the
ExternalStreamHandler.cpp code while I have been reading it. The
first is in Ready, where I believe the line:
if (m_poll[0].revents & POLLIN)
should instead be:
if (m_poll[0].revents & (POLLIN|POLLPRI))
The second is in Fork where there is this code:
bool error = false;
error = (fcntl(m_appin, F_SETFL, O_NONBLOCK) == -1);
error = (fcntl(m_appout, F_SETFL, O_NONBLOCK) == -1);
error = (fcntl(m_apperr, F_SETFL, O_NONBLOCK) == -1);
That overwrites the error flag, when they should be ORed together. So
I think this should work:
bool error =
(fcntl(m_appin, F_SETFL, O_NONBLOCK) == -1) ||
(fcntl(m_appout, F_SETFL, O_NONBLOCK) == -1) ||
(fcntl(m_apperr, F_SETFL, O_NONBLOCK) == -1);
or maybe
bool error = false;
error = error || (fcntl(m_appin, F_SETFL, O_NONBLOCK) == -1);
error = error || (fcntl(m_appout, F_SETFL, O_NONBLOCK) == -1);
error = error || (fcntl(m_apperr, F_SETFL, O_NONBLOCK) == -1);
if it is required that all the fcntl calls always be performed.
I can not see why either of those problems would be causing what you
are seeing, but it might be worthwhile trying the fixes just in case.
More information about the mythtv-users
mailing list