BETA: Channels DVR Server for Raspberry Pi 4 (USB BOOT IMAGE)

ah - is there a similar dvr upgrade script? may be that build (2020.11.04.1957)

I think its working correctly, you just have to wait a minute until the light on the RPI is solid green and then refresh the browser. The newer DVR build shows a nicer loading message during that time, instead of the confusing settings page with everything unchecked/missing.

If you do want to upgrade the DVR software over SSH:

cd /mnt/data
systemctl stop channels-dvr
curl -s https://getchannels.com/dvr/setup.sh | sudo -u channels env DOWNLOAD_ONLY=1 sh
systemctl start channels-dvr

i think the issue may be the ntp sync itself. Like you said, the new GUI gives you a wait while it finishes, but it doesn't finish. That's why the former build came up with tons of stuff missing - seems to make sense.

Anything to troubleshoot the ntp sync? would think this would be quick, but it's been hanging on that log entry essentially since your last post...

What's systemctl status and systemctl list-jobs show?

Also systemctl status systemd-timesyncd and systemctl status systemd-time-wait-sync

systemctl status
● dvr-server
State: starting
Jobs: 7 queued
Failed: 0 units
Since: Wed 1969-12-31 19:00:02 EST; 50 years 10 months ago
CGroup: /
├─init.scope
│ └─1 /sbin/init
└─system.slice
├─rngd.service
│ └─312 /usr/sbin/rngd -f
├─systemd-udevd.service
│ └─133 /usr/lib/systemd/systemd-udevd
├─system-usb\x2dmount.slice
│ └─[email protected]
│ └─365 /sbin/mount.exfat /dev/sda9 /media/DVR -o rw,relatime
├─rauc.service
│ └─309 /usr/bin/rauc --mount=/run/rauc service
├─wpa_supplicant.service
│ └─318 /usr/sbin/wpa_supplicant -u
├─systemd-journald.service
│ └─118 /usr/lib/systemd/systemd-journald
├─winbind.service
│ ├─490 /usr/sbin/winbindd --foreground --no-process-group
│ └─512 /usr/sbin/winbindd --foreground --no-process-group
├─NetworkManager.service
│ └─305 /usr/sbin/NetworkManager --no-daemon
├─channels-dvr.service
│ └─3841 /mnt/data/channels-dvr/latest/channels-dvr -dir /mnt/data/channels-dvr/data/
├─wsdd2.service
│ └─319 /usr/sbin/wsdd2 -w -b vendor:Channels,model:DVR server,vendorurl:getchannels.com,modelurl:getchannels.com/dvr-server
├─systemd-resolved.service
│ └─297 /usr/lib/systemd/systemd-resolved
├─dbus.service
│ └─304 /usr/bin/dbus-daemon --system --address=systemd: --nofork --nopidfile --systemd-activation --syslog-only
├─systemd-timesyncd.service
│ └─298 /usr/lib/systemd/systemd-timesyncd
├─system-getty.slice
│ └─[email protected]
│ └─381 /sbin/agetty -o -p -- \u --noclear tty1 linux
├─dropbear.service
│ ├─ 374 /usr/sbin/dropbear -F -R -E -p 22222 -s
│ ├─2313 /usr/sbin/dropbear -F -R -E -p 22222 -s
│ ├─2336 -bash
│ ├─6023 systemctl status
│ └─6024 less
├─systemd-logind.service
│ └─354 /usr/lib/systemd/systemd-logind
└─systemd-time-wait-sync.service
└─121 /usr/lib/systemd/systemd-time-wait-sync

systemctl list-jobs

JOB UNIT TYPE STATE
83 e2scrub_all.timer start waiting
21 time-sync.target start waiting
82 timers.target start waiting
106 led-ready.service start waiting
122 systemd-update-utmp-runlevel.service start waiting
1 multi-user.target start waiting
70 systemd-time-wait-sync.service start running

7 jobs listed.

systemctl status systemd-timesyncd

● systemd-timesyncd.service - Network Time Synchronization
Loaded: loaded (/usr/lib/systemd/system/systemd-timesyncd.service; enabled; vendor preset: enabled)
Drop-In: /etc/systemd/system/systemd-timesyncd.service.d
└─hassos.conf, ro.conf
Active: active (running) since Wed 2020-11-04 18:22:37 EST; 24min ago
Docs: man:systemd-timesyncd.service(8)
Main PID: 298 (systemd-timesyn)
Status: "Idle."
Tasks: 4 (limit: 4425)
Memory: 2.8M
CGroup: /system.slice/systemd-timesyncd.service
└─298 /usr/lib/systemd/systemd-timesyncd

