Page History

...

[AAMP-PLAYER] aamp-cli> stop
1615822313:989 : [AAMP-PLAYER]PLAYER[0] aamp_stop PlayerState=8
1615822313:989 : [AAMP-PLAYER]FOREGROUND PLAYER[0] Stopping Playback at Position '48720'.

1615822313:989 : [AAMP-PLAYER][AAMP_JS] SendEventSync(type=14)(state=0)
1615822313:989 : [AAMP-PLAYER]AAMP_EVENT_STATE_CHANGED: 0
1615822313:989 : [AAMP-PLAYER]fragment injector done. track audio
1615822313:989 : [AAMP-PLAYER]PrivateInstanceAAMP::BlockUntilGstreamerWantsData interrupted. mDownloadsEnabled:0 mTrackInjectionBlocked:0
1615822313:989 : [AAMP-PLAYER]WaitForCachedFragmentAvailable video aborted
1615822313:989 : [AAMP-PLAYER]fragment injector done. track video
1615822313:990 : [AAMP-PLAYER]MPD fragment collector done
1615822313:990 : [AAMP-PLAYER]TeardownStream:4580 mProgressReportFromProcessDiscontinuity:0 mDiscontinuityTuneOperationId:0 newTune:1
1615822314: 30 : [AAMP-PLAYER]entering AAMPGstPlayer_Stop keepLastFrame 0
1615822314: 30 : [AAMP-PLAYER]AAMPGstPlayer::Stop 2703 > Remove periodicProgressCallbackIdleTaskId 14
1615822314: 30 : [AAMP-PLAYER]AAMPGstPlayer::DisconnectCallbacks: video_dec  0x73d72778 type_check 1
1615822314: 38 : [AAMP-PLAYER]AAMPGstPlayerPipeline PLAYING -> PAUSED (pending NULL)
1615822314: 99 : [AAMP-PLAYER]AAMPGstPlayerPipeline PAUSED -> READY (pending NULL)
1615822314:101 : [AAMP-PLAYER]AAMPGstPlayer::Stop: Pipeline state set to null
1615822314:103 : [AAMP-PLAYER]AAMPGstPlayer::TearDownStream: exit mediaType = 0
1615822314:105 : [AAMP-PLAYER]AAMPGstPlayer::TearDownStream: exit mediaType = 1
1615822314:105 : [AAMP-PLAYER]AAMPGstPlayer::TearDownStream: exit mediaType = 2
1615822314:106 : [AAMP-PLAYER]DestroyPipeline(): Destroying gstreamer pipeline
1615822314:106 : [AAMP-PLAYER]exiting AAMPGstPlayer_Stop
[AAMP-PLAYER] aamp-cli>

AAMP stopping playback

1613139308:106 : [AAMP-PLAYER]AAMPGstPlayer::Flush:3250 Pipeline state NULL, ret 1 
1613139308:106 : [AAMP-PLAYER]AAMPGstPlayer::Flush:3253 Pipeline is not in playing/paused state, hence resetting it 
1613139308:106 : [AAMP-PLAYER]entering AAMPGstPlayer_Stop keepLastFrame 1 
1613139308:106 : [AAMP-PLAYER]AAMPGstPlayer::Stop: Pipeline state set to null 
1613139308:106 : [AAMP-PLAYER]AAMPGstPlayer::TearDownStream: exit mediaType = 0 
1613139308:106 : [AAMP-PLAYER]AAMPGstPlayer::TearDownStream: exit mediaType = 1 
1613139308:106 : [AAMP-PLAYER]AAMPGstPlayer::TearDownStream: exit mediaType = 2 
1613139308:107 : [AAMP-PLAYER]DestroyPipeline(): Destroying gstreamer pipeline 
1613139308:107 : [AAMP-PLAYER]exiting AAMPGstPlayer_Stop 
1613139308:107 : [AAMP-PLAYER]SetVideoZoom :: ZoomMode 0, using_playersinkbin = 0, video_sink =(nil) 
1613139308:107 : [AAMP-PLAYER]SetVideoMute: muted 0, using_playersinkbin = 0, video_sink =(nil)

New tune request reaching AAMP

