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

Exoplayer freezes for a couple of secondes on the first buffering state of an HLS video #2096

Closed
gbadoual opened this issue Nov 22, 2016 · 10 comments

Comments

@gbadoual
Copy link

gbadoual commented Nov 22, 2016

Hi,

We are trying to play smoothly a 4k HLS video,
but it appears that Exoplayer freezes for 3-4 of seconds on the first buffering state.

{NOT_READY}{READY}{PLAYING}{BUFFERING}{FREEZE 3-4 SECONDS}

Then, the video plays properly :
{PLAYING}{BUFFERING}{PLAYING}{BUFFERING}{PLAYING}{BUFFERING}{PLAYING}{BUFFERING}{PLAYING}{BUFFERING}{PLAYING}{BUFFERING}{END}

We try to understand why we have this behavior. We experience it both with Exoplayer 2 and Exoplayer1.5.12
We tried on a Samsung Galaxy S6 and a S7 and experience a similar behavior.

We use Exoplayer as a library to send content to a 360° surface in Unity 5.4.1 but have reproduce the issue in Exoplayer demo app.

You can see here logs reporting State and Exoplayer position.
The freeze comes at position 8106, for approximatively 4 seconds.

We use releasePlayer(), and preparePlayer() at every new load of a video.

Do someone have an explanation or any hint on how to fix this issue.

Thanks in advance,

Adb Logcat :

