Opened 14 years ago

Closed 13 years ago

Last modified 13 years ago

#1153 closed patch (fixed)

Ringbuffer Race condition

Reported by: ben@… Owned by: danielk
Priority: minor Milestone: 0.21
Component: mythtv Version: head
Severity: medium Keywords:
Cc: andrew@… Ticket locked: no

Description (last modified by danielk)

When entering LiveTV and sometimes when in LIveTV at the changeover point for the next show this error message is displayed. "Error was encountered while displaying video."

Sometimes if you leave LiveTV mode and go back in it will start to work again, sometimes you have to do this 4 or 5 times. Sometimes it never seems to want to show LiveTV.

The frontend longs suggest its some sort of issue with the ring buffer file being created :-

2006-01-28 21:18:46.114 RingBuf(/data/video/record/1025_20060128211843.mpg): Invalid file (fd 17) when opening '/data/video/record/1025_20060128211843.mpg'. 4 retries remaining.
2006-01-28 21:18:46.190 Video timing method: USleep with busy wait
2006-01-28 21:18:46.618 RingBuf(/data/video/record/1025_20060128211843.mpg): Invalid file (fd 17) when opening '/data/video/record/1025_20060128211843.mpg'. 3 retries remaining.
2006-01-28 21:18:47.030 NVP: Prebuffer wait timed out 10 times.
2006-01-28 21:18:47.122 RingBuf(/data/video/record/1025_20060128211843.mpg): Invalid file (fd 17) when opening '/data/video/record/1025_20060128211843.mpg'. 2 retries remaining.
2006-01-28 21:18:47.626 RingBuf(/data/video/record/1025_20060128211843.mpg): Invalid file (fd 17) when opening '/data/video/record/1025_20060128211843.mpg'. 1 retries remaining.
2006-01-28 21:18:47.870 NVP: Prebuffer wait timed out 10 times.
2006-01-28 21:18:48.130 RingBuf(/data/video/record/1025_20060128211843.mpg): Invalid file (fd 17) when opening '/data/video/record/1025_20060128211843.mpg'. 0 retries remaining.
2006-01-28 21:18:48.634 NVP, Error: JumpToProgram's OpenFile failed.
2006-01-28 21:18:48.634 NVP, Error: Unknown error, exiting decoder
2006-01-28 21:18:48.710 NVP: Prebuffer wait timed out 10 times.

Since scheduling a recording works fine (even the TV show you wanted to watch live) its clearly not an issue with physical disk space or a permissions thing. Both the frontend and backed are running as the same unprivileged user "mythtv".

There is nothing of interest in the backend logs as far as I can tell related to this.

Ben

Attachments (11)

mythbackend.log (76.9 KB) - added by ben@… 14 years ago.
Backend log
mythfrontend.log (10.8 KB) - added by ben@… 14 years ago.
Frontend log
1153.txt (122.5 KB) - added by bob@… 14 years ago.
Logs from Bob's Myth box
logsfromjohnsbox.tar.gz (7.0 KB) - added by John Pullan <john.pullan@…> 14 years ago.
Logs from John's box
logsfromjohnsbox.2.tar.gz (5.6 KB) - added by John Pullan <john.pullan@…> 14 years ago.
More logs
backend.log (76.4 KB) - added by and001@… 13 years ago.
frontend.log.bz2 (228.4 KB) - added by and001@… 13 years ago.
ringBufferSwitchRaceConditionFix.diff (2.7 KB) - added by Bradley Kite <bradley.kite@…> 13 years ago.
Patch to fix this bug.
1153-v2.patch (3.1 KB) - added by danielk 13 years ago.
Possible fix for problem
mythfrontend.out (38.1 KB) - added by tino.keitel+mythtv@… 13 years ago.
some succesful program changes and a failed one at the end
mythbackend.out (53.7 KB) - added by tino.keitel+mythtv@… 13 years ago.
backend log of some successful program changes and a failed one at the end

Download all attachments as: .zip

Change History (58)

comment:1 Changed 14 years ago by danielk

Milestone: 0.19
Owner: changed from ljr to danielk
Version: head

comment:2 Changed 14 years ago by danielk

