DVR stopped for upgrade, never restarted

Channels DVR Server
#1

I came back from vacation to find the DVR was disabled. I logged in via web to find “enable DVR” was unchecked, and a pending update (thought no activity, so not sure what was preventing it. As soon as I checked the box to re-enable, the update kicked off.

Only unusual thing during the week was trying to log in via iOS beta app remotely while I was away. I hadn’t been able to get it to work, but it seemed like others were experiencing difficulties with remote streaming the past week also.

I know there isn’t much to be done about it now, but if there is some interaction with the remote streaming affecting DVR I thought I’d post. As many have said, the DVR and app are great, and most importantly pass the wife test, but losing a week of recording loses some credibility with her.

Log attached.
2017/10/02 09:08:23 [IDX] Pruned 2260 expired airings from USA-CA04437-X in 2.919896828s.
2017/10/02 13:52:16 [SYS] Shutting down for upgrade from v2017.09.30.0722 to v2017.10.02.0617
2017/10/02 13:52:16 [DVR] Recording engine stopped.
2017/10/04 10:41:23 http: TLS handshake error from 93.174.95.106:49229: tls: client offered an unsupported, maximum protocol version of 300
2017/10/04 10:41:36 http: TLS handshake error from 93.174.95.106:54119: tls: no cipher suite supported by both client and server
2017/10/04 10:41:38 http: TLS handshake error from 93.174.95.106:54707: tls: no cipher suite supported by both client and server
2017/10/04 10:41:43 http: TLS handshake error from 93.174.95.106:55932: remote error: tls: unknown certificate authority
2017/10/07 22:47:46 http: TLS handshake error from 10.0.0.1:62486: EOF
2017/10/07 22:47:55 http: TLS handshake error from 10.0.0.1:62491: EOF
2017/10/07 22:47:55 http: TLS handshake error from 10.0.0.1:62492: EOF
2017/10/07 22:47:55 http: TLS handshake error from 10.0.0.1:62493: EOF
2017/10/07 22:47:55 http: TLS handshake error from 10.0.0.1:62494: EOF
2017/10/07 22:47:55 http: TLS handshake error from 10.0.0.1:62496: EOF
2017/10/07 22:47:55 http: TLS handshake error from 10.0.0.1:62498: EOF
2017/10/07 22:47:55 http: TLS handshake error from 10.0.0.1:62499: EOF
2017/10/07 22:51:41 [SYS] Bonjour service stopped.
2017/10/07 22:51:43 [SYS] Starting Channels DVR v2017.10.02.0617 (darwin-x86_64) in /Users/dkrach/channels-dvr/data
2017/10/07 22:51:44 [HDR] Found 2 devices
2017/10/07 22:51:45 [SYS] Started HTTP Server
2017/10/07 22:52:05 [DVR] Recording engine started in /Volumes/ThunderBay/Channels DVR
2017/10/07 22:52:05 [SYS] Removing old update 2017.09.01.0513

Waiting for update
#2

Hmm that’s a weird one. What version of macOS?

#3

10.13 (High Sierra)

#4

We haven’t done a lot of testing with 10.13 yet so that could be why.

In the macOS menu bar at the top of the screen, can you find the TV icon for the DVR and select Restart. Does the icon go away and then come back (and Log shows a restart)?

#5

Just tested, and yes the restart worked ok. Took about 15 seconds before it came back up.

#6

Okay. How about if you hold down SHIFT and click on the “check for updates” button on the web UI. Does it update and restart correctly?

#7

Yeah, just tried and that worked also. Maybe the computer got hung up doing something on that 9.30 to 10.02 update.

#8

I just released a new version (v2017.10.10.0006). Would be curious if your DVR updates itself automatically this time (without clicking on “check for updates”).

#9

Nothing yet, but I’ll keep an eye on it.

#10

Update to 10.11 finally went through on it’s own after about 48 hours. No issues with the DVR re-enabling after the update this time.

For some reason even after 24 hrs it didn’t try to self update to 10.10 (was at 10.08). Doesn’t the DVR software auto check once a day?

#11

Hmm, that’s weird. The DVR checks every 2 hours for an update.

There was a 10.12 release, I wonder if it will pick that up soon.

#12

Yep, just checked and it also picked up the 10.12 update about an hour ago.

Interesting in the Log it just purged the 10.08 update, does it hold onto a couple previous updates?

2017/10/12 09:55:05 [IDX] Pruned 1390 expired airings from USA-CA04437-X in 1.811324335s.
2017/10/12 13:23:14 [SYS] Downloading new version v2017.10.12.1708
2017/10/12 13:23:26 [SYS] Update downloaded and verified successfully.
2017/10/12 13:23:26 [SYS] Shutting down for upgrade from v2017.10.11.2339 to v2017.10.12.1708
2017/10/12 13:23:26 [SYS] Bonjour service stopped.
2017/10/12 13:23:26 [DVR] Recording engine stopped.
2017/10/12 13:23:28 [SYS] Starting Channels DVR v2017.10.12.1708 (darwin-x86_64) in /Users/dkrach/channels-dvr/data
2017/10/12 13:23:29 [HDR] Found 2 devices
2017/10/12 13:23:30 [TLS] Requesting certificate for xxxxx.channelsdvr.net
2017/10/12 13:23:30 [SYS] Started HTTP Server
2017/10/12 13:23:44 [DVR] Recording engine started in /Volumes/ThunderBay/Channels DVR

and 10.10 update logs you can see it didn’t pick up until yesterday afternoon, when you released it 3 days ago…

2017/10/11 15:47:49 [SYS] Downloading new version v2017.10.10.0006
2017/10/11 15:47:59 [SYS] Update downloaded and verified successfully.
2017/10/11 15:47:59 [SYS] Shutting down for upgrade from v2017.10.08.1850 to v2017.10.10.0006
2017/10/11 15:47:59 [SYS] Bonjour service stopped.
2017/10/11 15:47:59 [DVR] Recording engine stopped.
2017/10/11 15:48:00 [SYS] Starting Channels DVR v2017.10.10.0006 (darwin-x86_64) in /Users/dkrach/channels-dvr/data
2017/10/11 15:48:01 [HDR] Found 2 devices
2017/10/11 15:48:02 [SYS] Started HTTP Server
2017/10/11 15:48:17 [DVR] Recording engine started in /Volumes/ThunderBay/Channels DVR
2017/10/11 15:48:17 [SYS] Removing old update 2017.10.02.0617

#13

OH, I had forgotten to release 10.10.

It was actually released yesterday when I noticed…

#14

Hmm, looks like this problem popped up again. Today’s update check shut down the DVR, but never updated or restarted. Anything you want me to check before I force it to update / restart the DVR?

2017/10/17 09:34:01 [IDX] Pruned 2377 expired airings from USA-CA04437-X in 2.653625718s.
2017/10/17 11:06:34 [SYS] Downloading new version v2017.10.17.1728
2017/10/17 11:06:43 [SYS] Update downloaded and verified successfully.
2017/10/17 11:06:43 [SYS] Shutting down for upgrade from v2017.10.14.2323 to v2017.10.17.1728
2017/10/17 11:06:43 [DVR] Recording engine stopped.
2017/10/17 14:32:58 http: TLS handshake error from 17.115.16.121:50079: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50083: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50084: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50085: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50086: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50087: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50088: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50092: EOF
2017/10/17 14:48:17 [TNR] Opened connection to 1045823A for ch7.1
2017/10/17 15:07:32 [TNR] Closed connection to 1045823A for ch7.1

#15

Yes please save the output of http://127.0.0.1:8089/debug/stack and email it to [email protected]

#16

Just sent to support. Interesting thing to note, when I first observed this I was connected remotely in Safari from work via my home IP:port. When you asked for the output, I remote desktop’d to my server and loaded the config page in my browser and it immediately kicked off starting the server. I seem to recall the same thing happening the first time this occurred.

#17

Ah, so when you grabbed that output it wasn’t stuck anymore. That explains why I don’t see anything useful in there.

Good observation though. I think I have an idea of what’s going on.

#18

Yeah, I clicked on my bookmark to the server out of habit before pasting the debug link, and I saw it starting up.

#19

No worries.

Right before it restarted, I assume the log said “Bonjour service stopped.” ?

#20

It’s a few lines down before it says that…

2017/10/17 09:34:01 [IDX] Pruned 2377 expired airings from USA-CA04437-X in 2.653625718s.
2017/10/17 11:06:34 [SYS] Downloading new version v2017.10.17.1728
2017/10/17 11:06:43 [SYS] Update downloaded and verified successfully.
2017/10/17 11:06:43 [SYS] Shutting down for upgrade from v2017.10.14.2323 to v2017.10.17.1728
2017/10/17 11:06:43 [DVR] Recording engine stopped.
2017/10/17 14:32:58 http: TLS handshake error from 17.115.16.121:50079: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50083: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50084: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50085: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50086: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50087: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50088: EOF
2017/10/17 14:32:59 http: TLS handshake error from 17.115.16.121:50092: EOF
2017/10/17 14:48:17 [TNR] Opened connection to 1045823A for ch7.1
2017/10/17 15:07:32 [TNR] Closed connection to 1045823A for ch7.1
2017/10/17 17:16:19 [SYS] Starting Channels DVR v2017.10.17.1728 (darwin-x86_64) in /Users/dkrach/channels-dvr/data
2017/10/17 17:16:20 [HDR] Found 2 devices
2017/10/17 17:16:21 [SYS] Started HTTP Server
2017/10/17 17:16:38 [DVR] Recording engine started in /Volumes/ThunderBay/Channels DVR
2017/10/17 17:16:38 [SYS] Removing old update 2017.10.13.0017
2017/10/17 17:16:38 [DVR] Waiting 43m21.061693s until next job 1508288400-25 Shark Tank
2017/10/17 17:16:39 [SYS] Created database snapshot: backup-20171017.171639
2017/10/17 17:16:39 [SYS] Removing old backup backup-20170923.033729
2017/10/17 17:16:40 [SYS] Bonjour service registered with xxx.xxxxxx.com
2017/10/17 17:16:49 [IDX] Pruned 118 expired airings from USA-OTA95123 in 192.070599ms.
2017/10/17 17:16:50 [IDX] Pruned 772 expired airings from USA-CA04437-X in 898.692519ms.
2017/10/17 17:45:29 http: TLS handshake error from xxx.xxx.xxx.xxx:62681: tls: client using inappropriate protocol fallback
2017/10/17 17:54:18 [TNR] Opened connection to 1323A5C3 for ch793
2017/10/17 17:54:33 [TNR] Closed connection to 1323A5C3 for ch793
2017/10/17 17:54:48 [TNR] Opened connection to 1045823A for ch4.1