Recording stalls with buffer full, then nVidia Shield shuts down later

This is a recurrent reliability pattern that's been dogging me since early March. Current versions:

  • nVidia Shield Pro: kernel: 4.9.141-tegra-gfef2938fbb45-dirty
  • Channels DVR server: 2022.03.23.0209.
    The server is using an external HDD for the recordings. When the issue hits, this is seen in the logs:
2022/04/11 06:00:00.033047 [DVR] Starting job 1649674800-5 ABC7 Eyewitness News at 6am on ch=[7.1]
2022/04/11 06:00:00.033815 [DVR] Waiting 59m59.966224168s until next job 1649678400-1 Good Morning America
2022/04/11 06:00:00.372866 [TNR] Opened connection to 1090A053/0 for ch7.1 WLS-HD
2022/04/11 06:00:00.738038 [DVR] Recording for job 1649674800-5 from 1090A053 ch7.1 into "TV/ABC7 Eyewitness News at 6am/ABC7 Eyewitness News at 6am 2022-04-11-0600.mpg" for 59m59.966305627s
2022/04/11 06:00:00.806798 [IDX] Generating video index for job 1649674800-5
2022/04/11 06:05:50.905604 [NAT] Successfully mapped port 8089 using upnp
2022/04/11 06:36:59.768638 [WRN] Buffer for 1090A053 ch7.1 is more than 50% full (clients=1, len=33555836)
2022/04/11 06:37:19.141350 [WRN] Buffer for 1090A053 ch7.1 is more than 75% full (clients=1, len=50332852)
2022/04/11 06:37:37.307391 [WRN] Buffer for 1090A053 ch7.1 is more than 95% full (clients=1, len=63754772)
2022/04/11 06:37:40.006205 [WRN] Buffer for 1090A053 ch7.1 is more than 99% full (clients=1, len=66438252)
2022/04/11 07:00:00.003453 [TNR] Closed connection to 1090A053/0 for ch7.1 WLS-HD
2022/04/11 07:00:00.018643 [DVR] Deleting failed job 1649246400-1 Good Morning America
2022/04/11 07:00:00.034898 [DVR] Starting job 1649678400-1 Good Morning America on ch=[7.1]
2022/04/11 07:00:00.035248 [DVR] Waiting 2h59m59.964764604s until next job 1649689200-13 The View
2022/04/11 07:00:00.369183 [TNR] Opened connection to 1090A053/0 for ch7.1 WLS-HD
2022/04/11 07:00:36.981036 [WRN] Buffer for 1090A053 ch7.1 is more than 50% full (clients=1, len=33559896)
2022/04/11 07:00:55.622462 [WRN] Buffer for 1090A053 ch7.1 is more than 75% full (clients=1, len=50332376)
2022/04/11 07:01:10.553254 [WRN] Buffer for 1090A053 ch7.1 is more than 95% full (clients=1, len=63754156)
2022/04/11 07:01:13.609103 [WRN] Buffer for 1090A053 ch7.1 is more than 99% full (clients=1, len=66439084)
2022/04/11 07:05:50.911859 [NAT] Successfully mapped port 8089 using upnp
2022/04/11 08:05:50.914957 [NAT] Successfully mapped port 8089 using upnp
2022/04/11 08:47:26.706919 [DVR] Pruning old recording ABC7 Eyewitness News at 6am 2022-04-10-0600.mpg
2022/04/11 09:03:00.031888 [TNR] Closed connection to 1090A053/0 for ch7.1 WLS-HD
2022/04/11 09:05:50.921446 [NAT] Successfully mapped port 8089 using upnp
2022/04/11 09:25:00.189246 [DVR] Fetching guide data for 84 stations in USA-OTA60103 @ 2022-04-11 9:00AM
2022/04/11 09:25:02.543530 [DVR]   indexed 632 airings (84 channels) [0s fetch, 1s index]
2022/04/11 09:25:02.990064 [DVR]   indexed 28 movies (13 channels) [0s fetch, 0s index]
2022/04/11 09:25:03.047064 [DVR]   pruned 68 replaced airings in 0s.
  <lots more guide fetching log>

The last traces before Shield apparently shuts down on its own (or crashes):

2022/04/11 09:28:01.242286 [DVR] Waiting 31m58.757725231s until next job 1649689200-13 The View
2022/04/11 10:00:00.065952 [DVR] Deleting failed job 1649257200-13 The View
2022/04/11 10:00:00.071305 [DVR] Deleting failed job 1649257200-15 Today With Hoda & Jenna
2022/04/11 10:05:50.977691 [NAT] Successfully mapped port 8089 using upnp
2022/04/11 11:05:50.981863 [NAT] Successfully mapped port 8089 using upnp
2022/04/11 12:05:50.989205 [NAT] Successfully mapped port 8089 using upnp
2022/04/11 13:05:50.992090 [NAT] Successfully mapped port 8089 using upnp
2022/04/11 14:05:50.997827 [NAT] Successfully mapped port 8089 using upnp
2022/04/11 15:05:51.001008 [NAT] Successfully mapped port 8089 using upnp
2022/04/11 16:05:51.005128 [NAT] Successfully mapped port 8089 using upnp
2022/04/11 17:05:51.007520 [NAT] Successfully mapped port 8089 using upnp
2022/04/11 18:05:51.020510 [NAT] Successfully mapped port 8089 using upnp
2022/04/11 19:05:51.022925 [NAT] Successfully mapped port 8089 using upnp

Meanwhile, it has missed some other recordings, which becomes apparent from the later log.

After this point, usually it doesn't respond to the remote control and has to be restarted via power cycle. When it comes up:

2022/04/11 20:05:03.077354 [SYS] Starting Channels DVR v2022.03.23.0209 (android-arm64 pid:8376) in /data/user/0/com.getchannels.dvr/files/channels-dvr/data
2022/04/11 20:05:03.131805 [SYS] Started HTTP Server
2022/04/11 20:05:03.586723 [HDR] Found 1 devices
2022/04/11 20:05:04.775867 [DVR] Recording engine started in /storage/F8AE-7599/NVIDIA_SHIELD
2022/04/11 20:05:04.858605 [DVR] Deleting failed job 1649284200-4 ABC World News Tonight With David Muir
2022/04/11 20:05:04.878039 [SYS] Bonjour service running for dvr-shield.local. [192.168.1.7]

Based on other posts, I thought the HDD might be acting up. (WD Element 1 TB). Tested it on a PC and looked fine. Eventually replaced it with a Toshiba HDD taken out from my laptop, connected via an adapter/housing and a different cable. Same recording choking/crash problem continued. :frowning: :frowning: Now what? While the server is running, load metrics appear fine. (But I haven't had a chance to observe it while buffer is full.) Haven't seen anything else suspicious in the logs or a useful clue. How to find out why Shield shuts down? Would Channels DVR ever shut itself or the host down?

Thanks.

Sounds like shield 9.0.1 issues