Sep 20 06:44:02 dvr-server systemd[1]: Starting Network Time Synchronization...
Sep 20 06:44:02 dvr-server systemd-timesyncd[298]: System clock time unset or jumped backwards, restoring from recorded timestamp: Wed 2020-11-04 23:22:37 UTC
Nov 04 18:22:37 dvr-server systemd[1]: Started Network Time Synchronization.
Nov 04 18:22:37 dvr-server systemd-timesyncd[298]: Network configuration changed, trying to establish connection.
Nov 04 18:22:37 dvr-server systemd-timesyncd[298]: Network configuration changed, trying to establish connection.

systemctl status systemd-time-wait-sync

● systemd-time-wait-sync.service - Wait Until Kernel Time Synchronized
Loaded: loaded (/usr/lib/systemd/system/systemd-time-wait-sync.service; enabled; vendor preset: enabled)
Active: activating (start) since Sun 2020-09-20 06:43:58 EDT; 1 months 15 days ago
Docs: man:systemd-time-wait-sync.service(8)
Main PID: 121 (systemd-time-wa)
Tasks: 1 (limit: 4425)
Memory: 536.0K
CGroup: /system.slice/systemd-time-wait-sync.service
└─121 /usr/lib/systemd/systemd-time-wait-sync

Sep 20 06:43:58 dvr-server systemd-time-wait-sync[121]: Failed to add a watch for /run/systemd/timesync: No such file or directory
Sep 20 06:43:58 dvr-server systemd-time-wait-sync[121]: adjtime state 5 status 40 time Sun 2020-09-20 10:43:58.352258 UTC
Sep 20 06:43:58 dvr-server systemd-time-wait-sync[121]: Failed to add a watch for /run/systemd/timesync: No such file or directory
Sep 20 06:44:02 dvr-server systemd-time-wait-sync[121]: Failed to add a watch for /run/systemd/timesync: No such file or directory
Sep 20 06:44:02 dvr-server systemd-time-wait-sync[121]: Failed to add a watch for /run/systemd/timesync: No such file or directory
Sep 20 06:44:02 dvr-server systemd-time-wait-sync[121]: Failed to add a watch for /run/systemd/timesync: No such file or directory
Sep 20 06:44:02 dvr-server systemd-time-wait-sync[121]: Failed to add a watch for /run/systemd/timesync: No such file or directory
Sep 20 06:44:02 dvr-server systemd-time-wait-sync[121]: Failed to add a watch for /run/systemd/timesync: No such file or directory
Sep 20 06:44:02 dvr-server systemd-time-wait-sync[121]: Failed to add a watch for /run/systemd/timesync: No such file or directory
Nov 04 18:22:37 dvr-server systemd-time-wait-sync[121]: adjtime state 5 status 40 time Wed 2020-11-04 23:22:37.000215 UTC

Certainly looks stuck, but unclear why. I was afraid something like this could happen (or someone could have the ntp servers blocked on their firewall), which is why I started building out the UI for it. In older versions the DVR server would never start until time sync was achieved.

Maybe check find /run/systemd/timesync -ls

Then try systemctl restart systemd-timesyncd and see if that makes systemctl list-jobs list go away and get things started up.

find /run/systemd/timesync -ls

22059      0 drwxr-xr-x   2 systemd-timesync systemd-timesync       40 Nov  4 18:26 /run/systemd/timesync

tried a dvr restart after restarting the daemon, no luck - same state - hanging on ntp sync

Hmm very strange. This part hasn't changed at all.

Would time.cloudflare.com be blocked for some reason?

Here's what I see after restart:

# systemctl status systemd-timesyncd
● systemd-timesyncd.service - Network Time Synchronization
     Loaded: loaded (/usr/lib/systemd/system/systemd-timesyncd.service; enabled; vendor preset: enabled)
    Drop-In: /etc/systemd/system/systemd-timesyncd.service.d
             └─hassos.conf, ro.conf
     Active: active (running) since Thu 2020-11-05 00:34:28 UTC; 4s ago
       Docs: man:systemd-timesyncd.service(8)
   Main PID: 587 (systemd-timesyn)
     Status: "Initial synchronization to time server 162.159.200.1:123 (time.cloudflare.com)."
      Tasks: 2 (limit: 2086)
     Memory: 1.0M
     CGroup: /system.slice/systemd-timesyncd.service
             └─587 /usr/lib/systemd/systemd-timesyncd

Nov 05 00:34:28 dvr-server systemd[1]: Starting Network Time Synchronization...
Nov 05 00:34:28 dvr-server systemd[1]: Started Network Time Synchronization.
Nov 05 00:34:28 dvr-server systemd-timesyncd[587]: Initial synchronization to time server 162.159.200.1:123 (time.cloudflare.com).

Looks ok-ish to me:

systemctl status systemd-timesyncd

