CasaOS icon indicating copy to clipboard operation
CasaOS copied to clipboard

Too many DNS requests

Open Vizion-HUN opened this issue 2 years ago • 16 comments

Describe the bug

Casa OS frequently sending DNS requests. Way too many... github.com codeload.github.com

To Reproduce install Casa OS, log traffic.

Expected behavior Checking updates, etc. is OK. Daily 1 would be fine.

Screenshots casa2 casa1

Desktop (please complete the following information):

  • OS: linux
  • CasaOS Version: 0.4.4.2
  • Disk Total: 45173
  • Disk Used: 35051
  • System Info: Ubuntu 22.04.3 LTS \l Bit:64 Mem:5921M Core:3 Linux casa 5.15.0-87-generic 97 -Ubuntu SMP Mon Oct 2 21:09:21 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux
  • Remote Version: 0.4.4.2
  • Browser: Chrome / Brave
  • Version: 118.0.0.0

Thank You!

Vizion-HUN avatar Oct 27 '23 21:10 Vizion-HUN

This request should be coming from an app store source update. It does seem to be more frequent at the moment, and we'll discuss and determine a more reasonable frequency to fix it in a future release.

jerrykuku avatar Oct 28 '23 11:10 jerrykuku

@Vizion-HUN - On top of my mind I don't recall any logic within CasaOS keeps sending DNS Lookup requests. At most it resolves a domain to IP once, then following connections will be established via IP.

Would you please provide full repro step for this issue, including the tools you used?

tigerinus avatar Oct 31 '23 07:10 tigerinus

Hello!

There isn't any special steps, I am using AdGuard Home as DNS filter/resolver. And I see the requests, as You can see above on the pictures.

  • OS: linux, installed on a Proxmox server VM, PVE uodate
  • CasaOS Version: 0.4.4.2
  • System Info: [Ubuntu 22.04.3 LTS \l Bit:64 Mem:5921M Core:3 Linux casa 5.15.0-88-generic Ubuntu SMP Mon Oct 2 15:18:56 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux]
  • Remote Version: 0.4.4.2
  • Browser: Brave / Chrome
  • Version: 118.0.0.0
  • PVE info: Kernel Version Linux 6.2.16-18-pve 1 SMP PREEMPT_DYNAMIC PMX 6.2.16-18 (2023-10-11T15:05Z) PVE Manager Version pve-manager/8.0.4/d258a813cfa6b390
  • Running dockers: plex and Filebrowser. The others are stopped.
  • Luckybackup running in the background (GUI for rsync), and Tailscale is installed.

There was no changes in SW or anything (other Dockers are started and stopped as needed), this is why I think sohehow the problem is Casa OS update related.

How can I find the source of the requests?

Thank You for Your help! Vizion

Vizion-HUN avatar Oct 31 '23 21:10 Vizion-HUN

What tool do you use for capture the DNS lookups?

Can you help eliminating some factors (apps, settings, etc.) down to minimum environment for reproducing this issue? Super appreciated!

tigerinus avatar Nov 01 '23 02:11 tigerinus

As I wrote, I have AdGuard Home (LXC on my PVE server) as my DNS resolver, I can track my network there.

Look at this maybe it helps: vizion@casa:~$ sudo journalctl -xef -u casaos.service nov 01 19:12:26 casa casaos[1096]: /bin/bash -c source /usr/share/casaos/shell/helper.sh ;CatNetCardState ens18 nov 01 19:12:30 casa casaos[1096]: 消息来了,message:{"type":"ping"} nov 01 19:12:31 casa casaos[1096]: /bin/bash -c source /usr/share/casaos/shell/helper.sh ;CatNetCardState ens18 nov 01 19:12:36 casa casaos[1096]: /bin/bash -c source /usr/share/casaos/shell/helper.sh ;CatNetCardState ens18 nov 01 19:12:41 casa casaos[1096]: /bin/bash -c source /usr/share/casaos/shell/helper.sh ;CatNetCardState ens18 nov 01 19:12:46 casa casaos[1096]: /bin/bash -c source /usr/share/casaos/shell/helper.sh ;CatNetCardState ens18 nov 01 19:12:51 casa casaos[1096]: /bin/bash -c source /usr/share/casaos/shell/helper.sh ;CatNetCardState ens18 nov 01 19:12:56 casa casaos[1096]: /bin/bash -c source /usr/share/casaos/shell/helper.sh ;CatNetCardState ens18 nov 01 19:13:00 casa casaos[1096]: 消息来了,message:{"type":"ping"}

This thing is running continuosly.