http://cpetestutility.stb.r53.xcal.tv/VideoTestStream/main.mpd 
1613139307: 97 : [AAMP-PLAYER]PrivateInstanceAAMP::ConfigureDashParallelFragmentDownload:8112 DASH Paraller Frag DL Config [1] 
1613139307: 97 : [AAMP-PLAYER]PrivateInstanceAAMP::ConfigureRetuneForGSTInternalError:8168 GST Internal Stream Error Retune Config [1] 
1613139307: 97 : [AAMP-PLAYER]Enabling Westeros Sink 
1613139307: 97 : [AAMP-PLAYER]FOREGROUND PLAYER[0] aamp_tune: attempt: 1 format: DASH URL: http://cpetestutility.stb.r53.xcal.tv/VideoTestStream/main.mpd

...

 1613139307: 97 : [AAMP-PLAYER]TeardownStream:4530 mProgressReportFromProcessDiscontinuity:0 mDiscontinuityTuneOperationId:0 newTune:1

AAMP requesting Manifest

1613139307:101 : [AAMP-PLAYER]aamp url:3,3,0,http://cpetestutility.stb.r53.xcal.tv/VideoTestStream/main.mpd

Manifest response

1613139307:603 : [AAMP-PLAYER]HttpRequestEnd:

...

3,3,200,0.5020,0.5011,0.2561,0.5005,0.0127,0.0000,0.2563,0.0000,10059,278,http://cpetestutility.stb.r53.xcal.tv/VideoTestStream/main.mpd

Manifest parsing, prints indicate which period/adapatationSet/representation selected for playback

1613139308:149 : [AAMP-PLAYER]Found source for video 
1613139308:150 : [AAMP-PLAYER]bus_sync_handler: Received GST_MESSAGE_ASYNC_DONE message 
1613139308:151 : [AAMP-PLAYER]AAMPGstPlayerPipeline READY -> PAUSED (pending VOID_PENDING) 
1613139308:151 : [AAMP-PLAYER]msg type: async-done 
1613139308:151 : [AAMP-PLAYER]PrivateInstanceAAMP::SendEventAsync:2592 event type 14 

...

1613139308:151 : [AAMP-PLAYER][AAMP_JS] SendEventSync(type=14)(state=4) 
1613139308:151 : [AAMP-PLAYER]AAMP_EVENT_STATE_CHANGED: 4 
1613139308:151 : [AAMP-PLAYER]aamp-cli> 
1613139308:151 : [AAMP-PLAYER]fragment injector started. track audio 
1613139308:151 : [AAMP-PLAYER]fragment injector started. track video 
1613139308:158 : [AAMP-PLAYER]aamp: ready to collect fragments. mpd 0x9d75f0 
1613139308:158 : [AAMP-PLAYER]MPD has 1 periods current period index 0 
1613139308:158 : [AAMP-PLAYER]PushNextFragment:1811 Type[1] update startTime to 0 
1613139308:158 : [AAMP-PLAYER]aamp url:0,1,1,http://cpetestutility.stb.r53.xcal.tv/VideoTestStream/dash/de_001.mp3 
1613139308:158 : [AAMP-PLAYER]PushNextFragment:1811 Type[0] update startTime to 0

...

 1613139308:158 : [AAMP-PLAYER]aamp url:0,0,0,http://cpetestutility.stb.r53.xcal.tv/VideoTestStream/dash/480p_001.m4s

Checking and processing content protection from fragmentCollector thread

...

Creating Gstreamer pipeline

1613139308:107 : [AAMP-PLAYER]CreatePipeline(): Creating gstreamer pipeline 
1613139308:107 : [AAMP-PLAYER]AAMPGstPlayerPipeline buffering_enabled 1 
1613139308:107 : [AAMP-PLAYER]AAMPGstPlayer::Configure 2363 > Closing stream 0 old format = 0, new format = 2 
1613139308:107 : [AAMP-PLAYER]AAMPGstPlayer::Configure 2363 > Closing stream 1 old format = 0, new format = 2 
1613139308:107 : [AAMP-PLAYER]AAMPGstPlayer::TearDownStream: exit mediaType = 0 
1613139308:107 : [AAMP-PLAYER]AAMPGstPlayer_SetupStream - using playbin 
1613139308:116 : [AAMP-PLAYER]AAMPGstPlayer_SetupStream - using westerossink 
1613139308:127 : [AAMP-PLAYER]playbin flags1: 0x617 
1613139308:127 : [AAMP-PLAYER]AAMPGstPlayer::TearDownStream: exit mediaType = 1 
1613139308:127 : [AAMP-PLAYER]AAMPGstPlayer_SetupStream - using playbin 
1613139308:128 : [AAMP-PLAYER]playbin flags1: 0x617 
1613139308:128 : [AAMP-PLAYER]AAMPGstPlayerPipeline NULL -> READY (pending PAUSED)

