Trick Play Flow and Analysis

Created on June 21, 2022


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 : 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

[AAMP-PLAYER] aamp-cli> ff 4
1615825050:101 : [AAMP-PLAYER]aamp_SetRate(4)overshoot(0) ProgressReportDelta:(105) 
1615825050:101 : [AAMP-PLAYER]aamp_SetRate Adj position: 6.000000
1615825050:101 : [AAMP-PLAYER]aamp_SetRate rate(1)->(4)
1615825050:101 : [AAMP-PLAYER]aamp_SetRate cur pipeline: playing
1615825050:101 : [AAMP-PLAYER]TeardownStream:4580 mProgressReportFromProcessDiscontinuity:0 mDiscontinuityTuneOperationId:0 newTune:0
1615825050:102 : [AAMP-PLAYER]StopWaitForPlaylistRefresh:7118 track 
1615825050:102 : [AAMP-PLAYER]StopWaitForPlaylistRefresh:7118 track 
1615825050:102 : [AAMP-PLAYER]StopWaitForPlaylistRefresh:7118 track 
1615825050:104 : [AAMP-PLAYER]AAMPGstPlayer::Flush:3440 Pipeline is in PLAYING state position 0.000000 ret 1

1615825050:108 : [AAMP-PLAYER]alsasink1 PAUSED -> PAUSED (pending PAUSED)
1615825050:108 : [AAMP-PLAYER]abin PAUSED -> PAUSED (pending PAUSED)
1615825050:109 : [AAMP-PLAYER]playsink PAUSED -> PAUSED (pending PAUSED)
1615825050:109 : [AAMP-PLAYER]playbin3 PAUSED -> PAUSED (pending PAUSED)
1615825050:109 : [AAMP-PLAYER]AAMPGstPlayerPipeline PAUSED -> PAUSED (pending PAUSED)
1615825050:109 : [AAMP-PLAYER]msg type: reset-time
1615825050:145 : [AAMP-PLAYER]westerossink1 PAUSED -> PAUSED (pending PAUSED)
1615825050:145 : [AAMP-PLAYER]vbin PAUSED -> PAUSED (pending PAUSED)
1615825050:145 : [AAMP-PLAYER]playsink PAUSED -> PAUSED (pending PAUSED)
1615825050:145 : [AAMP-PLAYER]playbin2 PAUSED -> PAUSED (pending PAUSED)
1615825050:146 : [AAMP-PLAYER]msg type: reset-time
1615825050:146 : [AAMP-PLAYER]PlayerInstanceAAMP() : AVE DRM disabled
1615825050:146 : [AAMP-PLAYER]hls fragment collector seekpos = 6.000000
1615825050:146 : [AAMP-PLAYER]StreamAbstractionAAMP_HLS::Init:4073 Main manifest retrieved from cache
1615825050:147 : [AAMP-PLAYER]StreamAbstractionAAMP_HLS::GetPlaylistURI():3418 Couldn't find subtitle URI for preferred language: 
1615825050:628 : [AAMP-PLAYER]aamp: EXT-X-PLAYLIST-TYPE - VOD
1615825050:628 : [AAMP-PLAYER]IndexPlaylist iframe StartTimeForPlaylistSync : 0.000000 
1615825050:629 : [AAMP-PLAYER]GetCompletionTimeForFragment:2232 bad index! mediaSequenceNumber=-1, indexFirstMediaSequenceNumber=0
1615825050:629 : [AAMP-PLAYER]GetFormatFromFragmentExtension:3496 Could not find extension from line KeyFrames(video=0,format=m3u8-aapl)
1615825050:629 : [AAMP-PLAYER]StreamAbstractionAAMP_HLS::GetStreamOutputFormatForTrack 7720 Track[0] format is 7 [avc1.]
1615825050:629 : [AAMP-PLAYER]StreamAbstractionAAMP_HLS::Init : Configure video TS track demuxing demuxOp 2
1615825050:629 : [AAMP-PLAYER]StreamAbstractionAAMP_HLS::Init:4816 seek target out of range, mark EOS. playTarget:6.000000 End:6.366000. 
1615825050:629 : [AAMP-PLAYER]mpStreamAbstractionAAMP Init Failed.Seek Position(6.000000) out of range(6)
1615825050:629 : [AAMP-PLAYER]NotifyEOSReached: Enter . processingDiscontinuity 0
1615825050:629 : [AAMP-PLAYER]SetCallbackAsDispatched:7585 id not in mPendingAsyncEvents, insert and mark as not pending
1615825050:629 : [AAMP-PLAYER]AAMP_EVENT_EOS
1615825050:629 : [AAMP-PLAYER]SetCallbackAsPending:7602 id already in mPendingAsyncEvents and completed, erase it
1615825050:629 : [AAMP-PLAYER]SetCallbackAsDispatched:7585 id not in mPendingAsyncEvents, insert and mark as not pending
1615825050:629 : [AAMP-PLAYER]SetCallbackAsPending:7602 id already in mPendingAsyncEvents and completed, erase it
1615825050:629 : [AAMP-PLAYER]SetCallbackAsDispatched:7585 id not in mPendingAsyncEvents, insert and mark as not pending
1615825050:629 : [AAMP-PLAYER]AAMP_EVENT_SPEED_CHANGED
1615825050:629 : [AAMP-PLAYER]SetCallbackAsPending:7602 id already in mPendingAsyncEvents and completed, erase it
[AAMP-PLAYER] aamp-cli>