Description: modified (diff)
Resolution: invalid
Status: newclosed

What revision were you using?

There have been a number of fixes for this and related problems in the last 72 hours.

Also I will need full backend and frontend logs with '-v record,channel,siparser' and '-v playback' respectively. If they are on seperate machines, sync the clocks. And use the latest SVN, and tell me the revision.

Please use "Attach File" for the logs.

comment:3 Changed 14 years ago by ben@…

I was using revision 8761. I will update to the latest now (8778) and run with the -v flags. Both are running on the same machine.

If I encounter the problem again, I'll repoen.

Thanks

Bem

comment:4 Changed 14 years ago by ben@…

Resolution: invalid
Status: closedreopened

Unfortunately first time I tried it with the new version it failed. I'm running :-

Library API version: 0.19.20060121-2 Source code version: 8788M Options compiled in:

linux release using_oss using_alsa using_arts using_dbox2 using_lirc using_joystick_menu using_dvb using_dvb_eit using_x11 using_xv using_xrandr using_frontend using_backend

Regards

Ben

Changed 14 years ago by ben@…

Attachment: mythbackend.log added

Backend log

Changed 14 years ago by ben@…

Attachment: mythfrontend.log added

Frontend log

comment:5 Changed 14 years ago by danielk

Can you try increasing the retryCount on line 45 of RingBuffer?.h:

    void OpenFile(const QString &lfilename, uint retryCount = 4);

Something like 15 should work, but try larger and smaller values until you find the smallest one that works.. (but over about 25 you will start seeing other problems..)

comment:6 Changed 14 years ago by john.pullan@…

I'm also getting this error. Increasing the retry count didn't help me out any. I'd be tempted to bump priority to major :)

comment:7 Changed 14 years ago by ben@…

So far 10 is looking like a good number, 8 causes problems on some channels but not all. So far 10 has been good on all channels tested, but only a few days testing will tell I guess if its a permanent fix, or only a 99% fix.

Ben

comment:8 Changed 14 years ago by ben@…

Hmm,

I just got the error again, and I have tried various numbers now right upto 25, all are now giving me the error.

Ben

comment:9 Changed 14 years ago by bob@…

Can I jump in and say that I'm having the same problem, except I have never succeeded in getting livetv to display. I just upped the retries to 25 and no difference.

running 2.6.15, FX5200, FC4, Compro DVB-T200 card. SVN 8798.

Frontend and backend logs can be supplied if needed, but they look very similar to those already posted by others.

comment:10 Changed 14 years ago by danielk

John & Bob, please post your logs; the problem Ben is experiencing is due to the DVB recording taking too long to start up, I'd like to know if you are experiencing something similar, or if the recording doesn't start at all. Please also post the output of 'date ; ls -l /name/of/last/video/file.mpg" once the frontend gives you the error message, so I can estimate if and when the recording actually started.

Ben can you post the logs from when a high retry counts don't help?

Changed 14 years ago by bob@…

Attachment: 1153.txt added

Logs from Bob's Myth box

comment:11 Changed 14 years ago by John Pullan <john.pullan@…>

This is back with the retry count set to 4 again [jmp@killingtime ~]$ date Tue Jan 31 19:17:06 GMT 2006 [jmp@killingtime ~]$ ls -l /var/video/ total 7728 -rw-r--r-- 1 jmp jmp 2319732 Jan 31 19:16 1011_20060131191628.mpg -rw-rw-r-- 1 jmp jmp 184 Jan 31 19:16 1011_20060131191628.mpg.png -rw-r--r-- 1 jmp jmp 5569312 Jan 31 19:16 1011_20060131191629.mpg -rw-rw-r-- 1 jmp jmp 0 Jan 31 19:16 nfslockfile.lock

Changed 14 years ago by John Pullan <john.pullan@…>

Attachment: logsfromjohnsbox.tar.gz added

Logs from John's box

comment:12 Changed 14 years ago by danielk

Bob, I couldn't make heads or tails of your logs. Please use '-v record,channel' for the backend, and '-v playback' for the frontend.