DRM session creation "keysystem is" indicates which DRM is selected

2019 Jun 18 13:08:44.473503 arrisxg1v4 WPEWebProcess[16069]: Found Widevine encryption from manifest
2019 Jun 18 13:08:44.473522 arrisxg1v4 WPEWebProcess[16069]: queueing protection event for keysystem: edef8ba9-79d6-4ace-a3c8-27dcd51d21ed initdata size: 91
2019 Jun 18 13:08:44.473616 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:821 systemId is edef8ba9-79d6-4ace-a3c8-27dcd51d21ed
2019 Jun 18 13:08:44.473638 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:838 [HHH]systemId is Widevine
2019 Jun 18 13:08:44.473655 arrisxg1v4 WPEWebProcess[16069]: keysystem is com.widevine.alpha
2019 Jun 18 13:08:44.473671 arrisxg1v4 WPEWebProcess[16069]: _extractKeyIdFromPssh:602 wv keyid: 0cc84940-1541-ef5d-cc5f-1f5317cb417e keyIdlen: 36
2019 Jun 18 13:08:44.473684 arrisxg1v4 WPEWebProcess[16069]: _extractKeyIdFromPssh:642 KeyId : 0cc84940-1541-ef5d-cc5f-1f5317cb417e
2019 Jun 18 13:08:44.473702 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:915 Selected slot 1 for keyId 0cc84940-1541-ef5d-cc5f-1f5317cb417e sessionType video
2019 Jun 18 13:08:44.473737 arrisxg1v4 WPEWebProcess[16069]: AAMPOCDMSession :: enter
2019 Jun 18 13:08:44.473753 arrisxg1v4 WPEWebProcess[16069]: initAampDRMSession :: enter
2019 Jun 18 13:08:44.473780 arrisxg1v4 WPEWebProcess[16069]: initAampDRMSession :: exit
2019 Jun 18 13:08:44.473795 arrisxg1v4 WPEWebProcess[16069]: AAMPOCDMSession :: exit
2019 Jun 18 13:08:44.473814 arrisxg1v4 WPEWebProcess[16069]: generateAampDRMSession :: enter

FragmentCollector downloading and injecting init headers

1613139307:613 : [AAMP-PLAYER]PrivateStreamAbstractionMPD::Init:4281 - fetch initialization fragments 
1613139307:614 : [AAMP-PLAYER]aamp url:2,7,1,http://cpetestutility.stb.r53.xcal.tv/VideoTestStream/dash/de_init.m4s 
1613139307:614 : [AAMP-PLAYER]aamp url:2,6,0,http://cpetestutility.stb.r53.xcal.tv/VideoTestStream/dash/480p_init.m4s 
1613139307:858 : [AAMP-PLAYER]HttpRequestEnd: 2,6,200,0.2440,0.2442,0.0002,0.2441,0.0002,0.0002,0.0003,0.0000,811,288,http://cpetestutility.stb.r53.xcal.tv/VideoTestStream/dash/480p_init.m4s 
1613139308:106 : [AAMP-PLAYER]HttpRequestEnd: 2,7,200,0.4920,0.4918,0.2455,0.4916,0.0001,0.0000,0.2457,0.0000,741,286,http://cpetestutility.stb.r53.xcal.tv/VideoTestStream/dash/de_init.m4s

Gstreamer layer detects encryption for Audio and Video and suitable Decryptor plugin and initialized

...

FragmentCollector proceeds with fragment download/injection

