Skip to main content

TSB Convert stop is not really stopping the TSB conversion some times

Please note these java.net forums are being decommissioned and use the new and improved forums at https://community.oracle.com/community/java.
3 replies [Last post]
krushna
Offline
Joined: 2010-09-21

Hi,

when we stop the Recording, there is a call to stop the Time shift converiosn which is in progress.(RecordingImpl.stopTimeShiftConversion) which inturn call the native method nStopTimeShiftConversion.

Which inturn calls the method "mpeos_dvrTsbConvertStop" which will call the tsb.tsb_convert_stop().

tsb_convert_stop() is placing the Action command "TSB_ACTION_CONVERT_STOP" in the queue g_async_queue_push () .

But the action is not processed, as a result the TSB conversion still in progress, which leads to unable to delete the files. why the action is not processed some times from the queue. Please see the attached logs.

in the logs i have my customized logs in tsb_convert_stop() method ensures that the command is placesd in the queue.

If you see the file attachment i have logs for successful conversion stop and failure conversion stop.

/************************ LOGS only for failure case*************************************/

20110720 18:27:38.090 DEBUG RI.Stack- 1326703 [pool-30] DEBUG recording.RecordingImpl - RI 0x1925eab8: IStateStarted: handleBufferingStateChanged
20110720 18:27:38.090 DEBUG RI.Stack- 1326703 [pool-30] DEBUG recording.RecordingImpl - isEnabled(): Access to the MSV has been denied...appId: 11127133
20110720 18:27:38.090 DEBUG RI.Stack- 1326703 [pool-30] DEBUG recording.RecordingImpl - RI 0x1925eab8: IStateStarted: calling native stop
20110720 18:27:38.090 DEBUG RI.Stack- 1326703 [pool-30] DEBUG recording.RecordingImpl - RI 0x1925eab8: Remove table change listeners for: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es IN_PROGRESS_INSUFFICIENT_SPACE_STATE,is RecordingImpl.IStateStarted,pri 2,seg 1:[start 2011/07/20 06:57:23-0600,nname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE,tad TimeTable 0x40a87e1d:[TimeAssociatedDetailsInfo@0x4aefccd3:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d0,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e0, streamtype AUDIO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d1,estype 0x81}]}],ttc TimeTable 0x88705f49:[empty]]]]:ocap://0x45a
20110720 18:27:38.090 INFO RI.Stack- 1326703 [pool-30] INFO recording.RecordingImpl - RI 0x1925eab8: stopTimeShiftConversion: Calling nStopTimeShiftConversion(handle 0x1d883338, immediateStop false)
20110720 18:27:38.090 DEBUG RI.Stack- <<DVR>> mpeos_dvrTsbConvertStop - TSB = 1D883338
20110720 18:27:38.090 DEBUG RI.Stack- <<DVR>> mpeos_dvrTsbConvertStop - krushnar-dvr = 1D883338
20110720 18:27:38.090 INFO RI.Pipeline.TSB- <<DVR>> tsb_convert_stop - krushnar-tsb_convert_stop = 1D86C978
20110720 18:27:38.090 INFO RI.Pipeline.TSB- <<DVR>> tsb_convert_stop - krushnar-tsb_convert_stop-tsb not null = 1D86C978
20110720 18:27:38.090 INFO RI.Pipeline.TSB- <<DVR>> tsb_convert_stop - krushnar-tsb_convert_stop-tsb after gettsbEntry = 005002C0
20110720 18:27:38.090 INFO RI.Pipeline.TSB- <<DVR>> tsb_convert_stop - krushnar-tsb_convert_stop-tsb-pTsbItem is not null = 005002C0
20110720 18:27:38.105 INFO RI.Pipeline.TSB- <<DVR>> tsb_convert_stop - krushnar-tsb_convert_stop-tsb-inside mutex-lock = 005002C0
20110720 18:27:38.105 INFO RI.Pipeline.TSB- <<DVR>> tsb_convert_stop - krushnar-tsb_convert_stop-tsb-pipeLine is not null = 005002C0
20110720 18:27:38.105 INFO RI.Pipeline.TSB- <<DVR>> tsb_convert_stop - krushnar-tsb_convert_stop-tsb-converiosn_in_progress = 005002C0
20110720 18:27:38.105 INFO RI.Pipeline.TSB- <<DVR>> tsb_convert_stop - krushnar-tsb_convert_stop-tsb-insidecommand = 005002C0
20110720 18:27:38.105 INFO RI.Pipeline.TSB- <<DVR>> tsb_convert_stop - krushnar-tsb_convert_stop-tsb-end = 00000000
20110720 18:27:38.137 INFO RI.Pipeline.TSB- tsbStateStarted -- Waiting for TSB to start operation
20110720 18:27:38.105 INFO RI.Stack- 1326718 [pool-30] INFO recording.RecordingRetentionManager - Removing in progress recording RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es IN_PROGRESS_INSUFFICIENT_SPACE_STATE,is RecordingImpl.IStateStarted,pri 2,seg 1:[start 2011/07/20 06:57:23-0600,nname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE,tad TimeTable 0x40a87e1d:[TimeAssociatedDetailsInfo@0x4aefccd3:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d0,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e0, streamtype AUDIO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d1,estype 0x81}]}],ttc TimeTable 0x88705f49:[empty]]]]
20110720 18:27:38.230 DEBUG RI.Stack- Java_org_cablelabs_impl_storage_MediaStorageVolumeImpl_JNI:nGetFreeSpace
20110720 18:27:38.230 DEBUG RI.Stack- <<DVR>> mpeos_dvrMediaVolumeGetInfo Volume = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV (1DECE0D0)
20110720 18:27:38.246 DEBUG RI.Stack- <<DVR>> mpeos_dvrMediaVolumeGetInfo MPE_DVR_MEDIA_VOL_FREE_SPACE = 991351520, reservedSize = 1000000000, usedSize = 8648480, device freeMediaSize = -8673487873571728239
20110720 18:27:38.246 DEBUG RI.Stack- <<DVR>> Java_org_cablelabs_impl_storage_MediaStorageVolumeImpl_nGetFreeSpace returned storage space = 991351520 bytes
20110720 18:27:38.246 DEBUG RI.Stack- 1326859 [pool-30] DEBUG recording.RecordingRetentionManager - Sufficient space available. Not purging
20110720 18:27:38.246 DEBUG RI.Stack- 1326859 [pool-30] DEBUG recording.RecordingResourceManager - resolveConflictsForRecordingRemoval: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es IN_PROGRESS_INSUFFICIENT_SPACE_STATE,is RecordingImpl.IStateStarted,pri 2,seg 1:[start 2011/07/20 06:57:23-0600,nname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE,tad TimeTable 0x40a87e1d:[TimeAssociatedDetailsInfo@0x4aefccd3:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d0,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e0, streamtype AUDIO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d1,estype 0x81}]}],ttc TimeTable 0x88705f49:[empty]]]]
20110720 18:27:38.246 DEBUG RI.Stack- 1326859 [pool-30] DEBUG recording.RecordingResourceManager - attemptToReserveRecordingsDuring: << start 1311166643660, dur 2700000>>: Overlapping P_W_C entries
20110720 18:27:38.246 DEBUG RI.Stack- 1326859 [pool-30] DEBUG recording.RecordingResourceManager - OrderedRecordingSet 0x5d79ae6d has 0 recordings:

20110720 18:27:38.246 DEBUG RI.Stack- 1326859 [pool-30] DEBUG recording.RecordingResourceManager - attemptToReserveRecordingsInOrderWithRCH: Attempting to reserve 0 recordings on 2 tuners
20110720 18:27:38.246 INFO RI.Stack- 1326859 [pool-30] INFO recording.RecordingImpl - RI 0x1925eab8: setFailedExceptionReason: setting reason to INSUFFICIENT_RESOURCES (4)
20110720 18:27:38.246 DEBUG RI.Stack- 1326859 [pool-30] DEBUG recording.RecordingImpl - RI 0x1925eab8: setStateAndNotify - oldState: IN_PROGRESS_INSUFFICIENT_SPACE_STATE New State: IN_PROGRESS_WITH_ERROR_STATE
20110720 18:27:38.246 DEBUG RI.Stack- 1326859 [pool-30] DEBUG recording.RecordingImpl - RI 0x1925eab8: saveRecordingInfo: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es IN_PROGRESS_WITH_ERROR_STATE,is RecordingImpl.IStateStarted,pri 2,seg 1:[start 2011/07/20 06:57:23-0600,nname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE,tad TimeTable 0x40a87e1d:[TimeAssociatedDetailsInfo@0x4aefccd3:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d0,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e0, streamtype AUDIO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d1,estype 0x81}]}],ttc TimeTable 0x88705f49:[empty]]]]
20110720 18:27:38.262 DEBUG RI.Stack- 1326875 [pool-30] DEBUG db.SerializationMgr - updateRecord: ffffffff RecordingInfo2 0x80:[reqtype 2,loc {ocap://0x45a},snum 114,sdesc null,start 1311166643660,dur 2700000,dtime 0,drsn 2,fexp 4,mtime 0,rsrcePrior 0,nsegs 1,segs recordedSegmentList[0]=RecordedSegmentInfo@0x4b8de8b3 :{rname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE,svcname [Lorg.ocap.net.OcapLocator;@22bbf7dd,stime 1311166643660,mtime 0,detailsTT TimeTable 0x40a87e1d:[TimeAssociatedDetailsInfo@0x4aefccd3:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d0,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e0, streamtype AUDIO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d1,estype 0x81}]}],copyprotect false,TimeTable 0x88705f49:[empty]}, ,RecordingInfoNode:[uid 0x80,appId 11127133,state 15,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@142d9919,org 'null',expr Tue Sep 27 17:37:23 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:38.277 DEBUG RI.Stack- 1326890 [pool-30] DEBUG persistent.PersistentDataSerializer - savePriv: RecordingInfo2 0x80:[reqtype 2,loc {ocap://0x45a},snum 114,sdesc null,start 1311166643660,dur 2700000,dtime 0,drsn 2,fexp 4,mtime 0,rsrcePrior 0,nsegs 1,segs recordedSegmentList[0]=RecordedSegmentInfo@0x4b8de8b3 :{rname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE,svcname [Lorg.ocap.net.OcapLocator;@22bbf7dd,stime 1311166643660,mtime 0,detailsTT TimeTable 0x40a87e1d:[TimeAssociatedDetailsInfo@0x4aefccd3:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d0,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e0, streamtype AUDIO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d1,estype 0x81}]}],copyprotect false,TimeTable 0x88705f49:[empty]}, ,RecordingInfoNode:[uid 0x80,appId 11127133,state 15,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@142d9919,org 'null',expr Tue Sep 27 17:37:23 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:38.293 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error opening file. File not found
20110720 18:27:38.355 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error. File not found
20110720 18:27:38.449 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error opening file. File not found
20110720 18:27:38.449 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error. File not found
20110720 18:27:38.480 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80') error. Unknown Error
20110720 18:27:38.480 DEBUG RI.Stack- FAT32FileRename('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1'->'/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80')
20110720 18:27:38.512 DEBUG RI.Stack- 1327125 [pool-30] DEBUG persistent.PersistentDataSerializer - savePriv: saved to /syscwd/persistent/dvr/recdbser/80
20110720 18:27:38.512 DEBUG RI.Stack- 1327125 [pool-30] DEBUG manager.PropertiesManager - getInstancesByPrecedence for: OCAP.serializationMgrDelegate: [org.cablelabs.impl.manager.recording.db.HNSerializationMgrDelegate]
20110720 18:27:38.512 DEBUG RI.Stack- 1327125 [pool-30] DEBUG srs.RecordingContentItemLocal - updateMetadata()
20110720 18:27:38.512 DEBUG RI.Stack- 1327125 [pool-30] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x45a, null
20110720 18:27:38.512 DEBUG RI.Stack- 1327125 [pool-30] DEBUG service.SIRequestElement - @2f497ff8 SIRequestElement ctor...
20110720 18:27:38.512 DEBUG RI.Stack- 1327125 [pool-30] DEBUG service.SIRequestElement - @2f497ff8 Creating SIRequestServices...
20110720 18:27:38.512 DEBUG RI.Stack- 1327125 [pool-30] DEBUG service.SIRequestImpl - @a7708b09SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:38.512 DEBUG RI.Stack- 1327125 [pool-10] DEBUG service.SIRequestElement - @2f497ff8 Attempting delivery
20110720 18:27:38.512 DEBUG RI.Stack- 1327125 [pool-10] DEBUG service.SIRequestServices - @a7708b09 Attempting delivery
20110720 18:27:38.512 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:38.512 INFO RI.Stack- 1327125 [pool-10] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:38.512 DEBUG RI.Stack- 1327125 [pool-30] DEBUG recording.RecordingImpl - RI 0x1925eab8: specServiceNumber: 114, specSourceID():0x45a, sdi.getServiceNumber(): 114, sdi.getSourceID():0x45a
20110720 18:27:38.512 DEBUG RI.Stack- 1327125 [pool-30] DEBUG recording.RecordingImpl - RI 0x1925eab8: Matched specServiceNumber and sourceId...
20110720 18:27:38.512 INFO RI.Stack- 1327125 [pool-30] INFO recording.RecordingImpl - RI 0x1925eab8: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@9855dfcd[uniqueID=ServiceImpl414145360, locator=ocap://0x45a, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5b50[handle=18af5b50], name=DS 14, serviceType=UNKNOWN, serviceNumber=114, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:38.527 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetNumberOfServiceDetailsForServiceHandle()...returned 0
20110720 18:27:38.527 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetServiceDetailsForServiceHandle()...returned 0
20110720 18:27:38.527 DEBUG RI.Stack- 1327140 [pool-30] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveNetworks() called with org.cablelabs.impl.service.javatv.transport.TransportImpl@1ac3bc94[uniqueID=TransportImpl4096, deliverySystemType=CABLE, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$TransportHandleImpl@1000[handle=1000], transportID=1]
20110720 18:27:38.527 DEBUG RI.Stack- 1327140 [pool-30] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestNetworks@c74b1422
20110720 18:27:38.543 DEBUG RI.Stack- 1327156 [pool-20] DEBUG service.SIRequestNetworks - @c74b1422 Attempting delivery
20110720 18:27:38.543 DEBUG RI.Stack- 1327156 [pool-30] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveTransportStream() called with ocap://0x45a
20110720 18:27:38.543 DEBUG RI.Stack- 1327156 [pool-30] DEBUG service.SIRequestImpl - @7d16cf19SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:38.543 DEBUG RI.Stack- 1327156 [pool-30] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestTransportStream@7d16cf19[transportID=1, frequency=ffffffff, sourceID=45a, serviceName=null]
20110720 18:27:38.543 DEBUG RI.Stack- 1327156 [pool-22] DEBUG service.SIRequestTransportStream - @7d16cf19 Attempting delivery
20110720 18:27:38.543 DEBUG RI.Stack- 1327156 [pool-30] DEBUG srs.RecordingContentItemLocal - updateMetadata(): scheduledChannelID@Type/scheduledChannelID: SI/1,1357,1114
20110720 18:27:38.543 DEBUG RI.Stack- 1327156 [pool-30] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:38.543 DEBUG RI.Stack- 1327156 [pool-30] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:38.543 DEBUG RI.Stack- 1327156 [pool-30] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:38.543 DEBUG RI.Stack- 1327156 [pool-30] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:38.543 DEBUG RI.Stack- 1327156 [pool-30] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:38.543 DEBUG RI.Stack- 1327156 [pool-30] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:38.559 DEBUG RI.Stack- 1327171 [pool-30] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:38.559 DEBUG RI.Stack- 1327171 [pool-30] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:38.559 DEBUG RI.Stack- 1327171 [pool-30] DEBUG recording.SegmentedRecordedServiceImpl - SegmentedRecordedServiceImpl::getRecordingStartTime - returning first segment start time: 1311166643660
20110720 18:27:38.559 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE
20110720 18:27:38.559 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE, datafile = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA_DATA/4E26D0BE_18BE
20110720 18:27:38.574 DEBUG RI.Stack- 1327187 [pool-30] DEBUG mpe.HNAPIImpl - getRecordingContentItemLocalSize(recordingName=I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE)
20110720 18:27:38.574 INFO RI.Stack- mpeos_hnGetRecordingContentItemLocalSize() - called
20110720 18:27:38.574 INFO RI.Stack- hnServer_getRecordingContentItemLocalSize() -- asking for file size of content I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE
20110720 18:27:38.574 INFO RI.Stack- <<HN>> convertRecordingNameToPlatform - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE
20110720 18:27:38.574 INFO RI.Stack- <<HN>> convertRecordingNameToPlatform - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE, path = d:/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA, platformRecName = 4E26D0BE_18BE
20110720 18:27:38.574 INFO RI.Stack- hnServer_getRecordingContentItemLocalSize() -- asking for size of file, name 4E26D0BE_18BE, filepath d:/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA
20110720 18:27:38.574 INFO RI.Pipeline.HN- pipeline_hn_server_get_recording_file_size -- file path: d:/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA, name: 4E26D0BE_18BE
20110720 18:27:38.574 DEBUG RI.Stack- 1327187 [pool-30] DEBUG srs.RecordingContentItemLocal - getRecordingSizeStr - retrieved recording seg 0, size: 0
20110720 18:27:38.574 INFO RI.Stack- 1327187 [pool-30] INFO srs.RecordingContentItemLocal - getRecordingSizeStr - total size: 0
20110720 18:27:38.590 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE
20110720 18:27:38.590 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE, datafile = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA_DATA/4E26D0BE_18BE
20110720 18:27:38.590 DEBUG RI.Stack- <<DVR>> mpeos_dvrRecordingGet (I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE) MPE_DVR_RECORDING_LENGTH = 0
20110720 18:27:38.590 INFO RI.Stack- 1327203 [pool-30] INFO srs.RecordingContentItemLocal - getRecordingDurationStr - total duration: 0
20110720 18:27:38.590 DEBUG RI.Stack- 1327203 [pool-30] DEBUG srs.RecordingContentItemLocal - updateMetadata(): updating state: 15
20110720 18:27:38.605 INFO RI.Stack- 1327203 [pool-30] INFO recording.NavigationManager - NavigationManager: updateRecording from state = 5 to new state 15 for RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es IN_PROGRESS_WITH_ERROR_STATE,is RecordingImpl.IStateStarted,pri 2,seg 1:[start 2011/07/20 06:57:23-0600,nname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE,tad TimeTable 0x40a87e1d:[TimeAssociatedDetailsInfo@0x4aefccd3:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d0,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e0, streamtype AUDIO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d1,estype 0x81}]}],ttc TimeTable 0x88705f49:[empty]]]]
20110720 18:27:38.605 INFO RI.Stack- 1327218 [pool-30] INFO recording.RecordingImpl - RI 0x1925eab8: IStateSuspendedBufferingDisabled: constructing...
20110720 18:27:38.605 DEBUG RI.Stack- JNI(TSB): nTSBGetStartTime(tsb 495465272)20110720 18:27:38.605 DEBUG RI.Stack- JNI(TSB): nTSBGetStartTime(tsb 495465272)20110720 18:27:38.621 DEBUG RI.Stack- 1327234 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateForRemovedUses: Removing use(s) BUFFERING for client TSWC 0x5d91d582:[nlist 1,ru org.cablelabs.impl.ocap.dvr.RecordingResourceUsageImpl@-1921251610[id=11127133,prio=220,org.davic.net.tuning.NetworkInterfaceController,],tsw TSW 0x312d9cce:[service ServiceImpl414145360 (ocap://0x45a) ,state BUFFERING,tuner 2,tbst 1195125ms,btsb TSB 0xf131ee64[size 3900,ntsb 0x1d883338,sysbufstart/end Wed Jul 20 06:57:34 GMT-06:00 2011/Wed Jul 20 06:57:38 GMT-06:00 2011,tbstart/end 1205734ms/9223372036854ms,tswoffset 10609ms,bufstopreason NOREASON], nclients 1, TSC:[uses NI+BUFFERING+RECORDING,res BUFFERING+RECORDING,mind 0,desd 0,maxd MAX_VAL]],constrain TSC:[uses NI+RECORDING,res BUFFERING+RECORDING,mind 0,desd 0,maxd MAX_VAL],1st tsb:TSB 0xf131ee64[size 3900,ntsb 0x1d883338,sysbufstart/end Wed Jul 20 06:57:34 GMT-06:00 2011/Wed Jul 20 06:57:38 GMT-06:00 2011,tbstart/end 1205734ms/9223372036854ms,tswoffset 10609ms,bufstopreason NOREASON]]
20110720 18:27:38.777 DEBUG RI.Stack- 1327390 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateForRemovedUses: current state is BUFFERING, and no buffering uses remaining.
20110720 18:27:38.777 DEBUG RI.Stack- 1327390 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateForRemovedUses: No buffering uses remaining.
20110720 18:27:38.809 DEBUG RI.Stack- 1327421 [pool-30] DEBUG timer.TimerMgrJava2 - scheduleTimerSpec: org.cablelabs.impl.manager.timer.TimerMgrJava2$TVTimerImpl$1@541108e3, spec: TVTS 0x328fc603: [time=1311166663910, absolute=true, repeat=false, regular=true, listener=org.cablelabs.impl.manager.timeshift.TimeShiftWindow$ExpirationTrigger], time: 1311166663910
20110720 18:27:38.809 DEBUG RI.Stack- 1327421 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: scheduleTimerSpec spec: TVTS 0x328fc603: [time=1311166663910, absolute=true, repeat=false, regular=true, listener=org.cablelabs.impl.manager.timeshift.TimeShiftWindow$ExpirationTrigger]
20110720 18:27:38.809 DEBUG RI.Stack- 1327421 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: startTimer: death timer scheduled
20110720 18:27:38.809 DEBUG RI.Stack- 1327421 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateNIResourceUsages: Current NI resource usages: [org.cablelabs.impl.ocap.dvr.RecordingResourceUsageImpl@-1921251610[id=11127133,prio=220,org.davic.net.tuning.NetworkInterfaceController,]]
20110720 18:27:38.809 DEBUG RI.Stack- JNI(TSB): nTSBGetStartTime(tsb 495465272)20110720 18:27:38.809 DEBUG RI.Stack- JNI(TSB): nTSBGetStartTime(tsb 495465272)20110720 18:27:38.809 DEBUG RI.Stack- 1327421 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateForRemovedUses: Removing use(s) RECORDING for client TSWC 0x5d91d582:[nlist 1,ru org.cablelabs.impl.ocap.dvr.RecordingResourceUsageImpl@-1921251610[id=11127133,prio=220,org.davic.net.tuning.NetworkInterfaceController,],tsw TSW 0x312d9cce:[service ServiceImpl414145360 (ocap://0x45a) ,state BUFFERING,tuner 2,tbst 1195125ms,btsb TSB 0xf131ee64[size 3900,ntsb 0x1d883338,sysbufstart/end Wed Jul 20 06:57:34 GMT-06:00 2011/Wed Jul 20 06:57:38 GMT-06:00 2011,tbstart/end 1205734ms/9223372036854ms,tswoffset 10609ms,bufstopreason NOREASON], nclients 1, TSC:[uses NI+RECORDING,res BUFFERING+RECORDING,mind 0,desd 0,maxd MAX_VAL]],constrain TSC:[uses NI,res BUFFERING+RECORDING,mind 0,desd 0,maxd MAX_VAL],1st tsb:TSB 0xf131ee64[size 3900,ntsb 0x1d883338,sysbufstart/end Wed Jul 20 06:57:34 GMT-06:00 2011/Wed Jul 20 06:57:38 GMT-06:00 2011,tbstart/end 1205734ms/9223372036854ms,tswoffset 10609ms,bufstopreason NOREASON]]
20110720 18:27:38.824 DEBUG RI.Stack- 1327437 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateForRemovedUses: current state is BUFFERING, and no buffering uses remaining.
20110720 18:27:38.840 DEBUG RI.Stack- 1327453 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: descheduleTimer spec: TVTS 0x328fc603: [time=1311166663910, absolute=true, repeat=false, regular=true, listener=org.cablelabs.impl.manager.timeshift.TimeShiftWindow$ExpirationTrigger]
20110720 18:27:38.840 DEBUG RI.Stack- 1327453 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: stopTimer: death timer cancelled
20110720 18:27:38.840 DEBUG RI.Stack- 1327453 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateForRemovedUses: No buffering uses remaining.
20110720 18:27:38.840 DEBUG RI.Stack- 1327453 [pool-30] DEBUG timer.TimerMgrJava2 - scheduleTimerSpec: org.cablelabs.impl.manager.timer.TimerMgrJava2$TVTimerImpl$1@56423ee1, spec: TVTS 0xb5eaf3a: [time=1311166663940, absolute=true, repeat=false, regular=true, listener=org.cablelabs.impl.manager.timeshift.TimeShiftWindow$ExpirationTrigger], time: 1311166663940
20110720 18:27:38.840 DEBUG RI.Stack- 1327453 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: scheduleTimerSpec spec: TVTS 0xb5eaf3a: [time=1311166663940, absolute=true, repeat=false, regular=true, listener=org.cablelabs.impl.manager.timeshift.TimeShiftWindow$ExpirationTrigger]
20110720 18:27:38.840 DEBUG RI.Stack- 1327453 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: startTimer: death timer scheduled
20110720 18:27:38.840 DEBUG RI.Stack- 1327453 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateForRemovedUses: No TSB uses remaining.
20110720 18:27:38.840 DEBUG RI.Stack- 1327453 [pool-30] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateNIResourceUsages: Current NI resource usages: [org.cablelabs.impl.ocap.dvr.RecordingResourceUsageImpl@-1921251610[id=11127133,prio=220,org.davic.net.tuning.NetworkInterfaceController,]]
20110720 18:27:38.840 INFO RI.Stack- 1327453 [pool-30] INFO recording.RecordingImpl - RI 0x1925eab8: IState: setting state to RecordingImpl.IStateSuspendedBufferingDisabled
20110720 18:27:38.840 INFO RI.Stack- 1327453 [pool-30] INFO recording.RecordingImpl - RI 0x1925eab8: setFailedExceptionReason: setting reason to RESOURCES_REMOVED (6)
20110720 18:27:38.840 DEBUG RI.Stack- 1327453 [pool-30] DEBUG recording.RecordingImpl - Terminating ongoing presentations for Recording:RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es IN_PROGRESS_WITH_ERROR_STATE,is RecordingImpl.IStateSuspendedBufferingDisabled,pri 2,seg 1:[start 2011/07/20 06:57:23-0600,nname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE,tad TimeTable 0x40a87e1d:[TimeAssociatedDetailsInfo@0x4aefccd3:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d0,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e0, streamtype AUDIO, name , lang , servinft SCTE_SI, locator ocap://0x45a.+0x7d1,estype 0x81}]}],ttc TimeTable 0x88705f49:[empty]]]]
20110720 18:27:38.855 DEBUG RI.Stack- 1327468 [pool-30] DEBUG recording.RecordingImpl - RI 0x1925eab8: terminateOngoingPresentations - none found!
20110720 18:27:38.855 INFO RI.Stack- 1327468 [ED-Normal] INFO recording.RecordingImpl - RI 0x7c25a1dd: IState: ignoring handleNativeTerminationNotification(4099)
20110720 18:27:38.855 INFO RI.Stack.StdOut- [DCLI-CLIENT] [INFO] [VerifyResourcesRemovedSequenceDcli.performResourcesRemovedState: 100] - RecordingFailedException received as RESOURCES_REMOVED
20110720 18:27:38.855 INFO RI.Stack- 1327468 [Thread-47] INFO recording.RecordingImpl - RI 0x7c25a1dd: Recording delete() Enter
20110720 18:27:38.855 DEBUG RI.Stack- 1327468 [Thread-47] DEBUG recording.Scheduler - Scheduler:descheduleRecording
20110720 18:27:38.855 DEBUG RI.Stack- 1327468 [Thread-47] DEBUG recording.Scheduler - StopSpec deschedule called, retSpec: TVTS 0x7a774eaf: [time=1311166818910, absolute=true, repeat=false, regular=true, listener=org.cablelabs.impl.manager.recording.Scheduler]
20110720 18:27:38.855 INFO RI.Stack- 1327468 [Thread-47] INFO recording.RecordingImpl - RI 0x7c25a1dd: IStateSuspended: handleStop - Stop called
20110720 18:27:38.855 DEBUG RI.Stack- 1327468 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: IStateEnded: constructing......
20110720 18:27:38.855 DEBUG RI.Stack- 1327468 [Thread-47] DEBUG storage.StorageManagerImpl - Removeing Storage Manager Listener
20110720 18:27:38.855 DEBUG RI.Stack- 1327468 [Thread-47] DEBUG storage.StorageManagerImpl - Removed Storage Manager Listener Successfully
20110720 18:27:38.855 DEBUG RI.Stack- 1327468 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: IStateEnded: processInterruptionState Enter...
20110720 18:27:38.855 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:38.855 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029, datafile = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA_DATA/4E26D0B1_0029
20110720 18:27:38.980 DEBUG RI.Stack- <<DVR>> mpeos_dvrRecordingGet (I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029) MPE_DVR_RECORDING_LENGTH = 16
20110720 18:27:38.980 DEBUG RI.Stack- 1327593 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: getRecordingDuration::nativeRecordingName: I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029 duration: 16
20110720 18:27:38.980 INFO RI.Stack- 1327593 [Thread-47] INFO recording.RecordingImpl - RI 0x7c25a1dd: IStateEnded: processInterruption - actual duration of this recording: 16000
20110720 18:27:38.980 DEBUG RI.Stack- 1327593 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: IStateEnded: Incomplete recording - due to user stop=
20110720 18:27:38.980 DEBUG RI.Stack- 1327593 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: processInterruption - native recording found: RecordingImpl.IStateEnded -- transitioning to INCOMPLETE_STATE
20110720 18:27:38.980 DEBUG RI.Stack- 1327593 [Thread-47] DEBUG recording.RecordingManagerImpl - removeDisableBufferingListener: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@8c7507c, RI 0x7c25a1dd:[id 127,app 11127133,loc ocap://0x44c,start 2011/07/20 06:57:19-0600,dur 180s,es IN_PROGRESS_WITH_ERROR_STATE,is RecordingImpl.IStateSuspendedBufferingDisabled,pri 2,seg 1:[start 2011/07/20 06:57:20-0600,nname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029,tad TimeTable 0xd6b5808b:[TimeAssociatedDetailsInfo@0xca0a4553:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x44c.+0xbb8,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e1, streamtype AUDIO, name , lang eng, servinft SCTE_SI, locator ocap://0x44c.+0xbb9,estype 0x81}, RecordedServiceComponentInfo 0x0:{pid 0x2e2, streamtype AUDIO, name , lang spa, servinft SCTE_SI, locator ocap://0x44c.+0xbba,estype 0x81}]}],ttc TimeTable 0x84d78c9:[empty]]]]
20110720 18:27:38.980 DEBUG RI.Stack- 1327593 [Thread-47] DEBUG recording.RecordingManagerImpl - removeDisableRecordingListener: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@8c7507c, RI 0x7c25a1dd:[id 127,app 11127133,loc ocap://0x44c,start 2011/07/20 06:57:19-0600,dur 180s,es IN_PROGRESS_WITH_ERROR_STATE,is RecordingImpl.IStateSuspendedBufferingDisabled,pri 2,seg 1:[start 2011/07/20 06:57:20-0600,nname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029,tad TimeTable 0xd6b5808b:[TimeAssociatedDetailsInfo@0xca0a4553:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x44c.+0xbb8,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e1, streamtype AUDIO, name , lang eng, servinft SCTE_SI, locator ocap://0x44c.+0xbb9,estype 0x81}, RecordedServiceComponentInfo 0x0:{pid 0x2e2, streamtype AUDIO, name , lang spa, servinft SCTE_SI, locator ocap://0x44c.+0xbba,estype 0x81}]}],ttc TimeTable 0x84d78c9:[empty]]]]
20110720 18:27:39.012 INFO RI.Stack- 1327609 [Thread-47] INFO recording.RecordingImpl - RI 0x7c25a1dd: releaseTSWClient Called
20110720 18:27:39.012 DEBUG RI.Stack- 1327625 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: Calling TimeshiftClient.release()
20110720 18:27:39.012 DEBUG RI.Stack- JNI(TSB): nTSBGetStartTime(tsb 495471088)20110720 18:27:39.012 DEBUG RI.Stack- JNI(TSB): nTSBGetStartTime(tsb 495471088)20110720 18:27:39.012 DEBUG RI.Stack- 1327625 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x5e66c3a1: updateForRemovedUses: Removing use(s) NI for client TSWC 0xdeb58a01:[nlist 1,ru org.cablelabs.impl.ocap.dvr.RecordingResourceUsageImpl@1217648675[id=11127133,prio=220,org.davic.net.tuning.NetworkInterfaceController,],tsw TSW 0x5e66c3a1:[service ServiceImpl414144600 (ocap://0x44c) ,state BUFFERING,tuner 1,tbst 1191390ms,btsb TSB 0xb7296722[size 3900,ntsb 0x1d8849f0,sysbufstart/end Wed Jul 20 06:57:21 GMT-06:00 2011/Wed Jul 20 06:57:39 GMT-06:00 2011,tbstart/end 1192859ms/9223372036854ms,tswoffset 1469ms,bufstopreason NOREASON], nclients 1, TSC:[uses NI,res BUFFERING+RECORDING,mind 0,desd 0,maxd MAX_VAL]],constrain TSC:[uses NO USES,res NO USES,mind 0,desd 0,maxd MAX_VAL],1st tsb:TSB 0xb7296722[size 3900,ntsb 0x1d8849f0,sysbufstart/end Wed Jul 20 06:57:21 GMT-06:00 2011/Wed Jul 20 06:57:39 GMT-06:00 2011,tbstart/end 1192859ms/9223372036854ms,tswoffset 1469ms,bufstopreason NOREASON]]
20110720 18:27:39.012 DEBUG RI.Stack- 1327625 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x5e66c3a1: updateForRemovedUses: current state is BUFFERING, and no buffering uses remaining.
20110720 18:27:39.012 DEBUG RI.Stack- 1327625 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x5e66c3a1: descheduleTimer spec: TVTS 0xeecf01df: [time=1311166663140, absolute=true, repeat=false, regular=true, listener=org.cablelabs.impl.manager.timeshift.TimeShiftWindow$ExpirationTrigger]
20110720 18:27:39.012 DEBUG RI.Stack- 1327625 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x5e66c3a1: stopTimer: death timer cancelled
20110720 18:27:39.012 DEBUG RI.Stack- 1327625 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x5e66c3a1: updateForRemovedUses: No buffering uses remaining.
20110720 18:27:39.012 DEBUG RI.Stack- 1327625 [Thread-47] DEBUG timer.TimerMgrJava2 - scheduleTimerSpec: org.cablelabs.impl.manager.timer.TimerMgrJava2$TVTimerImpl$1@8911b73e, spec: TVTS 0x622e4a53: [time=1311166664110, absolute=true, repeat=false, regular=true, listener=org.cablelabs.impl.manager.timeshift.TimeShiftWindow$ExpirationTrigger], time: 1311166664110
20110720 18:27:39.012 DEBUG RI.Stack- 1327625 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x5e66c3a1: scheduleTimerSpec spec: TVTS 0x622e4a53: [time=1311166664110, absolute=true, repeat=false, regular=true, listener=org.cablelabs.impl.manager.timeshift.TimeShiftWindow$ExpirationTrigger]
20110720 18:27:39.012 DEBUG RI.Stack- 1327625 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x5e66c3a1: startTimer: death timer scheduled
20110720 18:27:39.012 DEBUG RI.Stack- 1327625 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x5e66c3a1: updateForRemovedUses: current state is BUFFERING/NOREASON and no tuner uses remaining.
20110720 18:27:39.027 DEBUG RI.Stack- 1327640 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x5e66c3a1: updateForRemovedUses: No TSB uses remaining.
20110720 18:27:39.027 DEBUG RI.Stack- 1327640 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x5e66c3a1: updateNIResourceUsages: Current NI resource usages: [org.cablelabs.impl.ocap.dvr.RecordingResourceUsageImpl@1217648675[id=11127133,prio=220,org.davic.net.tuning.NetworkInterfaceController,]]
20110720 18:27:39.027 DEBUG RI.Stack- 1327640 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x5e66c3a1: updateNIResourceUsages: Removing ResourceUsage org.cablelabs.impl.ocap.dvr.RecordingResourceUsageImpl@1217648675[id=11127133,prio=220,org.davic.net.tuning.NetworkInterfaceController,] from nic reservation
20110720 18:27:39.043 DEBUG RI.Stack- JNI(TSB): nTSBGetStartTime(tsb 495471088)20110720 18:27:39.043 INFO RI.Stack- 1327656 [Thread-47] INFO timeshift.TimeShiftWindow - TSW 0x5e66c3a1: removeClient: Removing client: TSWC 0xdeb58a01:[nlist 1,ru org.cablelabs.impl.ocap.dvr.RecordingResourceUsageImpl@1217648675[id=11127133,prio=220,org.davic.net.tuning.NetworkInterfaceController,],tsw TSW 0x5e66c3a1:[service ServiceImpl414144600 (ocap://0x44c) ,state BUFFERING,tuner 1,tbst 1191390ms,btsb TSB 0xb7296722[size 3900,ntsb 0x1d8849f0,sysbufstart/end Wed Jul 20 06:57:21 GMT-06:00 2011/Wed Jul 20 06:57:39 GMT-06:00 2011,tbstart/end 1192859ms/9223372036854ms,tswoffset 1469ms,bufstopreason NOREASON], nclients 0, TSC:[uses NO USES,res NO USES,mind 0,desd 0,maxd MAX_VAL]],constrain TSC:[uses NO USES,res NO USES,mind 0,desd 0,maxd MAX_VAL],1st tsb: none]
20110720 18:27:39.043 DEBUG RI.Stack- 1327656 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x5e66c3a1: removeClient: Prior constraints: TSC:[uses NO USES,res NO USES,mind 0,desd 0,maxd MAX_VAL]
20110720 18:27:39.043 DEBUG RI.Stack- 1327656 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x5e66c3a1: removeClient: New constraints: TSC:[uses NO USES,res NO USES,mind 0,desd 0,maxd MAX_VAL]
20110720 18:27:39.043 INFO RI.Stack- 1327656 [Thread-47] INFO timeshift.TimeShiftWindow - TSW 0x5e66c3a1: removeClient: Last client removed
20110720 18:27:39.043 INFO RI.Stack- 1327656 [Thread-47] INFO recording.RecordingImpl - RI 0x7c25a1dd: cleanupTimeTableCollection
20110720 18:27:39.043 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:39.043 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029, datafile = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA_DATA/4E26D0B1_0029
20110720 18:27:39.043 DEBUG RI.Stack- <<DVR>> mpeos_dvrRecordingGet (I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029) MPE_DVR_RECORDING_LENGTH = 16
20110720 18:27:39.043 DEBUG RI.Stack- 1327656 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: setStateAndNotify - oldState: IN_PROGRESS_WITH_ERROR_STATE New State: INCOMPLETE_STATE
20110720 18:27:39.043 DEBUG RI.Stack- 1327656 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: saveRecordingInfo: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@8c7507c, RI 0x7c25a1dd:[id 127,app 11127133,loc ocap://0x44c,start 2011/07/20 06:57:19-0600,dur 180s,es INCOMPLETE_STATE,is RecordingImpl.IStateSuspendedBufferingDisabled,pri 2,seg 1:[start 2011/07/20 06:57:20-0600,nname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029,tad TimeTable 0xd6b5808b:[TimeAssociatedDetailsInfo@0xca0a4553:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x44c.+0xbb8,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e1, streamtype AUDIO, name , lang eng, servinft SCTE_SI, locator ocap://0x44c.+0xbb9,estype 0x81}, RecordedServiceComponentInfo 0x0:{pid 0x2e2, streamtype AUDIO, name , lang spa, servinft SCTE_SI, locator ocap://0x44c.+0xbba,estype 0x81}]}],ttc TimeTable 0x84d78c9:[empty]]]]
20110720 18:27:39.074 DEBUG RI.Stack- 1327687 [Thread-47] DEBUG db.SerializationMgr - updateRecord: ffffffff RecordingInfo2 0x7f:[reqtype 2,loc {ocap://0x44c},snum 100,sdesc null,start 1311166639910,dur 180000,dtime 0,drsn 2,fexp 6,mtime 0,rsrcePrior 0,nsegs 1,segs recordedSegmentList[0]=RecordedSegmentInfo@0xe02a5318 :{rname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029,svcname [Lorg.ocap.net.OcapLocator;@a9e06d56,stime 1311166640544,mtime 0,detailsTT TimeTable 0xd6b5808b:[TimeAssociatedDetailsInfo@0xca0a4553:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x44c.+0xbb8,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e1, streamtype AUDIO, name , lang eng, servinft SCTE_SI, locator ocap://0x44c.+0xbb9,estype 0x81}, RecordedServiceComponentInfo 0x0:{pid 0x2e2, streamtype AUDIO, name , lang spa, servinft SCTE_SI, locator ocap://0x44c.+0xbba,estype 0x81}]}],copyprotect false,TimeTable 0x84d78c9:[empty]}, ,RecordingInfoNode:[uid 0x7f,appId 11127133,state 6,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@dd7539d0,org 'null',expr Tue Sep 27 17:37:19 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:39.074 DEBUG RI.Stack- 1327687 [Thread-47] DEBUG persistent.PersistentDataSerializer - savePriv: RecordingInfo2 0x7f:[reqtype 2,loc {ocap://0x44c},snum 100,sdesc null,start 1311166639910,dur 180000,dtime 0,drsn 2,fexp 6,mtime 0,rsrcePrior 0,nsegs 1,segs recordedSegmentList[0]=RecordedSegmentInfo@0xe02a5318 :{rname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029,svcname [Lorg.ocap.net.OcapLocator;@a9e06d56,stime 1311166640544,mtime 0,detailsTT TimeTable 0xd6b5808b:[TimeAssociatedDetailsInfo@0xca0a4553:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x44c.+0xbb8,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e1, streamtype AUDIO, name , lang eng, servinft SCTE_SI, locator ocap://0x44c.+0xbb9,estype 0x81}, RecordedServiceComponentInfo 0x0:{pid 0x2e2, streamtype AUDIO, name , lang spa, servinft SCTE_SI, locator ocap://0x44c.+0xbba,estype 0x81}]}],copyprotect false,TimeTable 0x84d78c9:[empty]}, ,RecordingInfoNode:[uid 0x7f,appId 11127133,state 6,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@dd7539d0,org 'null',expr Tue Sep 27 17:37:19 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:39.105 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error opening file. File not found
20110720 18:27:39.105 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error. File not found
20110720 18:27:39.105 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error opening file. File not found
20110720 18:27:39.105 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error. File not found
20110720 18:27:39.262 INFO RI.Pipeline.TSB- tsbStateStarted -- Waiting for TSB to start operation
20110720 18:27:39.277 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f') error. Unknown Error
20110720 18:27:39.277 DEBUG RI.Stack- FAT32FileRename('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1'->'/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f')
20110720 18:27:39.309 DEBUG RI.Stack- 1327921 [Thread-47] DEBUG persistent.PersistentDataSerializer - savePriv: saved to /syscwd/persistent/dvr/recdbser/7f
20110720 18:27:39.309 DEBUG RI.Stack- 1327921 [Thread-47] DEBUG manager.PropertiesManager - getInstancesByPrecedence for: OCAP.serializationMgrDelegate: [org.cablelabs.impl.manager.recording.db.HNSerializationMgrDelegate]
20110720 18:27:39.309 DEBUG RI.Stack- 1327921 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata()
20110720 18:27:39.309 DEBUG RI.Stack- 1327921 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x44c, null
20110720 18:27:39.309 DEBUG RI.Stack- 1327921 [Thread-47] DEBUG service.SIRequestElement - @eb78253c SIRequestElement ctor...
20110720 18:27:39.309 DEBUG RI.Stack- 1327921 [Thread-47] DEBUG service.SIRequestElement - @eb78253c Creating SIRequestServices...
20110720 18:27:39.309 DEBUG RI.Stack- 1327921 [Thread-47] DEBUG service.SIRequestImpl - @5d4a5abSIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:39.309 DEBUG RI.Stack- 1327921 [pool-7] DEBUG service.SIRequestElement - @eb78253c Attempting delivery
20110720 18:27:39.309 DEBUG RI.Stack- 1327921 [pool-7] DEBUG service.SIRequestServices - @5d4a5ab Attempting delivery
20110720 18:27:39.309 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:39.309 INFO RI.Stack- 1327921 [pool-7] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:39.340 DEBUG RI.Stack- 1327953 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: specServiceNumber: 100, specSourceID():0x44c, sdi.getServiceNumber(): 100, sdi.getSourceID():0x44c
20110720 18:27:39.340 DEBUG RI.Stack- 1327953 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: Matched specServiceNumber and sourceId...
20110720 18:27:39.340 INFO RI.Stack- 1327953 [Thread-47] INFO recording.RecordingImpl - RI 0x7c25a1dd: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@31bf6e64[uniqueID=ServiceImpl414144600, locator=ocap://0x44c, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5858[handle=18af5858], name=HDNET, serviceType=UNKNOWN, serviceNumber=100, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:39.340 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetNumberOfServiceDetailsForServiceHandle()...returned 0
20110720 18:27:39.340 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetServiceDetailsForServiceHandle()...returned 0
20110720 18:27:39.340 DEBUG RI.Stack- 1327953 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveNetworks() called with org.cablelabs.impl.service.javatv.transport.TransportImpl@1ac3bc94[uniqueID=TransportImpl4096, deliverySystemType=CABLE, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$TransportHandleImpl@1000[handle=1000], transportID=1]
20110720 18:27:39.340 DEBUG RI.Stack- 1327953 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestNetworks@75323090
20110720 18:27:39.340 DEBUG RI.Stack- 1327953 [pool-1] DEBUG service.SIRequestNetworks - @75323090 Attempting delivery
20110720 18:27:39.340 DEBUG RI.Stack- 1327953 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveTransportStream() called with ocap://0x44c
20110720 18:27:39.340 DEBUG RI.Stack- 1327953 [Thread-47] DEBUG service.SIRequestImpl - @17124e73SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:39.340 DEBUG RI.Stack- 1327953 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestTransportStream@17124e73[transportID=1, frequency=ffffffff, sourceID=44c, serviceName=null]
20110720 18:27:39.355 DEBUG RI.Stack- 1327968 [pool-3] DEBUG service.SIRequestTransportStream - @17124e73 Attempting delivery
20110720 18:27:39.433 DEBUG RI.Stack- 1328046 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata(): scheduledChannelID@Type/scheduledChannelID: SI/1,1357,1100
20110720 18:27:39.433 DEBUG RI.Stack- 1328046 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:39.433 DEBUG RI.Stack- 1328046 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:39.433 DEBUG RI.Stack- 1328046 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:39.433 DEBUG RI.Stack- 1328046 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:39.433 DEBUG RI.Stack- 1328046 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:39.433 DEBUG RI.Stack- 1328046 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:39.433 DEBUG RI.Stack- 1328046 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:39.433 DEBUG RI.Stack- 1328046 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:39.433 DEBUG RI.Stack- 1328046 [Thread-47] DEBUG recording.SegmentedRecordedServiceImpl - SegmentedRecordedServiceImpl::getRecordingStartTime - returning first segment start time: 1311166640544
20110720 18:27:39.433 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:39.433 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029, datafile = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA_DATA/4E26D0B1_0029
20110720 18:27:39.449 DEBUG RI.Stack- 1328062 [Thread-47] DEBUG mpe.HNAPIImpl - getRecordingContentItemLocalSize(recordingName=I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029)
20110720 18:27:39.449 INFO RI.Stack- mpeos_hnGetRecordingContentItemLocalSize() - called
20110720 18:27:39.449 INFO RI.Stack- hnServer_getRecordingContentItemLocalSize() -- asking for file size of content I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:39.449 INFO RI.Stack- <<HN>> convertRecordingNameToPlatform - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:39.449 INFO RI.Stack- <<HN>> convertRecordingNameToPlatform - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029, path = d:/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA, platformRecName = 4E26D0B1_0029
20110720 18:27:39.465 INFO RI.Stack- hnServer_getRecordingContentItemLocalSize() -- asking for size of file, name 4E26D0B1_0029, filepath d:/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA
20110720 18:27:39.465 INFO RI.Pipeline.HN- pipeline_hn_server_get_recording_file_size -- file path: d:/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA, name: 4E26D0B1_0029
20110720 18:27:39.496 DEBUG RI.Stack- 1328109 [Thread-47] DEBUG srs.RecordingContentItemLocal - getRecordingSizeStr - retrieved recording seg 0, size: 8636720
20110720 18:27:39.496 INFO RI.Stack- 1328109 [Thread-47] INFO srs.RecordingContentItemLocal - getRecordingSizeStr - total size: 8636720
20110720 18:27:39.496 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:39.496 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029, datafile = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA_DATA/4E26D0B1_0029
20110720 18:27:39.512 DEBUG RI.Stack- <<DVR>> mpeos_dvrRecordingGet (I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029) MPE_DVR_RECORDING_LENGTH = 16
20110720 18:27:39.512 INFO RI.Stack- 1328125 [Thread-47] INFO srs.RecordingContentItemLocal - getRecordingDurationStr - total duration: 16000
20110720 18:27:39.512 DEBUG RI.Stack- 1328125 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata(): updating state: 6
20110720 18:27:39.512 INFO RI.Stack- 1328125 [Thread-47] INFO recording.NavigationManager - NavigationManager: updateRecording from state = 15 to new state 6 for RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@8c7507c, RI 0x7c25a1dd:[id 127,app 11127133,loc ocap://0x44c,start 2011/07/20 06:57:19-0600,dur 180s,es INCOMPLETE_STATE,is RecordingImpl.IStateSuspendedBufferingDisabled,pri 2,seg 1:[start 2011/07/20 06:57:20-0600,nname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029,tad TimeTable 0xd6b5808b:[TimeAssociatedDetailsInfo@0xca0a4553:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x44c.+0xbb8,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e1, streamtype AUDIO, name , lang eng, servinft SCTE_SI, locator ocap://0x44c.+0xbb9,estype 0x81}, RecordedServiceComponentInfo 0x0:{pid 0x2e2, streamtype AUDIO, name , lang spa, servinft SCTE_SI, locator ocap://0x44c.+0xbba,estype 0x81}]}],ttc TimeTable 0x84d78c9:[empty]]]]
20110720 18:27:39.512 INFO RI.Stack- 1328125 [Thread-47] INFO recording.RecordingImpl - RI 0x7c25a1dd: IState: setting state to RecordingImpl.IStateEnded
20110720 18:27:39.512 INFO RI.Stack- 1328125 [Thread-47] INFO recording.RecordingImpl - RI 0x7c25a1dd: setFailedExceptionReason: setting reason to USER_STOP (9)
20110720 18:27:39.527 DEBUG RI.Stack- 1328125 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: saveRecordingInfo: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@8c7507c, RI 0x7c25a1dd:[id 127,app 11127133,loc ocap://0x44c,start 2011/07/20 06:57:19-0600,dur 180s,es INCOMPLETE_STATE,is RecordingImpl.IStateEnded,pri 2,seg 1:[start 2011/07/20 06:57:20-0600,nname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029,tad TimeTable 0xd6b5808b:[TimeAssociatedDetailsInfo@0xca0a4553:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x44c.+0xbb8,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e1, streamtype AUDIO, name , lang eng, servinft SCTE_SI, locator ocap://0x44c.+0xbb9,estype 0x81}, RecordedServiceComponentInfo 0x0:{pid 0x2e2, streamtype AUDIO, name , lang spa, servinft SCTE_SI, locator ocap://0x44c.+0xbba,estype 0x81}]}],ttc TimeTable 0x84d78c9:[empty]]]]
20110720 18:27:39.527 DEBUG RI.Stack- 1328140 [Thread-47] DEBUG db.SerializationMgr - updateRecord: 8000 RecordingInfo2 0x7f:[reqtype 2,loc {ocap://0x44c},snum 100,sdesc null,start 1311166639910,dur 180000,dtime 0,drsn 2,fexp 9,mtime 0,rsrcePrior 0,nsegs 1,segs recordedSegmentList[0]=RecordedSegmentInfo@0xe02a5318 :{rname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029,svcname [Lorg.ocap.net.OcapLocator;@a9e06d56,stime 1311166640544,mtime 0,detailsTT TimeTable 0xd6b5808b:[TimeAssociatedDetailsInfo@0xca0a4553:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x44c.+0xbb8,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e1, streamtype AUDIO, name , lang eng, servinft SCTE_SI, locator ocap://0x44c.+0xbb9,estype 0x81}, RecordedServiceComponentInfo 0x0:{pid 0x2e2, streamtype AUDIO, name , lang spa, servinft SCTE_SI, locator ocap://0x44c.+0xbba,estype 0x81}]}],copyprotect false,TimeTable 0x84d78c9:[empty]}, ,RecordingInfoNode:[uid 0x7f,appId 11127133,state 6,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@dd7539d0,org 'null',expr Tue Sep 27 17:37:19 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:39.527 DEBUG RI.Stack- 1328140 [Thread-47] DEBUG persistent.PersistentDataSerializer - savePriv: RecordingInfo2 0x7f:[reqtype 2,loc {ocap://0x44c},snum 100,sdesc null,start 1311166639910,dur 180000,dtime 0,drsn 2,fexp 9,mtime 0,rsrcePrior 0,nsegs 1,segs recordedSegmentList[0]=RecordedSegmentInfo@0xe02a5318 :{rname I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029,svcname [Lorg.ocap.net.OcapLocator;@a9e06d56,stime 1311166640544,mtime 0,detailsTT TimeTable 0xd6b5808b:[TimeAssociatedDetailsInfo@0xca0a4553:{pcr 481, components [RecordedServiceComponentInfo 0x0:{pid 0x1e1, streamtype VIDEO, name , lang , servinft SCTE_SI, locator ocap://0x44c.+0xbb8,estype 0x2}, RecordedServiceComponentInfo 0x0:{pid 0x2e1, streamtype AUDIO, name , lang eng, servinft SCTE_SI, locator ocap://0x44c.+0xbb9,estype 0x81}, RecordedServiceComponentInfo 0x0:{pid 0x2e2, streamtype AUDIO, name , lang spa, servinft SCTE_SI, locator ocap://0x44c.+0xbba,estype 0x81}]}],copyprotect false,TimeTable 0x84d78c9:[empty]}, ,RecordingInfoNode:[uid 0x7f,appId 11127133,state 6,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@dd7539d0,org 'null',expr Tue Sep 27 17:37:19 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:39.543 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error opening file. File not found
20110720 18:27:39.543 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error. File not found
20110720 18:27:39.543 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error opening file. File not found
20110720 18:27:39.543 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error. File not found
20110720 18:27:39.558 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f') error. Unknown Error
20110720 18:27:39.574 DEBUG RI.Stack- FAT32FileRename('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1'->'/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f')
20110720 18:27:39.574 DEBUG RI.Stack- 1328187 [Thread-47] DEBUG persistent.PersistentDataSerializer - savePriv: saved to /syscwd/persistent/dvr/recdbser/7f
20110720 18:27:39.574 DEBUG RI.Stack- 1328187 [Thread-47] DEBUG manager.PropertiesManager - getInstancesByPrecedence for: OCAP.serializationMgrDelegate: [org.cablelabs.impl.manager.recording.db.HNSerializationMgrDelegate]
20110720 18:27:39.574 DEBUG RI.Stack- 1328187 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata()
20110720 18:27:39.574 DEBUG RI.Stack- 1328187 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x44c, null
20110720 18:27:39.574 DEBUG RI.Stack- 1328187 [Thread-47] DEBUG service.SIRequestElement - @606fc1b7 SIRequestElement ctor...
20110720 18:27:39.574 DEBUG RI.Stack- 1328187 [Thread-47] DEBUG service.SIRequestElement - @606fc1b7 Creating SIRequestServices...
20110720 18:27:39.574 DEBUG RI.Stack- 1328187 [Thread-47] DEBUG service.SIRequestImpl - @716ffa9SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:39.574 DEBUG RI.Stack- 1328187 [pool-12] DEBUG service.SIRequestElement - @606fc1b7 Attempting delivery
20110720 18:27:39.574 DEBUG RI.Stack- 1328187 [pool-15] DEBUG service.SIRequestServices - @716ffa9 Attempting delivery
20110720 18:27:39.574 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:39.574 INFO RI.Stack- 1328187 [pool-15] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:39.574 DEBUG RI.Stack- 1328187 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: specServiceNumber: 100, specSourceID():0x44c, sdi.getServiceNumber(): 100, sdi.getSourceID():0x44c
20110720 18:27:39.590 DEBUG RI.Stack- 1328203 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: Matched specServiceNumber and sourceId...
20110720 18:27:39.590 INFO RI.Stack- 1328203 [Thread-47] INFO recording.RecordingImpl - RI 0x7c25a1dd: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@31bf6e64[uniqueID=ServiceImpl414144600, locator=ocap://0x44c, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5858[handle=18af5858], name=HDNET, serviceType=UNKNOWN, serviceNumber=100, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:39.590 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetNumberOfServiceDetailsForServiceHandle()...returned 0
20110720 18:27:39.590 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetServiceDetailsForServiceHandle()...returned 0
20110720 18:27:39.590 DEBUG RI.Stack- 1328203 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveNetworks() called with org.cablelabs.impl.service.javatv.transport.TransportImpl@1ac3bc94[uniqueID=TransportImpl4096, deliverySystemType=CABLE, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$TransportHandleImpl@1000[handle=1000], transportID=1]
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestNetworks@64fd4481
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [pool-10] DEBUG service.SIRequestNetworks - @64fd4481 Attempting delivery
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveTransportStream() called with ocap://0x44c
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [Thread-47] DEBUG service.SIRequestImpl - @ce9c99aaSIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestTransportStream@ce9c99aa[transportID=1, frequency=ffffffff, sourceID=44c, serviceName=null]
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [pool-6] DEBUG service.SIRequestTransportStream - @ce9c99aa Attempting delivery
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata(): scheduledChannelID@Type/scheduledChannelID: SI/1,1357,1100
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:39.605 DEBUG RI.Stack- 1328218 [Thread-47] DEBUG recording.SegmentedRecordedServiceImpl - SegmentedRecordedServiceImpl::getRecordingStartTime - returning first segment start time: 1311166640544
20110720 18:27:39.605 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:39.605 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029, datafile = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA_DATA/4E26D0B1_0029
20110720 18:27:39.637 DEBUG RI.Stack- 1328250 [Thread-47] DEBUG mpe.HNAPIImpl - getRecordingContentItemLocalSize(recordingName=I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029)
20110720 18:27:39.637 INFO RI.Stack- mpeos_hnGetRecordingContentItemLocalSize() - called
20110720 18:27:39.637 INFO RI.Stack- hnServer_getRecordingContentItemLocalSize() -- asking for file size of content I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:39.637 INFO RI.Stack- <<HN>> convertRecordingNameToPlatform - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:39.637 INFO RI.Stack- <<HN>> convertRecordingNameToPlatform - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029, path = d:/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA, platformRecName = 4E26D0B1_0029
20110720 18:27:39.637 INFO RI.Stack- hnServer_getRecordingContentItemLocalSize() -- asking for size of file, name 4E26D0B1_0029, filepath d:/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA
20110720 18:27:39.637 INFO RI.Pipeline.HN- pipeline_hn_server_get_recording_file_size -- file path: d:/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA, name: 4E26D0B1_0029
20110720 18:27:39.699 DEBUG RI.Stack- 1328312 [Thread-47] DEBUG srs.RecordingContentItemLocal - getRecordingSizeStr - retrieved recording seg 0, size: 8636720
20110720 18:27:39.699 INFO RI.Stack- 1328312 [Thread-47] INFO srs.RecordingContentItemLocal - getRecordingSizeStr - total size: 8636720
20110720 18:27:39.699 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:39.699 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029, datafile = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA_DATA/4E26D0B1_0029
20110720 18:27:39.699 DEBUG RI.Stack- <<DVR>> mpeos_dvrRecordingGet (I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029) MPE_DVR_RECORDING_LENGTH = 16
20110720 18:27:39.699 INFO RI.Stack- 1328312 [Thread-47] INFO srs.RecordingContentItemLocal - getRecordingDurationStr - total duration: 16000
20110720 18:27:39.699 DEBUG RI.Stack- 1328312 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata(): updating state: 6
20110720 18:27:39.699 INFO RI.Stack- 1328312 [Thread-47] INFO recording.RecordingImpl - RI 0x7c25a1dd: Deleting native recording:I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:39.699 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:39.699 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029, datafile = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA_DATA/4E26D0B1_0029
20110720 18:27:39.699 DEBUG RI.Stack- <<DVR>> mpeos_dvrRecordingDelete - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:39.730 DEBUG RI.Stack- Removing directory - /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA/4E26D0B1_0029
20110720 18:27:39.730 DEBUG RI.Stack- <<DVR>> findVolumeByRecordingName - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0B1_0029
20110720 18:27:39.730 DEBUG RI.Stack- <<STORAGE>> mpeos_storageGetDeviceCount - count = 3
20110720 18:27:39.730 DEBUG RI.Stack- <<STORAGE>> mpeos_storageGetDeviceList - Device Name = Internal One
20110720 18:27:39.730 DEBUG RI.Stack- <<STORAGE>> mpeos_storageGetDeviceList - Device Name = Internal Two
20110720 18:27:39.730 DEBUG RI.Stack- <<STORAGE>> mpeos_storageGetDeviceList - Device Name = Detachable One
20110720 18:27:39.730 DEBUG RI.Stack- <<DVR>> findVolumeByRecordingName - found volume (1DECE0D0)
20110720 18:27:39.730 DEBUG RI.Stack- <<DVR>> mpeos_dvrRecordingDelete - Volume (/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV) now has 0 bytes used
20110720 18:27:39.746 DEBUG RI.Stack- Java_org_cablelabs_impl_storage_MediaStorageVolumeImpl_JNI:nGetFreeSpace
20110720 18:27:39.746 DEBUG RI.Stack- <<DVR>> mpeos_dvrMediaVolumeGetInfo Volume = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV (1DECE0D0)
20110720 18:27:39.746 DEBUG RI.Stack- <<DVR>> mpeos_dvrMediaVolumeGetInfo MPE_DVR_MEDIA_VOL_FREE_SPACE = 1000000000, reservedSize = 1000000000, usedSize = 0, device freeMediaSize = -8673487873571728239
20110720 18:27:39.746 DEBUG RI.Stack- <<DVR>> Java_org_cablelabs_impl_storage_MediaStorageVolumeImpl_nGetFreeSpace returned storage space = 1000000000 bytes
20110720 18:27:39.746 DEBUG RI.Stack- 1328359 [Thread-47] DEBUG recording.RecordingRetentionManager - Sufficient space available. Not purging
20110720 18:27:39.746 DEBUG RI.Stack- 1328359 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: saveRecordingInfo: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@8c7507c, RI 0x7c25a1dd:[id 127,app 11127133,loc ocap://0x44c,start 2011/07/20 06:57:19-0600,dur 180s,es INCOMPLETE_STATE,is RecordingImpl.IStateEnded,pri 2,no segments]]
20110720 18:27:39.762 DEBUG RI.Stack- 1328375 [Thread-47] DEBUG db.SerializationMgr - updateRecord: 2000 RecordingInfo2 0x7f:[reqtype 2,loc {ocap://0x44c},snum 100,sdesc null,start 1311166639910,dur 180000,dtime 1311166659848,drsn 2,fexp 9,mtime 0,rsrcePrior 0,nsegs 0,segs no segments,RecordingInfoNode:[uid 0x7f,appId 11127133,state 6,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@dd7539d0,org 'null',expr Tue Sep 27 17:37:19 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:39.871 DEBUG RI.Stack- 1328484 [Thread-47] DEBUG persistent.PersistentDataSerializer - savePriv: RecordingInfo2 0x7f:[reqtype 2,loc {ocap://0x44c},snum 100,sdesc null,start 1311166639910,dur 180000,dtime 1311166659848,drsn 2,fexp 9,mtime 0,rsrcePrior 0,nsegs 0,segs no segments,RecordingInfoNode:[uid 0x7f,appId 11127133,state 6,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@dd7539d0,org 'null',expr Tue Sep 27 17:37:19 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:39.965 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error opening file. File not found
20110720 18:27:39.965 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error. File not found
20110720 18:27:39.965 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error opening file. File not found
20110720 18:27:39.965 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error. File not found
20110720 18:27:39.996 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f') error. Unknown Error
20110720 18:27:39.996 DEBUG RI.Stack- FAT32FileRename('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1'->'/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f')
20110720 18:27:39.996 DEBUG RI.Stack- 1328609 [Thread-47] DEBUG persistent.PersistentDataSerializer - savePriv: saved to /syscwd/persistent/dvr/recdbser/7f
20110720 18:27:39.996 DEBUG RI.Stack- 1328609 [Thread-47] DEBUG manager.PropertiesManager - getInstancesByPrecedence for: OCAP.serializationMgrDelegate: [org.cablelabs.impl.manager.recording.db.HNSerializationMgrDelegate]
20110720 18:27:39.996 DEBUG RI.Stack- 1328609 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata()
20110720 18:27:39.996 DEBUG RI.Stack- 1328609 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x44c, null
20110720 18:27:40.012 DEBUG RI.Stack- 1328609 [Thread-47] DEBUG service.SIRequestElement - @ab9c097c SIRequestElement ctor...
20110720 18:27:40.012 DEBUG RI.Stack- 1328625 [Thread-47] DEBUG service.SIRequestElement - @ab9c097c Creating SIRequestServices...
20110720 18:27:40.012 DEBUG RI.Stack- 1328625 [Thread-47] DEBUG service.SIRequestImpl - @7732c5d9SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.012 DEBUG RI.Stack- 1328625 [pool-14] DEBUG service.SIRequestElement - @ab9c097c Attempting delivery
20110720 18:27:40.012 DEBUG RI.Stack- 1328625 [pool-14] DEBUG service.SIRequestServices - @7732c5d9 Attempting delivery
20110720 18:27:40.012 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:40.027 INFO RI.Stack- 1328640 [pool-14] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:40.027 DEBUG RI.Stack- 1328640 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: specServiceNumber: 100, specSourceID():0x44c, sdi.getServiceNumber(): 100, sdi.getSourceID():0x44c
20110720 18:27:40.027 DEBUG RI.Stack- 1328640 [Thread-47] DEBUG recording.RecordingImpl - RI 0x7c25a1dd: Matched specServiceNumber and sourceId...
20110720 18:27:40.027 INFO RI.Stack- 1328640 [Thread-47] INFO recording.RecordingImpl - RI 0x7c25a1dd: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@31bf6e64[uniqueID=ServiceImpl414144600, locator=ocap://0x44c, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5858[handle=18af5858], name=HDNET, serviceType=UNKNOWN, serviceNumber=100, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:40.027 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetNumberOfServiceDetailsForServiceHandle()...returned 0
20110720 18:27:40.027 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetServiceDetailsForServiceHandle()...returned 0
20110720 18:27:40.027 DEBUG RI.Stack- 1328640 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveNetworks() called with org.cablelabs.impl.service.javatv.transport.TransportImpl@1ac3bc94[uniqueID=TransportImpl4096, deliverySystemType=CABLE, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$TransportHandleImpl@1000[handle=1000], transportID=1]
20110720 18:27:40.027 DEBUG RI.Stack- 1328640 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestNetworks@438500a6
20110720 18:27:40.027 DEBUG RI.Stack- 1328640 [pool-2] DEBUG service.SIRequestNetworks - @438500a6 Attempting delivery
20110720 18:27:40.043 DEBUG RI.Stack- 1328656 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveTransportStream() called with ocap://0x44c
20110720 18:27:40.043 DEBUG RI.Stack- 1328656 [Thread-47] DEBUG service.SIRequestImpl - @7deda819SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.043 DEBUG RI.Stack- 1328656 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestTransportStream@7deda819[transportID=1, frequency=ffffffff, sourceID=44c, serviceName=null]
20110720 18:27:40.043 DEBUG RI.Stack- 1328656 [pool-29] DEBUG service.SIRequestTransportStream - @7deda819 Attempting delivery
20110720 18:27:40.043 DEBUG RI.Stack- 1328656 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata(): scheduledChannelID@Type/scheduledChannelID: SI/1,1357,1100
20110720 18:27:40.043 DEBUG RI.Stack- 1328656 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.043 DEBUG RI.Stack- 1328656 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.043 DEBUG RI.Stack- 1328656 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.043 DEBUG RI.Stack- 1328656 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.043 DEBUG RI.Stack- 1328656 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.043 DEBUG RI.Stack- 1328656 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.043 DEBUG RI.Stack- 1328656 [Thread-47] DEBUG srs.SetMediaTimeListener - SetMediaTimeListener.notify(org.cablelabs.impl.ocap.hn.content.MetadataNodeImpl@f8bbf9a0, <"urn:schemas-cablelabs-org:metadata-1-0/", "mediaPresentationPoint">, 0, -1): the long number of milliseconds is -1, which indicates "not set"
20110720 18:27:40.043 DEBUG RI.Stack- 1328656 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.058 DEBUG RI.Stack- 1328671 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.058 DEBUG RI.Stack- 1328671 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.058 DEBUG RI.Stack- 1328671 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.058 DEBUG RI.Stack- 1328671 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.058 DEBUG RI.Stack- 1328671 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.058 DEBUG RI.Stack- 1328671 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata(): updating state: 6
20110720 18:27:40.058 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error. File not found
20110720 18:27:40.074 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error opening file. File not found
20110720 18:27:40.074 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f.1') error. File not found
20110720 18:27:40.074 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/7f') error. Unknown Error
20110720 18:27:40.074 DEBUG RI.Stack- 1328687 [Thread-47] DEBUG persistent.PersistentDataSerializer - Deleted /syscwd/persistent/dvr/recdbser/7f
20110720 18:27:40.074 INFO RI.Stack- 1328687 [Thread-47] INFO recording.NavigationManager - NavigatorManager::removeRecording from state 6 to 14 for req = RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@8c7507c, RI 0x7c25a1dd:[id 127,app 11127133,loc ocap://0x44c,start 2011/07/20 06:57:19-0600,dur 180s,es INCOMPLETE_STATE,is RecordingImpl.IStateEnded,pri 2,no segments]]
20110720 18:27:40.074 DEBUG RI.Stack- 1328687 [Thread-47] DEBUG recording.RecordingResourceManager - resolveConflictsForRecordingRemoval: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@8c7507c, RI 0x7c25a1dd:[id 127,app 11127133,loc ocap://0x44c,start 2011/07/20 06:57:19-0600,dur 180s,es DESTROYED_STATE,is RecordingImpl.IStateEnded,pri 2,no segments]]
20110720 18:27:40.090 DEBUG RI.Stack- 1328703 [Thread-47] DEBUG recording.RecordingResourceManager - attemptToReserveRecordingsDuring: << start 1311166639910, dur 180000>>: Overlapping P_W_C entries
20110720 18:27:40.090 DEBUG RI.Stack- 1328703 [Thread-47] DEBUG recording.RecordingResourceManager - OrderedRecordingSet 0xf4f7d8c4 has 0 recordings:

20110720 18:27:40.090 DEBUG RI.Stack- 1328703 [Thread-47] DEBUG recording.RecordingResourceManager - attemptToReserveRecordingsInOrderWithRCH: Attempting to reserve 0 recordings on 2 tuners
20110720 18:27:40.090 INFO RI.Stack.StdOut- [DCLI-CLIENT] [INFO] [RecordingUtil.recordingChanged: 783] - Not able to print the failure reason as the Recording Request has been already deleted
20110720 18:27:40.090 INFO RI.Stack- 1328703 [Thread-47] INFO recording.RecordingImpl - RI 0x1925eab8: Recording delete() Enter
20110720 18:27:40.090 DEBUG RI.Stack- 1328703 [Thread-47] DEBUG recording.Scheduler - Scheduler:descheduleRecording
20110720 18:27:40.090 DEBUG RI.Stack- 1328703 [Thread-47] DEBUG recording.Scheduler - StopSpec deschedule called, retSpec: TVTS 0x7e5874ab: [time=1311169342660, absolute=true, repeat=false, regular=true, listener=org.cablelabs.impl.manager.recording.Scheduler]
20110720 18:27:40.090 INFO RI.Stack- 1328703 [Thread-47] INFO recording.RecordingImpl - RI 0x1925eab8: IStateSuspended: handleStop - Stop called
20110720 18:27:40.090 DEBUG RI.Stack- 1328703 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: IStateEnded: constructing......
20110720 18:27:40.090 DEBUG RI.Stack- 1328703 [Thread-47] DEBUG storage.StorageManagerImpl - Removeing Storage Manager Listener
20110720 18:27:40.090 DEBUG RI.Stack- 1328703 [Thread-47] DEBUG storage.StorageManagerImpl - Removed Storage Manager Listener Successfully
20110720 18:27:40.090 DEBUG RI.Stack- 1328703 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: IStateEnded: processInterruptionState Enter...
20110720 18:27:40.105 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE
20110720 18:27:40.105 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE, datafile = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA_DATA/4E26D0BE_18BE
20110720 18:27:40.105 DEBUG RI.Stack- <<DVR>> mpeos_dvrRecordingGet (I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE) MPE_DVR_RECORDING_LENGTH = 0
20110720 18:27:40.105 DEBUG RI.Stack- 1328718 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: getRecordingDuration::nativeRecordingName: I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE duration: 0
20110720 18:27:40.105 INFO RI.Stack- 1328718 [Thread-47] INFO recording.RecordingImpl - RI 0x1925eab8: IStateEnded: processInterruption - actual duration of this recording: 0
20110720 18:27:40.105 DEBUG RI.Stack- 1328718 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: IStateEnded: Incomplete recording - due to user stop=
20110720 18:27:40.105 INFO RI.Stack- 1328718 [Thread-47] INFO recording.RecordingImpl - RI 0x1925eab8: IStateEnded: processInterruption on user stop - no recorded content found. Transitioning to FAILED_STATE
20110720 18:27:40.105 INFO RI.Stack- 1328718 [Thread-47] INFO recording.RecordingImpl - RI 0x1925eab8: Deleting native recording:I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE
20110720 18:27:40.105 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE
20110720 18:27:40.105 DEBUG RI.Stack- <<DVR>> convertRecordingNameToDatafile - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE, datafile = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA_DATA/4E26D0BE_18BE
20110720 18:27:40.105 DEBUG RI.Stack- <<DVR>> mpeos_dvrRecordingDelete - recordingName = I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE
20110720 18:27:40.121 ERROR RI.Stack- <<DVR>> mpeos_dvrRecordingDelete - Unable to delete recording data files -- I1/OCAP_LSV/1112/7133/TDK_MSV/4E26D0BE_18BE
20110720 18:27:40.121 DEBUG RI.Stack- Java_org_cablelabs_impl_storage_MediaStorageVolumeImpl_JNI:nGetFreeSpace
20110720 18:27:40.121 DEBUG RI.Stack- <<DVR>> mpeos_dvrMediaVolumeGetInfo Volume = /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV (1DECE0D0)
20110720 18:27:40.121 DEBUG RI.Stack- <<DVR>> mpeos_dvrMediaVolumeGetInfo MPE_DVR_MEDIA_VOL_FREE_SPACE = 1000000000, reservedSize = 1000000000, usedSize = 0, device freeMediaSize = -8673487873571728239
20110720 18:27:40.121 DEBUG RI.Stack- <<DVR>> Java_org_cablelabs_impl_storage_MediaStorageVolumeImpl_nGetFreeSpace returned storage space = 1000000000 bytes
20110720 18:27:40.121 DEBUG RI.Stack- 1328734 [Thread-47] DEBUG recording.RecordingRetentionManager - Sufficient space available. Not purging
20110720 18:27:40.137 DEBUG RI.Stack- 1328750 [Thread-47] DEBUG recording.RecordingManagerImpl - removeDisableBufferingListener: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es IN_PROGRESS_WITH_ERROR_STATE,is RecordingImpl.IStateSuspendedBufferingDisabled,pri 2,no segments]]
20110720 18:27:40.137 DEBUG RI.Stack- 1328750 [Thread-47] DEBUG recording.RecordingManagerImpl - removeDisableRecordingListener: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es IN_PROGRESS_WITH_ERROR_STATE,is RecordingImpl.IStateSuspendedBufferingDisabled,pri 2,no segments]]
20110720 18:27:40.137 INFO RI.Stack- 1328750 [Thread-47] INFO recording.RecordingImpl - RI 0x1925eab8: releaseTSWClient Called
20110720 18:27:40.137 DEBUG RI.Stack- 1328750 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: Calling TimeshiftClient.release()
20110720 18:27:40.137 DEBUG RI.Stack- JNI(TSB): nTSBGetStartTime(tsb 495465272)20110720 18:27:40.137 DEBUG RI.Stack- JNI(TSB): nTSBGetStartTime(tsb 495465272)20110720 18:27:40.137 DEBUG RI.Stack- 1328750 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateForRemovedUses: Removing use(s) NI for client TSWC 0x5d91d582:[nlist 1,ru org.cablelabs.impl.ocap.dvr.RecordingResourceUsageImpl@-1921251610[id=11127133,prio=220,org.davic.net.tuning.NetworkInterfaceController,],tsw TSW 0x312d9cce:[service ServiceImpl414145360 (ocap://0x45a) ,state BUFFERING,tuner 2,tbst 1195125ms,btsb TSB 0xf131ee64[size 3900,ntsb 0x1d883338,sysbufstart/end Wed Jul 20 06:57:34 GMT-06:00 2011/Wed Jul 20 06:57:40 GMT-06:00 2011,tbstart/end 1205734ms/9223372036854ms,tswoffset 10609ms,bufstopreason NOREASON], nclients 1, TSC:[uses NI,res BUFFERING+RECORDING,mind 0,desd 0,maxd MAX_VAL]],constrain TSC:[uses NO USES,res NO USES,mind 0,desd 0,maxd MAX_VAL],1st tsb:TSB 0xf131ee64[size 3900,ntsb 0x1d883338,sysbufstart/end Wed Jul 20 06:57:34 GMT-06:00 2011/Wed Jul 20 06:57:40 GMT-06:00 2011,tbstart/end 1205734ms/9223372036854ms,tswoffset 10609ms,bufstopreason NOREASON]]
20110720 18:27:40.152 DEBUG RI.Stack- 1328765 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateForRemovedUses: current state is BUFFERING, and no buffering uses remaining.
20110720 18:27:40.152 DEBUG RI.Stack- 1328765 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: descheduleTimer spec: TVTS 0xb5eaf3a: [time=1311166663940, absolute=true, repeat=false, regular=true, listener=org.cablelabs.impl.manager.timeshift.TimeShiftWindow$ExpirationTrigger]
20110720 18:27:40.152 DEBUG RI.Stack- 1328765 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: stopTimer: death timer cancelled
20110720 18:27:40.152 DEBUG RI.Stack- 1328765 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateForRemovedUses: No buffering uses remaining.
20110720 18:27:40.152 DEBUG RI.Stack- 1328765 [Thread-47] DEBUG timer.TimerMgrJava2 - scheduleTimerSpec: org.cablelabs.impl.manager.timer.TimerMgrJava2$TVTimerImpl$1@346e2a83, spec: TVTS 0x95b84ba4: [time=1311166665250, absolute=true, repeat=false, regular=true, listener=org.cablelabs.impl.manager.timeshift.TimeShiftWindow$ExpirationTrigger], time: 1311166665250
20110720 18:27:40.168 DEBUG RI.Stack- 1328781 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: scheduleTimerSpec spec: TVTS 0x95b84ba4: [time=1311166665250, absolute=true, repeat=false, regular=true, listener=org.cablelabs.impl.manager.timeshift.TimeShiftWindow$ExpirationTrigger]
20110720 18:27:40.168 DEBUG RI.Stack- 1328781 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: startTimer: death timer scheduled
20110720 18:27:40.168 DEBUG RI.Stack- 1328781 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateForRemovedUses: current state is BUFFERING/NOREASON and no tuner uses remaining.
20110720 18:27:40.168 DEBUG RI.Stack- 1328781 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateForRemovedUses: No TSB uses remaining.
20110720 18:27:40.168 DEBUG RI.Stack- 1328781 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateNIResourceUsages: Current NI resource usages: [org.cablelabs.impl.ocap.dvr.RecordingResourceUsageImpl@-1921251610[id=11127133,prio=220,org.davic.net.tuning.NetworkInterfaceController,]]
20110720 18:27:40.168 DEBUG RI.Stack- 1328781 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: updateNIResourceUsages: Removing ResourceUsage org.cablelabs.impl.ocap.dvr.RecordingResourceUsageImpl@-1921251610[id=11127133,prio=220,org.davic.net.tuning.NetworkInterfaceController,] from nic reservation
20110720 18:27:40.168 DEBUG RI.Stack- JNI(TSB): nTSBGetStartTime(tsb 495465272)20110720 18:27:40.168 INFO RI.Stack- 1328781 [Thread-47] INFO timeshift.TimeShiftWindow - TSW 0x312d9cce: removeClient: Removing client: TSWC 0x5d91d582:[nlist 1,ru org.cablelabs.impl.ocap.dvr.RecordingResourceUsageImpl@-1921251610[id=11127133,prio=220,org.davic.net.tuning.NetworkInterfaceController,],tsw TSW 0x312d9cce:[service ServiceImpl414145360 (ocap://0x45a) ,state BUFFERING,tuner 2,tbst 1195125ms,btsb TSB 0xf131ee64[size 3900,ntsb 0x1d883338,sysbufstart/end Wed Jul 20 06:57:34 GMT-06:00 2011/Wed Jul 20 06:57:40 GMT-06:00 2011,tbstart/end 1205734ms/9223372036854ms,tswoffset 10609ms,bufstopreason NOREASON], nclients 0, TSC:[uses NO USES,res NO USES,mind 0,desd 0,maxd MAX_VAL]],constrain TSC:[uses NO USES,res NO USES,mind 0,desd 0,maxd MAX_VAL],1st tsb: none]
20110720 18:27:40.199 DEBUG RI.Stack- 1328812 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: removeClient: Prior constraints: TSC:[uses NO USES,res NO USES,mind 0,desd 0,maxd MAX_VAL]
20110720 18:27:40.199 DEBUG RI.Stack- 1328812 [Thread-47] DEBUG timeshift.TimeShiftWindow - TSW 0x312d9cce: removeClient: New constraints: TSC:[uses NO USES,res NO USES,mind 0,desd 0,maxd MAX_VAL]
20110720 18:27:40.199 INFO RI.Stack- 1328812 [Thread-47] INFO timeshift.TimeShiftWindow - TSW 0x312d9cce: removeClient: Last client removed
20110720 18:27:40.199 DEBUG RI.Stack- 1328812 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: setStateAndNotify - oldState: IN_PROGRESS_WITH_ERROR_STATE New State: FAILED_STATE
20110720 18:27:40.199 DEBUG RI.Stack- 1328812 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: saveRecordingInfo: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es FAILED_STATE,is RecordingImpl.IStateSuspendedBufferingDisabled,pri 2,no segments]]
20110720 18:27:40.199 DEBUG RI.Stack- 1328812 [Thread-47] DEBUG db.SerializationMgr - updateRecord: ffffffff RecordingInfo2 0x80:[reqtype 2,loc {ocap://0x45a},snum 114,sdesc null,start 1311166643660,dur 2700000,dtime 0,drsn 2,fexp 6,mtime 0,rsrcePrior 0,nsegs 0,segs no segments,RecordingInfoNode:[uid 0x80,appId 11127133,state 8,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@142d9919,org 'null',expr Tue Sep 27 17:37:23 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:40.199 DEBUG RI.Stack- 1328812 [Thread-47] DEBUG persistent.PersistentDataSerializer - savePriv: RecordingInfo2 0x80:[reqtype 2,loc {ocap://0x45a},snum 114,sdesc null,start 1311166643660,dur 2700000,dtime 0,drsn 2,fexp 6,mtime 0,rsrcePrior 0,nsegs 0,segs no segments,RecordingInfoNode:[uid 0x80,appId 11127133,state 8,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@142d9919,org 'null',expr Tue Sep 27 17:37:23 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:40.199 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error opening file. File not found
20110720 18:27:40.199 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error. File not found
20110720 18:27:40.230 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error opening file. File not found
20110720 18:27:40.230 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error. File not found
20110720 18:27:40.230 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80') error. Unknown Error
20110720 18:27:40.293 INFO RI.Pipeline.TSB- tsbStateStarted -- Waiting for TSB to start operation
20110720 18:27:40.293 DEBUG RI.Stack- FAT32FileRename('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1'->'/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80')
20110720 18:27:40.293 DEBUG RI.Stack- 1328906 [Thread-47] DEBUG persistent.PersistentDataSerializer - savePriv: saved to /syscwd/persistent/dvr/recdbser/80
20110720 18:27:40.293 DEBUG RI.Stack- 1328906 [Thread-47] DEBUG manager.PropertiesManager - getInstancesByPrecedence for: OCAP.serializationMgrDelegate: [org.cablelabs.impl.manager.recording.db.HNSerializationMgrDelegate]
20110720 18:27:40.293 DEBUG RI.Stack- 1328906 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata()
20110720 18:27:40.293 DEBUG RI.Stack- 1328906 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x45a, null
20110720 18:27:40.293 DEBUG RI.Stack- 1328906 [Thread-47] DEBUG service.SIRequestElement - @6aa93cbd SIRequestElement ctor...
20110720 18:27:40.308 DEBUG RI.Stack- 1328921 [Thread-47] DEBUG service.SIRequestElement - @6aa93cbd Creating SIRequestServices...
20110720 18:27:40.308 DEBUG RI.Stack- 1328921 [Thread-47] DEBUG service.SIRequestImpl - @13d2b4bdSIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.308 DEBUG RI.Stack- 1328921 [pool-23] DEBUG service.SIRequestElement - @6aa93cbd Attempting delivery
20110720 18:27:40.308 DEBUG RI.Stack- 1328921 [pool-23] DEBUG service.SIRequestServices - @13d2b4bd Attempting delivery
20110720 18:27:40.308 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:40.308 INFO RI.Stack- 1328921 [pool-23] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:40.308 DEBUG RI.Stack- 1328921 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: specServiceNumber: 114, specSourceID():0x45a, sdi.getServiceNumber(): 114, sdi.getSourceID():0x45a
20110720 18:27:40.308 DEBUG RI.Stack- 1328921 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: Matched specServiceNumber and sourceId...
20110720 18:27:40.308 INFO RI.Stack- 1328921 [Thread-47] INFO recording.RecordingImpl - RI 0x1925eab8: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@9855dfcd[uniqueID=ServiceImpl414145360, locator=ocap://0x45a, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5b50[handle=18af5b50], name=DS 14, serviceType=UNKNOWN, serviceNumber=114, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:40.308 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetNumberOfServiceDetailsForServiceHandle()...returned 0
20110720 18:27:40.324 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetServiceDetailsForServiceHandle()...returned 0
20110720 18:27:40.324 DEBUG RI.Stack- 1328937 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveNetworks() called with org.cablelabs.impl.service.javatv.transport.TransportImpl@1ac3bc94[uniqueID=TransportImpl4096, deliverySystemType=CABLE, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$TransportHandleImpl@1000[handle=1000], transportID=1]
20110720 18:27:40.324 DEBUG RI.Stack- 1328937 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestNetworks@f161ca14
20110720 18:27:40.324 DEBUG RI.Stack- 1328937 [pool-18] DEBUG service.SIRequestNetworks - @f161ca14 Attempting delivery
20110720 18:27:40.324 DEBUG RI.Stack- 1328937 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveTransportStream() called with ocap://0x45a
20110720 18:27:40.324 DEBUG RI.Stack- 1328937 [Thread-47] DEBUG service.SIRequestImpl - @3b19ec5fSIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.340 DEBUG RI.Stack- 1328953 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestTransportStream@3b19ec5f[transportID=1, frequency=ffffffff, sourceID=45a, serviceName=null]
20110720 18:27:40.340 DEBUG RI.Stack- 1328953 [pool-9] DEBUG service.SIRequestTransportStream - @3b19ec5f Attempting delivery
20110720 18:27:40.340 DEBUG RI.Stack- 1328953 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata(): scheduledChannelID@Type/scheduledChannelID: SI/1,1357,1114
20110720 18:27:40.340 DEBUG RI.Stack- 1328953 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.340 DEBUG RI.Stack- 1328953 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.340 DEBUG RI.Stack- 1328953 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.340 DEBUG RI.Stack- 1328953 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.340 DEBUG RI.Stack- 1328953 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.340 DEBUG RI.Stack- 1328953 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.340 DEBUG RI.Stack- 1328953 [Thread-47] DEBUG srs.SetMediaTimeListener - SetMediaTimeListener.notify(org.cablelabs.impl.ocap.hn.content.MetadataNodeImpl@3b738863, <"urn:schemas-cablelabs-org:metadata-1-0/", "mediaPresentationPoint">, 0, -1): the long number of milliseconds is -1, which indicates "not set"
20110720 18:27:40.340 DEBUG RI.Stack- 1328953 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.355 DEBUG RI.Stack- 1328968 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.355 DEBUG RI.Stack- 1328968 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.355 DEBUG RI.Stack- 1328968 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.433 DEBUG RI.Stack- 1329046 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.433 DEBUG RI.Stack- 1329046 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.433 DEBUG RI.Stack- 1329046 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata(): updating state: 8
20110720 18:27:40.433 INFO RI.Stack- 1329046 [Thread-47] INFO recording.NavigationManager - NavigationManager: updateRecording from state = 15 to new state 8 for RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es FAILED_STATE,is RecordingImpl.IStateSuspendedBufferingDisabled,pri 2,no segments]]
20110720 18:27:40.433 INFO RI.Stack- 1329046 [Thread-47] INFO recording.RecordingImpl - RI 0x1925eab8: IState: setting state to RecordingImpl.IStateEnded
20110720 18:27:40.433 INFO RI.Stack- 1329046 [Thread-47] INFO recording.RecordingImpl - RI 0x1925eab8: setFailedExceptionReason: setting reason to USER_STOP (9)
20110720 18:27:40.433 DEBUG RI.Stack- 1329046 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: saveRecordingInfo: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es FAILED_STATE,is RecordingImpl.IStateEnded,pri 2,no segments]]
20110720 18:27:40.433 DEBUG RI.Stack- 1329046 [Thread-47] DEBUG db.SerializationMgr - updateRecord: 8000 RecordingInfo2 0x80:[reqtype 2,loc {ocap://0x45a},snum 114,sdesc null,start 1311166643660,dur 2700000,dtime 0,drsn 2,fexp 9,mtime 0,rsrcePrior 0,nsegs 0,segs no segments,RecordingInfoNode:[uid 0x80,appId 11127133,state 8,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@142d9919,org 'null',expr Tue Sep 27 17:37:23 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:40.449 DEBUG RI.Stack- 1329062 [Thread-47] DEBUG persistent.PersistentDataSerializer - savePriv: RecordingInfo2 0x80:[reqtype 2,loc {ocap://0x45a},snum 114,sdesc null,start 1311166643660,dur 2700000,dtime 0,drsn 2,fexp 9,mtime 0,rsrcePrior 0,nsegs 0,segs no segments,RecordingInfoNode:[uid 0x80,appId 11127133,state 8,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@142d9919,org 'null',expr Tue Sep 27 17:37:23 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:40.465 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error opening file. File not found
20110720 18:27:40.465 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error. File not found
20110720 18:27:40.465 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error opening file. File not found
20110720 18:27:40.465 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error. File not found
20110720 18:27:40.480 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80') error. Unknown Error
20110720 18:27:40.496 DEBUG RI.Stack- FAT32FileRename('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1'->'/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80')
20110720 18:27:40.496 DEBUG RI.Stack- 1329109 [Thread-47] DEBUG persistent.PersistentDataSerializer - savePriv: saved to /syscwd/persistent/dvr/recdbser/80
20110720 18:27:40.496 DEBUG RI.Stack- 1329109 [Thread-47] DEBUG manager.PropertiesManager - getInstancesByPrecedence for: OCAP.serializationMgrDelegate: [org.cablelabs.impl.manager.recording.db.HNSerializationMgrDelegate]
20110720 18:27:40.496 DEBUG RI.Stack- 1329109 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata()
20110720 18:27:40.496 DEBUG RI.Stack- 1329109 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x45a, null
20110720 18:27:40.496 DEBUG RI.Stack- 1329109 [Thread-47] DEBUG service.SIRequestElement - @81cdf856 SIRequestElement ctor...
20110720 18:27:40.496 DEBUG RI.Stack- 1329109 [Thread-47] DEBUG service.SIRequestElement - @81cdf856 Creating SIRequestServices...
20110720 18:27:40.496 DEBUG RI.Stack- 1329109 [Thread-47] DEBUG service.SIRequestImpl - @b36b161dSIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.496 DEBUG RI.Stack- 1329109 [pool-6] DEBUG service.SIRequestElement - @81cdf856 Attempting delivery
20110720 18:27:40.496 DEBUG RI.Stack- 1329109 [pool-6] DEBUG service.SIRequestServices - @b36b161d Attempting delivery
20110720 18:27:40.496 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:40.496 INFO RI.Stack- 1329109 [pool-6] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:40.496 DEBUG RI.Stack- 1329109 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: specServiceNumber: 114, specSourceID():0x45a, sdi.getServiceNumber(): 114, sdi.getSourceID():0x45a
20110720 18:27:40.496 DEBUG RI.Stack- 1329109 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: Matched specServiceNumber and sourceId...
20110720 18:27:40.527 INFO RI.Stack- 1329140 [Thread-47] INFO recording.RecordingImpl - RI 0x1925eab8: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@9855dfcd[uniqueID=ServiceImpl414145360, locator=ocap://0x45a, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5b50[handle=18af5b50], name=DS 14, serviceType=UNKNOWN, serviceNumber=114, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:40.527 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetNumberOfServiceDetailsForServiceHandle()...returned 0
20110720 18:27:40.527 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetServiceDetailsForServiceHandle()...returned 0
20110720 18:27:40.527 DEBUG RI.Stack- 1329140 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveNetworks() called with org.cablelabs.impl.service.javatv.transport.TransportImpl@1ac3bc94[uniqueID=TransportImpl4096, deliverySystemType=CABLE, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$TransportHandleImpl@1000[handle=1000], transportID=1]
20110720 18:27:40.527 DEBUG RI.Stack- 1329140 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestNetworks@cd38da28
20110720 18:27:40.527 DEBUG RI.Stack- 1329140 [pool-30] DEBUG service.SIRequestNetworks - @cd38da28 Attempting delivery
20110720 18:27:40.527 DEBUG RI.Stack- 1329140 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveTransportStream() called with ocap://0x45a
20110720 18:27:40.527 DEBUG RI.Stack- 1329140 [Thread-47] DEBUG service.SIRequestImpl - @a47aa1c0SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.527 DEBUG RI.Stack- 1329140 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestTransportStream@a47aa1c0[transportID=1, frequency=ffffffff, sourceID=45a, serviceName=null]
20110720 18:27:40.527 DEBUG RI.Stack- 1329140 [pool-14] DEBUG service.SIRequestTransportStream - @a47aa1c0 Attempting delivery
20110720 18:27:40.527 DEBUG RI.Stack- 1329140 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata(): scheduledChannelID@Type/scheduledChannelID: SI/1,1357,1114
20110720 18:27:40.527 DEBUG RI.Stack- 1329140 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.527 DEBUG RI.Stack- 1329140 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.543 DEBUG RI.Stack- 1329156 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.543 DEBUG RI.Stack- 1329156 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.543 DEBUG RI.Stack- 1329156 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.543 DEBUG RI.Stack- 1329156 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.558 DEBUG RI.Stack- 1329171 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata(): updating state: 8
20110720 18:27:40.558 DEBUG RI.Stack- 1329171 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: saveRecordingInfo: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es FAILED_STATE,is RecordingImpl.IStateEnded,pri 2,no segments]]
20110720 18:27:40.558 DEBUG RI.Stack- 1329171 [Thread-47] DEBUG db.SerializationMgr - updateRecord: 2000 RecordingInfo2 0x80:[reqtype 2,loc {ocap://0x45a},snum 114,sdesc null,start 1311166643660,dur 2700000,dtime 1311166660660,drsn 2,fexp 9,mtime 0,rsrcePrior 0,nsegs 0,segs no segments,RecordingInfoNode:[uid 0x80,appId 11127133,state 8,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@142d9919,org 'null',expr Tue Sep 27 17:37:23 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:40.558 DEBUG RI.Stack- 1329171 [Thread-47] DEBUG persistent.PersistentDataSerializer - savePriv: RecordingInfo2 0x80:[reqtype 2,loc {ocap://0x45a},snum 114,sdesc null,start 1311166643660,dur 2700000,dtime 1311166660660,drsn 2,fexp 9,mtime 0,rsrcePrior 0,nsegs 0,segs no segments,RecordingInfoNode:[uid 0x80,appId 11127133,state 8,pri 2,br 3,MSV org.cablelabs.impl.recording.MediaStorageVolumeReference@142d9919,org 'null',expr Tue Sep 27 17:37:23 GMT-06:00 2011,rpri 0,fap {perms 3f,raoids [none],waoids [none]},appdata [none]]]
20110720 18:27:40.558 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error opening file. File not found
20110720 18:27:40.558 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error. File not found
20110720 18:27:40.558 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error opening file. File not found
20110720 18:27:40.558 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error. File not found
20110720 18:27:40.590 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80') error. Unknown Error
20110720 18:27:40.605 DEBUG RI.Stack- FAT32FileRename('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1'->'/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80')
20110720 18:27:40.668 DEBUG RI.Stack- 1329281 [Thread-47] DEBUG persistent.PersistentDataSerializer - savePriv: saved to /syscwd/persistent/dvr/recdbser/80
20110720 18:27:40.683 DEBUG RI.Stack- 1329296 [Thread-47] DEBUG manager.PropertiesManager - getInstancesByPrecedence for: OCAP.serializationMgrDelegate: [org.cablelabs.impl.manager.recording.db.HNSerializationMgrDelegate]
20110720 18:27:40.683 DEBUG RI.Stack- 1329296 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata()
20110720 18:27:40.683 DEBUG RI.Stack- 1329296 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x45a, null
20110720 18:27:40.683 DEBUG RI.Stack- 1329296 [Thread-47] DEBUG service.SIRequestElement - @4b74419c SIRequestElement ctor...
20110720 18:27:40.683 DEBUG RI.Stack- 1329296 [Thread-47] DEBUG service.SIRequestElement - @4b74419c Creating SIRequestServices...
20110720 18:27:40.683 DEBUG RI.Stack- 1329296 [Thread-47] DEBUG service.SIRequestImpl - @e7fa9a0SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.683 DEBUG RI.Stack- 1329296 [pool-29] DEBUG service.SIRequestElement - @4b74419c Attempting delivery
20110720 18:27:40.683 DEBUG RI.Stack- 1329296 [pool-29] DEBUG service.SIRequestServices - @e7fa9a0 Attempting delivery
20110720 18:27:40.683 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:40.699 INFO RI.Stack- 1329312 [pool-29] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:40.699 DEBUG RI.Stack- 1329312 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: specServiceNumber: 114, specSourceID():0x45a, sdi.getServiceNumber(): 114, sdi.getSourceID():0x45a
20110720 18:27:40.699 DEBUG RI.Stack- 1329312 [Thread-47] DEBUG recording.RecordingImpl - RI 0x1925eab8: Matched specServiceNumber and sourceId...
20110720 18:27:40.699 INFO RI.Stack- 1329312 [Thread-47] INFO recording.RecordingImpl - RI 0x1925eab8: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@9855dfcd[uniqueID=ServiceImpl414145360, locator=ocap://0x45a, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5b50[handle=18af5b50], name=DS 14, serviceType=UNKNOWN, serviceNumber=114, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:40.699 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetNumberOfServiceDetailsForServiceHandle()...returned 0
20110720 18:27:40.699 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsByService: mpe_siGetServiceDetailsForServiceHandle()...returned 0
20110720 18:27:40.699 DEBUG RI.Stack- 1329312 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveNetworks() called with org.cablelabs.impl.service.javatv.transport.TransportImpl@1ac3bc94[uniqueID=TransportImpl4096, deliverySystemType=CABLE, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$TransportHandleImpl@1000[handle=1000], transportID=1]
20110720 18:27:40.699 DEBUG RI.Stack- 1329312 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestNetworks@8fb1136a
20110720 18:27:40.715 DEBUG RI.Stack- 1329328 [pool-3] DEBUG service.SIRequestNetworks - @8fb1136a Attempting delivery
20110720 18:27:40.715 DEBUG RI.Stack- 1329328 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveTransportStream() called with ocap://0x45a
20110720 18:27:40.715 DEBUG RI.Stack- 1329328 [Thread-47] DEBUG service.SIRequestImpl - @d8719dbcSIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.715 DEBUG RI.Stack- 1329328 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 Enqueued request org.cablelabs.impl.manager.service.SIRequestTransportStream@d8719dbc[transportID=1, frequency=ffffffff, sourceID=45a, serviceName=null]
20110720 18:27:40.715 DEBUG RI.Stack- 1329328 [pool-18] DEBUG service.SIRequestTransportStream - @d8719dbc Attempting delivery
20110720 18:27:40.715 DEBUG RI.Stack- 1329328 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata(): scheduledChannelID@Type/scheduledChannelID: SI/1,1357,1114
20110720 18:27:40.715 DEBUG RI.Stack- 1329328 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.730 DEBUG RI.Stack- 1329343 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.730 DEBUG RI.Stack- 1329343 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.730 DEBUG RI.Stack- 1329343 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.730 DEBUG RI.Stack- 1329343 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - entry id null, isLocal()=true, m_action=null
20110720 18:27:40.730 DEBUG RI.Stack- 1329343 [Thread-47] DEBUG content.ContentEntryImpl - ContentEntryImpl.getCDSContentEntry() - getting entry from server
20110720 18:27:40.730 DEBUG RI.Stack- 1329343 [Thread-47] DEBUG srs.RecordingContentItemLocal - updateMetadata(): updating state: 8
20110720 18:27:40.730 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error. File not found
20110720 18:27:40.730 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error opening file. File not found
20110720 18:27:40.730 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80.1') error. File not found
20110720 18:27:40.730 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/persistent/dvr/recdbser/80') error. Unknown Error
20110720 18:27:40.746 DEBUG RI.Stack- 1329359 [Thread-47] DEBUG persistent.PersistentDataSerializer - Deleted /syscwd/persistent/dvr/recdbser/80
20110720 18:27:40.746 INFO RI.Stack- 1329359 [Thread-47] INFO recording.NavigationManager - NavigatorManager::removeRecording from state 8 to 14 for req = RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es FAILED_STATE,is RecordingImpl.IStateEnded,pri 2,no segments]]
20110720 18:27:40.746 DEBUG RI.Stack- 1329359 [Thread-47] DEBUG recording.RecordingResourceManager - resolveConflictsForRecordingRemoval: RecordingContentItemLocal [id = null, CDS RecordingContentItem = org.cablelabs.impl.ocap.hn.recording.RecordingContentItemImpl@1118dc65, RI 0x1925eab8:[id 128,app 11127133,loc ocap://0x45a,start 2011/07/20 06:57:23-0600,dur 2700s,es DESTROYED_STATE,is RecordingImpl.IStateEnded,pri 2,no segments]]
20110720 18:27:40.762 DEBUG RI.Stack- 1329375 [Thread-47] DEBUG recording.RecordingResourceManager - attemptToReserveRecordingsDuring: << start 1311166643660, dur 2700000>>: Overlapping P_W_C entries
20110720 18:27:40.762 DEBUG RI.Stack- 1329375 [Thread-47] DEBUG recording.RecordingResourceManager - OrderedRecordingSet 0xe10a4dd1 has 0 recordings:

20110720 18:27:40.762 DEBUG RI.Stack- 1329375 [Thread-47] DEBUG recording.RecordingResourceManager - attemptToReserveRecordingsInOrderWithRCH: Attempting to reserve 0 recordings on 2 tuners
20110720 18:27:40.762 DEBUG RI.Stack- 1329375 [Thread-47] DEBUG storage.StorageProxyImpl - Available Options Size is :1
20110720 18:27:40.762 INFO RI.Stack.StdOut- [DCLI-CLIENT] [INFO] [StorageUtil.deleteMediaStorageVolume: 152] - Path of mediaStorageVolume present : /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV
20110720 18:27:40.762 DEBUG RI.Stack- 1329375 [Thread-47] DEBUG storage.DVRStorageProxyImpl - deleteVolume :Removing Media Storage Volume
20110720 18:27:40.762 DEBUG RI.Stack- 1329375 [Thread-47] DEBUG storage.StorageProxyImpl - deleteVolume:The volume exists :org.cablelabs.impl.storage.MediaStorageVolumeImpl@a1be4418
20110720 18:27:40.762 DEBUG RI.Stack- 1329375 [Thread-47] DEBUG recording.NavigationManager - NavigationManager: getEntries
20110720 18:27:40.762 DEBUG RI.Stack- 1329375 [Thread-47] DEBUG recording.NavigationManager - NavigationManager: getEntries(filter)
20110720 18:27:40.762 DEBUG RI.Stack- 1329375 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x44c, null
20110720 18:27:40.777 DEBUG RI.Stack- 1329390 [Thread-47] DEBUG service.SIRequestElement - @8b7ad45c SIRequestElement ctor...
20110720 18:27:40.777 DEBUG RI.Stack- 1329390 [Thread-47] DEBUG service.SIRequestElement - @8b7ad45c Creating SIRequestServices...
20110720 18:27:40.793 DEBUG RI.Stack- 1329406 [Thread-47] DEBUG service.SIRequestImpl - @170bf6b9SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.793 DEBUG RI.Stack- 1329406 [pool-10] DEBUG service.SIRequestElement - @8b7ad45c Attempting delivery
20110720 18:27:40.793 DEBUG RI.Stack- 1329406 [pool-10] DEBUG service.SIRequestServices - @170bf6b9 Attempting delivery
20110720 18:27:40.793 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:40.793 INFO RI.Stack- 1329406 [pool-10] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:40.793 DEBUG RI.Stack- 1329406 [Thread-47] DEBUG recording.RecordingImpl - RI 0x9be95e3a: specServiceNumber: 100, specSourceID():0x44c, sdi.getServiceNumber(): 100, sdi.getSourceID():0x44c
20110720 18:27:40.793 DEBUG RI.Stack- 1329406 [Thread-47] DEBUG recording.RecordingImpl - RI 0x9be95e3a: Matched specServiceNumber and sourceId...
20110720 18:27:40.793 INFO RI.Stack- 1329406 [Thread-47] INFO recording.RecordingImpl - RI 0x9be95e3a: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@31bf6e64[uniqueID=ServiceImpl414144600, locator=ocap://0x44c, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5858[handle=18af5858], name=HDNET, serviceType=UNKNOWN, serviceNumber=100, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:40.793 DEBUG RI.Stack- 1329406 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x45a, null
20110720 18:27:40.793 DEBUG RI.Stack- 1329406 [Thread-47] DEBUG service.SIRequestElement - @99732b4e SIRequestElement ctor...
20110720 18:27:40.793 DEBUG RI.Stack- 1329406 [Thread-47] DEBUG service.SIRequestElement - @99732b4e Creating SIRequestServices...
20110720 18:27:40.793 DEBUG RI.Stack- 1329406 [Thread-47] DEBUG service.SIRequestImpl - @b1204a1fSIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.793 DEBUG RI.Stack- 1329406 [pool-20] DEBUG service.SIRequestElement - @99732b4e Attempting delivery
20110720 18:27:40.793 DEBUG RI.Stack- 1329406 [pool-20] DEBUG service.SIRequestServices - @b1204a1f Attempting delivery
20110720 18:27:40.793 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:40.793 INFO RI.Stack- 1329406 [pool-20] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:40.793 DEBUG RI.Stack- 1329406 [Thread-47] DEBUG recording.RecordingImpl - RI 0x450485e4: specServiceNumber: 114, specSourceID():0x45a, sdi.getServiceNumber(): 114, sdi.getSourceID():0x45a
20110720 18:27:40.808 DEBUG RI.Stack- 1329421 [Thread-47] DEBUG recording.RecordingImpl - RI 0x450485e4: Matched specServiceNumber and sourceId...
20110720 18:27:40.808 INFO RI.Stack- 1329421 [Thread-47] INFO recording.RecordingImpl - RI 0x450485e4: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@9855dfcd[uniqueID=ServiceImpl414145360, locator=ocap://0x45a, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5b50[handle=18af5b50], name=DS 14, serviceType=UNKNOWN, serviceNumber=114, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:40.808 DEBUG RI.Stack- 1329421 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x44c, null
20110720 18:27:40.808 DEBUG RI.Stack- 1329421 [Thread-47] DEBUG service.SIRequestElement - @aee26879 SIRequestElement ctor...
20110720 18:27:40.808 DEBUG RI.Stack- 1329421 [Thread-47] DEBUG service.SIRequestElement - @aee26879 Creating SIRequestServices...
20110720 18:27:40.808 DEBUG RI.Stack- 1329421 [Thread-47] DEBUG service.SIRequestImpl - @743906daSIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.808 DEBUG RI.Stack- 1329421 [pool-24] DEBUG service.SIRequestElement - @aee26879 Attempting delivery
20110720 18:27:40.808 DEBUG RI.Stack- 1329421 [pool-24] DEBUG service.SIRequestServices - @743906da Attempting delivery
20110720 18:27:40.808 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:40.808 INFO RI.Stack- 1329421 [pool-24] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:40.824 DEBUG RI.Stack- 1329437 [Thread-47] DEBUG recording.RecordingImpl - RI 0xa8745809: specServiceNumber: 100, specSourceID():0x44c, sdi.getServiceNumber(): 100, sdi.getSourceID():0x44c
20110720 18:27:40.824 DEBUG RI.Stack- 1329437 [Thread-47] DEBUG recording.RecordingImpl - RI 0xa8745809: Matched specServiceNumber and sourceId...
20110720 18:27:40.824 INFO RI.Stack- 1329437 [Thread-47] INFO recording.RecordingImpl - RI 0xa8745809: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@31bf6e64[uniqueID=ServiceImpl414144600, locator=ocap://0x44c, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5858[handle=18af5858], name=HDNET, serviceType=UNKNOWN, serviceNumber=100, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:40.840 DEBUG RI.Stack- 1329453 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x44c, null
20110720 18:27:40.855 DEBUG RI.Stack- 1329468 [Thread-47] DEBUG service.SIRequestElement - @a7f11270 SIRequestElement ctor...
20110720 18:27:40.855 DEBUG RI.Stack- 1329468 [Thread-47] DEBUG service.SIRequestElement - @a7f11270 Creating SIRequestServices...
20110720 18:27:40.855 DEBUG RI.Stack- 1329468 [Thread-47] DEBUG service.SIRequestImpl - @b8f18d16SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.949 DEBUG RI.Stack- 1329562 [pool-14] DEBUG service.SIRequestElement - @a7f11270 Attempting delivery
20110720 18:27:40.949 DEBUG RI.Stack- 1329562 [pool-14] DEBUG service.SIRequestServices - @b8f18d16 Attempting delivery
20110720 18:27:40.949 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:40.949 INFO RI.Stack- 1329562 [pool-14] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:40.949 DEBUG RI.Stack- 1329562 [Thread-47] DEBUG recording.RecordingImpl - RI 0x774017d6: specServiceNumber: 100, specSourceID():0x44c, sdi.getServiceNumber(): 100, sdi.getSourceID():0x44c
20110720 18:27:40.949 DEBUG RI.Stack- 1329562 [Thread-47] DEBUG recording.RecordingImpl - RI 0x774017d6: Matched specServiceNumber and sourceId...
20110720 18:27:40.949 INFO RI.Stack- 1329562 [Thread-47] INFO recording.RecordingImpl - RI 0x774017d6: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@31bf6e64[uniqueID=ServiceImpl414144600, locator=ocap://0x44c, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5858[handle=18af5858], name=HDNET, serviceType=UNKNOWN, serviceNumber=100, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:40.949 DEBUG RI.Stack- 1329562 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x45a, null
20110720 18:27:40.965 DEBUG RI.Stack- 1329578 [Thread-47] DEBUG service.SIRequestElement - @5965bc8e SIRequestElement ctor...
20110720 18:27:40.965 DEBUG RI.Stack- 1329578 [Thread-47] DEBUG service.SIRequestElement - @5965bc8e Creating SIRequestServices...
20110720 18:27:40.965 DEBUG RI.Stack- 1329578 [Thread-47] DEBUG service.SIRequestImpl - @c73e4d69SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.980 DEBUG RI.Stack- 1329593 [pool-16] DEBUG service.SIRequestElement - @5965bc8e Attempting delivery
20110720 18:27:40.980 DEBUG RI.Stack- 1329593 [pool-16] DEBUG service.SIRequestServices - @c73e4d69 Attempting delivery
20110720 18:27:40.980 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:40.980 INFO RI.Stack- 1329593 [pool-16] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:40.980 DEBUG RI.Stack- 1329593 [Thread-47] DEBUG recording.RecordingImpl - RI 0xb05f7a11: specServiceNumber: 114, specSourceID():0x45a, sdi.getServiceNumber(): 114, sdi.getSourceID():0x45a
20110720 18:27:40.980 DEBUG RI.Stack- 1329593 [Thread-47] DEBUG recording.RecordingImpl - RI 0xb05f7a11: Matched specServiceNumber and sourceId...
20110720 18:27:40.996 INFO RI.Stack- 1329593 [Thread-47] INFO recording.RecordingImpl - RI 0xb05f7a11: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@9855dfcd[uniqueID=ServiceImpl414145360, locator=ocap://0x45a, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5b50[handle=18af5b50], name=DS 14, serviceType=UNKNOWN, serviceNumber=114, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:40.996 DEBUG RI.Stack- 1329609 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x44c, null
20110720 18:27:40.996 DEBUG RI.Stack- 1329609 [Thread-47] DEBUG service.SIRequestElement - @644c3fb3 SIRequestElement ctor...
20110720 18:27:40.996 DEBUG RI.Stack- 1329609 [Thread-47] DEBUG service.SIRequestElement - @644c3fb3 Creating SIRequestServices...
20110720 18:27:40.996 DEBUG RI.Stack- 1329609 [Thread-47] DEBUG service.SIRequestImpl - @2bea2c85SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:40.996 DEBUG RI.Stack- 1329609 [pool-3] DEBUG service.SIRequestElement - @644c3fb3 Attempting delivery
20110720 18:27:40.996 DEBUG RI.Stack- 1329609 [pool-3] DEBUG service.SIRequestServices - @2bea2c85 Attempting delivery
20110720 18:27:40.996 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:40.996 INFO RI.Stack- 1329609 [pool-3] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:40.996 DEBUG RI.Stack- 1329609 [Thread-47] DEBUG recording.RecordingImpl - RI 0x268abe87: specServiceNumber: 100, specSourceID():0x44c, sdi.getServiceNumber(): 100, sdi.getSourceID():0x44c
20110720 18:27:40.996 DEBUG RI.Stack- 1329609 [Thread-47] DEBUG recording.RecordingImpl - RI 0x268abe87: Matched specServiceNumber and sourceId...
20110720 18:27:40.996 INFO RI.Stack- 1329609 [Thread-47] INFO recording.RecordingImpl - RI 0x268abe87: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@31bf6e64[uniqueID=ServiceImpl414144600, locator=ocap://0x44c, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5858[handle=18af5858], name=HDNET, serviceType=UNKNOWN, serviceNumber=100, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:40.996 DEBUG RI.Stack- 1329609 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x44c, null
20110720 18:27:40.996 DEBUG RI.Stack- 1329609 [Thread-47] DEBUG service.SIRequestElement - @ec10d03b SIRequestElement ctor...
20110720 18:27:41.011 DEBUG RI.Stack- 1329625 [Thread-47] DEBUG service.SIRequestElement - @ec10d03b Creating SIRequestServices...
20110720 18:27:41.011 DEBUG RI.Stack- 1329625 [Thread-47] DEBUG service.SIRequestImpl - @1dd6d8b3SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:41.011 DEBUG RI.Stack- 1329625 [pool-13] DEBUG service.SIRequestElement - @ec10d03b Attempting delivery
20110720 18:27:41.011 DEBUG RI.Stack- 1329625 [pool-13] DEBUG service.SIRequestServices - @1dd6d8b3 Attempting delivery
20110720 18:27:41.011 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:41.011 INFO RI.Stack- 1329625 [pool-13] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:41.011 DEBUG RI.Stack- 1329625 [Thread-47] DEBUG recording.RecordingImpl - RI 0xaae9d00b: specServiceNumber: 100, specSourceID():0x44c, sdi.getServiceNumber(): 100, sdi.getSourceID():0x44c
20110720 18:27:41.011 DEBUG RI.Stack- 1329625 [Thread-47] DEBUG recording.RecordingImpl - RI 0xaae9d00b: Matched specServiceNumber and sourceId...
20110720 18:27:41.011 INFO RI.Stack- 1329625 [Thread-47] INFO recording.RecordingImpl - RI 0xaae9d00b: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@31bf6e64[uniqueID=ServiceImpl414144600, locator=ocap://0x44c, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5858[handle=18af5858], name=HDNET, serviceType=UNKNOWN, serviceNumber=100, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:41.011 DEBUG RI.Stack- 1329625 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x45a, null
20110720 18:27:41.011 DEBUG RI.Stack- 1329625 [Thread-47] DEBUG service.SIRequestElement - @ff2d0a28 SIRequestElement ctor...
20110720 18:27:41.027 DEBUG RI.Stack- 1329640 [Thread-47] DEBUG service.SIRequestElement - @ff2d0a28 Creating SIRequestServices...
20110720 18:27:41.027 DEBUG RI.Stack- 1329640 [Thread-47] DEBUG service.SIRequestImpl - @99f5f137SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:41.027 DEBUG RI.Stack- 1329640 [pool-10] DEBUG service.SIRequestElement - @ff2d0a28 Attempting delivery
20110720 18:27:41.027 DEBUG RI.Stack- 1329640 [pool-10] DEBUG service.SIRequestServices - @99f5f137 Attempting delivery
20110720 18:27:41.027 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:41.027 INFO RI.Stack- 1329640 [pool-10] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:41.215 DEBUG RI.Stack- 1329828 [Thread-47] DEBUG recording.RecordingImpl - RI 0x99eee138: specServiceNumber: 114, specSourceID():0x45a, sdi.getServiceNumber(): 114, sdi.getSourceID():0x45a
20110720 18:27:41.215 DEBUG RI.Stack- 1329828 [Thread-47] DEBUG recording.RecordingImpl - RI 0x99eee138: Matched specServiceNumber and sourceId...
20110720 18:27:41.230 INFO RI.Stack- 1329843 [Thread-47] INFO recording.RecordingImpl - RI 0x99eee138: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@9855dfcd[uniqueID=ServiceImpl414145360, locator=ocap://0x45a, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5b50[handle=18af5b50], name=DS 14, serviceType=UNKNOWN, serviceNumber=114, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:41.230 DEBUG RI.Stack- 1329843 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x44c, null
20110720 18:27:41.261 DEBUG RI.Stack- 1329859 [Thread-47] DEBUG service.SIRequestElement - @f2af7125 SIRequestElement ctor...
20110720 18:27:41.261 DEBUG RI.Stack- 1329875 [Thread-47] DEBUG service.SIRequestElement - @f2af7125 Creating SIRequestServices...
20110720 18:27:41.261 DEBUG RI.Stack- 1329875 [Thread-47] DEBUG service.SIRequestImpl - @812d502fSIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:41.261 DEBUG RI.Stack- 1329875 [pool-22] DEBUG service.SIRequestElement - @f2af7125 Attempting delivery
20110720 18:27:41.261 DEBUG RI.Stack- 1329875 [pool-22] DEBUG service.SIRequestServices - @812d502f Attempting delivery
20110720 18:27:41.261 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:41.261 INFO RI.Stack- 1329875 [pool-22] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:41.261 DEBUG RI.Stack- 1329875 [Thread-47] DEBUG recording.RecordingImpl - RI 0x654aecc4: specServiceNumber: 100, specSourceID():0x44c, sdi.getServiceNumber(): 100, sdi.getSourceID():0x44c
20110720 18:27:41.261 DEBUG RI.Stack- 1329875 [Thread-47] DEBUG recording.RecordingImpl - RI 0x654aecc4: Matched specServiceNumber and sourceId...
20110720 18:27:41.261 INFO RI.Stack- 1329875 [Thread-47] INFO recording.RecordingImpl - RI 0x654aecc4: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@31bf6e64[uniqueID=ServiceImpl414144600, locator=ocap://0x44c, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5858[handle=18af5858], name=HDNET, serviceType=UNKNOWN, serviceNumber=100, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:41.277 DEBUG RI.Stack- 1329890 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x45a, null
20110720 18:27:41.277 DEBUG RI.Stack- 1329890 [Thread-47] DEBUG service.SIRequestElement - @aeeb5a79 SIRequestElement ctor...
20110720 18:27:41.324 INFO RI.Pipeline.TSB- tsbStateStarted -- Waiting for TSB to start operation
20110720 18:27:41.277 DEBUG RI.Stack- 1329890 [Thread-47] DEBUG service.SIRequestElement - @aeeb5a79 Creating SIRequestServices...
20110720 18:27:41.355 DEBUG RI.Stack- 1329968 [Thread-47] DEBUG service.SIRequestImpl - @4b80d1e5SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:41.355 DEBUG RI.Stack- 1329968 [pool-30] DEBUG service.SIRequestElement - @aeeb5a79 Attempting delivery
20110720 18:27:41.355 DEBUG RI.Stack- 1329968 [pool-30] DEBUG service.SIRequestServices - @4b80d1e5 Attempting delivery
20110720 18:27:41.418 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:41.418 INFO RI.Stack- 1330031 [pool-30] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:41.418 DEBUG RI.Stack- 1330031 [Thread-47] DEBUG recording.RecordingImpl - RI 0xc8043f69: specServiceNumber: 114, specSourceID():0x45a, sdi.getServiceNumber(): 114, sdi.getSourceID():0x45a
20110720 18:27:41.418 DEBUG RI.Stack- 1330031 [Thread-47] DEBUG recording.RecordingImpl - RI 0xc8043f69: Matched specServiceNumber and sourceId...
20110720 18:27:41.418 INFO RI.Stack- 1330031 [Thread-47] INFO recording.RecordingImpl - RI 0xc8043f69: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@9855dfcd[uniqueID=ServiceImpl414145360, locator=ocap://0x45a, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5b50[handle=18af5b50], name=DS 14, serviceType=UNKNOWN, serviceNumber=114, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:41.418 DEBUG RI.Stack- 1330031 [Thread-47] DEBUG service.SICacheImpl - org.cablelabs.impl.manager.service.SICacheImpl@151e54e8 retrieveSIElement() called with ocap://0x44c, null
20110720 18:27:41.418 DEBUG RI.Stack- 1330031 [Thread-47] DEBUG service.SIRequestElement - @4854249f SIRequestElement ctor...
20110720 18:27:41.418 DEBUG RI.Stack- 1330031 [Thread-47] DEBUG service.SIRequestElement - @4854249f Creating SIRequestServices...
20110720 18:27:41.433 DEBUG RI.Stack- 1330046 [Thread-47] DEBUG service.SIRequestImpl - @db305975SIRequestImpl setExpirationTime: 9223372036854775807
20110720 18:27:41.433 DEBUG RI.Stack- 1330046 [pool-14] DEBUG service.SIRequestElement - @4854249f Attempting delivery
20110720 18:27:41.433 DEBUG RI.Stack- 1330046 [pool-7] DEBUG service.SIRequestServices - @db305975 Attempting delivery
20110720 18:27:41.433 DEBUG RI.Stack- <<JNI-SIDB>> nativeGetServiceDetailsBySourceID - returned result:0 length:1
20110720 18:27:41.433 INFO RI.Stack- 1330046 [pool-7] INFO service.SIRequestServices - getServiceDetailsBySourceID returned 1
20110720 18:27:41.449 DEBUG RI.Stack- 1330062 [Thread-47] DEBUG recording.RecordingImpl - RI 0xfef41a5f: specServiceNumber: 100, specSourceID():0x44c, sdi.getServiceNumber(): 100, sdi.getSourceID():0x44c
20110720 18:27:41.449 DEBUG RI.Stack- 1330062 [Thread-47] DEBUG recording.RecordingImpl - RI 0xfef41a5f: Matched specServiceNumber and sourceId...
20110720 18:27:41.449 INFO RI.Stack- 1330062 [Thread-47] INFO recording.RecordingImpl - RI 0xfef41a5f: specService: org.cablelabs.impl.service.javatv.service.ServiceImpl@31bf6e64[uniqueID=ServiceImpl414144600, locator=ocap://0x44c, handle=org.cablelabs.impl.manager.service.SIDatabaseImpl$ServiceHandleImpl@18af5858[handle=18af5858], name=HDNET, serviceType=UNKNOWN, serviceNumber=100, minorNumber=-1, lsData=null, locData=null]
20110720 18:27:41.465 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA') error opening file. Unknown Error
20110720 18:27:41.465 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA') error opening file. Unknown Error
20110720 18:27:41.480 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA/4E26D0BE_18BE') error opening file. Unknown Error
20110720 18:27:41.496 DEBUG RI.Stack- FAT32FileOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA/4E26D0BE_18BE') error opening file. Unknown Error
20110720 18:27:41.511 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA/4E26D0BE_18BE/0000000000.mpg') error. Unknown Error
20110720 18:27:41.527 DEBUG RI.Stack- FAT32DirOpen('/d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA/4E26D0BE_18BE/0000000000.ndx') error. Unknown Error
20110720 18:27:41.527 DEBUG RI.Stack- Removing directory - /d/RI-DEV/RI-114-Latest/ri/RI_Stack/bin/CableLabs/simulator/Win32/debug/env/storage/I1/OCAP_LSV/1112/7133/TDK_MSV/MEDIA/4E26D0BE_18BE
20110720 18:27:41.527 DEBUG RI.Stack- mpeos_fileFAT32DirDelete Return Value Error - 13
20110720 18:27:41.527 DEBUG RI.Stack- 1330140 [Thread-47] DEBUG storage.LogicalStorageVolumeImpl - Unable to delete file(s)

AttachmentSize
tsb-convert-stop.txt176.33 KB

Reply viewing options

Select your preferred way to display the comments and click "Save settings" to activate your changes.
smaynard
Offline
Joined: 2009-01-27

This looks like a legit bug - you should probably create an issue. We'll dig into this further...

krushna
Offline
Joined: 2010-09-21

Hi i have raised a Issue tracker for this : http://java.net/jira/browse/OCAP_RI-510

krushna
Offline
Joined: 2010-09-21

Hi

After analysing the code and logs carefully, When we start the TSB the TSB is not actually started by platform it is in tsbstatestarted becuase the starttime is 0. when we try to stop the conversion the code checks the current state of the TSB if it is activestate then only it can stop the conversion properly. Since the state is tsbstatestarted it never stops the TSB conversion.

I can see the waiting for TSB to start log. This issue would be addressed with the Issue tracker : http://java.net/jira/browse/OCAP_RI-445