17 replies to this topic

[betacentauri]

Attached is a patch to enable timeshift in radio mode. I have tested it here with some radio channels.
Pause and unpause works good. Seeking is problematic. Sometimes it switches to live tv. Currently I don't know why. I'll have to debug it in the next days. Because of low bitrate there might be also problems with seeking when you are only some seconds before live tv.
At best wait before seeking several seconds after timeshift start (otherwise it will most probably switch to live tv).

Some infos for pli team:[list]
[*]timing_pid_type must be -1 to stop writing entries in .sc file
[*]To the changes in tstools.cpp calcEnd 1:
If file size changes, the procedure searches a new m_pts_end and the corresponding m_offset_end. m_offset_end is lower than current filesize (=m_last_filelength).
Let's assume that file size haven't changed when calcEnd is executed the next time. Then "m_offset_end = m_last_filelength;" is executed. So m_offset_end changes and m_pts_end not. I don't think that that is correct.
[*]To the changes in calcEnd 2:
getLastFrame changes m_offset_end to 0, if empty .sc exists(if no .sc file exist, m_offset_end is not changed.). So with empty .sc file m_pts_end will be found only at file start (because m_offset_end is 0). To get correct offsets, I restore old offset value before searching a new one.
[/list]
Enjoy testing, timeshifting...

Attached Files

•  Timeshift-in-radio-mode-enabled.zip   1.11KB   10 downloads

[pieterg]

I'd like to commit the separate fixes separately, if you don't mind?
At least the streamtype -1 fix, which corrects a simple copy/paste error, there can be no discussion about that.
Regarding the tstools changes, there might be some discussion about the best way to fix things.
(for instance, pass temporary variables to getLastFrame, to make sure current values are not invalidated when getLastFrame returns an error, that would make the code a bit more readable I think)

[betacentauri]

Hi pieterg,

yes, sure! And I was also thinking whether I should add a new temporary variable for the offset. But that meant several more changes...
So feel free changing it.

It would be good, if you also can test with another receiver (I have a et9200). Because of low bitrate you'll need to wait some seconds before m_pts_begin and m_pts_end are found and m_pts_length>0. Could it be possible to lower buffer size for radio recordings to make it quicker?
Or is it too much work?

Edited by betacentauri, 6 February 2013 - 00:04.

[pieterg]

Could it be possible to lower buffer size for radio recordings to make it quicker?

yes, probably (not having looked at the code, but of course there is a way, if it's needed)

[betacentauri]

Well, wait. Not only for radio recordings.
What about using a smaller buffer only for first write into a recording file.
Also tv time shift on channels with low bitrate could profit. What do you think?

[pieterg]

that might lead to buffer overflows, especially when the hdd is spinning up

[betacentauri]

Hi pieterg,

I have searched the reason why sometimes seeking switches to live tv even when seek point is far away from end of file.
In my debug logs I often see this:

cur_pos: 962560 filesize 962560, maxread: 96256, span_remain 1072779136								
maxread: 96256																						  
buf_end 0																
buf_end == 0, send_pvr... 1																			
wait for driver eof timeout  

So current position in file is equal to filesize. In this case a timeout occurs in poll (see filepush.cpp).

When seek switches to live tv I see this:

before getNextSourceSpan current_position: 2406400
...
ok, resolved skip (rel: 1, diff 2511828), now at 0013bc80											  
after NextSourceSpan current_pos: 1293440													  
cur_pos: 1293440 filesize 2502656, maxread: 96256, span_remain 1073741696							  
maxread: 96256																					
buf_end 96256																						  
cur_pos: 1389696 filesize 2502656, maxread: 96256, span_remain 1073645440					  
maxread: 96256																						  
buf_end 96256																				  
cur_pos: 1485952 filesize 2502656, maxread: 96256, span_remain 1073549184							  
maxread: 96256																						  
buf_end 96256													  
....
cur_pos: 2448512 filesize 2502656, maxread: 96256, span_remain 1072586624	  
maxread: 96256																						  
buf_end 54144																  
cur_pos: 2502656 filesize 2502656, maxread: 96256, span_remain 1072532480							  
maxread: 96256																						  
buf_end 0																							  
buf_end == 0, send_pvr... 1											  
POLLIN 1 POLLERR 0 POLLHUP 0 POLLNVAL 0																
wait for driver eof ok																				  
Filepush send EOF!!!!!!!!			  

So position calculation is ok (it seeks back from 2406400 to 1293440). Afterwards I see only reading until end of file and at least EOF.
In this case poll returned 1 and EOF was sent.
According to this http://linux.die.net/man/3/poll 1 means that an event occured. You can see in the log that POLLIN was returned(it's the revent field). On the website stands: "Data other than high-priority data may be read without blocking." I read it like more data is available and not like EOF is reached.
This website http://www.greenend..../tech/poll.html says this:
"The lesson for authors of portable code is clear: test for both POLLIN and POLLHUP, and rely on the subsequent read() to tell you whether you reached EOF".
It confuses me. POLLIN means more data available but at the same time EOF???
Let's assume that EOF is correct. Then the other thread is not fast enough writing data into the timeshift file. But why is there no poll timeout??
I hope that you can help me a little bit with this.

[pieterg]

checking POLLIN to test for an empty decoder buffer is actually a hack, it doesn't follow any standards.
Remember we're not reading from the dvr device, and there is no data to be read, so normally POLLIN should not signal anything.

So the resources you found do not apply to this specific part of the e2 code.

[betacentauri]

Thanks for the answer! It's now too late for me to look into it. But I think that I know what I misinterpreted (poll isn't "watching" timeshift file, correct?).

