Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Strange unexplained time jump with SimpleCache #1755

Open
1 task
Tolriq opened this issue Sep 25, 2024 · 0 comments
Open
1 task

Strange unexplained time jump with SimpleCache #1755

Tolriq opened this issue Sep 25, 2024 · 0 comments
Assignees

Comments

@Tolriq
Copy link
Contributor

Tolriq commented Sep 25, 2024

Version

Media3 pre-release (alpha, beta or RC not in this list)

More version details

1.5.0 alpha 1

Devices that reproduce the issue

Does not seems tied to device

Devices that do not reproduce the issue

No response

Reproducible in the demo app?

Not tested

Reproduction steps

I unfortunately do not have a reproduction step, but from a few reports it only happens when using SimpleCache and not tied to specific media.

Expected result

The song correctly plays till the end or there's an error somewhere logged to be able to react and eventually cleanup the cache.

Actual result

See https://www.youtube.com/watch?v=_G3WU6cNf50 near 2:17 in the video the timeline jumps near the end without audible issue, then the song ends and the next plays.

Logs:

2024-09-25 10:23:30.276 Verbose ExoPlayer timeline [eventTime=791.70, mediaPos=0.00, window=0, periodCount=1, windowCount=1, reason=PLAYLIST_CHANGED 
2024-09-25 10:23:30.276 Verbose ExoPlayer period [?] 
2024-09-25 10:23:30.276 Verbose ExoPlayer window [?, seekable=false, dynamic=true] 
2024-09-25 10:23:30.277 Verbose ExoPlayer ] 
2024-09-25 10:23:30.277 Verbose ExoPlayer mediaItem [eventTime=791.70, mediaPos=0.00, window=0, reason=PLAYLIST_CHANGED] 
2024-09-25 10:23:30.278 Verbose ExoPlayer state [eventTime=791.70, mediaPos=0.00, window=0, BUFFERING] 
2024-09-25 10:23:30.278 Verbose ExoPlayer positionDiscontinuity [eventTime=791.70, mediaPos=0.00, window=0, reason=SEEK, PositionInfo:old [mediaItem=0, period=0, pos=0], PositionInfo:new [mediaItem=0, period=0, pos=0]] 
2024-09-25 10:23:30.286 Verbose ExoPlayer playWhenReady [eventTime=791.71, mediaPos=0.00, window=0, true, USER_REQUEST] 
2024-09-25 10:23:30.298 Verbose ExoPlayer timeline [eventTime=791.71, mediaPos=0.00, window=0, period=0, periodCount=1, windowCount=1, reason=SOURCE_UPDATE 
2024-09-25 10:23:30.298 Verbose ExoPlayer period [?] 
2024-09-25 10:23:30.299 Verbose ExoPlayer window [?, seekable=false, dynamic=false] 
2024-09-25 10:23:30.299 Verbose ExoPlayer ] 
2024-09-25 10:23:30.300 Verbose ExoPlayer loading [eventTime=791.71, mediaPos=0.00, window=0, period=0, true] 
2024-09-25 10:23:30.300 Verbose ExoPlayer timeline [eventTime=791.71, mediaPos=0.00, window=0, period=0, periodCount=1, windowCount=1, reason=SOURCE_UPDATE 
2024-09-25 10:23:30.301 Verbose ExoPlayer period [214.69] 
2024-09-25 10:23:30.302 Verbose ExoPlayer window [214.69, seekable=true, dynamic=false] 
2024-09-25 10:23:30.308 Verbose ExoPlayer ] 
2024-09-25 10:23:30.312 Verbose ExoPlayer audioEnabled [eventTime=791.71, mediaPos=0.00, window=0, period=0] 
2024-09-25 10:23:30.314 Verbose ExoPlayer tracks [eventTime=791.71, mediaPos=0.00, window=0, period=0 
2024-09-25 10:23:30.315 Verbose ExoPlayer group [ 
2024-09-25 10:23:30.315 Verbose ExoPlayer [X] Track:0, id=null, mimeType=audio/flac, pcmEncoding=21, channels=2, sample_rate=48000, supported=YES 
2024-09-25 10:23:30.316 Verbose ExoPlayer ] 
2024-09-25 10:23:30.316 Verbose ExoPlayer Metadata [ 
2024-09-25 10:23:30.316 Verbose ExoPlayer VC: ARTIST=水曜日のカンパネラ 
2024-09-25 10:23:30.317 Verbose ExoPlayer VC: TITLE=赤猫 
2024-09-25 10:23:30.317 Verbose ExoPlayer VC: ALBUM=POP DELIVERY 
2024-09-25 10:23:30.318 Verbose ExoPlayer VC: DATE=2024.06.05 
2024-09-25 10:23:30.318 Verbose ExoPlayer VC: GENRE=J-Pop 
2024-09-25 10:23:30.319 Verbose ExoPlayer VC: COMPOSER=Kenmochi Hidefumi 
2024-09-25 10:23:30.322 Verbose ExoPlayer VC: ALBUMARTIST=水曜日のカンパネラ 
2024-09-25 10:23:30.323 Verbose ExoPlayer VC: TRACKNUMBER=1 
2024-09-25 10:23:30.323 Verbose ExoPlayer VC: TRACKTOTAL=8 
2024-09-25 10:23:30.323 Verbose ExoPlayer VC: DISCNUMBER=1 
2024-09-25 10:23:30.324 Verbose ExoPlayer VC: DISCTOTAL=1 
2024-09-25 10:23:30.324 Verbose ExoPlayer VC: COPYRIGHT=℗© 2024 WARNER MUSIC JAPAN INC. 
2024-09-25 10:23:30.324 Verbose ExoPlayer VC: LABEL=WM Japan 
2024-09-25 10:23:30.325 Verbose ExoPlayer ] 
2024-09-25 10:23:30.325 Verbose ExoPlayer ] 
2024-09-25 10:23:30.325 Verbose ExoPlayer downstreamFormat [eventTime=791.71, mediaPos=0.00, window=0, period=0, id=null, mimeType=audio/flac, pcmEncoding=21, channels=2, sample_rate=48000] 
2024-09-25 10:23:30.326 Verbose ExoPlayer audioDecoderInitialized [eventTime=791.71, mediaPos=0.00, window=0, period=0, ffmpegLavc60.3.100-flac] 
2024-09-25 10:23:30.326 Verbose ExoPlayer audioInputFormat [eventTime=791.71, mediaPos=0.00, window=0, period=0, id=null, mimeType=audio/flac, pcmEncoding=21, channels=2, sample_rate=48000] 
2024-09-25 10:23:30.326 Verbose ExoPlayer rendererReady [eventTime=791.71, mediaPos=0.00, window=0, period=0, rendererIndex=0, audio, true] 
2024-09-25 10:23:30.327 Verbose ExoPlayer timeline [eventTime=791.72, mediaPos=0.00, window=0, period=0, periodCount=2, windowCount=2, reason=PLAYLIST_CHANGED 
2024-09-25 10:23:30.327 Verbose ExoPlayer period [214.69] 
2024-09-25 10:23:30.328 Verbose ExoPlayer period [?] 
2024-09-25 10:23:30.328 Verbose ExoPlayer window [214.69, seekable=true, dynamic=false] 
2024-09-25 10:23:30.331 Verbose ExoPlayer window [?, seekable=false, dynamic=true] 
2024-09-25 10:23:30.333 Verbose ExoPlayer ] 
2024-09-25 10:23:30.349 Verbose ExoPlayer audioTrackInit [eventTime=791.75, mediaPos=0.00, window=0, period=0, 4,12,48000,false,false,2106368] 
2024-09-25 10:23:30.353 Verbose ExoPlayer state [eventTime=791.77, mediaPos=0.00, window=0, period=0, READY] 
2024-09-25 10:23:30.354 Verbose ExoPlayer isPlaying [eventTime=791.77, mediaPos=0.00, window=0, period=0, true] 
2024-09-25 10:23:30.633 Verbose ExoPlayer loading [eventTime=792.06, mediaPos=0.00, window=0, period=0, false] 
2024-09-25 10:23:32.716 Verbose ExoPlayer loading [eventTime=794.14, mediaPos=2.04, window=0, period=0, true] 
2024-09-25 10:23:32.731 Verbose ExoPlayer loading [eventTime=794.16, mediaPos=2.05, window=0, period=0, false] 
2024-09-25 10:23:37.015 Verbose ExoPlayer loading [eventTime=798.44, mediaPos=6.34, window=0, period=0, true] 
2024-09-25 10:23:37.032 Verbose ExoPlayer loading [eventTime=798.46, mediaPos=6.35, window=0, period=0, false] 
2024-09-25 10:23:41.245 Verbose ExoPlayer loading [eventTime=802.67, mediaPos=10.58, window=0, period=0, true] 
2024-09-25 10:23:41.270 Verbose ExoPlayer loading [eventTime=802.69, mediaPos=10.60, window=0, period=0, false] 
2024-09-25 10:23:45.529 Verbose ExoPlayer loading [eventTime=806.95, mediaPos=14.86, window=0, period=0, true] 
2024-09-25 10:23:45.555 Verbose ExoPlayer loading [eventTime=806.98, mediaPos=14.88, window=0, period=0, false] 
2024-09-25 10:23:49.888 Verbose ExoPlayer loading [eventTime=811.31, mediaPos=19.22, window=0, period=0, true] 
2024-09-25 10:23:49.923 Verbose ExoPlayer loading [eventTime=811.35, mediaPos=19.25, window=0, period=0, false] 
2024-09-25 10:23:54.227 Verbose ExoPlayer loading [eventTime=815.65, mediaPos=23.56, window=0, period=0, true] 
2024-09-25 10:23:54.272 Verbose ExoPlayer loading [eventTime=815.70, mediaPos=23.60, window=0, period=0, false] 
2024-09-25 10:23:58.682 Verbose ExoPlayer loading [eventTime=820.11, mediaPos=28.01, window=0, period=0, true] 
2024-09-25 10:23:58.727 Verbose ExoPlayer loading [eventTime=820.15, mediaPos=28.05, window=0, period=0, false] 
2024-09-25 10:24:03.127 Verbose ExoPlayer loading [eventTime=824.55, mediaPos=32.46, window=0, period=0, true] 
2024-09-25 10:24:03.163 Verbose ExoPlayer loading [eventTime=824.59, mediaPos=32.49, window=0, period=0, false] 
2024-09-25 10:24:07.487 Verbose ExoPlayer loading [eventTime=828.91, mediaPos=36.82, window=0, period=0, true] 
2024-09-25 10:24:07.526 Verbose ExoPlayer loading [eventTime=828.95, mediaPos=36.85, window=0, period=0, false] 
2024-09-25 10:24:11.910 Verbose ExoPlayer loading [eventTime=833.34, mediaPos=41.24, window=0, period=0, true] 
2024-09-25 10:24:11.947 Verbose ExoPlayer loading [eventTime=833.37, mediaPos=41.27, window=0, period=0, false] 
2024-09-25 10:24:16.431 Verbose ExoPlayer loading [eventTime=837.85, mediaPos=45.76, window=0, period=0, true] 
2024-09-25 10:24:16.484 Verbose ExoPlayer loading [eventTime=837.91, mediaPos=45.81, window=0, period=0, false] 
2024-09-25 10:24:20.894 Verbose ExoPlayer loading [eventTime=842.32, mediaPos=50.21, window=0, period=0, true] 
2024-09-25 10:24:20.929 Verbose ExoPlayer loading [eventTime=842.35, mediaPos=50.24, window=0, period=0, false] 
2024-09-25 10:24:25.317 Verbose ExoPlayer loading [eventTime=846.74, mediaPos=54.64, window=0, period=0, true] 
2024-09-25 10:24:25.359 Verbose ExoPlayer loading [eventTime=846.78, mediaPos=54.68, window=0, period=0, false] 
2024-09-25 10:24:29.769 Verbose ExoPlayer loading [eventTime=851.19, mediaPos=59.09, window=0, period=0, true] 
2024-09-25 10:24:29.814 Verbose ExoPlayer loading [eventTime=851.24, mediaPos=59.13, window=0, period=0, false] 
2024-09-25 10:24:34.258 Verbose ExoPlayer loading [eventTime=855.68, mediaPos=63.58, window=0, period=0, true] 
2024-09-25 10:24:34.298 Verbose ExoPlayer loading [eventTime=855.72, mediaPos=63.62, window=0, period=0, false] 
2024-09-25 10:24:38.778 Verbose ExoPlayer loading [eventTime=860.20, mediaPos=68.10, window=0, period=0, true] 
2024-09-25 10:24:38.830 Verbose ExoPlayer loading [eventTime=860.26, mediaPos=68.15, window=0, period=0, false] 
2024-09-25 10:24:43.009 Verbose ExoPlayer loading [eventTime=864.43, mediaPos=72.34, window=0, period=0, true] 
2024-09-25 10:24:43.046 Verbose ExoPlayer loading [eventTime=864.47, mediaPos=72.37, window=0, period=0, false] 
2024-09-25 10:24:47.387 Verbose ExoPlayer loading [eventTime=868.81, mediaPos=76.72, window=0, period=0, true] 
2024-09-25 10:24:47.393 Verbose ExoCacheManager Cache read: 883a7c43-14dc-4b91-9714-1b35bf89bd63 - 32.0 MB/4.0 GB [B:-1-/mnt/Music/Japanese/水曜日のカンパネラ/Albums/[2024.06.05] POP DELIVERY/01. 赤猫.flac] 
2024-09-25 10:24:47.395 Verbose ExoPlayer loading [eventTime=868.82, mediaPos=76.72, window=0, period=0, false] 
2024-09-25 10:24:47.396 Verbose ExoPlayer loading [eventTime=868.82, mediaPos=76.73, window=0, period=0, true] 
2024-09-25 10:24:47.397 Verbose ExoPlayer timeline [eventTime=868.82, mediaPos=76.73, window=0, period=0, periodCount=2, windowCount=2, reason=SOURCE_UPDATE 
2024-09-25 10:24:47.397 Verbose ExoPlayer period [214.69] 
2024-09-25 10:24:47.398 Verbose ExoPlayer period [?] 
2024-09-25 10:24:47.398 Verbose ExoPlayer window [214.69, seekable=true, dynamic=false] 
2024-09-25 10:24:47.399 Verbose ExoPlayer window [?, seekable=false, dynamic=false] 
2024-09-25 10:24:47.400 Verbose ExoPlayer ] 
2024-09-25 10:24:47.401 Verbose ExoPlayer timeline [eventTime=868.83, mediaPos=76.73, window=0, period=0, periodCount=2, windowCount=2, reason=SOURCE_UPDATE 
2024-09-25 10:24:47.401 Verbose ExoPlayer period [214.69] 
2024-09-25 10:24:47.402 Verbose ExoPlayer period [179.44] 
2024-09-25 10:24:47.402 Verbose ExoPlayer window [214.69, seekable=true, dynamic=false] 
2024-09-25 10:24:47.402 Verbose ExoPlayer window [179.44, seekable=true, dynamic=false] 
2024-09-25 10:24:47.403 Verbose ExoPlayer ] 
2024-09-25 10:24:47.403 Verbose ExoPlayer loading [eventTime=868.83, mediaPos=76.73, window=0, period=0, false] 
2024-09-25 10:25:41.702 Verbose ExoPlayer downstreamFormat [eventTime=923.13, mediaPos=0.00, window=1, period=1, id=null, mimeType=audio/flac, pcmEncoding=21, channels=2, sample_rate=48000] 
2024-09-25 10:25:41.703 Verbose ExoPlayer audioInputFormat [eventTime=923.13, mediaPos=0.00, window=1, period=1, id=null, mimeType=audio/flac, pcmEncoding=21, channels=2, sample_rate=48000] 
2024-09-25 10:25:42.283 Verbose ExoPlayer audioDecoderReleased [eventTime=923.71, mediaPos=0.00, window=1, period=1, ffmpegLavc60.3.100-flac] 
2024-09-25 10:25:42.284 Verbose ExoPlayer audioDecoderInitialized [eventTime=923.71, mediaPos=0.00, window=1, period=1, ffmpegLavc60.3.100-flac] 
2024-09-25 10:25:42.313 Verbose ExoPlayer loading [eventTime=923.74, mediaPos=209.06, window=0, period=0, true] 
2024-09-25 10:25:42.477 Verbose ExoPlayer loading [eventTime=923.90, mediaPos=209.23, window=0, period=0, false] 
2024-09-25 10:25:44.176 Verbose ExoPlayer loading [eventTime=925.60, mediaPos=210.93, window=0, period=0, true] 
2024-09-25 10:25:44.189 Verbose ExoPlayer loading [eventTime=925.61, mediaPos=210.94, window=0, period=0, false] 
2024-09-25 10:25:47.959 Verbose ExoPlayer positionDiscontinuity [eventTime=929.38, mediaPos=0.02, window=1, period=1, reason=AUTO_TRANSITION, PositionInfo:old [mediaItem=0, period=0, pos=214688], PositionInfo:new [mediaItem=1, period=1, pos=0]] 
2024-09-25 10:25:47.973 Verbose ExoPlayer mediaItem [eventTime=929.38, mediaPos=0.02, window=1, period=1, reason=AUTO] 
2024-09-25 10:25:47.985 Verbose ExoPlayer tracks [eventTime=929.38, mediaPos=0.02, window=1, period=1 
2024-09-25 10:25:47.985 Verbose ExoPlayer group [ 
2024-09-25 10:25:47.986 Verbose ExoPlayer [X] Track:0, id=null, mimeType=audio/flac, pcmEncoding=21, channels=2, sample_rate=48000, supported=YES 
2024-09-25 10:25:47.986 Verbose ExoPlayer ] 
2024-09-25 10:25:47.990 Verbose ExoPlayer Metadata [ 
2024-09-25 10:25:47.993 Verbose ExoPlayer VC: ARTIST=水曜日のカンパネラ 
2024-09-25 10:25:47.995 Verbose ExoPlayer VC: TITLE=キャロライナ 
2024-09-25 10:25:47.999 Verbose ExoPlayer VC: ALBUM=POP DELIVERY 
2024-09-25 10:25:47.999 Verbose ExoPlayer VC: DATE=2024.06.05 
2024-09-25 10:25:48.001 Verbose ExoPlayer VC: GENRE=J-Pop 
2024-09-25 10:25:48.003 Verbose ExoPlayer VC: COMPOSER=Kenmochi Hidefumi 
2024-09-25 10:25:48.007 Verbose ExoPlayer VC: ALBUMARTIST=水曜日のカンパネラ 
2024-09-25 10:25:48.020 Verbose ExoPlayer VC: TRACKNUMBER=2 
2024-09-25 10:25:48.022 Verbose ExoPlayer VC: TRACKTOTAL=8 
2024-09-25 10:25:48.034 Verbose ExoPlayer VC: DISCNUMBER=1 
2024-09-25 10:25:48.036 Verbose ExoPlayer VC: DISCTOTAL=1 
2024-09-25 10:25:48.038 Verbose ExoPlayer VC: COPYRIGHT=℗© 2024 WARNER MUSIC JAPAN INC. 
2024-09-25 10:25:48.038 Verbose ExoPlayer VC: LABEL=WM Japan 
2024-09-25 10:25:48.039 Verbose ExoPlayer ] 
2024-09-25 10:25:48.039 Verbose ExoPlayer ] 
2024-09-25 10:25:48.042 Verbose ExoPlayer timeline [eventTime=929.39, mediaPos=0.02, window=0, period=0, periodCount=1, windowCount=1, reason=PLAYLIST_CHANGED 
2024-09-25 10:25:48.042 Verbose ExoPlayer period [179.44] 
2024-09-25 10:25:48.042 Verbose ExoPlayer window [179.44, seekable=true, dynamic=false] 
2024-09-25 10:25:48.042 Verbose ExoPlayer ] 
2024-09-25 10:25:48.046 Verbose ExoPlayer timeline [eventTime=929.40, mediaPos=0.03, window=0, period=0, periodCount=2, windowCount=2, reason=PLAYLIST_CHANGED 
2024-09-25 10:25:48.047 Verbose ExoPlayer period [179.44] 
2024-09-25 10:25:48.047 Verbose ExoPlayer period [?] 
2024-09-25 10:25:48.048 Verbose ExoPlayer window [179.44, seekable=true, dynamic=false] 
2024-09-25 10:25:48.049 Verbose ExoPlayer window [?, seekable=false, dynamic=true] 
2024-09-25 10:25:48.051 Verbose ExoPlayer ] 
2024-09-25 10:25:48.835 Verbose ExoPlayer loading [eventTime=930.26, mediaPos=0.90, window=0, period=0, true] 
2024-09-25 10:25:48.846 Verbose ExoPlayer loading [eventTime=930.27, mediaPos=0.90, window=0, period=0, false] 
2024-09-25 10:25:53.283 Verbose ExoPlayer loading [eventTime=934.71, mediaPos=5.35, window=0, period=0, true] 
2024-09-25 10:25:53.302 Verbose ExoPlayer loading [eventTime=934.73, mediaPos=5.36, window=0, period=0, false] 
2024-09-25 10:25:54.369 Verbose ExoPlayer playWhenReady [eventTime=935.79, mediaPos=6.42, window=0, period=0, false, USER_REQUEST] 
2024-09-25 10:25:54.371 Verbose ExoPlayer isPlaying [eventTime=935.79, mediaPos=6.42, window=0, period=0, false] 
2024-09-25 10:30:17.926 Verbose ExoPlayer timeline [eventTime=1199.35, mediaPos=0.00, window=0, periodCount=0, windowCount=0, reason=PLAYLIST_CHANGED 
2024-09-25 10:30:17.935 Verbose ExoPlayer ] 
2024-09-25 10:30:17.937 Verbose ExoPlayer positionDiscontinuity [eventTime=1199.35, mediaPos=0.00, window=0, reason=REMOVE, PositionInfo:old [mediaItem=0, period=0, pos=6425], PositionInfo:new [mediaItem=0, period=-1, pos=0]] 
2024-09-25 10:30:17.942 Verbose ExoPlayer mediaItem [eventTime=1199.35, mediaPos=0.00, window=0, reason=PLAYLIST_CHANGED] 
2024-09-25 10:30:17.953 Verbose ExoPlayer tracks [eventTime=1199.35, mediaPos=0.00, window=0 
2024-09-25 10:30:17.954 Verbose ExoPlayer ] 
2024-09-25 10:30:17.965 Verbose ExoPlayer state [eventTime=1199.35, mediaPos=0.00, window=0, ENDED] 
2024-09-25 10:30:17.967 Verbose ExoPlayer state [eventTime=1199.35, mediaPos=0.00, window=0, IDLE] 
2024-09-25 10:30:17.967 Verbose ExoPlayer rendererReady [eventTime=1199.35, mediaPos=0.00, window=0, period=0, rendererIndex=0, audio, false] 
2024-09-25 10:30:17.974 Verbose ExoPlayer audioDecoderReleased [eventTime=1199.36, mediaPos=0.00, window=0, period=0, ffmpegLavc60.3.100-flac] 
2024-09-25 10:30:17.975 Verbose ExoPlayer audioDisabled [eventTime=1199.36, mediaPos=0.00, window=0, period=0] 
2024-09-25 10:30:17.980 Verbose ExoPlayer audioTrackReleased [eventTime=1199.40, mediaPos=0.00, window=0, period=0, 4,12,48000,false,false,2106368] 

I do not know how to debug this more, waiting for more details by that user.
From what I see, when the next item starts to preload, the first one stops to load , then after 1 minute (the approximate buffer size) starts to load again but with a mediaPos that makes no sense. (I do logs all and positionDiscontinuity and there's none in the log).

2024-09-25 10:24:47.403 Verbose ExoPlayer loading [eventTime=868.83, mediaPos=76.73, window=0, period=0, false]
next ->
2024-09-25 10:25:42.313 Verbose ExoPlayer loading [eventTime=923.74, mediaPos=209.06, window=0, period=0, true]

That's a 55 seconds difference so the mediaPos should have been more in the 131 range not 209.

Note: The ExoCache line is from onCachedBytesRead of the SimpleCache listener, being called that early, I would suspect that the cache is not complete, but it should use the setUpstreamDataSourceFactory and it's not called at all.

Media

N/A

Bug Report

  • You will email the zip file produced by adb bugreport to [email protected] after filing this issue.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

2 participants