Versions Compared

Old Version 1

changes.mady.by.user Ashraf Bhanu Kothapeta

Saved on

compared with

New Version 2

changes.mady.by.user Ashraf Bhanu Kothapeta

Saved on

Key

  • This line was added.
  • This line was removed.
  • Formatting was changed.

...

AAMP Stopping previous playback

2019 Jun 18 22:25:19.403980 pacexi5 WPEWebProcess[6625]: aamp_stop PlayerState=8
...
2019 Jun 18 22:25:19.458400 pacexi5 WPEWebProcess[6625]: Stopping Playback at Position '194938'.
2019 Jun 18 22:25:19.463187 pacexi5 WPEWebProcess[6625]: sleep interrupted!
2019 Jun 18 22:25:19.464602 pacexi5 WPEWebProcess[6625]: sleep interrupted!
2019 Jun 18 22:25:19.464679 pacexi5 WPEWebProcess[6625]: downloads disabled
2019 Jun 18 22:25:19.464770 pacexi5 WPEWebProcess[6625]: RunFetchLoop:3817: fragment collector done. track muxed
2019 Jun 18 22:25:19.465206 pacexi5 WPEWebProcess[6625]: WaitForCachedFragmentAvailable muxed aborted
2019 Jun 18 22:25:19.465232 pacexi5 WPEWebProcess[6625]: fragment injector done. track muxed
2019 Jun 18 22:25:19.465971 pacexi5 WPEWebProcess[6625]: StopWaitForPlaylistRefresh:4890 track [muxed]
2019 Jun 18 22:25:19.465997 pacexi5 WPEWebProcess[6625]: [ReleaseAll]Releasing AveDrmManager of size=1
2019 Jun 18 22:25:19.481369 pacexi5 WPEWebProcess[6625]: StopWaitForPlaylistRefresh:4890 track [muxed]
2019 Jun 18 22:25:19.482242 pacexi5 WPEWebProcess[6625]: Exit StreamAbstractionAAMP::~StreamAbstractionAAMP
2019 Jun 18 22:25:19.482282 pacexi5 WPEWebProcess[6625]: entering AAMPGstPlayer_Stop keepLastFrame 0
2019 Jun 18 22:25:19.489224 pacexi5 WPEWebProcess[6625]: AAMPGstPlayer::Stop 2075 > Remove periodicProgressCallbackIdleTaskId 34
...
2019 Jun 18 22:25:19.650315 pacexi5 WPEWebProcess[6625]: AAMPGstPlayer::Stop: Pipeline state set to null
2019 Jun 18 22:25:19.650345 pacexi5 WPEWebProcess[6625]: AAMPGstPlayer::TearDownStream: mediaType 0
2019 Jun 18 22:25:19.651235 pacexi5 WPEWebProcess[6625]: AAMPGstPlayer::TearDownStream: exit mediaType = 0
2019 Jun 18 22:25:19.651251 pacexi5 WPEWebProcess[6625]: AAMPGstPlayer::TearDownStream: mediaType 1
2019 Jun 18 22:25:19.651923 pacexi5 WPEWebProcess[6625]: AAMPGstPlayer::TearDownStream: exit mediaType = 1
2019 Jun 18 22:25:19.652145 pacexi5 WPEWebProcess[6625]: DestroyPipeline(): Destroying gstreamer pipeline
2019 Jun 18 22:25:19.656995 pacexi5 WPEWebProcess[6625]: exiting AAMPGstPlayer_Stop

New tune request reaching AAMP

