Nvidia Shield on WIFI is freezing with Live TV

saltyzip · January 20, 2020, 6:00pm

My gut feeling is there is some new ffmpeg configuration required, specific for new 2019 shield, to make streaming more stable.

To answer Aman's post, I tried with software encoding yesterday when you originally requested it, and had the same issue, although didn't verify the same out of memory error via my own logging attempts, as it pre-dated it.

I did submit error reports via the app when software decode was selected. The only one I haven't tried is hybrid.

Do you want me to have another go with Software anyway?

saltyzip · January 20, 2020, 6:28pm

Same problem with Software Encoding:

01-20 18:16:06.296 7682 7790 V Streamer: started with 8589933380 byte buffer in /mnt/expand/53d42424-e034-4fbf-9218-ca3830162943/user/0/com.getchannels.app/cache/channels-streamer.ts
01-20 18:16:06.296 7682 7790 V Streamer: seek(0) = 0 -> 0
01-20 18:16:06.297 7682 7730 D mpv : [stream_callback] Stream opened successfully.
01-20 18:16:06.297 7682 7730 V mpv : [demux] Trying demuxers for level=force.
01-20 18:16:06.297 7682 7730 D mpv : [demux] Trying demuxer: lavf (force-level: force)
01-20 18:16:06.310 7682 7730 V mpv : [lavf] Found 'mpegts' at score=50 size=2048.
01-20 18:16:06.310 7682 7730 V mpv : [lavf] avformat_open_input() finished after 2048 bytes.
01-20 18:16:06.310 7682 7730 D mpv : [ffmpeg/demuxer] mpegts: Before avformat_find_stream_info() pos: 0 bytes read:2048 seeks:0 nb_streams:3
01-20 18:16:06.375 7682 7730 D mpv : [ffmpeg/video] h264: Reinit context to 1920x1088, pix_fmt: yuv420p
01-20 18:16:06.462 7682 7730 E mpv : [ffmpeg/video] h264: mmco: unref short failure
01-20 18:16:06.463 7682 7730 V mpv : [ffmpeg/demuxer] mpegts: Skipping duration calculation in estimate_timings_from_pts
01-20 18:16:06.463 7682 7790 V Streamer: seek(0) = 611816 -> 0
01-20 18:16:06.464 7682 7730 D mpv : [ffmpeg/demuxer] mpegts: After avformat_find_stream_info() pos: 0 bytes read:611816 seeks:1 frames:72
01-20 18:16:06.465 7682 7730 V mpv : [lavf] avformat_find_stream_info() finished after 0 bytes.
01-20 18:16:06.465 7682 7730 V mpv : [demux] Detected file format: mpegts (libavformat)
01-20 18:16:06.465 7682 7730 V mpv : [cplayer] Opening done: hdhr://107
01-20 18:16:06.465 7682 7730 V mpv : event: tracks-changed
01-20 18:16:06.465 7682 7730 I chatty : uid=10123(com.getchannels.app) mpv-events identical 1 line
01-20 18:16:06.465 7682 7730 V mpv : event: tracks-changed
01-20 18:16:06.465 7682 7730 D mpv : [global] config path: 'sub' -/-> '/mnt/expand/53d42424-e034-4fbf-9218-ca3830162943/user/0/com.getchannels.app/files/mpv/sub'
01-20 18:16:06.466 7682 7730 V mpv : event: metadata-update
01-20 18:16:06.467 7682 7730 V mpv : property: track-list has 3 entries
01-20 18:16:06.471 3080 3080 E SELinux : avc: denied { find } for interface=vendor.nvidia.hardware.cpl.service::INvCplHalService sid=u:r:untrusted_app:s0:c123,c256,c512,c768 pid=7682 scontext=u:r:untrusted_app:s0:c123,c256,c512,c768 tcontext=u:object_r:hal_cplservice_hwservice:s0 tclass=hwservice_manager permissive=0
01-20 18:16:06.471 7682 7793 E libnvcpl_vendor: NvCplGetAppProfileSettingInt failed to get INvCplHalService
01-20 18:16:06.471 3080 3080 E SELinux : avc: denied { find } for interface=vendor.nvidia.hardware.cpl.service::INvCplHalService sid=u:r:untrusted_app:s0:c123,c256,c512,c768 pid=7682 scontext=u:r:untrusted_app:s0:c123,c256,c512,c768 tcontext=u:object_r:hal_cplservice_hwservice:s0 tclass=hwservice_manager permissive=0
01-20 18:16:06.471 7682 7793 E libnvcpl_vendor: NvCplGetAppProfileSettingInt failed to get INvCplHalService
01-20 18:16:06.502 7682 7730 V mpv : event: audio-reconfig
01-20 18:16:06.503 7682 7730 V mpv : event: audio-reconfig
01-20 18:16:06.503 7682 7730 V mpv : event: file-loaded
01-20 18:16:06.503 7682 7682 V PlayerActivity: state LOADING -> LOADED
01-20 18:16:06.503 7682 7730 V mpv : [lavf] select track 0
01-20 18:16:06.503 7682 7730 V mpv : property: buffering = false
01-20 18:16:06.504 7682 7730 V mpv : property: track-list has 3 entries
01-20 18:16:06.504 7682 7730 V mpv : [lavf] select track 1
01-20 18:16:06.504 7682 7730 I mpv : [cplayer] (+) Video --vid=1 (h264 1920x1080 25.000fps)
01-20 18:16:06.504 7682 7730 I mpv : [cplayer] (+) Audio --aid=1 --alang=eng (aac_latm 2ch 48000Hz)
01-20 18:16:06.504 7682 7730 I mpv : [cplayer] Subs --sid=1 --slang=eng (dvb_subtitle)
01-20 18:16:06.504 7682 7730 F mpv : [vo/gpu/opengl] Could not create EGL context for Desktop OpenGL!
01-20 18:16:06.504 7682 7730 V mpv : [vd] Container reported FPS: 25.000000
01-20 18:16:06.504 7682 7730 V mpv : [vd] Codec list:
01-20 18:16:06.504 7682 7730 V mpv : [vd] h264 - H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
01-20 18:16:06.504 7682 7730 V mpv : [vd] h264_mediacodec (h264) - H.264 Android MediaCodec decoder
01-20 18:16:06.504 7682 7730 V mpv : [vd] Opening decoder h264
01-20 18:16:06.504 7682 7730 V mpv : [vd] No hardware decoding requested.
01-20 18:16:06.505 7682 7730 V mpv : [vd] Using software decoding.
01-20 18:16:06.505 7682 7730 V mpv : [vd] Detected 4 logical cores.
01-20 18:16:06.505 7682 7730 V mpv : [vd] Requesting 5 threads for decoding.
01-20 18:16:06.505 7682 7730 V mpv : [vd] Selected codec: h264 (H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10)
01-20 18:16:06.505 7682 7730 D mpv : [user_filter_wrapper] Setting option 'graph' = 'fastdeint=linear' (flags = 0)
01-20 18:16:06.505 7682 7730 V mpv : [vf] User filter list:
01-20 18:16:06.505 7682 7730 V mpv : [vf] lavfi (lavfi.00)
01-20 18:16:06.505 7682 7730 V mpv : [ad] Codec list:
01-20 18:16:06.505 7682 7730 V mpv : [ad] aac_latm - AAC LATM (Advanced Audio Coding LATM syntax)
01-20 18:16:06.505 7682 7730 V mpv : [ad] Opening decoder aac_latm
01-20 18:16:06.506 7682 7730 V mpv : [ad] Requesting 1 threads for decoding.
01-20 18:16:06.506 7682 7730 V mpv : [ad] Selected codec: aac_latm (AAC LATM (Advanced Audio Coding LATM syntax))
01-20 18:16:06.506 7682 7730 V mpv : [af] User filter list:
01-20 18:16:06.506 7682 7730 V mpv : [af] (empty)
01-20 18:16:06.506 7682 7730 V mpv : [cplayer] Starting playback...
01-20 18:16:06.506 7682 7730 I mpv : [cplayer] Track switched:
01-20 18:16:06.506 7682 7730 I mpv : [cplayer] (+) Video --vid=1 (h264 1920x1080 25.000fps)
01-20 18:16:06.506 7682 7730 I mpv : [cplayer] (+) Audio --aid=1 --alang=eng (aac_latm 2ch 48000Hz)
01-20 18:16:06.506 7682 7730 I mpv : [cplayer] Subs --sid=1 --slang=eng (dvb_subtitle)
01-20 18:16:06.507 7682 7730 V mpv : [cplayer] Set property: aid=1 -> 1
01-20 18:16:06.507 7682 7730 V mpv : [af] [in] 48000Hz stereo 2ch floatp
01-20 18:16:06.507 7682 7730 V mpv : [af] [userspeed] 48000Hz stereo 2ch floatp
01-20 18:16:06.507 7682 7730 V mpv : [af] [userspeed] (disabled)
01-20 18:16:06.507 7682 7730 V mpv : [af] [convert] 48000Hz stereo 2ch floatp
01-20 18:16:06.507 7682 7730 V mpv : [ao] Trying audio driver 'audiotrack'
01-20 18:16:06.507 7682 7730 V mpv : [ao/audiotrack] requested format: 48000 Hz, stereo channels, floatp
01-20 18:16:06.509 7682 7730 V mpv : [ao/audiotrack] AudioTrack.nativeOutputSampleRate = 48000
01-20 18:16:06.518 7682 7730 V mpv : [ao/audiotrack] Setting bufferSize = 19200 (driver=6160, min=19200, max=28800)
01-20 18:16:06.519 3231 4123 I APM_AudioPolicyManager: setMsdEnable: dolby_audio_enable = 1, is_media_streaming_app = 0 enable = 0 mMsdEnable = 0 is_dolby_formats = 0
01-20 18:16:06.522 3231 4123 I APM_AudioPolicyManager: getOutputForAttr() device 0x400, sampling rate 48000, format 0x1, channel mask 0x3, flags 0x8
01-20 18:16:06.522 3231 4123 W AudioFlinger: createTrack_l(): mismatch between requested flags (00000008) and output flags (00000006)
01-20 18:16:06.522 3231 4123 D AudioFlinger: Client defaulted notificationFrames to 2400 for frameCount 4800
01-20 18:16:06.524 7682 7727 W AudioTrack: Use of stream types is deprecated for operations other than volume control
01-20 18:16:06.524 7682 7727 W AudioTrack: See the documentation of AudioTrack() for what to use instead with android.media.AudioAttributes to qualify your playback use case
01-20 18:16:06.524 7682 7730 V mpv : [ao/audiotrack] device buffer: 9600 samples.
01-20 18:16:06.524 7682 7730 V mpv : [ao/audiotrack] using soft-buffer of 9600 samples.
01-20 18:16:06.524 7682 7730 I mpv : [cplayer] AO: [audiotrack] 48000Hz stereo 2ch s16
01-20 18:16:06.524 7682 7730 V mpv : [cplayer] AO: Description: Android AudioTrack audio output
01-20 18:16:06.525 7682 7730 V mpv : event: audio-reconfig
01-20 18:16:06.525 7682 7730 V mpv : [autoconvert] inserting resampler
01-20 18:16:06.525 7682 7730 V mpv : [swresample] format change, reinitializing resampler
01-20 18:16:06.525 7682 7730 V mpv : [swresample] 48000Hz stereo floatp -> 48000Hz stereo s16
01-20 18:16:06.525 7682 7730 V mpv : [af] [out] 48000Hz stereo 2ch s16
01-20 18:16:06.525 7682 7730 D mpv : [ffmpeg/video] h264: Reinit context to 1920x1088, pix_fmt: yuv420p
01-20 18:16:06.526 7682 7730 D mpv : [vd] DR parameter change to 1920x1090 yuv420p align=16
01-20 18:16:06.526 7682 7730 D mpv : [vd] Allocating new DR image...
01-20 18:16:06.526 7682 7730 D mpv : [vd] ...failed..
01-20 18:16:06.526 7682 7730 V mpv : [vd] DR failed - disabling.
01-20 18:16:06.534 7682 7730 E mpv : [ffmpeg/video] h264: co located POCs unavailable
01-20 18:16:06.542 7682 7730 D mpv : [ffmpeg/video] h264: Increasing reorder buffer to 2
01-20 18:16:06.601 7682 7730 E mpv : [ffmpeg/video] h264: reference picture missing during reorder
01-20 18:16:06.601 7682 7730 E mpv : [ffmpeg/video] h264: Missing reference picture, default is 65848
01-20 18:16:06.676 7682 7730 E mpv : [ffmpeg/video] h264: reference picture missing during reorder
01-20 18:16:06.676 7682 7730 E mpv : [ffmpeg/video] h264: Missing reference picture, default is 65864
01-20 18:16:06.679 7682 7730 E mpv : [ffmpeg/video] h264: mmco: unref short failure
01-20 18:16:06.817 7682 7730 D mpv : [ffmpeg/video] h264: Increasing reorder buffer to 3
01-20 18:16:06.835 7682 7730 V mpv : [vd] Decoder format: 1920x1080 yuv420p bt.709/bt.709/bt.1886/limited/auto CL=mpeg2/4/h264 (auto 0.000000/0.000000/0.000000)
01-20 18:16:06.835 7682 7730 V mpv : [vd] Forcing user-set aspect ratio.
01-20 18:16:06.835 7682 7730 V mpv : [vf] [in] 1920x1080 [134217729:134217728] yuv420p bt.709/bt.709/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
01-20 18:16:06.835 7682 7730 V mpv : [vf] [userdeint] 1920x1080 [134217729:134217728] yuv420p bt.709/bt.709/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
01-20 18:16:06.836 7682 7730 V mpv : [vf] [userdeint] (disabled)
01-20 18:16:06.836 7682 7730 V mpv : [vf] [lavfi] 1920x1080 [134217729:134217728] yuv420p bt.709/bt.709/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
01-20 18:16:06.836 7682 7730 D mpv : [ffmpeg] mpv_src_in0: w:1920 h:1080 pixfmt:yuv420p tb:1/1000000 fr:25/1 sar:134217729/134217728 sws_param:
01-20 18:16:06.836 7682 7730 D mpv : [lavfi] Filter graph:
01-20 18:16:06.836 7682 7730 D mpv : [lavfi] +--------------------+
01-20 18:16:06.836 7682 7730 D mpv : [lavfi] mpv_src_in0:default--[1920x1080 134217729:134217728 yuv420p]--default| Parsed_fastdeint_0 |default--[1920x1080 134217729:134217728 yuv420p]--mpv_sink_out0:default
01-20 18:16:06.836 7682 7730 D mpv : [lavfi] | (fastdeint) |
01-20 18:16:06.836 7682 7730 D mpv : [lavfi] +--------------------+
01-20 18:16:06.836 7682 7730 D mpv : [lavfi]
01-20 18:16:06.836 7682 7730 D mpv : [lavfi] +---------------+
01-20 18:16:06.836 7682 7730 D mpv : [lavfi] Parsed_fastdeint_0:default--[1920x1080 134217729:134217728 yuv420p]--default| mpv_sink_out0 |
01-20 18:16:06.836 7682 7730 D mpv : [lavfi] | (buffersink) |
01-20 18:16:06.836 7682 7730 D mpv : [lavfi] +---------------+
01-20 18:16:06.837 7682 7730 D mpv : [lavfi]
01-20 18:16:06.837 7682 7730 D mpv : [lavfi] +-------------+
01-20 18:16:06.837 7682 7730 D mpv : [lavfi] | mpv_src_in0 |default--[1920x1080 134217729:134217728 yuv420p]--Parsed_fastdeint_0:default
01-20 18:16:06.837 7682 7730 D mpv : [lavfi] | (buffer) |
01-20 18:16:06.837 7682 7730 D mpv : [lavfi] +-------------+
01-20 18:16:06.837 7682 7730 D mpv : [lavfi]
01-20 18:16:06.837 7682 7730 D mpv : [lavfi]
01-20 18:16:06.860 7682 7730 V mpv : [vf] [autorotate] 1920x1080 [134217729:134217728] yuv420p bt.709/bt.709/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
01-20 18:16:06.860 7682 7730 V mpv : [vf] [autorotate] (disabled)
01-20 18:16:06.860 7682 7730 V mpv : [vf] [convert] 1920x1080 [134217729:134217728] yuv420p bt.709/bt.709/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
01-20 18:16:06.860 7682 7730 V mpv : [vf] [convert] (disabled)
01-20 18:16:06.860 7682 7730 V mpv : [vf] [out] 1920x1080 [134217729:134217728] yuv420p bt.709/bt.709/bt.1886/limited/display SP=1.000000 CL=mpeg2/4/h264
01-20 18:16:06.860 7682 7730 I mpv : [cplayer] VO: [gpu] 1920x1080 => 1920x1080 yuv420p
01-20 18:16:06.860 7682 7730 V mpv : [cplayer] VO: Description: Shader-based GPU Renderer
01-20 18:16:06.863 7682 7730 V mpv : event: video-reconfig
01-20 18:16:06.871 3233 3317 D SurfaceFlinger: Connected to Power Manager
01-20 18:16:06.874 7682 7730 V mpv : [cplayer] first video frame after restart shown
01-20 18:16:06.874 7682 7730 D mpv : [cplayer] Setting option 'cache-pause-initial' = "0.3" (flags = 64) -> 0
01-20 18:16:06.874 7682 7730 D mpv : [cplayer] Setting option 'cache-pause-wait' = "0.1" (flags = 64) -> 0
01-20 18:16:06.874 7682 7730 D mpv : [cplayer] Setting option 'cache-pause-fill' = "0.5" (flags = 64) -> 0
01-20 18:16:06.890 7682 7730 V mpv : event: video-reconfig
01-20 18:16:06.900 3668 4118 I bt_btif_avrc: register_notification_rsp: Avrcp device is not connected, handle: 0x0
01-20 18:16:06.900 3668 4118 I chatty : uid=1002(bluetooth) BluetoothAvrcpH identical 4 lines
01-20 18:16:06.900 3668 4118 I bt_btif_avrc: register_notification_rsp: Avrcp device is not connected, handle: 0x0
01-20 18:16:06.901 7682 7730 V mpv : [cplayer] starting audio playback
01-20 18:16:06.952 7682 7730 V mpv : event: playback-restart
01-20 18:16:06.952 7682 7682 V PlayerActivity: state LOADED -> PLAYING
01-20 18:16:06.953 7682 7730 V mpv : [cplayer] playback restart complete @ 1.823056
01-20 18:16:09.294 7682 7682 V mpvstats: AV: 4.083 A-V: 0.000 Dropped: 0 Cache: 0.341s + 0KB
01-20 18:16:09.575 3508 3552 D NetlinkTracker/wlan0: addressUpdated: 2a00:23c7:3c17:6600:204:4bff:feef:f448/64 on wlan0 flags 0 scope 0
01-20 18:16:09.575 3508 3552 D NetlinkTracker/wlan0: addressUpdated: 2a00:23c7:3c17:6600:65bf:8880:3a4d:91dd/64 on wlan0 flags 1 scope 0
01-20 18:16:09.576 3508 3552 D NetlinkTracker/wlan0: interfaceDnsServerInfo: [2a00:23c7:3c17:6600::1]
01-20 18:16:12.304 7682 7682 V mpvstats: AV: 7.063 A-V: 0.000 Dropped: 0 Cache: 0.235s + 0KB
01-20 18:16:15.305 7682 7682 V mpvstats: AV: 10.083 A-V: 0.000 Dropped: 0 Cache: 0.277s + 0KB
01-20 18:16:17.975 4054 4054 D AtvRemote.ABridgeX: AudioPolicy is being unregistered
01-20 18:16:17.975 3508 7037 I AudioService: unregisterAudioPolicyAsync for android.os.BinderProxy@7a16537
01-20 18:16:17.975 3231 4123 I APM_AudioPolicyManager: setDeviceConnectionStateInt() device: 0x8000, state 0, address -581846373:ap:58mixr:0 name remote-submix
01-20 18:16:18.034 3231 7417 D AudioFlinger: ro.audio.silent will be ignored for threads on AUDIO_DEVICE_OUT_REMOTE_SUBMIX
01-20 18:16:18.035 3191 3397 D r_submix: out_set_parameters(): shutting down MonoPipe sink
01-20 18:16:18.036 3191 3397 D r_submix: adev_close_output_stream() addr = -581846373:ap:58mixr:0
01-20 18:16:18.036 3191 3397 D r_submix: submix_audio_device_release_pipe_l(idx=9) addr=-581846373:ap:58mixr:0
01-20 18:16:18.036 3191 3397 D r_submix: submix_audio_device_destroy_pipe_l(): pipe destroyed
01-20 18:16:18.305 7682 7682 V mpvstats: AV: 13.083 A-V: 0.000 Dropped: 0 Cache: 0.405s + 0KB
01-20 18:16:18.589 3508 3552 D NetlinkTracker/wlan0: addressUpdated: 2a00:23c7:3c17:6600:204:4bff:feef:f448/64 on wlan0 flags 0 scope 0
01-20 18:16:18.590 3508 3552 D NetlinkTracker/wlan0: addressUpdated: 2a00:23c7:3c17:6600:65bf:8880:3a4d:91dd/64 on wlan0 flags 1 scope 0
01-20 18:16:18.590 3508 3552 D NetlinkTracker/wlan0: interfaceDnsServerInfo: [2a00:23c7:3c17:6600::1]
01-20 18:16:21.306 7682 7682 V mpvstats: AV: 16.083 A-V: 0.000 Dropped: 0 Cache: 0.320s + 0KB
01-20 18:16:23.642 3294 3343 E storaged: getDiskStats failed with result NOT_SUPPORTED and size 0
01-20 18:16:24.309 7682 7682 V mpvstats: AV: 19.083 A-V: 0.000 Dropped: 0 Cache: 0.384s + 0KB
01-20 18:16:26.676 3508 3552 D NetlinkTracker/wlan0: addressUpdated: 2a00:23c7:3c17:6600:204:4bff:feef:f448/64 on wlan0 flags 0 scope 0
01-20 18:16:26.676 3508 3552 D NetlinkTracker/wlan0: addressUpdated: 2a00:23c7:3c17:6600:65bf:8880:3a4d:91dd/64 on wlan0 flags 1 scope 0
01-20 18:16:26.676 3508 3552 D NetlinkTracker/wlan0: interfaceDnsServerInfo: [2a00:23c7:3c17:6600::1]
01-20 18:16:27.310 7682 7682 V mpvstats: AV: 22.103 A-V: 0.000 Dropped: 0 Cache: 0.256s + 0KB
01-20 18:16:28.039 6788 6858 I chromium: [6788:6858:INFO:ssdp_device.c(101)] SSDP packets sent for 39 seconds = 4
01-20 18:16:30.311 7682 7682 V mpvstats: AV: 25.103 A-V: 0.000 Dropped: 0 Cache: 0.320s + 0KB
01-20 18:16:30.630 6788 6828 I chromium: [6788:6828:INFO:mdns_app_filter.cc(2579)] MdnsAppFilter: responses sent in 63 seconds: 1
01-20 18:16:33.311 7682 7682 V mpvstats: AV: 28.103 A-V: 0.000 Dropped: 0 Cache: 0.405s + 0KB
01-20 18:16:33.639 3508 3552 D NetlinkTracker/wlan0: addressUpdated: 2a00:23c7:3c17:6600:204:4bff:feef:f448/64 on wlan0 flags 0 scope 0
01-20 18:16:33.640 3508 3552 D NetlinkTracker/wlan0: addressUpdated: 2a00:23c7:3c17:6600:65bf:8880:3a4d:91dd/64 on wlan0 flags 1 scope 0
01-20 18:16:33.640 3508 3552 D NetlinkTracker/wlan0: interfaceDnsServerInfo: [2a00:23c7:3c17:6600::1]
01-20 18:16:35.384 6788 6788 I chromium: [6788:6788:INFO:metrics_recorder.cc(106)] Metrics stat: total=3
01-20 18:16:35.384 6788 6788 I chromium: Cast.Discovery.Mdns.Query.Cast.Count=1
01-20 18:16:35.384 6788 6788 I chromium: Cast.Discovery.Mdns.Request.In=1
01-20 18:16:35.384 6788 6788 I chromium: Cast.Discovery.Mdns.Response.Out=1
01-20 18:16:36.305 6788 6828 I chromium: [6788:6828:INFO:mdns_app_filter.cc(2766)] Mdns cast queries recently sent: queries=1
01-20 18:16:36.312 7682 7682 V mpvstats: AV: 31.103 A-V: 0.000 Dropped: 0 Cache: 0.299s + 0KB
01-20 18:16:36.471 6788 6832 I chromium: [6788:6832:INFO:wifi_proximity.cc(176)] Request scan.
01-20 18:16:37.159 4096 30392 E WakeLock: GCM_HB_ALARM release without a matched acquire!
01-20 18:16:37.199 4096 30394 W GCM : Raising heartbeat interval to 1740000, good=30 bad=0
01-20 18:16:37.313 3508 3548 I ActivityManager: Start proc 7813:com.google.android.gms:snet/u0a6 for service com.google.android.gms/.chimera.SnetIntentOperationService
01-20 18:16:37.320 7813 7813 E ndroid.gms:sne: Not starting debugger since process cannot load the jdwp agent.
01-20 18:16:37.374 7813 7813 I ndroid.gms:sne: The ClassLoaderContext is a special shared library.
01-20 18:16:37.445 7813 7813 W DynamiteModule: Local module descriptor class for providerinstaller not found.
01-20 18:16:37.453 7813 7813 W ProviderHelper: Unknown dynamite feature providerinstaller
01-20 18:16:37.464 7813 7813 I DynamiteModule: Considering local module providerinstaller:0 and remote module providerinstaller:0
01-20 18:16:37.464 7813 7813 W ProviderInstaller: Failed to load providerinstaller module: No acceptable module found. Local version is 0 and remote version is 0.
01-20 18:16:37.473 7813 7813 V NativeCrypto: Registering com/google/android/gms/org/conscrypt/NativeCrypto's 286 native methods...
01-20 18:16:37.490 7813 7813 D NetworkSecurityConfig: Using Network Security Config from resource network_security_config debugBuild: false
01-20 18:16:37.493 7813 7813 I ProviderInstaller: Installed default security provider GmsCore_OpenSSL
01-20 18:16:37.512 7813 7813 I Safeboot: Checking safeboot...
01-20 18:16:37.513 7813 7813 I Safeboot: Not entering safeboot; wrong process.
01-20 18:16:37.588 7813 7813 W PrimesInit: Primes instant initialization
01-20 18:16:37.594 7813 7837 W Primes : background initialization
01-20 18:16:37.798 3508 3532 I system_server: Background concurrent copying GC freed 148124(7MB) AllocSpace objects, 31(1452KB) LOS objects, 42% free, 12MB/21MB, paused 158us total 115.198ms
01-20 18:16:39.312 7682 7682 V mpvstats: AV: 34.103 A-V: 0.000 Dropped: 0 Cache: 0.341s + 0KB
01-20 18:16:40.602 3508 3552 D NetlinkTracker/wlan0: addressUpdated: 2a00:23c7:3c17:6600:204:4bff:feef:f448/64 on wlan0 flags 0 scope 0
01-20 18:16:40.603 3508 3552 D NetlinkTracker/wlan0: addressUpdated: 2a00:23c7:3c17:6600:65bf:8880:3a4d:91dd/64 on wlan0 flags 1 scope 0
01-20 18:16:40.603 3508 3552 D NetlinkTracker/wlan0: interfaceDnsServerInfo: [2a00:23c7:3c17:6600::1]
01-20 18:16:42.313 7682 7682 V mpvstats: AV: 37.103 A-V: 0.000 Dropped: 0 Cache: 0.235s + 0KB
01-20 18:16:45.313 7682 7682 V mpvstats: AV: 40.103 A-V: 0.000 Dropped: 0 Cache: 0.277s + 0KB
01-20 18:16:48.314 7682 7682 V mpvstats: AV: 43.103 A-V: 0.000 Dropped: 0 Cache: 0.277s + 0KB
01-20 18:16:50.023 3508 3552 D NetlinkTracker/wlan0: addressUpdated: 2a00:23c7:3c17:6600:204:4bff:feef:f448/64 on wlan0 flags 0 scope 0
01-20 18:16:50.023 3508 3552 D NetlinkTracker/wlan0: addressUpdated: 2a00:23c7:3c17:6600:65bf:8880:3a4d:91dd/64 on wlan0 flags 1 scope 0
01-20 18:16:50.023 3508 3552 D NetlinkTracker/wlan0: interfaceDnsServerInfo: [2a00:23c7:3c17:6600::1]
01-20 18:16:51.315 7682 7682 V mpvstats: AV: 46.103 A-V: 0.000 Dropped: 0 Cache: 0.320s + 0KB
01-20 18:16:53.554 7682 7730 W mpv : [lavf] error reading packet: Out of memory.
01-20 18:16:53.554 7682 7730 V mpv : [lavf] EOF reached.
01-20 18:16:53.567 7682 7730 W mpv : [lavf] error reading packet: Out of memory.
01-20 18:16:53.588 7682 7730 W mpv : [lavf] error reading packet: Out of memory.
01-20 18:16:53.628 7682 7730 E mpv : [ad] Error decoding audio.
01-20 18:16:53.628 7682 7730 I chatty : uid=10123(com.getchannels.app) mpv-events identical 1 line
01-20 18:16:53.628 7682 7730 E mpv : [ad] Error decoding audio.
01-20 18:16:53.628 7682 7730 V mpv : [af] filter input EOF
01-20 18:16:53.628 7682 7730 V mpv : [af] filter output EOF
01-20 18:16:53.653 7682 7730 W mpv : [ad] Invalid audio PTS: 48.832000 -> 49.152000
01-20 18:16:53.654 7682 7730 V mpv : event: unpause
01-20 18:16:53.654 3668 4118 I bt_btif_avrc: register_notification_rsp: Avrcp device is not connected, handle: 0x0
01-20 18:16:53.654 3668 4118 I chatty : uid=1002(bluetooth) BluetoothAvrcpH identical 4 lines
01-20 18:16:53.654 3668 4118 I bt_btif_avrc: register_notification_rsp: Avrcp device is not connected, handle: 0x0
01-20 18:16:53.654 7682 7730 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
01-20 18:16:53.654 7682 7730 V mpv : property: buffering = true
01-20 18:16:53.655 7682 7682 V PlayerActivity: state PLAYING -> BUFFERING
01-20 18:16:53.656 7682 7682 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=6.983055111111753, end=48.98133288888857}], cache-end=49.15199955555545, reader-pts=49.15199955555545, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=32433920, fw-bytes=440640, debug-low-level-seeks=0, debug-ts-last=9768.899255555556, ts-per-stream=[{type=video, duration=0.7600000000002183, reader=9768.33031111111, end=9769.090311111111}, {type=audio, duration=0.0, reader=9768.899255555556, end=9768.899255555556}]}
01-20 18:16:53.661 7682 7730 E mpv : [ad] Error decoding audio.
01-20 18:16:53.681 7682 7730 W mpv : [lavf] error reading packet: Out of memory.
01-20 18:16:53.681 7682 7730 V mpv : [lavf] EOF reached.
01-20 18:16:53.682 7682 7730 V mpv : event: unpause
01-20 18:16:53.682 7682 7730 V mpv : [cplayer] End buffering (waited 0.028269 secs) [0.000000s].
01-20 18:16:53.682 7682 7730 V mpv : [af] filter input EOF
01-20 18:16:53.682 7682 7730 V mpv : property: buffering = false
01-20 18:16:53.682 7682 7730 V mpv : [af] filter output EOF
01-20 18:16:53.683 3668 4118 I bt_btif_avrc: register_notification_rsp: Avrcp device is not connected, handle: 0x0
01-20 18:16:53.684 3668 4118 I chatty : uid=1002(bluetooth) BluetoothAvrcpH identical 10 lines
01-20 18:16:53.684 3668 4118 I bt_btif_avrc: register_notification_rsp: Avrcp device is not connected, handle: 0x0
01-20 18:16:53.688 7682 7682 V PlayerActivity: state BUFFERING -> PLAYING
01-20 18:16:53.785 7682 7730 W mpv : [lavf] error reading packet: Out of memory.
01-20 18:16:53.827 7682 7730 V mpv : event: unpause
01-20 18:16:53.827 7682 7730 W mpv : [ad] Invalid audio PTS: 49.173333 -> 49.322667
01-20 18:16:53.828 7682 7730 V mpv : property: buffering = true
01-20 18:16:53.828 7682 7730 V mpv : [cplayer] Enter buffering (buffer went from 100% -> 0%) [0.000000s].
01-20 18:16:53.848 7682 7682 V PlayerActivity: state PLAYING -> BUFFERING
01-20 18:16:53.848 7682 7682 V mpvstats: demuxer-cache-state: {seekable-ranges=[{start=6.983055111111753, end=49.17333288888949}], cache-end=49.322666222222324, reader-pts=49.322666222222324, cache-duration=0.0, eof=false, underrun=true, idle=false, total-bytes=32396544, fw-bytes=396928, debug-low-level-seeks=0, debug-ts-last=9769.069922222223, ts-per-stream=[{type=video, duration=0.6399999999994179, reader=9768.450311111112, end=9769.090311111111}, {type=audio, duration=0.0, reader=9769.069922222223, end=9769.069922222223}]}
01-20 18:16:53.878 7682 7730 V mpv : [cplayer] Still buffering (buffer went from 0% -> 4%) [0.021333s].
01-20 18:16:53.878 7682 7730 E mpv : [ad] Error decoding audio.
01-20 18:16:53.878 7682 7730 V mpv : [cplayer] Still buffering (buffer went from 4% -> 0%) [0.000000s].
01-20 18:16:53.899 7682 7730 W mpv : [lavf] error reading packet: Out of memory.
01-20 18:16:53.900 7682 7730 V mpv : [lavf] EOF reached.
01-20 18:16:53.900 3668 4118 I bt_btif_avrc: register_notification_rsp: Avrcp device is not connected, handle: 0x0
01-20 18:16:53.900 3668 4118 I chatty : uid=1002(bluetooth) BluetoothAvrcpH identical 4 lines
01-20 18:16:53.900 3668 4118 I bt_btif_avrc: register_notification_rsp: Avrcp device is not connected, handle: 0x0
01-20 18:16:53.932 7682 7730 V mpv : event: unpause
01-20 18:16:53.932 7682 7730 V mpv : [cplayer] End buffering (waited 0.072684 secs) [0.000000s].
01-20 18:16:53.932 7682 7730 V mpv : [af] filter input EOF
01-20 18:16:53.932 7682 7730 V mpv : [af] filter output EOF
01-20 18:16:53.932 7682 7730 W mpv : [lavf] error reading packet: Out of memory.
01-20 18:16:53.934 7682 7730 V mpv : property: buffering = false

