Trick Play Flow and Analysis

Trick operations supported by AAMP

1. 1x ( speed level 4 )
2. 2x ( speed level 16 )
3. 3x ( speed level 32 )
4. 4x ( speed level 64 )

Trick play supported over AAMP by XRE : Lightning speed

1. Lightning : During the lightning speed AAMP will be in paused state and that will be resumed once player is served with play state.

Example here is Fast Forward ( HLS playback ) Case here is similar for DASH playback as well

User pressing fast forward key

2019 Jun 27 14:04:24.147723 pacexi5 Receiver[6829]: Thread-31632 [ECM] - XREKeyPressLog Keyevent sent to server: {"name":"onPreviewKeyDown","timestamp":1561644264140,"handler":2063,"phase":"PREVIEW","event":12840,"source":2063,"params":{"shift":false,"alt":false,"keySource":"physical","rawCode":0,"virtualKeyCode":"FAST_FORWARD","control":false,"meta":false,"elapsedMs":-1091524352,"tid":"a24367ba-4016-4ed3-98b1-ba786039afbd"}}

XRE message for set speed 4 (1x)

2019 Jun 27 14:04:25.127952 pacexi5 Receiver[6829]: Thread-6829 [VideoResource] - playbackmode [VOD] setSpeed [4] REQUEST overshoot[0]

AAMPWebvideo call for set speed

2019 Jun 27 14:04:25.128377 pacexi5 Receiver[6829]: Thread-6829 [AAMP-WEB] - callMethodInBrowser -> calling setSpeed

AAMP native call for set speed

2019 Jun 27 14:04:25.244536 pacexi5 WPEWebProcess[8411]: aamp_SetRate(4)overshoot(0) ProgressReportDelta:(334)
2019 Jun 27 14:04:25.245262 pacexi5 WPEWebProcess[8411]: aamp_SetRate Adj position: 1261.000000
2019 Jun 27 14:04:25.245702 pacexi5 WPEWebProcess[8411]: aamp_SetRate rate(1)->(4)
2019 Jun 27 14:04:25.246048 pacexi5 WPEWebProcess[8411]: aamp_SetRate cur pipeline: playing

Stopping current playback to process trick play for speed 4. Stopping the audio video injector thread

2019 Jun 27 14:04:25.248186 pacexi5 WPEWebProcess[8411]: sleep interrupted!
2019 Jun 27 14:04:25.248311 pacexi5 WPEWebProcess[8411]: sleep interrupted!
2019 Jun 27 14:04:25.248380 pacexi5 WPEWebProcess[8411]: sleep interrupted!
2019 Jun 27 14:04:25.248400 pacexi5 WPEWebProcess[8411]: PrivateInstanceAAMP::BlockUntilGstreamerWantsData interrupted
2019 Jun 27 14:04:25.248552 pacexi5 WPEWebProcess[8411]: fragment injector done. track audio
2019 Jun 27 14:04:25.248737 pacexi5 WPEWebProcess[8411]: sleep interrupted!
2019 Jun 27 14:04:25.248752 pacexi5 WPEWebProcess[8411]: PrivateInstanceAAMP::BlockUntilGstreamerWantsData interrupted
2019 Jun 27 14:04:25.248783 pacexi5 WPEWebProcess[8411]: FetchFragment:1559: audio
2019 Jun 27 14:04:25.248822 pacexi5 WPEWebProcess[8411]: downloads disabled
2019 Jun 27 14:04:25.248833 pacexi5 WPEWebProcess[8411]: FetchFragmentHelper aamp_GetFile failed
2019 Jun 27 14:04:25.248844 pacexi5 WPEWebProcess[8411]: FetchFragment:1641: audio cachedFragment->fragment.ptr is NULL
2019 Jun 27 14:04:25.248858 pacexi5 WPEWebProcess[8411]: RunFetchLoop:3917: fragment collector done. track audio
2019 Jun 27 14:04:25.250715 pacexi5 WPEWebProcess[8411]: StopWaitForPlaylistRefresh:4990 track [audio]
2019 Jun 27 14:04:25.250759 pacexi5 WPEWebProcess[8411]: WaitForCachedFragmentAvailable video aborted
2019 Jun 27 14:04:25.250775 pacexi5 WPEWebProcess[8411]: fragment injector done. track video
2019 Jun 27 14:04:25.251528 pacexi5 WPEWebProcess[8411]: write_callback - interrupted
2019 Jun 27 14:04:25.251775 pacexi5 WPEWebProcess[8411]: HttpRequestEnd: {"url":"http://odol-atsec-pan-29.col-jitp2.xcr.comcast.net/omg11/383/1001/EST_KongSkullIslandHD_E9170020_mezz_LVLH05/track-video-repid-3721200-tc-0-frag-643.ts","curlTime":0.3650,"times":{"total":0.3645,"connect":0.0001,"startTransfer":0.0358,"resolve":0.0001,"appConnect":0.0001,"preTransfer":0.0008,"redirect":0.0000,"dlSz":747549,"ulSz":481},"responseCode":23}
2019 Jun 27 14:04:25.252139 pacexi5 WPEWebProcess[8411]: FetchFragment:1641: video cachedFragment->fragment.ptr is NULL
2019 Jun 27 14:04:25.252159 pacexi5 WPEWebProcess[8411]: RunFetchLoop:3917: fragment collector done. track video
2019 Jun 27 14:04:25.252483 pacexi5 WPEWebProcess[8411]: StopWaitForPlaylistRefresh:4990 track [video]
2019 Jun 27 14:04:25.253718 pacexi5 WPEWebProcess[8411]: Exit StreamAbstractionAAMP::~StreamAbstractionAAMP
2019 Jun 27 14:04:25.253770 pacexi5 WPEWebProcess[8411]: AAMPGstPlayer::Flush:2607 Pipeline is in PLAYING state position 0.000000
2019 Jun 27 14:04:25.253784 pacexi5 WPEWebProcess[8411]: AAMPGstPlayer::Flush:2637 Pipeline flush seek - start = 0.000000