John, it looks like you are experiencing a variation of #971, somehow you are not getting the ringbuffer switch into the real recording after the pseudorecording ends. This acts like the transition from one recording to the next when using a recorder such as the PVR-250.

comment:13 Changed 14 years ago by danielk

Resolution: duplicate
Status: reopenedclosed

Closing as a duplicate of #894.

I will put in the stopgap fix for #894, this until we re-engineer the SIParser in 0.20.

comment:14 Changed 14 years ago by John Pullan <john.pullan@…>

Resolution: duplicate
Status: closedreopened

Here are the logs you requested. (Just went in and got the error immediately)

Changed 14 years ago by John Pullan <john.pullan@…>

Attachment: logsfromjohnsbox.2.tar.gz added

More logs

comment:15 Changed 14 years ago by John Pullan <john.pullan@…>

Resolution: fixed
Status: reopenedclosed

Ijr's fix 8847 seems to have fixed this so I'm re-closing it.

comment:16 Changed 13 years ago by andrew@…

Cc: andrew@… added
Resolution: fixed
Status: closedreopened

I am using atrpms version mythtv-0.19-128.rhfc5.at, which was cooked Wed 03 May 2006 and I still get the same error. The machine is a combined client/server with no NFS or SMB involved. Here is a snip from the log:

2006-06-05 08:24:36.921 NVP: Enabling Audio 2006-06-05 09:15:12.559 RingBuf?(/export/mythtv-rec/1001_20060605091501.mpg): Invalid file (fd 17) when opening '/export/mythtv-rec/1001_20060605091501.mpg'. 10 retries remaining. 2006-06-05 09:15:12.875 NVP: prebuffering pause 2006-06-05 09:15:13.106 RingBuf?(/export/mythtv-rec/1001_20060605091501.mpg): Invalid file (fd 17) when opening '/export/mythtv-rec/1001_20060605091501.mpg'. 9 retries remaining.

... above line for 9 -> 2

2006-06-05 09:15:17.210 RingBuf?(/export/mythtv-rec/1001_20060605091501.mpg): Invalid file (fd 17) when opening '/export/mythtv-rec/1001_20060605091501.mpg'. 1 retries remaining. 2006-06-05 09:15:17.738 RingBuf?(/export/mythtv-rec/1001_20060605091501.mpg): Invalid file (fd 17) when opening '/export/mythtv-rec/1001_20060605091501.mpg'. 0 retries remaining. 2006-06-05 09:15:17.794 NVP: Prebuffer wait timed out 10 times. 2006-06-05 09:15:18.242 NVP, Error: SwitchToProgram?'s OpenFile? failed. 2006-06-05 09:15:18.242 NVP, Error: Unknown error, exiting decoder 2006-06-05 09:15:18.243 TV: Attempting to change from WatchingLiveTV to None

This is causing me a real problem.

comment:17 Changed 13 years ago by anonymous

mythbackend --version, please.

comment:18 Changed 13 years ago by andrew@…

Package: mythtv-backend-0.19-128.rhfc5.at

# mythbackend --version Library API version: 0.19.20060121-2 Source code version: Unknown Options compiled in:

linux release using_xvmcw using_v4l using_oss using_alsa using_arts using_ivtv using_firewire using_dbox2 using_lirc using_joystick_menu using_dvb using_dvb_eit using_x11 using_xv using_dvdnav using_xrandr using_xvmc using_xvmc_vld using_opengl_vsync using_frontend using_backend

comment:19 Changed 13 years ago by danielk

Owner: changed from danielk to Isaac Richards
Status: reopenednew

comment:20 Changed 13 years ago by danielk

Resolution: fixed
Status: newclosed

You need to test with the latest svn, either head or 0.19-fixes, and you will need to provide matching logs from the frontend and backend, with '-v playback' and '-v record,channel', respectively.

comment:21 Changed 13 years ago by and001@…

Resolution: fixed
Status: closedreopened

Still having issues at the transition from one show to the next watching LiveTV using the 0.19-fixes. I have attached my logs and the version info is below.

Library API version: 0.19.20060121-2 Source code version: 10249 Options compiled in:

linux release using_xvmcw using_v4l using_oss using_alsa using_arts using_ivtv using_firewire using_dvb using_dvb_eit using_x11 using_xv using_dvdnav using_xrandr using_xvmc using_xvmc_vld using_opengl_vsync using_frontend using_backend

Changed 13 years ago by and001@…

Attachment: backend.log added

Changed 13 years ago by and001@…

Attachment: frontend.log.bz2 added

comment:22 Changed 13 years ago by anonymous

I had a similar issue, which I finally traced to the clocks on the front and back ends being out by ~20minutes. I'm not sure how close they have to be, but I now use NTP to keep them exact and it has worked for me. YMMV.

comment:23 Changed 13 years ago by and001@…

I am running the frontend and backend on the same machine.

comment:24 Changed 13 years ago by anonymous

Milestone: 0.190.19.1

comment:25 Changed 13 years ago by danielk

Resolution: wontfix
Status: reopenedclosed

If you have this problem upgrade to SVN head, or wait for 0.20. The problem code no longer exists there.

comment:26 Changed 13 years ago by and001@…

Resolution: wontfix
Status: closedreopened

I have upgraded to the SVN head on Monday (10766) as well as updating my kernel to 2.6.17-1.2142_FC4 and this problem is still occurring for me.

I am running 2 V-stream xpert DVB-T PCI capture cards using the cx88-dvb module if that is of any consequence.

comment:27 Changed 13 years ago by anonymous

Milestone: 0.19.1unknown

comment:28 in reply to:  27 Changed 13 years ago by anonymous

I also have cx88-dvb cards (KWorld DVB T-100 cards), and I'm getting exactly the same problem. I just upgraded to head, and the same is happening.

comment:29 Changed 13 years ago by Bradley Kite <bradley.kite@…>

Milestone: unknown0.20
Type: defectpatch

Please find ringBufferSwitchRaceConditionFix.diff attached. This should close this ticket, and also #2315, #2335, and #2340 which are dupes.

Regards -- Bradley Kite.

Changed 13 years ago by Bradley Kite <bradley.kite@…>

Patch to fix this bug.

comment:30 Changed 13 years ago by paladine@…

This patch didn't fix the issue for me. I am using "No Grabber" as I am using Sky TV connected to a PVR 150 via SVideo In with no IR Blaster. This apparantly makes MythTV automatically assume a program change 2 times an hour on the 00 and 30 during LiveTV.

This does not happen every 30 minutes, in fact I have managed to go upto 90 minutes before the freeze occurs in LiveTV, however, more often than not it happens every 30 minutes. It does continue to record the signal to file and I can watch the mpg from an external program (such as VLC) with no issue, sound is synced with the video and everything is perfect, so it is just LiveTV that is freezing.

I spent a lot of time with some people in the #mythtv-users channel yesterday (thanks to everyone who tried to figure this out) but I figured I should officially update the ticket.

This problem does not occur when I am watching a "Manual Recording", it only occurs in LiveTV.

On advice of Sphery I tried adding /bin/true and /bin/sleep 5 to the configuration but again, this made no difference. It just happened again as I was typing this message, below is the output from mythfrontend:

