Skip to main content

System time gets updated while recording

Please note these java.net forums are being decommissioned and use the new and improved forums at https://community.oracle.com/community/java.
6 replies [Last post]
BigiCP
Offline
Joined: 2011-03-28

In Continuous Integration server(where its checks out the RI code, builds it and runs the application) I am running an application in which initially it does an SD recording with start time as current time + 10 sec and duration as 6 minutes. The recording is going to PEDING_NO_CONFLICT_STATE and at the start time of the recording the start spec is getting expired. It schedules Stop spec also. Tuning is success but takes some time. So the recording goes to IN_PROGRESS_INCOMPLETE_STATE. After sometime Stop spec is getting expired and the recording duration comes as 259sec (4.3 minutes) instead of 360sec(6 minutes). So recording moves to IN_COMPLETE_STATE (with reason INSUFFICIENT_RESOURCES). Around 1.5 minutes of data is missing.
After analyzing the logs, I could see that lot of timer tasks are getting expired together along with stop spec. There is a chance to expire all the timer tasks together if timer thread was blocked. But in this case timer thread was not blocked. Here it seems like system time is changed and hence stop timer is getting expired, before actually doing recording for 6 minutes.
I started a dedicated thread in the class TimerMgrJava2.java for printing the system time in every 5 seconds (using System.currentTimeMillis()). It shows that the system time is getting changed.
My query is: Is there any chance of system time getting updated? Or is it any timer related problem which is leading to this issue?
Note: This issue is observed only with continuous integration server. I am not able to reproduce this issue in my local machine.

Reply viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.
cpratt
Offline
Joined: 2008-12-18

I'm having a bit of difficulty getting my head around the question. Could you perhaps rephrase the question?

Are you wondering if the stop time of the recording should be adjusted if the recording starts late?
If an application specifies a RecordingRequest to start at time x and run for y seconds, it expects the recording to stop at time x+y regardless of whether it starts late, gets interrupted, etc.
e.g. If I request a recording to start at 9:00 for 60 minutes, it's expected to end at 10:00 regardless of conditions. If it starts 1.5 minutes late, recording 1.5 minutes longer isn't going to make up for the lost content.
Is it possible that the native conversion start is blocking for a long period? Tuning won't block the timer thread (resource reservation and tuning are done async). But if the tuner is already tuned to the Service, conversion initiation will be done on the timer thread.
Generally blocking the timer thread is something that you want to avoid. So I'd like to understand what the issue is to see if there's a solution that doesn't involve blocking the timer.

BigiCP
Offline
Joined: 2011-03-28

Hi,
The problem is related to stop timer expiration. i.e, Stop timer is getting expired before actually doing the entire recording. The recording is started properly at correct time(Please ignore the tuning issue I mentioned in the original query). But I am not getting the entire recording(6 minutes of recording). I am getting only 4.3 minutes of recording.
Thanks,
Bigi.

cpratt
Offline
Joined: 2008-12-18

Just to make sure I understand - is it:
(a) You're scheduling the RecordingRequest at 12:00 pm for 6 minutes, the recording is being stopped by the RI at 12:04:20 pm?
(b) It's recording until 12:06pm but RecordedService.getRecordedDuration() is returning 4.3 minutes (258000ms)?
(c) You play back the RecordedService on the RI/simulator (not using HDHomeRun) and it only plays for 4.3 minutes.
(c) None of the above.
Let me try to provide another follow-up and avoid another reply round-trip:
If (a) or (b), please open a bug at java.net/jira/secure/CreateIssue.jspa and provide a log if you can. We have many tests that would fail if this were happening regularly. We would want to find out why it's failing in your case.
If (c), this is a known issue with the looping of files. A bit of content is lost each time the file is looped. So your recording may playback 15% shorter than the recording duration. (Doesn't happen if you use an HDHomeRun since the content isn't looped in that case).

BigiCP
Offline
Joined: 2011-03-28

Hi All,
Could someone please clarify the above query?
Thanks,
Bigi.

howardteece
Offline
Joined: 2010-06-17

Perhaps we need to look at how mpeos_timeGetMillis() is implemented in Windows.
The link: http://msdn.microsoft.com/en-us/library/ms644904(v=vs.85).aspx suggests that the Performance Counter could prove troublesome. Would it be possible to use GetTickCount() or GetTickCount64() to get the system clock?

vishaln
Offline
Joined: 2011-01-27

I tried 2 things.
1) The current implementation avoids the call to GetSystemTimeAsFileTime() everytime mpeos_timeGetMillis() is invoked. There is a dependency on QueryPerformanceFrequency and QueryPerformanceCounter to calculate the milliseconds since the last request. Scope for error is evident since QueryPerformanceCounter is not reliable. Looks like the current code is expecting the deviation by coding the following.
if (millisSinceSynch && (*pMpeTimeMillis > millisSinceEpoch)) millisSinceEpoch = *pMpeTimeMillis; //Went back in time, don't allow time reversal.
I removed usage of QueryPerformanceCounter and used GetSystemTimeAsFileTime() method every time a request is made.
This fixed the issues but I am really not sure whether this causes any regression.
2) Instead of QueryPerformanceCounter, I used GetTickCount() method. Howard Teece has also suggested the same.
Even this has worked well.
-----------------------
Verification Method used:
1) Initiated a timer for 10 minutes. Before the changes, the difference between System.currentTimeMillis() after timerWentOff and scheduling was varying. Sometimes 678, 752 and so on...After the changes, it is fired exactly 600 seconds!
2) Recording scheduled immediately after RI is up was going to Incomplete state consistently because startSpec was expiring at the wrong time. After the changes, it is expiring properly and the recording is going to completed state consistently.
-------------------------
Please provide suggestions/opinions on these fixes.