Logs for Set Speed : rate(1)->(16) , rate(16)->(32)

ff16
1620190306:905 : [AAMP-PLAYER]aamp_SetRate(16)overshoot(0) ProgressReportDelta:(726)
1620190306:905 : [AAMP-PLAYER]aamp_SetRate Adj position: 6.000000
1620190306:905 : [AAMP-PLAYER]aamp_SetRate rate(1)->(16)
1620190306:905 : [AAMP-PLAYER]aamp_SetRate cur pipeline: playing
...

ff32
1620190383:948 : [AAMP-PLAYER]## AAMPGstPlayer_OnGstBufferUnderflowCb() : Got Underflow message from westerossink2 ##

1620190384:134 : [AAMP-PLAYER]aamp_SetRate(32)overshoot(0) ProgressReportDelta:(875)
1620190384:134 : [AAMP-PLAYER]aamp_SetRate Adj position: 558.000000
1620190384:135 : [AAMP-PLAYER]aamp_SetRate rate(16)->(32)
1620190384:135 : [AAMP-PLAYER]aamp_SetRate cur pipeline: playing
1620190384:135 : [AAMP-PLAYER]TeardownStream:4577 mProgressReportFromProcessDiscontinuity:0 mDiscontinuityTuneOperationId:0 newTune:0
1620190384:135 : [AAMP-PLAYER]WaitForCachedFragmentAvailable iframe aborted
1620190384:135 : [AAMP-PLAYER]fragment injector done. track iframe
1620190384:436 : [AAMP-PLAYER]HttpRequestEnd: 0,0,42,0.5870,0.5802,0.0001,0.5801,0.0001,0.0001,0.0002,0.0000,0,296,https://<>/VideoTestStream/hls/iframe_573.ts
1620190384:437 : [AAMP-PLAYER]FetchFragment:2080 iframe Already at the lowest profile, skipping segment
1620190384:437 : [AAMP-PLAYER]RunFetchLoop:5473: fragment collector done. track iframe

AAMP native call for set speed

[AAMP-PLAYER] aamp-cli> ff 4
1615825050:101 : [AAMP-PLAYER]aamp_SetRate(4)overshoot(0) ProgressReportDelta:(105)
1615825050:101 : [AAMP-PLAYER]aamp_SetRate Adj position: 6.000000
1615825050:101 : [AAMP-PLAYER]aamp_SetRate rate(1)->(4)
1615825050:101 : [AAMP-PLAYER]aamp_SetRate cur pipeline: playing

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

1615828166:962 : [AAMP-PLAYER]SetRate:433 PLAYER[0] rate=4.
1615828166:962 : [AAMP-PLAYER]aamp_SetRate(4)overshoot(0) ProgressReportDelta:(56596) 
1615828166:962 : [AAMP-PLAYER]aamp_SetRate Adj position: 0.000000
1615828166:962 : [AAMP-PLAYER]aamp_SetRate rate(1)->(4)
1615828166:962 : [AAMP-PLAYER]aamp_SetRate cur pipeline: playing
1615828166:962 : [AAMP-PLAYER]TeardownStream:4580 mProgressReportFromProcessDiscontinuity:0 mDiscontinuityTuneOperationId:0 newTune:0
1615828166:963 : [AAMP-PLAYER]StopWaitForPlaylistRefresh:7118 track 
1615828166:963 : [AAMP-PLAYER]RunFetchLoop:5473: fragment collector done. track audio
1615828166:963 : [AAMP-PLAYER]RunFetchLoop:5473: fragment collector done. track video
1615828166:963 : [AAMP-PLAYER]WaitForCachedFragmentAvailable audio aborted
1615828166:963 : [AAMP-PLAYER]fragment injector done. track audio
1615828166:963 : [AAMP-PLAYER]WaitForCachedFragmentAvailable video aborted
1615828166:963 : [AAMP-PLAYER]fragment injector done. track video

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