saltyzip · January 20, 2020, 6:33pm

Aman, I have put the full software log error file in the Google Drive Folder I PM you the other day. There is one labeled hardware and one labelled software now from today. In the software log file, the first error is due to me starting a stream which had no sound, so I had to kill channels app to get it back and then start again.

saltyzip · January 20, 2020, 6:57pm

If it isn't the ffmpg settings that require tweaking perhaps its the java code itself needs to be a little bit more frugal on the main memory. From my simple java mobile app exploits many years ago, I remember the pain of ensuring I reuse objects and having to call System.gc() every so often to keep the memory tuned. The new nvidia shield isn't so forgiving with it's 2GB Ram. If they had stuck 3 GB RAM within it and supported 64 bit mode we probably wouldn't all be reading this now.

saltyzip · January 22, 2020, 10:54am

Hi Aman, what is the next steps with this one, any potential ETA on the fix, have you manged to replicate the issue in house? I appreciate we are probably looking at weeks for a resolution depending on other priorities.

More than happy to help test any developer builds if it helps, just let me know.

tmm1 · January 22, 2020, 5:36pm

I'm guessing this is related to the UK interlaced h264 streams, which is going to make it hard for me to reproduce. I also don't have the new shield.

Next step in debugging I would suggest signing up for the DVR beta and try to record and watch to see if the issue also affects recordings or only live tv.

