[Nexus Player] Resume broken on Android TV for some files

[Nodja 9]

Some files, mostly downloaded anime, can't be resumed from the Android TV app on the Nexus Player.

 

Here's a video demonstrating it. At the end the app stopped responding and the black screen turns gray, It's not showing in the video because android itself seems to hang (I'm using adb screengrab). Pressing the home button will return me home after 5-10 seconds. Most times I have to force stop/clear data to get back into the emby app.

 

 

If you want to match the time of the logs with the video, the video starts at 0:12:14 server time.

 

Extra possibly useful info:

• The app was started right after I cleared all data on it.
• This was done on a fresh install of the server. The same behavior happens on the dev version of the server.
• Some files resume normally, but all anime I tried doesn't resume properly (only tried 2 animes tho).
• Sometimes it starts playing if I try to forward playback.
• The files play fine if I play from the beginning.
• If I don't press anything the black screen stays there "forever", the app doesn't crash and the server logs just show calls to /mediabrowser/Sessions/Playing/Progress every couple seconds

 

Another problem with these files is that if you forward playback too fast (I do this to skip anime intros) the same behavior starts to happen. It seems to be happening if the time I skip to is not yet transcoded. Might be the same issue or it might be another one. Let me know if you need a video/logs of this.

 

I didn't find any logs in /data/data/tv.emby.embyatv or in /sdcard so I'm assuming the Android TV app doesn't have logs yet.

Attached server logs and an ffprobe of the test file I used.

 

 - Nodja

20150411 logs nexus player resume broken.zip

20150411 ffprobe resume broken file.txt

Edited April 11, 2015 by Nodja

[ebr 14913]

What version (exact version #) of the server are you on?  There are issues with the dev line right now.

 

Never mind, I see in your log.  I know these issues exist in the dev line I guess maybe they do in the release as well.

[Nodja 9]

Yeah both 3.0.5572.0 and the dev version seem to have the same issues.

 

Is there a known server version that doesn't have this issue? I don't mind doing some regression testing.

Edited April 11, 2015 by Nodja

[ebr 14913]

No, I'm afraid we haven't nabbed this yet.  Is your NP on Android 5.1?

[Nodja 9]

Yes. 5.1 made the app hang less often (or at least so it seems) but the problem was present on both 5.0 and 5.1.

 

I'll try some old versions of the server later tonight and see if the problem exists on those versions.

Does the Android TV not have logs? I couldn't seem to find them anywhere.

[Nodja 9]

Alright I didn't have to go far. The last stable version (3.0.5569.0) worked, so I did a git bisect and here's the results:

Nodja>git bisect start

Nodja>git bisect good 3.0.5569.0

Nodja>git bisect bad 3.0.5572.0
Bisecting: 5 revisions left to test after this (roughly 3 steps)
[19b6b88ea330dd90cd5814443388ab733ec81389] hls resume fix

Nodja>git bisect good
Bisecting: 2 revisions left to test after this (roughly 2 steps)
[1be4f4842b942265cfc39e5bc3dc087822eda137] create user info from exchange token

Nodja>git bisect bad
Bisecting: 0 revisions left to test after this (roughly 1 step)
[e87b8f2c0e0d11031f98eb30f85240bf10260523] remove copyts from hls

Nodja>git bisect bad
Bisecting: 0 revisions left to test after this (roughly 0 steps)
[e6ee7588d26b63d6f002b9023026d25ccd024904] remove extra trims

Nodja>git bisect good
e87b8f2c0e0d11031f98eb30f85240bf10260523 is the first bad commit
commit e87b8f2c0e0d11031f98eb30f85240bf10260523
Author: Luke Pulverenti <luke.pulverenti@gmail.com>
Date:   Fri Apr 3 11:50:50 2015 -0400

    remove copyts from hls

:040000 040000 08033ede4d27c8249a643021214ff5bf0a5dfb14 3a3ce9ad53f4e98175daae102a13c3faefee3c88 M      MediaBrowser.Api
:040000 040000 493e6111b042c91c6ed329754757ba85740b87c8 ece0c96489f751367c16621dd889e1e5b03d7dd1 M      MediaBrowser.Model
:040000 040000 028076f39095d109f0274ea5516aa98d5ff26e08 f655c59755cd23488ec4f62b8d851747ceb69076 M      MediaBrowser.Server.Implementations

Which points to this commit.

 

Which seems to blame the removal of the -copyts flag from ffmpeg.

 

I ran the command using MB's ffmpeg version and got this output:

Nodja>C:\Users\Nodja\AppData\ProgramData-Server\ffmpeg\20150110\ffmpeg.exe -ss 00:12:18.000 -fflags +genpts -i file:"D:\Media\test\transcode example.mkv" -map_metadata -1 -threads 0 -map 0:0 -map 0:1 -codec:v:0 libx264 -pix_fmt yuv420p -preset superfast -crf 23 -maxrate 1899917 -bufsize 3799834 -vsync vfr -level 42 -force_key_frames expr:gte(t,n_forced*3) -vf "scale=min(iw\,1280):trunc(ow/dar/2)*2,subtitles='D\:/Media/test/transcode example.mkv:si=0',setpts=PTS -753/TB" -flags -global_header -sc_threshold 0 -codec:a:0 aac -strict experimental -ac 2 -ab 510000 -af "adelay=1,aresample=async=1,asetpts=PTS-753/TB" -hls_time 3 -start_number 251 -hls_list_size 0 -y "D:\vids\test2.m3u8"

ffmpeg version N-68994-g4df01d5 Copyright (c) 2000-2015 the FFmpeg developers
  built on Jan  9 2015 22:13:35 with gcc 4.9.2 (GCC)
  configuration: --enable-gpl --enable-version3 --disable-w32threads --enable-avisynth --enable-bzlib --enable-fontconfig --enable-frei0r --enable-gnutls --enable-iconv --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libfreetype --enable-libgme --enable-libgsm --enable-libilbc --enable-libmodplug --enable-libmp3lame --enable-libopencore-amrnb --enable-libopencore-amrwb --enable-libopenjpeg --enable-libopus --enable-librtmp --enable-libschroedinger --enable-libsoxr --enable-libspeex --enable-libtheora --enable-libtwolame --enable-libvidstab --enable-libvo-aacenc --enable-libvo-amrwbenc --enable-libvorbis --enable-libvpx --enable-libwavpack --enable-libwebp --enable-libx264 --enable-libx265 --enable-libxavs --enable-libxvid --enable-lzma --enable-decklink --enable-zlib
  libavutil      54. 16.100 / 54. 16.100
  libavcodec     56. 20.100 / 56. 20.100
  libavformat    56. 18.100 / 56. 18.100
  libavdevice    56.  3.100 / 56.  3.100
  libavfilter     5.  7.100 /  5.  7.100
  libswscale      3.  1.101 /  3.  1.101
  libswresample   1.  1.100 /  1.  1.100
  libpostproc    53.  3.100 / 53.  3.100
Input #0, matroska,webm, from 'file:D:\Media\test\transcode example.mkv':
  Metadata:
    encoder         : libebml v1.2.3 + libmatroska v1.3.0
    creation_time   : 2014-10-09 15:35:50
  Duration: 00:24:42.62, start: 0.000000, bitrate: 1899 kb/s
    Stream #0:0: Video: h264 (High), yuv420p, 1280x720 [SAR 1:1 DAR 16:9], 23.81 fps, 23.81 tbr, 1k tbn, 47.95 tbc (default) (forced)
    Stream #0:1: Audio: aac (LC), 44100 Hz, stereo, fltp (default) (forced)
    Stream #0:2: Subtitle: ass (default) (forced)
    Stream #0:3: Attachment: ttf
    Metadata:
      filename        : OpenSans-Semibold.ttf
      mimetype        : application/x-truetype-font
[libx264 @ 0000000004c23960] using SAR=1/1
[libx264 @ 0000000004c23960] using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2
[libx264 @ 0000000004c23960] profile High, level 4.2
Output #0, hls, to 'D:\vids\test2.m3u8':
  Metadata:
    encoder         : Lavf56.18.100
    Stream #0:0: Video: h264 (libx264), yuv420p, 1280x720 [SAR 1:1 DAR 16:9], q=-1--1, max. 1899 kb/s, 23.81 fps, 90k tbn, 23.81 tbc (default) (forced)
    Metadata:
      encoder         : Lavc56.20.100 libx264
    Stream #0:1: Audio: aac, 44100 Hz, stereo, fltp, 510 kb/s (default) (forced)
    Metadata:
      encoder         : Lavc56.20.100 aac
Stream mapping:
  Stream #0:0 -> #0:0 (h264 (native) -> h264 (libx264))
  Stream #0:1 -> #0:1 (aac (native) -> aac (native))
Press [q] to stop, [?] for help
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=144    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=315    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=468    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=640    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=856    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=1020    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=1156    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=1308    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=1497    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=1719    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=1884    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=2058    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=2240    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=2368    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=2520    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=2712    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=2854    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=3004    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=3173    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=3330    
frame=    0 fps=0.0 q=0.0 size=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=3465    
frame=    0 fps=0.0 q=0.0 Lsize=N/A time=00:00:00.00 bitrate=N/A dup=0 drop=3566    
video:0kB audio:7378kB subtitle:0kB other streams:0kB global headers:0kB muxing overhead: unknown
Received signal 2: terminating.

Which seems to be dropping every frame for some reason. Let me know if you need anything else.

 

edit: Forgot to say that I also ran the command with the -copyts flag and it generated the files correctly.

 

Edited April 13, 2015 by Nodja

[Luke 37065]

Since you're already on the dev builds, please try the latest one going up and and see if that behaves differently.

[Nodja 9]

The new one behaves correctly with hls enabled.

Hammering the forward button no longer causes it to misbehave either. Nice work Luke, thanks

[ebr 14913]

Excellent!

 

Thanks for the top-notch investigation.