search

kinu-garage / hut_10sqft

Computer setup tools for my own environment, and public discussion place holder.
2 stars 1 forks source link

Home Assistant not accessible, not even the host #825

Closed 130s closed 1 year ago

130s commented 1 year ago

Tech resolution to https://github.com/kinu-garage/30y-130s_life/issues/1674

Issue

What is attempted but does not seem effective

130s commented 1 year ago

Resolved by itself, it looks like.

Some syslog pieces. ``` Apr 12 12:17:28 130s-rpi4-1 dhcpcd[556]: vethb4b975c: adding route to 169.254.0.0/16 Apr 12 12:17:31 130s-rpi4-1 dhcpcd[556]: vethb4b975c: no IPv6 Routers available Apr 12 12:17:33 130s-rpi4-1 systemd[1]: systemd-fsckd.service: Succeeded. Apr 12 12:17:44 130s-rpi4-1 systemd[1]: systemd-hostnamed.service: Succeeded. Apr 12 12:17:51 130s-rpi4-1 packagekitd[1883]: http://deb.debian.org/debian bullseye InRelease is not (yet) available (Temporary failure resolving 'deb.debian.org') Apr 12 12:17:51 130s-rpi4-1 packagekitd[1883]: http://archive.raspberrypi.org/debian bullseye InRelease is not (yet) available (Temporary failure resolving 'archive.raspberrypi.org') Apr 12 12:17:51 130s-rpi4-1 PackageKit: refresh-cache transaction /472_bacaeada from uid 1000 finished with failed after 27459ms Apr 12 12:17:51 130s-rpi4-1 packagekitd[1883]: http://security.debian.org/debian-security bullseye-security InRelease is not (yet) available (Temporary failure resolving 'security.debian.org') Apr 12 12:17:51 130s-rpi4-1 packagekitd[1883]: http://deb.debian.org/debian bullseye-updates InRelease is not (yet) available (Temporary failure resolving 'deb.debian.org') Apr 12 12:23:35 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 12:24:40 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 12:25:43 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 12:26:48 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 12:27:52 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 12:28:56 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 12:30:00 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 12:31:04 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 12:31:59 130s-rpi4-1 systemd[1]: Starting Cleanup of Temporary Directories... Apr 12 12:31:59 130s-rpi4-1 systemd[1]: systemd-tmpfiles-clean.service: Succeeded. Apr 12 12:31:59 130s-rpi4-1 systemd[1]: Finished Cleanup of Temporary Directories. Apr 12 12:32:09 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 12:33:13 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 12:34:17 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 12:35:20 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available : Apr 12 14:53:55 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 14:55:00 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 14:56:03 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 14:57:07 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 14:58:12 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available Apr 12 14:59:15 130s-rpi4-1 dhcpcd[556]: eth0: bpf_send: No buffer space available ``` Entire 4pm is very short. I guess at some point around 17:03 I physically forced reboot. ``` Apr 12 15:46:53 130s-rpi4-1 dhcpcd[556]: eth0: adding default route via 192.168.1.1 Apr 12 15:46:53 130s-rpi4-1 avahi-daemon[438]: New relevant interface eth0.IPv4 for mDNS. Apr 12 15:46:53 130s-rpi4-1 dhcpcd[556]: vethb4b975c: deleting default route Apr 12 15:46:53 130s-rpi4-1 avahi-daemon[438]: Registering new address record for 192.168.1.34 on eth0.IPv4. Apr 12 15:46:53 130s-rpi4-1 avahi-daemon[438]: Got SIGHUP, reloading. Apr 12 15:46:53 130s-rpi4-1 avahi-daemon[438]: No service file found in /etc/avahi/services. Apr 12 15:55:25 130s-rpi4-1 systemd-timesyncd[341]: Initial synchronization to time server 66.151.147.38:123 (1.debian.pool.ntp.org). Apr 12 16:17:01 130s-rpi4-1 CRON[6362]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: bits received from HRNG source: 160064 Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: bits sent to kernel pool: 120000 Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: entropy added to kernel pool: 120000 Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: FIPS 140-2 successes: 8 Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: FIPS 140-2 failures: 0 Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: FIPS 140-2(2001-10-10) Monobit: 0 Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: FIPS 140-2(2001-10-10) Poker: 0 Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: FIPS 140-2(2001-10-10) Runs: 0 Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: FIPS 140-2(2001-10-10) Long run: 0 Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: FIPS 140-2(2001-10-10) Continuous run: 0 Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: HRNG source speed: (min=277.926; avg=438.304; max=547.907)Kibits/s Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: FIPS tests speed: (min=24.422; avg=27.021; max=34.305)Mibits/s Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: Lowest ready-buffers level: 2 Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: Entropy starvations: 0 Apr 12 16:25:35 130s-rpi4-1 rngd[529]: stats: Time spent starving for entropy: (min=0; avg=0.000; max=0)us Apr 12 17:03:12 130s-rpi4-1 systemd-modules-load[146]: Failed to find module 'lp' Apr 12 17:03:12 130s-rpi4-1 systemd-modules-load[146]: Failed to find module 'ppdev' Apr 12 17:03:12 130s-rpi4-1 systemd-modules-load[146]: Failed to find module 'parport_pc' Apr 12 17:03:12 130s-rpi4-1 systemd-modules-load[146]: Inserted module 'i2c_dev' Apr 12 17:03:12 130s-rpi4-1 systemd-sysctl[159]: Couldn't write '1' to 'kernel/unprivileged_userns_clone', ignoring: No such file or directory Apr 12 17:03:12 130s-rpi4-1 fake-hwclock[149]: Wed 12 Apr 2023 08:17:01 PM UTC Apr 12 17:03:12 130s-rpi4-1 systemd-fsck[163]: e2fsck 1.46.2 (28-Feb-2021) Apr 12 17:03:12 130s-rpi4-1 systemd-fsck[163]: rootfs: clean, 298216/1910656 files, 2151290/7725184 blocks Apr 12 17:03:12 130s-rpi4-1 systemd[1]: Finished Remount Root and Kernel File Systems. Apr 12 17:03:12 130s-rpi4-1 kernel: [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083] Apr 12 17:03:12 130s-rpi4-1 systemd[1]: Condition check resulted in Rebuild Hardware Database being skipped. ```

