Channels DVR stops responding randomly on macOS

Channels DVR Server Troubleshooting
#83

Uh, sorry, this is long and rambly, but: With Little Snitch uninstalled, unaccepted connections count continuously remained 0 for port 8089, over the course of the initial 48 hours since my last post -- I checked once every 60 seconds.

At about half way through those 48 hours, I turned on Remote DVR port forwarding, and it also had no affect on unaccepted connection counts over the next 24 hours. They remained 0.

Last night, (about 18 hours ago) I reinstalled little snitch. Unaccepted connections climbed to 5 after a six hours. Then, 12 hours ago, I upgraded channels DVR to the then latest prerelease 2022.08.29.0732, which reset the count to 0. In the last 12 hours it's climbed to 3, although two minutes ago, it jumped from 3 to 5.

And it didn't just affect channels -- several services (homebridge, jellyfin, and an rtsp relay) also have unaccepted connections tick up since little snitch was reinstalled. They had remained 0 while little snitch was uninstalled.

Looking at the time of the last jump, between 2:59p and 3:00p,.

Mon Aug 29 14:59:11 PDT 2022
0/0/8192 127.0.0.1.58089
3/3/8192 *.8089

Mon Aug 29 15:00:11 PDT 2022
0/0/8192 127.0.0.1.58089
5/5/8192 *.8089

Between those times, this was the channels http log:

2022/08/29 14:59:12.097247 [HTTP] | 200 |      99.639ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:14.190506 [HTTP] | 200 |   85.168333ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:16.272905 [HTTP] | 200 |   67.091625ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:18.355584 [HTTP] | 200 |   64.539416ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:20.419733 [HTTP] | 200 |   56.198458ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:22.490728 [HTTP] | 200 |   60.866416ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:24.556013 [HTTP] | 200 |   50.933875ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:26.664447 [HTTP] | 200 |   93.738458ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:28.765248 [HTTP] | 200 |   78.621041ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:30.871245 [HTTP] | 200 |   83.696458ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:32.988058 [HTTP] | 200 |   99.479167ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:35.049449 [HTTP] | 200 |   47.629375ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:37.110325 [HTTP] | 200 |     50.7985ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:39.169727 [HTTP] | 200 |     49.5875ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:41.296000 [HTTP] | 200 |  111.188834ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:43.358467 [HTTP] | 200 |   45.947042ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:45.426466 [HTTP] | 200 |   46.895542ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:47.561894 [HTTP] | 200 |  116.545625ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:49.528301 [HTTP] | 200 |     127.917µs |   167.94.138.62 | GET      "/"
2022/08/29 14:59:49.625967 [HTTP] | 200 |   34.993083ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:49.638067 [HTTP] | 200 |      81.709µs |   167.94.138.62 | GET      "/"
2022/08/29 14:59:49.747911 [HTTP] | 200 |      97.083µs |   167.94.138.62 | PRI      "*"
2022/08/29 14:59:49.860210 [HTTP] | 200 |      110.75µs |   167.94.138.62 | GET      "/favicon.ico"
2022/08/29 14:59:51.692148 [HTTP] | 200 |   47.193417ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:53.757780 [HTTP] | 200 |   46.180542ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:55.824103 [HTTP] | 200 |   57.614541ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:57.898898 [HTTP] | 200 |   66.926041ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 14:59:59.983117 [HTTP] | 200 |   68.110667ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 15:00:02.042379 [HTTP] | 200 |   56.017167ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 15:00:04.082324 [HTTP] | 200 |   31.664459ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 15:00:06.159674 [HTTP] | 200 |   69.937125ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 15:00:08.225525 [HTTP] | 200 |   52.189833ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"
2022/08/29 15:00:08.433785 [HTTP] | 200 |  4.885585083s |      10.0.0.123 | GET      "/tmsimg/assets/p10158345_b_h9_aa.jpg?w=360"
2022/08/29 15:00:10.323723 [HTTP] | 200 |     81.0325ms |      10.0.0.123 | GET      "/devices/10A22AE4/status/2-1/debug"

Coincidentally, the 167.94.* ip address is Censys again remotely probing channels.

More interestingly, the prior jump happened with no corresponding http traffic logged

