ocapri_log.txt:Oct 24 10:31:13.892168 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.890773 [mod=REC, lvl=INFO] [tid=3493] processScheduleData New request=0x9ab1b108 ocapri_log.txt:Oct 24 10:31:13.892605 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.891725 [mod=REC, lvl=INFO] [tid=3369] reservedSpace TSB = 10000000000 ocapri_log.txt:Oct 24 10:31:13.893133 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.889841 [mod=REC, lvl=INFO] [tid=3494] [Monitor::run ]Getting monitor interval: 60 20170915 ocapri_log.txt:Oct 24 10:31:13.893594 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.892176 [mod=REC, lvl=INFO] [tid=3493] [Communicator::processScheduleData] before parseAndProcess(p->data_url New request=0x9ab1b108 20170915 ocapri_log.txt:Oct 24 10:31:13.894045 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.892696 [mod=MS, lvl=INFO] [tid=3369] 20170925#########startRecorder#### before rec->recorderRun() [MediaStreamerMain.cpp] ocapri_log.txt:Oct 24 10:31:13.894808 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.892789 [mod=REC, lvl=INFO] [tid=3495] Starting disk space monitor... ocapri_log.txt:Oct 24 10:31:13.894961 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.893147 [mod=REC, lvl=INFO] [tid=3494] Starting monitor... ocapri_log.txt:Oct 24 10:31:13.895403 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.893605 [mod=REC, lvl=INFO] [tid=3493] [Communicator::parseAndProcess] @@@@@@@@@@@@@@@@@@@@@@@ 20170915 ocapri_log.txt:Oct 24 10:31:13.895962 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.894817 [mod=REC, lvl=INFO] [tid=3495] DiskSpaceMonitor: SpaceChecker :- Going to check diskspace ocapri_log.txt:Oct 24 10:31:13.896283 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.894969 [mod=REC, lvl=INFO] [tid=3494] Monitor: SpaceChecker :- Going to check diskspace ocapri_log.txt:Oct 24 10:31:13.896719 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.895412 [mod=REC, lvl=INFO] [tid=3493] [Communicator::parseAndProcess] data_url (null) resp_url (null) 20170915 ocapri_log.txt:Oct 24 10:31:13.897584 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.896291 [mod=REC, lvl=INFO] [tid=3494] [Monitor::run ] Monitor: SpaceChecker :- Going to check diskspace 20170915 ocapri_log.txt:Oct 24 10:31:13.897623 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.897605 [mod=REC, lvl=INFO] [tid=3494] [Config::getFileSystemExt3Config] end fileSystemExt3 = [1] fileSystemExt3ConfigRead = [1] ocapri_log.txt:Oct 24 10:31:13.898067 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.896727 [mod=REC, lvl=INFO] [tid=3493] [Communicator::parseAndProcess] @@@@@@@@@@@@@@@@@@@@@@@ 20170915 ocapri_log.txt:Oct 24 10:31:13.898533 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.897630 [mod=REC, lvl=INFO] [tid=3494] checkVolume - Ext3 file system ocapri_log.txt:Oct 24 10:31:13.899045 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.895989 [mod=REC, lvl=INFO] [tid=3495] [Config::getDefaultVolume] mountTablet=/proc/mounts 20170915 ocapri_log.txt:Oct 24 10:31:13.899607 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.898100 [mod=REC, lvl=WARN] [tid=3493] Could not retrieve dvr protocol version from object ocapri_log.txt:Oct 24 10:31:13.900061 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.898541 [mod=REC, lvl=INFO] [tid=3494] [Monitor::checkVolume]checkVolume - Ext3 file system 20170915 ocapri_log.txt:Oct 24 10:31:13.900515 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.899203 [mod=REC, lvl=INFO] [tid=3495] /dev/sda1 on /tmp/usb type ext3 (rw,relatime,data=ordered) ocapri_log.txt:Oct 24 10:31:13.900960 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.899617 [mod=REC, lvl=INFO] [tid=3493] [Communicator::parseAndProcess] update_schedule = [-1699630688] 20170915 ocapri_log.txt:Oct 24 10:31:13.901537 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.900085 [mod=REC, lvl=INFO] [tid=3494] [Monitor::calculateSpaceMarkedForFreeing] Calculating space occupied by recordings that are marked for deletion 20170915 ocapri_log.txt:Oct 24 10:31:13.901994 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.900524 [mod=REC, lvl=INFO] [tid=3495] [Config::getDefaultVolume] if (mountTable)/dev/sda1 on /tmp/usb type ext3 (rw,relatime,data=ordered) 20170915 ocapri_log.txt:Oct 24 10:31:13.902446 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.901103 [mod=REC, lvl=INFO] [tid=3493] [Communicator::parseAndProcess] updateSchedule = -1699730704 parseAndProcess RequestID=900 20170915 ocapri_log.txt:Oct 24 10:31:13.902899 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.901545 [mod=REC, lvl=INFO] [tid=3494] spaceMarkedForFreeing : Calculating space occupied by recordings that are marked for deletion ocapri_log.txt:Oct 24 10:31:13.903345 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.902014 [mod=REC, lvl=INFO] [tid=3495] [Config::getFileSystemExt3Config] end fileSystemExt3 = [1] fileSystemExt3ConfigRead = [1] ocapri_log.txt:Oct 24 10:31:13.903783 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.902453 [mod=REC, lvl=INFO] [tid=3493] parseAndProcess RequestID=900 ocapri_log.txt:Oct 24 10:31:13.904254 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.902910 [mod=REC, lvl=INFO] [tid=3494] [Monitor::calculateSpaceMarkedForFreeing] Checking for recordings to delete at level P0 20170915 ocapri_log.txt:Oct 24 10:31:13.904701 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.903353 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::checkVolume] checkVolume - Ext3 file system ocapri_log.txt:Oct 24 10:31:13.905144 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.903823 [mod=REC, lvl=INFO] [tid=3493] generationId=0 Length=1 ocapri_log.txt:Oct 24 10:31:13.905706 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.904268 [mod=REC, lvl=INFO] [tid=3494] [RecordingDb::dvr_recordings_at_level] Getting recordings updated in request level= [0] 20170915 ocapri_log.txt:Oct 24 10:31:13.906154 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.904708 [mod=REC, lvl=INFO] [tid=3495] checkVolume - Ext3 file system ocapri_log.txt:Oct 24 10:31:13.906598 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.905715 [mod=REC, lvl=INFO] [tid=3494] function = dvr_recordings_at_level: 0 ocapri_log.txt:Oct 24 10:31:13.907055 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.906169 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::checkVolume] 455646108672 freeSpace 10000000000 tsbReserve ocapri_log.txt:Oct 24 10:31:13.907494 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.906618 [mod=REC, lvl=INFO] [tid=3494] [Monitor::calculateSpaceMarkedForFreeing]spaceMarkedForFreeing : No recordings at Delete Priority 0 20170915 ocapri_log.txt:Oct 24 10:31:13.907958 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.907064 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::run][run] Free space 455646108672 available; Notify Recorder 20170915 ocapri_log.txt:Oct 24 10:31:13.908403 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.907502 [mod=REC, lvl=INFO] [tid=3494] spaceMarkedForFreeing : No recordings at Delete Priority 0 ocapri_log.txt:Oct 24 10:31:13.909191 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.907970 [mod=REC, lvl=INFO] [tid=3495] [run] Free space 455646108672 available; Notify Recorder ocapri_log.txt:Oct 24 10:31:13.909632 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.908418 [mod=REC, lvl=INFO] [tid=3494] [Monitor::calculateSpaceMarkedForFreeing] Checking for recordings to delete at level P1 20170915 ocapri_log.txt:Oct 24 10:31:13.910089 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.909144 [mod=REC, lvl=WARN] [tid=3493] Could not retrieve dvr protocol version from object ocapri_log.txt:Oct 24 10:31:13.910529 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.909201 [mod=REC, lvl=INFO] [tid=3495] Free space available; attempt resuming recordings ocapri_log.txt:Oct 24 10:31:13.910974 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.909643 [mod=REC, lvl=INFO] [tid=3494] [RecordingDb::dvr_recordings_at_level] Getting recordings updated in request level= [1] 20170915 ocapri_log.txt:Oct 24 10:31:13.911418 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.910097 [mod=REC, lvl=INFO] [tid=3493] [Communicator::parseAndProcess] parseAndProcess : Invalid format for DVR protocol version , discarding and reusing previous protocol version 20170915 ocapri_log.txt:Oct 24 10:31:13.911869 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.910536 [mod=REC, lvl=INFO] [tid=3495] [Recording::disk_space_handle_event] Free space available; attempt resuming recordings 20170915 ocapri_log.txt:Oct 24 10:31:13.912311 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.910982 [mod=REC, lvl=INFO] [tid=3494] function = dvr_recordings_at_level: 1 ocapri_log.txt:Oct 24 10:31:13.912781 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.911426 [mod=REC, lvl=WARN] [tid=3493] parseAndProcess : Invalid format for DVR protocol version , discarding and reusing previous protocol version ocapri_log.txt:Oct 24 10:31:13.913230 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.911879 [mod=REC, lvl=INFO] [tid=3495] function = getSuspendedRecordings ocapri_log.txt:Oct 24 10:31:13.913668 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.912320 [mod=REC, lvl=INFO] [tid=3494] [Monitor::calculateSpaceMarkedForFreeing]spaceMarkedForFreeing : No recordings at Delete Priority 1 20170915 ocapri_log.txt:Oct 24 10:31:13.914130 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.912789 [mod=REC, lvl=INFO] [tid=3493] [Communicator::parseAndProcess] before performUpdateSchedule 20170915 ocapri_log.txt:Oct 24 10:31:13.914598 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.913676 [mod=REC, lvl=INFO] [tid=3494] spaceMarkedForFreeing : No recordings at Delete Priority 1 ocapri_log.txt:Oct 24 10:31:13.915050 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.914167 [mod=REC, lvl=INFO] [tid=3493] Communicator::performUpdateSchedule performUpdateSchedule :Performing schedule update: Request ID: 900 ::Schedule {"requestId": "900", "schedule": [{"properties": {"title": "97so happy"}, "deletePriority": "P3", "bitRate": "HIGH_BIT_RATE", "recordingId": 2017102416, "duration": 360000, "start": 1508835550955, "locator": ["ocap://0x2"], "ppv": false, "entitlementId": 0}], "generationId": "0", "fullSchedule": true} 20170915 ocapri_log.txt:Oct 24 10:31:13.915494 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.914610 [mod=REC, lvl=INFO] [tid=3494] [Monitor::calculateSpaceMarkedForFreeing] Checking for recordings to delete at level P2 20170915 ocapri_log.txt:Oct 24 10:31:13.915951 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.915059 [mod=REC, lvl=INFO] [tid=3493] performUpdateSchedule :Performing schedule update: Request ID: 900 ::Schedule {"requestId": "900", "schedule": [{"properties": {"title": "97so happy"}, "deletePriority": "P3", "bitRate": "HIGH_BIT_RATE", "recordingId": 2017102416, "duration": 360000, "start": 1508835550955, "locator": ["ocap://0x2"], "ppv": false, "entitlementId": 0}], "generationId": "0", "fullSchedule": true} ocapri_log.txt:Oct 24 10:31:13.916617 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.915505 [mod=REC, lvl=INFO] [tid=3494] [RecordingDb::dvr_recordings_at_level] Getting recordings updated in request level= [2] 20170915 ocapri_log.txt:Oct 24 10:31:13.917116 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.915960 [mod=REC, lvl=INFO] [tid=3493] fullSchedule present and is true ocapri_log.txt:Oct 24 10:31:13.917617 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.916627 [mod=REC, lvl=INFO] [tid=3494] function = dvr_recordings_at_level: 2 ocapri_log.txt:Oct 24 10:31:13.918063 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.917182 [mod=REC, lvl=INFO] [tid=3493] [Communicator::performUpdateSchedule] Performing schedule update: sched_array: [{"properties": {"title": "97so happy"}, "deletePriority": "P3", "bitRate": "HIGH_BIT_RATE", "recordingId": 2017102416, "duration": 360000, "start": 1508835550955, "locator": ["ocap://0x2"], "ppv": false, "entitlementId": 0}], count :: 1 20170915 ocapri_log.txt:Oct 24 10:31:13.918578 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.917627 [mod=REC, lvl=INFO] [tid=3494] [Monitor::calculateSpaceMarkedForFreeing]spaceMarkedForFreeing : No recordings at Delete Priority 2 20170915 ocapri_log.txt:Oct 24 10:31:13.919021 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.918090 [mod=REC, lvl=INFO] [tid=3493] 'dvr_update_recording' [Recording::dvr_update_recording] begin 20170915 ocapri_log.txt:Oct 24 10:31:13.919473 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.918586 [mod=REC, lvl=INFO] [tid=3494] spaceMarkedForFreeing : No recordings at Delete Priority 2 ocapri_log.txt:Oct 24 10:31:13.919940 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.919036 [mod=REC, lvl=INFO] [tid=3493] updateRecording : [RecordingDb::updateRecording] 20170915 ocapri_log.txt:Oct 24 10:31:13.920380 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.919485 [mod=REC, lvl=INFO] [tid=3494] [Monitor::calculateSpaceMarkedForFreeing] Checking for recordings to delete at level P3 20170915 ocapri_log.txt:Oct 24 10:31:13.920831 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.919949 [mod=REC, lvl=INFO] [tid=3493] [RecordingDb::updateRecording]updateRecording: recid str is NULL 20170915 ocapri_log.txt:Oct 24 10:31:13.921311 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.920391 [mod=REC, lvl=INFO] [tid=3494] [RecordingDb::dvr_recordings_at_level] Getting recordings updated in request level= [3] 20170915 ocapri_log.txt:Oct 24 10:31:13.921757 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.920877 [mod=REC, lvl=INFO] [tid=3493] [RecordingDb::updateRecording] Updating recording 2017102416 function = updateRecording 20170915 ocapri_log.txt:Oct 24 10:31:13.922205 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.921319 [mod=REC, lvl=INFO] [tid=3494] function = dvr_recordings_at_level: 3 ocapri_log.txt:Oct 24 10:31:13.922651 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.921768 [mod=REC, lvl=INFO] [tid=3493] function = updateRecording ocapri_log.txt:Oct 24 10:31:13.923106 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.922219 [mod=REC, lvl=INFO] [tid=3494] Found 0 bytes that can be freed. ocapri_log.txt:Oct 24 10:31:13.923549 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.922667 [mod=REC, lvl=INFO] [tid=3493] [RecordingDb::updateRecording]Updating old value for the recording '2017102416' 20170915 ocapri_log.txt:Oct 24 10:31:13.924012 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.923117 [mod=REC, lvl=INFO] [tid=3494] getAvailableDiskSpace::free disk space = 455646108672 bytes ocapri_log.txt:Oct 24 10:31:13.924452 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.923568 [mod=REC, lvl=INFO] [tid=3493] [dvr_recording_from_json] recIdStr = [(null)] 20170915 ocapri_log.txt:Oct 24 10:31:13.924909 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.924021 [mod=REC, lvl=INFO] [tid=3494] [Monitor::getAvailableDiskSpace] getAvailableDiskSpace::free disk space = 455646108672 bytes 20170915 ocapri_log.txt:Oct 24 10:31:13.925350 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.924468 [mod=REC, lvl=INFO] [tid=3493] dvr_recording_from_json : deviceId = [(null)] ocapri_log.txt:Oct 24 10:31:13.925791 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.924917 [mod=REC, lvl=INFO] [tid=3494] getAvailableDiskSpace::purge threshold = 12000000000 bytes ocapri_log.txt:Oct 24 10:31:13.926245 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.925358 [mod=REC, lvl=INFO] [tid=3493] [dvr_recording_from_json] dvr_recording_from_json : deviceId = [(null)] 20170915 ocapri_log.txt:Oct 24 10:31:13.926741 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.925809 [mod=REC, lvl=INFO] [tid=3494] [Monitor::evaluateAvailableSpaceImpl] [32] = Sufficient free disk space available 20170915 ocapri_log.txt:Oct 24 10:31:13.927185 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.926275 [mod=REC, lvl=INFO] [tid=3493] [dvr_recording_from_json] : startPadding = [0] endPadding = [0] 20170915 ocapri_log.txt:Oct 24 10:31:13.927624 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.926749 [mod=REC, lvl=INFO] [tid=3494] evaluateAvailableSpaceImpl: Sufficient free disk space available; not purging. ocapri_log.txt:Oct 24 10:31:13.928074 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.927193 [mod=REC, lvl=INFO] [tid=3493] dvr_recording_from_json : startPadding = [0] endPadding = [0] ocapri_log.txt:Oct 24 10:31:13.928520 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.927631 [mod=REC, lvl=INFO] [tid=3494] [Monitor::evaluateAvailableSpaceImpl] evaluateAvailableSpaceImpl: Sufficient free disk space available; not purging. 20170915 ocapri_log.txt:Oct 24 10:31:13.928967 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.928089 [mod=REC, lvl=INFO] [tid=3493] [dvr_recording_from_json] j_properties is a json object and requestedStart=0!! 20170915 ocapri_log.txt:Oct 24 10:31:13.929407 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.928975 [mod=REC, lvl=INFO] [tid=3493] j_properties is a json object and requestedStart=0!! ocapri_log.txt:Oct 24 10:31:13.929854 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.929415 [mod=REC, lvl=INFO] [tid=3493] [dvr_recording_from_json] j_properties is a json object and name=97so happy 20170915 ocapri_log.txt:Oct 24 10:31:13.930295 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.929862 [mod=REC, lvl=INFO] [tid=3493] j_properties is a json object and name=97so happy ocapri_log.txt:Oct 24 10:31:13.930738 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.930308 [mod=REC, lvl=INFO] [tid=3493] [dvr_recording_from_json] :padding startPadding = [0] endPadding = [0] 20170915 ocapri_log.txt:Oct 24 10:31:13.931183 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.930747 [mod=REC, lvl=INFO] [tid=3493] dvr_recording_from_json :padding startPadding = [0] endPadding = [0] ocapri_log.txt:Oct 24 10:31:13.931623 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.931191 [mod=REC, lvl=INFO] [tid=3493] Recording '2017102416' : dvr_recording_from_json : Recording Name : [{"title":"97so happy"}] ocapri_log.txt:Oct 24 10:31:13.932070 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.931631 [mod=REC, lvl=INFO] [tid=3493] [dvr_recording_from_json] Recording '2017102416' : dvr_recording_from_json : Recording Name : [{"title":"97so happy"}] 20170915 ocapri_log.txt:Oct 24 10:31:13.932531 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.932092 [mod=REC, lvl=INFO] [tid=3493] [dvr_recording_from_json] Created recording ID: '2017102416' State: PendingNoConflict Start: 1508835550955 Duration: 360000 Locators: 1 20170915 ocapri_log.txt:Oct 24 10:31:13.932988 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.932543 [mod=REC, lvl=INFO] [tid=3493] [dvr_recording_from_json] changing from state PendingNoConflict to PendingNoConflict [ADDED] 20170915 ocapri_log.txt:Oct 24 10:31:13.933428 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.932996 [mod=REC, lvl=INFO] [tid=3493] changing from state PendingNoConflict to PendingNoConflict [ADDED] ocapri_log.txt:Oct 24 10:31:13.933874 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.933438 [mod=REC, lvl=INFO] [tid=3493] [update_recording] State when updating from XRE: PendingNoConflict, state from DVRManger: Complete 20170915 ocapri_log.txt:Oct 24 10:31:13.934315 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.933882 [mod=REC, lvl=INFO] [tid=3493] State when updating from XRE: PendingNoConflict, state from DVRManger: Complete ocapri_log.txt:Oct 24 10:31:13.934758 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.934326 [mod=REC, lvl=INFO] [tid=3493] 'dvr_update_recording' : updateRecording returned, changed = 0, returning ocapri_log.txt:Oct 24 10:31:13.935212 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.934766 [mod=REC, lvl=INFO] [tid=3493] [Recording::dvr_update_recording]'dvr_update_recording' : updateRecording returned, changed = 0, returning 20170915 ocapri_log.txt:Oct 24 10:31:13.935651 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.935220 [mod=REC, lvl=INFO] [tid=3493] [Communicator::performUpdateSchedule] FullSchedule is true :: Applying implicit delete - Legacy behaviour 20170915 ocapri_log.txt:Oct 24 10:31:13.936150 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.935659 [mod=REC, lvl=INFO] [tid=3493] FullSchedule is true :: Applying implicit delete - Legacy behaviour ocapri_log.txt:Oct 24 10:31:13.936598 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.936161 [mod=REC, lvl=INFO] [tid=3493] function = dvr_deleted_pending_recordings ocapri_log.txt:Oct 24 10:31:13.937045 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.936609 [mod=REC, lvl=INFO] [tid=3493] [RecordingDb::dvr_deleted_pending_recordings] Getting deleted pending recordings 20170915 ocapri_log.txt:Oct 24 10:31:13.937486 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.937056 [mod=REC, lvl=INFO] [tid=3493] [get_deleted_pending_recordings] get_deleted_recordings: 0x7255c 0x9ab03600 0x9a9bea88: '2017102414' 0 0 :10 20170915 ocapri_log.txt:Oct 24 10:31:13.937937 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.937500 [mod=REC, lvl=INFO] [tid=3493] [get_deleted_pending_recordings] get_deleted_recordings: 0x13699c 0x9ab03800 0x9a9bea88: '2017102416' 1 0 :10 20170915 ocapri_log.txt:Oct 24 10:31:13.938390 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.937955 [mod=REC, lvl=INFO] [tid=3493] function = dvr_stopped_active_recordings ocapri_log.txt:Oct 24 10:31:13.938840 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.938400 [mod=REC, lvl=INFO] [tid=3493] [Communicator::parseAndProcess] after performUpdateSchedule change =[0]20170915 ocapri_log.txt:Oct 24 10:31:13.939284 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.938851 [mod=REC, lvl=INFO] [tid=3493] function = clearSeenState ocapri_log.txt:Oct 24 10:31:13.939726 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.939295 [mod=REC, lvl=INFO] [tid=3493] Schedule::getInstance [getInstance] [124] 20170915 ocapri_log.txt:Oct 24 10:31:13.940173 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.939737 [mod=REC, lvl=INFO] [tid=3493] [Schedule::scheduler_update] Sending event 0x1 to scheduler 20170915 ocapri_log.txt:Oct 24 10:31:13.940624 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.940190 [mod=REC, lvl=INFO] [tid=3493] [Schedule::scheduler_update] g_async_queue_push 0x1 to scheduler 20170915 ocapri_log.txt:Oct 24 10:31:13.941069 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.940206 [mod=REC, lvl=INFO] [tid=3490] [Schedule::run] 3 timeout=[0] Back from waiting. Got event: 0x1 20170915 ocapri_log.txt:Oct 24 10:31:13.941476 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.940631 [mod=REC, lvl=INFO] [tid=3493] [Communicator::parseAndProcess] uncomment getInstance(NULL, NULL)->scheduler_update( 20170915 ocapri_log.txt:Oct 24 10:31:13.941927 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.941077 [mod=REC, lvl=INFO] [tid=3490] Back from waiting. Got event: 0x1 ocapri_log.txt:Oct 24 10:31:13.942335 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.941484 [mod=REC, lvl=INFO] [tid=3493] [Communicator::parseAndProcess] uncomment *get_recordings = json_object_get(envelope, XRE_GET_RECORDINGS 20170915 ocapri_log.txt:Oct 24 10:31:13.942776 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.941936 [mod=REC, lvl=INFO] [tid=3490] [Schedule::run] 1 event->time[] now=[] 20170915 ocapri_log.txt:Oct 24 10:31:13.943187 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.942345 [mod=REC, lvl=INFO] [tid=3493] [Communicator::commit] 20170915 ocapri_log.txt:Oct 24 10:31:13.943695 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.942787 [mod=REC, lvl=INFO] [tid=3490] [Schedule::run] Waiting without timeout 20170915 ocapri_log.txt:Oct 24 10:31:13.944143 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.943265 [mod=REC, lvl=INFO] [tid=3493] [RecordingDb::dvr_future_recordings] function = dvr_future_recordings 20170915 ocapri_log.txt:Oct 24 10:31:13.944584 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.944151 [mod=REC, lvl=INFO] [tid=3493] function = dvr_future_recordings ocapri_log.txt:Oct 24 10:31:13.945030 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.944593 [mod=REC, lvl=INFO] [tid=3493] [RecordingDb::checksum] Generating hash for recordings 20170915 ocapri_log.txt:Oct 24 10:31:13.945478 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.945043 [mod=REC, lvl=INFO] [tid=3493] [RecordingDb::checksum] Generated hash for future recordings - 20170915 ocapri_log.txt:Oct 24 10:31:13.949739 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.949718 [mod=REC, lvl=INFO] [tid=3493] [Communicator::commit]Next commit scheduled after 43200 seconds 20170915 ocapri_log.txt:Oct 24 10:31:13.949781 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.949764 [mod=REC, lvl=INFO] [tid=3493] [Communicator::processScheduleData] after parseAndProcess(p->data_url 20170915 ocapri_log.txt:Oct 24 10:31:13.949805 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.949778 [mod=REC, lvl=INFO] [tid=3492] [Communicator::runRehasher] after g_async_queue_pop(rehash_queue) 20170915 ocapri_log.txt:Oct 24 10:31:13.949859 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.949843 [mod=REC, lvl=INFO] [tid=3492] [Communicator::runRehasher] Waiting for 43200 seconds 20170915 ocapri_log.txt:Oct 24 10:31:13.949884 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.949869 [mod=REC, lvl=INFO] [tid=3492] runRehasher : Waiting for 43200 seconds ocapri_log.txt:Oct 24 10:31:13.949893 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.949876 [mod=REC, lvl=INFO] [tid=3493] [Communicator::processScheduleData] Free request=0xb6ee3611 20170915 ocapri_log.txt:Oct 24 10:31:13.949915 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.949900 [mod=REC, lvl=INFO] [tid=3493] processScheduleData Free request=0x9ab1b108 ocapri_log.txt:Oct 24 10:31:13.949939 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:31:13.949924 [mod=REC, lvl=INFO] [tid=3493] [Communicator::processScheduleData] before g_async_queue_pop(m_scheduleQueue) 20170915 ocapri_log.txt:Oct 24 10:33:44.577000 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:44.576960 [mod=MS, lvl=INFO] [tid=2820] [query_variable_cb:1108] DLNA query_variable_cb Got a call back 20170915 variable=[SystemUpdateID] ocapri_log.txt:Oct 24 10:33:44.577062 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:44.577045 [mod=MS, lvl=INFO] [tid=2820] [query_variable_cb:1108] DLNA query_variable_cb Got a call back 20170915 variable=[SearchCapabilities] ocapri_log.txt:Oct 24 10:33:48.901215 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:48.901172 [mod=MS, lvl=INFO] [tid=2820] [on_Browse:735] DLNA on_Browse Got a call back 20170915 ocapri_log.txt:Oct 24 10:33:48.901283 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:48.901267 [mod=MS, lvl=INFO] [tid=2820] DLNA [on_Browse:796] Enter 20170915 ocapri_log.txt:Oct 24 10:33:48.901335 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:48.901319 [mod=MS, lvl=INFO] [tid=2820] DLNA on_Browse ObjectID = 0 20170915 ocapri_log.txt:Oct 24 10:33:48.901361 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:48.901346 [mod=MS, lvl=INFO] [tid=2820] DLNA on_Browse BrowseFlag = BrowseDirectChildren 20170915 ocapri_log.txt:Oct 24 10:33:48.901458 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:48.901442 [mod=MS, lvl=INFO] [tid=2820] DLNA on_Browse StartingIndex = 0 20170915 ocapri_log.txt:Oct 24 10:33:48.901484 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:48.901469 [mod=MS, lvl=INFO] [tid=2820] DLNA on_Browse RequestedCount = 200 20170915 ocapri_log.txt:Oct 24 10:33:48.901508 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:48.901494 [mod=MS, lvl=INFO] [tid=2820] DLNA on_Browse SortCriteria = 20170915 ocapri_log.txt:Oct 24 10:33:49.676096 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.676053 [mod=MS, lvl=INFO] [tid=2820] [on_Browse:735] DLNA on_Browse Got a call back 20170915 ocapri_log.txt:Oct 24 10:33:49.676142 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.676126 [mod=MS, lvl=INFO] [tid=2820] DLNA [on_Browse:796] Enter 20170915 ocapri_log.txt:Oct 24 10:33:49.676172 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.676157 [mod=MS, lvl=INFO] [tid=2820] DLNA on_Browse ObjectID = 1 20170915 ocapri_log.txt:Oct 24 10:33:49.676197 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.676183 [mod=MS, lvl=INFO] [tid=2820] DLNA on_Browse BrowseFlag = BrowseDirectChildren 20170915 ocapri_log.txt:Oct 24 10:33:49.676264 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.676249 [mod=MS, lvl=INFO] [tid=2820] DLNA on_Browse StartingIndex = 0 20170915 ocapri_log.txt:Oct 24 10:33:49.676289 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.676274 [mod=MS, lvl=INFO] [tid=2820] DLNA on_Browse RequestedCount = 200 20170915 ocapri_log.txt:Oct 24 10:33:49.676313 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.676299 [mod=MS, lvl=INFO] [tid=2820] DLNA on_Browse SortCriteria = 20170915 ocapri_log.txt:Oct 24 10:33:49.676356 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.676341 [mod=MS, lvl=INFO] [tid=2820] [on_Browse:832] DLNA on_Browse count =[2] 20170915 ocapri_log.txt:Oct 24 10:33:49.676392 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.676377 [mod=MS, lvl=INFO] [tid=2820] DLNA Recording state: 7 title: 95so happy priority: P3 20170915 ocapri_log.txt:Oct 24 10:33:49.676415 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.676400 [mod=MS, lvl=INFO] [tid=2820] DLNA url=[http://192.168.100.101:8081/vldms/dvr?rec_id=2017102414&segmentId=0] 20170915 ocapri_log.txt:Oct 24 10:33:49.676435 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.676420 [mod=MS, lvl=INFO] [tid=2820] DLNA recording 0 id 2017102414 title "95so happy" 20170915 ocapri_log.txt:Oct 24 10:33:49.681494 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.676442 [mod=MS, lvl=INFO] [tid=2820] DLNA url=[http://192.168.100.101:8081/vldms/dvr?rec_id=2017102414&segmentId=0] 20170915 ocapri_log.txt:Oct 24 10:33:49.681629 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.681610 [mod=MS, lvl=INFO] [tid=2820] DLNA [on_Browse:935] Protocol Info 10000000 20170915 ocapri_log.txt:Oct 24 10:33:49.681672 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.681656 [mod=MS, lvl=INFO] [tid=2820] DLNA [on_Browse:954] Primary flag: 10000000 20170915 ocapri_log.txt:Oct 24 10:33:49.682335 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.682316 [mod=MS, lvl=INFO] [tid=2820] DLNA [on_Browse:988] Protocol Info http-get:*:video/vnd.dlna.mpeg-tts:DLNA.ORG_PN=MPEG_TS_HD_NA_T;DLNA.ORG_OP=10;DLNA.ORG_PS=-60,-30,-15,15,30,60;DLNA.ORG_FLAGS=01000000000000000000000000000000 20170915 ocapri_log.txt:Oct 24 10:33:49.682360 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.682345 [mod=MS, lvl=INFO] [tid=2820] DLNA Recording state: 7 title: 97so happy priority: P3 20170915 ocapri_log.txt:Oct 24 10:33:49.682383 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.682369 [mod=MS, lvl=INFO] [tid=2820] DLNA url=[http://192.168.100.101:8081/vldms/dvr?rec_id=2017102416&segmentId=0] 20170915 ocapri_log.txt:Oct 24 10:33:49.682402 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.682388 [mod=MS, lvl=INFO] [tid=2820] DLNA recording 1 id 2017102416 title "97so happy" 20170915 ocapri_log.txt:Oct 24 10:33:49.682424 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.682410 [mod=MS, lvl=INFO] [tid=2820] DLNA url=[http://192.168.100.101:8081/vldms/dvr?rec_id=2017102416&segmentId=0] 20170915 ocapri_log.txt:Oct 24 10:33:49.682450 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.682436 [mod=MS, lvl=INFO] [tid=2820] DLNA [on_Browse:935] Protocol Info 10000000 20170915 ocapri_log.txt:Oct 24 10:33:49.682475 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.682460 [mod=MS, lvl=INFO] [tid=2820] DLNA [on_Browse:954] Primary flag: 10000000 20170915 ocapri_log.txt:Oct 24 10:33:49.682708 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:33:49.682691 [mod=MS, lvl=INFO] [tid=2820] DLNA [on_Browse:988] Protocol Info http-get:*:video/vnd.dlna.mpeg-tts:DLNA.ORG_PN=MPEG_TS_HD_NA_T;DLNA.ORG_OP=10;DLNA.ORG_PS=-60,-30,-15,15,30,60;DLNA.ORG_FLAGS=01000000000000000000000000000000 20170915 ocapri_log.txt:Oct 24 10:34:20.040463 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:20.040413 [mod=REC, lvl=INFO] [tid=3495] DiskSpaceMonitor: SpaceChecker :- Going to check diskspace ocapri_log.txt:Oct 24 10:34:20.040546 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:20.040525 [mod=REC, lvl=INFO] [tid=3495] [Config::getDefaultVolume] mountTablet=/proc/mounts 20170915 ocapri_log.txt:Oct 24 10:34:20.040776 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:20.040758 [mod=REC, lvl=INFO] [tid=3495] /dev/sda1 on /tmp/usb type ext3 (rw,relatime,data=ordered) ocapri_log.txt:Oct 24 10:34:20.040798 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:20.040783 [mod=REC, lvl=INFO] [tid=3495] [Config::getDefaultVolume] if (mountTable)/dev/sda1 on /tmp/usb type ext3 (rw,relatime,data=ordered) 20170915 ocapri_log.txt:Oct 24 10:34:20.040837 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:20.040821 [mod=REC, lvl=INFO] [tid=3495] [Config::getFileSystemExt3Config] end fileSystemExt3 = [1] fileSystemExt3ConfigRead = [1] ocapri_log.txt:Oct 24 10:34:20.040859 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:20.040844 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::checkVolume] checkVolume - Ext3 file system ocapri_log.txt:Oct 24 10:34:20.040879 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:20.040865 [mod=REC, lvl=INFO] [tid=3495] checkVolume - Ext3 file system ocapri_log.txt:Oct 24 10:34:20.040925 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:20.040909 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::checkVolume] 455646108672 freeSpace 10000000000 tsbReserve ocapri_log.txt:Oct 24 10:34:20.040947 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:20.040933 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::run][run] Free space 455646108672 available; Notify Recorder 20170915 ocapri_log.txt:Oct 24 10:34:37.165310 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.165265 [mod=MS, lvl=INFO] [tid=6488] [HTTPServer::httpServerDmsHandler][httpServerDmsHandler:241] begin 20170915 ocapri_log.txt:Oct 24 10:34:37.165657 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.165635 [mod=MS, lvl=INFO] [tid=6488] [httpServerDmsHandler:297] Client requested URI: '/vldms/dvr?rec_id=2017102416&segmentId=0' ocapri_log.txt:Oct 24 10:34:37.165685 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.165670 [mod=MS, lvl=INFO] [tid=6488] [HTTPServer::httpServerDmsHandler][httpServerDmsHandler:348] before true == isDLNARequest(pRequest) 20170915 ocapri_log.txt:Oct 24 10:34:37.165705 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.165691 [mod=MS, lvl=INFO] [tid=6488] [HTTPServer::isDLNARequest][isDLNARequest:189] begin 20170915 ocapri_log.txt:Oct 24 10:34:37.165731 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.165716 [mod=MS, lvl=INFO] [tid=6488] [HTTPServer::isDLNARequest][isDLNARequest:233] end 20170915 ocapri_log.txt:Oct 24 10:34:37.166056 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.166032 [mod=MS, lvl=NOTICE] [tid=6488] [parseUrl:544] DVR request received from 192.168.100.100 20170915 ocapri_log.txt:Oct 24 10:34:37.166078 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.166063 [mod=MS, lvl=NOTICE] [tid=6488] [parseUrl:546] DVR request received from 192.168.100.100 ocapri_log.txt:Oct 24 10:34:37.166385 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.166368 [mod=MS, lvl=INFO] [tid=6488] dvr://local/2017102416#0 Duration: 297 Size: 764151168 PTS: b210ce70 b2dcebcf ocapri_log.txt:Oct 24 10:34:37.166585 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.166568 [mod=MS, lvl=INFO] [tid=6488] [HTTPServer::httpServerDmsHandler][httpServerDmsHandler:368] aftere msgHandler->sendResponse 20170915 ocapri_log.txt:Oct 24 10:34:37.166614 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.166599 [mod=MS, lvl=NOTICE] [tid=6488] [locator: dvr://local/2017102416#0] [1.000000 0.000000] [IP: 192.168.100.100] [TSB: FALSE] [continueTSB: TRUE] ocapri_log.txt:Oct 24 10:34:37.166637 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.166622 [mod=MS, lvl=NOTICE] [tid=6488] [MsgHandler::showRequest][locator: dvr://local/2017102416#0] [1.000000 0.000000] [IP: 192.168.100.100] [TSB: FALSE] 20170915 ocapri_log.txt:Oct 24 10:34:37.166674 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.166659 [mod=MS, lvl=INFO] [tid=6488] [httpStreamingHandler:2033] Received service selection message for service: DVR_SRC play speed: 1.0 time position: 0.000000 source id: dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:37.166694 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.166680 [mod=MS, lvl=INFO] [tid=6488] [httpStreamingHandler:2036] Number of request received: 1 Active sessions now 1 ocapri_log.txt:Oct 24 10:34:37.166750 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.166732 [mod=MS, lvl=INFO] [tid=6488] [serviceSelection:1701] Processing service selection for: DVR_SRC play speed: 1.0 time position: 0.000000 source id: dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:37.166996 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.166979 [mod=MS, lvl=INFO] [tid=6488] [open:434] Transcoder support : FALSE ocapri_log.txt:Oct 24 10:34:37.167214 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.167002 [mod=MS, lvl=INFO] [tid=6488] [open:437] Now tuning to service dvr://local/2017102416#0 tsb_support=FALSE ocapri_log.txt:Oct 24 10:34:37.167617 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.167224 [mod=MS, lvl=INFO] [tid=6488] [createSource:317] RMFMediaStreamer::createSource dvr://local/2017102416#0 20170915 ocapri_log.txt:Oct 24 10:34:37.168036 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.167639 [mod=DVR, lvl=INFO] [tid=6488] DVRSource::DVRSource() [SOURCE] DVRSource constructor= 0x9ab1f248 ocapri_log.txt:Oct 24 10:34:37.168446 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.168043 [mod=MS, lvl=INFO] [tid=6488] RMFMediaStreamer::createSource() [SOURCE] DVRSource created pSource= 0x9ab1f248 for locator= dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:37.168851 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.168474 [mod=RMFBASE, lvl=INFO] [tid=6488] RMFInit:124 - Enter. ocapri_log.txt:Oct 24 10:34:37.169656 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.169635 [mod=RMFBASE, lvl=INFO] [tid=6488] init bus=0xee548 m_bus_event_source_id=130 ocapri_log.txt:Oct 24 10:34:37.169768 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.169687 [mod=RMFBASE, lvl=INFO] [tid=6488] RMFMediaSourcePrivate::addEventHandler :: 9ab1b6e8 :: Size : 1 ocapri_log.txt:Oct 24 10:34:37.170187 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.169777 [mod=DVR, lvl=INFO] [tid=6488] DVRSourcePrivate::open: uri(dvr://local/2017102416#0) ocapri_log.txt:Oct 24 10:34:37.170592 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.170209 [mod=DVR, lvl=INFO] [tid=6488] DVRSourcePrivate::open: setting gst tee element properties for device mem alloc/free ocapri_log.txt:Oct 24 10:34:37.171011 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.170797 [mod=DVR, lvl=INFO] [tid=6488] DVRSourcePrivate::open: get recordingId 2017102416 and segmentNumber 0 segmentName 1508835613284 from uri ocapri_log.txt:Oct 24 10:34:37.180977 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.180941 [mod=RMFBASE, lvl=INFO] [tid=6488] RMFInit:124 - Enter. ocapri_log.txt:Oct 24 10:34:37.182856 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.182827 [mod=RMFBASE, lvl=INFO] [tid=6488] RMFMediaSinkPrivate::addEventHandler :: 9ab1c0b0 :: size 1 ocapri_log.txt:Oct 24 10:34:37.182912 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.182880 [mod=HN, lvl=INFO] [tid=6489] streamStatusThread Begin ocapri_log.txt:Oct 24 10:34:37.182913 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.182896 [mod=MS, lvl=INFO] [tid=6488] [RMFMediaStreamer::open][open:624] Source and Sink created 20170915 ocapri_log.txt:Oct 24 10:34:37.182933 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.182918 [mod=MS, lvl=NOTICE] [tid=6488] [open:626] Source and Sink created ocapri_log.txt:Oct 24 10:34:37.182967 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.182952 [mod=MS, lvl=INFO] [tid=6488] [RMFMediaStreamer::stream][stream:734] Play Speed : 1.000000 Time Position: 0.000000 20170915 ocapri_log.txt:Oct 24 10:34:37.182989 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.182975 [mod=MS, lvl=INFO] [tid=6488] [stream:736] Play Speed : 1.000000 Time Position: 0.000000 ocapri_log.txt:Oct 24 10:34:37.183008 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.182994 [mod=MS, lvl=INFO] [tid=6488] [stream:755] play_request ocapri_log.txt:Oct 24 10:34:37.183045 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.183030 [mod=RMFBASE, lvl=INFO] [tid=6488] RMFMediaSinkPrivate::setSource :: Calling addSink ocapri_log.txt:Oct 24 10:34:37.183430 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.183412 [mod=RMFBASE, lvl=INFO] [tid=6488] QueueSize=10 QueueType=non-leaky ocapri_log.txt:Oct 24 10:34:37.183450 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.183435 [mod=RMFBASE, lvl=INFO] [tid=6488] m_pipeline=0x14d658 queue=0x9ab36170 ocapri_log.txt:Oct 24 10:34:37.183509 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.183493 [mod=RMFBASE, lvl=INFO] [tid=6488] m_pipeline=0x14d658 sink=0x14f6c0 ocapri_log.txt:Oct 24 10:34:37.184053 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.184034 [mod=RMFBASE, lvl=INFO] [tid=6488] RMFMediaSinkPrivate::setSource :: Out of addSink ocapri_log.txt:Oct 24 10:34:37.184081 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.184066 [mod=MS, lvl=INFO] [tid=6488] [stream:852] setting playback rate to 1.0 ocapri_log.txt:Oct 24 10:34:37.184128 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.184113 [mod=RMFBASE, lvl=INFO] [tid=6488] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:37.185264 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.184207 [mod=HN, lvl=INFO] [tid=6488] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from NULL to READY ocapri_log.txt:Oct 24 10:34:37.185747 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.185415 [mod=DVR, lvl=INFO] [tid=6488] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 10 ocapri_log.txt:Oct 24 10:34:37.186182 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.185763 [mod=DVR, lvl=INFO] [tid=6488] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 10 calling parent ocapri_log.txt:Oct 24 10:34:37.186591 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.186200 [mod=DVR, lvl=INFO] [tid=6488] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 10 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:37.187020 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.186606 [mod=DVR, lvl=INFO] [tid=6488] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 10 ret 1 ocapri_log.txt:Oct 24 10:34:37.187427 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.187090 [mod=RMFBASE, lvl=ERROR] [tid=6488] Changed state to READY ocapri_log.txt:Oct 24 10:34:37.187833 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.187104 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to READY state ocapri_log.txt:Oct 24 10:34:37.188245 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.187595 [mod=RMFBASE, lvl=INFO] [tid=6488] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(PLAYING) ocapri_log.txt:Oct 24 10:34:37.188652 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.188336 [mod=HN, lvl=INFO] [tid=6488] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from READY to PAUSED ocapri_log.txt:Oct 24 10:34:37.189073 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.189006 [mod=DVR, lvl=INFO] [tid=6488] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 19 ocapri_log.txt:Oct 24 10:34:37.189483 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.189087 [mod=DVR, lvl=INFO] [tid=6488] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 19 calling parent ocapri_log.txt:Oct 24 10:34:37.189909 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.189575 [mod=DVR, lvl=INFO] [tid=6488] PlayContext using soc buffer allocator ocapri_log.txt:Oct 24 10:34:37.190314 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.189926 [mod=DVR, lvl=INFO] [tid=6488] [REC_SEG] PlayContext::attachToSegment() attaching segment for play activity ... m_recording= 0x107f00 for m_segmentName= 1508835613284 ocapri_log.txt:Oct 24 10:34:37.190719 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.190332 [mod=DVR, lvl=INFO] [tid=6488] first mpeg chunk 0x12a8d0 with offset 0 chunk size 2000000 ocapri_log.txt:Oct 24 10:34:37.191140 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.190795 [mod=DVR, lvl=INFO] [tid=6488] PlayContext::generatePATandPMT: trick 0 prognum 100 pmtpid: 39 pcrpid: 3F pmt section len 45 video 1 audio 1 data 2 ocapri_log.txt:Oct 24 10:34:37.191545 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.191147 [mod=DVR, lvl=INFO] [tid=6488] If it is MC channel where in audio is the PCR PID && trick is true (ie no audio during trick), then the VID PID will become new PCR PID; So update the PMT Version by 1 ocapri_log.txt:Oct 24 10:34:37.191959 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.191589 [mod=DVR, lvl=INFO] [tid=6488] PlayContext::generatePATandPMT: trick 1 prognum 100 pmtpid: 39 pcrpid: 3F pmt section len 40 video 1 audio 1 data 2 ocapri_log.txt:Oct 24 10:34:37.192366 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.192010 [mod=DVR, lvl=INFO] [tid=6488] PlayContext::generatePATandPMT: trick 0 prognum 100 pmtpid: 39 pcrpid: 3F pmt section len 45 video 1 audio 1 data 2 ocapri_log.txt:Oct 24 10:34:37.192769 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:37.192373 [mod=DVR, lvl=INFO] [tid=6488] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000000000000.mpg ocapri_log.txt:Oct 24 10:34:40.693449 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.693404 [mod=DVR, lvl=INFO] [tid=6488] using 10.000000 for m_apparentFrameRate ocapri_log.txt:Oct 24 10:34:40.693488 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.693471 [mod=DVR, lvl=INFO] [tid=6488] PlayContext::setThrottleEnable enable=1 ocapri_log.txt:Oct 24 10:34:40.693547 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.693532 [mod=DVR, lvl=INFO] [tid=6488] setting playback rate to 1.000000 ocapri_log.txt:Oct 24 10:34:40.694096 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.694072 [mod=RMFBASE, lvl=INFO] [tid=6488] gstbasesrc.c[1328]-gst_base_src_do_seek :: seeking: time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x09, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999 ocapri_log.txt:Oct 24 10:34:40.694228 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.694211 [mod=DVR, lvl=INFO] [tid=6488] PlayContext::getOffsetForStreamTime: time 0 ns ocapri_log.txt:Oct 24 10:34:40.741496 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.741468 [mod=DVR, lvl=INFO] [tid=6488] PlayContext::getOffsetForStreamTime: time 0 base PTS 164219ce0 pts 164219ce0 offset d080 ocapri_log.txt:Oct 24 10:34:40.741601 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.741583 [mod=DVR, lvl=INFO] [tid=6488] setting playback rate to 1.000000 ocapri_log.txt:Oct 24 10:34:40.741942 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.741921 [mod=RMFBASE, lvl=WARN] [tid=2820] Unknown bus call (reset-time) occurred ocapri_log.txt:Oct 24 10:34:40.742293 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.742274 [mod=DVR, lvl=INFO] [tid=6488] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 19 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:40.742323 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.742308 [mod=DVR, lvl=INFO] [tid=6488] PlayContext::notifyPaused: 0x9ab3b800 release segment name 1508835613284 while paused ocapri_log.txt:Oct 24 10:34:40.742380 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.742360 [mod=DVR, lvl=INFO] [tid=6488] PlayContext::notifyPaused: exit ocapri_log.txt:Oct 24 10:34:40.742413 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.742395 [mod=DVR, lvl=INFO] [tid=6488] dvrsrc.c[664]-gst_dvr_src_change_state :: gst_dvr_src_change_state: PLAYING_TO_PAUSED ocapri_log.txt:Oct 24 10:34:40.742442 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.742427 [mod=DVR, lvl=INFO] [tid=6488] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 19 ret 1 ocapri_log.txt:Oct 24 10:34:40.742666 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.742643 [mod=DVR, lvl=INFO] [tid=6552] dvrsrc.c[490]-gst_dvr_src_negotiate :: gst_dvr_src_negotiate: setting video/vnd.dlna.mpeg-tts mimetype ocapri_log.txt:Oct 24 10:34:40.742669 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.742651 [mod=RMFBASE, lvl=INFO] [tid=2820] onStateChange 1965 Iterator is 9ab1b6e8 size is 1 ocapri_log.txt:Oct 24 10:34:40.742690 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.742675 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PAUSED state ocapri_log.txt:Oct 24 10:34:40.743067 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.743048 [mod=DVR, lvl=INFO] [tid=6552] aesdecrypt.c[200]-gst_aesdecrypt_set_caps :: aesdecrypt_set_caps: packetSize=192 ocapri_log.txt:Oct 24 10:34:40.743399 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.743382 [mod=HN, lvl=INFO] [tid=6488] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PAUSED to PLAYING ocapri_log.txt:Oct 24 10:34:40.743623 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.743605 [mod=DVR, lvl=INFO] [tid=6552] PlayContext::findNextPCR: scan for next PCR from offset 155d00 ocapri_log.txt:Oct 24 10:34:40.743776 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.743758 [mod=DVR, lvl=INFO] [tid=6488] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 28 ocapri_log.txt:Oct 24 10:34:40.743811 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.743795 [mod=DVR, lvl=INFO] [tid=6488] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 28 calling parent ocapri_log.txt:Oct 24 10:34:40.743848 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.743832 [mod=DVR, lvl=INFO] [tid=6488] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 28 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:40.744100 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.743862 [mod=DVR, lvl=INFO] [tid=6488] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 28 ret 1 ocapri_log.txt:Oct 24 10:34:40.744505 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.744257 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PLAYING state ocapri_log.txt:Oct 24 10:34:40.744922 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.744288 [mod=RMFBASE, lvl=ERROR] [tid=6488] Changed state to PLAYING ocapri_log.txt:Oct 24 10:34:40.745334 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.744931 [mod=MS, lvl=INFO] [tid=6488] [stream:906] play_success ocapri_log.txt:Oct 24 10:34:40.745740 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.745342 [mod=MS, lvl=NOTICE] [tid=6488] [RMFMediaStreamer::stream][stream:912] Streaming started source id dvr://local/2017102416#0 : 562397 20170915 ocapri_log.txt:Oct 24 10:34:40.746153 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.745747 [mod=MS, lvl=NOTICE] [tid=6488] [stream:914] Streaming started source id dvr://local/2017102416#0 : 562397 ocapri_log.txt:Oct 24 10:34:40.746560 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.746173 [mod=MS, lvl=INFO] [tid=6488] [serviceSelection:1714] EventQ: 0x9ab1b238, Semaphore: 0x9ab1a638 ocapri_log.txt:Oct 24 10:34:40.746970 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.746567 [mod=MS, lvl=INFO] [tid=6488] [serviceSelection: 579842] ocapri_log.txt:Oct 24 10:34:40.940529 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.940480 [mod=DVR, lvl=INFO] [tid=6552] PlayContext::findNextPCR: found PCR c62c9160 at offset 58cec0 ocapri_log.txt:Oct 24 10:34:40.942072 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.942038 [mod=RMFBASE, lvl=INFO] [tid=6552] gstbasesrc.c[2828]-gst_base_src_loop :: marking pending DISCONT ocapri_log.txt:Oct 24 10:34:40.942268 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.942243 [mod=HN, lvl=INFO] [tid=6490] gsthttpsink.c[499]-gst_http_sink_render :: httpsink::Received first packet[98304]: ocapri_log.txt:Oct 24 10:34:40.947323 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.947269 [mod=HN, lvl=INFO] [tid=6490] gsthttpsink.c[618]-gst_http_sink_render :: Source Type: DVR_SRC packet[1] Source Id: dvr://local/2017102416#0 sent [98304 bytes] on ConnId [70] ocapri_log.txt:Oct 24 10:34:40.947522 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.947489 [mod=HN, lvl=INFO] [tid=6490] gsthttpsink.c[421]-onError :: streaming error occurred : Broken pipe ocapri_log.txt:Oct 24 10:34:40.947791 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.947764 [mod=HN, lvl=INFO] [tid=6490] gsthttpsink.c[618]-gst_http_sink_render :: Source Type: DVR_SRC packet[5] Source Id: dvr://local/2017102416#0 sent [98304 bytes] on ConnId [-1] ocapri_log.txt:Oct 24 10:34:40.948157 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.948132 [mod=MS, lvl=INFO] [tid=2820] [error:4225] Pipeline event received,Error code - 769 Message - Error: Client Closed Connection ocapri_log.txt:Oct 24 10:34:40.948515 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.948495 [mod=MS, lvl=INFO] [tid=6488] [eventHandlerAndClientNotifier:1307] RMF error events received ocapri_log.txt:Oct 24 10:34:40.948559 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.948544 [mod=MS, lvl=INFO] [tid=6488] [httpStreamingHandler:2112] No of active session present: 0 ocapri_log.txt:Oct 24 10:34:40.948582 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:40.948567 [mod=MS, lvl=INFO] [tid=6488] [httpStreamingHandler:2115] Streaming completed for 192.168.100.100 ocapri_log.txt:Oct 24 10:34:41.025138 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.025093 [mod=MS, lvl=INFO] [tid=6561] [HTTPServer::httpServerDmsHandler][httpServerDmsHandler:241] begin 20170915 ocapri_log.txt:Oct 24 10:34:41.026068 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.026035 [mod=MS, lvl=INFO] [tid=6561] [httpServerDmsHandler:297] Client requested URI: '/vldms/dvr?rec_id=2017102416&segmentId=0' ocapri_log.txt:Oct 24 10:34:41.026583 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.026564 [mod=MS, lvl=INFO] [tid=6561] [HTTPServer::httpServerDmsHandler][httpServerDmsHandler:348] before true == isDLNARequest(pRequest) 20170915 ocapri_log.txt:Oct 24 10:34:41.027047 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.027029 [mod=MS, lvl=INFO] [tid=6561] [HTTPServer::isDLNARequest][isDLNARequest:189] begin 20170915 ocapri_log.txt:Oct 24 10:34:41.027502 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.027484 [mod=MS, lvl=INFO] [tid=6561] [HTTPServer::isDLNARequest][isDLNARequest:233] end 20170915 ocapri_log.txt:Oct 24 10:34:41.028203 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.028179 [mod=MS, lvl=NOTICE] [tid=6561] [parseUrl:544] DVR request received from 192.168.100.100 20170915 ocapri_log.txt:Oct 24 10:34:41.028650 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.028633 [mod=MS, lvl=NOTICE] [tid=6561] [parseUrl:546] DVR request received from 192.168.100.100 ocapri_log.txt:Oct 24 10:34:41.029408 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.029389 [mod=MS, lvl=INFO] [tid=6561] dvr://local/2017102416#0 Duration: 297 Size: 764151168 PTS: b210ce70 b2dcebcf ocapri_log.txt:Oct 24 10:34:41.030064 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.030046 [mod=MS, lvl=INFO] [tid=6561] [HTTPServer::httpServerDmsHandler][httpServerDmsHandler:368] aftere msgHandler->sendResponse 20170915 ocapri_log.txt:Oct 24 10:34:41.030528 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.030510 [mod=MS, lvl=NOTICE] [tid=6561] [locator: dvr://local/2017102416#0] [1.000000 0.000000] [IP: 192.168.100.100] [TSB: FALSE] [continueTSB: TRUE] ocapri_log.txt:Oct 24 10:34:41.030996 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.030977 [mod=MS, lvl=NOTICE] [tid=6561] [MsgHandler::showRequest][locator: dvr://local/2017102416#0] [1.000000 0.000000] [IP: 192.168.100.100] [TSB: FALSE] 20170915 ocapri_log.txt:Oct 24 10:34:41.031488 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.031470 [mod=MS, lvl=INFO] [tid=6561] [httpStreamingHandler:2033] Received service selection message for service: DVR_SRC play speed: 1.0 time position: 0.000000 source id: dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:41.031943 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.031926 [mod=MS, lvl=INFO] [tid=6561] [httpStreamingHandler:2036] Number of request received: 2 Active sessions now 1 ocapri_log.txt:Oct 24 10:34:41.032430 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.032410 [mod=MS, lvl=INFO] [tid=6561] [serviceSelection:1701] Processing service selection for: DVR_SRC play speed: 1.0 time position: 0.000000 source id: dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:41.033004 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.032980 [mod=MS, lvl=INFO] [tid=6561] [open:434] Transcoder support : FALSE ocapri_log.txt:Oct 24 10:34:41.033028 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.033012 [mod=MS, lvl=INFO] [tid=6561] [open:437] Now tuning to service dvr://local/2017102416#0 tsb_support=FALSE ocapri_log.txt:Oct 24 10:34:41.033053 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.033038 [mod=MS, lvl=INFO] [tid=6561] [createSource:317] RMFMediaStreamer::createSource dvr://local/2017102416#0 20170915 ocapri_log.txt:Oct 24 10:34:41.033079 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.033064 [mod=DVR, lvl=INFO] [tid=6561] DVRSource::DVRSource() [SOURCE] DVRSource constructor= 0x9ab38bd8 ocapri_log.txt:Oct 24 10:34:41.033113 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.033096 [mod=MS, lvl=INFO] [tid=6561] RMFMediaStreamer::createSource() [SOURCE] DVRSource created pSource= 0x9ab38bd8 for locator= dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:41.033141 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.033126 [mod=RMFBASE, lvl=INFO] [tid=6561] RMFInit:124 - Enter. ocapri_log.txt:Oct 24 10:34:41.033782 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.033764 [mod=RMFBASE, lvl=INFO] [tid=6561] init bus=0xee788 m_bus_event_source_id=131 ocapri_log.txt:Oct 24 10:34:41.033810 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.033795 [mod=RMFBASE, lvl=INFO] [tid=6561] RMFMediaSourcePrivate::addEventHandler :: 9a8686c0 :: Size : 1 ocapri_log.txt:Oct 24 10:34:41.033833 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.033819 [mod=DVR, lvl=INFO] [tid=6561] DVRSourcePrivate::open: uri(dvr://local/2017102416#0) ocapri_log.txt:Oct 24 10:34:41.033856 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.033841 [mod=DVR, lvl=INFO] [tid=6561] DVRSourcePrivate::open: setting gst tee element properties for device mem alloc/free ocapri_log.txt:Oct 24 10:34:41.033998 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.033980 [mod=DVR, lvl=INFO] [tid=6561] DVRSourcePrivate::open: get recordingId 2017102416 and segmentNumber 0 segmentName 1508835613284 from uri ocapri_log.txt:Oct 24 10:34:41.034550 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.034531 [mod=RMFBASE, lvl=INFO] [tid=6561] RMFInit:124 - Enter. ocapri_log.txt:Oct 24 10:34:41.034699 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.034681 [mod=HN, lvl=INFO] [tid=6561] gsthttpsink.c[323]-gst_http_sink_set_property :: HTTP_OBJ socket 0x46 ocapri_log.txt:Oct 24 10:34:41.034996 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.034977 [mod=RMFBASE, lvl=INFO] [tid=6561] RMFMediaSinkPrivate::addEventHandler :: 9ab9e878 :: size 1 ocapri_log.txt:Oct 24 10:34:41.035021 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.035006 [mod=MS, lvl=INFO] [tid=6561] [RMFMediaStreamer::open][open:624] Source and Sink created 20170915 ocapri_log.txt:Oct 24 10:34:41.035067 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.035051 [mod=MS, lvl=NOTICE] [tid=6561] [open:626] Source and Sink created ocapri_log.txt:Oct 24 10:34:41.035115 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.035099 [mod=MS, lvl=INFO] [tid=6561] [RMFMediaStreamer::stream][stream:734] Play Speed : 1.000000 Time Position: 0.000000 20170915 ocapri_log.txt:Oct 24 10:34:41.035516 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.035123 [mod=MS, lvl=INFO] [tid=6561] [stream:736] Play Speed : 1.000000 Time Position: 0.000000 ocapri_log.txt:Oct 24 10:34:41.035936 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.035118 [mod=HN, lvl=INFO] [tid=6562] streamStatusThread Begin ocapri_log.txt:Oct 24 10:34:41.036342 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.035521 [mod=MS, lvl=INFO] [tid=6561] [stream:755] play_request ocapri_log.txt:Oct 24 10:34:41.036757 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.035992 [mod=HN, lvl=INFO] [tid=6562] ConnId [-1] Client IP [localhost] uri [None] last send() time=0 current time=1508841281 send status=Free ocapri_log.txt:Oct 24 10:34:41.037176 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.036355 [mod=RMFBASE, lvl=INFO] [tid=6561] RMFMediaSinkPrivate::setSource :: Calling addSink ocapri_log.txt:Oct 24 10:34:41.037590 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.037339 [mod=RMFBASE, lvl=INFO] [tid=6561] QueueSize=10 QueueType=non-leaky ocapri_log.txt:Oct 24 10:34:41.038002 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.037596 [mod=RMFBASE, lvl=INFO] [tid=6561] m_pipeline=0x14da78 queue=0x9ab36860 ocapri_log.txt:Oct 24 10:34:41.038413 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.038042 [mod=RMFBASE, lvl=INFO] [tid=6561] m_pipeline=0x14da78 sink=0x14f8f0 ocapri_log.txt:Oct 24 10:34:41.038909 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.038890 [mod=RMFBASE, lvl=INFO] [tid=6561] RMFMediaSinkPrivate::setSource :: Out of addSink ocapri_log.txt:Oct 24 10:34:41.039233 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.038926 [mod=MS, lvl=INFO] [tid=6561] [stream:852] setting playback rate to 1.0 ocapri_log.txt:Oct 24 10:34:41.039783 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.039262 [mod=RMFBASE, lvl=INFO] [tid=6561] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:41.040234 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.039870 [mod=HN, lvl=INFO] [tid=6561] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from NULL to READY ocapri_log.txt:Oct 24 10:34:41.040662 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.040644 [mod=DVR, lvl=INFO] [tid=6561] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 10 ocapri_log.txt:Oct 24 10:34:41.041062 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.040674 [mod=DVR, lvl=INFO] [tid=6561] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 10 calling parent ocapri_log.txt:Oct 24 10:34:41.041469 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.041079 [mod=DVR, lvl=INFO] [tid=6561] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 10 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:41.041878 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.041484 [mod=DVR, lvl=INFO] [tid=6561] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 10 ret 1 ocapri_log.txt:Oct 24 10:34:41.042322 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.042044 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to READY state ocapri_log.txt:Oct 24 10:34:41.042728 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.042073 [mod=RMFBASE, lvl=ERROR] [tid=6561] Changed state to READY ocapri_log.txt:Oct 24 10:34:41.043144 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.042839 [mod=RMFBASE, lvl=INFO] [tid=6561] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(PLAYING) ocapri_log.txt:Oct 24 10:34:41.043552 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.043223 [mod=HN, lvl=INFO] [tid=6561] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from READY to PAUSED ocapri_log.txt:Oct 24 10:34:41.044191 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.044173 [mod=DVR, lvl=INFO] [tid=6561] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 19 ocapri_log.txt:Oct 24 10:34:41.044372 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.044204 [mod=DVR, lvl=INFO] [tid=6561] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 19 calling parent ocapri_log.txt:Oct 24 10:34:41.044785 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.044446 [mod=DVR, lvl=INFO] [tid=6561] [REC_SEG] PlayContext::attachToSegment() attaching segment for play activity ... m_recording= 0x107f00 for m_segmentName= 1508835613284 ocapri_log.txt:Oct 24 10:34:41.045213 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.044799 [mod=DVR, lvl=INFO] [tid=6561] first mpeg chunk 0x12a8d0 with offset 0 chunk size 2000000 ocapri_log.txt:Oct 24 10:34:41.045617 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.045266 [mod=DVR, lvl=INFO] [tid=6561] PlayContext::generatePATandPMT: trick 0 prognum 100 pmtpid: 39 pcrpid: 3F pmt section len 45 video 1 audio 1 data 2 ocapri_log.txt:Oct 24 10:34:41.046029 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.045625 [mod=DVR, lvl=INFO] [tid=6561] If it is MC channel where in audio is the PCR PID && trick is true (ie no audio during trick), then the VID PID will become new PCR PID; So update the PMT Version by 1 ocapri_log.txt:Oct 24 10:34:41.046433 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.046068 [mod=DVR, lvl=INFO] [tid=6561] PlayContext::generatePATandPMT: trick 1 prognum 100 pmtpid: 39 pcrpid: 3F pmt section len 40 video 1 audio 1 data 2 ocapri_log.txt:Oct 24 10:34:41.046844 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.046484 [mod=DVR, lvl=INFO] [tid=6561] PlayContext::generatePATandPMT: trick 0 prognum 100 pmtpid: 39 pcrpid: 3F pmt section len 45 video 1 audio 1 data 2 ocapri_log.txt:Oct 24 10:34:41.047259 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.046851 [mod=DVR, lvl=INFO] [tid=6561] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000000000000.mpg ocapri_log.txt:Oct 24 10:34:41.047665 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.047426 [mod=DVR, lvl=INFO] [tid=6561] using 10.000000 for m_apparentFrameRate ocapri_log.txt:Oct 24 10:34:41.048081 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.047674 [mod=DVR, lvl=INFO] [tid=6561] PlayContext::setThrottleEnable enable=1 ocapri_log.txt:Oct 24 10:34:41.048490 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.048122 [mod=DVR, lvl=INFO] [tid=6561] setting playback rate to 1.000000 ocapri_log.txt:Oct 24 10:34:41.048904 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.048737 [mod=RMFBASE, lvl=INFO] [tid=6561] gstbasesrc.c[1328]-gst_base_src_do_seek :: seeking: time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x09, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999 ocapri_log.txt:Oct 24 10:34:41.049316 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.048986 [mod=DVR, lvl=INFO] [tid=6561] PlayContext::getOffsetForStreamTime: time 0 ns ocapri_log.txt:Oct 24 10:34:41.049891 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.049867 [mod=DVR, lvl=INFO] [tid=6561] PlayContext::getOffsetForStreamTime: time 0 base PTS 164219ce0 pts 164219ce0 offset d080 ocapri_log.txt:Oct 24 10:34:41.050136 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.049962 [mod=DVR, lvl=INFO] [tid=6561] setting playback rate to 1.000000 ocapri_log.txt:Oct 24 10:34:41.050544 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.050217 [mod=RMFBASE, lvl=WARN] [tid=2820] Unknown bus call (reset-time) occurred ocapri_log.txt:Oct 24 10:34:41.050977 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.050421 [mod=DVR, lvl=INFO] [tid=6561] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 19 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:41.051834 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.050987 [mod=DVR, lvl=INFO] [tid=6561] PlayContext::notifyPaused: 0x9a875800 release segment name 1508835613284 while paused ocapri_log.txt:Oct 24 10:34:41.051857 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.051841 [mod=DVR, lvl=INFO] [tid=6561] PlayContext::notifyPaused: exit ocapri_log.txt:Oct 24 10:34:41.052247 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.051867 [mod=DVR, lvl=INFO] [tid=6561] dvrsrc.c[664]-gst_dvr_src_change_state :: gst_dvr_src_change_state: PLAYING_TO_PAUSED ocapri_log.txt:Oct 24 10:34:41.052652 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.052262 [mod=DVR, lvl=INFO] [tid=6561] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 19 ret 1 ocapri_log.txt:Oct 24 10:34:41.053068 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.050752 [mod=DVR, lvl=INFO] [tid=6564] dvrsrc.c[490]-gst_dvr_src_negotiate :: gst_dvr_src_negotiate: setting video/vnd.dlna.mpeg-tts mimetype ocapri_log.txt:Oct 24 10:34:41.053482 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.052835 [mod=RMFBASE, lvl=INFO] [tid=2820] onStateChange 1965 Iterator is 9a8686c0 size is 1 ocapri_log.txt:Oct 24 10:34:41.053921 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.053275 [mod=HN, lvl=INFO] [tid=6561] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PAUSED to PLAYING ocapri_log.txt:Oct 24 10:34:41.054339 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.053327 [mod=DVR, lvl=INFO] [tid=6564] aesdecrypt.c[200]-gst_aesdecrypt_set_caps :: aesdecrypt_set_caps: packetSize=192 ocapri_log.txt:Oct 24 10:34:41.054749 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.053497 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PAUSED state ocapri_log.txt:Oct 24 10:34:41.055184 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.054107 [mod=DVR, lvl=INFO] [tid=6561] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 28 ocapri_log.txt:Oct 24 10:34:41.055593 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.054947 [mod=DVR, lvl=INFO] [tid=6564] PlayContext::findNextPCR: scan for next PCR from offset 155d00 ocapri_log.txt:Oct 24 10:34:41.056006 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.055206 [mod=DVR, lvl=INFO] [tid=6561] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 28 calling parent ocapri_log.txt:Oct 24 10:34:41.056555 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.056031 [mod=DVR, lvl=INFO] [tid=6561] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 28 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:41.057004 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.056571 [mod=DVR, lvl=INFO] [tid=6561] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 28 ret 1 ocapri_log.txt:Oct 24 10:34:41.057421 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.057294 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PLAYING state ocapri_log.txt:Oct 24 10:34:41.057833 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.057329 [mod=RMFBASE, lvl=ERROR] [tid=6561] Changed state to PLAYING ocapri_log.txt:Oct 24 10:34:41.058262 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.057843 [mod=MS, lvl=INFO] [tid=6561] [stream:906] play_success ocapri_log.txt:Oct 24 10:34:41.058675 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.058270 [mod=MS, lvl=NOTICE] [tid=6561] [RMFMediaStreamer::stream][stream:912] Streaming started source id dvr://local/2017102416#0 : 23178 20170915 ocapri_log.txt:Oct 24 10:34:41.059088 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.058681 [mod=MS, lvl=NOTICE] [tid=6561] [stream:914] Streaming started source id dvr://local/2017102416#0 : 23178 ocapri_log.txt:Oct 24 10:34:41.059497 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.059102 [mod=MS, lvl=INFO] [tid=6561] [serviceSelection:1714] EventQ: 0x9ab1be68, Semaphore: 0x9ab43eb0 ocapri_log.txt:Oct 24 10:34:41.059909 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.059504 [mod=MS, lvl=INFO] [tid=6561] [serviceSelection: 27101] ocapri_log.txt:Oct 24 10:34:41.083777 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.083714 [mod=DVR, lvl=INFO] [tid=6564] PlayContext::findNextPCR: found PCR c62c9160 at offset 58cec0 ocapri_log.txt:Oct 24 10:34:41.084225 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.084195 [mod=RMFBASE, lvl=INFO] [tid=6564] gstbasesrc.c[2828]-gst_base_src_loop :: marking pending DISCONT ocapri_log.txt:Oct 24 10:34:41.084317 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.084296 [mod=HN, lvl=INFO] [tid=6563] gsthttpsink.c[499]-gst_http_sink_render :: httpsink::Received first packet[98304]: ocapri_log.txt:Oct 24 10:34:41.090545 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.090490 [mod=HN, lvl=INFO] [tid=6563] gsthttpsink.c[618]-gst_http_sink_render :: Source Type: DVR_SRC packet[1] Source Id: dvr://local/2017102416#0 sent [98304 bytes] on ConnId [70] ocapri_log.txt:Oct 24 10:34:41.106866 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.106819 [mod=MS, lvl=INFO] [tid=6565] [HTTPServer::httpServerDmsHandler][httpServerDmsHandler:241] begin 20170915 ocapri_log.txt:Oct 24 10:34:41.107790 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.107757 [mod=MS, lvl=INFO] [tid=6565] [httpServerDmsHandler:297] Client requested URI: '/vldms/dvr?rec_id=2017102416&segmentId=0&WMContentFeatures=DLNA.ORG_PN=MPEG_TS_HD_NA_T;DLNA.ORG_OP=10;DLNA.ORG_PS=-60,-30,-15,15,30,60;DLNA.ORG_FLAGS=01000000000000000000000000000000&WMHME=1&HMEExt=.tts' ocapri_log.txt:Oct 24 10:34:41.108283 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.108264 [mod=MS, lvl=INFO] [tid=6565] [HTTPServer::httpServerDmsHandler][httpServerDmsHandler:348] before true == isDLNARequest(pRequest) 20170915 ocapri_log.txt:Oct 24 10:34:41.108744 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.108727 [mod=MS, lvl=INFO] [tid=6565] [HTTPServer::isDLNARequest][isDLNARequest:189] begin 20170915 ocapri_log.txt:Oct 24 10:34:41.109204 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.109187 [mod=MS, lvl=INFO] [tid=6565] [HTTPServer::isDLNARequest][isDLNARequest:233] end 20170915 ocapri_log.txt:Oct 24 10:34:41.109916 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.109895 [mod=MS, lvl=NOTICE] [tid=6565] [parseUrl:544] DVR request received from 192.168.100.100 20170915 ocapri_log.txt:Oct 24 10:34:41.110368 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.110350 [mod=MS, lvl=NOTICE] [tid=6565] [parseUrl:546] DVR request received from 192.168.100.100 ocapri_log.txt:Oct 24 10:34:41.111101 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.111081 [mod=MS, lvl=INFO] [tid=6565] dvr://local/2017102416#0 Duration: 297 Size: 764151168 PTS: b210ce70 b2dcebcf ocapri_log.txt:Oct 24 10:34:41.111778 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.111759 [mod=MS, lvl=INFO] [tid=6565] [HTTPServer::httpServerDmsHandler][httpServerDmsHandler:368] aftere msgHandler->sendResponse 20170915 ocapri_log.txt:Oct 24 10:34:41.112258 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.112240 [mod=MS, lvl=NOTICE] [tid=6565] [locator: dvr://local/2017102416#0] [1.000000 0.000000] [IP: 192.168.100.100] [TSB: FALSE] [continueTSB: TRUE] ocapri_log.txt:Oct 24 10:34:41.112711 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.112694 [mod=MS, lvl=NOTICE] [tid=6565] [MsgHandler::showRequest][locator: dvr://local/2017102416#0] [1.000000 0.000000] [IP: 192.168.100.100] [TSB: FALSE] 20170915 ocapri_log.txt:Oct 24 10:34:41.112946 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.112925 [mod=MS, lvl=INFO] [tid=6565] [httpStreamingHandler:2033] Received service selection message for service: DVR_SRC play speed: 1.0 time position: 0.000000 source id: dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:41.112968 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.112952 [mod=MS, lvl=INFO] [tid=6565] [httpStreamingHandler:2036] Number of request received: 3 Active sessions now 2 ocapri_log.txt:Oct 24 10:34:41.113023 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.113005 [mod=MS, lvl=INFO] [tid=6565] [serviceSelection:1701] Processing service selection for: DVR_SRC play speed: 1.0 time position: 0.000000 source id: dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:41.113253 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.113237 [mod=MS, lvl=INFO] [tid=6565] [open:434] Transcoder support : FALSE ocapri_log.txt:Oct 24 10:34:41.113274 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.113259 [mod=MS, lvl=INFO] [tid=6565] [open:437] Now tuning to service dvr://local/2017102416#0 tsb_support=FALSE ocapri_log.txt:Oct 24 10:34:41.113297 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.113283 [mod=MS, lvl=INFO] [tid=6565] [createSource:317] RMFMediaStreamer::createSource dvr://local/2017102416#0 20170915 ocapri_log.txt:Oct 24 10:34:41.113322 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.113308 [mod=DVR, lvl=INFO] [tid=6565] DVRSource::DVRSource() [SOURCE] DVRSource constructor= 0x9a873f78 ocapri_log.txt:Oct 24 10:34:41.113342 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.113327 [mod=MS, lvl=INFO] [tid=6565] RMFMediaStreamer::createSource() [SOURCE] DVRSource created pSource= 0x9a873f78 for locator= dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:41.113370 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.113356 [mod=RMFBASE, lvl=INFO] [tid=6565] RMFInit:124 - Enter. ocapri_log.txt:Oct 24 10:34:41.114050 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.114031 [mod=RMFBASE, lvl=INFO] [tid=6565] init bus=0x9ab28398 m_bus_event_source_id=132 ocapri_log.txt:Oct 24 10:34:41.114078 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.114063 [mod=RMFBASE, lvl=INFO] [tid=6565] RMFMediaSourcePrivate::addEventHandler :: 9a8f1f48 :: Size : 1 ocapri_log.txt:Oct 24 10:34:41.114101 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.114086 [mod=DVR, lvl=INFO] [tid=6565] DVRSourcePrivate::open: uri(dvr://local/2017102416#0) ocapri_log.txt:Oct 24 10:34:41.114123 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.114109 [mod=DVR, lvl=INFO] [tid=6565] DVRSourcePrivate::open: setting gst tee element properties for device mem alloc/free ocapri_log.txt:Oct 24 10:34:41.114324 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.114307 [mod=DVR, lvl=INFO] [tid=6565] DVRSourcePrivate::open: get recordingId 2017102416 and segmentNumber 0 segmentName 1508835613284 from uri ocapri_log.txt:Oct 24 10:34:41.115536 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.115508 [mod=RMFBASE, lvl=INFO] [tid=6565] RMFInit:124 - Enter. ocapri_log.txt:Oct 24 10:34:41.115708 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.115689 [mod=HN, lvl=INFO] [tid=6565] gsthttpsink.c[323]-gst_http_sink_set_property :: HTTP_OBJ socket 0x4f ocapri_log.txt:Oct 24 10:34:41.116050 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.116031 [mod=RMFBASE, lvl=INFO] [tid=6565] RMFMediaSinkPrivate::addEventHandler :: 9a870fe8 :: size 1 ocapri_log.txt:Oct 24 10:34:41.116088 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.116072 [mod=MS, lvl=INFO] [tid=6565] [RMFMediaStreamer::open][open:624] Source and Sink created 20170915 ocapri_log.txt:Oct 24 10:34:41.116111 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.116096 [mod=MS, lvl=NOTICE] [tid=6565] [open:626] Source and Sink created ocapri_log.txt:Oct 24 10:34:41.116472 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.116116 [mod=HN, lvl=INFO] [tid=6566] streamStatusThread Begin ocapri_log.txt:Oct 24 10:34:41.116924 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.116128 [mod=MS, lvl=INFO] [tid=6565] [RMFMediaStreamer::stream][stream:734] Play Speed : 1.000000 Time Position: 0.000000 20170915 ocapri_log.txt:Oct 24 10:34:41.117295 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.116506 [mod=HN, lvl=INFO] [tid=6566] ConnId [-1] Client IP [localhost] uri [None] last send() time=0 current time=1508841281 send status=Free ocapri_log.txt:Oct 24 10:34:41.117704 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.116934 [mod=MS, lvl=INFO] [tid=6565] [stream:736] Play Speed : 1.000000 Time Position: 0.000000 ocapri_log.txt:Oct 24 10:34:41.118123 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.117710 [mod=MS, lvl=INFO] [tid=6565] [stream:755] play_request ocapri_log.txt:Oct 24 10:34:41.118688 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.118137 [mod=RMFBASE, lvl=INFO] [tid=6565] RMFMediaSinkPrivate::setSource :: Calling addSink ocapri_log.txt:Oct 24 10:34:41.118969 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.118848 [mod=RMFBASE, lvl=INFO] [tid=6565] QueueSize=10 QueueType=non-leaky ocapri_log.txt:Oct 24 10:34:41.119379 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.118975 [mod=RMFBASE, lvl=INFO] [tid=6565] m_pipeline=0x14dd38 queue=0x9ab36d00 ocapri_log.txt:Oct 24 10:34:41.119788 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.119424 [mod=RMFBASE, lvl=INFO] [tid=6565] m_pipeline=0x14dd38 sink=0x14fe68 ocapri_log.txt:Oct 24 10:34:41.120294 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.120275 [mod=RMFBASE, lvl=INFO] [tid=6565] RMFMediaSinkPrivate::setSource :: Out of addSink ocapri_log.txt:Oct 24 10:34:41.120608 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.120310 [mod=MS, lvl=INFO] [tid=6565] [stream:852] setting playback rate to 1.0 ocapri_log.txt:Oct 24 10:34:41.121019 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.120638 [mod=RMFBASE, lvl=INFO] [tid=6565] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:41.121431 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.121101 [mod=HN, lvl=INFO] [tid=6565] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from NULL to READY ocapri_log.txt:Oct 24 10:34:41.121872 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.121854 [mod=DVR, lvl=INFO] [tid=6565] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 10 ocapri_log.txt:Oct 24 10:34:41.122545 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.121904 [mod=DVR, lvl=INFO] [tid=6565] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 10 calling parent ocapri_log.txt:Oct 24 10:34:41.122675 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.122564 [mod=DVR, lvl=INFO] [tid=6565] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 10 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:41.123231 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.122690 [mod=DVR, lvl=INFO] [tid=6565] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 10 ret 1 ocapri_log.txt:Oct 24 10:34:41.123678 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.123466 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to READY state ocapri_log.txt:Oct 24 10:34:41.124119 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.123498 [mod=RMFBASE, lvl=ERROR] [tid=6565] Changed state to READY ocapri_log.txt:Oct 24 10:34:41.124528 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.124242 [mod=RMFBASE, lvl=INFO] [tid=6565] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(PLAYING) ocapri_log.txt:Oct 24 10:34:41.124940 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.124622 [mod=HN, lvl=INFO] [tid=6565] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from READY to PAUSED ocapri_log.txt:Oct 24 10:34:41.125601 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.125582 [mod=DVR, lvl=INFO] [tid=6565] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 19 ocapri_log.txt:Oct 24 10:34:41.125760 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.125614 [mod=DVR, lvl=INFO] [tid=6565] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 19 calling parent ocapri_log.txt:Oct 24 10:34:41.126447 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.125840 [mod=DVR, lvl=INFO] [tid=6565] [REC_SEG] PlayContext::attachToSegment() attaching segment for play activity ... m_recording= 0x107f00 for m_segmentName= 1508835613284 ocapri_log.txt:Oct 24 10:34:41.126596 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.126462 [mod=DVR, lvl=INFO] [tid=6565] first mpeg chunk 0x12a8d0 with offset 0 chunk size 2000000 ocapri_log.txt:Oct 24 10:34:41.127074 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.126660 [mod=DVR, lvl=INFO] [tid=6565] PlayContext::generatePATandPMT: trick 0 prognum 100 pmtpid: 39 pcrpid: 3F pmt section len 45 video 1 audio 1 data 2 ocapri_log.txt:Oct 24 10:34:41.127420 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.127115 [mod=DVR, lvl=INFO] [tid=6565] If it is MC channel where in audio is the PCR PID && trick is true (ie no audio during trick), then the VID PID will become new PCR PID; So update the PMT Version by 1 ocapri_log.txt:Oct 24 10:34:41.127830 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.127462 [mod=DVR, lvl=INFO] [tid=6565] PlayContext::generatePATandPMT: trick 1 prognum 100 pmtpid: 39 pcrpid: 3F pmt section len 40 video 1 audio 1 data 2 ocapri_log.txt:Oct 24 10:34:41.128246 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.127881 [mod=DVR, lvl=INFO] [tid=6565] PlayContext::generatePATandPMT: trick 0 prognum 100 pmtpid: 39 pcrpid: 3F pmt section len 45 video 1 audio 1 data 2 ocapri_log.txt:Oct 24 10:34:41.128657 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.128253 [mod=DVR, lvl=INFO] [tid=6565] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000000000000.mpg ocapri_log.txt:Oct 24 10:34:41.129249 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.128825 [mod=DVR, lvl=INFO] [tid=6565] using 10.000000 for m_apparentFrameRate ocapri_log.txt:Oct 24 10:34:41.129659 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.129260 [mod=DVR, lvl=INFO] [tid=6565] PlayContext::setThrottleEnable enable=1 ocapri_log.txt:Oct 24 10:34:41.130072 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.129701 [mod=DVR, lvl=INFO] [tid=6565] setting playback rate to 1.000000 ocapri_log.txt:Oct 24 10:34:41.130821 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.130799 [mod=RMFBASE, lvl=INFO] [tid=6565] gstbasesrc.c[1328]-gst_base_src_do_seek :: seeking: time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x09, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999 ocapri_log.txt:Oct 24 10:34:41.131080 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.130945 [mod=DVR, lvl=INFO] [tid=6565] PlayContext::getOffsetForStreamTime: time 0 ns ocapri_log.txt:Oct 24 10:34:41.131694 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.131677 [mod=DVR, lvl=INFO] [tid=6565] PlayContext::getOffsetForStreamTime: time 0 base PTS 164219ce0 pts 164219ce0 offset d080 ocapri_log.txt:Oct 24 10:34:41.131783 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.131767 [mod=DVR, lvl=INFO] [tid=6565] setting playback rate to 1.000000 ocapri_log.txt:Oct 24 10:34:41.132180 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.131922 [mod=RMFBASE, lvl=WARN] [tid=2820] Unknown bus call (reset-time) occurred ocapri_log.txt:Oct 24 10:34:41.132589 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.132153 [mod=DVR, lvl=INFO] [tid=6565] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 19 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:41.133005 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.132599 [mod=DVR, lvl=INFO] [tid=6565] PlayContext::notifyPaused: 0x9a404800 release segment name 1508835613284 while paused ocapri_log.txt:Oct 24 10:34:41.133419 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.133012 [mod=DVR, lvl=INFO] [tid=6565] PlayContext::notifyPaused: exit ocapri_log.txt:Oct 24 10:34:41.133833 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.133355 [mod=DVR, lvl=INFO] [tid=6568] dvrsrc.c[490]-gst_dvr_src_negotiate :: gst_dvr_src_negotiate: setting video/vnd.dlna.mpeg-tts mimetype ocapri_log.txt:Oct 24 10:34:41.134558 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.133433 [mod=DVR, lvl=INFO] [tid=6565] dvrsrc.c[664]-gst_dvr_src_change_state :: gst_dvr_src_change_state: PLAYING_TO_PAUSED ocapri_log.txt:Oct 24 10:34:41.134667 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.134102 [mod=DVR, lvl=INFO] [tid=6568] aesdecrypt.c[200]-gst_aesdecrypt_set_caps :: aesdecrypt_set_caps: packetSize=192 ocapri_log.txt:Oct 24 10:34:41.135273 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.134576 [mod=DVR, lvl=INFO] [tid=6565] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 19 ret 1 ocapri_log.txt:Oct 24 10:34:41.135519 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.135277 [mod=DVR, lvl=INFO] [tid=6568] PlayContext::findNextPCR: scan for next PCR from offset 155d00 ocapri_log.txt:Oct 24 10:34:41.135953 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.135515 [mod=RMFBASE, lvl=INFO] [tid=2820] onStateChange 1965 Iterator is 9a8f1f48 size is 1 ocapri_log.txt:Oct 24 10:34:41.136367 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.135962 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PAUSED state ocapri_log.txt:Oct 24 10:34:41.136785 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.135996 [mod=HN, lvl=INFO] [tid=6565] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PAUSED to PLAYING ocapri_log.txt:Oct 24 10:34:41.137227 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.137203 [mod=DVR, lvl=INFO] [tid=6565] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 28 ocapri_log.txt:Oct 24 10:34:41.137617 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.137247 [mod=DVR, lvl=INFO] [tid=6565] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 28 calling parent ocapri_log.txt:Oct 24 10:34:41.138048 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.137641 [mod=DVR, lvl=INFO] [tid=6565] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 28 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:41.138607 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.138063 [mod=DVR, lvl=INFO] [tid=6565] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 28 ret 1 ocapri_log.txt:Oct 24 10:34:41.138900 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.138839 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PLAYING state ocapri_log.txt:Oct 24 10:34:41.139315 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.138876 [mod=RMFBASE, lvl=ERROR] [tid=6565] Changed state to PLAYING ocapri_log.txt:Oct 24 10:34:41.139860 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.139326 [mod=MS, lvl=INFO] [tid=6565] [stream:906] play_success ocapri_log.txt:Oct 24 10:34:41.140313 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.139869 [mod=MS, lvl=NOTICE] [tid=6565] [RMFMediaStreamer::stream][stream:912] Streaming started source id dvr://local/2017102416#0 : 23746 20170915 ocapri_log.txt:Oct 24 10:34:41.140723 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.140320 [mod=MS, lvl=NOTICE] [tid=6565] [stream:914] Streaming started source id dvr://local/2017102416#0 : 23746 ocapri_log.txt:Oct 24 10:34:41.141153 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.140739 [mod=MS, lvl=INFO] [tid=6565] [serviceSelection:1714] EventQ: 0x9a8825c8, Semaphore: 0x9a87c8e0 ocapri_log.txt:Oct 24 10:34:41.141569 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.141160 [mod=MS, lvl=INFO] [tid=6565] [serviceSelection: 28161] ocapri_log.txt:Oct 24 10:34:41.162025 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.161968 [mod=DVR, lvl=INFO] [tid=6568] PlayContext::findNextPCR: found PCR c62c9160 at offset 58cec0 ocapri_log.txt:Oct 24 10:34:41.163199 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.163168 [mod=RMFBASE, lvl=INFO] [tid=6568] gstbasesrc.c[2828]-gst_base_src_loop :: marking pending DISCONT ocapri_log.txt:Oct 24 10:34:41.163331 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.163306 [mod=HN, lvl=INFO] [tid=6567] gsthttpsink.c[499]-gst_http_sink_render :: httpsink::Received first packet[98304]: ocapri_log.txt:Oct 24 10:34:41.165182 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.165124 [mod=HN, lvl=INFO] [tid=6563] gsthttpsink.c[421]-onError :: streaming error occurred : Connection reset by peer ocapri_log.txt:Oct 24 10:34:41.165365 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.165340 [mod=HN, lvl=INFO] [tid=6563] gsthttpsink.c[618]-gst_http_sink_render :: Source Type: DVR_SRC packet[5] Source Id: dvr://local/2017102416#0 sent [98304 bytes] on ConnId [-1] ocapri_log.txt:Oct 24 10:34:41.165375 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.165352 [mod=MS, lvl=INFO] [tid=2820] [error:4225] Pipeline event received,Error code - 769 Message - Error: Client Closed Connection ocapri_log.txt:Oct 24 10:34:41.165882 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.165850 [mod=MS, lvl=INFO] [tid=6561] [eventHandlerAndClientNotifier:1307] RMF error events received ocapri_log.txt:Oct 24 10:34:41.165946 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.165919 [mod=MS, lvl=INFO] [tid=6561] [httpStreamingHandler:2112] No of active session present: 1 ocapri_log.txt:Oct 24 10:34:41.165980 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.165962 [mod=MS, lvl=INFO] [tid=6561] [httpStreamingHandler:2115] Streaming completed for 192.168.100.100 ocapri_log.txt:Oct 24 10:34:41.170538 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.170480 [mod=HN, lvl=INFO] [tid=6567] gsthttpsink.c[618]-gst_http_sink_render :: Source Type: DVR_SRC packet[1] Source Id: dvr://local/2017102416#0 sent [98304 bytes] on ConnId [79] ocapri_log.txt:Oct 24 10:34:41.178488 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.178435 [mod=HN, lvl=INFO] [tid=6567] gsthttpsink.c[421]-onError :: streaming error occurred : Broken pipe ocapri_log.txt:Oct 24 10:34:41.178643 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.178622 [mod=MS, lvl=INFO] [tid=2820] [error:4225] Pipeline event received,Error code - 769 Message - Error: Client Closed Connection ocapri_log.txt:Oct 24 10:34:41.178698 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.178679 [mod=HN, lvl=INFO] [tid=6567] gsthttpsink.c[618]-gst_http_sink_render :: Source Type: DVR_SRC packet[5] Source Id: dvr://local/2017102416#0 sent [98304 bytes] on ConnId [-1] ocapri_log.txt:Oct 24 10:34:41.179176 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.179123 [mod=MS, lvl=INFO] [tid=6565] [eventHandlerAndClientNotifier:1307] RMF error events received ocapri_log.txt:Oct 24 10:34:41.179311 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.179292 [mod=MS, lvl=INFO] [tid=6565] [httpStreamingHandler:2112] No of active session present: 0 ocapri_log.txt:Oct 24 10:34:41.179335 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.179320 [mod=MS, lvl=INFO] [tid=6565] [httpStreamingHandler:2115] Streaming completed for 192.168.100.100 ocapri_log.txt:Oct 24 10:34:41.197996 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.197946 [mod=MS, lvl=INFO] [tid=6569] [HTTPServer::httpServerDmsHandler][httpServerDmsHandler:241] begin 20170915 ocapri_log.txt:Oct 24 10:34:41.198287 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.198267 [mod=MS, lvl=INFO] [tid=6569] [httpServerDmsHandler:297] Client requested URI: '/vldms/dvr?rec_id=2017102416&segmentId=0' ocapri_log.txt:Oct 24 10:34:41.198314 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.198298 [mod=MS, lvl=INFO] [tid=6569] [HTTPServer::httpServerDmsHandler][httpServerDmsHandler:348] before true == isDLNARequest(pRequest) 20170915 ocapri_log.txt:Oct 24 10:34:41.198334 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.198319 [mod=MS, lvl=INFO] [tid=6569] [HTTPServer::isDLNARequest][isDLNARequest:189] begin 20170915 ocapri_log.txt:Oct 24 10:34:41.198360 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.198345 [mod=MS, lvl=INFO] [tid=6569] [HTTPServer::isDLNARequest][isDLNARequest:233] end 20170915 ocapri_log.txt:Oct 24 10:34:41.198627 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.198604 [mod=MS, lvl=NOTICE] [tid=6569] [parseUrl:544] DVR request received from 192.168.100.100 20170915 ocapri_log.txt:Oct 24 10:34:41.198648 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.198633 [mod=MS, lvl=NOTICE] [tid=6569] [parseUrl:546] DVR request received from 192.168.100.100 ocapri_log.txt:Oct 24 10:34:41.198939 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.198921 [mod=MS, lvl=INFO] [tid=6569] dvr://local/2017102416#0 Duration: 297 Size: 764151168 PTS: b210ce70 b2dcebcf ocapri_log.txt:Oct 24 10:34:41.199147 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.199129 [mod=MS, lvl=INFO] [tid=6569] [HTTPServer::httpServerDmsHandler][httpServerDmsHandler:368] aftere msgHandler->sendResponse 20170915 ocapri_log.txt:Oct 24 10:34:41.199179 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.199163 [mod=MS, lvl=NOTICE] [tid=6569] [locator: dvr://local/2017102416#0] [1.000000 0.000000] [IP: 192.168.100.100] [TSB: FALSE] [continueTSB: TRUE] ocapri_log.txt:Oct 24 10:34:41.199202 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.199187 [mod=MS, lvl=NOTICE] [tid=6569] [MsgHandler::showRequest][locator: dvr://local/2017102416#0] [1.000000 0.000000] [IP: 192.168.100.100] [TSB: FALSE] 20170915 ocapri_log.txt:Oct 24 10:34:41.199233 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.199217 [mod=MS, lvl=INFO] [tid=6569] [httpStreamingHandler:2033] Received service selection message for service: DVR_SRC play speed: 1.0 time position: 0.000000 source id: dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:41.199252 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.199238 [mod=MS, lvl=INFO] [tid=6569] [httpStreamingHandler:2036] Number of request received: 4 Active sessions now 1 ocapri_log.txt:Oct 24 10:34:41.199312 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.199293 [mod=MS, lvl=INFO] [tid=6569] [serviceSelection:1701] Processing service selection for: DVR_SRC play speed: 1.0 time position: 0.000000 source id: dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:41.199578 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.199560 [mod=MS, lvl=INFO] [tid=6569] [open:434] Transcoder support : FALSE ocapri_log.txt:Oct 24 10:34:41.199961 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.199584 [mod=MS, lvl=INFO] [tid=6569] [open:437] Now tuning to service dvr://local/2017102416#0 tsb_support=FALSE ocapri_log.txt:Oct 24 10:34:41.200386 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.199974 [mod=MS, lvl=INFO] [tid=6569] [createSource:317] RMFMediaStreamer::createSource dvr://local/2017102416#0 20170915 ocapri_log.txt:Oct 24 10:34:41.200804 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.200400 [mod=DVR, lvl=INFO] [tid=6569] DVRSource::DVRSource() [SOURCE] DVRSource constructor= 0x9ab38bc8 ocapri_log.txt:Oct 24 10:34:41.201233 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.200811 [mod=MS, lvl=INFO] [tid=6569] RMFMediaStreamer::createSource() [SOURCE] DVRSource created pSource= 0x9ab38bc8 for locator= dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:41.201646 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.201249 [mod=RMFBASE, lvl=INFO] [tid=6569] RMFInit:124 - Enter. ocapri_log.txt:Oct 24 10:34:41.202261 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.202234 [mod=RMFBASE, lvl=INFO] [tid=6569] init bus=0x9ab285d8 m_bus_event_source_id=133 ocapri_log.txt:Oct 24 10:34:41.203899 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.202275 [mod=RMFBASE, lvl=INFO] [tid=6569] RMFMediaSourcePrivate::addEventHandler :: 9a882768 :: Size : 1 ocapri_log.txt:Oct 24 10:34:41.204531 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.203919 [mod=DVR, lvl=INFO] [tid=6569] DVRSourcePrivate::open: uri(dvr://local/2017102416#0) ocapri_log.txt:Oct 24 10:34:41.204953 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.204541 [mod=DVR, lvl=INFO] [tid=6569] DVRSourcePrivate::open: setting gst tee element properties for device mem alloc/free ocapri_log.txt:Oct 24 10:34:41.205364 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.205094 [mod=DVR, lvl=INFO] [tid=6569] DVRSourcePrivate::open: get recordingId 2017102416 and segmentNumber 0 segmentName 1508835613284 from uri ocapri_log.txt:Oct 24 10:34:41.206029 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.206009 [mod=RMFBASE, lvl=INFO] [tid=6569] RMFInit:124 - Enter. ocapri_log.txt:Oct 24 10:34:41.206202 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.206172 [mod=HN, lvl=INFO] [tid=6569] gsthttpsink.c[323]-gst_http_sink_set_property :: HTTP_OBJ socket 0x46 ocapri_log.txt:Oct 24 10:34:41.207072 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.206630 [mod=RMFBASE, lvl=INFO] [tid=6569] RMFMediaSinkPrivate::addEventHandler :: 9a668118 :: size 1 ocapri_log.txt:Oct 24 10:34:41.207680 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.206775 [mod=HN, lvl=INFO] [tid=6570] streamStatusThread Begin ocapri_log.txt:Oct 24 10:34:41.207933 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.207081 [mod=MS, lvl=INFO] [tid=6569] [RMFMediaStreamer::open][open:624] Source and Sink created 20170915 ocapri_log.txt:Oct 24 10:34:41.208388 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.207723 [mod=HN, lvl=INFO] [tid=6570] ConnId [-1] Client IP [localhost] uri [None] last send() time=0 current time=1508841281 send status=Free ocapri_log.txt:Oct 24 10:34:41.208764 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.207941 [mod=MS, lvl=NOTICE] [tid=6569] [open:626] Source and Sink created ocapri_log.txt:Oct 24 10:34:41.209179 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.208787 [mod=MS, lvl=INFO] [tid=6569] [RMFMediaStreamer::stream][stream:734] Play Speed : 1.000000 Time Position: 0.000000 20170915 ocapri_log.txt:Oct 24 10:34:41.209584 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.209188 [mod=MS, lvl=INFO] [tid=6569] [stream:736] Play Speed : 1.000000 Time Position: 0.000000 ocapri_log.txt:Oct 24 10:34:41.210000 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.209590 [mod=MS, lvl=INFO] [tid=6569] [stream:755] play_request ocapri_log.txt:Oct 24 10:34:41.210408 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.210017 [mod=RMFBASE, lvl=INFO] [tid=6569] RMFMediaSinkPrivate::setSource :: Calling addSink ocapri_log.txt:Oct 24 10:34:41.210818 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.210602 [mod=RMFBASE, lvl=INFO] [tid=6569] QueueSize=10 QueueType=non-leaky ocapri_log.txt:Oct 24 10:34:41.211240 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.210824 [mod=RMFBASE, lvl=INFO] [tid=6569] m_pipeline=0x14de98 queue=0x9ab373f0 ocapri_log.txt:Oct 24 10:34:41.211652 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.211293 [mod=RMFBASE, lvl=INFO] [tid=6569] m_pipeline=0x14de98 sink=0x14fb20 ocapri_log.txt:Oct 24 10:34:41.212342 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.212305 [mod=RMFBASE, lvl=INFO] [tid=6569] RMFMediaSinkPrivate::setSource :: Out of addSink ocapri_log.txt:Oct 24 10:34:41.212516 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.212362 [mod=MS, lvl=INFO] [tid=6569] [stream:852] setting playback rate to 1.0 ocapri_log.txt:Oct 24 10:34:41.214071 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.212551 [mod=RMFBASE, lvl=INFO] [tid=6569] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:41.214494 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.214180 [mod=HN, lvl=INFO] [tid=6569] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from NULL to READY ocapri_log.txt:Oct 24 10:34:41.214915 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.214663 [mod=DVR, lvl=INFO] [tid=6569] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 10 ocapri_log.txt:Oct 24 10:34:41.215321 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.214929 [mod=DVR, lvl=INFO] [tid=6569] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 10 calling parent ocapri_log.txt:Oct 24 10:34:41.215730 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.215339 [mod=DVR, lvl=INFO] [tid=6569] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 10 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:41.216162 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.215746 [mod=DVR, lvl=INFO] [tid=6569] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 10 ret 1 ocapri_log.txt:Oct 24 10:34:41.216582 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.216248 [mod=RMFBASE, lvl=ERROR] [tid=6569] Changed state to READY ocapri_log.txt:Oct 24 10:34:41.217007 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.216291 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to READY state ocapri_log.txt:Oct 24 10:34:41.217426 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.216717 [mod=RMFBASE, lvl=INFO] [tid=6569] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(PLAYING) ocapri_log.txt:Oct 24 10:34:41.217833 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.217530 [mod=HN, lvl=INFO] [tid=6569] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from READY to PAUSED ocapri_log.txt:Oct 24 10:34:41.218256 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.218197 [mod=DVR, lvl=INFO] [tid=6569] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 19 ocapri_log.txt:Oct 24 10:34:41.218668 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.218270 [mod=DVR, lvl=INFO] [tid=6569] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 19 calling parent ocapri_log.txt:Oct 24 10:34:41.219083 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.218743 [mod=DVR, lvl=INFO] [tid=6569] [REC_SEG] PlayContext::attachToSegment() attaching segment for play activity ... m_recording= 0x107f00 for m_segmentName= 1508835613284 ocapri_log.txt:Oct 24 10:34:41.219488 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.219096 [mod=DVR, lvl=INFO] [tid=6569] first mpeg chunk 0x12a8d0 with offset 0 chunk size 2000000 ocapri_log.txt:Oct 24 10:34:41.219927 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.219543 [mod=DVR, lvl=INFO] [tid=6569] PlayContext::generatePATandPMT: trick 0 prognum 100 pmtpid: 39 pcrpid: 3F pmt section len 45 video 1 audio 1 data 2 ocapri_log.txt:Oct 24 10:34:41.220352 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.219946 [mod=DVR, lvl=INFO] [tid=6569] If it is MC channel where in audio is the PCR PID && trick is true (ie no audio during trick), then the VID PID will become new PCR PID; So update the PMT Version by 1 ocapri_log.txt:Oct 24 10:34:41.220764 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.220394 [mod=DVR, lvl=INFO] [tid=6569] PlayContext::generatePATandPMT: trick 1 prognum 100 pmtpid: 39 pcrpid: 3F pmt section len 40 video 1 audio 1 data 2 ocapri_log.txt:Oct 24 10:34:41.221183 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.220817 [mod=DVR, lvl=INFO] [tid=6569] PlayContext::generatePATandPMT: trick 0 prognum 100 pmtpid: 39 pcrpid: 3F pmt section len 45 video 1 audio 1 data 2 ocapri_log.txt:Oct 24 10:34:41.221593 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.221190 [mod=DVR, lvl=INFO] [tid=6569] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000000000000.mpg ocapri_log.txt:Oct 24 10:34:41.222027 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.221766 [mod=DVR, lvl=INFO] [tid=6569] using 10.000000 for m_apparentFrameRate ocapri_log.txt:Oct 24 10:34:41.222441 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.222036 [mod=DVR, lvl=INFO] [tid=6569] PlayContext::setThrottleEnable enable=1 ocapri_log.txt:Oct 24 10:34:41.223971 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.222482 [mod=DVR, lvl=INFO] [tid=6569] setting playback rate to 1.000000 ocapri_log.txt:Oct 24 10:34:41.224954 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.224910 [mod=RMFBASE, lvl=INFO] [tid=6569] gstbasesrc.c[1328]-gst_base_src_do_seek :: seeking: time segment start=0:00:00.000000000, offset=0:00:00.000000000, stop=99:99:99.999999999, rate=1.000000, applied_rate=1.000000, flags=0x09, time=0:00:00.000000000, base=0:00:00.000000000, position 0:00:00.000000000, duration 99:99:99.999999999 ocapri_log.txt:Oct 24 10:34:41.225087 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.225069 [mod=DVR, lvl=INFO] [tid=6569] PlayContext::getOffsetForStreamTime: time 0 ns ocapri_log.txt:Oct 24 10:34:41.225657 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.225639 [mod=DVR, lvl=INFO] [tid=6569] PlayContext::getOffsetForStreamTime: time 0 base PTS 164219ce0 pts 164219ce0 offset d080 ocapri_log.txt:Oct 24 10:34:41.225746 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.225730 [mod=DVR, lvl=INFO] [tid=6569] setting playback rate to 1.000000 ocapri_log.txt:Oct 24 10:34:41.226078 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.225912 [mod=RMFBASE, lvl=WARN] [tid=2820] Unknown bus call (reset-time) occurred ocapri_log.txt:Oct 24 10:34:41.226490 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.226080 [mod=DVR, lvl=INFO] [tid=6569] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 19 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:41.226906 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.226500 [mod=DVR, lvl=INFO] [tid=6569] PlayContext::notifyPaused: 0x9a8c8000 release segment name 1508835613284 while paused ocapri_log.txt:Oct 24 10:34:41.227313 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.226601 [mod=DVR, lvl=INFO] [tid=6572] dvrsrc.c[490]-gst_dvr_src_negotiate :: gst_dvr_src_negotiate: setting video/vnd.dlna.mpeg-tts mimetype ocapri_log.txt:Oct 24 10:34:41.227732 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.226913 [mod=DVR, lvl=INFO] [tid=6569] PlayContext::notifyPaused: exit ocapri_log.txt:Oct 24 10:34:41.228214 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.227564 [mod=DVR, lvl=INFO] [tid=6572] aesdecrypt.c[200]-gst_aesdecrypt_set_caps :: aesdecrypt_set_caps: packetSize=192 ocapri_log.txt:Oct 24 10:34:41.228623 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.227744 [mod=DVR, lvl=INFO] [tid=6569] dvrsrc.c[664]-gst_dvr_src_change_state :: gst_dvr_src_change_state: PLAYING_TO_PAUSED ocapri_log.txt:Oct 24 10:34:41.229061 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.228642 [mod=DVR, lvl=INFO] [tid=6569] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 19 ret 1 ocapri_log.txt:Oct 24 10:34:41.229473 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.228735 [mod=DVR, lvl=INFO] [tid=6572] PlayContext::findNextPCR: scan for next PCR from offset 155d00 ocapri_log.txt:Oct 24 10:34:41.229882 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.229169 [mod=RMFBASE, lvl=INFO] [tid=2820] onStateChange 1965 Iterator is 9a882768 size is 1 ocapri_log.txt:Oct 24 10:34:41.230300 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.229533 [mod=HN, lvl=INFO] [tid=6569] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PAUSED to PLAYING ocapri_log.txt:Oct 24 10:34:41.230710 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.229897 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PAUSED state ocapri_log.txt:Oct 24 10:34:41.231134 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.230435 [mod=DVR, lvl=INFO] [tid=6569] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 28 ocapri_log.txt:Oct 24 10:34:41.231540 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.231156 [mod=DVR, lvl=INFO] [tid=6569] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 28 calling parent ocapri_log.txt:Oct 24 10:34:41.231955 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.231563 [mod=DVR, lvl=INFO] [tid=6569] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 28 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:41.232360 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.231970 [mod=DVR, lvl=INFO] [tid=6569] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 28 ret 1 ocapri_log.txt:Oct 24 10:34:41.233815 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.232430 [mod=RMFBASE, lvl=ERROR] [tid=6569] Changed state to PLAYING ocapri_log.txt:Oct 24 10:34:41.234237 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.232440 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PLAYING state ocapri_log.txt:Oct 24 10:34:41.234645 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.233825 [mod=MS, lvl=INFO] [tid=6569] [stream:906] play_success ocapri_log.txt:Oct 24 10:34:41.235063 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.234653 [mod=MS, lvl=NOTICE] [tid=6569] [RMFMediaStreamer::stream][stream:912] Streaming started source id dvr://local/2017102416#0 : 25874 20170915 ocapri_log.txt:Oct 24 10:34:41.235473 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.235070 [mod=MS, lvl=NOTICE] [tid=6569] [stream:914] Streaming started source id dvr://local/2017102416#0 : 25874 ocapri_log.txt:Oct 24 10:34:41.235948 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.235484 [mod=MS, lvl=INFO] [tid=6569] [serviceSelection:1714] EventQ: 0x9ab1bd20, Semaphore: 0x9a87c760 ocapri_log.txt:Oct 24 10:34:41.236364 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.235955 [mod=MS, lvl=INFO] [tid=6569] [serviceSelection: 36668] ocapri_log.txt:Oct 24 10:34:41.253790 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.253731 [mod=DVR, lvl=INFO] [tid=6572] PlayContext::findNextPCR: found PCR c62c9160 at offset 58cec0 ocapri_log.txt:Oct 24 10:34:41.254130 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.254101 [mod=RMFBASE, lvl=INFO] [tid=6572] gstbasesrc.c[2828]-gst_base_src_loop :: marking pending DISCONT ocapri_log.txt:Oct 24 10:34:41.254246 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.254210 [mod=HN, lvl=INFO] [tid=6571] gsthttpsink.c[499]-gst_http_sink_render :: httpsink::Received first packet[98304]: ocapri_log.txt:Oct 24 10:34:41.260406 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.260350 [mod=HN, lvl=INFO] [tid=6571] gsthttpsink.c[618]-gst_http_sink_render :: Source Type: DVR_SRC packet[1] Source Id: dvr://local/2017102416#0 sent [98304 bytes] on ConnId [70] ocapri_log.txt:Oct 24 10:34:41.326448 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.326392 [mod=HN, lvl=INFO] [tid=6571] gsthttpsink.c[618]-gst_http_sink_render :: Source Type: DVR_SRC packet[5] Source Id: dvr://local/2017102416#0 sent [98304 bytes] on ConnId [70] ocapri_log.txt:Oct 24 10:34:41.747294 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.747212 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[323]-gst_http_sink_set_property :: HTTP_OBJ socket 0xffffffff ocapri_log.txt:Oct 24 10:34:41.747393 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.747372 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[323]-gst_http_sink_set_property :: HTTP_OBJ socket 0xffffffff ocapri_log.txt:Oct 24 10:34:41.747466 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.747449 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[323]-gst_http_sink_set_property :: HTTP_OBJ socket 0xffffffff ocapri_log.txt:Oct 24 10:34:41.943284 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.943238 [mod=DVR, lvl=INFO] [tid=6564] switch to next mpeg chunk 0x12a1c0 with offset 2000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:34:41.943313 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.943297 [mod=DVR, lvl=INFO] [tid=6564] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000002000000.mpg ocapri_log.txt:Oct 24 10:34:41.944277 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.944248 [mod=DVR, lvl=INFO] [tid=6568] switch to next mpeg chunk 0x12a1c0 with offset 2000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:34:41.944300 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.944284 [mod=DVR, lvl=INFO] [tid=6568] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000002000000.mpg ocapri_log.txt:Oct 24 10:34:41.945737 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.945717 [mod=DVR, lvl=INFO] [tid=6552] switch to next mpeg chunk 0x12a1c0 with offset 2000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:34:41.945762 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:41.945746 [mod=DVR, lvl=INFO] [tid=6552] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000002000000.mpg ocapri_log.txt:Oct 24 10:34:42.183180 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.183121 [mod=HN, lvl=INFO] [tid=6489] ConnId [-1] Client IP [192.168.100.100] uri [dvr://local/2017102416#0] Bytes sent [103.67 K] Bit Rate [82.93 Kbps] ocapri_log.txt:Oct 24 10:34:42.747778 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.747690 [mod=MS, lvl=INFO] [tid=3209] [run:2749] Cleaning up inactive session ocapri_log.txt:Oct 24 10:34:42.747830 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.747810 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::removeEventHandler :: 9ab1b6e8 :: Size : 1 ocapri_log.txt:Oct 24 10:34:42.747918 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.747901 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourceBase::stop() :: Calling m_pimpl->stop() ocapri_log.txt:Oct 24 10:34:42.747945 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.747929 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:42.748176 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748159 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PLAYING to PAUSED ocapri_log.txt:Oct 24 10:34:42.748387 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748370 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 35 ocapri_log.txt:Oct 24 10:34:42.748419 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748404 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 35 calling parent ocapri_log.txt:Oct 24 10:34:42.748456 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748441 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 35 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:42.748480 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748466 [mod=DVR, lvl=INFO] [tid=3209] PlayContext::notifyPaused: 0x9ab3b800 release segment name 1508835613284 while paused ocapri_log.txt:Oct 24 10:34:42.748502 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748487 [mod=DVR, lvl=INFO] [tid=3209] PlayContext::notifyPaused: exit ocapri_log.txt:Oct 24 10:34:42.748527 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748512 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[664]-gst_dvr_src_change_state :: gst_dvr_src_change_state: PLAYING_TO_PAUSED ocapri_log.txt:Oct 24 10:34:42.753470 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748540 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 35 ret 1 ocapri_log.txt:Oct 24 10:34:42.753608 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.753583 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PAUSED state ocapri_log.txt:Oct 24 10:34:42.753731 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.753713 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PAUSED to READY ocapri_log.txt:Oct 24 10:34:42.754312 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.754293 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 26 ocapri_log.txt:Oct 24 10:34:42.754345 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.754329 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 26 calling parent ocapri_log.txt:Oct 24 10:34:42.766975 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.766908 [mod=RMFBASE, lvl=INFO] [tid=6552] gstbasesrc.c[2841]-gst_base_src_loop :: pausing after gst_pad_push() = flushing ocapri_log.txt:Oct 24 10:34:42.767415 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.767385 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 26 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:42.767446 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.767430 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 26 ret 1 ocapri_log.txt:Oct 24 10:34:42.767568 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.767550 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to READY ocapri_log.txt:Oct 24 10:34:42.767583 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.767563 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to READY state ocapri_log.txt:Oct 24 10:34:42.767978 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.767958 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from READY to NULL ocapri_log.txt:Oct 24 10:34:42.768206 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768188 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:42.768294 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768277 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to READY ocapri_log.txt:Oct 24 10:34:42.768320 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768304 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(NULL) ocapri_log.txt:Oct 24 10:34:42.768457 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768440 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 17 ocapri_log.txt:Oct 24 10:34:42.768485 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768469 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 17 calling parent ocapri_log.txt:Oct 24 10:34:42.768522 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768507 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 17 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:42.769210 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768533 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[669]-gst_dvr_src_change_state :: gst_dvr_src_change_state: READY_TO_NULL ocapri_log.txt:Oct 24 10:34:42.769686 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.769235 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 17 ret 1 ocapri_log.txt:Oct 24 10:34:42.770740 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.769809 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to NULL ocapri_log.txt:Oct 24 10:34:42.771747 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.771110 [mod=RMFBASE, lvl=INFO] [tid=3209] ~RMFMediaSinkPrivate: ref_count: 1 ocapri_log.txt:Oct 24 10:34:42.772509 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.772036 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(NULL) ocapri_log.txt:Oct 24 10:34:42.773056 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.772598 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to NULL ocapri_log.txt:Oct 24 10:34:42.773508 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.773067 [mod=RMFBASE, lvl=INFO] [tid=3209] Pipeline gst_element_get_state success: State = 1, Pending = 0 ocapri_log.txt:Oct 24 10:34:42.774011 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.773552 [mod=RMFBASE, lvl=INFO] [tid=3209] m_pipeline ref_count=1 bus=0xee548 m_bus_event_source_id=130 ocapri_log.txt:Oct 24 10:34:42.774901 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.774151 [mod=RMFBASE, lvl=INFO] [tid=3209] g_source_remove signaled ocapri_log.txt:Oct 24 10:34:42.775862 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.775252 [mod=MS, lvl=INFO] [tid=3209] RMFMediaStreamer::destroySource() [SOURCE] deleting pSource= 0x9ab1f248 ocapri_log.txt:Oct 24 10:34:42.776379 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.775897 [mod=DVR, lvl=INFO] [tid=3209] DVRSource::~DVRSource() [SOURCE] DVRSource destructor= 0x9ab1f248 ocapri_log.txt:Oct 24 10:34:42.776896 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.776448 [mod=MS, lvl=INFO] [tid=3209] RMFMediaStreamer::destroySource() [SOURCE] deleted pSource= 0x9ab1f248 ocapri_log.txt:Oct 24 10:34:42.777349 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.776909 [mod=MS, lvl=NOTICE] [tid=3209] [close:1216] Streaming stopped source id dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:42.777800 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.777366 [mod=MS, lvl=INFO] [tid=3209] destroySession : Releasing semaphore ocapri_log.txt:Oct 24 10:34:42.778439 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.777830 [mod=MS, lvl=INFO] [tid=3209] [~RMFMediaStreamer:270] Event received, signal to destroy the MediaStreamer object ocapri_log.txt:Oct 24 10:34:42.779303 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.778750 [mod=MS, lvl=INFO] [tid=3209] [run:2749] Cleaning up inactive session ocapri_log.txt:Oct 24 10:34:42.779878 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.779327 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::removeEventHandler :: 9a8f1f48 :: Size : 1 ocapri_log.txt:Oct 24 10:34:42.780339 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.779902 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourceBase::stop() :: Calling m_pimpl->stop() ocapri_log.txt:Oct 24 10:34:42.780815 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.780353 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:42.781410 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.780943 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PLAYING to PAUSED ocapri_log.txt:Oct 24 10:34:42.782043 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.781600 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 35 ocapri_log.txt:Oct 24 10:34:42.782497 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.782063 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 35 calling parent ocapri_log.txt:Oct 24 10:34:42.783048 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.782524 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 35 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:42.783663 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.783073 [mod=DVR, lvl=INFO] [tid=3209] PlayContext::notifyPaused: 0x9a404800 release segment name 1508835613284 while paused ocapri_log.txt:Oct 24 10:34:42.784121 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.783672 [mod=DVR, lvl=INFO] [tid=3209] PlayContext::notifyPaused: exit ocapri_log.txt:Oct 24 10:34:42.784569 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.784136 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[664]-gst_dvr_src_change_state :: gst_dvr_src_change_state: PLAYING_TO_PAUSED ocapri_log.txt:Oct 24 10:34:42.785033 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.784586 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 35 ret 1 ocapri_log.txt:Oct 24 10:34:42.785651 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.785191 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PAUSED state ocapri_log.txt:Oct 24 10:34:42.786158 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.785776 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PAUSED to READY ocapri_log.txt:Oct 24 10:34:42.787022 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.786579 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 26 ocapri_log.txt:Oct 24 10:34:42.787617 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.786837 [mod=RMFBASE, lvl=INFO] [tid=6568] gstbasesrc.c[2841]-gst_base_src_loop :: pausing after gst_pad_push() = flushing ocapri_log.txt:Oct 24 10:34:42.788072 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.787043 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 26 calling parent ocapri_log.txt:Oct 24 10:34:42.788808 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.788358 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 26 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:42.789273 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.788825 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 26 ret 1 ocapri_log.txt:Oct 24 10:34:42.789793 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.789354 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to READY ocapri_log.txt:Oct 24 10:34:42.790238 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.789363 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to READY state ocapri_log.txt:Oct 24 10:34:42.790932 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.790430 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from READY to NULL ocapri_log.txt:Oct 24 10:34:42.791854 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.791120 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:42.792408 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.791964 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to READY ocapri_log.txt:Oct 24 10:34:42.792855 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.792415 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(NULL) ocapri_log.txt:Oct 24 10:34:42.793432 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.792991 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 17 ocapri_log.txt:Oct 24 10:34:42.793892 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.793447 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 17 calling parent ocapri_log.txt:Oct 24 10:34:42.794366 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.793919 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 17 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:42.795016 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.794380 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[669]-gst_dvr_src_change_state :: gst_dvr_src_change_state: READY_TO_NULL ocapri_log.txt:Oct 24 10:34:42.795582 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.795037 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 17 ret 1 ocapri_log.txt:Oct 24 10:34:42.796151 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.795676 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to NULL ocapri_log.txt:Oct 24 10:34:42.796741 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.796326 [mod=RMFBASE, lvl=INFO] [tid=3209] ~RMFMediaSinkPrivate: ref_count: 1 ocapri_log.txt:Oct 24 10:34:42.797342 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.796900 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(NULL) ocapri_log.txt:Oct 24 10:34:42.797855 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.797409 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to NULL ocapri_log.txt:Oct 24 10:34:42.798310 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.797865 [mod=RMFBASE, lvl=INFO] [tid=3209] Pipeline gst_element_get_state success: State = 1, Pending = 0 ocapri_log.txt:Oct 24 10:34:42.798850 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.798350 [mod=RMFBASE, lvl=INFO] [tid=3209] m_pipeline ref_count=1 bus=0x9ab28398 m_bus_event_source_id=132 ocapri_log.txt:Oct 24 10:34:42.799624 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.799048 [mod=RMFBASE, lvl=INFO] [tid=3209] g_source_remove signaled ocapri_log.txt:Oct 24 10:34:42.800326 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.799866 [mod=MS, lvl=INFO] [tid=3209] RMFMediaStreamer::destroySource() [SOURCE] deleting pSource= 0x9a873f78 ocapri_log.txt:Oct 24 10:34:42.800775 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.800336 [mod=DVR, lvl=INFO] [tid=3209] DVRSource::~DVRSource() [SOURCE] DVRSource destructor= 0x9a873f78 ocapri_log.txt:Oct 24 10:34:42.801284 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.800789 [mod=MS, lvl=INFO] [tid=3209] RMFMediaStreamer::destroySource() [SOURCE] deleted pSource= 0x9a873f78 ocapri_log.txt:Oct 24 10:34:42.801734 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.801294 [mod=MS, lvl=NOTICE] [tid=3209] [close:1216] Streaming stopped source id dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:42.802188 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.801743 [mod=MS, lvl=INFO] [tid=3209] destroySession : Releasing semaphore ocapri_log.txt:Oct 24 10:34:42.802634 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.802198 [mod=MS, lvl=INFO] [tid=3209] [~RMFMediaStreamer:270] Event received, signal to destroy the MediaStreamer object ocapri_log.txt:Oct 24 10:34:42.183180 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.183121 [mod=HN, lvl=INFO] [tid=6489] ConnId [-1] Client IP [192.168.100.100] uri [dvr://local/2017102416#0] Bytes sent [103.67 K] Bit Rate [82.93 Kbps] ocapri_log.txt:Oct 24 10:34:42.747778 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.747690 [mod=MS, lvl=INFO] [tid=3209] [run:2749] Cleaning up inactive session ocapri_log.txt:Oct 24 10:34:42.747830 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.747810 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::removeEventHandler :: 9ab1b6e8 :: Size : 1 ocapri_log.txt:Oct 24 10:34:42.747918 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.747901 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourceBase::stop() :: Calling m_pimpl->stop() ocapri_log.txt:Oct 24 10:34:42.747945 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.747929 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:42.748176 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748159 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PLAYING to PAUSED ocapri_log.txt:Oct 24 10:34:42.748387 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748370 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 35 ocapri_log.txt:Oct 24 10:34:42.748419 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748404 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 35 calling parent ocapri_log.txt:Oct 24 10:34:42.748456 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748441 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 35 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:42.748480 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748466 [mod=DVR, lvl=INFO] [tid=3209] PlayContext::notifyPaused: 0x9ab3b800 release segment name 1508835613284 while paused ocapri_log.txt:Oct 24 10:34:42.748502 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748487 [mod=DVR, lvl=INFO] [tid=3209] PlayContext::notifyPaused: exit ocapri_log.txt:Oct 24 10:34:42.748527 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748512 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[664]-gst_dvr_src_change_state :: gst_dvr_src_change_state: PLAYING_TO_PAUSED ocapri_log.txt:Oct 24 10:34:42.753470 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.748540 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 35 ret 1 ocapri_log.txt:Oct 24 10:34:42.753608 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.753583 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PAUSED state ocapri_log.txt:Oct 24 10:34:42.753731 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.753713 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PAUSED to READY ocapri_log.txt:Oct 24 10:34:42.754312 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.754293 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 26 ocapri_log.txt:Oct 24 10:34:42.754345 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.754329 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 26 calling parent ocapri_log.txt:Oct 24 10:34:42.766975 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.766908 [mod=RMFBASE, lvl=INFO] [tid=6552] gstbasesrc.c[2841]-gst_base_src_loop :: pausing after gst_pad_push() = flushing ocapri_log.txt:Oct 24 10:34:42.767415 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.767385 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 26 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:42.767446 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.767430 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 26 ret 1 ocapri_log.txt:Oct 24 10:34:42.767568 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.767550 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to READY ocapri_log.txt:Oct 24 10:34:42.767583 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.767563 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to READY state ocapri_log.txt:Oct 24 10:34:42.767978 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.767958 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from READY to NULL ocapri_log.txt:Oct 24 10:34:42.768206 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768188 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:42.768294 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768277 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to READY ocapri_log.txt:Oct 24 10:34:42.768320 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768304 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(NULL) ocapri_log.txt:Oct 24 10:34:42.768457 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768440 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 17 ocapri_log.txt:Oct 24 10:34:42.768485 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768469 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 17 calling parent ocapri_log.txt:Oct 24 10:34:42.768522 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768507 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 17 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:42.769210 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.768533 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[669]-gst_dvr_src_change_state :: gst_dvr_src_change_state: READY_TO_NULL ocapri_log.txt:Oct 24 10:34:42.769686 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.769235 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 17 ret 1 ocapri_log.txt:Oct 24 10:34:42.770740 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.769809 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to NULL ocapri_log.txt:Oct 24 10:34:42.771747 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.771110 [mod=RMFBASE, lvl=INFO] [tid=3209] ~RMFMediaSinkPrivate: ref_count: 1 ocapri_log.txt:Oct 24 10:34:42.772509 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.772036 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(NULL) ocapri_log.txt:Oct 24 10:34:42.773056 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.772598 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to NULL ocapri_log.txt:Oct 24 10:34:42.773508 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.773067 [mod=RMFBASE, lvl=INFO] [tid=3209] Pipeline gst_element_get_state success: State = 1, Pending = 0 ocapri_log.txt:Oct 24 10:34:42.774011 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.773552 [mod=RMFBASE, lvl=INFO] [tid=3209] m_pipeline ref_count=1 bus=0xee548 m_bus_event_source_id=130 ocapri_log.txt:Oct 24 10:34:42.774901 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.774151 [mod=RMFBASE, lvl=INFO] [tid=3209] g_source_remove signaled ocapri_log.txt:Oct 24 10:34:42.775862 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.775252 [mod=MS, lvl=INFO] [tid=3209] RMFMediaStreamer::destroySource() [SOURCE] deleting pSource= 0x9ab1f248 ocapri_log.txt:Oct 24 10:34:42.776379 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.775897 [mod=DVR, lvl=INFO] [tid=3209] DVRSource::~DVRSource() [SOURCE] DVRSource destructor= 0x9ab1f248 ocapri_log.txt:Oct 24 10:34:42.776896 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.776448 [mod=MS, lvl=INFO] [tid=3209] RMFMediaStreamer::destroySource() [SOURCE] deleted pSource= 0x9ab1f248 ocapri_log.txt:Oct 24 10:34:42.777349 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.776909 [mod=MS, lvl=NOTICE] [tid=3209] [close:1216] Streaming stopped source id dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:42.777800 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.777366 [mod=MS, lvl=INFO] [tid=3209] destroySession : Releasing semaphore ocapri_log.txt:Oct 24 10:34:42.778439 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.777830 [mod=MS, lvl=INFO] [tid=3209] [~RMFMediaStreamer:270] Event received, signal to destroy the MediaStreamer object ocapri_log.txt:Oct 24 10:34:42.779303 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.778750 [mod=MS, lvl=INFO] [tid=3209] [run:2749] Cleaning up inactive session ocapri_log.txt:Oct 24 10:34:42.779878 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.779327 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::removeEventHandler :: 9a8f1f48 :: Size : 1 ocapri_log.txt:Oct 24 10:34:42.780339 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.779902 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourceBase::stop() :: Calling m_pimpl->stop() ocapri_log.txt:Oct 24 10:34:42.780815 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.780353 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:42.781410 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.780943 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PLAYING to PAUSED ocapri_log.txt:Oct 24 10:34:42.782043 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.781600 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 35 ocapri_log.txt:Oct 24 10:34:42.782497 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.782063 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 35 calling parent ocapri_log.txt:Oct 24 10:34:42.783048 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.782524 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 35 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:42.783663 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.783073 [mod=DVR, lvl=INFO] [tid=3209] PlayContext::notifyPaused: 0x9a404800 release segment name 1508835613284 while paused ocapri_log.txt:Oct 24 10:34:42.784121 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.783672 [mod=DVR, lvl=INFO] [tid=3209] PlayContext::notifyPaused: exit ocapri_log.txt:Oct 24 10:34:42.784569 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.784136 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[664]-gst_dvr_src_change_state :: gst_dvr_src_change_state: PLAYING_TO_PAUSED ocapri_log.txt:Oct 24 10:34:42.785033 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.784586 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 35 ret 1 ocapri_log.txt:Oct 24 10:34:42.785651 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.785191 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PAUSED state ocapri_log.txt:Oct 24 10:34:42.786158 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.785776 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PAUSED to READY ocapri_log.txt:Oct 24 10:34:42.787022 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.786579 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 26 ocapri_log.txt:Oct 24 10:34:42.787617 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.786837 [mod=RMFBASE, lvl=INFO] [tid=6568] gstbasesrc.c[2841]-gst_base_src_loop :: pausing after gst_pad_push() = flushing ocapri_log.txt:Oct 24 10:34:42.788072 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.787043 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 26 calling parent ocapri_log.txt:Oct 24 10:34:42.788808 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.788358 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 26 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:42.789273 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.788825 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 26 ret 1 ocapri_log.txt:Oct 24 10:34:42.789793 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.789354 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to READY ocapri_log.txt:Oct 24 10:34:42.790238 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.789363 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to READY state ocapri_log.txt:Oct 24 10:34:42.790932 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.790430 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from READY to NULL ocapri_log.txt:Oct 24 10:34:42.791854 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.791120 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:42.792408 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.791964 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to READY ocapri_log.txt:Oct 24 10:34:42.792855 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.792415 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(NULL) ocapri_log.txt:Oct 24 10:34:42.793432 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.792991 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 17 ocapri_log.txt:Oct 24 10:34:42.793892 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.793447 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 17 calling parent ocapri_log.txt:Oct 24 10:34:42.794366 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.793919 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 17 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:42.795016 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.794380 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[669]-gst_dvr_src_change_state :: gst_dvr_src_change_state: READY_TO_NULL ocapri_log.txt:Oct 24 10:34:42.795582 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.795037 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 17 ret 1 ocapri_log.txt:Oct 24 10:34:42.796151 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.795676 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to NULL ocapri_log.txt:Oct 24 10:34:42.796741 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.796326 [mod=RMFBASE, lvl=INFO] [tid=3209] ~RMFMediaSinkPrivate: ref_count: 1 ocapri_log.txt:Oct 24 10:34:42.797342 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.796900 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(NULL) ocapri_log.txt:Oct 24 10:34:42.797855 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.797409 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to NULL ocapri_log.txt:Oct 24 10:34:42.798310 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.797865 [mod=RMFBASE, lvl=INFO] [tid=3209] Pipeline gst_element_get_state success: State = 1, Pending = 0 ocapri_log.txt:Oct 24 10:34:42.798850 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.798350 [mod=RMFBASE, lvl=INFO] [tid=3209] m_pipeline ref_count=1 bus=0x9ab28398 m_bus_event_source_id=132 ocapri_log.txt:Oct 24 10:34:42.799624 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.799048 [mod=RMFBASE, lvl=INFO] [tid=3209] g_source_remove signaled ocapri_log.txt:Oct 24 10:34:42.800326 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.799866 [mod=MS, lvl=INFO] [tid=3209] RMFMediaStreamer::destroySource() [SOURCE] deleting pSource= 0x9a873f78 ocapri_log.txt:Oct 24 10:34:42.800775 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.800336 [mod=DVR, lvl=INFO] [tid=3209] DVRSource::~DVRSource() [SOURCE] DVRSource destructor= 0x9a873f78 ocapri_log.txt:Oct 24 10:34:42.801284 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.800789 [mod=MS, lvl=INFO] [tid=3209] RMFMediaStreamer::destroySource() [SOURCE] deleted pSource= 0x9a873f78 ocapri_log.txt:Oct 24 10:34:42.801734 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.801294 [mod=MS, lvl=NOTICE] [tid=3209] [close:1216] Streaming stopped source id dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:42.802188 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.801743 [mod=MS, lvl=INFO] [tid=3209] destroySession : Releasing semaphore ocapri_log.txt:Oct 24 10:34:42.802634 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:42.802198 [mod=MS, lvl=INFO] [tid=3209] [~RMFMediaStreamer:270] Event received, signal to destroy the MediaStreamer object ocapri_log.txt:Oct 24 10:34:43.330067 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.329996 [mod=DVR, lvl=INFO] [tid=6564] switch to next mpeg chunk 0x126600 with offset 4000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:34:43.330098 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.330081 [mod=DVR, lvl=INFO] [tid=6564] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000004000000.mpg ocapri_log.txt:Oct 24 10:34:43.803076 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.803020 [mod=MS, lvl=INFO] [tid=3209] [run:2749] Cleaning up inactive session ocapri_log.txt:Oct 24 10:34:43.803115 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.803098 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::removeEventHandler :: 9a8686c0 :: Size : 1 ocapri_log.txt:Oct 24 10:34:43.803140 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.803125 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourceBase::stop() :: Calling m_pimpl->stop() ocapri_log.txt:Oct 24 10:34:43.803162 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.803148 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:43.803318 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.803300 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PLAYING to PAUSED ocapri_log.txt:Oct 24 10:34:43.803516 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.803499 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 35 ocapri_log.txt:Oct 24 10:34:43.803547 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.803532 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 35 calling parent ocapri_log.txt:Oct 24 10:34:43.803585 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.803570 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 35 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:43.803609 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.803594 [mod=DVR, lvl=INFO] [tid=3209] PlayContext::notifyPaused: 0x9a875800 release segment name 1508835613284 while paused ocapri_log.txt:Oct 24 10:34:43.803629 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.803615 [mod=DVR, lvl=INFO] [tid=3209] PlayContext::notifyPaused: exit ocapri_log.txt:Oct 24 10:34:43.803654 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.803639 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[664]-gst_dvr_src_change_state :: gst_dvr_src_change_state: PLAYING_TO_PAUSED ocapri_log.txt:Oct 24 10:34:43.808653 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.803668 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 35 ret 1 ocapri_log.txt:Oct 24 10:34:43.808898 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.808846 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PAUSED state ocapri_log.txt:Oct 24 10:34:43.809699 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.809673 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PAUSED to READY ocapri_log.txt:Oct 24 10:34:43.810215 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.810187 [mod=RMFBASE, lvl=INFO] [tid=6564] gstbasesrc.c[2841]-gst_base_src_loop :: pausing after gst_pad_push() = flushing ocapri_log.txt:Oct 24 10:34:43.810249 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.810231 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 26 ocapri_log.txt:Oct 24 10:34:43.810281 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.810266 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 26 calling parent ocapri_log.txt:Oct 24 10:34:43.810671 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.810652 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 26 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:43.810701 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.810685 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 26 ret 1 ocapri_log.txt:Oct 24 10:34:43.810797 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.810779 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to READY ocapri_log.txt:Oct 24 10:34:43.810813 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.810791 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to READY state ocapri_log.txt:Oct 24 10:34:43.811027 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.811008 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from READY to NULL ocapri_log.txt:Oct 24 10:34:43.811218 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.811201 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:34:43.811302 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.811285 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to READY ocapri_log.txt:Oct 24 10:34:43.811481 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.811307 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(NULL) ocapri_log.txt:Oct 24 10:34:43.812113 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.811599 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 17 ocapri_log.txt:Oct 24 10:34:43.812586 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.812128 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 17 calling parent ocapri_log.txt:Oct 24 10:34:43.813080 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.812611 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 17 back from parent ret 1 ocapri_log.txt:Oct 24 10:34:43.813540 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.813093 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[669]-gst_dvr_src_change_state :: gst_dvr_src_change_state: READY_TO_NULL ocapri_log.txt:Oct 24 10:34:43.814022 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.813557 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 17 ret 1 ocapri_log.txt:Oct 24 10:34:43.814549 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.814102 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to NULL ocapri_log.txt:Oct 24 10:34:43.815054 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.814744 [mod=RMFBASE, lvl=INFO] [tid=3209] ~RMFMediaSinkPrivate: ref_count: 1 ocapri_log.txt:Oct 24 10:34:43.815490 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.815240 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(NULL) ocapri_log.txt:Oct 24 10:34:43.815918 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.815555 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to NULL ocapri_log.txt:Oct 24 10:34:43.816336 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.815928 [mod=RMFBASE, lvl=INFO] [tid=3209] Pipeline gst_element_get_state success: State = 1, Pending = 0 ocapri_log.txt:Oct 24 10:34:43.816759 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.816376 [mod=RMFBASE, lvl=INFO] [tid=3209] m_pipeline ref_count=1 bus=0xee788 m_bus_event_source_id=131 ocapri_log.txt:Oct 24 10:34:43.817226 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.816863 [mod=RMFBASE, lvl=INFO] [tid=3209] g_source_remove signaled ocapri_log.txt:Oct 24 10:34:43.817680 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.817440 [mod=MS, lvl=INFO] [tid=3209] RMFMediaStreamer::destroySource() [SOURCE] deleting pSource= 0x9ab38bd8 ocapri_log.txt:Oct 24 10:34:43.818121 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.817689 [mod=DVR, lvl=INFO] [tid=3209] DVRSource::~DVRSource() [SOURCE] DVRSource destructor= 0x9ab38bd8 ocapri_log.txt:Oct 24 10:34:43.818541 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.818132 [mod=MS, lvl=INFO] [tid=3209] RMFMediaStreamer::destroySource() [SOURCE] deleted pSource= 0x9ab38bd8 ocapri_log.txt:Oct 24 10:34:43.818967 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.818550 [mod=MS, lvl=NOTICE] [tid=3209] [close:1216] Streaming stopped source id dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:34:43.819450 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.818975 [mod=MS, lvl=INFO] [tid=3209] destroySession : Releasing semaphore ocapri_log.txt:Oct 24 10:34:43.819806 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:43.819461 [mod=MS, lvl=INFO] [tid=3209] [~RMFMediaStreamer:270] Event received, signal to destroy the MediaStreamer object ocapri_log.txt:Oct 24 10:34:46.208610 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:46.208553 [mod=HN, lvl=INFO] [tid=6570] ConnId [70] Client IP [192.168.100.100] uri [dvr://local/2017102416#0] Bytes sent [26.74 M] Bit Rate [21.39 Mbps] ocapri_log.txt:Oct 24 10:34:46.611512 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:46.611465 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x12a1c0 with offset 2000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:34:46.611541 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:46.611525 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000002000000.mpg ocapri_log.txt:Oct 24 10:34:51.199359 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:51.199311 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x126600 with offset 4000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:34:51.199388 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:51.199372 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000004000000.mpg ocapri_log.txt:Oct 24 10:34:51.208803 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:51.208757 [mod=HN, lvl=INFO] [tid=6570] ConnId [70] Client IP [192.168.100.100] uri [dvr://local/2017102416#0] Bytes sent [65.08 M] Bit Rate [61.35 Mbps] ocapri_log.txt:Oct 24 10:34:55.362995 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:55.362943 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x125218 with offset 6000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:34:55.363023 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:55.363007 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000006000000.mpg ocapri_log.txt:Oct 24 10:34:59.532142 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:59.532095 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x124ae8 with offset 8000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:34:59.532171 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:34:59.532155 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000008000000.mpg ocapri_log.txt:Oct 24 10:35:04.324753 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:04.324705 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x124bb8 with offset a000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:04.324781 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:04.324765 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_000000000a000000.mpg ocapri_log.txt:Oct 24 10:35:04.560986 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:04.560940 [mod=SYS, lvl=INFO] [tid=2822] =================================RMF_OSAL Process id : 2785 stats================================== ocapri_log.txt:Oct 24 10:35:04.561022 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:04.561005 [mod=SYS, lvl=INFO] [tid=2822] rmf_osal_ResStat: Thread Count = 41, Mutex Count = 0, Deadlocks = 0 ocapri_log.txt:Oct 24 10:35:04.561045 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:04.561030 [mod=SYS, lvl=INFO] [tid=2822] rmf_osal_ResStat: Heap = 18 MB, Mapped = 417 MB, Total = 461 MB, Peak Vir = 462 MB ocapri_log.txt:Oct 24 10:35:04.561066 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:04.561052 [mod=SYS, lvl=INFO] [tid=2822] rmf_osal_ResStat: Physical = 16 MB, Peak Phy = 19 MB, Pg Tb En = 700 KB ocapri_log.txt:Oct 24 10:35:08.253086 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:08.253037 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x122fe8 with offset c000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:08.253115 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:08.253098 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_000000000c000000.mpg ocapri_log.txt:Oct 24 10:35:12.169896 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:12.169840 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x1230b8 with offset e000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:12.170643 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:12.170621 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_000000000e000000.mpg ocapri_log.txt:Oct 24 10:35:16.457137 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:16.457089 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x120d00 with offset 10000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:16.457892 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:16.457862 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000010000000.mpg ocapri_log.txt:Oct 24 10:35:20.041131 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041053 [mod=REC, lvl=INFO] [tid=3495] DiskSpaceMonitor: SpaceChecker :- Going to check diskspace ocapri_log.txt:Oct 24 10:35:20.041262 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041243 [mod=REC, lvl=INFO] [tid=3495] [Config::getDefaultVolume] mountTablet=/proc/mounts 20170915 ocapri_log.txt:Oct 24 10:35:20.041529 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041509 [mod=REC, lvl=INFO] [tid=3495] /dev/sda1 on /tmp/usb type ext3 (rw,relatime,data=ordered) ocapri_log.txt:Oct 24 10:35:20.041552 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041537 [mod=REC, lvl=INFO] [tid=3495] [Config::getDefaultVolume] if (mountTable)/dev/sda1 on /tmp/usb type ext3 (rw,relatime,data=ordered) 20170915 ocapri_log.txt:Oct 24 10:35:20.041608 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041591 [mod=REC, lvl=INFO] [tid=3495] [Config::getFileSystemExt3Config] end fileSystemExt3 = [1] fileSystemExt3ConfigRead = [1] ocapri_log.txt:Oct 24 10:35:20.041633 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041617 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::checkVolume] checkVolume - Ext3 file system ocapri_log.txt:Oct 24 10:35:20.041657 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041642 [mod=REC, lvl=INFO] [tid=3495] checkVolume - Ext3 file system ocapri_log.txt:Oct 24 10:35:20.041706 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041676 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::checkVolume] 455646108672 freeSpace 10000000000 tsbReserve ocapri_log.txt:Oct 24 10:35:20.041732 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041717 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::run][run] Free space 455646108672 available; Notify Recorder 20170915 ocapri_log.txt:Oct 24 10:35:20.041131 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041053 [mod=REC, lvl=INFO] [tid=3495] DiskSpaceMonitor: SpaceChecker :- Going to check diskspace ocapri_log.txt:Oct 24 10:35:20.041262 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041243 [mod=REC, lvl=INFO] [tid=3495] [Config::getDefaultVolume] mountTablet=/proc/mounts 20170915 ocapri_log.txt:Oct 24 10:35:20.041529 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041509 [mod=REC, lvl=INFO] [tid=3495] /dev/sda1 on /tmp/usb type ext3 (rw,relatime,data=ordered) ocapri_log.txt:Oct 24 10:35:20.041552 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041537 [mod=REC, lvl=INFO] [tid=3495] [Config::getDefaultVolume] if (mountTable)/dev/sda1 on /tmp/usb type ext3 (rw,relatime,data=ordered) 20170915 ocapri_log.txt:Oct 24 10:35:20.041608 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041591 [mod=REC, lvl=INFO] [tid=3495] [Config::getFileSystemExt3Config] end fileSystemExt3 = [1] fileSystemExt3ConfigRead = [1] ocapri_log.txt:Oct 24 10:35:20.041633 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041617 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::checkVolume] checkVolume - Ext3 file system ocapri_log.txt:Oct 24 10:35:20.041657 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041642 [mod=REC, lvl=INFO] [tid=3495] checkVolume - Ext3 file system ocapri_log.txt:Oct 24 10:35:20.041706 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041676 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::checkVolume] 455646108672 freeSpace 10000000000 tsbReserve ocapri_log.txt:Oct 24 10:35:20.041732 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:20.041717 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::run][run] Free space 455646108672 available; Notify Recorder 20170915 ocapri_log.txt:Oct 24 10:35:21.209565 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:21.209515 [mod=HN, lvl=INFO] [tid=6570] ConnId [70] Client IP [192.168.100.100] uri [dvr://local/2017102416#0] Bytes sent [299.85 M] Bit Rate [62.61 Mbps] ocapri_log.txt:Oct 24 10:35:21.265955 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:21.265908 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x120748 with offset 12000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:21.265982 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:21.265966 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000012000000.mpg ocapri_log.txt:Oct 24 10:35:25.641474 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:25.641428 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x11f888 with offset 14000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:25.641502 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:25.641485 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000014000000.mpg ocapri_log.txt:Oct 24 10:35:29.419088 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:29.419041 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x11e688 with offset 16000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:29.419116 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:29.419100 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000016000000.mpg ocapri_log.txt:Oct 24 10:35:33.149696 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:33.149648 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x11d888 with offset 18000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:33.149724 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:33.149708 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000018000000.mpg ocapri_log.txt:Oct 24 10:35:37.627496 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:37.627445 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x114288 with offset 1a000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:37.627525 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:37.627508 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_000000001a000000.mpg ocapri_log.txt:Oct 24 10:35:42.186862 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:42.186815 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x112088 with offset 1c000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:42.186908 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:42.186873 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_000000001c000000.mpg ocapri_log.txt:Oct 24 10:35:46.794472 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:46.794423 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x110288 with offset 1e000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:46.794500 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:46.794484 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_000000001e000000.mpg ocapri_log.txt:Oct 24 10:35:51.210313 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:51.210256 [mod=HN, lvl=INFO] [tid=6570] ConnId [70] Client IP [192.168.100.100] uri [dvr://local/2017102416#0] Bytes sent [529.42 M] Bit Rate [61.22 Mbps] ocapri_log.txt:Oct 24 10:35:51.817229 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:51.817176 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x10f688 with offset 20000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:51.817960 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:51.817938 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000020000000.mpg ocapri_log.txt:Oct 24 10:35:51.210313 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:51.210256 [mod=HN, lvl=INFO] [tid=6570] ConnId [70] Client IP [192.168.100.100] uri [dvr://local/2017102416#0] Bytes sent [529.42 M] Bit Rate [61.22 Mbps] ocapri_log.txt:Oct 24 10:35:51.817229 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:51.817176 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x10f688 with offset 20000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:51.817960 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:51.817938 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000020000000.mpg ocapri_log.txt:Oct 24 10:35:56.452047 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:56.452002 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x120700 with offset 22000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:35:56.452813 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:35:56.452788 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000022000000.mpg ocapri_log.txt:Oct 24 10:36:00.787569 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:00.787519 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x123db0 with offset 24000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:36:00.787614 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:00.787596 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000024000000.mpg ocapri_log.txt:Oct 24 10:36:04.561390 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:04.561343 [mod=SYS, lvl=INFO] [tid=2822] =================================RMF_OSAL Process id : 2785 stats================================== ocapri_log.txt:Oct 24 10:36:04.561430 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:04.561413 [mod=SYS, lvl=INFO] [tid=2822] rmf_osal_ResStat: Thread Count = 41, Mutex Count = 0, Deadlocks = 0 ocapri_log.txt:Oct 24 10:36:04.561453 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:04.561439 [mod=SYS, lvl=INFO] [tid=2822] rmf_osal_ResStat: Heap = 18 MB, Mapped = 417 MB, Total = 461 MB, Peak Vir = 462 MB ocapri_log.txt:Oct 24 10:36:04.561475 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:04.561461 [mod=SYS, lvl=INFO] [tid=2822] rmf_osal_ResStat: Physical = 15 MB, Peak Phy = 19 MB, Pg Tb En = 700 KB ocapri_log.txt:Oct 24 10:36:06.025999 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:06.025949 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x10b688 with offset 26000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:36:06.026029 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:06.026013 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000026000000.mpg ocapri_log.txt:Oct 24 10:36:10.597477 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:10.597431 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x109588 with offset 28000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:36:10.597505 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:10.597489 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_0000000028000000.mpg ocapri_log.txt:Oct 24 10:36:15.576410 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:15.576364 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x108788 with offset 2a000000 chunk size 2000000 ocapri_log.txt:Oct 24 10:36:15.576438 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:15.576422 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_000000002a000000.mpg ocapri_log.txt:Oct 24 10:36:20.041874 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:20.041822 [mod=REC, lvl=INFO] [tid=3495] DiskSpaceMonitor: SpaceChecker :- Going to check diskspace ocapri_log.txt:Oct 24 10:36:20.041989 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:20.041964 [mod=REC, lvl=INFO] [tid=3495] [Config::getDefaultVolume] mountTablet=/proc/mounts 20170915 ocapri_log.txt:Oct 24 10:36:20.042219 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:20.042200 [mod=REC, lvl=INFO] [tid=3495] /dev/sda1 on /tmp/usb type ext3 (rw,relatime,data=ordered) ocapri_log.txt:Oct 24 10:36:20.042246 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:20.042227 [mod=REC, lvl=INFO] [tid=3495] [Config::getDefaultVolume] if (mountTable)/dev/sda1 on /tmp/usb type ext3 (rw,relatime,data=ordered) 20170915 ocapri_log.txt:Oct 24 10:36:20.042283 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:20.042267 [mod=REC, lvl=INFO] [tid=3495] [Config::getFileSystemExt3Config] end fileSystemExt3 = [1] fileSystemExt3ConfigRead = [1] ocapri_log.txt:Oct 24 10:36:20.042304 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:20.042289 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::checkVolume] checkVolume - Ext3 file system ocapri_log.txt:Oct 24 10:36:20.042325 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:20.042310 [mod=REC, lvl=INFO] [tid=3495] checkVolume - Ext3 file system ocapri_log.txt:Oct 24 10:36:20.042357 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:20.042343 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::checkVolume] 455646108672 freeSpace 10000000000 tsbReserve ocapri_log.txt:Oct 24 10:36:20.042379 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:20.042365 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::run][run] Free space 455646108672 available; Notify Recorder 20170915 ocapri_log.txt:Oct 24 10:36:20.239748 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:20.239698 [mod=DVR, lvl=INFO] [tid=6572] switch to next mpeg chunk 0x105c88 with offset 2c000000 chunk size 18c0580 ocapri_log.txt:Oct 24 10:36:20.239777 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:20.239761 [mod=DVR, lvl=INFO] [tid=6572] mpeg path /tmp/usb/media/tsb/OCAP_MSV/0/0/DEFAULT_RECORDING_VOLUME/dvr/chunks/f54e93b0-9e9e-4be5-a1ce-224371e03fc4_000000002c000000.mpg ocapri_log.txt:Oct 24 10:36:21.211006 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:21.210968 [mod=HN, lvl=INFO] [tid=6570] ConnId [70] Client IP [192.168.100.100] uri [dvr://local/2017102416#0] Bytes sent [748.95 M] Bit Rate [58.54 Mbps] ocapri_log.txt:Oct 24 10:36:23.915719 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:23.915671 [mod=DVR, lvl=INFO] [tid=6572] Retrying to get the frame length for frame 8900 retryCount 5 ocapri_log.txt:Oct 24 10:36:24.416385 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.416345 [mod=DVR, lvl=INFO] [tid=6572] Retrying to get the frame length for frame 8900 retryCount 0 ocapri_log.txt:Oct 24 10:36:24.416413 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.416397 [mod=DVR, lvl=ERROR] [tid=6572] failed to get frame length for frame 8900 currStreamOffset 2d8ae880 ocapri_log.txt:Oct 24 10:36:24.421584 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.421559 [mod=DVR, lvl=INFO] [tid=6572] dvrsrc.c[830]-gst_dvr_src_create :: gst_dvr_src_create: EoS event pushed to sink element ocapri_log.txt:Oct 24 10:36:24.421635 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.421618 [mod=RMFBASE, lvl=INFO] [tid=6572] gstbasesrc.c[2724]-gst_base_src_loop :: pausing after gst_base_src_get_range() = custom-success ocapri_log.txt:Oct 24 10:36:24.421916 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.421898 [mod=RMFBASE, lvl=INFO] [tid=2820] End of stream ocapri_log.txt:Oct 24 10:36:24.421940 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.421925 [mod=MS, lvl=INFO] [tid=2820] [complete:3809] EoS event received ocapri_log.txt:Oct 24 10:36:24.422047 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.422030 [mod=HN, lvl=INFO] [tid=2820] gsthttpsink.c[323]-gst_http_sink_set_property :: HTTP_OBJ socket 0xffffffff ocapri_log.txt:Oct 24 10:36:24.422236 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.422219 [mod=MS, lvl=INFO] [tid=2820] [sendTrailer:3670] 0 DiagnosticCode.cmst.com:Unknown ErrorCode.cmst.com:ErrorCode-003 ErrorMessage.cmst.com:Playback completed ocapri_log.txt:Oct 24 10:36:24.422352 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.422335 [mod=MS, lvl=INFO] [tid=2820] [isInProgressRecording:3612] RecordingId: 2017102416, segNum: 0 Segment state: Completed ocapri_log.txt:Oct 24 10:36:24.422453 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.422437 [mod=MS, lvl=INFO] [tid=2820] [complete:3837] Playback completed ocapri_log.txt:Oct 24 10:36:24.424739 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.424719 [mod=MS, lvl=INFO] [tid=6569] [eventHandlerAndClientNotifier:1307] RMF error events received ocapri_log.txt:Oct 24 10:36:24.424775 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.424759 [mod=MS, lvl=INFO] [tid=6569] [httpStreamingHandler:2112] No of active session present: 0 ocapri_log.txt:Oct 24 10:36:24.424796 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.424782 [mod=MS, lvl=INFO] [tid=6569] [httpStreamingHandler:2115] Streaming completed for 192.168.100.100 ocapri_log.txt:Oct 24 10:36:24.835939 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:24.835892 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[323]-gst_http_sink_set_property :: HTTP_OBJ socket 0xffffffff ocapri_log.txt:Oct 24 10:36:25.836190 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.836142 [mod=MS, lvl=INFO] [tid=3209] [run:2749] Cleaning up inactive session ocapri_log.txt:Oct 24 10:36:25.836230 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.836213 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::removeEventHandler :: 9a882768 :: Size : 1 ocapri_log.txt:Oct 24 10:36:25.836254 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.836240 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourceBase::stop() :: Calling m_pimpl->stop() ocapri_log.txt:Oct 24 10:36:25.836277 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.836262 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:36:25.836469 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.836451 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PLAYING to PAUSED ocapri_log.txt:Oct 24 10:36:25.836663 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.836646 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 35 ocapri_log.txt:Oct 24 10:36:25.836696 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.836681 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 35 calling parent ocapri_log.txt:Oct 24 10:36:25.836736 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.836720 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 35 back from parent ret 1 ocapri_log.txt:Oct 24 10:36:25.836759 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.836744 [mod=DVR, lvl=INFO] [tid=3209] PlayContext::notifyPaused: 0x9a8c8000 release segment name 1508835613284 while paused ocapri_log.txt:Oct 24 10:36:25.836780 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.836766 [mod=DVR, lvl=INFO] [tid=3209] PlayContext::notifyPaused: exit ocapri_log.txt:Oct 24 10:36:25.836805 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.836790 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[664]-gst_dvr_src_change_state :: gst_dvr_src_change_state: PLAYING_TO_PAUSED ocapri_log.txt:Oct 24 10:36:25.840456 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.836818 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 35 ret 1 ocapri_log.txt:Oct 24 10:36:25.840609 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.840586 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to PAUSED state ocapri_log.txt:Oct 24 10:36:25.840688 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.840670 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from PAUSED to READY ocapri_log.txt:Oct 24 10:36:25.843149 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.843130 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 26 ocapri_log.txt:Oct 24 10:36:25.843181 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.843165 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 26 calling parent ocapri_log.txt:Oct 24 10:36:25.843445 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.843428 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 26 back from parent ret 1 ocapri_log.txt:Oct 24 10:36:25.843476 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.843460 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 26 ret 1 ocapri_log.txt:Oct 24 10:36:25.843563 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.843547 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to READY ocapri_log.txt:Oct 24 10:36:25.843575 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.843556 [mod=RMFBASE, lvl=INFO] [tid=2820] GST Pipeline set to READY state ocapri_log.txt:Oct 24 10:36:25.843759 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.843742 [mod=HN, lvl=INFO] [tid=3209] gsthttpsink.c[170]-gst_http_sink_change_state :: changed state from READY to NULL ocapri_log.txt:Oct 24 10:36:25.843957 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.843939 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(READY) ocapri_log.txt:Oct 24 10:36:25.844039 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.844023 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to READY ocapri_log.txt:Oct 24 10:36:25.844060 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.844045 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(NULL) ocapri_log.txt:Oct 24 10:36:25.844244 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.844172 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[615]-gst_dvr_src_change_state :: gst_dvr_src_change_state: enter: transition 17 ocapri_log.txt:Oct 24 10:36:25.844717 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.844258 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[653]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 17 calling parent ocapri_log.txt:Oct 24 10:36:25.845201 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.844742 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[655]-gst_dvr_src_change_state :: gst_dvr_src_change_state: transition 17 back from parent ret 1 ocapri_log.txt:Oct 24 10:36:25.845662 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.845213 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[669]-gst_dvr_src_change_state :: gst_dvr_src_change_state: READY_TO_NULL ocapri_log.txt:Oct 24 10:36:25.846137 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.845678 [mod=DVR, lvl=INFO] [tid=3209] dvrsrc.c[674]-gst_dvr_src_change_state :: gst_dvr_src_change_state: exit: transition 17 ret 1 ocapri_log.txt:Oct 24 10:36:25.846658 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.846208 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to NULL ocapri_log.txt:Oct 24 10:36:25.847157 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.846858 [mod=RMFBASE, lvl=INFO] [tid=3209] ~RMFMediaSinkPrivate: ref_count: 1 ocapri_log.txt:Oct 24 10:36:25.847585 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.847273 [mod=RMFBASE, lvl=INFO] [tid=3209] RMFMediaSourcePrivate::setState() :: Calling gst_element_set_state(NULL) ocapri_log.txt:Oct 24 10:36:25.848015 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.847648 [mod=RMFBASE, lvl=ERROR] [tid=3209] Changed state to NULL ocapri_log.txt:Oct 24 10:36:25.848461 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.848023 [mod=RMFBASE, lvl=INFO] [tid=3209] Pipeline gst_element_get_state success: State = 1, Pending = 0 ocapri_log.txt:Oct 24 10:36:25.848901 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.848501 [mod=RMFBASE, lvl=INFO] [tid=3209] m_pipeline ref_count=1 bus=0x9ab285d8 m_bus_event_source_id=133 ocapri_log.txt:Oct 24 10:36:25.849328 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.849008 [mod=RMFBASE, lvl=INFO] [tid=3209] g_source_remove signaled ocapri_log.txt:Oct 24 10:36:25.849754 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.849541 [mod=MS, lvl=INFO] [tid=3209] RMFMediaStreamer::destroySource() [SOURCE] deleting pSource= 0x9ab38bc8 ocapri_log.txt:Oct 24 10:36:25.850192 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.849763 [mod=DVR, lvl=INFO] [tid=3209] DVRSource::~DVRSource() [SOURCE] DVRSource destructor= 0x9ab38bc8 ocapri_log.txt:Oct 24 10:36:25.850615 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.850204 [mod=MS, lvl=INFO] [tid=3209] RMFMediaStreamer::destroySource() [SOURCE] deleted pSource= 0x9ab38bc8 ocapri_log.txt:Oct 24 10:36:25.851045 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.850624 [mod=MS, lvl=NOTICE] [tid=3209] [close:1216] Streaming stopped source id dvr://local/2017102416#0 ocapri_log.txt:Oct 24 10:36:25.851472 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.851054 [mod=MS, lvl=INFO] [tid=3209] destroySession : Releasing semaphore ocapri_log.txt:Oct 24 10:36:25.851907 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:36:25.851482 [mod=MS, lvl=INFO] [tid=3209] [~RMFMediaStreamer:270] Event received, signal to destroy the MediaStreamer object ocapri_log.txt:Oct 24 10:37:04.561761 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:37:04.561717 [mod=SYS, lvl=INFO] [tid=2822] =================================RMF_OSAL Process id : 2785 stats================================== ocapri_log.txt:Oct 24 10:37:04.561790 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:37:04.561774 [mod=SYS, lvl=INFO] [tid=2822] rmf_osal_ResStat: Thread Count = 38, Mutex Count = 0, Deadlocks = 0 ocapri_log.txt:Oct 24 10:37:04.561814 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:37:04.561799 [mod=SYS, lvl=INFO] [tid=2822] rmf_osal_ResStat: Heap = 18 MB, Mapped = 417 MB, Total = 461 MB, Peak Vir = 462 MB ocapri_log.txt:Oct 24 10:37:04.561835 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:37:04.561821 [mod=SYS, lvl=INFO] [tid=2822] rmf_osal_ResStat: Physical = 16 MB, Peak Phy = 19 MB, Pg Tb En = 700 KB ocapri_log.txt:Oct 24 10:37:20.042519 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:37:20.042465 [mod=REC, lvl=INFO] [tid=3495] DiskSpaceMonitor: SpaceChecker :- Going to check diskspace ocapri_log.txt:Oct 24 10:37:20.042614 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:37:20.042596 [mod=REC, lvl=INFO] [tid=3495] [Config::getDefaultVolume] mountTablet=/proc/mounts 20170915 ocapri_log.txt:Oct 24 10:37:20.042841 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:37:20.042821 [mod=REC, lvl=INFO] [tid=3495] /dev/sda1 on /tmp/usb type ext3 (rw,relatime,data=ordered) ocapri_log.txt:Oct 24 10:37:20.042863 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:37:20.042848 [mod=REC, lvl=INFO] [tid=3495] [Config::getDefaultVolume] if (mountTable)/dev/sda1 on /tmp/usb type ext3 (rw,relatime,data=ordered) 20170915 ocapri_log.txt:Oct 24 10:37:20.042915 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:37:20.042898 [mod=REC, lvl=INFO] [tid=3495] [Config::getFileSystemExt3Config] end fileSystemExt3 = [1] fileSystemExt3ConfigRead = [1] ocapri_log.txt:Oct 24 10:37:20.042937 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:37:20.042922 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::checkVolume] checkVolume - Ext3 file system ocapri_log.txt:Oct 24 10:37:20.042957 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:37:20.042943 [mod=REC, lvl=INFO] [tid=3495] checkVolume - Ext3 file system ocapri_log.txt:Oct 24 10:37:20.042989 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:37:20.042974 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::checkVolume] 455646108672 freeSpace 10000000000 tsbReserve ocapri_log.txt:Oct 24 10:37:20.043010 brcm97271ip-refboard rmfStreamer[2785]: 171024-10:37:20.042996 [mod=REC, lvl=INFO] [tid=3495] [DiskSpaceMonitor::run][run] Free space 455646108672 available; Notify Recorder 20170915 top_log.txt: 2785 root 20 0 461m 15m 7800 S 4 6.8 0:02.71 rmfStreamer ro