2019 Jun 18 22:25:20.189964 pacexi5 WPEWebProcess[6625]: Detected ContentType 3 (LINEAR_TV)
2019 Jun 18 22:25:20.189981 pacexi5 WPEWebProcess[6625]: mLiveOffset: 15
2019 Jun 18 22:25:20.190012 pacexi5 WPEWebProcess[6625]: aamp_tune: attempt: 1 format: HLS URL: http://127.0.0.1:9080/tsb?clientId=FOG_AAMP&recordedUrl=http%3A%2F%2Fcdn-ec-pan-002-03.linear-nat-ntlk-pil.xcr.comcast.net%2FMSNBC_HD_NAT_18292_0_8348966700753924163.m3u8%3Ftrred%3Dfalse&analyticsUrl=https%3A%2F%2Fanalytics.xcal.tv%2Fcomcast%2Ffog&money=%7B%22PARENT_ID%22%3A%221066361147828367%22%2C%22TRACE_ID%22%3A%226237bf1b-7b03-4c8c-952c-ce56467fd7fa%22%7D&ses=%7B%22PSI%22%3A%22da3b113e-e81b-4717-be55-f558abd0a251%22%2C%22PBI%22%3A2%7D&asset=%7B%22ID_TYPE%22%3A%22StreamId%22%2C%22CLASS%22%3A%22Linear%22%2C%22PLAYBACK_TYPE%22%3A%22FOG%22%2C%22INFO%22%3A%7B%7D%2C%22SECURITY%22%3A%22TRUE%22%2C%22RegulatoryClass%22%3A%22T6%22%2C%22IDS%22%3A%7B%22STRID%22%3A%228348966700753924163%22%7D%2C%22VSTRM%22%3A%7B%7D%7D&appName=STB-XI5&appVer=3.9s3&acId=7764333496681121343&devName=ipstb&devID=E8%3A82%3A5B%3A68%3A9D%3AB8&phyID=1895170694941655639

AAMP requesting Manifest

2019 Jun 18 22:25:20.205263 pacexi5 WPEWebProcess[6625]: aamp url: http://127.0.0.1:9080/tsb?clientId=FOG_AAMP&recordedUrl=http%3A%2F%2Fcdn-ec-pan-002-03.linear-nat-ntlk-pil.xcr.comcast.net%2FMSNBC_HD_NAT_18292_0_8348966700753924163.m3u8%3Ftrred%3Dfalse&analyticsUrl=https%3A%2F%2Fanalytics.xcal.tv%2Fcomcast%2Ffog&money=%7B%22PARENT_ID%22%3A%221066361147828367%22%2C%22TRACE_ID%22%3A%226237bf1b-7b03-4c8c-952c-ce56467fd7fa%22%7D&ses=%7B%22PSI%22%3A%22da3b113e-e81b-4717-be55-f558abd0a251%22%2C%22PBI%22%3A2%7D&asset=%7B%22ID_TYPE%22%3A%22StreamId%22%2C%22CLASS%22%3A%22Linear%22%2C%22PLAYBACK_TYPE%22%3A%22FOG%22%2C%22INFO%22%3A%7B%7D%2C%22SECURITY%22%3A%22TRUE%22%2C%22RegulatoryClass%22%3A%22T6%22%2C%22IDS%22%3A%7B%22STRID%22%3A%228348966700753924163%22%7D%2C%22VSTRM%22%3A%7B%7D%7D&appName=STB-XI5&appVer=3.9s3&acId=7764333496681121343&devName=ipstb&devID=E8%3A82%3A5B%3A68%3A9D%3AB8&phyID=1895170694941655639

Manifest response

2019 Jun 18 22:25:20.323691 pacexi5 WPEWebProcess[6625]: HttpRequestEnd: {"url":"http://127.0.0.1:9080/manifests/362601d6-bf6d-4ca0-9287-8c26c343fa14/manifest.m3u8","curlTime":0.1190,"times":{"total":0.1181,"connect":0.0009,"startTransfer":0.1175,"resolve":0.0002,"appConnect":0.0000,"preTransfer":0.0036,"redirect":0.1166,"dlSz":10384,"ulSz":1587},"responseCode":200}

...

1613143701:288 : [AAMP-PLAYER]entering AAMPGstPlayer_Stop keepLastFrame 0
1613143701:288 : [AAMP-PLAYER]AAMPGstPlayer::Stop 2546 > Remove periodicProgressCallbackIdleTaskId 15
1613143701:288 : [AAMP-PLAYER]AAMPGstPlayer::DisconnectCallbacks: video_dec  0x708051c0 type_check 1
1613143701:290 : [AAMP-PLAYER]AAMPGstPlayerPipeline PLAYING -> PAUSED (pending NULL)
1613143701:458 : [AAMP-PLAYER]AAMPGstPlayerPipeline PAUSED -> READY (pending NULL)
1613143701:459 : [AAMP-PLAYER]AAMPGstPlayer::Stop: Pipeline state set to null
1613143701:461 : [AAMP-PLAYER]AAMPGstPlayer::TearDownStream: exit mediaType = 0
1613143701:462 : [AAMP-PLAYER]AAMPGstPlayer::TearDownStream: exit mediaType = 1
1613143701:462 : [AAMP-PLAYER]AAMPGstPlayer::TearDownStream: exit mediaType = 2
1613143701:463 : [AAMP-PLAYER]DestroyPipeline(): Destroying gstreamer pipeline
1613143701:463 : [AAMP-PLAYER]exiting AAMPGstPlayer_Stop