2021 Apr 05 05:37:12.507919 WPEWebProcess[9456]: [AAMP-PLAYER]AAMPGstPlayer::Flush:3443 Pipeline is in PLAYING state position 0.000000 ret 1
2021 Apr 05 05:37:12.549339 WPEFramework[6988]: 11:07:12:549 INFO  av_sync_destroy:197: begin
2021 Apr 05 05:37:12.549743 WPEFramework[6988]: 11:07:12:549 INFO  tsync_send_video_stop:112: video stop
2021 Apr 05 05:37:12.551656 WPEFramework[6988]: 11:07:12:551 INFO  av_sync_destroy:211: done
2021 Apr 05 05:37:12.684439 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::UpdateMPD:4323 manifest retrieved from cache
2021 Apr 05 05:37:12.687421 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::Init:3725 - MPD duration str PT888.053S val 888 seconds
2021 Apr 05 05:37:12.687502 WPEWebProcess[9456]: [AAMP-PLAYER]GetPeriodEndTime:3438 :  Period startTime required to calculate period duration not present in MPD
2021 Apr 05 05:37:12.687550 WPEWebProcess[9456]: [AAMP-PLAYER]GetBestAudioTrackByLanguage: aamp->language en, aamp->noExplicitUserLanguageSelection false, aamp->preferredLanguages "en"
2021 Apr 05 05:37:12.687593 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection 5583 > lang[en] AudioType[2]
2021 Apr 05 05:37:12.687637 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection 5845 > Media Adaptation set[10] RepIdx[-1] TrackCnt[1]
2021 Apr 05 05:37:12.687659 WPEWebProcess[9456]: [AAMP-PLAYER]ProcessContentProtection:3140 (video) Skipping creation of session for duplicate helper
2021 Apr 05 05:37:12.687682 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection 5858 > Media enabled
2021 Apr 05 05:37:12.687720 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection() 5759 Audio Track - lang:en, group:main, name:11, codec:mp4a.40.2, bandwidth:132445
2021 Apr 05 05:37:12.687752 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection() 5759 Audio Track - lang:en, group:main, name:23, codec:opus, bandwidth:130600
2021 Apr 05 05:37:12.687777 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection 5845 > Media Adaptation set[11] RepIdx[0] TrackCnt[2]
2021 Apr 05 05:37:12.687800 WPEWebProcess[9456]: [AAMP-PLAYER]ProcessContentProtection:3140 (audio) Skipping creation of session for duplicate helper
2021 Apr 05 05:37:12.687822 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection 5858 > Media enabled
2021 Apr 05 05:37:12.687847 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection() 5765 Text Track - lang:nl, isCC:0, group:, name:0, codec:
2021 Apr 05 05:37:12.687874 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection() 5765 Text Track - lang:en, isCC:0, group:main, name:1, codec:
2021 Apr 05 05:37:12.687900 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection() 5765 Text Track - lang:fr, isCC:0, group:, name:2, codec:
2021 Apr 05 05:37:12.687996 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection() 5765 Text Track - lang:de, isCC:0, group:, name:3, codec:
2021 Apr 05 05:37:12.688020 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection() 5765 Text Track - lang:it, isCC:0, group:, name:4, codec:
2021 Apr 05 05:37:12.688051 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection() 5765 Text Track - lang:pl, isCC:0, group:, name:5, codec:
2021 Apr 05 05:37:12.688074 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection() 5765 Text Track - lang:pt, isCC:0, group:, name:6, codec:
2021 Apr 05 05:37:12.688099 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection() 5765 Text Track - lang:ru, isCC:0, group:, name:7, codec:
2021 Apr 05 05:37:12.688123 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection() 5765 Text Track - lang:es, isCC:0, group:, name:8, codec:
2021 Apr 05 05:37:12.688151 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection() 5765 Text Track - lang:vi, isCC:0, group:, name:9, codec:
2021 Apr 05 05:37:12.688181 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection 5854 > No valid adaptation set found for Media[text]
2021 Apr 05 05:37:12.688202 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::StreamSelection 5858 > Media[text] disabled
2021 Apr 05 05:37:12.688280 WPEWebProcess[9456]: [ABRManager] getInitialProfileIndex:195 Get initial profile index = 8, bitrate = 9260354 and defaultBitrate = 13000000
                                                 