saltyzip · January 22, 2020, 8:46pm

Let me get this right, I've already bought the standard channels product which has a bug in it on the new shield and now I need to buy the DVR which I don't need to help your investigation?

tmm1 · January 22, 2020, 8:50pm

The DVR has a 30-day free trial. You don't need to buy anything. Understanding whether the issue occurs on recorded TV will help us narrow down whether the issue is occurring in the player or the live tv buffer.

Andrew_Fuller · January 23, 2020, 8:57am

Hey there. I’m in the uk. Are there any channels you’d like me to check. I have a shield too, but not the cylinder one.

saltyzip · January 23, 2020, 10:30am

I have the original shield 2015 version and I don't have the issue, the problem is only confirmed on my new 2019 cylinder version at the moment. If you have the new 2019 pro version then it would be good to test on that.

Channel wise I've had issues on most channels I don't think it has to be HD although that is mostly what I've been testing with. BBC News HD I've completed most of the tests with lately. I think my original tests were with Pick and this is SD.

saltyzip · January 23, 2020, 10:31am

Ok, I've signed up and will record BBC News HD for a couple of hours shortly and then test playback a little later.

Watch this space!

Andrew_Fuller · January 23, 2020, 4:33pm

Nope, no cylinder here. I don’t think you can win with any box these days: Apple doesn’t do universal search for Netflix in the uk or Plex anywhere. Shield doesn’t do universal for amazon. And the fire tv doesn’t play back rips via Plex well.