New tune request reaching AAMP

http://devimages.apple.com/iphone/samples/bipbop/bipbopall.m3u8
1613142994:132 : [AAMP-PLAYER]PrivateInstanceAAMP::ConfigureDashParallelFragmentDownload:8112 DASH Paraller Frag DL Config [1]
1613142994:132 : [AAMP-PLAYER]PrivateInstanceAAMP::ConfigureRetuneForGSTInternalError:8168 GST Internal Stream Error Retune Config [1]
1613142994:132 : [AAMP-PLAYER]Enabling Westeros Sink
1613142994:132 : [AAMP-PLAYER]FOREGROUND PLAYER[0] aamp_tune: attempt: 1 format: HLS URL: http://devimages.apple.com/iphone/samples/bipbop/bipbopall.m3u8
1613142994:132 : [AAMP-PLAYER]TeardownStream:4530 mProgressReportFromProcessDiscontinuity:0 mDiscontinuityTuneOperationId:0 newTune:1

AAMP requesting Manifest

1613144318:975 : [AAMP-PLAYER]aamp url:3,9,3,http://devimages.apple.com/iphone/samples/bipbop/gear4/prog_index.m3u8

Manifest response

1613144319:842 : [AAMP-PLAYER]HttpRequestEnd: 3,9,200,0.8670,0.8675,0.0001,0.8671,0.0001,0.0001,0.0002,0.0000,7019,286,http://devimages.apple.com/iphone/samples/bipbop/gear4/prog_index.m3u8

Manifest parsing, and the below print indicates duration of the playback

1613142996:700 : [AAMP-PLAYER]Found source for video
1613142996:700 : [AAMP-PLAYER]GetGstCaps:443 Unknown format 11
1613142996:705 : [AAMP-PLAYER]bus_sync_handler: Received GST_MESSAGE_ASYNC_DONE message
1613142996:705 : [AAMP-PLAYER]AAMPGstPlayerPipeline READY -> PAUSED (pending VOID_PENDING)
1613142996:705 : [AAMP-PLAYER]TSProcessor[0x1207fa0]reset:2162 - reset video demux 0x11ff758
1613142996:705 : [AAMP-PLAYER]msg type: async-done
1613142996:705 : [AAMP-PLAYER]TSProcessor[0x1207fa0]reset:2168 - reset audio demux 0x12012b8
1613142996:706 : [AAMP-PLAYER]aamp url:0,0,0,http://devimages.apple.com/iphone/samples/bipbop/gear4/fileSequence0.ts

DRM Initialization and Key acquisition

2019 Jun 18 22:25:20.440576 pacexi5 WPEWebProcess[6625]: TheDRMListener::TheDRMListener:117 AveDrm[0x193f40]Listner[0x22d818]Track[0]
2019 Jun 18 22:25:20.440598 pacexi5 WPEWebProcess[6625]: AveDrm::SetMetaData:365[0x193f40]Track[0] drmState:0
2019 Jun 18 22:25:20.440609 pacexi5 WPEWebProcess[6625]: SetMetadata:931: Created new AveDrmManager[763557531d09355a3331750aab7382daeea56725] .Track[0].Total Sz=1
2019 Jun 18 22:25:20.463579 pacexi5 runAppManager.sh[5611]: [MyFlashAccessAdapter][0x236c00] Constructor
2019 Jun 18 22:25:20.476126 pacexi5 runAppManager.sh[5611]: DRMManager_CreateDRMMetadata calling created source/DRMInterface.cpp
2019 Jun 18 22:25:20.324113 481279 pacexi5 WPEWebProcessrunAppManager.sh[6625]: GetPlaylistURI updating aamp->language from en to "en"5611]: [Initialize_Stage2][0x236c00]MyFlashAccessAdapter Initialize Stage 2 with encryption Algorithm: AES-CBC
2019 Jun 18 22:25:20.324135 481679 pacexi5 WPEWebProcessrunAppManager.sh[6625]: TrackState::FetchPlaylist [muxed] start5611]: 33528 createDRMDecryptionContext_FromDrmMetadataEx calling new DRMCreateDecryptionSessionOperation DRMInterface.cpp
2019 Jun 18 22:25:20.324150 481975 pacexi5 WPEWebProcessrunAppManager.sh[66255611]: aamp url: http://127.0.0.1:9080/manifests/362601d6-bf6d-4ca0-9287-8c26c343fa14/video1/manifest.m3u8
...machineID: NTczZWI2YTBjN2ExNDNiM2YzNzM4MmQ1ZWQ2MjBjOWI=
2019 Jun 18 22:25:20.488720 pacexi5 runAppManager.sh[5611]: 33528 OemGlobalStateStoreSPI::IOemGlobalStateStore::getDeviceInfo
2019 Jun 18 22:25:20.440297 489057 pacexi5 WPEWebProcessrunAppManager.sh[66255611]: UpdateVideoEnd33528 OemDeviceBindingSPI:T:7 br:262144 err:200 dur:0.000000 taTop:0.000000 ttTop:0.000000 tot:0.000000 n:getDeviceInfo Line 156
2019 Jun 18 22:25:20.440320 489324 pacexi5 WPEWebProcessrunAppManager.sh[66255611]: TrackState:: FetchPlaylist [muxed98B blob data] end
2019 Jun 18 22:25:20.440354 489630 pacexi5 WPEWebProcessrunAppManager.sh[6625]: aamp: EXT-X-TARGETDURATION = 3.000000
2019 Jun 18 22:25:20.440538 pacexi5 WPEWebProcess[6625]: aamp_UpdateDuration(28.028000)