2006-09-16 18:30:14.908 TV: Changing from None to WatchingLiveTV
2006-09-16 18:30:15.004 Video timing method: USleep with busy wait
2006-09-16 19:00:00.851 Finished recording Unknown: channel 1000
2006-09-16 19:00:00.941 TVRec(1): Enabling Full LiveTV UI.
2006-09-16 19:00:01.120 TVRec(1): RingBufferChanged?()
2006-09-16 19:00:01.127 Finished recording Unknown: channel 1000
0: start_time: 0.036 duration: 160.740
1: start_time: 0.025 duration: 160.726
stream: start_time: 0.276 duration: 1786.124 bitrate=5149 kb/s
2006-09-16 19:00:01.208 AFD: Opened codec 0x8237680, id(MPEG2VIDEO) type(Video)
2006-09-16 19:00:01.208 AFD: Opened codec 0x8237a70, id(MP2) type(Audio)
2006-09-16 19:00:02.380 NVP: prebuffering pause
2006-09-16 19:00:04.020 NVP: Prebuffer wait timed out 10 times.
2006-09-16 19:00:05.660 NVP: Prebuffer wait timed out 10 times.
2006-09-16 19:00:07.300 NVP: Prebuffer wait timed out 10 times.
2006-09-16 19:00:08.940 NVP: Prebuffer wait timed out 10 times.
2006-09-16 19:00:10.580 NVP: Prebuffer wait timed out 10 times.
2006-09-16 19:00:12.220 NVP: Prebuffer wait timed out 10 times.
2006-09-16 19:00:13.861 NVP: Prebuffer wait timed out 10 times.
2006-09-16 19:00:15.021 TV: Attempting to change from WatchingLiveTV to None
2006-09-16 19:00:15.075 TVRec(1): Changing from WatchingLiveTV to None
2006-09-16 19:00:15.124 Finished recording Unknown: channel 1000
2006-09-16 19:00:15.233 TV: Changing from WatchingLiveTV to None
2006-09-16 19:00:15.241 DPMS Reactivated.
2006-09-16 19:00:19.037 TV: Attempting to change from None to WatchingLiveTV
2006-09-16 19:00:19.038 Using protocol version 30
2006-09-16 19:00:19.038 MainServer::HandleAnnounce? Playback
2006-09-16 19:00:19.038 adding: main as a client (events: 0)
2006-09-16 19:00:19.039 TVRec(1): Changing from None to WatchingLiveTV
2006-09-16 19:00:19.039 TVRec(1): HW Tuner: 1->1
2006-09-16 19:00:20.049 ret_pid(0) child(25653) status(0x0)
2006-09-16 19:00:21.053 ret_pid(0) child(25653) status(0x0)
2006-09-16 19:00:22.057 ret_pid(0) child(25653) status(0x0)
2006-09-16 19:00:23.061 ret_pid(0) child(25653) status(0x0)
2006-09-16 19:00:24.065 ret_pid(25653) child(25653) status(0x0)
2006-09-16 19:00:24.065 External Tuning program exited with no error
2006-09-16 19:00:25.405 DPMS Deactivated
2006-09-16 19:00:25.461 AFD: Opened codec 0x9737ba0, id(MPEG2VIDEO) type(Video)
2006-09-16 19:00:25.461 AFD: Opened codec 0x9737ef0, id(MP2) type(Audio)
2006-09-16 19:00:25.650 Opening OSS audio device '/dev/dsp'.
2006-09-16 19:00:25.656 VideoOutputXv?: XvMCTex: Init failed
2006-09-16 19:00:25.657 VideoOutputXv?: XVideo Adaptor Name: 'NV17 Video Texture'X Error: BadMatch? (invalid parameter attributes) 8

Major opcode: 140
Minor opcode: 14
Resource id: 0x19f

2006-09-16 19:00:26.010 The realtime priority setting is not enabled.
2006-09-16 19:00:26.010 TV: Changing from None to WatchingLiveTV
2006-09-16 19:00:26.114 Video timing method: USleep with busy wait

As you can seefrom the timestamp 2006-09-16 19:00:15.021, the only way to resume LiveTV is for me to exit back to the Mythfrontend Menu and then go back into LiveTV.

Please feel free to email me if you require any more information, with instructions for debugging (I haveonly been using mythtv for about 36 hours) and I will be happy to run any tests you require and send back the results.

Thanks

Paladine

comment:31 Changed 13 years ago by Bradley Kite <bradley.kite@…>

Hi there,

This patch does solve the problem for me, however I am using a DVB recorder, so it may be a seperate problem.

As part of the patch, some extra verbose messages are logged in the backend.

Would you be able to provide them please ('-v important,general,record,schedule'), as it may be to do with the way the ring-buffer is switched when using other types of recorder.

Regards -- Brad.

comment:32 Changed 13 years ago by paladine@…

I replied to your email Bradley but it doesn't seem to have made it to the ticket yet.

However, I have accidentally discovered a workaround to the problem. I paused my LiveTV earlier for a few seconds (currently on approx 5 second delay) and I have not had the prebuffer issue since. I will let you know if it returns.

Hope this helps you in your investigation.

Paladine