[pieterg]

indeed, poll is just monitoring the video decoder fill level (in a non-POSIX way)

[betacentauri]

Now I monitored also writing to /dev/dvb/adapter0/demux0. I see this:

...
calculated diff 0 ms used pts 20005988									
aborting. Taking 10303528 as offset for 20005988						  
ok, resolved skip (rel: 1, diff 20005988), now at 009d3828				
after NextSourceSpan current_pos: 10303528								
cur_pos: 10303528 filesize 11550720, maxread: 96256, span_remain 1073741696
maxread: 96256															
buf_end 96256															
WRITE: buf_start 0 buf_end 96256										  
WRITE: 96256 bytes written, buf_start 0							  
cur_pos: 10399784 filesize 11550720, maxread: 96256, span_remain 1073645440
maxread: 96256															
buf_end 96256															
WRITE: buf_start 0 buf_end 96256										 
WRITE: 96256 bytes written, buf_start 0
...
cur_pos: 11458600 filesize 11550720, maxread: 96256, span_remain 1072586624	
maxread: 96256																  
buf_end 92120																  
WRITE: buf_start 0 buf_end 92120																												   
WRITE: 92120 bytes written, buf_start 0										
cur_pos: 11550720 filesize 11550720, maxread: 96256, span_remain 1072494504	
maxread: 96256																  
buf_end 0																	  
buf_end == 0, send_pvr... 1													
file descriptor m_fd_dest 51											  
POLLIN 1 POLLERR 0 POLLHUP 0 POLLNVAL 0								  
wait for driver eof ok													
Filepush send EOF!!!!!!!!				  

So, what is the conclusion?? Thread reads timeshift file and sends the data to demux. I see no error here. Demux should have enough data. Normally it shouldn't signal EOF in such case (I see several such conditions in log and only "wait for driver eof timeout" is shown). But here it signals EOF. Is it possible to debug it more? I fear no, because it's driver related, right?
So pieterg what do you think? Is it a driver bug?

Edited by betacentauri, 7 February 2013 - 21:53.

[pieterg]

Data is not written to the demux, but to the dvr device.

This is what goes on during a timeshift:

On the recording end, data is read from the demux, written to file. And at the playback end, it is read from the file, and written to the dvr device.

What could be happening, is that the POLLIN status gets confused about the video decoder being empty (because no video data is being written), so some false EOF conditions might occur?

[betacentauri]

Yes, dvr. I'm not very familiar with it yet (and I looked at file descriptor in /proc/<pid>/fd/... and there I saw demux, but timeshift wasn't active at that moment ).

False EOF conditions, maybe. But there must be a special condition, because it normally works and only after seeking sometimes (every 5-30 times) not.
Did you have time to test my changes? I would be good to hear whether these problems also occur on other hardware. If not, it hints to a driver bug.

[pieterg]

I just tested your changes, and to me it seems the decoder status (POLLIN) is correct, but what is happening is this:

because the recording buffers (both in the demux, and in the recorderfilepush thread) are huge, playback can run ahead of the recording, and the audio decoder literally risks draining.

Looking at the timeline, it fluctuates from 10s to 0s, back to 10s.
And whey it gets to 0s, the audio decoder almost drains.

Tried to decrease some buffer sizes, but it seems to be the combination of demux buffer (in the kernel), and the userspace buffers.
And possibly the read buffer (filepush) as well.
So there's no easy single point to tweak things, and make radio timeshift work smoothly.
Everything is optimized for large data bitrates.

[pieterg]

actually, now with 64K buffers I'm getting

[eFilePushThreadRecorder] OVERFLOW while recording

but still the difference between recording and playback point in the timeshift file is getting dangerously close to zero

[betacentauri]

But can it also explain the seeking problem? I seek back more than 30 seconds away from live tv. The thread reads very fast the timeshift data until timeshift file end and writes it to pvr(see my logs). So the audio decoder buffer should be filled. But pollin event occurs!

[pieterg]

I can't tell from your log, I don't see most of the usual debug messages around the skip action, so I cannot follow what's going on there.

[betacentauri]

At first thanks for checking in the changes, even when it's not 100% perfect!!

Attached are my debug sources and a log file.
Almost at the end of the log file I seek back to the start of the timeshift file. Then the filepush thread reads the whole timeshift file (~1,7 MB) within milliseconds and writes it to pvr. The next file read couldn't read a byte (buf_end==0) and poll returns POLLIN event.
So the audio decoder should have ~1,7MB data and I cannot see a reason why pvr signals EOF.


Can you reproduce this error? To be sure that it works you should at least do 20 seeks within timeshift file.

Attached Files

•  sources_with_debug_logs.tar.gz   22.67KB   1 downloads
•  log12.txt   91.07KB   2 downloads