sudo journalctl -xef -u casaos-app-management: nov 01 21:38:39 casa casaos-app-management[1994]: 2023-11-01T21:38:39.799Z info Using default appstore {"func": "service.(*AppStoreManagement).ComposeApp", "file": "/home/runner/work/CasaOS-AppManagement/CasaOS-AppManagement/service/appstore_management.go", "line": 397} nov 01 21:38:39 casa casaos-app-management[1994]: 2023-11-01T21:38:39.799Z error store compose app not found, thus no update available {"storeAppID": "digikam", "func": "service.(*ComposeApp).IsUpdateAvailable", "file": "/home/runner/work/CasaOS-AppManagement/CasaOS-AppManagement/service/compose_app.go", "line": 181} nov 01 21:38:39 casa casaos-app-management[1994]: 2023-11-01T21:38:39.808Z info main app image tag is latest, thus no update available {"image": "filebrowser/filebrowser:latest", "func": "service.(*ComposeApp).IsUpdateAvailableWith", "file": "/home/runner/work/CasaOS-AppManagement/CasaOS-AppManagement/service/compose_app.go", "line": 206} nov 01 21:38:39 casa casaos-app-management[1994]: {"time":"2023-11-01T21:38:39.828558532Z","id":"","remote_ip":"192.168.0.5","host":"192.168.0.8:36163","method":"GET","uri":"/v2/app_management/web/appgrid","user_agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/537.36","status":200,"error":"","latency":54110769,"latency_human":"54.110769ms","bytes_in":0,"bytes_out":1421} nov 01 21:38:44 casa casaos-app-management[1994]: 2023-11-01T21:38:44.803Z info main app image tag is latest, thus no update available {"image": "filebrowser/filebrowser:latest", "func": "service.(*ComposeApp).IsUpdateAvailableWith", "file": "/home/runner/work/CasaOS-AppManagement/CasaOS-AppManagement/service/compose_app.go", "line": 206} nov 01 21:38:44 casa casaos-app-management[1994]: 2023-11-01T21:38:44.810Z info app not found in any appstore {"id": "digikam", "func": "service.(*AppStoreManagement).ComposeApp", "file": "/home/runner/work/CasaOS-AppManagement/CasaOS-AppManagement/service/appstore_management.go", "line": 390} nov 01 21:38:44 casa casaos-app-management[1994]: 2023-11-01T21:38:44.810Z info Using default appstore {"func": "service.(*AppStoreManagement).ComposeApp", "file": "/home/runner/work/CasaOS-AppManagement/CasaOS-AppManagement/service/appstore_management.go", "line": 397} nov 01 21:38:44 casa casaos-app-management[1994]: 2023-11-01T21:38:44.810Z error store compose app not found, thus no update available {"storeAppID": "digikam", "func": "service.(*ComposeApp).IsUpdateAvailable", "file": "/home/runner/work/CasaOS-AppManagement/CasaOS-AppManagement/service/compose_app.go", "line": 181} nov 01 21:38:44 casa casaos-app-management[1994]: {"time":"2023-11-01T21:38:44.827304107Z","id":"","remote_ip":"192.168.0.5","host":"192.168.0.8:36163","method":"GET","uri":"/v2/app_management/web/appgrid","user_agent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/118.0.0.0 Safari/537.36","status":200,"error":"","latency":50065941,"latency_human":"50.065941ms","bytes_in":0,"bytes_out":1421}

Vizion-HUN avatar Nov 01 '23 21:11 Vizion-HUN

Can u stop AdGuard Home and see if it still send these many DNS lookups?

Just want to see if it is AdGuard or CasaOS causing the issue.

tigerinus avatar Nov 01 '23 23:11 tigerinus

No, AdGuard Home is my DNS server, can't stop it. However I tested: add line to Casa OS hosts file: 0.0.0.0 github.com and no more request sended to AGH, so it is sure the Casa OS sending this. I dont know much about helper.sh, but I think that file triggers the pings somehow.

Vizion-HUN avatar Nov 03 '23 10:11 Vizion-HUN

Like I said above, CasaOS has no functionality or need to keep sending DNS lookups. It is not a DNS service (but AdGuard is).

Correct me if I am wrong, but I don't see helper.sh has anything to do with DNS lookup, especially GitHub.com.

I was not suggesting u to turn off AdGuard as a solution. I was asking u to turn it off for like 1min and see if the behavior still persist just so we can rule out AdGuard as a factor. I need ur help before I can help u.

tigerinus avatar Nov 03 '23 10:11 tigerinus

AGH just receiving the requests, logs and redirect to the upstream server. I used AGH even before Casa OS, it is not the source. With 0.0.0.0 inb Casa OS's hosts file, there is no more requests. I will try to stop all dockers, or reinstall Casa OS, and see. THX for Your help.

Vizion-HUN avatar Nov 03 '23 10:11 Vizion-HUN