...

5611]: BRCM_RI_SecureStore_Read reading /opt/persistent/adobe/drm/deviceBinding.txt in size 8000
...
2019 Jun 18 22:25:20.440576 459925 pacexi5 WPEWebProcess[6625]: TheDRMListenerAveDrm::TheDRMListenerAcquireKey:117 AveDrm637[0x193f40] Listner[0x22d818]drmState:1 Track[0]
2019 Jun 18 22:25:20.440598 pacexi5 WPEWebProcess[6625]: AveDrm::SetMetaData:365[0x193f40]Track[0] drmState:0
2019 Jun 18 22:25:20.440609 pacexi5 WPEWebProcess[6625]: SetMetadata:931: Created new AveDrmManager[763557531d09355a3331750aab7382daeea56725] .Track[0].Total Sz=1
2019 Jun 18 22:25:20.463579 pacexi5 runAppManager.sh[5611]: [MyFlashAccessAdapter][0x236c00] Constructor

Player level tune initialization and Gstreamer pipeline creation for the playback.

1613144307:322 : [AAMP-PLAYER]CreatePipeline(): Creating gstreamer pipeline
1613144307:322 : [AAMP-PLAYER]AAMPGstPlayerPipeline buffering_enabled 1
1613144317:586 : [AAMP-PLAYER]PrivateInstanceAAMP::ConfigureDashParallelFragmentDownload:8112 DASH Paraller Frag DL Config [1]
1613144317:586 : [AAMP-PLAYER]PrivateInstanceAAMP::ConfigureRetuneForGSTInternalError:8168 GST Internal Stream Error Retune Config [1]
1613144317:586 : [AAMP-PLAYER]Enabling Westeros Sink
1613144317:587 : [AAMP-PLAYER]FOREGROUND PLAYER[0] aamp_tune: attempt: 1 format: HLS URL: http://devimages.apple.com/iphone/samples/bipbop/bipbopall.m3u8

Fragment request start point and fragment decryption; pipeline state change to playing after decrypted data sent to gstreamer.

