Skip to main content

RI Restart because of GStreamer issue

Please note these java.net forums are being decommissioned and use the new and improved forums at https://community.oracle.com/community/java.
12 replies [Last post]
kganga4
Offline
Joined: 2011-01-30

hi,
RI Simulator is getting restarted in middle when we execute any scenario which is triggering rate change event.This is happening only in win32 environment and may be due to GStreamer . Could you please help me on knowing the exact issue? Is this problem with GStreamer library ?
the log is
20110413 09:49:12.069 INFO RI.GStreamer- gsttrickplayfilesrc.c gst_trick_play_file_src_create:535 Attemping to execute requested time seek to 0:04:44.614000000.
20110413 09:49:12.069 INFO RI.Stack- 780930 [Thread-55] INFO player.AbstractPlayer - clock rate changed from: 0.0 to 0.0
20110413 09:49:12.069 INFO RI.GStreamer- gstmpegdecoder.c gst_mpeg_decoder_event:422 Received FLUSH_START event.
20110413 09:49:12.069 INFO RI.GStreamer- gstmpegdecoder.c gst_mpeg_decoder_event:426 Received FLUSH_STOP event.
20110413 09:49:12.069 INFO RI.GStreamer- gsttrickplayfilesrc.c gst_trick_play_file_src_create:623 Switch from 1x playback to trick-play: buffer timestamps will restart from 0:00:00.000000000.
20110413 09:49:12.069 INFO RI.Pipeline- playbackStateStarting -- state = PLAYBACK_STATE_STARTING - playback rate is 0.000000
20110413 09:49:12.084 INFO RI.GStreamer- gstmpegdecoder.c gst_mpeg_decoder_event:413 Received NEWSEGMENT event.
20110413 09:49:12.100 INFO RI.Stack.StdOut- [DCLI-CLIENT] [INFO] [PlayerUtil$ControllerListenerImpl.controllerUpdate: 254] - controllerEventorg.ocap.shared.media.LeavingLiveModeEvent[source=TSBServiceMediaHandler@7749bd77]
20110413 09:49:12.100 INFO RI.Stack.StdOut- [DCLI-CLIENT] [INFO] [PlayerUtil$ControllerListenerImpl.controllerUpdate: 254] - controllerEventjavax.media.RateChangeEvent[source=TSBServiceMediaHandler@7749bd77,rate=0.0]
20110413 09:49:12.115 INFO RI.Stack- 780967 [pool-19] INFO presentation.AbstractServicePresentation - handleSessionEventAsync - event: MEDIA_CONTENT_PRESENTING, selection: pending selection: Selection { trigger=MODE, svcDetails=org.cablelabs.impl.service.javatv.navigation.ServiceDetailsImpl@33b550c6[uniqueID=ServiceDetailsImpl442125344, locator=ocap://0x44c, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceDetailsHandleImpl@1a5a4c20[handle=1a5a4c20], sourceID=1100, programNumber=2, appID=0, longName=, deliverySystemType=CABLE, serviceInformationType=SCTE_SI, updateTime=Wed Apr 13 02:35:59 GMT-06:00 2011, caSystemIDs=[ ], isFree=true, lsData[language=]], locators=null, isDefault=true, full media access auth: true, conditional access auth: true, hashCode: 0x8a35d902}, session: TSBSession - tsw: TSWC 0xaacaa29d:[nlist 1,ru org.cablelabs.impl.service.ServiceContextResourceUsageImpl@711448011[id=11127133,prio=220,org.davic.net.tuning.NetworkInterfaceController,org.havi.ui.HVideoDevice,],tsw TSW 0x87053887:[service ServiceImpl442125344 (ocap://0x44c) ,state BUFFERING,tuner 1,tbst 467209ms,btsb TSB 0x5da3eda3[size 3900,ntsb 0x1a666a80,sysbufstart/end Wed Apr 13 02:44:13 GMT-06:00 2011/Wed Apr 13 02:48:58 GMT-06:00 2011,tbstart/end 467976ms/9223372036854ms,tswoffset 767ms,bufstopreason NOREASON ], nclients 3, TSC:[uses BUFFERING+BUFFPLAYBACK,res NI+LIVEPLAYBACK+BUFFPLAYBACK,mind 10,desd 0,maxd MAX_VAL]],constrain TSC:[uses BUFFPLAYBACK,res LIVEPLAYBACK+BUFFPLAYBACK,mind 0,desd 0,maxd MAX_VAL],1st tsb:TSB 0x5da3eda3[size 3900,ntsb 0x1a666a80,sysbufstart/end Wed Apr 13 02:44:13 GMT-06:00 2011/Wed Apr 13 02:48:58 GMT-06:00 2011,tbstart/end 467976ms/9223372036854ms,tswoffset 767ms,bufstopreason NOREASON ]], tsb:TSB 0x5da3eda3[size 3900,ntsb 0x1a666a80,sysbufstart/end Wed Apr 13 02:44:13 GMT-06:00 2011/Wed Apr 13 02:48:58 GMT-06:00 2011,tbstart/end 467976ms/9223372036854ms,tswoffset 767ms,bufstopreason NOREASON ], dfd95fdf, time: 284.61400000000003s (284614000000ns), rate: 0.0, playback: 0x1dde6498, dfd95fdf, lock=java.lang.Object@b6569d22, details(id)=ServiceDetailsImpl442125344, video=0xd7bef80, started=true, blocked=false, data1: 0, data2: 0, current state: STATE_NORMAL_CONTENT_SESSION_STARTING
20110413 09:49:12.115 INFO RI.Stack- 780971 [pool-19] INFO player.AbstractServicePlayer - notifyMediaAuthorization: NormalMediaPresentationEvent: TSBServiceMediaHandler@7749bd77
20110413 09:49:12.115 INFO RI.Stack- 780972 [pool-19] INFO presentation.AbstractServicePresentation - updateState - from: STATE_NORMAL_CONTENT_SESSION_STARTING to STATE_NORMAL_CONTENT_SESSION_STARTED
20110413 09:49:13.569 ERROR RI.GStreamer- gstdisplay.c gst_display_get_times:2832 Buffer is over 1 second early (approx. 1s) - this might cause a deadlock!!!
20110413 09:49:13.569 ERROR RI.GStreamer- gstdisplay.c gst_display_get_times:2832 Buffer is over 1 second early (approx. 1s) - this might cause a deadlock!!!
exe:9640): GStreamer-CRITICAL **: gst_caps_is_fixed: assertion `GST_IS_CAPS (caps)' failed
(ri.exe:9640): GStreamer-CRITICAL **: gst_caps_is_empty: assertion `GST_IS_CAPS (caps)' failed
(ri.exe:9640): GStreamer-CRITICAL **: gst_caps_is_any: assertion `GST_IS_CAPS (caps)' failed
(ri.exe:9640): GStreamer-CRITICAL **: gst_caps_is_empty: assertion `GST_IS_CAPS (caps)' failed
(ri.exe:9640): GStreamer-CRITICAL **: gst_caps_is_any: assertion `GST_IS_CAPS (caps)' failed
(ri.exe:9640): GStreamer-CRITICAL **: gst_caps_copy: assertion `GST_IS_CAPS (caps)' failed
Regards
Gangadharan K

Reply viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.
mkorzen
Offline
Joined: 2008-03-05

Hello -
Can you supply any more information? Is this issue specific to a particular MPEG-2 transport stream that you are using?
Also, can you run it with GDB to see if we can get a stack trace? This can be done as follows:
<code>
cd $PLATFORMROOT
./runRI.sh -gdb -capall
</code>
When the crash occurs, you should drop out to GDB. Try the following:
<code>
thread apply all bt
</code>
This should give all stack traces of all active RI threads. Please post it here...

kganga4
Offline
Joined: 2011-01-30

If we enable debuging either by enabling gstreamer log in platform.cfg or my GDB ,issue is not reproducing .It is not specific to particular MPEG. Is there any other way to get debug logs ?

mkorzen
Offline
Joined: 2008-03-05

It sounds like the issue might be timing-sensitive.
Do you have access to a Linux distribution to see if you can reproduce it there?
As an alternative, can you send a full log file that shows the crash. To capture absolutely everything, use the "-capall" option and send "ri-iter-0.log" file instead of "RILog.txt"

kganga4
Offline
Joined: 2011-01-30

Now I can able to reproduce the issue by enabling gdb logs. This issue is reproducable only in win32 platform
Please find the attached RI Console log along with gdb trace at the end.
Could you please help us on this ?

kganga4
Offline
Joined: 2011-01-30

Could you please help us on this ?

raja2526
Offline
Joined: 2011-05-17

Hi Korzen,

Any updates on this?

mkorzen
Offline
Joined: 2008-03-05

After looking at the attached log files, it looks like you are encountering a known issue that we had been tracking internally since July 27, 2010. Our main problem is the ability to reproduce it consistenly and reliably - and that is the main reason why it had been open for almost 1 year now.

In summary - the issue is specific to Win32 and occurs in dual tuner set-up with timeshift bufferring enabled. When the live tuner's TSB is paused, the crash occurs after 5 or more minutes of remaining in the paused state. Unfortunately, the GDB stack traces that we have (which are identical to your ri_console_log.txt) do not contain enough information to pinpoint the potential source of the problem. Unless the memory corruption that occurs is triggered by non-GStreamer (i.e. RI) code, we suspect a bug in the GStreamer implementation.

When happens is that suddently one of the GST elements' pad structure becomes corrupted (either via memory overwrite or reference miscounting) and as soon as that occurs, whichever thread attempts access to any of the data structures of the pad results in a segfault/crash.

We are actively looking to resolve this problem, so ANY indication of how you are able to consistently reproduce this issue would be very helpful. Specifically, can you describe how/when this problem occurs:

- is it specific to an MPEG stream that you are using?

- is it specific to a PC hardware configuration?

- is it specific to a Windows installation?

Please supply as many details as you think might be helpful...

raja2526
Offline
Joined: 2011-05-17

Hi Korzen,

Is there any IT raised for this issue? Is there any other information required from my side? please let me know.

Thanks & Regards,

Raj

mkorzen
Offline
Joined: 2008-03-05

Hi Raj -

Feel free to raise IT issue for this. We have been tracking this issue internally for over a year but so far have not had any success in resolving it. Any scenario that will make this issue reproducible in a consistent manner would greatly help us in getting a closure on this.

Best -

Marcin

raja2526
Offline
Joined: 2011-05-17

Thanks Marcin,

Raised an IT557.

raja2526
Offline
Joined: 2011-05-17

Hi Korzen,

I have not observed this in linux platform. I don't think any hardware configuration OR the MPEG stream is causing the RI to reboot issue. I tried the trickplay operations on different MPEG streams and found no issues. Regarding the configuration of the system the test cases were ran on HP 8000 Elite CMT PCs on Windows XP Pro service pack 3. Here by I am attaching a png file for your reference

mkorzen
Offline
Joined: 2008-03-05

Sorry, we have had a few glitches in the past few months with the async forum notifications.

I will take a look at the attached log file.