Inconsistent position change when using seek over dbus

[macpijan]

omxplayer version:

omxplayer --version
omxplayer - Commandline multimedia player for the Raspberry Pi
        Build date: Fri, 28 Feb 2020 11:45:16 +0000
        Version   : b4bbef8 [master]
        Repository: git://github.com/popcornmix/omxplayer.git

Hardware:

• RaspberryPi Zero

Video:

• Generally available Big Buck Bunny 1080p. Slightly converted for this usecase. But the issue was spotted on several different videos.

Expected behavior:

Using the seek over dbus causes the video to change position by the amount provided as the argument (in us).

Spotted behavior:

On average, the actual seek is about 2.2s longer than requested. That average would be fine if it would be reproducible across multiple tries. But there can happen even >8s longer seeks. So in case of a 5s seek, we can get 12-13s seek instead. For 30s seek, we can get 38s seek instead, etc.

A little bit similar to question raised here: https://github.com/popcornmix/omxplayer/issues/624

Scenarios tested:

• status -> seek (5/10/30s) -> status
• pause -> sleep (0/1/5s) -> status -> seek (5/10/30s) -> status -> play

Script used for calculating the position diff:

if [ "$2" = "pause" ]
then
  RES=$(./dbuscontrol.sh pause \
   && sleep $1 \
   && ./dbuscontrol.sh status | grep Position \
   && ./dbuscontrol.sh seek 30000000 \
   && ./dbuscontrol.sh status | grep Position \
   && ./dbuscontrol.sh pause \
   && ./dbuscontrol.sh status | grep Position)
else
  RES=$(./dbuscontrol.sh status | grep Position \
   && ./dbuscontrol.sh seek 30000000 \
   && ./dbuscontrol.sh status | grep Position)
fi

POS_BEFORE=$(echo $RES | cut -d ' ' -f 2)
POS_AFTER=$(echo $RES | cut -d ' ' -f 4)

POS_DIFF=$(($POS_AFTER - $POS_BEFORE))

Results:

[pietrushnic]

@popcornmix any ideas about how to approach this bug?

[macpijan]

It looks like the crucial thing is the starting position (when the seek command was executed). The test scenario was:

Start the video -> sleep (1..25s) -> get current position -> seek 5s forward -> get current position

It looks like there are some "predefined" positions where seek can move us into.

How to read below logs:

Example:

Seek to: 00:00:05
12781427 - 237127 = 12544300

00:00:05 - the absolute position to seek into, according to omxplayer it will move us to the 5s position

12781427 - the real position we were moved to, around 12.7s in this case 237127 - the starting position (in us) 12544300 - the real seek value (in us) - around 12.5s

Logs:

Seek to: 00:00:05
12781427 - 237127 = 12544300

Seek to: 00:00:06
12654845 - 1158119 = 11496726

Seek to: 00:00:07
12740080 - 1901248 = 10838832

Seek to: 00:00:08
12735887 - 2888053 = 9847834

Seek to: 00:00:09
12711618 - 3919223 = 8792395

Seek to: 00:00:10
12766978 - 4950758 = 7816220

Seek to: 00:00:11
12722977 - 5962109 = 6760868

Seek to: 00:00:12
12804131 - 6914779 = 5889352

Seek to: 00:00:13
16412438 - 7929892 = 8482546

Seek to: 00:00:14
16432898 - 8882762 = 7550136

Seek to: 00:00:15
16407923 - 9909574 = 6498349

Seek to: 00:00:16
16430680 - 10887941 = 5542739

Seek to: 00:00:17
20308645 - 11933410 = 8375235

Seek to: 00:00:18
20345075 - 12915285 = 7429790

Seek to: 00:00:19
20289029 - 13925843 = 6363186

Seek to: 00:00:20
20326341 - 14885173 = 5441168

Seek to: 00:00:20
20268911 - 14887504 = 5381407

Seek to: 00:00:22
27531961 - 16818756 = 10713205

Seek to: 00:00:23
27569733 - 17862795 = 9706938

Seek to: 00:00:24
27662837 - 18925581 = 8737256

Seek to: 00:00:25
27610534 - 19935387 = 7675147

Seek to: 00:00:26
27573341 - 20846775 = 6726566

Seek to: 00:00:27
27586781 - 21944912 = 5641869

Seek to: 00:00:28
35916633 - 22924122 = 12992511

Seek to: 00:00:29
36012541 - 23827803 = 12184738

With each second sleep the difference between requested and real seek value is lower. Until we pass a certain "seekable" point.

The positions we can seek into are (in case of this video) roughly:

• 12.7s, 16.4s, 20s, 27,5s, 36s The seek forward moves forward by the value of (requested seek value + number of us to the next "seekable position").

[macpijan]

Per some additional research, it looks like the omxplayers seeks to the next keyframe. For my video the keyframes are:

ffprobe -loglevel error -select_streams v:0 -show_entries packet=pts_time,flags -of csv=print_section=0 bbb_sunflower_1080p_24fps_normal.mp4 | awk -F',' '/K/ {print $1}' 
0.000000
4.233333
12.566667
16.300000
20.166667
27.466667
35.800000
39.766667
48.100000
...

which matches the experimental results.

[popcornmix]

Yep that looks right. You can only start decoding video from a keyframe.

[macpijan]

@popcornmix Thanks. It does make more sense now when I read more about the video formats etc. I know some players do support seeking to a precise timestamp (e.g. VLC). Do you think it is theoretically possible for the omxplayer to support such thing as well, or there are other restrictions in this case (like the OMX API)?

[macpijan]

Apparently, this is how the accurate seek is usually implemented:

To start playback from non-keyframe position in a video, the player has to go back to the previous
key frame and start decoding from there until it reaches your selected position, at which point it will
 resume playback. This means that sometimes playback will take a while to start, whereas at other
 times it will be almost instant.