2019 Jun 18 22:25:20.476126 538816 pacexi5 runAppManager.shWPEWebProcess[56116625]: DRMManager_CreateDRMMetadata calling created source/DRMInterface.cpp: FetchFragment:1494: muxed
2019 Jun 18 22:25:20.481279 538950 pacexi5 runAppManager.shWPEWebProcess[56116625]: [Initialize_Stage2][0x236c00]MyFlashAccessAdapter Initialize Stage 2 with encryption Algorithm: AES-CBC
2019 Jun 18 22:25:20.481679 pacexi5 runAppManager.sh[5611]: 33528 createDRMDecryptionContext_FromDrmMetadataEx calling new DRMCreateDecryptionSessionOperation DRMInterface.cppaamp url: http://127.0.0.1:9080/manifests/362601d6-bf6d-4ca0-9287-8c26c343fa14/video1/bandwidth-2224800-track-muxed-repid-root_audio_video1-tc-0-frag-779669337.ts
...
2019 Jun 18 22:25:20.481975 688877 pacexi5 runAppManager.shWPEWebProcess[56116625]: machineID: NTczZWI2YTBjN2ExNDNiM2YzNzM4MmQ1ZWQ2MjBjOWI=AAMPGstPlayerPipeline NULL -> READY (pending PAUSED)
2019 Jun 18 22:25:2021.488720 353778 pacexi5 runAppManager.shWPEWebProcess[56116625]: 33528 OemGlobalStateStoreSPI::IOemGlobalStateStore::getDeviceInfoTrackState::[SetDrmContext][muxed] Enter mCMSha1Hash [(nil)] mDrmMetaDataIndexPosition 0
2019 Jun 18 22:25:2021.489057 353794 pacexi5 runAppManager.shWPEWebProcess[56116625]: 33528 OemDeviceBindingSPIGetAveDrm::getDeviceInfo Line 1561079:[0] Returned only available Drm Instance
2019 Jun 18 22:25:2021.489324 353806 pacexi5 runAppManager.shWPEWebProcess[56116625]: SetDrmContext:1897: [98B blob data[muxed] Initiating Key Request as Key is not available for index [0]
2019 Jun 18 22:25:2021.489630 353818 pacexi5 runAppManager.shWPEWebProcess[56116625]: BRCM_RI_SecureStore_Read reading /opt/persistent/adobe/drm/deviceBinding.txt in size 8000
...: InitiateDRMKeyAcquisition:1856:[muxed]Request DRM Key immediately for indexPosn[0]
2019 Jun 18 22:25:2021.459925 353849 pacexi5 WPEWebProcess[6625]: AveDrm::AcquireKeyDecrypt:637474[0x193f40] drmState:1 Track[0]

...

waiting for key acquisition to complete,wait time:12000
2019 Jun 18 22:25:2021.460253 359066 pacexi5 WPEWebProcessReceiver[66256007]: StreamAbstractionAAMP_HLS::Init : VideoTrack: format is 7 [avc1.]Thread-6007 [XREApplication] - onWriteLocalObjectComplete
2019 Jun 18 22:25:2021.460266 381172 pacexi5 WPEWebProcessReceiver[66256007]: StreamAbstractionAAMP_HLS::Init : Audio format is 3 [mp4a.40.5]Thread-6007 [XREApplication] - onWriteLocalObjectComplete
2019 Jun 18 22:25:2021.460276 385209 pacexi5 WPEWebProcessReceiver[6625]: StreamAbstractionAAMP_HLS::Init : Configure video TS track demuxing demuxOp 36007]: Thread-6007 [VideoResource] - got traceId '6237bf1b-7b03-4c8c-952c-ce56467fd7fa'
2019 Jun 18 22:25:2021.474715 385313 pacexi5 WPEWebProcessReceiver[66256007]: aamp: hls - sent tune event after indexing playlist
2019 Thread-6007 [VideoResource] - [LINEAR_TV] NEW RAW url: http://ccr.linear-nat-pil-red.xcr.comcast.net/MSNBC_HD_NAT_18292_0_8348966700753924163.m3u8
2019 Jun 18 22:25:2021.474759 389877 pacexi5 WPEWebProcessReceiver[66256007]: aamp: after live adjust - V-target 13.000000 A-target 0.000000 offsetFromLive 15 offsetToLive 13 offsetVideo[13] offsetAudio[13] AtLivePoint[1]
...Thread-6007 [XREApplication] - __PLOG__ Overcard hidden SerTime=1560896721254 threadId=4200848 recTime=1560896721389
2019 Jun 18 22:25:21.422637 pacexi5 Receiver[6007]: Thread-6007 [XREApplication] - onReadLocalObjectComplete
2019 Jun 18 22:25:2023.474794 666291 pacexi5 WPEWebProcessrunAppManager.sh[6625]: TuneHelper:3810 Updated seek_pos_seconds 13.0000005611]: [SetDecryptInfo][0x236c00] MyFlashAccessAdapter
2019 Jun 18 22:25:2023.474806 666724 pacexi5 WPEWebProcessrunAppManager.sh[66255611]: TuneHelper : mFormat 7, mAudioFormat 333528 HttpRequestTransferEnd https://bet.ccp.xcal.tv/flashaccess/license/v6
2019 Jun 18 22:25:2023.474821 666995 pacexi5 WPEWebProcessrunAppManager.sh[66255611]: SetVideoZoom :: ZoomMode 0, using_playersinkbin = 0, video_sink =(nil)
2019 Jun 18 22:25:20.474832 pacexi5 WPEWebProcess[6625]: SetVideoMute: muted 0, using_playersinkbin = 0, video_sink =(nil)33528 HttpRequest after ConfigureAndPerformCurlRequest33528 HttpRequestEnd https://bet.ccp.xcal.tv/flashaccess/license/v6 TOTAL=2.37749 times={total=2.37718 connect=0.224836 startTransfer=0.498429 resolve=0.128993 appConnect=0.496993 preTransfer=0.498413 redirect=0 dlSz=4780 dlSpd=2010b/s ulSz=16384 ulSpd=1962b/s} responseCode=200
2019 Jun 18 22:25:2023.474848 667244 pacexi5 WPEWebProcessrunAppManager.sh[6625]: AAMPGstPlayer::setVolumeOrMuteUnMute() 2534 > volume = 1.000000, using_playersinkbin = 0, audio_sink = (nil)5611]: BRCM_RI_SecureStore_Write writing /opt/persistent/adobe/drm/sss/SFM581F0Zk0P8rndN7DRz_HguWw=/serverData size 80
2019 Jun 18 22:25:2023.474861 667508 pacexi5 WPEWebProcessrunAppManager.sh[6625]: AAMPGstPlayer::Configure 1838 > format 7 audioFormat 35611]: [121B blob data]
2019 Jun 18 22:25:2023.474871 667754 pacexi5 WPEWebProcessrunAppManager.sh[66255611]: CreatePipeline(): Creating gstreamer pipeline
2019 Jun 18 190618-22:25:20.475303 pacexi5 WPEWebProcess[6625]: AAMPGstPlayerPipeline buffering_enabled 23.665736 [mod=RDKBROWSER2, lvl=WARN] [tid=8213] aveLogCallback:AVESupport.cpp:237 AVE-Lib DRM_Common_AllocKeySlot count=1
2019 Jun 18 22:25:2023.475319 728267 pacexi5 WPEWebProcess[6625]: AAMPGstPlayer::Configure 1862 > Closing stream 0 old format = 0, new format = 7: DRMListener::NotifyDRMStatus:281[0x193f40]aamp:***drmState:1
2019 Jun 18 22:25:2023.475329 729152 pacexi5 WPEWebProcess[6625]: DRMListener:: AAMPGstPlayer::Configure 1862 > Closing stream 1 old format = 0, new format = 3
2019 Jun 18 22:25:20.475339 pacexi5 WPEWebProcess[6625]: AAMPGstPlayer::TearDownStream: exit mediaType = 0SignalKeyAcquired:142[0x193f40][0]drmState:1 moving to KeyAcquired.callbackID[42]
...
2019 Jun 18 22:25:2024.475347 064616 pacexi5 WPEWebProcess[6625]: AAMPGstPlayer_SetupStream - using playbinAAMPGstPlayerPipeline READY -> PAUSED (pending VOID_PENDING)
2019 Jun 18 22:25:2024.485140 149873 pacexi5 WPEWebProcess[6625]: playbin flags1: 0x617
2019 Jun 18 22:25:20.485330 pacexi5 WPEWebProcess[6625]: AAMPGstPlayer::TearDownStream: exit mediaType = 1AAMPGstPlayerPipeline PAUSED -> PLAYING (pending VOID_PENDING)