● systemd-timesyncd.service - Network Time Synchronization
Loaded: loaded (/usr/lib/systemd/system/systemd-timesyncd.service; enabled; vendor preset: enabled)
Drop-In: /etc/systemd/system/systemd-timesyncd.service.d
└─hassos.conf, ro.conf
Active: active (running) since Wed 2020-11-04 18:26:00 EST; 10min ago
Docs: man:systemd-timesyncd.service(8)
Main PID: 1284 (systemd-timesyn)
Status: "Idle."
Tasks: 2 (limit: 4425)
Memory: 1.0M
CGroup: /system.slice/systemd-timesyncd.service
└─1284 /usr/lib/systemd/systemd-timesyncd

Nov 04 18:26:00 dvr-server systemd[1]: Starting Network Time Synchronization...
Nov 04 18:26:00 dvr-server systemd[1]: Started Network Time Synchronization.

date

Wed Nov 4 19:38:39 EST 2020

Maybe its so close its not kicking in the fix? Try these:

timedatectl status
timedatectl timesync-status

timedatectl status

           Local time: Wed 2020-11-04 19:40:52 EST
       Universal time: Thu 2020-11-05 00:40:52 UTC
             RTC time: n/a
            Time zone: Etc/UTC (EST, -0500)

System clock synchronized: yes
NTP service: active
RTC in local TZ: no

timedatectl timesync-status

   Server: 162.159.200.123 (time.cloudflare.com)

Poll interval: 2min 8s (min: 32s; max 34min 8s)
Leap: normal
Version: 4
Stratum: 3
Reference: A100F63
Precision: 1us (-25)
Root distance: 11.893ms (max: 5s)
Offset: -297us
Delay: 20.709ms
Jitter: 491us
Packet count: 3
Frequency: -1.161ppm

Thinking maybe this is a red herring - it looks like ntp sort of finished, but DVR in same state (gui still waiting for ntp)

2020/11/04 18:22:38.917725 [SYS] Starting Channels DVR v2020.11.04.2258 (linux-arm64 pid:305) in /mnt/data/channels-dvr/data
2020/11/04 18:22:39.047175 [SYS] Started HTTP Server
2020/11/04 18:22:39.063123 [SYS] Waiting on dependencies network-online.target time-sync.target
2020/11/04 18:22:51.693717 [SYS] Waiting on dependencies time-sync.target
2020/11/04 18:29:21.008803 [SYS] Starting Channels DVR v2020.11.04.2258 (linux-arm64 pid:2109) in /mnt/data/channels-dvr/data
2020/11/04 18:29:21.017333 [SYS] Started HTTP Server
2020/11/04 18:29:21.037078 [SYS] Waiting on dependencies time-sync.target
2020/11/04 19:38:12.814762 [SYS] Done waiting on dependencies
2020/11/04 19:38:13.460796 [HDR] Found 3 devices

submited 87589182-3157-4bcd-97a0-bc8b6858d64e .

Can you submit diagnostics again

ha - great minds - just did :slight_smile:

Thanks. What does lslocks show

lslocks

COMMAND PID TYPE SIZE MODE M START END PATH
wsdd2 321 FLOCK WRITE 0 0 0 /etc/machine-id...
winbindd 506 POSIX 21B WRITE 0 0 0 /run/lock/samba/msg.lock/506
channels-dvr 2109 FLOCK 64K WRITE 0 0 0 /mnt/data/channels-dvr/data/X-TVE.groups/store/root.bolt
winbindd 486 POSIX 12K READ 0 4 4 /run/lock/samba/names.tdb
winbindd 486 POSIX 8.7K READ 0 4 4 /var/lib/samba/private/netlogon_creds_cli.tdb
winbindd 486 POSIX 4B WRITE 0 0 0 /run/samba/winbindd.pid
winbindd 486 POSIX 20B WRITE 0 0 0 /run/lock/samba/msg.lock/486
winbindd 486 POSIX 1.3K READ 0 4 4 /var/log/samba/log.winbindd
channels-dvr 2109 FLOCK 64K WRITE 0 0 0 /mnt/data/channels-dvr/data/USA-CT56421-X.groups/store/root.bolt
channels-dvr 2109 FLOCK 64K WRITE 0 0 0 /mnt/data/channels-dvr/data/X-TVE.airings/store/root.bolt
channels-dvr 2109 FLOCK 1.2M WRITE 0 0 0 /mnt/data/channels-dvr/data/settings.db
channels-dvr 2109 FLOCK 1.7M WRITE 0 0 0 /mnt/data/channels-dvr/data/recorder.db
channels-dvr 2109 FLOCK 128K WRITE 0 0 0 /mnt/data/channels-dvr/data/USA-CT56421-X.airings/store/root.bolt

Okay go ahead and systemctl reboot. I think that will fix it. There's some weird state the DVR got stuck in where a lock wasn't released. I have the logs to look into it more.

phew. back up and running. Thanks!

1 Like

Share still fails on reboot. Light solid green now. Sent logs.