1613139308:151 : [AAMP-PLAYER]fragment injector started. track audio 
1613139308:151 : [AAMP-PLAYER]fragment injector started. track video 
1613139308:158 : [AAMP-PLAYER]aamp: ready to collect fragments. mpd 0x9d75f0 
1613139308:158 : [AAMP-PLAYER]MPD has 1 periods current period index 0 
1613139308:158 : [AAMP-PLAYER]PushNextFragment:1811 Type[1] update startTime to 0 
1613139308:158 : [AAMP-PLAYER]aamp url:0,1,1,http://cpetestutility.stb.r53.xcal.tv/VideoTestStream/dash/de_001.mp3 
1613139308:158 : [AAMP-PLAYER]PushNextFragment:1811 Type[0] update startTime to 0 
1613139308:158 : [AAMP-PLAYER]aamp url:0,0,0,http://cpetestutility.stb.r53.xcal.tv/VideoTestStream/dash/480p_001.m4s

DRM license request in progress

...

2019 Jun 18 13:08:45.664064 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:1220 acquireLicense SUCCESS! license request attempt 1; response code : sec_client 0
2019 Jun 18 13:08:45.665123 arrisxg1v4 runAppManager.sh[15527]: set generic heap 1, secure heap 2span-name=snd-msg trace-id=e5de25f4-b903-42ee-a872-3f6b95a3b29f;parent-id=-101473692534903567;span-id=-7616813685635720481 span-success=true start-time=Tue Jun 18 13:08:45 2019
2019 Jun 18 13:08:45.665434 arrisxg1v4 runAppManager.sh[15527]: span-duration=0.638453
2019 Jun 18 13:08:45.665673 arrisxg1v4 runAppManager.sh[15527]: SecClient-Status: 0, 0, 200, 0, e5de25f4-b903-42ee-a872-3f6b95a3b29f, 1560863324745, -101473692534903567
2019 Jun 18 13:08:45.665902 arrisxg1v4 runAppManager.sh[15527]: SecClient-PerfTime: 0, 0.918269, 0.638453
2019 Jun 18 13:08:46.002655 arrisxg1v4 WPEWebProcess[16069]: processKey: Key Usable!
2019 Jun 18 13:08:46.004196 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:1329 Key Ready for video stream
2019 Jun 18 13:08:46.024009 arrisxg1v4 runAppManager.sh[15527]: span-name=acq-lic trace-id=e5de25f4-b903-42ee-a872-3f6b95a3b29f;parent-id=1560863324745;span-id=-101473692534903567 span-success=true start-time=Tue Jun 18 13:08:44 2019
2019 Jun 18 13:08:46.032575 arrisxg1v4 runAppManager.sh[15527]: span-duration=0.918269
2019 Jun 18 13:08:46.034516 arrisxg1v4 runAppManager.sh[15527]: [AAMP_JS] Event() ctx=0x99fd80d0, type=22, jsCallback=0x993b94b0
2019 Jun 18 13:08:46.035152 arrisxg1v4 runAppManager.sh[15527]: AAMP_JSListener_DRMMetadata code 0 Description accessAttributeStatus
2019 Jun 18 13:08:46.004226 arrisxg1v4 WPEWebProcess[16069]: Sending DRMMetaData
2019 Jun 18 13:08:46.004263 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:971 Found drm session READY with same keyID 0cc84940-1541-ef5d-cc5f-1f5317cb417e - Reusing drm session for audio
2019 Jun 18 13:08:46.006478 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:971 Found drm session READY with same keyID 0cc84940-1541-ef5d-cc5f-1f5317cb417e - Reusing drm session for video
2019 Jun 18 13:08:46.031797 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:821 systemId is edef8ba9-79d6-4ace-a3c8-27dcd51d21ed
2019 Jun 18 13:08:46.031819 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:838 [HHH]systemId is Widevine
2019 Jun 18 13:08:46.031835 arrisxg1v4 WPEWebProcess[16069]: keysystem is com.widevine.alpha
2019 Jun 18 13:08:46.031857 arrisxg1v4 WPEWebProcess[16069]: _extractKeyIdFromPssh:602 wv keyid: 0cc84940-1541-ef5d-cc5f-1f5317cb417e keyIdlen: 36
2019 Jun 18 13:08:46.031868 arrisxg1v4 WPEWebProcess[16069]: _extractKeyIdFromPssh:642 KeyId : 0cc84940-1541-ef5d-cc5f-1f5317cb417e
2019 Jun 18 13:08:46.031883 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:876 Session created/inprogress with same keyID 0cc84940-1541-ef5d-cc5f-1f5317cb417e at slot 1, can reuse same for audio
2019 Jun 18 13:08:46.031928 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:971 Found drm session READY with same keyID 0cc84940-1541-ef5d-cc5f-1f5317cb417e - Reusing drm session for audio
2019 Jun 18 13:08:46.032364 arrisxg1v4 WPEWebProcess[16069]: IsSourceUHD viddec (0xb232ee78) --> says width 1920, height 1080
2019 Jun 18 13:08:46.039716 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:821 systemId is edef8ba9-79d6-4ace-a3c8-27dcd51d21ed
2019 Jun 18 13:08:46.039739 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:838 [HHH]systemId is Widevine
2019 Jun 18 13:08:46.039753 arrisxg1v4 WPEWebProcess[16069]: keysystem is com.widevine.alpha
2019 Jun 18 13:08:46.039772 arrisxg1v4 WPEWebProcess[16069]: _extractKeyIdFromPssh:602 wv keyid: 0cc84940-1541-ef5d-cc5f-1f5317cb417e keyIdlen: 36
2019 Jun 18 13:08:46.039784 arrisxg1v4 WPEWebProcess[16069]: _extractKeyIdFromPssh:642 KeyId : 0cc84940-1541-ef5d-cc5f-1f5317cb417e
2019 Jun 18 13:08:46.039801 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:876 Session created/inprogress with same keyID 0cc84940-1541-ef5d-cc5f-1f5317cb417e at slot 1, can reuse same for video
2019 Jun 18 13:08:46.039839 arrisxg1v4 WPEWebProcess[16069]: createDrmSession:971 Found drm session READY with same keyID 0cc84940-1541-ef5d-cc5f-1f5317cb417e - Reusing drm session for video

