CPU overloaded at the 0.11.1.11

DmytroKorniienko commented 1 year ago

After upgrede to 0.11.1.11 cpu utilization continuatelly height. Reverting to previous version solves issue, reinstall or/and reboot - not. Environment - Proxmox, HAOS. Addon configuration: exit node, funnel - all works, exept CPU issue. Nothing weird in the logs.

2023-08-02 2023-08-02 (1)

2023/08/02 01:15:27 router: disabling tunneled IPv6 due to system IPv6 config: kernel doesn't support IPv6 policy routing: querying IPv6 policy routing rules: address family not supported by protocol
2023/08/02 01:15:27 dns: [resolved-ping=yes rc=unknown ret=direct]
2023/08/02 01:15:27 dns: using "direct" mode
2023/08/02 01:15:27 dns: using *dns.directManager
2023/08/02 01:15:27 link state: interfaces.State{defaultRoute=enp0s18 ifs={docker0:[172.30.232.1/23] enp0s18:[192.168.1.137/24] hassio:[172.30.32.1/23]} v4=true v6=false}
2023/08/02 01:15:27 magicsock: disco key = d:41adeb77a50bdbb4
2023/08/02 01:15:27 Creating WireGuard device...
2023/08/02 01:15:27 Bringing WireGuard device up...
2023/08/02 01:15:27 Bringing router up...
2023/08/02 01:15:27 external route: up
2023/08/02 01:15:27 Clearing router settings...
2023/08/02 01:15:27 Starting network monitor...
2023/08/02 01:15:27 Engine created.
2023/08/02 01:15:27 pm: using backend prefs for "profile-06d6": Prefs{ra=true dns=true want=true routes=[0.0.0.0/0 ::/0 192.168.1.0/24] snat=true nf=on host="haos" Persist{lm=, o=, n=[H1KK9] u="login@gmail.com"}}
2023/08/02 01:15:27 envknob: TS_NO_LOGS_NO_SUPPORT="true"
2023/08/02 01:15:27 logpolicy: using system state directory "/var/lib/tailscale"
2023/08/02 01:15:28 got LocalBackend in 115ms
2023/08/02 01:15:28 Start
2023/08/02 01:15:28 Backend: logs: be:7206ccb7ab321dc0fe158d38866f4845f30dc3c28bd7b44177447eaa77f114c1 fe:
2023/08/02 01:15:28 control: client.Login(false, 0)
2023/08/02 01:15:28 control: doLogin(regen=false, hasUrl=false)
2023/08/02 01:15:28 health("overall"): error: not in map poll
2023/08/02 01:15:28 control: control server key from https://controlplane.tailscale.com: ts2021=[fSeS+], legacy=[nlFWp]
2023/08/02 01:15:28 control: RegisterReq: onode= node=[H1KK9] fup=false nks=false
2023/08/02 01:15:28 control: creating new noise client
[01:15:28] INFO: Adding advertised local subnets to ip rules with higher priority than Tailscale's routing,
[01:15:28] INFO: to prevent routing advertised local subnets if the same subnet is routed within your tailnet.
[01:15:28] INFO:   Adding route 192.168.1.0/24 to ip rules
2023/08/02 01:15:28 control: RegisterReq: got response; nodeKeyExpired=false, machineAuthorized=true; authURL=false
2023/08/02 01:15:28 control: netmap: got new dial plan from control
2023/08/02 01:15:28 active login: login@gmail.com
2023/08/02 01:15:28 serve: creating a new proxy handler for http://127.0.0.1:8123
2023/08/02 01:15:28 Hostinfo.WireIngress changed to true
2023/08/02 01:15:28 Switching ipn state NoState -> Starting (WantRunning=true, nm=true)
2023/08/02 01:15:28 magicsock: SetPrivateKey called (init)
2023/08/02 01:15:28 wgengine: Reconfig: configuring userspace WireGuard config (with 0/2 peers)
2023/08/02 01:15:28 wgengine: Reconfig: configuring router
2023/08/02 01:15:28 wgengine: Reconfig: configuring DNS
2023/08/02 01:15:28 dns: Set: {DefaultResolvers:[192.168.1.99] Routes:{duck-buri.ts.net.:[] ts.net.:[199.247.155.53 2620:111:8007::53]}+65arpa SearchDomains:[duck-buri.ts.net.] Hosts:3}
2023/08/02 01:15:28 dns: Resolvercfg: {Routes:{.:[192.168.1.99] ts.net.:[199.247.155.53 2620:111:8007::53]} Hosts:3 LocalDomains:[duck-buri.ts.net.]+65arpa}
2023/08/02 01:15:28 dns: OScfg: {Nameservers:[100.100.100.100] SearchDomains:[duck-buri.ts.net.] MatchDomains:[] Hosts:[]}
2023/08/02 01:15:28 rename of "/etc/resolv.conf" to "/etc/resolv.pre-tailscale-backup.conf" failed (rename /etc/resolv.conf /etc/resolv.pre-tailscale-backup.conf: device or resource busy), falling back to copy+delete
2023/08/02 01:15:28 peerapi: serving on http://100.01.01.77:61465
2023/08/02 01:15:28 peerapi: failed to do peerAPI listen, harmless (netstack available) but error was: listen tcp6 [fd7a:115c:a1e0:ab12:4843:cd96:6254:c44d]:0: bind: cannot assign requested address
2023/08/02 01:15:28 peerapi: serving on http://[fd7a:115c:a1e0:ab12:4843:cd96:6254:c44d]:1
2023/08/02 01:15:28 portmapper: UPnP meta changed: {Location:http://192.168.1.1:49095/rootDesc.xml Server:Keenetic Ltd. UPnP/1.1 MiniUPnPd/2.0 USN:uuid:7a3f4b5b-ca1c-3c87-13ca-a4e3b2a09da3::urn:schemas-upnp-org:device:InternetGatewayDevice:1}
2023/08/02 01:15:28 magicsock: home is now derp-22 (waw)
2023/08/02 01:15:28 magicsock: adding connection to derp-22 for home-keep-alive
2023/08/02 01:15:28 control: NetInfo: NetInfo{varies=false hairpin=false ipv6=false ipv6os=true udp=true icmpv4=false derp=#22 portmap=active-UMC link=""}
2023/08/02 01:15:28 magicsock: 1 active derp conns: derp-22=cr0s,wr0s
2023/08/02 01:15:28 derphttp.Client.Connect: connecting to derp-22 (waw)
2023/08/02 01:15:28 Switching ipn state Starting -> Running (WantRunning=true, nm=true)
2023/08/02 01:15:28 magicsock: endpoints changed: 10.1.12.201:44475 (portmap), 46.175.252.52:44475 (stun), 172.30.32.1:44475 (local), 172.30.232.1:44475 (local), 192.168.1.137:44475 (local)
2023/08/02 01:15:28 wgengine: Reconfig: configuring userspace WireGuard config (with 0/10 peers)
2023/08/02 01:15:28 serve listening on 100.01.01.77:443
2023/08/02 01:15:28 magicsock: derp-22 connected; connGen=1
[01:15:30] INFO: Tailscale is running
[01:15:30] INFO: Clamping the MSS to the MTU for all advertised subnet's interface,
[01:15:30] INFO: to support site-to-site networking better
[01:15:30] INFO:   Clamping the MSS for interface enp0s18
s6-rc: info: service post-tailscaled successfully started
s6-rc: info: service proxy: starting
s6-rc: info: service taildrop: starting
s6-rc: info: service taildrop successfully started
2023/08/02 01:15:28 health("overall"): ok
2023/08/02 01:15:31 serve: closing idle connections to http://127.0.0.1:8123
2023/08/02 01:15:31 closing listener 100.01.01.77:443
2023/08/02 01:15:31 closing listener [fd7a:115c:a1e0:ab12:4843:cd96:6254:c44d]:443
2023/08/02 01:15:31 Hostinfo.WireIngress changed to false
2023/08/02 01:15:31 serve: creating a new proxy handler for http://127.0.0.1:8123
[01:15:31] INFO: Tailscale Proxy is enabled:
[01:15:31] INFO:   Your Home Assistant instance is available within your Tailnet VPN at
[01:15:31] INFO:   https://network.ts.net
s6-rc: info: service proxy successfully started
s6-rc: info: service funnel: starting
2023/08/02 01:15:31 serve listening on 100.01.01.77:443
2023/08/02 01:15:31 wgengine: Reconfig: configuring userspace WireGuard config (with 0/2 peers)
[01:15:31] INFO: Tailscale Funnel is enabled:
[01:15:31] INFO:   Your Home Assistant instance is publicly available on the internet at
[01:15:31] INFO:   https://network.ts.net
s6-rc: info: service funnel successfully started
s6-rc: info: service legacy-services: starting

What I missed? Will be appreciated for your help. THanks for the great job!

lmagyar commented 1 year ago

Strange, I've checked what I've changed (https://github.com/lmagyar/homeassistant-addon-tailscale/commit/45419363f41befb1683e3f7a2a4bbd8c5a91ab3e), and based on your log, my script executes the same steps as the previous version, so my guess is that the problem is with the binaries (tailscale or base-image).

I see only one strange unrelated thing in the logs: https://network.ts.net

So please:

what is the output of this command, executed in the add-on's cli: /opt/tailscale status --self=true --peers=false --json | jq "{HostName: .Self.HostName, DNSName: .Self.DNSName, MagicDNSSuffix: .MagicDNSSuffix, CertDomains: .CertDomains}" it should be something like this:
```
{
"HostName": "dev-homeassistant",
"DNSName": "dev-homeassistant-beta.tail6158.ts.net.",
"MagicDNSSuffix": "tail6158.ts.net",
"CertDomains": [
  "dev-homeassistant-beta.tail6158.ts.net"
]
}
```
you can get into the add-on's container with something like docker exec -it addon_09716aab_tailscale /bin/bash
I've created a new beta version v0.11.1.12-rc02 of my fork, with the latest binaries (base-image v14.0.7), I don't think it will solve the CPU issue, but this is a first step to test, so please:
- stop the non-beta tailscale version
- install, start, login, configure the beta version from here: https://github.com/lmagyar/homeassistant-addon-tailscale-beta
- note: it creates a tailscale2 interface, just to not completely mess up networking if accidentally started parallel with the non-beta version
- does this solve the CPU issue?
- stop the beta, start the non-beta add-on

If the CPU issue doesn't solved, I will create a downgraded beta release (downgraded tailscale, then downgraded base-image versions, but with my latest script version), maybe we will see something. Eg. there is an issue with taildrop and network performance: https://github.com/hassio-addons/addon-tailscale/issues/168

DmytroKorniienko commented 1 year ago

I see only one strange unrelated thing in the logs: https://network.ts.net

I replaced some personal info for security reason. Thank you, I will test beta version and give you feedback soon.

lmagyar commented 1 year ago

Ah, OK. :) So the link that is shown in the log, as "Your Home Assistant instance is publicly available on the internet at https://network.ts.net" in reality is working? I was scared that something is really different on a Proxmox/HAOS installation.

DmytroKorniienko commented 1 year ago

Both version works and accessible from external, but beta without CPU overload:

2023-08-03 2023-08-03 (1)

...
2023/08/03 01:53:47 serve: creating a new proxy handler for http://127.0.0.1:8123
[01:53:48] INFO: Tailscale Funnel is enabled:
[01:53:48] INFO:   Your Home Assistant instance is publicly available on the internet at
[01:53:48] INFO:   https://host.nw.ts.net
s6-rc: info: service funnel successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
2023/08/03 01:53:48 Hostinfo.WireIngress changed to true

If any additional testing required please let me know.

lmagyar commented 1 year ago

Wow! This means the problem is with the v14.0.6 base image.

I've released v0.11.1.12 NON-beta version.

Please report back, if the new v0.11.1.12 NON-beta version works without extra CPU load.

DmytroKorniienko commented 1 year ago

I've released v0.11.1.12 NON-beta version.

I updated to v0.11.1.12 and nothing changes for me. Extra load was found again, so then I totally uninstalled main version and reinstalled it again. Add-on asked for autorization by url and then all extra CPU loads was fixed. So my best gues - this is not related with a binary or/and add-on and something at the cloud side. Thank you for your help.

lmagyar commented 1 year ago

Computers are 'a complete mystery'... :) Closing this issue for now, reopen it if you think it is relevant again.

lmagyar / homeassistant-addon-tailscale

CPU overloaded at the 0.11.1.11 #50