Dimitri1177 · January 24, 2020, 8:48pm

I had issues with shield too. Switched to Apple TV and virtually issue free since then. The Apple TV on wifi is still better than shield wired.

Another thing I noticed is when the shield froze it was never coming back. You had to exit to guide and restart the stream. On the rare occasion the Apple TV freezes clicking the remote restarts the strem.

saltyzip · January 25, 2020, 1:31pm

This issue has nothing to do with wired vs wi-fi, a lot of people have jumped to that conclusion. The problem seems related to memory handling on the 2019 cylinder shield only, due to its lower 2GB memory size. I don't do Apple, the products are good but I don't like the people who run the company, Schiller especially. He seems to think no one can succeed in this world without buying an Apple product, they are just obnoxious.

On my 2019 Shield I watched a Blu-ray on Plex last night for couple of hours averaging 35Mbps, played sweet as a icing on a cake. The shield WiFi connects on 5ghz AC so complete overkill for my Live TV requirements, TX rate is above 320Mbps.

I'll have some time later to properly test the DVR playback. As a spoiler It has hung for me in the week but I've not had time to submit or capture my own logs to confirm exact same issue.

saltyzip · January 25, 2020, 2:03pm

Hi Aman, The results are in, same sort of out of memory error on playback from DVR, snippet below. I've placed the log file android-debug-hardware-dvr.log in the same directory as the others on my shared Google Drive folder. I also clicked submit log option via the channels app too.