Thanks for your feedback, I will close this question and reopen it if you have any questions.

LinkLeong avatar Nov 05 '23 13:11 LinkLeong

Hello again! Fresh installed (a few hours ago) Casa OS on Proxmox VE (fully updated free version), using Ubuntu live Server 2023.10 Casaa OS installed on Ubuntu server via wget -qO- https://get.casaos.io | sudo bash Also fully updated, no dockers or anything installed:

  • OS: linux
  • CasaOS Version: 0.4.4.2
  • Disk Total: 40010
  • Disk Used: 7247
  • System Info: [Ubuntu 23.10 \l Bit:64 Mem:5916M Core:3 Linux casa 6.5.0-10-generic 10-Ubuntu SMP PREEMPT_DYNAMIC Fri Oct 13 13:49:38 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux]
  • Remote Version: 0.4.4.2
  • Browser: Chrome
  • Version: 119.0.0.0

So this one is a new virtual SSD, with a different linux base system. And the result is sadly the same. github.com and codeload.github requests (6-10 times) every 10 minutes. casa

To reproduce: install Casa OS and log network/DNS requests. Later I will test Casa OS on other server distros, maybe Ubuntu causing the requests. Thank You!

Vizion-HUN avatar Nov 06 '23 21:11 Vizion-HUN

Let's keep this issue open until its cause is clear.

tigerinus avatar Nov 07 '23 00:11 tigerinus

I want to chime in here as well. I am having the same exact issue. I have Adguard as my DNS on a Pi4. My Casa machine is latest Debian (Bookworm). It only has Casa installed and Jellyfin installed on Casa. Maybe a couple of other terminal apps to help me monitor the system like btop. It's really just a vessel for Jellyfin and nothing else. It looks like Casa is making these requests every 10 minutes which is excessive.

Screenshot from 2024-06-23 12-15-28

ObiWaz avatar Jun 23 '24 16:06 ObiWaz

Hi, I have a similar issue, my /var/log/syslog file is growing excessively - now 2.4 GB and will fill up the filesystem (every 5 seconds it is getting these entries ).

2024-11-30T16:02:02.015089-05:00 casaos casaos[926]: /bin/bash -c source /usr/share/casaos/shell/helper.sh ;CatNetCardState enp2s0
2024-11-30T16:02:02.021002-05:00 casaos casaos[926]: up
2024-11-30T16:02:02.023097-05:00 casaos casaos[926]: {"time":"2024-11-30T16:02:02.022874371-05:00","id":"","remote_ip":"127.0.0.1","host":"127.0.0.1:39257","method":"POST","uri":"/v1/notify/system_status","user_agent":"Go-http-client/1.1","status":200,"error":"","latency":132844,"latency_human":"132.844µs","bytes_in":14,"bytes_out":43}
2024-11-30T16:02:02.025219-05:00 casaos casaos-message-bus[919]: {"time":"2024-11-30T16:02:02.024540184-05:00","id":"","remote_ip":"127.0.0.1","host":"127.0.0.1:37619","method":"POST","uri":"/v2/message_bus/event/casaos/casaos:system:utilization","user_agent":"Go-http-client/1.1","status":200,"error":"","latency":1157823,"latency_human":"1.157823ms","bytes_in":628,"bytes_out":785}
2024-11-30T16:02:07.002546-05:00 casaos casaos[926]: /bin/bash -c source /usr/share/casaos/shell/helper.sh ;GetNetCard 2
2024-11-30T16:02:07.004730-05:00 casaos casaos[926]: {"time":"2024-11-30T16:02:07.004516656-05:00","id":"","remote_ip":"127.0.0.1","host":"127.0.0.1:39257","method":"POST","uri":"/v1/notify/system_status","user_agent":"Go-http-client/1.1","status":200,"error":"","latency":167021,"latency_human":"167.021µs","bytes_in":91,"bytes_out":43}
2024-11-30T16:02:07.014310-05:00 casaos casaos[926]: enp2s0
2024-11-30T16:02:07.014487-05:00 casaos casaos[926]: /bin/bash -c source /usr/share/casaos/shell/helper.sh ;CatNetCardState enp2s0
2024-11-30T16:02:07.020464-05:00 casaos casaos[926]: up
2024-11-30T16:02:07.023617-05:00 casaos casaos[926]: {"time":"2024-11-30T16:02:07.02341173-05:00","id":"","remote_ip":"127.0.0.1","host":"127.0.0.1:39257","method":"POST","uri":"/v1/notify/system_status","user_agent":"Go-http-client/1.1","status":200,"error":"","latency":166289,"latency_human":"166.289µs","bytes_in":14,"bytes_out":43}
2024-11-30T16:02:07.024796-05:00 casaos casaos-message-bus[919]: {"time":"2024-11-30T16:02:07.023984927-05:00","id":"","remote_ip":"127.0.0.1","host":"127.0.0.1:37619","method":"POST","uri":"/v2/message_bus/event/casaos/casaos:system:utilization","user_agent":"Go-http-client/1.1","status":200,"error":"","latency":1474633,"latency_human":"1.474633ms","bytes_in":628,"bytes_out":785}
2024-11-30T16:02:12.003517-05:00 casaos casaos[926]: /bin/bash -c source /usr/share/casaos/shell/helper.sh ;GetNetCard 2
2024-11-30T16:02:12.003748-05:00 casaos casaos[926]: {"time":"2024-11-30T16:02:12.002549862-05:00","id":"","remote_ip":"127.0.0.1","host":"127.0.0.1:39257","method":"POST","uri":"/v1/notify/system_status","user_agent":"Go-http-client/1.1","status":200,"error":"","latency":250398,"latency_human":"250.398µs","bytes_in":91,"bytes_out":43}
2024-11-30T16:02:12.014829-05:00 casaos casaos[926]: enp2s0