comment:33 Changed 13 years ago by anonymous

Milestone: 0.200.21

comment:34 Changed 13 years ago by danielk

Owner: changed from Isaac Richards to danielk
Status: reopenednew
Summary: Live TV : "Error was encountered while displaying video."Ringbuffer Race condition

comment:35 Changed 13 years ago by danielk

Type: patchdefect

The attached patch is bogus. But, it might help us diagnose the real problem..

comment:36 Changed 13 years ago by davidp@…

I have updated the patch so that it works against the current SVN. Ringbuffer now appears to switch properly in accordance with the original patch again. And the code compiles again.

comment:37 Changed 13 years ago by davidp@…

I cant figure out how to attach so here is the svn diff:

Index: libs/libmythtv/recorderbase.cpp =================================================================== --- libs/libmythtv/recorderbase.cpp (revision 12423) +++ libs/libmythtv/recorderbase.cpp (working copy) @@ -197,6 +197,9 @@

if (nextRingBuffer) {

+ + VERBOSE(VB_RECORD, LOC + "CheckForRingBufferSwitch?() - Switching Ring-Buffer"); +

FinishRecording?(); ResetForNewFile?();

Index: libs/libmythtv/tv_rec.cpp =================================================================== --- libs/libmythtv/tv_rec.cpp (revision 12423) +++ libs/libmythtv/tv_rec.cpp (working copy) @@ -135,7 +135,10 @@

tvchain tvchain(NULL), RingBuffer? info

  • ringBuffer(NULL), rbFileExt("mpg")

+ ringBuffer(NULL), rbFileExt("mpg") + ringBuffer(NULL), + ringBufferSwitchInProgress(false), + rbFilePrefix(""), rbFileExt("mpg")

{ }

@@ -1311,7 +1314,10 @@

<<"!has_rec("<<!has_rec<<") " <<"!rec_soon("<<!rec_soon<<") " <<"curRec("<<curRecording<<") "

  • <<"starttm("<<starttime.toString(Qt::ISODate)<<")");

+ <<"starttm("<<starttime.toString(Qt::ISODate)<<")"); + <<"starttm("<<starttime.toString(Qt::ISODate)<<")" + <<"now(" << now.toString(Qt::ISODate)<<")" + <<"curRecording->endts(" << curRecording->endts.toString(Qt::ISODate)<<")");

last = QDateTime::currentDateTime().addSecs(20);

} else

@@ -3084,6 +3090,7 @@

curRecording = new ProgramInfo?(*pginfo); curRecording->MarkAsInUse?(true, "recorder");

}

+ ringBufferSwitchInProgress = false;

}

QString TVRec::TuningGetChanNum?(const TuningRequest? &request,

@@ -4151,8 +4158,20 @@

bool TVRec::SwitchLiveTVRingBuffer(bool discont, bool set_rec) {

VERBOSE(VB_RECORD, LOC + "SwitchLiveTVRingBuffer(discont "

  • <<discont<<", set_rec "<<set_rec<<")");

+ <<discont<<", set_rec "<<set_rec<<")"); + <<discont<<", set_rec "<<set_rec<<") - ringBufferSwitchInProgress(" << ringBufferSwitchInProgress << ")"); + if (set_rec && ringBufferSwitchInProgress) + { + /* The ring-buffer is already being switched */ + return false; + } + else if (set_rec && !ringBufferSwitchInProgress) + { + ringBufferSwitchInProgress = true; + } + +

ProgramInfo? *pginfo = NULL; RingBuffer? *rb = NULL;

Index: libs/libmythtv/tv_rec.h =================================================================== --- libs/libmythtv/tv_rec.h (revision 12423) +++ libs/libmythtv/tv_rec.h (working copy) @@ -371,6 +371,8 @@

RingBuffer? info RingBuffer? *ringBuffer;

+ bool ringBufferSwitchInProgress; + QString rbFilePrefix;

QString rbFileExt;

public:

comment:38 Changed 13 years ago by anonymous

Funnily I have used the old patch against an earlier SVN version and it worked perfectly. It is a must have patch. Without it I get the error at the end of every show. Why hasnt this code made it into the SVN proper.