To confirm send segment data during tune ( mediaType[0] : Video / mediaType[1] : Audio )

2019 Jun 18 22:25:2023.485341 765015 pacexi5 WPEWebProcess[6625]: AAMPGstPlayer_SetupStream - using playbin

Fragment request start point and fragment decryption; pipeline state change to playing after decrypted data sent to gstreamer.

Sending segment event for mediaType[0]. start 500000000 stop 18446744073709551615 rate 1.000000 applied_rate 1.0000002019 Jun 18 22:25:20.538816 pacexi5 WPEWebProcess[6625]: FetchFragment:1494: muxed
2019 Jun 18 22:25:2023.538950 779102 pacexi5 WPEWebProcess[6625]: aamp url: http://127.0.0.1:9080/manifests/362601d6-bf6d-4ca0-9287-8c26c343fa14/video1/bandwidth-2224800-track-muxed-repid-root_audio_video1-tc-0-frag-779669337.ts
...
2019 Jun 18 22:25:20.688877 pacexi5 WPEWebProcess[6625]: AAMPGstPlayerPipeline NULL -> READY (pending PAUSED)
2019 Jun 18 22:25:21.353778 pacexi5 WPEWebProcess[6625]: TrackState::[SetDrmContext][muxed] Enter mCMSha1Hash [(nil)] mDrmMetaDataIndexPosition 0
2019 Jun 18 22:25:21.353794 pacexi5 WPEWebProcess[6625]: GetAveDrm:1079:[0] Returned only available Drm Instance
2019 Jun 18 22:25:21.353806 pacexi5 WPEWebProcess[6625]: SetDrmContext:1897:[muxed] Initiating Key Request as Key is not available for index [0]
2019 Jun 18 22:25:21.353818 pacexi5 WPEWebProcess[6625]: InitiateDRMKeyAcquisition:1856:[muxed]Request DRM Key immediately for indexPosn[0]
2019 Jun 18 22:25:21.353849 pacexi5 WPEWebProcess[6625]: AveDrm::Decrypt:474[0x193f40] waiting for key acquisition to complete,wait time:12000
2019 Jun 18 22:25:21.359066 pacexi5 Receiver[6007]: Thread-6007 [XREApplication] - onWriteLocalObjectComplete
2019 Jun 18 22:25:21.381172 pacexi5 Receiver[6007]: Thread-6007 [XREApplication] - onWriteLocalObjectComplete
2019 Jun 18 22:25:21.385209 pacexi5 Receiver[6007]: Thread-6007 [VideoResource] - got traceId '6237bf1b-7b03-4c8c-952c-ce56467fd7fa'
2019 Jun 18 22:25:21.385313 pacexi5 Receiver[6007]: Thread-6007 [VideoResource] - [LINEAR_TV] NEW RAW url: http://ccr.linear-nat-pil-red.xcr.comcast.net/MSNBC_HD_NAT_18292_0_8348966700753924163.m3u8
2019 Jun 18 22:25:21.389877 pacexi5 Receiver[6007]: Thread-6007 [XREApplication] - __PLOG__ Overcard hidden SerTime=1560896721254 threadId=4200848 recTime=1560896721389
2019 Jun 18 22:25:21.422637 pacexi5 Receiver[6007]: Thread-6007 [XREApplication] - onReadLocalObjectComplete
2019 Jun 18 22:25:23.666291 pacexi5 runAppManager.sh[5611]: [SetDecryptInfo][0x236c00] MyFlashAccessAdapter
2019 Jun 18 22:25:23.666724 pacexi5 runAppManager.sh[5611]: 33528 HttpRequestTransferEnd https://bet.ccp.xcal.tv/flashaccess/license/v6
2019 Jun 18 22:25:23.666995 pacexi5 runAppManager.sh[5611]: 33528 HttpRequest after ConfigureAndPerformCurlRequest33528 HttpRequestEnd https://bet.ccp.xcal.tv/flashaccess/license/v6 TOTAL=2.37749 times={total=2.37718 connect=0.224836 startTransfer=0.498429 resolve=0.128993 appConnect=0.496993 preTransfer=0.498413 redirect=0 dlSz=4780 dlSpd=2010b/s ulSz=16384 ulSpd=1962b/s} responseCode=200
2019 Jun 18 22:25:23.667244 pacexi5 runAppManager.sh[5611]: BRCM_RI_SecureStore_Write writing /opt/persistent/adobe/drm/sss/SFM581F0Zk0P8rndN7DRz_HguWw=/serverData size 80
2019 Jun 18 22:25:23.667508 pacexi5 runAppManager.sh[5611]: [121B blob data]
2019 Jun 18 22:25:23.667754 pacexi5 runAppManager.sh[5611]: 190618-22:25:23.665736 [mod=RDKBROWSER2, lvl=WARN] [tid=8213] aveLogCallback:AVESupport.cpp:237 AVE-Lib DRM_Common_AllocKeySlot count=1
2019 Jun 18 22:25:23.728267 pacexi5 WPEWebProcess[6625]: DRMListener::NotifyDRMStatus:281[0x193f40]aamp:***drmState:1
2019 Jun 18 22:25:23.729152 pacexi5 WPEWebProcess[6625]: DRMListener::SignalKeyAcquired:142[0x193f40][0]drmState:1 moving to KeyAcquired.callbackID[42]
...
2019 Jun 18 22:25:24.064616 pacexi5 WPEWebProcess[6625]: AAMPGstPlayerPipeline READY -> PAUSED (pending VOID_PENDING)
2019 Jun 18 22:25:24.149873 pacexi5 WPEWebProcess[6625]: AAMPGstPlayerPipeline PAUSED -> PLAYING (pending VOID_PENDING)