01-25 13:52:50.098 7963 8043 W mpv : [lavf] error reading packet: Out of memory.
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: Failed to execute task.
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: java.util.regex.PatternSyntaxException: U_MEMORY_ALLOCATION_ERROR
01-25 13:52:50.098 7963 8004 E CrashlyticsCore:

01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at java.util.regex.Pattern.compileImpl(Native Method)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at java.util.regex.Pattern.compile(Pattern.java:1344)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at java.util.regex.Pattern.(Pattern.java:1328)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at java.util.regex.Pattern.compile(Pattern.java:950)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at java.lang.String.replaceAll(String.java:2286)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at com.crashlytics.android.core.QueueFileLogStore.doWriteToLog(QueueFileLogStore.java:5)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at com.crashlytics.android.core.QueueFileLogStore.writeToLog(QueueFileLogStore.java:2)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at com.crashlytics.android.core.LogFileManager.writeToLog(LogFileManager.java:1)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at com.crashlytics.android.core.CrashlyticsController$8.call(CrashlyticsController.java:3)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at com.crashlytics.android.core.CrashlyticsController$8.call(CrashlyticsController.java:1)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at com.crashlytics.android.core.CrashlyticsBackgroundWorker$2.call(CrashlyticsBackgroundWorker.java:1)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at io.fabric.sdk.android.m.b.o$a$a.onRun(ExecutorUtils.java:1)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at io.fabric.sdk.android.m.b.h.run(BackgroundPriorityRunnable.java:2)
01-25 13:52:50.098 7963 8004 E CrashlyticsCore: at java.lang.Thread.run(Thread.java:764)
01-25 13:52:50.104 7963 8043 W mpv : [lavf] error reading packet: Out of memory.
01-25 13:52:50.105 7963 8043 W mpv : [lavf] error reading packet: Out of memory.
01-25 13:52:50.105 7963 8004 E CrashlyticsCore: Failed to execute task.

saltyzip · January 25, 2020, 2:04pm

Any other testing you need me to do?

ppotthoff53 · January 28, 2020, 12:39am

I have repeatedly reported this issue. Doesn't matter if you are on WiFi or hardwired ethernet, My Shield 2017 based Channels DVR app skips / freezes so badly it has become unwatchable. I have gone back to using KODI PVR addon to view (I.e. the 'unoffical' one that doesn't record) - https://kodi.wiki/view/Add-on:HDHomeRun_PVR

lseufer · March 11, 2020, 10:16pm

Hi,

Have you managed to fix it? I have the same issue as you on the same hardware but I am in France and not sure if the streams are identical from a tech. POV.

Thanks,

tmm1 · April 28, 2020, 1:59am

Please try the latest android beta from getchannels.com/beta

tmm1 · May 11, 2020, 7:29pm

We've uploaded another beta with more improvements for this device.