bard.google.com returned this answer.

Q. My linux host wasn't accessible over IP network for hours. Here's a piece from syslog. What do you think was happening? ``` Apr 12 12:17:22 130s-rpi4-1 dbus-daemon[1046]: [session uid=1000 pid=1046] Activating via systemd: service name='org.gtk.vfs.GPhoto2VolumeMonitor' unit='gvfs-gphoto2-volume-monitor.service' requested by \ ':1.10' (uid=1000 pid=1604 comm="pcmanfm --desktop --profile LXDE-pi ") Apr 12 12:17:22 130s-rpi4-1 systemd[934]: Starting Virtual filesystem service - digital camera monitor... Apr 12 12:17:22 130s-rpi4-1 dbus-daemon[1046]: [session uid=1000 pid=1046] Successfully activated service 'org.gtk.vfs.GPhoto2VolumeMonitor' Apr 12 12:17:22 130s-rpi4-1 systemd[934]: Started Virtual filesystem service - digital camera monitor. Apr 12 12:17:22 130s-rpi4-1 dbus-daemon[1046]: [session uid=1000 pid=1046] Activating via systemd: service name='org.gtk.vfs.MTPVolumeMonitor' unit='gvfs-mtp-volume-monitor.service' requested by ':1.10' \ (uid=1000 pid=1604 comm="pcmanfm --desktop --profile LXDE-pi ") Apr 12 12:17:22 130s-rpi4-1 systemd[934]: Starting Virtual filesystem service - Media Transfer Protocol monitor... Apr 12 12:17:22 130s-rpi4-1 dhcpcd[556]: eth0: no IPv6 Routers available Apr 12 12:17:22 130s-rpi4-1 dbus-daemon[1046]: [session uid=1000 pid=1046] Successfully activated service 'org.gtk.vfs.MTPVolumeMonitor' Apr 12 12:17:22 130s-rpi4-1 systemd[934]: Started Virtual filesystem service - Media Transfer Protocol monitor. Apr 12 12:17:22 130s-rpi4-1 dbus-daemon[1046]: [session uid=1000 pid=1046] Activating via systemd: service name='org.gtk.vfs.GoaVolumeMonitor' unit='gvfs-goa-volume-monitor.service' requested by ':1.10' \ (uid=1000 pid=1604 comm="pcmanfm --desktop --profile LXDE-pi ") Apr 12 12:17:22 130s-rpi4-1 systemd[934]: Starting Virtual filesystem service - GNOME Online Accounts monitor... Apr 12 12:17:23 130s-rpi4-1 dbus-daemon[1046]: [session uid=1000 pid=1046] Successfully activated service 'org.gtk.vfs.GoaVolumeMonitor' Apr 12 12:17:23 130s-rpi4-1 systemd[934]: Started Virtual filesystem service - GNOME Online Accounts monitor. Apr 12 12:17:24 130s-rpi4-1 dbus-daemon[440]: [system] Activating via systemd: service name='org.freedesktop.PackageKit' unit='packagekit.service' requested by ':1.44' (uid=1000 pid=1601 comm="lxpanel --\ profile LXDE-pi ") Apr 12 12:17:24 130s-rpi4-1 systemd[1]: Starting PackageKit Daemon... Apr 12 12:17:24 130s-rpi4-1 PackageKit: daemon start Apr 12 12:17:24 130s-rpi4-1 dhcpcd[556]: vethb4b975c: probing for an IPv4LL address Apr 12 12:17:24 130s-rpi4-1 dbus-daemon[440]: [system] Successfully activated service 'org.freedesktop.PackageKit' Apr 12 12:17:24 130s-rpi4-1 systemd[1]: Started PackageKit Daemon. Apr 12 12:17:28 130s-rpi4-1 dhcpcd[556]: vethb4b975c: using IPv4LL address 169.254.86.35 Apr 12 12:17:28 130s-rpi4-1 avahi-daemon[438]: Joining mDNS multicast group on interface vethb4b975c.IPv4 with address 169.254.86.35. Apr 12 12:17:28 130s-rpi4-1 avahi-daemon[438]: New relevant interface vethb4b975c.IPv4 for mDNS. Apr 12 12:17:28 130s-rpi4-1 avahi-daemon[438]: Registering new address record for 169.254.86.35 on vethb4b975c.IPv4. Apr 12 12:17:28 130s-rpi4-1 dhcpcd[556]: vethb4b975c: adding route to 169.254.0.0/16 Apr 12 12:17:31 130s-rpi4-1 dhcpcd[556]: vethb4b975c: no IPv6 Routers available Apr 12 12:17:33 130s-rpi4-1 systemd[1]: systemd-fsckd.service: Succeeded. Apr 12 12:17:44 130s-rpi4-1 systemd[1]: systemd-hostnamed.service: Succeeded. Apr 12 12:17:51 130s-rpi4-1 packagekitd[1883]: http://deb.debian.org/debian bullseye InRelease is not (yet) available (Temporary failure resolving 'deb.debian.org') Apr 12 12:17:51 130s-rpi4-1 packagekitd[1883]: http://archive.raspberrypi.org/debian bullseye InRelease is not (yet) available (Temporary failure resolving 'archive.raspberrypi.org') Apr 12 12:17:51 130s-rpi4-1 PackageKit: refresh-cache transaction /472_bacaeada from uid 1000 finished with failed after 27459ms Apr 12 12:17:51 130s-rpi4-1 packagekitd[1883]: http://security.debian.orgView other drafts ```

Based on the syslog you provided, it appears that your Linux host was not accessible over IP network for hours because it was unable to resolve DNS names.

The first few lines of the syslog show that your host was successfully able to obtain an IPv4LL address (169.254.86.35). This means that your host was able to connect to the local network, but it was unable to connect to the internet.

The lines that start with "packagekitd" show that your host was trying to update its software packages. However, it was unable to resolve the DNS names for the Debian and Raspberry Pi repositories. This prevented your host from downloading the latest software updates, which may have caused it to become inaccessible over IP network.

To fix this issue, you can try the following:

  1. Check your DNS settings to make sure that they are correct.
  2. Flush your DNS cache.
  3. Restart your DNS server.
  4. Try connecting to the internet from another device to see if the issue is with your host or your internet connection.

If you are still unable to resolve the issue, you can contact your internet service provider for assistance.

Other hosts were also experiencing unusual laggy response in both WAN and LAN communications, but not as extreme as this rpi4 host, which doesn't give a hint for why DNS failed for rpi4 host.

I can dig more but stops here for now.

130s commented 1 year ago

Looking at the logbook on Lovelace, HASS kept receiving events from devices during the issue was happening, some of which are from IP-based (e.g. ring.com home server). Hmmmmmm.