Mon Aug 29 07:02:38 PDT 2022
0/0/8192 127.0.0.1.58089
2/2/8192 *.8089

Mon Aug 29 07:03:38 PDT 2022
0/0/8192 127.0.0.1.58089
3/3/8192 *.8089

2022/08/29 04:20:23.066568 [HTTP] | 200 |    1.531584ms |  185.220.101.58 | GET      "/"
2022/08/29 04:20:24.611134 [HTTP] | 200 |     378.208µs | 185.220.101.161 | GET      "/favicon.ico"
2022/08/29 13:08:13.300542 [HTTP] | 200 |  205.201167ms |       10.0.0.11 | GET      "/dvr/files"
2022/08/29 13:08:13.521647 [HTTP] | 200 |  150.601958ms |       10.0.0.11 | DELETE   "/dvr/files/15103"

However, I did also capture a tcpdump of port 8089 over the last 12 hours,nas well. I see this in that time period:

07:02:47.861463 IP ns3181291.ip-151-106-40.eu.57898 > macmini.8089: Flags [S], seq 4279450726, win 1024, length 0
E..(_).....o.j(.
....*....<f....P....m........
07:02:48.034109 IP ns3181291.ip-151-106-40.eu.57898 > macmini.8089: Flags [R], seq 4279450727, win 0, length 0
E..(%n@.j.!+.j(.
....*....<g..<gP...l.........
07:02:48.036569 IP ns3181291.ip-151-106-40.eu.57898 > macmini.8089: Flags [R], seq 4279450727, win 1200, length 0
E..(_(.....p.j(.
....*....<g....P.............

So it's some kind of non-http TCP traffic -- I haven't yet tried to understand it.

And the prior jump, also not in the http logs:

Mon Aug 29 04:56:29 PDT 2022
0/0/8192 127.0.0.1.58089
1/1/8192 *.8089

Mon Aug 29 04:57:29 PDT 2022
0/0/8192 127.0.0.1.58089
2/2/8192 *.8089

but in tcpdump I see:

04:56:59.567501 IP 89.248.171.133.54116 > 10.0.0.11.8089: Flags [S], seq 587785294, win 65535, length 0
E..(.1......Y...
....d..#..N....P.............
04:56:59.705773 IP 89.248.171.133.54116 > 10.0.0.11.8089: Flags [R], seq 587785295, win 0, length 0
E..(..@...=HY...
....d..#..O....P.............

Some more non-http traffic. There's no other surrounding traffic for quite a while, so for whatever reason, those packets cause the unaccepted count to tick up, but, seemingly, only while little snitch is installed.

I think I may turn off Remote DVR again, and figure out what local packets, if any, cause the count to tick up.

Also, I'm still not sure I understand what the listen queue behavior should be. Does the fact that the unaccepted connection count, and unaccepted incomplete connection count rise in tandem mean simply that incomplete connections tally to both totals -- is the first inclusive of the second, and that there simply weren't unaccepted connections for reasons other than incompleteness? And are those counts meant to reset after a period of time, or do they persist the duration of the socket listening? I mean, clearly they do persist in our case, but are they supposed to? Are the incomplete connections just waiting to be completed, and thus consuming "slots" in the max listening connections queue? Is Apple's Network Extension API just dropping certain (rejected/malformed?) TCP SYN packets, leaving the connection in an incomplete state, and for some reason, things aren't timing out properly?

I also want to check if I can install another Network Extension API using app, instead of Little Snitch and see if the problem persists.

1 Like
#84

I don't think these are supposed to persist. Best I can tell this is some kind of macOS kernel bug related to the network extension API.

Because as far as the userland is concerned, there is no way to clear the queue. Only the kernel has control over it, and the only syscall it offers to interact with the listener socket is accept().

Since the SYN flood via hping3 does clear out on its own, I think that further indicates that something is being leaked inadvertently.

I reached out to the Little Snitch folks last week but have not heard back. I wonder if they have any insights here, or can clarify how they're blocking connections. Clearly its happening in a way that's causing these slots to leak instead of being cleared out.

Great next step. I suspect the behavior will be the same if @thully's VPN extension is any indication.

1 Like
#85

After uninstalling the Cisco VPN software, the unaccepted connections remained at 0 for a while. Given that, I re-enabled Remote Access, and connections remained 0 about a day or so later. I am now away from home so I can’t easily check the count since I didn’t set up remote SSH. Can’t reach the server right now, though I think that may be due to a power outage…

1 Like
#86

Okay, maybe it's not all Network Extensions apps. It seems more subtle than I thought.

Just before midnight last night, I uninstalled Little Snitch, and installed Lulu, an open source alternative that also seems to use network extensions (packet tunnel provider, app proxy provider, content-filter provider, and dns proxy) also used by Little Snitch. I set it to approve all traffic, as I had with Little Snitch. I expected the same results.

It's been 13+ hours and unaccepted connection count is still zero, system wide, despite more Censys probes and other similar remote traffic that previously triggered unaccepted connection count increases under LS.

I'll wait until later tonight, to give it a full day, uninstall Lulu and reinstall Little Snitch, but be sure to clear all of its rules and configs this time, to see if they're confounding things. In a subsequent test, I may install Cisco AnyConnect (if I can find an installer) to see if I can replicate @thully's experience.

I'll open a ticket with Little Snitch to see if they can help trouble shoot.

Maybe it could be helpful if any readers of this thread (assuming we're all mac users) that have also experienced dvr unresponsive events could run:

systemextensionsctl list

and report their results? It would be great to know what other apps may also inadvertently trigger the hangs.

1 Like
#87

Just got back home. It seems my server being down was due to the power outage - my system restarted when power was restored as I set it to, but Channels DVR didn’t start until I logged in. Is there any way to make that happen on boot in the future?

Now that the server is back up, I’ll keep an eye on the unaccepted connections and keep you posted as to whether this increases from 0 and/or the server becomes unresponsive again. I am currently running without the Cisco VPN client installed, but Renate Access enabled.

#88

It seems like you may have installed Channels as a user service instead of a system service.

I think you can run these commands to fix it:

~/Library/Application\ Support/ChannelsDVR/uninstall.sh
~/Library/Application\ Support/ChannelsDVR/install.sh --system

@tmm1 says below that running those doesn't affect your recordings or data:

Looking at both scripts, they only involve the removal or creation of Channel's launchd script. The --system argument ensures that Channel's launchd plist is installed in /Library/LaunchDaemons which runs channels after boot and before first login. (As opposed to in ~/Library/LaunchAgents, which only runs after your user login.)

(Alternatively, I've very infrequently experienced Channel's not fully starting itself on reboot, for some reason. The channels-dvr process is still running, but the menu bar icon never appears and http service doesn't respond. It's possible it was busy doing some longer-than-normal setup step and I was too impatient.)

As far as the hanging problem, the core issue isn't inside Channels, it's in the interaction between macOS and certain VPN/firewall apps, but affects all long-lived services running on the Mac, including channels. I've replicated it on a second machine just by installing Little Snitch, so hopefully Little Snitch will figure out a workaround and/or get Apple to fix it. (A LittleSnitch workaround won't help you, so hopefully Apple fixes the root cause.)

Ultimately, it's probably an Apple problem to fix, but Channel's could employ a workaround, either by checking unaccepted connection counts periodically to see if they exceed some threshold, or testing if it's http service is working, and restarting it if necessary, or maybe setting somaxconn before http service launch. Probably whether they do any of those depends on how many of us are affected or complaining or how long it seems it will be until Apple (or possibly developers of apps that use Apple's Network Extension Framework) ultimately fix the underlying problems.

In the mean time, if you want to continue using AnyConnect VPN without Channels hanging, you might want to run:

sudo sysctl kern.ipc.somaxconn=8192

...and then restart channels -- that increases the time before hang by 64 times, so if it used to hang once a week for you, then it'll postpone the hang by a year. (Which basically solves the problem, because Channel's updates itself much more frequently, and every update resets that count back to zero.) Unfortunately, somaxconn value will reset itself to 128 every time you reboot, so you'll need to run it again every time you reboot, unless you automate it somehow.

(I tried adding "kern.ipc.somaxconn=8192" to /private/etc/sysctl.conf, but that config file seems to be ignored by macOS now-a-days. I could add it to a new launchd plist, but I'm not sure how to guarantee it runs before channels. I could also add it to the channels launchd plist, but in the end, the somaxconn workaround just feels kinda too hacky to make permanent.)

Instead of doing all that, I just removed Little Snitch. I'll wait to see what comes up from Objective Development's (Little Snitch) efforts.

1 Like
#89

Following the instructions doesn't seem to resolve the issue - it does seem to install as a system service, but still doesn't fully respond prior to log in. I can sometimes get the admin page to start loading right after reboot, but it won't finish loading (nor will clients connect) until after I log in. One thing I notice is that once I do log in, Setup Guide Data prompts me to enter a zip code to load guide data, though my previous sources are already listed and configured properly.

As for the Cisco client - I really only installed it for my work VPN, which I only needed because my work computer stopped working a few months ago. That's also about when I remember the issue with Channels starting. Since the work PC issue has since been resolved, I can leave it uninstalled for the time being and hopefully won't have any more issues with the server becoming unresponsive. I do hope I can get the issue with reboot fixed, though, so a power outage while I'm out of town doesn't stop Channels from working once I regain power...

#90

I think you're right. I just tested, and Channels (at least on a mac) does repeatedly crash on start up, in a loop, when run before login session is created. It looks like it dies trying to create a new menu bar icon! I emailed support and submitted diagnostics f11c99ec-1f14-4d50-8112-63a9c86fdfa0

#91

Part of this is probably due to OS security. If you have FileVault enabled, your system's home directories will not be fully decrypted until you login. This isn't really a limitation of Channels, but rather how you chose to install it and system security measures.

Unfortunately, this is starting to show the dichotomy between server systems, and secure home systems. The line was always blurred, but as certain vendors try to be more proactively secure, it will entail more active user involvement.

1 Like
#92

The crash issue before login has been fixed.

1 Like
#93

Can confirm the latest DVR pre-release fixes the issue.

2 Likes
#94

So everything all good without network extensions installed?

@justinmk3 are you running any extensions?

#95

Yes - uptime at 9 days since my last restart now that Cisco AnyConnect has been uninstalled.

#96

@sejmann Apple requested a sysdiagnose from me. If you feel like it maybe you can submit one on feedbackassistant.apple.com and reference FB11405981

Any repro steps you can share, or any sysdiagnose you collected that captured the issue?

Please turn on NetworkExtension debug log

log config --subsystem "com.apple.networkextension" --mode level:debug,persist:debug
log config --subsystem "com.apple.networkextension" --reset <set back to default after repro>

sysctl -w net.cfil.log=6
sysctl -w net.cfil.log_port=8089

Collect sysdiagnose
1 Like
#97

@tmm1, I've submitted feedback FB11519876 with sysdiagnose after logging stuck connections, and referenced your FB.

I've also worked with Christian at obdev.at, as I think have you. After some low level logging in Little Snitch, he confirmed the problem is on Apple's side, and also has found his own server has been affected, too. Interestingly, you and Christian both passed on the same request from Apple. So, hopefully Ventura will have a fix of some kind!

#98

Has this issue been resolved in Ventura? I still have Monterey installed and don't see any benefits to upgrading other than having this issue resolved. It still persists on the latest version of Monterey and I also have Little Snitch.

Every few days, I use the Channels app to stop and restart the DVR. If there isn't a fix, is there a way to automate restarting the server every fews hours when not in use?

1 Like
#99

Did you try this?

#100

If Little Snitch still causes issues, is there a way to prevent Channels DVR from auto-updating? (I apologize if my understanding of how things work is wrong. My novice-level understanding is that the problems arise when the DVR auto updates. I think I read that the pre-release version generally doesn't auto-update, but will auto-update if the release version catches up to it?). If a setting exited to make updates manual-only, maybe that would be a work around of sorts for the Little Snitch issue, so we could make sure we also reset Little Snitch at the same time we update?

#101

I
Does this work for Little Snitch, I don't user AnyConnect VPN? I will give it a try. I'm just an average user. I tried following this thread for a solution and got lost.

So, the problem still exists in latest version Mac OS Ventura?

#102

How are you resetting Little Snitch?

1 Like