To confirm send segment data during tune ( mediaType[0] : Video / mediaType[1] : Audio )

2019 Jun 18 22:25:23.765015 pacexi5 WPEWebProcess[6625]: Sending segment event for mediaType[0]. start 500000000 stop 18446744073709551615 rate 1.000000 applied_rate 1.000000
2019 Jun 18 22:25:23.779102 pacexi5 WPEWebProcess[6625]: Sending segment event for mediaType[1]. start 505355555 stop 18446744073709551615 rate 1.000000 applied_rate 1.000000

Finally tune succeeded and tune time print will have the statistics

2019 Jun 18 22:25:24.018072 pacexi5 Receiver[6007]: Thread-6007 [AAMP-WEB] - IP_EX_CONTENT_URL:http://127.0.0.1:9080/tsb?clientId=FOG_AAMP&recordedUrl=http://ccr.linear-nat-pil-red.xcr.comcast.net/MSNBC_HD_NAT_18292_0_8348966700753924163.m3u8 DurationMs:28000
2019 Jun 18 22:25:24.018150 pacexi5 Receiver[6007]: Thread-6007 [AAMP-WEB] - IP_TUNETIME:3,4.4,4.3
...
2019 Jun 18 22:25:24.018204 pacexi5 Receiver[6007]: Thread-6007 [AAMP-WEB] - IP_EX_TUNETIME:3,4.479,4.338,0.825,0.134,0.116,3.289,0.114,0.001,0.000,0.000,0.914,3.288,1,0.119,1,0.116,1,0.815,1,12,0,1,0,0,28,1,0.000,2,1
2019 Jun 18 22:25:24.018367 pacexi5 Receiver[6007]: Thread-6007 [AAMP-WEB] - New flash video is playing. Duration=28000
2019 Jun 18 22:25:24.018401 pacexi5 Receiver[6007]: Thread-6007 [ECM] - New flash video is playing. Duration=28000 hasTSB=1
2019 Jun 18 22:25:24.018469 pacexi5 Receiver[6007]: Thread-6007 [VideoResource] - event=onVideoInfo