Finally tune succeeded and tune time print will have the statistics

1613139308:681 : [AAMP-PLAYER]msg type: async-done 
1613139308:685 : [AAMP-PLAYER]AAMPGstPlayer_OnFirstVideoFrameCallback. got First Video Frame 
1613139308:685 : [AAMP-PLAYER]FOREGROUND PLAYER[0] IP_AAMP_TUNETIME:4,0,1613139307097,4,502,0,0,0,0,0,0,0,517,244,0,517,492,0,1061,489,0,1400000,1061,492,0,0,0,0,0,0,0,0,0,0,1105,1588,2,20,1,0,0 
1613139308:685 : [AAMP-PLAYER]AAMP=>XRE: 2219,2137380,0,506,0,0,35,502,0,1717,1047,0,1,900000,0,2137380,2137886,2137886,2137886,2138933,2138968,20,1,1,-1768394611 
1613139308:685 : [AAMP-PLAYER]AAMP=>XRE: 2219,2137380,0,506,0,0,35,502,0,1717,1047,0,1,900000,0,2137380,2137886,2137886,2137886,2138933,2138968,20,1,1,-1768394611 
1613139308:685 : [AAMP-PLAYER]Anomaly evt:2 msg:Tune attempt#1. VOD:DASH/Clear URL:http://cpetestutility.stb.r53.xcal.tv/VideoTestStream/main.mpd 
1613139308:685 : [AAMP-PLAYER]PrivateInstanceAAMP::SendEventAsync:2592 event type 26 

...

1613139308:685 : [AAMP-PLAYER][AAMP_JS] SendEventSync(type=26) 
1613139308:685 : [AAMP-PLAYER][AAMP_JS] SendEventSync(type=14)(state=8) 
1613139308:685 : [AAMP-PLAYER]AAMP_EVENT_STATE_CHANGED: 8 
1613139308:685 : [AAMP-PLAYER]AAMP_EVENT_TUNED 
1613139308:685 : [AAMP-PLAYER]aamp: - sent tune event on Tune Completion.