Player level tune initialization and Gstreamer pipeline creation for the playback; iframe manifest request

2019 Jun 27 14:04:25.331697 pacexi5 WPEWebProcess[8411]: hls fragment collector seekpos = 1261.000000
2019 Jun 27 14:04:25.333502 pacexi5 WPEWebProcess[8411]: StreamAbstractionAAMP_HLS::Init:3008 Main manifest retrieved from cache
2019 Jun 27 14:04:25.335177 pacexi5 WPEWebProcess[8411]: ABRMonitor-Reset::{"Reason":"TrickPlay","Bandwidth":508400,"Profile":8}
2019 Jun 27 14:04:25.336212 pacexi5 WPEWebProcess[8411]: NotifyBitRateChangeEvent :: bitrate:508400 desc:BitrateChanged - Network Adaptation width:320 height:180, IndexFromTopProfile: -7
2019 Jun 27 14:04:25.338711 pacexi5 WPEWebProcess[8411]: Selected BitRate: 508400, Max BitRate: 4003200
2019 Jun 27 14:04:25.339983 pacexi5 WPEWebProcess[8411]: TrackState::FetchPlaylist [iframe] start
2019 Jun 27 14:04:25.340009 pacexi5 WPEWebProcess[8411]: aamp url: http://vex-ashburn.mm-col-jitp2.xcr.comcast.net/omg11/383/1001/EST_KongSkullIslandHD_E9170020_mezz_LVLH05/track-iframe-repid-508400-tc-0.m3u8?VP=1001101001_632800_508400_2_0.0_320_180_&isBit=true&StreamType=VOD_T6&AssetId=INTL0617222000346691&ProviderId=indemand.com&DeviceId=E8%3A82%3A5B%3A68%3A9D%3AB8&sid=71b31ca2-f002-40f5-8770-0df32d9078e1-13&dtz=2019-06-27T10%3A03%3A44.959-04%3A00&PartnerId=private%3AComcast
2019 Jun 27 14:04:25.705177 pacexi5 WPEWebProcess[8411]: HttpRequestEnd: {"url":"http://vex-ashburn.mm-col-jitp2.xcr.comcast.net/omg11/383/1001/EST_KongSkullIslandHD_E9170020_mezz_LVLH05/track-iframe-repid-508400-tc-0.m3u8?VP=1001101001_632800_508400_2_0.0_320_180_&isBit=true&StreamType=VOD_T6&AssetId=INTL0617222000346691&ProviderId=indemand.com&DeviceId=E8%3A82%3A5B%3A68%3A9D%3AB8&sid=71b31ca2-f002-40f5-8770-0df32d9078e1-13&dtz=2019-06-27T10%3A03%3A44.959-04%3A00&PartnerId=private%3AComcast","curlTime":0.3640,"times":{"total":0.3644,"connect":0.0446,"startTransfer":0.0901,"resolve":0.0127,"appConnect":0.0000,"preTransfer":0.0452,"redirect":0.0000,"dlSz":625037,"ulSz":745},"responseCode":200}
2019 Jun 27 14:04:25.705335 pacexi5 WPEWebProcess[8411]: UpdateVideoEnd:T:9 br:262144 err:200 dur:0.000000 taTop:48.048000 ttTop:6.006000 tot:58.057999 keyChan:0 encry:0
2019 Jun 27 14:04:25.705367 pacexi5 WPEWebProcess[8411]: TrackState::FetchPlaylist [iframe] end
2019 Jun 27 14:04:25.705395 pacexi5 WPEWebProcess[8411]: aamp: EXT-X-PLAYLIST-TYPE - VOD
2019 Jun 27 14:04:25.705415 pacexi5 WPEWebProcess[8411]: aamp: EXT-X-TARGETDURATION = 3.000000
2019 Jun 27 14:04:25.719488 pacexi5 WPEWebProcess[8411]: aamp_UpdateDuration(7099.384000)
2019 Jun 27 14:04:25.719528 pacexi5 WPEWebProcess[8411]: TheDRMListener::TheDRMListener:116 AveDrm[0x235770]Listner[0x1deca8]Track[0]
2019 Jun 27 14:04:25.719552 pacexi5 WPEWebProcess[8411]: AveDrm::SetMetaData:364[0x235770]Track[0] drmState:0
2019 Jun 27 14:04:25.719565 pacexi5 WPEWebProcess[8411]: SetMetadata:927: Created new AveDrmManager[829c581ab79834352ee735566de732aed14c7332] .Track[0].Total Sz=2
2019 Jun 27 14:04:25.719584 pacexi5 WPEWebProcess[8411]: [AcquireKey][984][0] Request KeyIdx[1] for hash[829c581ab79834352ee735566de732aed14c7332]
2019 Jun 27 14:04:25.741238 pacexi5 WPEWebProcess[8411]: AveDrm::AcquireKey:636[0x235770] drmState:1 Track[0]
2019 Jun 27 14:04:25.741281 pacexi5 WPEWebProcess[8411]: UpdateRefreshPlaylistInterval(): maxRefreshPlaylistIntervalSecs (6.000000)
2019 Jun 27 14:04:25.754203 pacexi5 WPEWebProcess[8411]: GetFormatFromFragmentExtension:2676 fragment extension .ts - FORMAT_MPEGTS
2019 Jun 27 14:04:25.754462 pacexi5 WPEWebProcess[8411]: StreamAbstractionAAMP_HLS::Init : VideoTrack: format is 7 [avc1.]
2019 Jun 27 14:04:25.754475 pacexi5 WPEWebProcess[8411]: StreamAbstractionAAMP_HLS::Init : Configure video TS track demuxing demuxOp 2
2019 Jun 27 14:04:25.754533 pacexi5 WPEWebProcess[8411]: TuneHelper:3768 Updated seek_pos_seconds 1261.000000
2019 Jun 27 14:04:25.926085 pacexi5 WPEWebProcess[8411]: TuneHelper : mFormat 7, mAudioFormat 10
2019 Jun 27 14:04:25.926107 pacexi5 WPEWebProcess[8411]: SetVideoZoom :: ZoomMode 0, using_playersinkbin = 0, video_sink =0x9bb76ee0
2019 Jun 27 14:04:25.926713 pacexi5 WPEWebProcess[8411]: SetVideoMute: muted 0, using_playersinkbin = 0, video_sink =0x9bb76ee0
2019 Jun 27 14:04:25.928519 pacexi5 WPEWebProcess[8411]: AAMPGstPlayer::setVolumeOrMuteUnMute() 2494 > volume = 1.000000, using_playersinkbin = 0, audio_sink = 0x9bb6cdf0
2019 Jun 27 14:04:25.928542 pacexi5 WPEWebProcess[8411]: AAMPGstPlayer::setVolumeOrMuteUnMute 2548 > Setting Volume 1.000000
2019 Jun 27 14:04:25.929015 pacexi5 WPEWebProcess[8411]: AAMPGstPlayer::Configure 1817 > format 7 audioFormat 10

iFrame fragment request, send segment; pipeline state is changing from Paused to Playing after sending the segment

2019 Jun 27 14:04:25.947853 pacexi5 WPEWebProcess[8411]: FetchFragment:1559: iframe
2019 Jun 27 14:04:25.948082 pacexi5 WPEWebProcess[8411]: aamp url: http://odol-atsec-pan-29.col-jitp2.xcr.comcast.net/omg11/383/1001/EST_KongSkullIslandHD_E9170020_mezz_LVLH05/track-iframe-repid-508400-tc-0-frag-630.ts
...
2019 Jun 27 14:04:26.092569 pacexi5 WPEWebProcess[8411]: Sending segment event for mediaType[0]. start 1261000000000 stop 18446744073709551615 rate 1.000000 applied_rate 4.000000
...
2019 Jun 27 14:04:26.130248 pacexi5 WPEWebProcess[8411]: AAMPGstPlayerPipeline PAUSED -> PAUSED (pending PLAYING)
2019 Jun 27 14:04:26.207302 pacexi5 WPEWebProcess[8411]: AAMPGstPlayerPipeline PAUSED -> PLAYING (pending VOID_PENDING)