Actual receiver log for the above snippets

...

Sending segment event for mediaType[1]. start 505355555 stop 18446744073709551615 rate 1.000000 applied_rate 1.000000

Finally tune succeeded and tune time print will have the statistics

1613144321:704 : [AAMP-PLAYER]AAMPGstPlayer_OnFirstVideoFrameCallback. got First Video Frame
1613144321:704 : [AAMP-PLAYER]FOREGROUND PLAYER[0] IP_AAMP_TUNETIME:4,0,1613144317587,4,1383,0,1388,868,0,0,0,0,0,0,0,0,0,0,2306,1644,0,737777,0,0,0,0,2256,0,0,0,0,0,0,0,3991,4117,2,10,1,0,0
1613144321:704 : [AAMP-PLAYER]AAMP=>XRE: 3895,7147870,0,1387,869,0,167,1383,868,1644,1694,0,1,1801000,0,7147870,7149257,7150126,7150126,7151820,7151987,10,1,0,-1763381592
1613144321:704 : [AAMP-PLAYER]AAMP=>XRE: 3895,7147870,0,1387,869,0,167,1383,868,1644,1694,0,1,1801000,0,7147870,7149257,7150126,7150126,7151820,7151987,10,1,0,-1763381592
1613144321:704 : [AAMP-PLAYER]Anomaly evt:2 msg:Tune attempt#1. VOD:HLS/Clear URL:http://devimages.apple.com/iphone/samples/bipbop/bipbopall.m3u8
1613144321:704 : [AAMP-PLAYER]PrivateInstanceAAMP::SendEventAsync:2592 event type  26
1613144321:704 : [AAMP-PLAYER][AAMP_JS] SendEventSync(type=26)
1613144321:704 : [AAMP-PLAYER][AAMP_JS] SendEventSync(type=14)(state=8)
1613144321:704 : [AAMP-PLAYER]AAMP_EVENT_STATE_CHANGED: 8
1613144321:704 : [AAMP-PLAYER]AAMP_EVENT_TUNED
1613144321:704 : [AAMP-PLAYER]aamp: - sent tune event on Tune Completion.

...