11-22 17:59:34.310 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.320 26215-26228/? I/Unity: srcMedia happens somathing - .GetCurrentState () / NOT_READY
11-22 17:59:34.320 26215-26228/? I/Unity:  
11-22 17:59:34.320 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.320 26215-26228/? I/Unity: srcMedia happens somathing - .GetSeekPosition() / 0
11-22 17:59:34.320 26215-26228/? I/Unity:  
11-22 17:59:34.320 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.330 26215-26215/? D/EasyMovieTexture: onStateChanged : playWhenReady=true, playbackState=ready
11-22 17:59:34.340 3063-13156/? W/AudioPolicyIntefaceImpl: Skipped to add effects on session 1461
11-22 17:59:34.340 3063-13156/? I/APM::AudioPolicyManager: startOutput() output 2, stream 3, session 1461
11-22 17:59:34.340 3063-3708/? D/audio_hw_primary: out_set_parameters: enter: kvpairs: routing=2
11-22 17:59:34.340 3063-3708/? D/AudioFlinger: setCurDevice() 0x2
11-22 17:59:34.340 26215-26228/? I/Unity: srcMedia happens somathing - .GetCurrentState () / NOT_READY
11-22 17:59:34.340 26215-26228/? I/Unity:  
11-22 17:59:34.340 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.340 26215-26228/? I/Unity: srcMedia happens somathing - .GetSeekPosition() / 0
11-22 17:59:34.340 26215-26228/? I/Unity:  
11-22 17:59:34.340 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.350 26215-26321/? I/VrApi: FPS=57,Prd=50ms,Tear=0,Early=54,Stale=2,VSnc=1,Lat=1,CPU4/GPU=2/2,800/420MHz,OC=FF,TA=F0/F0/F0/F0,SP=F/F/F/F,Mem=1026MHz,Free=602MB,PSM=0,PLS=0,Temp=31.8C/30.0C
11-22 17:59:34.350 3063-3708/? V/audio_hw_primary: start_output_stream+, out->device : 00000002 , out->type = 0
11-22 17:59:34.350 3063-3708/? D/audio_hw_primary: start_output_stream (0xedad09a0) out->pcm_device:3 out->config.rate:48000 out->config.format:0 out->period_size:1440
11-22 17:59:34.350 3063-3708/? D/audio_hw_primary: start_output_stream (0xedad09a0) out->config.rate:48000 out->config.format:0 out->period_size:1440
11-22 17:59:34.350 3063-3708/? V/audio_hw_primary: select_devices output_scenario:0 input_scenario:-1 out_snd_device 0x2 in_snd_device:0x0
11-22 17:59:34.350 3063-3708/? I/audio_hw_primary: select_devices - do not update mixer_path
11-22 17:59:34.350 3063-3708/? V/audio_hw_primary: start_output_stream-
11-22 17:59:34.360 26215-26228/? I/Unity: srcMedia.GetCurrentState () / READY
11-22 17:59:34.360 26215-26228/? I/Unity:  
11-22 17:59:34.360 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.360 26215-26228/? I/Unity: srcMedia.GetSeekPosition() / 0
11-22 17:59:34.360 26215-26228/? I/Unity:  
11-22 17:59:34.360 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.370 26215-26228/? I/Unity: srcMedia.GetCurrentState () / PLAYING
11-22 17:59:34.370 26215-26228/? I/Unity:  
11-22 17:59:34.370 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.380 26215-26228/? I/Unity: srcMedia.GetSeekPosition() / 0
11-22 17:59:34.380 26215-26228/? I/Unity:  
11-22 17:59:34.380 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.410 3508-3640/? D/PowerManagerService: [s] UserActivityState : 1 -> 2
11-22 17:59:34.410 3508-3640/? D/PowerManagerService: mDisplayReady: false
11-22 17:59:34.410 3508-3640/? D/DisplayPowerController: animateScreenStateChange[0]: target=2
11-22 17:59:34.410 3508-3640/? D/DisplayPowerController: [Dual Screen Compatible] state[0] :2
11-22 17:59:34.410 3508-3640/? D/DisplayPowerController: getFinalBrightness : Summary is 20 -> 20
11-22 17:59:34.410 3508-3640/? D/DisplayPowerController: Animating brightness: target=20, rate=500 (PSM:false, AB limit:(-1 ~ -1) MB Limit:(-1 ~ 255))
11-22 17:59:34.410 3508-3640/? D/PowerManagerService: [s] DisplayPowerCallbacks : onStateChanged()
11-22 17:59:34.410 3508-3640/? D/PowerManagerService: mDisplayReady: true
11-22 17:59:34.420 3508-4079/? D/lights: lcd : 82 +
11-22 17:59:34.420 3508-4079/? D/lights: lcd : 82 -
11-22 17:59:34.420 3508-3640/? D/DisplayPowerController: animateScreenStateChange[0]: target=2
11-22 17:59:34.420 3508-3640/? D/DisplayPowerController: [Dual Screen Compatible] state[0] :2
11-22 17:59:34.420 3508-3640/? D/DisplayPowerController: getFinalBrightness : Summary is 20 -> 20
11-22 17:59:34.420 3508-3640/? D/DisplayPowerController: Animating brightness: target=20, rate=500 (PSM:false, AB limit:(-1 ~ -1) MB Limit:(-1 ~ 255))
11-22 17:59:34.430 3508-4079/? D/lights: lcd : 73 +
11-22 17:59:34.440 3508-4079/? D/lights: lcd : 73 -
11-22 17:59:34.440 3508-3640/? D/DisplayPowerController: animateScreenStateChange[0]: target=2
11-22 17:59:34.440 3508-3640/? D/DisplayPowerController: [Dual Screen Compatible] state[0] :2
11-22 17:59:34.440 3508-3640/? D/DisplayPowerController: getFinalBrightness : Summary is 20 -> 20
11-22 17:59:34.440 3508-3640/? D/DisplayPowerController: Animating brightness: target=20, rate=500 (PSM:false, AB limit:(-1 ~ -1) MB Limit:(-1 ~ 255))
11-22 17:59:34.450 26215-26319/? W/TimeWarp: VSync 35058228: eye=1,late=0.0ms,over=0.0ms,CPU=26.3ms,GPU>=0.1
11-22 17:59:34.450 3508-4079/? D/lights: lcd : 65 +
11-22 17:59:34.450 3508-4079/? D/lights: lcd : 65 -
11-22 17:59:34.450 26215-26319/? I/TimeWarp: Adjusting  35058229.09 > 35058228 to 35058229
11-22 17:59:34.450 3508-3640/? D/DisplayPowerController: animateScreenStateChange[0]: target=2
11-22 17:59:34.450 3508-3640/? D/DisplayPowerController: [Dual Screen Compatible] state[0] :2
11-22 17:59:34.450 3508-3640/? D/DisplayPowerController: getFinalBrightness : Summary is 20 -> 20
11-22 17:59:34.450 3508-3640/? D/DisplayPowerController: Animating brightness: target=20, rate=500 (PSM:false, AB limit:(-1 ~ -1) MB Limit:(-1 ~ 255))
11-22 17:59:34.470 26215-26319/? D/VrApi: setSchedFifoStatic tid:26228 pto:0
11-22 17:59:34.470 3508-4079/? D/lights: lcd : 57 +
11-22 17:59:34.470 3508-4079/? D/lights: lcd : 57 -
11-22 17:59:34.470 3508-3640/? D/DisplayPowerController: animateScreenStateChange[0]: target=2
11-22 17:59:34.470 3508-3640/? D/DisplayPowerController: [Dual Screen Compatible] state[0] :2
11-22 17:59:34.470 3508-3640/? D/DisplayPowerController: getFinalBrightness : Summary is 20 -> 20
11-22 17:59:34.470 3508-3640/? D/DisplayPowerController: Animating brightness: target=20, rate=500 (PSM:false, AB limit:(-1 ~ -1) MB Limit:(-1 ~ 255))
11-22 17:59:34.470 27275-27784/? V/VRManagerServer: (VRManagerService.java:401) yTqX [setThreadSchedFifo pkg=fr.samsung.lifechanger.gearvr pid=26215 tid=26228 prio=0]
11-22 17:59:34.470 27275-27784/? V/VRManagerServer: (VRManagerService.java:405) yTqX [setAffinity pid=26228 cpus=[4, 5, 6, 7]]
11-22 17:59:34.480 3508-4459/? V/VRManagerService: ---- demoteProcessThread 'fr.samsung.lifechanger.gearvr' requestPriority(pid=26215, tid=26228, prio=0 ----
11-22 17:59:34.480 26215-26319/? D/VRManagerGearVR: VRManager set thread priority to 0
11-22 17:59:34.480 26215-26319/? I/VrApi_Clocks: SetSchedFifo( tid=26228, pri=0 ) succeeded
11-22 17:59:34.480 26215-26319/? D/VrApi: setSchedFifoStatic tid:26228 pto:0
11-22 17:59:34.480 3508-4079/? D/lights: lcd : 48 +
11-22 17:59:34.480 3508-4079/? D/lights: lcd : 48 -
11-22 17:59:34.490 27275-27287/? V/VRManagerServer: (VRManagerService.java:401) yTqX [setThreadSchedFifo pkg=fr.samsung.lifechanger.gearvr pid=26215 tid=26228 prio=0]
11-22 17:59:34.490 3508-3640/? D/DisplayPowerController: animateScreenStateChange[0]: target=2
11-22 17:59:34.490 27275-27287/? V/VRManagerServer: (VRManagerService.java:405) yTqX [setAffinity pid=26228 cpus=[4, 5, 6, 7]]
11-22 17:59:34.490 3508-3640/? D/DisplayPowerController: [Dual Screen Compatible] state[0] :2
11-22 17:59:34.490 3063-3708/? D/AudioFlinger: mixer(0xef040000) throttle end: throttle time(73)
11-22 17:59:34.490 3508-3640/? D/DisplayPowerController: getFinalBrightness : Summary is 20 -> 20
11-22 17:59:34.490 3508-3640/? D/DisplayPowerController: Animating brightness: target=20, rate=500 (PSM:false, AB limit:(-1 ~ -1) MB Limit:(-1 ~ 255))
11-22 17:59:34.490 3508-5182/? V/VRManagerService: ---- demoteProcessThread 'fr.samsung.lifechanger.gearvr' requestPriority(pid=26215, tid=26228, prio=0 ----
11-22 17:59:34.490 26215-26228/? E/jni: CreateFBO 3840 1920 156
11-22 17:59:34.490 26215-26319/? D/VRManagerGearVR: VRManager set thread priority to 0
11-22 17:59:34.490 26215-26319/? I/VrApi_Clocks: SetSchedFifo( tid=26228, pri=0 ) succeeded
11-22 17:59:34.500 3508-4079/? D/lights: lcd : 40 +
11-22 17:59:34.500 3508-4079/? D/lights: lcd : 40 -
11-22 17:59:34.500 3508-3640/? D/DisplayPowerController: animateScreenStateChange[0]: target=2
11-22 17:59:34.500 3508-3640/? D/DisplayPowerController: [Dual Screen Compatible] state[0] :2
11-22 17:59:34.500 3508-3640/? D/DisplayPowerController: getFinalBrightness : Summary is 20 -> 20
11-22 17:59:34.500 3508-3640/? D/DisplayPowerController: Animating brightness: target=20, rate=500 (PSM:false, AB limit:(-1 ~ -1) MB Limit:(-1 ~ 255))
11-22 17:59:34.520 3508-4079/? D/lights: lcd : 31 +
11-22 17:59:34.520 3508-4079/? D/lights: lcd : 31 -
11-22 17:59:34.520 3508-3640/? D/DisplayPowerController: animateScreenStateChange[0]: target=2
11-22 17:59:34.520 3508-3640/? D/DisplayPowerController: [Dual Screen Compatible] state[0] :2
11-22 17:59:34.520 3508-3640/? D/DisplayPowerController: getFinalBrightness : Summary is 20 -> 20
11-22 17:59:34.520 3508-3640/? D/DisplayPowerController: Animating brightness: target=20, rate=500 (PSM:false, AB limit:(-1 ~ -1) MB Limit:(-1 ~ 255))
11-22 17:59:34.530 26215-26319/? W/TimeWarp: VSync 35058231: eye=1,late=19.7ms,over=0.0ms,CPU=31.3ms,GPU>=0.0
11-22 17:59:34.530 26215-26319/? I/TimeWarp: Adjusting  35058233.55 > 35058231 to 35058234
11-22 17:59:34.530 26215-26228/? D/libEGL: eglInitialize EGLDisplay = 0xef2c0a94
11-22 17:59:34.530 26215-26228/? W/GLConsumer: [SurfaceTexture--3927972-26215-1] bindTextureImage: clearing GL error: 0x502
11-22 17:59:34.530 3508-4079/? D/lights: lcd : 23 +
11-22 17:59:34.530 3508-4079/? D/lights: lcd : 23 -
11-22 17:59:34.530 26215-26228/? I/Unity: srcMedia - Call_GetSeekPosition / 137
11-22 17:59:34.530 26215-26228/? I/Unity:  
11-22 17:59:34.530 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.540 3508-3640/? D/DisplayPowerController: animateScreenStateChange[0]: target=2
11-22 17:59:34.540 3508-3640/? D/DisplayPowerController: [Dual Screen Compatible] state[0] :2
11-22 17:59:34.540 3508-3640/? D/DisplayPowerController: getFinalBrightness : Summary is 20 -> 20
11-22 17:59:34.540 3508-3640/? D/DisplayPowerController: Animating brightness: target=20, rate=500 (PSM:false, AB limit:(-1 ~ -1) MB Limit:(-1 ~ 255))
11-22 17:59:34.550 26215-26228/? I/Unity: srcMedia.GetCurrentState () / PLAYING
11-22 17:59:34.550 26215-26228/? I/Unity:  
11-22 17:59:34.550 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.550 26215-26228/? I/Unity: srcMedia.GetSeekPosition() / 137
11-22 17:59:34.550 26215-26228/? I/Unity:  
11-22 17:59:34.550 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.550 26215-26228/? I/Unity: srcMedia - Call_GetSeekPosition / 147
11-22 17:59:34.550 26215-26228/? I/Unity:  
11-22 17:59:34.550 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.550 26215-26319/? D/VrApi: setSchedFifoStatic tid:26228 pto:1
11-22 17:59:34.550 3508-3640/? D/DisplayPowerController: animateScreenStateChange[0]: target=2
11-22 17:59:34.550 3508-4079/? D/lights: lcd : 20 +
11-22 17:59:34.550 3508-3640/? D/DisplayPowerController: [Dual Screen Compatible] state[0] :2
11-22 17:59:34.550 3508-4079/? D/lights: lcd : 20 -
11-22 17:59:34.550 3508-3640/? D/DisplayPowerController: getFinalBrightness : Summary is 20 -> 20
11-22 17:59:34.550 3508-3640/? D/DisplayPowerController: Animating brightness: target=20, rate=500 (PSM:false, AB limit:(-1 ~ -1) MB Limit:(-1 ~ 255))
11-22 17:59:34.550 3508-3640/? D/DisplayPowerController: animateScreenStateChange[0]: target=2
11-22 17:59:34.550 3508-3640/? D/DisplayPowerController: [Dual Screen Compatible] state[0] :2
11-22 17:59:34.550 3508-3640/? D/DisplayPowerController: getFinalBrightness : Summary is 20 -> 20
11-22 17:59:34.550 3508-3640/? D/DisplayPowerController: Animating brightness: target=20, rate=500 (PSM:false, AB limit:(-1 ~ -1) MB Limit:(-1 ~ 255))
11-22 17:59:34.560 27275-27286/? V/VRManagerServer: (VRManagerService.java:401) yTqX [setThreadSchedFifo pkg=fr.samsung.lifechanger.gearvr pid=26215 tid=26228 prio=1]
11-22 17:59:34.560 27275-27286/? V/VRManagerServer: (VRManagerService.java:405) yTqX [setAffinity pid=26228 cpus=[4, 5, 6, 7]]
11-22 17:59:34.560 3508-5181/? V/VRManagerService: ---- elevateProcessThread 'fr.samsung.lifechanger.gearvr' requestPriority(pid=26215, tid=26228, prio=1 ----
11-22 17:59:34.560 26215-26319/? D/VRManagerGearVR: VRManager set thread priority to 1
11-22 17:59:34.560 26215-26319/? I/VrApi_Clocks: SetSchedFifo( tid=26228, pri=1 ) succeeded
11-22 17:59:34.560 26215-26319/? D/VrApi: setSchedFifoStatic tid:26228 pto:1
11-22 17:59:34.570 27275-27285/? V/VRManagerServer: (VRManagerService.java:401) yTqX [setThreadSchedFifo pkg=fr.samsung.lifechanger.gearvr pid=26215 tid=26228 prio=1]
11-22 17:59:34.570 27275-27285/? V/VRManagerServer: (VRManagerService.java:405) yTqX [setAffinity pid=26228 cpus=[4, 5, 6, 7]]
11-22 17:59:34.570 3508-4458/? V/VRManagerService: ---- elevateProcessThread 'fr.samsung.lifechanger.gearvr' requestPriority(pid=26215, tid=26228, prio=1 ----
11-22 17:59:34.570 26215-26319/? D/VRManagerGearVR: VRManager set thread priority to 1
11-22 17:59:34.570 26215-26319/? I/VrApi_Clocks: SetSchedFifo( tid=26228, pri=1 ) succeeded
11-22 17:59:34.570 26215-26319/? W/TimeWarp: VSync 35058236: eye=1,late=14.1ms,over=0.0ms,CPU=0.5ms,GPU>=0.0
11-22 17:59:34.570 26215-26228/? I/Unity: srcMedia.GetCurrentState () / PLAYING
11-22 17:59:34.570 26215-26228/? I/Unity:  
11-22 17:59:34.570 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.580 26215-26228/? I/Unity: srcMedia.GetSeekPosition() / 147
11-22 17:59:34.580 26215-26228/? I/Unity:  
11-22 17:59:34.580 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.580 26215-26228/? D/libEGL: eglInitialize EGLDisplay = 0xef2c0a94
11-22 17:59:34.580 26215-26228/? I/Unity: srcMedia - Call_GetSeekPosition / 181
11-22 17:59:34.580 26215-26228/? I/Unity:  
11-22 17:59:34.580 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.590 26215-26228/? I/Unity: srcMedia.GetCurrentState () / PLAYING
11-22 17:59:34.590 26215-26228/? I/Unity:  
11-22 17:59:34.590 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.590 26215-26228/? I/Unity: srcMedia.GetSeekPosition() / 181
11-22 17:59:34.590 26215-26228/? I/Unity:  
11-22 17:59:34.590 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.600 26215-26228/? I/Unity: srcMedia - Call_GetSeekPosition / 206
11-22 17:59:34.600 26215-26228/? I/Unity:  
11-22 17:59:34.600 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.610 26215-26228/? I/Unity: srcMedia.GetCurrentState () / PLAYING
11-22 17:59:34.610 26215-26228/? I/Unity:  
11-22 17:59:34.610 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.610 26215-26228/? I/Unity: srcMedia.GetSeekPosition() / 206
11-22 17:59:34.610 26215-26228/? I/Unity:  
11-22 17:59:34.610 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.610 26215-26228/? D/libEGL: eglInitialize EGLDisplay = 0xef2c0a94
11-22 17:59:34.610 26215-26228/? I/Unity: srcMedia - Call_GetSeekPosition / 225
11-22 17:59:34.610 26215-26228/? I/Unity:  
11-22 17:59:34.610 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:34.630 26215-26228/? I/Unity: srcMedia.GetCurrentState () / PLAYING
11-22 17:59:34.630 26215-26228/? I/Unity:  
[…]
11-22 17:59:42.410 26215-26228/? I/Unity: srcMedia.GetSeekPosition() / 8015
11-22 17:59:42.410 26215-26228/? I/Unity:  
11-22 17:59:42.410 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.410 26215-26228/? I/Unity: srcMedia - Call_GetSeekPosition / 8035
11-22 17:59:42.410 26215-26228/? I/Unity:  
11-22 17:59:42.410 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.420 26215-26228/? I/Unity: srcMedia.GetCurrentState () / PLAYING
11-22 17:59:42.420 26215-26228/? I/Unity:  
11-22 17:59:42.420 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.420 26215-26228/? I/Unity: srcMedia.GetSeekPosition() / 8035
11-22 17:59:42.420 26215-26228/? I/Unity:  
11-22 17:59:42.420 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.420 26215-26228/? I/Unity: srcMedia - Call_GetSeekPosition / 8045
11-22 17:59:42.420 26215-26228/? I/Unity:  
11-22 17:59:42.420 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.440 26215-26228/? I/Unity: srcMedia.GetCurrentState () / PLAYING
11-22 17:59:42.440 26215-26228/? I/Unity:  
11-22 17:59:42.440 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.440 26215-26228/? I/Unity: srcMedia.GetSeekPosition() / 8045
11-22 17:59:42.440 26215-26228/? I/Unity:  
11-22 17:59:42.440 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.440 26215-26228/? I/Unity: srcMedia - Call_GetSeekPosition / 8065
11-22 17:59:42.440 26215-26228/? I/Unity:  
11-22 17:59:42.440 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.460 26215-26228/? I/Unity: srcMedia.GetCurrentState () / PLAYING
11-22 17:59:42.460 26215-26228/? I/Unity:  
11-22 17:59:42.460 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.460 26215-26228/? I/Unity: srcMedia.GetSeekPosition() / 8065
11-22 17:59:42.460 26215-26228/? I/Unity:  
11-22 17:59:42.460 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.460 26215-26228/? I/Unity: srcMedia - Call_GetSeekPosition / 8085
11-22 17:59:42.460 26215-26228/? I/Unity:  
11-22 17:59:42.460 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.470 26215-26228/? I/Unity: srcMedia.GetCurrentState () / PLAYING
11-22 17:59:42.470 26215-26228/? I/Unity:  
11-22 17:59:42.470 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.470 26215-26228/? I/Unity: srcMedia.GetSeekPosition() / 8085
11-22 17:59:42.470 26215-26228/? I/Unity:  
11-22 17:59:42.470 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.480 26215-26228/? I/Unity: srcMedia - Call_GetSeekPosition / 8095
11-22 17:59:42.480 26215-26228/? I/Unity:  
11-22 17:59:42.480 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.480 26215-26215/? D/EasyMovieTexture: onStateChanged : playWhenReady=true, playbackState=buffering
11-22 17:59:42.490 26215-26228/? I/Unity: srcMedia.GetCurrentState () / PLAYING
11-22 17:59:42.490 26215-26228/? I/Unity:  
11-22 17:59:42.490 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.490 26215-26228/? I/Unity: srcMedia.GetSeekPosition() / 8106
11-22 17:59:42.490 26215-26228/? I/Unity:  
11-22 17:59:42.490 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.490 26215-26228/? I/Unity: srcMedia - Call_GetSeekPosition / 8106
11-22 17:59:42.490 26215-26228/? I/Unity:  
11-22 17:59:42.490 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.510 26215-26228/? I/Unity: srcMedia.GetCurrentState () / PLAYING
11-22 17:59:42.510 26215-26228/? I/Unity:  
11-22 17:59:42.510 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.510 26215-26228/? I/Unity: srcMedia.GetSeekPosition() / 8106
11-22 17:59:42.510 26215-26228/? I/Unity:  
11-22 17:59:42.510 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.510 26215-26228/? I/Unity: srcMedia - Call_GetSeekPosition / 8106
11-22 17:59:42.510 26215-26228/? I/Unity:  
11-22 17:59:42.510 26215-26228/? I/Unity: (Filename: ./artifacts/generated/common/runtime/UnityEngineDebugBindings.gen.cpp Line: 42)
11-22 17:59:42.520 26215-26228/? I/Unity: srcMedia.GetCurrentState () / PLAYING

AdbBugReport.docx

@ojw28
Copy link
Contributor

ojw28 commented Nov 24, 2016

It's unclear exactly what you mean here (and the bug report attached doesn't look like a full bug report, as would be obtained from adb bugreport). The video plays fine for me in both 1.5.12 and 2.0.4 demo apps.

Please could you clarify what you mean by "freeze"? Please also provide logging and a full bug report when reproducing this issue with the demo app, rather than your own, since we know what logging to expect in that case and not in the case of your app. Thanks!

@Nelsun
Copy link

Nelsun commented Nov 26, 2016

I have the same problem. v 2.0.4
On some HLS streams - And ONLY on first bandwidth change
..MediaCodecVideoRenderer.CodecMaxValues fails to get max values /i didn't check why/
actually returns current format values. And on next BW change because the buffer /usually must be increased /the check canReconfigureCodec returns false and rendere sets REINITIALIZATION_STATE_SIGNAL_END_OF_STREAM flag up.

This is happen in MediaCodec.render / drainOutputBuffer call, but drainOutputBuffer is in while and codec is null after processEndOfStream because of BUFFER_FLAG_END_OF_STREAM.
There is null pointer exception and after second codec init everything is fine. But there is a ~1 second freeze.

I'm working with single hls provider and i know all stream details, to avoid this i did override of max width, height and buffer values in CodecMaxValues to full hd.
Now the stream switches are fine - but this is workaround.

I didn't have time to track everything to the root. but looks like async problem. if a stream start from lowest bitrate the processing of the next segment /period/ can happen before playback start .. or something. For example on first call after start AdaptiveVideoTrackSelectionController updateSelectedTrack - currentFormat returns second fragment bitrate. /if there is a bw change/
I just guess that some objects couldn't be initialised on time in some cases .

I hope this info will help.

@ojw28
Copy link
Contributor

ojw28 commented Nov 26, 2016

@Nelsun - You should ask your HLS provider to include RESOLUTION attributes in the master playlist, or use a provider who does this. Whilst technically optional in the HLS spec, inclusion of RESOLUTION attributes has been recommended for over three years now. If the master playlist contains these attributes then the player will not need to reconfigure the decoder in this way. If the master playlist doesn't contain them then the player has no way of knowing what the maximum resolution is in advance of switching to the highest resolution variant, and may have to perform a (potentially quite expensive) buffer re-allocation when this occurs.

@gbadoual - You'll likely find including RESOLUTION attributes in your master playlist also resolves the issue for your stream.

@Nelsun - I'm not sure I follow your null pointer exception description. It sounds like something we should definitely fix though. Could you provide more details to help? As I understand it:

  1. Resolution of stream changes. canReconfigureCodec returns false and codecReinitializationState is set to REINITIALIZATION_STATE_SIGNAL_END_OF_STREAM.
  2. feedInputBuffer will queue an input buffer with BUFFER_FLAG_END_OF_STREAM and will update codecReinitializationState to REINITIALIZATION_STATE_WAIT_END_OF_STREAM
  3. In drainOutputBuffer, a the buffer with BUFFER_FLAG_END_OF_STREAM is read. This causes processEndOfStream to be called.

It's here that I get lost. processEndOfStream should re-initialize the codec when it calls maybeInitCodec, so codec shouldn't end up null after this call. Could you take a look and see why this isn't happening? The only thing I can think of is if the surface isn't valid, but that sounds pretty strange?

@ojw28
Copy link
Contributor

ojw28 commented Nov 26, 2016

Please also provide a stack trace for the null pointer exception. Thanks.

@Nelsun
Copy link

Nelsun commented Nov 30, 2016

Hi - thanks for the answer and sorry about the delay.

In my case - player receiving 3 bandwidths 1, 3, 5 Mbit in order 1, 5, 3 /from m3u8/
the player starts from first (1) this is preferred BW from provider I think
then in AdaptiveVideoTrackSelection's constructor
selectedIndex = determineIdealSelectedIndex(Long.MIN_VALUE);
in my case returns index 0, but in formats array this is the highest bitrate value (5 Mbit)
then on the next calls of AdaptiveVideoTrackSelection .updateSelectedTrack
selectedIndex is the same because idealFormat.bitrate == currentFormat.bitrate
or cannot be changed because the buffering time is still short.
the stream switch is always form 1 to 5 Mb on first and the second segments.
and the player go to buffering state if bandwidth is not enough or data processing is slow.

I just guess - the first bitrate is actually group.getFormat(0).bitrate - where the list is not sorted
and first selectedIndex must be index of BaseTrackSelection.formats on this bitrate
in my case 2 - lowest bitrate / last index ?
this is network and content dependent - if network access to a stream is good everything is fine.

Also, you are right about that RESOLUTION is missing in my playlists.
and on my device I have short freezes on codec reinitialization.
Is it possible to tell me a way how /is it possible/ to init/set the max values outside of the library.
the only way that I found is to override master playlists in data source object.

And there is NO code exception - all was my fault. Sorry about.

ojw28 added a commit that referenced this issue Dec 1, 2016
I can't see how this would ever make a difference, but there's no
point in returning true. Either we've really reached EOS (in which
case outputStreamEnded will be true and the next drainOutputBuffer
will be turned into a no-op) or we've re-initialized the codec (in
which case there wont be anything to drain since we wont have fed
anything to the codec yet).

This change should also prevent the hypothetical NPE described in
issue #2096, although we're unsure how that NPE would occur unless
MediaCodecRenderer has been extended in an unusual way.

-------------
Created by MOE: https://github.com/google/moe
MOE_MIGRATED_REVID=140338581
@peddisri
Copy link
Contributor

@ojw28 The sample HLS URls provided by Apple and included in the Exo samples itself does not contain the RESOLUTION attribute in master playlist.
https://devimages.apple.com.edgekey.net/streaming/examples/bipbop_4x3/bipbop_4x3_variant.m3u8

In 1.x Exo, canReconfigureCodec API of MediaCodecVideoTrackRenderer used to only check for current format and new format mime types before it deciding if a reconfiguration is possible or not.

Whereas, 2.x sets the max width and max height of the codec based on the maximum width and height provided in streamformats in onStreamChanged API. So it ends up having to re-create codec if the new format is of higher resolution than current.

I think one small change that can be done to handle URLs that do not contain RESOLUTION attribute is that in getCodecMaxValues API, the codecMaxValues can be set to the max value support by the platform when the resolution info is missing from the stream codecs. (or do not set the max width and max height values at all in this scenario). Is that an acceptable solution?

@ojw28
Copy link
Contributor

ojw28 commented Jan 20, 2017

I'm pretty sure there is a check somewhere in V1. The reason playbacks are able to avoid the codec re-instantiation in most cases is because HlsChunkSource hard-codes 1080p in the case that resolution tags were missing (here). I think that approach is quite problematic, since it can cause unnecessary playback failures on devices not supporting resolutions that high.

We should probably do as you suggest for V2. A few caveats:

  • I don't think there is a single maximum resolution in all cases. For example a decoder might support 1980x1080 and 1080x1980, but not 1980x1980.
  • I don't think it's wise to set at the very maximum value. It seems likely that the larger the value you choose, the more likely it is that decoder instantiation may fail (e.g. due to memory constraints). It seems reasonable that if someone's delivering >1080p they should probably be up to date enough with the HLS spec to be setting resolution tags, for example.

@peddisri
Copy link
Contributor

peddisri commented Jan 25, 2017

I don't think there is a single maximum resolution in all cases. For example a decoder might support 1980x1080 and 1080x1980, but not 1980x1980_.

I think we can just avoid setting the Max values when RESOLUTION field is missing. Platform decoders will allocate memory for the maximum supported resolution by default.

I don't think it's wise to set at the very maximum value. It seems likely that the larger the value you choose, the more likely it is that decoder instantiation may fail.

It's a trade off if the content provider has not set the RESOLUTION. To guarantee optimal memory usage, RESOLUTION must be provided, I agree.

@ojw28
Copy link
Contributor

ojw28 commented Jan 25, 2017

I think we can just avoid setting the Max values when RESOLUTION field is missing. Platform decoders will allocate memory for the maximum supported resolution by default.

I don't think that's correct. As I understand it decoders operate in two modes. Decoders that operate in "legacy" mode they allocate for (width,height) or (maxWidth,maxHeight) if specified, and playback will fail if those dimension are exceeded. This is why it's not valid to avoid setting the max values in such cases. Decoders that operate in "non-legacy" mode are able to dynamically re-allocate their output buffers when adaptation occurs, and so don't fail in this case. I suspect these decoders might ignore (maxWidth,maxHeight) even if specified, although I'm not certain about this. Anyway, due to "legacy" mode decoders, not setting the max values and also not re-initializing the decoder when the resolution increases is not an option.

We have a change under review that will set (maxWidth,maxHeight) to something sensible, based on standard video resolutions, the aspect ratio of the initial video and the capabilities of the decoder. It'll get merged into dev-v2 today or next week.

ojw28 added a commit that referenced this issue Jan 25, 2017
…are unknown

Issue: #2096

-------------
Created by MOE: https://github.com/google/moe
MOE_MIGRATED_REVID=145542983
@ojw28
Copy link
Contributor

ojw28 commented Jan 25, 2017

The change above sets the maximum resolution to something sensible when the variant resolutions are unknown. Please give it a try on the dev-v2 branch. We're planning to cut a 2.2.0 release containing this fix sometime next week.

@ojw28 ojw28 closed this as completed Jan 25, 2017
@google google locked and limited conversation to collaborators Jun 28, 2017
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

4 participants