2021 Apr 05 05:37:12.688316 WPEWebProcess[9456]: [AAMP-PLAYER]GetPeriodEndTime:3438 :  Period startTime required to calculate period duration not present in MPD
2021 Apr 05 05:37:12.688346 WPEWebProcess[9456]: [AAMP-PLAYER]GetPeriodEndTime:3438 :  Period startTime required to calculate period duration not present in MPD
2021 Apr 05 05:37:13.620380 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::Init:4199 - fetch initialization fragments
2021 Apr 05 05:37:14.311736 WPEWebProcess[9456]: [AAMP-PLAYER]TuneHelper:4984 Updated seek_pos_seconds 48.000000 culledSeconds :0.000000
2021 Apr 05 05:37:14.411902 WPEWebProcess[9456]: [AAMP-PLAYER]AAMPGstPlayer::Flush:3443 Pipeline is in PAUSED state position 0.000000 ret 2
2021 Apr 05 05:37:14.436695 WPEWebProcess[9456]: [AAMP-PLAYER]AAMPGstPlayer::Configure 2484 > format 2 audioFormat 2

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

2021 Apr 05 05:37:13.620380 WPEWebProcess[9456]: [AAMP-PLAYER]PrivateStreamAbstractionMPD::Init:4199 - fetch initialization fragments
2021 Apr 05 05:37:14.311736 WPEWebProcess[9456]: [AAMP-PLAYER]TuneHelper:4984 Updated seek_pos_seconds 48.000000 culledSeconds :0.000000
2021 Apr 05 05:37:14.411902 WPEWebProcess[9456]: [AAMP-PLAYER]AAMPGstPlayer::Flush:3443 Pipeline is in PAUSED state position 0.000000 ret 2
2021 Apr 05 05:37:14.436695 WPEWebProcess[9456]: [AAMP-PLAYER]AAMPGstPlayer::Configure 2484 > format 2 audioFormat 2
2021 Apr 05 05:37:14.437313 WPEWebProcess[9456]: [AAMP-PLAYER]fragment injector started. track audio
2021 Apr 05 05:37:14.437685 WPEWebProcess[9456]: [AAMP-PLAYER]msg type: reset-time
2021 Apr 05 05:37:14.440511 WPEFramework[6988]: gst_qtdemux_handle_sink_event:2320 - aamp_override - enabled = 0, player = 1, rate  1.000000
2021 Apr 05 05:37:14.440936 WPEFramework[6988]: http://<>/players/version10/js/src/Mediaplayer.js:898:32: CONSOLE LOG AAMP: progress update: {"event":{"durationMiliseconds":888053,"positionMiliseconds":48000,"playbackSpeed":1,"startMiliseconds":0,"endMiliseconds":888053,"currentPTS":-1,"videoBufferedMiliseconds":0}}
2021 Apr 05 05:37:14.441402 WPEFramework[6988]: http://<>/players/version10/js/src/Mediaplayer.js:904:32: CONSOLE LOG Mediaplayer.playbackProgressUpdate (AAMP): currentTime (ms): 48000
2021 Apr 05 05:37:14.437854 WPEWebProcess[9456]: [AAMP-PLAYER]Sending segment event for mediaType[1]. start 48006000518 stop 18446744073709551615 rate 1.000000 applied_rate 1.000000
2021 Apr 05 05:37:14.442513 WPEFramework[6988]: AAMPMediaPlayerJS_getSupportedKeySystems(): Invoked getSupportedKeySystems
2021 Apr 05 05:37:14.443078 WPEFramework[6988]: gst_qtdemux_handle_sink_event:2320 - aamp_override - enabled = 0, player = 1, rate  1.000000
2021 Apr 05 05:37:14.440626 WPEWebProcess[9456]: [AAMP-PLAYER]AAMPGstPlayerPipeline PAUSED -> PAUSED (pending PAUSED)
2021 Apr 05 05:37:14.440668 WPEWebProcess[9456]: [AAMP-PLAYER]msg type: reset-time
2021 Apr 05 05:37:14.440705 WPEWebProcess[9456]: [AAMP-PLAYER]msg type: reset-time
2021 Apr 05 05:37:14.440753 WPEWebProcess[9456]: [AAMP-PLAYER]msg type: reset-time
2021 Apr 05 05:37:14.440821 WPEWebProcess[9456]: [AAMP-PLAYER]fragment injector started. track video
2021 Apr 05 05:37:14.441054 WPEWebProcess[9456]: [AAMP-PLAYER]Sending segment event for mediaType[0]. start 48000000000 stop 18446744073709551615 rate 1.000000 applied_rate 1.000000
...
2021 Apr 05 05:37:17.118008 WPEWebProcess[9456]: [AAMP-PLAYER]AAMPGstPlayerPipeline PAUSED -> PAUSED (pending VOID_PENDING) 
...
2021 Apr 05 05:37:17.268459 WPEWebProcess[9456]: [AAMP-PLAYER]AAMPGstPlayerPipeline PAUSED -> PLAYING (pending VOID_PENDING)

Previous
HLS Playback Analysis
Next
Triage Guidelines
Go To Top