FYI @LinkLeong take a look if you can take a look as to what is causing /usr/share/casaos/shell/helper.sh to be run every 5 seconds and it seems to not like something that is filling up /var/log/syslog

I am running on Debian 12 on a zimablade and my CasaOS version is v0.4.13 (I updated from Debian 11 to 12) as you can see from

root@casaos:~# casaos -v
v0.4.13
root@casaos:~# cat /etc/os-release
PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
NAME="Debian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
ID=debian
HOME_URL="https://www.debian.org/"
SUPPORT_URL="https://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"
root@casaos:~#

so I will do some configuration to limit the size of /var/log/syslog and I edited /etc/logrotate.d/rsyslog and modified the top of the file to look like this

/var/log/syslog
{
    rotate 7
    size 100M
    daily
    missingok
    notifempty
    delaycompress
    compress
    postrotate
        /usr/lib/rsyslog/rsyslog-rotate
    endscript
}

such that log file rotation is done for /var/log/syslog

But there was another bug related to incorrect dates on files under /var/log that I needed to fix before the log rotation above would work, that is described here. This last bug is from an original installation of Debian by Zimablade team with incorrect dates and times on files, it is not a CasaOS bug.

strouja avatar Nov 30 '24 21:11 strouja

@strouja

Hi, I have a similar issue, my /var/log/syslog file is growing excessively - now 2.4 GB and will fill up the filesystem (every 5 seconds it is getting these entries ).

Aside from controlling log size, have you ever found a way to reduce the number of requests?

A request every 5s (with or without log) seems absolutely excessive. And at the very least there should be a straightforward way to avoid a log…

zedrdave avatar Mar 30 '25 11:03 zedrdave

@zedrdave I was never able to figure out what causes /var/log/syslog to get an entry like below every 5 seconds. I thought it was because of /usr/share/casaos/shell/helper.sh to be run every 5 seconds and it seems to not like something that is filling up /var/log/syslog but I don't know anymore

2025-03-30T19:22:31.008246-04:00 casaos casaos[1695758]: {"time":"2025-03-30T19:22:31.006969403-04:00","id":"","remote_ip":"127.0.0.1","host":"127.0.0.1:35251","method":"POST","uri":"/v1/notify/system_status","user_agent":"Go-http-client/1.1","status":200,"error":"","latency":296929,"latency_human":"296.929µs","bytes_in":85,"bytes_out":43}
2025-03-30T19:22:31.027059-04:00 casaos casaos[1695758]: {"time":"2025-03-30T19:22:31.02686458-04:00","id":"","remote_ip":"127.0.0.1","host":"127.0.0.1:35251","method":"POST","uri":"/v1/notify/system_status","user_agent":"Go-http-client/1.1","status":200,"error":"","latency":185805,"latency_human":"185.805µs","bytes_in":14,"bytes_out":43}
2025-03-30T19:22:35.027827-04:00 casaos casaos-message-bus[931]: {"time":"2025-03-30T19:22:35.027098398-04:00","id":"","remote_ip":"127.0.0.1","host":"127.0.0.1:36097","method":"POST","uri":"/v2/message_bus/event/casaos/casaos:system:utilization","user_agent":"Go-http-client/1.1","status":200,"error":"","latency":1028029,"latency_human":"1.028029ms","bytes_in":632,"bytes_out":789}

The configuration I showed earlier about /etc/logrotate.d/rsyslog limits the size and rotates the syslog file.

I don't see any cronjobs running via crontab -e as the root user

strouja avatar Mar 30 '25 23:03 strouja