comment:39 Changed 13 years ago by danielk

Anon, This hasn't made it into SVN proper because the patch is incorrect, it doesn't fix the underlying problem and causes other problems. If someone creates a patch that converts this race condition into a deadlock and then provides a backtrace for that I can probably fix it. (I unfortunately haven't had the time to produce such a patch myself yet..)

comment:40 Changed 13 years ago by david@…

I have managed to get the backtrace, but it is not very interesting, SwitchLiveTVRingBuffer is simply executed twice from the TVRec::RunTV thread.

However, I think I've managed to find the race condition.

At the end of a program, TVRec::RunTV calls SwitchLiveTVRingBuffer with arguments discont 0, set_rec 1. discont = 0 means that recorder->CheckForRingBufferSwitch?() will not be called in SwitchLiveTVRingBuffer. TVRec::RunTV then continues and reaches the end of the loop where it sleeps for 1000ms before the TVRec::RunTV loop is executed again.

If everything goes well, TVRec::RecorderThread? should (during the time that the TVRec::RunTV thread is sleeping) call RingBufferChanged?. In the example of DVB, the call chain is as follows:

TVRec::TuningNewRecorder? -> pthread_create(&recorder_thread, NULL, TVRec::RecorderThread?, recorder); -> TVRec::RecorderThread? -> DVBRecorder::StartRecording? -> DVBRecorder::ProcessDataTS -> DVBRecorder::ProcessTSPacket -> DVBRecorder::ProcessTSPacket2 -> DTVRecorder::FindMPEG2Keyframes -> DTVRecorder::HandleKeyframe? -> RecorderBase::CheckForRingBufferSwitch? -> TVRec::RingBufferChanged?

So RingBufferChanged? will only be called while the TVRec::RunTV thread is sleeping if a keyframe is found during that period. Since RingBufferChanged? updates curRecording, TVRec::RunTV will run the same test with the same curRecording as last time the next time the loop is executed and re-run SwitchLiveTVRingBuffer if RingBufferChanged? hasn't been executed (i.e. if no keyframe was found).

I'm not sure what the best way to fix this would be....danielk?

comment:41 Changed 13 years ago by danielk

Status: newassigned

Thanks, I've been able to reproduce this here with this info.

I'm looking at how to fix this right now...

Changed 13 years ago by danielk

Attachment: 1153-v2.patch added

Possible fix for problem

comment:42 Changed 13 years ago by danielk

Type: defectpatch

comment:43 Changed 13 years ago by tino.keitel+mythtv@…

I initially reported #2335, which was marked as a duplicate of this bug. I applied the patch 1153-v2.patch and rebuilt everything, but mythfrontend still hangs sometimes when a new recording starts. I'll attach my frontend log with -v channel,record,playback,file.

Changed 13 years ago by tino.keitel+mythtv@…

Attachment: mythfrontend.out added

some succesful program changes and a failed one at the end

comment:44 in reply to:  43 Changed 13 years ago by david@…

Replying to tino.keitel+mythtv@tikei.de:

I initially reported #2335, which was marked as a duplicate of this bug. I applied the patch 1153-v2.patch and rebuilt everything, but mythfrontend still hangs sometimes when a new recording starts. I'll attach my frontend log with -v channel,record,playback,file.

Could you please attach the backend log as well?

Changed 13 years ago by tino.keitel+mythtv@…

Attachment: mythbackend.out added

backend log of some successful program changes and a failed one at the end

comment:45 Changed 13 years ago by david@…

From what I can tell from the logs, it seems to be a different issue from the one remedied by the above patches as the SwitchLiveTVRingBuffer call isn't called twice and the RingBuffer? seems to switch correctly at 08:22, but it's not being filled.

comment:46 Changed 13 years ago by danielk

Resolution: fixed
Status: assignedclosed

(In [12550]) Fixes #1153. Fixes a ringbuffer switching race condition.

comment:47 Changed 13 years ago by anonymous

Patch "1153-v2.patch" applied cleanly to release-0-20-fixes and seems to fix it in the same way. Could you please consider applying it there too? Cheers.

Note: See TracTickets for help on using tickets.