B
B-N
Guest
Hi support!
I get intermittent write errors on recordings a couple of times each week. I use a Synology DS413 as a network HDD for recordings. I have checked and rechecked the network and cables and can find no problem. No problem with diskspace or the server as far as I can determine.
So I started logging and am no longer so sure that error really is a write error. It may even be a serious error in OpenVIX code.
First indication of the error seems to come from the method
int eDVBRecordFileThread::AsyncIO::wait()
in the file https://github.com/OpenViX/enigma2/blob/master/lib/dvb/demux.cpp
I hope that is the right place and I’m not looking at old code
I include a copy of that method down a bit.
I get two different errors: EINTR and Success (0, no error!)
This suggest to me that something might be wrong with the code so I started trying to understand how the code works and why it may be possible to get those errors. Lots of code so I have probably misunderstood some of how it is supposed to work
If it really was a write error it would have been presented as a EDQUOT , EFBIG, EIO or ENOSPC or something like that.
EINTR means that the operation (in this case aio_write) was interrupted before it had any chance to begin writing data. If it would have been interrupted later it would have been a “short write”. In both cases the write need to be restarted.
The code just aborts on EINTR. Is that really the intended behaviour? The return value of aio_return is only used for error checking and don't check how many bytes was actually written successfully, to check for a short write.
I have no idea what signal causes the interrupt, maybe internal use in some library or elsewhere in Enigma2, but the possibility of an interrupt should always be taken into account in all code. Even if the interrupt is handled correctly so that user code continues without problems, system calls may be interrupted and has to be restarted after an interrupt.
My first thought was that maybe AIO-calls don’t need to check for interrupts or short writes. Searching the Internet indicates that some people believe so. But reading the documentation for AIO a bit I think it says that the AIO-calls behave exactly the same as the corresponding normal IO-calls with mostly the same errors and return values.
And I obviously get an interrupt during aio_write so in my mind that means it must be handled correctly! And from that follows that short writes must also be handled.
Even worse is that none of the potential short writes are logged or reported to the user. That may mean there are a lot of recordings out there that are missing small chunks here and there without anyone knowing. When I notice freezes and jumps in a recording I have previously said “it was probably bad weather when it was recorded”. Maybe not?
So I think there are two problems with the code: EINTR and short writes are not handled correctly.
Disclaimer: I have not been programming low level Unix code for the last 15 years so my memory may be a bit fuzzy and out dated about some details I hope no one feels insulted by my opinions how code should be written in the best of worlds. And I have a tendency to talk to much
I have yet to figure out why I got one “Success”-error, that is a bit strange.
Another thought: why does the code use AIO instead of normal IO?
The method I think generates the first error:
Selected parts of the loggs:
I get intermittent write errors on recordings a couple of times each week. I use a Synology DS413 as a network HDD for recordings. I have checked and rechecked the network and cables and can find no problem. No problem with diskspace or the server as far as I can determine.
So I started logging and am no longer so sure that error really is a write error. It may even be a serious error in OpenVIX code.
First indication of the error seems to come from the method
int eDVBRecordFileThread::AsyncIO::wait()
in the file https://github.com/OpenViX/enigma2/blob/master/lib/dvb/demux.cpp
I hope that is the right place and I’m not looking at old code
I include a copy of that method down a bit.
I get two different errors: EINTR and Success (0, no error!)
This suggest to me that something might be wrong with the code so I started trying to understand how the code works and why it may be possible to get those errors. Lots of code so I have probably misunderstood some of how it is supposed to work
If it really was a write error it would have been presented as a EDQUOT , EFBIG, EIO or ENOSPC or something like that.
EINTR means that the operation (in this case aio_write) was interrupted before it had any chance to begin writing data. If it would have been interrupted later it would have been a “short write”. In both cases the write need to be restarted.
The code just aborts on EINTR. Is that really the intended behaviour? The return value of aio_return is only used for error checking and don't check how many bytes was actually written successfully, to check for a short write.
I have no idea what signal causes the interrupt, maybe internal use in some library or elsewhere in Enigma2, but the possibility of an interrupt should always be taken into account in all code. Even if the interrupt is handled correctly so that user code continues without problems, system calls may be interrupted and has to be restarted after an interrupt.
My first thought was that maybe AIO-calls don’t need to check for interrupts or short writes. Searching the Internet indicates that some people believe so. But reading the documentation for AIO a bit I think it says that the AIO-calls behave exactly the same as the corresponding normal IO-calls with mostly the same errors and return values.
And I obviously get an interrupt during aio_write so in my mind that means it must be handled correctly! And from that follows that short writes must also be handled.
Even worse is that none of the potential short writes are logged or reported to the user. That may mean there are a lot of recordings out there that are missing small chunks here and there without anyone knowing. When I notice freezes and jumps in a recording I have previously said “it was probably bad weather when it was recorded”. Maybe not?
So I think there are two problems with the code: EINTR and short writes are not handled correctly.
Disclaimer: I have not been programming low level Unix code for the last 15 years so my memory may be a bit fuzzy and out dated about some details
I hope no one feels insulted by my opinions how code should be written in the best of worlds. And I have a tendency to talk to much I have yet to figure out why I got one “Success”-error, that is a bit strange.
Another thought: why does the code use AIO instead of normal IO?
The method I think generates the first error:
Code:
int eDVBRecordFileThread::AsyncIO::wait()
{
if (aio.aio_buf != NULL) // Only if we had a request outstanding
{
while (aio_error(&aio) == EINPROGRESS)
{
eDebug("[eDVBRecordFileThread] Waiting for I/O to complete");
struct aiocb* paio = &aio;
int r = aio_suspend(&paio, 1, NULL);
if (r < 0)
{
eDebug("[eDVBRecordFileThread] aio_suspend failed: %m");
return -1;
}
}
int r = aio_return(&aio);
aio.aio_buf = NULL;
if (r < 0)
{
eDebug("[eDVBRecordFileThread] wait: aio_return returned failure: %m");
return -1;
}
}
return 0;
}Selected parts of the loggs:
Code:
...
< 52876.093> [eDVBRecordFileThread] wait: aio_return returned failure: Interrupted system call
< 52876.094> [eFilePushThreadRecorder] WRITE ERROR, aborting thread: Interrupted system call
< 52876.094> [eDVBRecordFileThread] waiting for aio to complete
< 52876.094> [eDVBRecordFileThread] Waiting for I/O to complete
< 52876.094> [eDVBServiceRecord] record write error
< 52876.094> [eDVBServiceRecord] stop recording!
< 52876.095> [eFilePushThreadRecorder] stopping thread.
< 52876.095> [eDVBRecordFileThread] Waiting for I/O to complete
< 52876.096> [eDVBRecordFileThread] buffer usage histogram (40 buffers of 188 kB)
< 52876.096> [eDVBRecordFileThread] 0: 18
< 52876.096> [eDVBRecordFileThread] 1: 5559
< 52876.096> [eDVBRecordFileThread] 2: 5507
< 52876.248> [eFilePushThreadRecorder] THREAD STOP
< 52876.295> [eDVBTSTools] setSource loading streaminfo for /media/hdd/movie/20161108 0625 - SVT1 HD - Gomorron Sverige.ts
< 52876.304> [eDVBServiceRecord] fixed up 16b837f25 to 45241 (offset 0)
< 52876.309> [RecordTimer] WRITE ERROR on recording, disk full?
< 52876.310> [Notifications] RemovePopup, id = DiskFullMessage
< 52876.310> [Notifications] AddPopup, id = DiskFullMessage
…
< 19043.820> [eDVBRecordFileThread] wait: aio_return returned failure: Interrupted system call
< 19043.820> [eFilePushThreadRecorder] WRITE ERROR, aborting thread: Interrupted system call
< 19043.820> [eDVBRecordFileThread] waiting for aio to complete
< 19043.820> [eDVBRecordFileThread] Waiting for I/O to complete
< 19043.821> [eDVBServiceRecord] record write error
< 19043.821> [eDVBServiceRecord] stop recording!
< 19043.822> [eFilePushThreadRecorder] stopping thread.
< 19043.824> [eDVBRecordFileThread] buffer usage histogram (40 buffers of 188 kB)
< 19043.824> [eDVBRecordFileThread] 0: 67
< 19043.824> [eDVBRecordFileThread] 1: 4879
< 19043.824> [eDVBRecordFileThread] 2: 4818
< 19043.995> [eFilePushThreadRecorder] THREAD STOP
< 19044.002> [eDVBTSTools] setSource loading streaminfo for /media/hdd/movie/20161111 1500 - H2 HD - Engineering Disasters.ts
< 19044.006> [eDVBServiceRecord] fixed up 9b646bb8 to a4fdb (offset 0)
< 19044.009> [RecordTimer] WRITE ERROR on recording, disk full?
< 19044.009> [Notifications] RemovePopup, id = DiskFullMessage
< 19044.009> [Notifications] AddPopup, id = DiskFullMessage
...
< 20762.202> [eDVBRecordFileThread] wait: aio_return returned failure: Success
< 20762.203> [eFilePushThreadRecorder] WRITE ERROR, aborting thread: Success
< 20762.203> [eDVBRecordFileThread] waiting for aio to complete
< 20762.203> [eDVBRecordFileThread] Waiting for I/O to complete
< 20762.203> [eDVBServiceRecord] record write error
< 20762.203> [eDVBServiceRecord] stop recording!
< 20762.204> [eFilePushThreadRecorder] stopping thread.
< 20762.205> [eDVBRecordFileThread] buffer usage histogram (40 buffers of 188 kB)
< 20762.206> [eDVBRecordFileThread] 0: 49
< 20762.206> [eDVBRecordFileThread] 1: 11634
< 20762.206> [eDVBRecordFileThread] 2: 11565
< 20762.268> [eFilePushThreadRecorder] THREAD STOP
< 20762.277> [eDVBTSTools] setSource loading streaminfo for /media/hdd/movie/Helmy/20161107 2100 - Animal Planet HD - My cat from hell.ts
< 20762.294> [eDVBServiceRecord] fixed up 14dd02ade to e4af6 (offset 0)
< 20762.294> [eDVBServiceRecord] fixed up 15f79eb9e to 11b80bb6 (offset 0)
< 20762.304> [RecordTimer] WRITE ERROR on recording, disk full?
< 20762.304> [Notifications] RemovePopup, id = DiskFullMessage
< 20762.304> [Notifications] AddPopup, id = DiskFullMessage
…..
rocessOneEvent] unhandled POLLERR/HUP/NVAL for fd NN(16)
