[mythtv-users] ExternalRecorder - Errno 11
Marc Rawji
mrawji at gmail.com
Fri Nov 24 07:45:57 UTC 2017
On Thu, Nov 23, 2017 at 7:22 PM, Stephen Worthington <
stephen_agent at jsw.gen.nz> wrote:
> 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.
I made the changes and still the same behavior (somewhat expected). On a
hunch, i tried increasing the size of my 'writes' to 1k instead of 256
bytes, but no luck there either.
I'll see if I can come up with any other bright ideas.
Thanks,
Marc
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.mythtv.org/pipermail/mythtv-users/attachments/20171123/f0255b81/attachment.html>
More information about the mythtv-users
mailing list