Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

adguard home does not respect client configuration overrides #4982

Closed
3 tasks done
ishanjain28 opened this issue Oct 2, 2022 · 12 comments · Fixed by #4983
Closed
3 tasks done

adguard home does not respect client configuration overrides #4982

ishanjain28 opened this issue Oct 2, 2022 · 12 comments · Fixed by #4983
Assignees
Milestone

Comments

@ishanjain28
Copy link
Contributor

Prerequisites

  • I have checked the Wiki and Discussions and found no answer

  • I have searched other issues and found no duplicates

  • I want to report a bug and not ask a question

Operating system type

Linux, Other (please mention the version in the description)

CPU architecture

AMD64

Installation

GitHub releases or script from README

Setup

On a router, DHCP is handled by the router

AdGuard Home version

latest beta release(v0.108.0-b.16 Pre-release) and HEAD(2ffea60)

Description

What did you do?

  1. Configured adguard to run a DNS server on port 5354.
  2. Configured adguard home to block all services.
  3. Added a client(127.0.0.0/8) and for this client, I unblocked all services.

Expected result

dig -p 5354 @127.0.0.1 cloudflare.com

should return the correct IP for cloudflare.com. The client in this case is localhost which comes under the client I added initially and for this client, No services should be blocked.

Actual result

It blocks DNS for all globally blocked services and does not respect client specific overrides.

Screenshots (if applicable)

image
image

image

Additional information

This is happen on the most recent commit and the most recent release. It does not happen in, v0.107.14

@ishanjain28
Copy link
Contributor Author

Video demonstration. Re-opening the client overrides page, Clicking on unblock all button and then saving changes fixes the problem.

adguard.home.client.overrides.glitch.mp4

@ishanjain28
Copy link
Contributor Author

/add request contains,

{
    "ids": [
        "127.0.0.0/8"
    ],
    "tags": [

    ],
    "use_global_settings": true,
    "use_global_blocked_services": false,
    "name": "test2",
    "upstreams": [

    ]
}

Clicking on unblock all and updating client sends a request to /update which contains,

{
    "name": "test2",
    "data": {
        "upstreams": [

        ],
        "tags": [

        ],
        "name": "test2",
        "blocked_services": [

        ],
        "ids": [
            "127.0.0.0/8"
        ],
        "filtering_enabled": false,
        "parental_enabled": false,
        "safebrowsing_enabled": false,
        "safesearch_enabled": false,
        "use_global_blocked_services": false,
        "use_global_settings": true
    }
}

Looks like it's just missing a check for the global blocked services somewhere.

@ishanjain28
Copy link
Contributor Author

Here is the problem,

Context.filters.ApplyBlockedServices(setts, c.BlockedServices)

This adds client specific blocked services but does not remove the inherited global blocked list.

2022/10/02 23:53:28.570807 45142#57 [info] []string{"9gag", "amazon", "bilibili", "cloudflare", "dailymotion", "discord", "disneyplus", "ebay", "epic_games", "facebook", "hulu", "imgur", "instagram", "mail_ru", "netflix", "ok", "origin", "pinterest", "qq", "reddit", "skype", "snapchat", "spotify", "steam", "telegram", "tiktok", "tinder", "twitch", "twitter", "viber", "vimeo", "vk", "wechat", "weibo", "whatsapp", "youtube"}

This is the value of Context.filters.BlockedServices when client is configured to not follow global settings.

@EugeneOne1
Copy link
Member

@ishanjain28, hello and thanks for the thorough report and for the contribution, but we've already fixed it ourselves in the latest edge build. Could you please check it out?

@EugeneOne1 EugeneOne1 added the waiting for data Waiting for users to provide more data. label Oct 3, 2022
@ishanjain28
Copy link
Contributor Author

hey @EugeneOne1

I can replicate this bug in the build here, https://github.com/AdguardTeam/AdGuardHome/releases/tag/v0.108.0-b.16
and I was able to replicate it in a build with the latest commit in the main branch. 2ffea60

@EugeneOne1
Copy link
Member

@ishanjain28, that's rather odd. We aren't being able to reproduce it with the latest commit on several test machines. Are you sure the client's settings haven't changed since the last report, the use_global_blocked_services field in particular? If so, could you please collect a verbose log for us? You may send it to devteam@adguard.com.

@ishanjain28
Copy link
Contributor Author

@EugeneOne1

I can consistently replicate this on a linux x64 machine and some rpi 3b+.

I have included verbose logs and the config file in this.

Verbose Logs
2022/10/03 17:19:32.686212 63690#1 [info] AdGuard Home, version v0.0.0
2022/10/03 17:19:32.686240 63690#1 [debug] current working directory is /home/ishan/adguardhome
2022/10/03 17:19:32.686269 63690#1 [debug] reading config file: /home/ishan/adguardhome/AdGuardHome.yaml
2022/10/03 17:19:32.686582 63690#1 [debug] github.com/AdguardTeam/AdGuardHome/internal/home.upgradeConfig(): got schema version 14
2022/10/03 17:19:32.686596 63690#1 [debug] reading config file: /home/ishan/adguardhome/AdGuardHome.yaml
2022/10/03 17:19:32.687295 63690#1 [debug] hosts container: starting
2022/10/03 17:19:32.687311 63690#1 [debug] hosts container: refreshing
2022/10/03 17:19:32.687353 63690#1 [debug] hosts container: added ip-host pair "127.0.0.1"-"localhost"
2022/10/03 17:19:32.687378 63690#1 [debug] hosts container: added ip-host pair "::1"-"localhost"
2022/10/03 17:19:32.687400 63690#1 [debug] hosts container: added ip-host pair "127.0.1.1"-"emerald.localdomain"
2022/10/03 17:19:32.687419 63690#1 [debug] hosts container: added ip-host pair "127.0.1.1"-"emerald"
2022/10/03 17:19:32.687498 63690#1 [debug] hosts container: sending upd
2022/10/03 17:19:32.687676 63690#1 [debug] filtering: initialized 36 services
2022/10/03 17:19:32.687713 63690#1 [error] creating dhcpv4 srv: dhcpv4: <nil> is not an IP address
2022/10/03 17:19:32.688005 63690#1 [debug] clients: removed 0 client aliases
2022/10/03 17:19:32.688023 63690#1 [debug] clients: added 0 client aliases from dhcp
2022/10/03 17:19:32.688044 63690#1 [debug] writing config file "/home/ishan/adguardhome/AdGuardHome.yaml"
2022/10/03 17:19:32.688116 63690#23 [debug] clients: removed 0 client aliases
2022/10/03 17:19:32.688147 63690#23 [debug] clients: added 127.0.0.1 -> "localhost" [1]
2022/10/03 17:19:32.688159 63690#23 [debug] clients: added ::1 -> "localhost" [2]
2022/10/03 17:19:32.688175 63690#23 [debug] clients: added 127.0.1.1 -> "emerald.localdomain" [3]
2022/10/03 17:19:32.688183 63690#23 [debug] clients: added 3 client aliases from system hosts file
2022/10/03 17:19:32.698387 63690#1 [info] Initializing auth module: /home/ishan/adguardhome/data/sessions.db
2022/10/03 17:19:32.698440 63690#1 [debug] auth: loaded 1 sessions from DB (removed 0 expired)
2022/10/03 17:19:32.698451 63690#1 [info] auth: initialized.  users:1  sessions:1
2022/10/03 17:19:32.698468 63690#1 [info] Initialize web module
2022/10/03 17:19:32.698491 63690#1 [debug] stats: opening database
2022/10/03 17:19:32.698522 63690#1 [debug] stats: database opened
2022/10/03 17:19:32.698534 63690#1 [debug] stats: deleting old units until id 462418
2022/10/03 17:19:32.698552 63690#1 [debug] github.com/AdguardTeam/AdGuardHome/internal/stats.loadUnitFromDB(): Loading unit 462443
2022/10/03 17:19:32.698619 63690#1 [debug] stats: initialized
2022/10/03 17:19:32.698672 63690#1 [debug] os.Open(): filtering: loading filter 1 from /home/ishan/adguardhome/data/filters/1.txt
2022/10/03 17:19:32.698691 63690#1 [debug] github.com/AdguardTeam/AdGuardHome/internal/filtering.(*DNSFilter).load(): filtering: File /home/ishan/adguardhome/data/filters/1.txt, id 1, length 958801
2022/10/03 17:19:32.704160 63690#1 [debug] dns: added 0 A/PTR entries from DHCP
2022/10/03 17:19:32.704194 63690#1 [debug] Bootstraps: [9.9.9.10 149.112.112.10 2620:fe::10 2620:fe::fe:10]
2022/10/03 17:19:32.704216 63690#1 [debug] Upstream 0: https://dns10.quad9.net:443/dns-query
2022/10/03 17:19:32.704237 63690#1 [info] DNS cache is enabled
2022/10/03 17:19:32.704247 63690#1 [info] MaxGoroutines is set to 300
2022/10/03 17:19:32.704678 63690#1 [debug] upstreams to resolve PTR for local addresses: [127.0.0.53]
2022/10/03 17:19:32.704691 63690#1 [debug] Upstream 0: 127.0.0.53:53
2022/10/03 17:19:32.704723 63690#1 [debug] Web: applying new TLS configuration
2022/10/03 17:19:32.704736 63690#1 [info] AdGuard Home is available at the following addresses:
2022/10/03 17:19:32.705116 63690#1 [info] Go to http://127.0.0.1:8080
2022/10/03 17:19:32.705128 63690#1 [info] Go to http://127.0.0.1:3001 (BETA)
2022/10/03 17:19:32.705138 63690#1 [info] Go to http://[::1]:8080
2022/10/03 17:19:32.705147 63690#1 [info] Go to http://[::1]:3001 (BETA)
2022/10/03 17:19:32.705156 63690#1 [info] Go to http://10.0.10.5:8080
2022/10/03 17:19:32.705166 63690#1 [info] Go to http://10.0.10.5:3001 (BETA)
2022/10/03 17:19:32.705175 63690#1 [info] Go to http://[2a06:a004:27:10:a2d0:37dd:e168:1962]:8080
2022/10/03 17:19:32.705184 63690#1 [info] Go to http://[2a06:a004:27:10:a2d0:37dd:e168:1962]:3001 (BETA)
2022/10/03 17:19:32.705194 63690#1 [info] Go to http://[2a06:a004:27:10:c5bd:ef2a:7c46:dfe2]:8080
2022/10/03 17:19:32.705203 63690#1 [info] Go to http://[2a06:a004:27:10:c5bd:ef2a:7c46:dfe2]:3001 (BETA)
2022/10/03 17:19:32.786534 63690#69 [debug] initialized filtering engine
2022/10/03 17:19:32.786570 63690#69 [info] Starting the DNS proxy server
2022/10/03 17:19:32.786581 63690#69 [info] Ratelimit is enabled and set to 20 rps
2022/10/03 17:19:32.786588 63690#69 [info] The server is configured to refuse ANY requests
2022/10/03 17:19:32.786596 63690#69 [info] MaxGoroutines is set to 300
2022/10/03 17:19:32.786619 63690#69 [info] Creating the UDP server socket
2022/10/03 17:19:32.786679 63690#69 [info] Listening to udp://[::]:5354
2022/10/03 17:19:32.786694 63690#69 [info] Creating a TCP server socket
2022/10/03 17:19:32.786705 63690#9 [debug] clients: removed 0 client aliases
2022/10/03 17:19:32.786717 63690#69 [info] Listening to tcp://[::]:5354
2022/10/03 17:19:32.786724 63690#9 [debug] clients: added 10.0.10.1 -> "" [4]
2022/10/03 17:19:32.786733 63690#9 [debug] clients: added 1 client aliases from arp neighborhood
2022/10/03 17:19:32.786769 63690#10 [info] Entering the UDP listener loop on [::]:5354
2022/10/03 17:19:32.786773 63690#11 [info] Entering the tcp listener loop on [::]:5354
2022/10/03 17:19:32.786813 63690#15 [debug] querylog: no log to rotate
2022/10/03 17:19:32.786824 63690#15 [debug] querylog: rotated successfully
2022/10/03 17:19:32.786842 63690#13 [debug] filtering: updating...
2022/10/03 17:19:32.786892 63690#13 [debug] checking list at index 0: &{true https://adguardteam.github.io/AdGuardSDNSFilter/Filters/filter.txt AdGuard DNS filter 49650 2022-10-03 17:19:06.972450054 +0530 IST 132472387 false { [] 1}}
2022/10/03 17:19:32.786909 63690#13 [debug] checking list at index 1: &{false https://adaway.org/hosts.txt AdAway Default Blocklist 0 0001-01-01 00:00:00 +0000 UTC 0 false { [] 2}}
2022/10/03 17:19:32.786918 63690#13 [debug] filtering: update finished
2022/10/03 17:19:34.742642 63690#16 [debug] started GET localhost:8080 /control/status
2022/10/03 17:19:34.743195 63690#16 [debug] finished GET localhost:8080 /control/status in 555.979µs
2022/10/03 17:19:34.782367 63690#16 [debug] started GET localhost:8080 /control/access/list
2022/10/03 17:19:34.782460 63690#16 [debug] finished GET localhost:8080 /control/access/list in 95.676µs
2022/10/03 17:19:34.782460 63690#42 [debug] started GET localhost:8080 /control/stats
2022/10/03 17:19:34.782526 63690#42 [debug] stats: prepared data in 21.249µs
2022/10/03 17:19:34.782618 63690#42 [debug] finished GET localhost:8080 /control/stats in 178.073µs
2022/10/03 17:19:34.782653 63690#16 [debug] started GET localhost:8080 /control/stats_info
2022/10/03 17:19:34.782691 63690#16 [debug] finished GET localhost:8080 /control/stats_info in 42.539µs
2022/10/03 17:19:34.784983 63690#42 [debug] started GET localhost:8080 /control/tls/status
2022/10/03 17:19:34.785119 63690#42 [debug] finished GET localhost:8080 /control/tls/status in 137.925µs
2022/10/03 17:19:34.785461 63690#16 [debug] started GET localhost:8080 /control/profile
2022/10/03 17:19:34.785492 63690#16 [debug] finished GET localhost:8080 /control/profile in 33.659µs
2022/10/03 17:19:34.797964 63690#16 [debug] started GET localhost:8080 /control/clients/find?
2022/10/03 17:19:34.798063 63690#16 [debug] finished GET localhost:8080 /control/clients/find? in 118.546µs
2022/10/03 17:19:37.299536 63690#16 [debug] started GET localhost:8080 /control/blocked_services/list
2022/10/03 17:19:37.299570 63690#16 [debug] finished GET localhost:8080 /control/blocked_services/list in 55.698µs
2022/10/03 17:19:39.434884 63690#16 [debug] started POST localhost:8080 /control/blocked_services/set
2022/10/03 17:19:39.434958 63690#16 [debug] Updated blocked services list: 36
2022/10/03 17:19:39.435007 63690#16 [debug] writing config file "/home/ishan/adguardhome/AdGuardHome.yaml"
2022/10/03 17:19:39.445129 63690#16 [debug] finished POST localhost:8080 /control/blocked_services/set in 10.26267ms
2022/10/03 17:19:39.463845 63690#16 [debug] started GET localhost:8080 /control/blocked_services/list
2022/10/03 17:19:39.463912 63690#16 [debug] finished GET localhost:8080 /control/blocked_services/list in 89.267µs
2022/10/03 17:19:43.362715 63690#99 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:55900
2022/10/03 17:19:43.362774 63690#99 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 24160
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: c45f18e210184a1e

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:19:43.362870 63690#99 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:43.362894 63690#99 [debug] applying filters: no clients with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:43.362921 63690#99 [debug] hosts container: handling the request
2022/10/03 17:19:43.363098 63690#99 [debug] blocked services: matched rule: ||cloudflare.com^  host: cloudflare.com  service: cloudflare
2022/10/03 17:19:43.363126 63690#99 [debug] github.com/AdguardTeam/AdGuardHome/internal/dnsforward.(*Server).filterDNSRequest(): host "cloudflare.com" is filtered, reason "FilteredBlockedService", rule: "||cloudflare.com^"
2022/10/03 17:19:43.363146 63690#99 [debug] client ip: 127.0.0.1
2022/10/03 17:19:43.363179 63690#99 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 24160
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	10	IN	A	0.0.0.0

2022/10/03 17:19:44.446173 63690#114 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:32844
2022/10/03 17:19:44.446230 63690#114 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 17039
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: 1d8d22f94f579e5e

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:19:44.446316 63690#114 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:44.446341 63690#114 [debug] applying filters: no clients with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:44.446372 63690#114 [debug] hosts container: handling the request
2022/10/03 17:19:44.446421 63690#114 [debug] blocked services: matched rule: ||cloudflare.com^  host: cloudflare.com  service: cloudflare
2022/10/03 17:19:44.446444 63690#114 [debug] github.com/AdguardTeam/AdGuardHome/internal/dnsforward.(*Server).filterDNSRequest(): host "cloudflare.com" is filtered, reason "FilteredBlockedService", rule: "||cloudflare.com^"
2022/10/03 17:19:44.446467 63690#114 [debug] client ip: 127.0.0.1
2022/10/03 17:19:44.446504 63690#114 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 17039
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	10	IN	A	0.0.0.0

2022/10/03 17:19:44.821367 63690#101 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:50997
2022/10/03 17:19:44.821408 63690#101 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 3077
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: bf75b682a5e72e71

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:19:44.821487 63690#101 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:44.821503 63690#101 [debug] applying filters: no clients with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:44.821527 63690#101 [debug] hosts container: handling the request
2022/10/03 17:19:44.821566 63690#101 [debug] blocked services: matched rule: ||cloudflare.com^  host: cloudflare.com  service: cloudflare
2022/10/03 17:19:44.821582 63690#101 [debug] github.com/AdguardTeam/AdGuardHome/internal/dnsforward.(*Server).filterDNSRequest(): host "cloudflare.com" is filtered, reason "FilteredBlockedService", rule: "||cloudflare.com^"
2022/10/03 17:19:44.821597 63690#101 [debug] client ip: 127.0.0.1
2022/10/03 17:19:44.821620 63690#101 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 3077
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	10	IN	A	0.0.0.0

2022/10/03 17:19:45.150194 63690#102 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:42898
2022/10/03 17:19:45.150232 63690#102 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 47948
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: e395f47f771bf9ee

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:19:45.150303 63690#102 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:45.150323 63690#102 [debug] applying filters: no clients with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:45.150349 63690#102 [debug] hosts container: handling the request
2022/10/03 17:19:45.150395 63690#102 [debug] blocked services: matched rule: ||cloudflare.com^  host: cloudflare.com  service: cloudflare
2022/10/03 17:19:45.150414 63690#102 [debug] github.com/AdguardTeam/AdGuardHome/internal/dnsforward.(*Server).filterDNSRequest(): host "cloudflare.com" is filtered, reason "FilteredBlockedService", rule: "||cloudflare.com^"
2022/10/03 17:19:45.150431 63690#102 [debug] client ip: 127.0.0.1
2022/10/03 17:19:45.150456 63690#102 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 47948
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	10	IN	A	0.0.0.0

2022/10/03 17:19:45.486552 63690#103 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:59995
2022/10/03 17:19:45.486589 63690#103 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 32401
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: dc52b8fbdf7cade4

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:19:45.486657 63690#103 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:45.486678 63690#103 [debug] applying filters: no clients with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:45.486702 63690#103 [debug] hosts container: handling the request
2022/10/03 17:19:45.486750 63690#103 [debug] blocked services: matched rule: ||cloudflare.com^  host: cloudflare.com  service: cloudflare
2022/10/03 17:19:45.486768 63690#103 [debug] github.com/AdguardTeam/AdGuardHome/internal/dnsforward.(*Server).filterDNSRequest(): host "cloudflare.com" is filtered, reason "FilteredBlockedService", rule: "||cloudflare.com^"
2022/10/03 17:19:45.486786 63690#103 [debug] client ip: 127.0.0.1
2022/10/03 17:19:45.486812 63690#103 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 32401
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	10	IN	A	0.0.0.0

2022/10/03 17:19:48.220591 63690#16 [debug] started POST localhost:8080 /control/blocked_services/set
2022/10/03 17:19:48.220664 63690#16 [debug] Updated blocked services list: 0
2022/10/03 17:19:48.220733 63690#16 [debug] writing config file "/home/ishan/adguardhome/AdGuardHome.yaml"
2022/10/03 17:19:48.231218 63690#16 [debug] finished POST localhost:8080 /control/blocked_services/set in 10.655614ms
2022/10/03 17:19:48.254436 63690#16 [debug] started GET localhost:8080 /control/blocked_services/list
2022/10/03 17:19:48.254484 63690#16 [debug] finished GET localhost:8080 /control/blocked_services/list in 80.057µs
2022/10/03 17:19:49.238510 63690#117 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:60032
2022/10/03 17:19:49.238543 63690#117 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 33850
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: d4a14fc23b31f5ce

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:19:49.238597 63690#117 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:49.238614 63690#117 [debug] applying filters: no clients with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:49.238636 63690#117 [debug] hosts container: handling the request
2022/10/03 17:19:49.238707 63690#104 [debug] 9.9.9.10:53: sending request A dns10.quad9.net.
2022/10/03 17:19:49.238720 63690#123 [debug] [2620:fe::fe:10]:53: sending request AAAA dns10.quad9.net.
2022/10/03 17:19:49.238724 63690#105 [debug] 9.9.9.10:53: sending request AAAA dns10.quad9.net.
2022/10/03 17:19:49.238743 63690#129 [debug] 149.112.112.10:53: sending request A dns10.quad9.net.
2022/10/03 17:19:49.238744 63690#130 [debug] 149.112.112.10:53: sending request AAAA dns10.quad9.net.
2022/10/03 17:19:49.238754 63690#58 [debug] [2620:fe::10]:53: sending request AAAA dns10.quad9.net.
2022/10/03 17:19:49.238850 63690#122 [debug] [2620:fe::fe:10]:53: sending request A dns10.quad9.net.
2022/10/03 17:19:49.238853 63690#57 [debug] [2620:fe::10]:53: sending request A dns10.quad9.net.
2022/10/03 17:19:49.240286 63690#105 [debug] 9.9.9.10:53: response: ok
2022/10/03 17:19:49.240463 63690#104 [debug] 9.9.9.10:53: response: ok
2022/10/03 17:19:49.240506 63690#118 [debug] github.com/AdguardTeam/dnsproxy/upstream.lookup(): successfully finished lookup for dns10.quad9.net in 1.795032ms using 9.9.9.10. Result : [{9.9.9.10 } {149.112.112.10 } {2620:fe::10 } {2620:fe::fe:10 }]
2022/10/03 17:19:49.240546 63690#117 [debug] https://dns10.quad9.net:443/dns-query: sending request A cloudflare.com.
2022/10/03 17:19:49.240602 63690#74 [debug] github.com/AdguardTeam/dnsproxy/upstream.(*bootstrapper).createDialContext.func1(): Dialing to 9.9.9.10:443
2022/10/03 17:19:49.240722 63690#129 [debug] 149.112.112.10:53: response: ok
2022/10/03 17:19:49.240895 63690#130 [debug] 149.112.112.10:53: response: ok
2022/10/03 17:19:49.240945 63690#119 [debug] github.com/AdguardTeam/dnsproxy/upstream.lookup(): successfully finished lookup for dns10.quad9.net in 2.213756ms using 149.112.112.10. Result : [{9.9.9.10 } {149.112.112.10 } {2620:fe::10 } {2620:fe::fe:10 }]
2022/10/03 17:19:49.286883 63690#74 [debug] github.com/AdguardTeam/dnsproxy/upstream.(*bootstrapper).createDialContext.func1(): dialer has successfully initialized connection to 9.9.9.10:443 in 46.209784ms
2022/10/03 17:19:49.892608 63690#117 [debug] https://dns10.quad9.net:443/dns-query: response: ok
2022/10/03 17:19:49.892650 63690#117 [debug] time.Duration.Milliseconds(): upstream https://dns10.quad9.net:443/dns-query successfully finished exchange of ;cloudflare.com.	IN	 A. Elapsed 653.96711ms.
2022/10/03 17:19:49.892672 63690#117 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).replyFromUpstream(): RTT: 654.002398ms
2022/10/03 17:19:49.892697 63690#117 [debug] dnsforward: checking A 104.16.133.229 for cloudflare.com.
2022/10/03 17:19:49.892732 63690#117 [debug] dnsforward: checking A 104.16.132.229 for cloudflare.com.
2022/10/03 17:19:49.892755 63690#117 [debug] client ip: 127.0.0.1
2022/10/03 17:19:49.892789 63690#117 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 33850
;; flags: qr rd ra ad; QUERY: 1, ANSWER: 2, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	300	IN	A	104.16.133.229
cloudflare.com.	300	IN	A	104.16.132.229

2022/10/03 17:19:52.986022 63690#16 [debug] started POST localhost:8080 /control/blocked_services/set
2022/10/03 17:19:52.986101 63690#16 [debug] Updated blocked services list: 36
2022/10/03 17:19:52.986160 63690#16 [debug] writing config file "/home/ishan/adguardhome/AdGuardHome.yaml"
2022/10/03 17:19:52.996409 63690#16 [debug] finished POST localhost:8080 /control/blocked_services/set in 10.404513ms
2022/10/03 17:19:53.017343 63690#16 [debug] started GET localhost:8080 /control/blocked_services/list
2022/10/03 17:19:53.017400 63690#16 [debug] finished GET localhost:8080 /control/blocked_services/list in 78.527µs
2022/10/03 17:19:53.974345 63690#163 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:38592
2022/10/03 17:19:53.974411 63690#163 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 6241
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: b47be5a9e78b7813

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:19:53.974522 63690#163 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:53.974560 63690#163 [debug] applying filters: no clients with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:53.974607 63690#163 [debug] hosts container: handling the request
2022/10/03 17:19:53.974680 63690#163 [debug] blocked services: matched rule: ||cloudflare.com^  host: cloudflare.com  service: cloudflare
2022/10/03 17:19:53.974719 63690#163 [debug] github.com/AdguardTeam/AdGuardHome/internal/dnsforward.(*Server).filterDNSRequest(): host "cloudflare.com" is filtered, reason "FilteredBlockedService", rule: "||cloudflare.com^"
2022/10/03 17:19:53.974753 63690#163 [debug] client ip: 127.0.0.1
2022/10/03 17:19:53.974801 63690#163 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 6241
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	10	IN	A	0.0.0.0

2022/10/03 17:19:54.461965 63690#164 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:48155
2022/10/03 17:19:54.462001 63690#164 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 58829
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: 85ff2de204a4a876

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:19:54.462060 63690#164 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:54.462075 63690#164 [debug] applying filters: no clients with ip 127.0.0.1 and clientid ""
2022/10/03 17:19:54.462096 63690#164 [debug] hosts container: handling the request
2022/10/03 17:19:54.462131 63690#164 [debug] blocked services: matched rule: ||cloudflare.com^  host: cloudflare.com  service: cloudflare
2022/10/03 17:19:54.462147 63690#164 [debug] github.com/AdguardTeam/AdGuardHome/internal/dnsforward.(*Server).filterDNSRequest(): host "cloudflare.com" is filtered, reason "FilteredBlockedService", rule: "||cloudflare.com^"
2022/10/03 17:19:54.462162 63690#164 [debug] client ip: 127.0.0.1
2022/10/03 17:19:54.462182 63690#164 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 58829
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	10	IN	A	0.0.0.0

2022/10/03 17:19:56.890669 63690#16 [debug] started GET localhost:8080 /control/clients
2022/10/03 17:19:56.890814 63690#16 [debug] finished GET localhost:8080 /control/clients in 171.084µs
2022/10/03 17:19:56.890820 63690#42 [debug] started GET localhost:8080 /control/stats
2022/10/03 17:19:56.890886 63690#42 [debug] stats: prepared data in 21.239µs
2022/10/03 17:19:56.890942 63690#42 [debug] finished GET localhost:8080 /control/stats in 132.195µs
2022/10/03 17:19:56.907721 63690#16 [debug] started GET localhost:8080 /control/clients/find?ip0=127.0.0.1
2022/10/03 17:19:56.907838 63690#16 [debug] finished GET localhost:8080 /control/clients/find?ip0=127.0.0.1 in 156.944µs
2022/10/03 17:19:59.239216 63690#57 [debug] [2620:fe::10]:53: response: read udp [2a06:a004:27:10:a2d0:37dd:e168:1962]:59841->[2620:fe::10]:53: i/o timeout
2022/10/03 17:19:59.239230 63690#122 [debug] [2620:fe::fe:10]:53: response: read udp [2a06:a004:27:10:a2d0:37dd:e168:1962]:50365->[2620:fe::fe:10]:53: i/o timeout
2022/10/03 17:19:59.239238 63690#123 [debug] [2620:fe::fe:10]:53: response: read udp [2a06:a004:27:10:a2d0:37dd:e168:1962]:36817->[2620:fe::fe:10]:53: i/o timeout
2022/10/03 17:19:59.239280 63690#121 [debug] github.com/AdguardTeam/dnsproxy/upstream.lookup(): failed to lookup for dns10.quad9.net in 10.000563312s using 2620:fe::fe:10: read udp [2a06:a004:27:10:a2d0:37dd:e168:1962]:50365->[2620:fe::fe:10]:53: i/o timeout
2022/10/03 17:19:59.239231 63690#58 [debug] [2620:fe::10]:53: response: read udp [2a06:a004:27:10:a2d0:37dd:e168:1962]:56266->[2620:fe::10]:53: i/o timeout
2022/10/03 17:19:59.239306 63690#120 [debug] github.com/AdguardTeam/dnsproxy/upstream.lookup(): failed to lookup for dns10.quad9.net in 10.000588422s using 2620:fe::10: read udp [2a06:a004:27:10:a2d0:37dd:e168:1962]:59841->[2620:fe::10]:53: i/o timeout
2022/10/03 17:20:06.464655 63690#16 [debug] started POST localhost:8080 /control/clients/add
2022/10/03 17:20:06.464747 63690#16 [debug] clients: added "test": ID:["127.0.0.0/8"] [1]
2022/10/03 17:20:06.464809 63690#16 [debug] writing config file "/home/ishan/adguardhome/AdGuardHome.yaml"
2022/10/03 17:20:06.469930 63690#16 [debug] finished POST localhost:8080 /control/clients/add in 5.306388ms
2022/10/03 17:20:06.507887 63690#16 [debug] started GET localhost:8080 /control/clients
2022/10/03 17:20:06.507981 63690#16 [debug] finished GET localhost:8080 /control/clients in 118.706µs
2022/10/03 17:20:10.278494 63690#166 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:45299
2022/10/03 17:20:10.278524 63690#166 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 1436
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: 21c275e20734efeb

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:20:10.278578 63690#166 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:20:10.278593 63690#166 [debug] applying filters: using settings for client "test" (127.0.0.1; "")
2022/10/03 17:20:10.278613 63690#166 [debug] hosts container: handling the request
2022/10/03 17:20:10.278643 63690#166 [debug] blocked services: matched rule: ||cloudflare.com^  host: cloudflare.com  service: cloudflare
2022/10/03 17:20:10.278656 63690#166 [debug] github.com/AdguardTeam/AdGuardHome/internal/dnsforward.(*Server).filterDNSRequest(): host "cloudflare.com" is filtered, reason "FilteredBlockedService", rule: "||cloudflare.com^"
2022/10/03 17:20:10.278667 63690#166 [debug] client ip: 127.0.0.1
2022/10/03 17:20:10.278685 63690#166 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 1436
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	10	IN	A	0.0.0.0

2022/10/03 17:20:10.990419 63690#124 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:53482
2022/10/03 17:20:10.990463 63690#124 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 55940
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: 8f1743f253d5e694

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:20:10.990526 63690#124 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:20:10.990543 63690#124 [debug] applying filters: using settings for client "test" (127.0.0.1; "")
2022/10/03 17:20:10.990569 63690#124 [debug] hosts container: handling the request
2022/10/03 17:20:10.990622 63690#124 [debug] blocked services: matched rule: ||cloudflare.com^  host: cloudflare.com  service: cloudflare
2022/10/03 17:20:10.990637 63690#124 [debug] github.com/AdguardTeam/AdGuardHome/internal/dnsforward.(*Server).filterDNSRequest(): host "cloudflare.com" is filtered, reason "FilteredBlockedService", rule: "||cloudflare.com^"
2022/10/03 17:20:10.990652 63690#124 [debug] client ip: 127.0.0.1
2022/10/03 17:20:10.990674 63690#124 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 55940
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	10	IN	A	0.0.0.0

2022/10/03 17:20:11.524278 63690#125 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:38573
2022/10/03 17:20:11.524321 63690#125 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 6245
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: 831668bb56c938d7

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:20:11.524400 63690#125 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:20:11.524429 63690#125 [debug] applying filters: using settings for client "test" (127.0.0.1; "")
2022/10/03 17:20:11.524464 63690#125 [debug] hosts container: handling the request
2022/10/03 17:20:11.524513 63690#125 [debug] blocked services: matched rule: ||cloudflare.com^  host: cloudflare.com  service: cloudflare
2022/10/03 17:20:11.524538 63690#125 [debug] github.com/AdguardTeam/AdGuardHome/internal/dnsforward.(*Server).filterDNSRequest(): host "cloudflare.com" is filtered, reason "FilteredBlockedService", rule: "||cloudflare.com^"
2022/10/03 17:20:11.524561 63690#125 [debug] client ip: 127.0.0.1
2022/10/03 17:20:11.524593 63690#125 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 6245
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	10	IN	A	0.0.0.0

2022/10/03 17:20:12.079074 63690#167 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:56843
2022/10/03 17:20:12.079108 63690#167 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 64688
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: 5478dbb7863db9c3

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:20:12.079176 63690#167 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:20:12.079195 63690#167 [debug] applying filters: using settings for client "test" (127.0.0.1; "")
2022/10/03 17:20:12.079222 63690#167 [debug] hosts container: handling the request
2022/10/03 17:20:12.079259 63690#167 [debug] blocked services: matched rule: ||cloudflare.com^  host: cloudflare.com  service: cloudflare
2022/10/03 17:20:12.079273 63690#167 [debug] github.com/AdguardTeam/AdGuardHome/internal/dnsforward.(*Server).filterDNSRequest(): host "cloudflare.com" is filtered, reason "FilteredBlockedService", rule: "||cloudflare.com^"
2022/10/03 17:20:12.079287 63690#167 [debug] client ip: 127.0.0.1
2022/10/03 17:20:12.079310 63690#167 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 64688
;; flags: qr rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	10	IN	A	0.0.0.0

2022/10/03 17:20:14.248732 63690#16 [debug] started GET localhost:8080 /control/querylog?search=&response_status=&older_than=&limit=20
2022/10/03 17:20:14.248751 63690#42 [debug] started GET localhost:8080 /control/filtering/status
2022/10/03 17:20:14.248809 63690#16 [debug] querylog: prepared data (12/12) older than 0001-01-01 00:00:00 +0000 UTC in 32.429µs
2022/10/03 17:20:14.248856 63690#42 [debug] finished GET localhost:8080 /control/filtering/status in 115.656µs
2022/10/03 17:20:14.249080 63690#42 [debug] started GET localhost:8080 /control/clients
2022/10/03 17:20:14.249146 63690#42 [debug] finished GET localhost:8080 /control/clients in 80.007µs
2022/10/03 17:20:14.249462 63690#16 [debug] finished GET localhost:8080 /control/querylog?search=&response_status=&older_than=&limit=20 in 738.532µs
2022/10/03 17:20:14.250888 63690#16 [debug] started GET localhost:8080 /control/querylog_info
2022/10/03 17:20:14.250937 63690#16 [debug] finished GET localhost:8080 /control/querylog_info in 52.558µs
2022/10/03 17:20:14.251412 63690#16 [debug] started GET localhost:8080 /control/dns_info
2022/10/03 17:20:14.251490 63690#42 [debug] started GET localhost:8080 /control/access/list
2022/10/03 17:20:14.251519 63690#42 [debug] finished GET localhost:8080 /control/access/list in 32.349µs
2022/10/03 17:20:14.251869 63690#16 [debug] finished GET localhost:8080 /control/dns_info in 459.183µs
2022/10/03 17:20:14.252022 63690#42 [debug] started GET localhost:8080 /control/querylog?older_than=&limit=20
2022/10/03 17:20:14.252085 63690#42 [debug] querylog: prepared data (12/12) older than 0001-01-01 00:00:00 +0000 UTC in 23.239µs
2022/10/03 17:20:14.252341 63690#42 [debug] finished GET localhost:8080 /control/querylog?older_than=&limit=20 in 319.198µs
2022/10/03 17:20:15.099801 63690#16 [debug] started GET localhost:8080 /control/querylog?older_than=2022-10-03T17%3A19%3A43.363149893%2B05%3A30&limit=20
2022/10/03 17:20:15.099868 63690#16 [debug] querylog: cannot seek to 2022-10-03 17:19:43.363149893 +0530 IST: EOF
2022/10/03 17:20:15.099906 63690#16 [debug] querylog: prepared data (0/12) older than 2022-10-03 17:19:43.363149893 +0530 IST in 63.757µs
2022/10/03 17:20:15.099938 63690#16 [debug] finished GET localhost:8080 /control/querylog?older_than=2022-10-03T17%3A19%3A43.363149893%2B05%3A30&limit=20 in 175.503µs
2022/10/03 17:20:25.706306 63690#16 [debug] started GET localhost:8080 /control/querylog?search=&response_status=&older_than=&limit=20
2022/10/03 17:20:25.706383 63690#16 [debug] querylog: prepared data (12/12) older than 0001-01-01 00:00:00 +0000 UTC in 30.069µs
2022/10/03 17:20:25.706461 63690#42 [debug] started GET localhost:8080 /control/clients
2022/10/03 17:20:25.706515 63690#42 [debug] finished GET localhost:8080 /control/clients in 62.257µs
2022/10/03 17:20:25.706637 63690#16 [debug] finished GET localhost:8080 /control/querylog?search=&response_status=&older_than=&limit=20 in 353.727µs
2022/10/03 17:20:25.706710 63690#42 [debug] started GET localhost:8080 /control/stats
2022/10/03 17:20:25.706749 63690#42 [debug] stats: prepared data in 15.759µs
2022/10/03 17:20:25.706781 63690#42 [debug] finished GET localhost:8080 /control/stats in 74.897µs
2022/10/03 17:20:25.716563 63690#16 [debug] started GET localhost:8080 /control/clients/find?ip0=127.0.0.1
2022/10/03 17:20:25.716614 63690#16 [debug] finished GET localhost:8080 /control/clients/find?ip0=127.0.0.1 in 69.907µs
2022/10/03 17:20:33.153749 63690#16 [debug] started POST localhost:8080 /control/clients/update
2022/10/03 17:20:33.153876 63690#16 [debug] writing config file "/home/ishan/adguardhome/AdGuardHome.yaml"
2022/10/03 17:20:33.163267 63690#16 [debug] finished POST localhost:8080 /control/clients/update in 9.51324ms
2022/10/03 17:20:33.193300 63690#16 [debug] started GET localhost:8080 /control/clients
2022/10/03 17:20:33.193354 63690#16 [debug] finished GET localhost:8080 /control/clients in 81.647µs
2022/10/03 17:20:34.413359 63690#62 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:33729
2022/10/03 17:20:34.413409 63690#62 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 40198
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: 6d21c479f8205ffe

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:20:34.413494 63690#62 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:20:34.413524 63690#62 [debug] applying filters: using settings for client "test" (127.0.0.1; "")
2022/10/03 17:20:34.413556 63690#62 [debug] hosts container: handling the request
2022/10/03 17:20:34.413610 63690#62 [debug] https://dns10.quad9.net:443/dns-query: sending request A cloudflare.com.
2022/10/03 17:20:34.413687 63690#64 [debug] github.com/AdguardTeam/dnsproxy/upstream.(*bootstrapper).createDialContext.func1(): Dialing to 9.9.9.10:443
2022/10/03 17:20:34.611955 63690#64 [debug] github.com/AdguardTeam/dnsproxy/upstream.(*bootstrapper).createDialContext.func1(): dialer has successfully initialized connection to 9.9.9.10:443 in 198.211712ms
2022/10/03 17:20:34.995008 63690#62 [debug] https://dns10.quad9.net:443/dns-query: response: ok
2022/10/03 17:20:34.995054 63690#62 [debug] time.Duration.Milliseconds(): upstream https://dns10.quad9.net:443/dns-query successfully finished exchange of ;cloudflare.com.	IN	 A. Elapsed 581.440549ms.
2022/10/03 17:20:34.995083 63690#62 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).replyFromUpstream(): RTT: 581.479278ms
2022/10/03 17:20:34.995109 63690#62 [debug] dnsforward: checking A 104.16.132.229 for cloudflare.com.
2022/10/03 17:20:34.995146 63690#62 [debug] dnsforward: checking A 104.16.133.229 for cloudflare.com.
2022/10/03 17:20:34.995172 63690#62 [debug] client ip: 127.0.0.1
2022/10/03 17:20:34.995210 63690#62 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 40198
;; flags: qr rd ra ad; QUERY: 1, ANSWER: 2, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	39	IN	A	104.16.132.229
cloudflare.com.	39	IN	A	104.16.133.229

2022/10/03 17:20:35.652871 63690#180 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpHandlePacket(): Start handling new UDP packet from 127.0.0.1:36776
2022/10/03 17:20:35.652902 63690#180 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): IN: ;; opcode: QUERY, status: NOERROR, id: 6146
;; flags: rd ad; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232
; COOKIE: b43635ee57c46836

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

2022/10/03 17:20:35.652958 63690#180 [debug] applying filters: looking for client with ip 127.0.0.1 and clientid ""
2022/10/03 17:20:35.652972 63690#180 [debug] applying filters: using settings for client "test" (127.0.0.1; "")
2022/10/03 17:20:35.652991 63690#180 [debug] hosts container: handling the request
2022/10/03 17:20:35.653023 63690#180 [debug] https://dns10.quad9.net:443/dns-query: sending request A cloudflare.com.
2022/10/03 17:20:36.096536 63690#180 [debug] https://dns10.quad9.net:443/dns-query: response: ok
2022/10/03 17:20:36.096581 63690#180 [debug] time.Duration.Milliseconds(): upstream https://dns10.quad9.net:443/dns-query successfully finished exchange of ;cloudflare.com.	IN	 A. Elapsed 443.539411ms.
2022/10/03 17:20:36.096598 63690#180 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).replyFromUpstream(): RTT: 443.57733ms
2022/10/03 17:20:36.096618 63690#180 [debug] dnsforward: checking A 104.16.133.229 for cloudflare.com.
2022/10/03 17:20:36.096649 63690#180 [debug] dnsforward: checking A 104.16.132.229 for cloudflare.com.
2022/10/03 17:20:36.096667 63690#180 [debug] client ip: 127.0.0.1
2022/10/03 17:20:36.096694 63690#180 [debug] github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).logDNSMessage(): OUT: ;; opcode: QUERY, status: NOERROR, id: 6146
;; flags: qr rd ra ad; QUERY: 1, ANSWER: 2, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version 0; flags: ; udp: 1232

;; QUESTION SECTION:
;cloudflare.com.	IN	 A

;; ANSWER SECTION:
cloudflare.com.	300	IN	A	104.16.133.229
cloudflare.com.	300	IN	A	104.16.132.229

^C2022/10/03 17:20:42.087175 63690#18 [info] Received signal "interrupt"
2022/10/03 17:20:42.087200 63690#18 [info] stopping AdGuard Home
2022/10/03 17:20:42.087212 63690#18 [info] stopping http server...
2022/10/03 17:20:42.087401 63690#18 [info] stopped http server
2022/10/03 17:20:42.087453 63690#18 [info] Stopping the DNS proxy server
2022/10/03 17:20:42.087493 63690#11 [debug] tcpPacketLoop: connection closed: accept tcp [::]:5354: use of closed network connection
2022/10/03 17:20:42.087521 63690#10 [debug] udpPacketLoop: connection closed
2022/10/03 17:20:42.087540 63690#18 [info] Stopped the DNS proxy server
2022/10/03 17:20:42.087562 63690#18 [debug] stats: flushing unit with id 462443 and total of 14
2022/10/03 17:20:42.095813 63690#18 [debug] stats: database closed
2022/10/03 17:20:42.095987 63690#18 [debug] 14 elements serialized via json in 152.014µs: 4 kB, 324.42857142857144/entry, 10.858µs/entry
2022/10/03 17:20:42.096054 63690#18 [debug] querylog: ok "/home/ishan/adguardhome/data/querylog.json": 4542 bytes written
2022/10/03 17:20:42.096067 63690#18 [debug] all dns modules are closed
2022/10/03 17:20:42.096081 63690#18 [debug] dhcpv6 ra: closing
2022/10/03 17:20:42.096161 63690#22 [debug] hosts container: watcher closed the events channel
2022/10/03 17:20:42.096176 63690#18 [debug] hosts container: closing
2022/10/03 17:20:42.096192 63690#18 [info] Stopped
Configuration file
bind_host: 0.0.0.0
bind_port: 8080
beta_bind_port: 3001
users:
  - name: admin
    password: $2a$10$JQPLc6ygptxZU6bTU2fMVOPyHcW5G5/f01QoUH0pG9iz3aoscadDq
auth_attempts: 5
block_auth_min: 15
http_proxy: ""
language: ""
debug_pprof: false
web_session_ttl: 720
dns:
  bind_hosts:
    - 0.0.0.0
  port: 5354
  statistics_interval: 1
  querylog_enabled: true
  querylog_file_enabled: true
  querylog_interval: 2160h
  querylog_size_memory: 1000
  anonymize_client_ip: false
  protection_enabled: true
  blocking_mode: default
  blocking_ipv4: ""
  blocking_ipv6: ""
  blocked_response_ttl: 10
  parental_block_host: family-block.dns.adguard.com
  safebrowsing_block_host: standard-block.dns.adguard.com
  ratelimit: 20
  ratelimit_whitelist: []
  refuse_any: true
  upstream_dns:
    - https://dns10.quad9.net/dns-query
  upstream_dns_file: ""
  bootstrap_dns:
    - 9.9.9.10
    - 149.112.112.10
    - 2620:fe::10
    - 2620:fe::fe:10
  all_servers: false
  fastest_addr: false
  fastest_timeout: 1s
  allowed_clients: []
  disallowed_clients: []
  blocked_hosts:
    - version.bind
    - id.server
    - hostname.bind
  trusted_proxies:
    - 127.0.0.0/8
    - ::1/128
  cache_size: 0
  cache_ttl_min: 0
  cache_ttl_max: 0
  cache_optimistic: false
  bogus_nxdomain: []
  aaaa_disabled: false
  enable_dnssec: false
  edns_client_subnet: false
  max_goroutines: 300
  handle_ddr: true
  ipset: []
  ipset_file: ""
  filtering_enabled: true
  filters_update_interval: 24
  parental_enabled: false
  safesearch_enabled: false
  safebrowsing_enabled: false
  safebrowsing_cache_size: 1048576
  safesearch_cache_size: 1048576
  parental_cache_size: 1048576
  cache_time: 30
  rewrites: []
  blocked_services:
    - 9gag
    - amazon
    - bilibili
    - cloudflare
    - dailymotion
    - discord
    - disneyplus
    - ebay
    - epic_games
    - facebook
    - hulu
    - imgur
    - instagram
    - mail_ru
    - netflix
    - ok
    - origin
    - pinterest
    - qq
    - reddit
    - skype
    - snapchat
    - spotify
    - steam
    - telegram
    - tiktok
    - tinder
    - twitch
    - twitter
    - viber
    - vimeo
    - vk
    - wechat
    - weibo
    - whatsapp
    - youtube
  upstream_timeout: 10s
  private_networks: []
  use_private_ptr_resolvers: true
  local_ptr_upstreams: []
tls:
  enabled: false
  server_name: ""
  force_https: false
  port_https: 443
  port_dns_over_tls: 853
  port_dns_over_quic: 853
  port_dnscrypt: 0
  dnscrypt_config_file: ""
  allow_unencrypted_doh: false
  strict_sni_check: false
  certificate_chain: ""
  private_key: ""
  certificate_path: ""
  private_key_path: ""
filters:
  - enabled: true
    url: https://adguardteam.github.io/AdGuardSDNSFilter/Filters/filter.txt
    name: AdGuard DNS filter
    id: 1
  - enabled: false
    url: https://adaway.org/hosts.txt
    name: AdAway Default Blocklist
    id: 2
whitelist_filters: []
user_rules: []
dhcp:
  enabled: false
  interface_name: ""
  local_domain_name: lan
  dhcpv4:
    gateway_ip: ""
    subnet_mask: ""
    range_start: ""
    range_end: ""
    lease_duration: 86400
    icmp_timeout_msec: 1000
    options: []
  dhcpv6:
    range_start: ""
    lease_duration: 86400
    ra_slaac_only: false
    ra_allow_slaac: false
clients:
  runtime_sources:
    whois: true
    arp: true
    rdns: true
    dhcp: true
    hosts: true
  persistent:
    - name: test
      tags: []
      ids:
        - 127.0.0.0/8
      blocked_services: []
      upstreams: []
      use_global_settings: true
      filtering_enabled: false
      parental_enabled: false
      safesearch_enabled: false
      safebrowsing_enabled: false
      use_global_blocked_services: false
log_file: ""
log_max_backups: 0
log_max_size: 100
log_max_age: 3
log_compress: false
log_localtime: false
verbose: true
os:
  group: ""
  user: ""
  rlimit_nofile: 0
schema_version: 14

@ishanjain28
Copy link
Contributor Author

In the PR, I have linked to the problematic line. A call to Context.filters.ApplyBlockedServices with nil parameter will add globally blocked services to the list of filters.

list = d.Config.BlockedServices

This call is made without checking if the client has opted to ignore global blocklists here.

Context.filters.ApplyBlockedServices(setts, nil)

@EugeneOne1
Copy link
Member

EugeneOne1 commented Oct 3, 2022

@ishanjain28, firstly, it's quite unsecure to post unredacted configuration file of AdGuard Home to the public space, I'd recommend that you at least change your password.

There are no issues with applying services' rules according to the log. It actually says that the client with address 127.0.0.1 couldn't be found, which is possibly a separate bug. So it just applies the global blocked services for unidentified client, which is an expected bahavior.

By the way, to give a feeedback on your PR, I'd say it introduces a bug, which makes AGH to not apply global services to the non-persistent clients' requests. The logic there is a bit convoluted and really requires attention to all the other parts.

As far as I can see, you've built the AdGuard Home yourself. Just to ensure, haven't you change any code in comparison with master branch before building? Could please also try it on our signed builds? Those may either be installed with the README.md script:

curl -s -S -L https://raw.githubusercontent.com/AdguardTeam/AdGuardHome/master/scripts/install.sh | sh -s -- -c edge -v

or downloaded directly from:

https://static.adtidy.org/adguardhome/edge/AdGuardHome_linux_amd64.tar.gz

(Replace the linux and amd64 parts with the corresponding values of yours)

If it reproduces there? Thanks.

@ishanjain28
Copy link
Contributor Author

Hey @EugeneOne1
Noted the comment on publishing unredacted logs.

You are right in that for the first few times, it says it couldn't find 127.0.0.1 in the clients list. This was because I had not added the client when I sent request the first few times.

I had also recorded a video of the whole process along with the logs. I have shared the logs above and the video is here, https://www.youtube.com/watch?v=48BUwk2ABDo

(I couldn't upload it here because of size constraints and the video was still processing when I posted the logs)

By the way, to give a feeedback on your PR, I'd say it introduces a bug, which makes AGH to not apply global services to the non-persistent clients' requests. The logic there is a bit convoluted and really requires attention to all the other parts.

I have tested this in my PR by removing the 127.0.0.0/8 client and,

  1. blocking all services and trying to resolve a domain. The domain is expected is blocked by AGH.
  2. Unblocked a service and tried to query a domain related to it and the domain was resolved correctly.

Lastly, This was on the most recent commit in the branch. I did not have any un-stashed changes when building the project.

adguard pushed a commit that referenced this issue Oct 3, 2022
Merge in DNS/adguard-home from 4983-fix-custom-svcs to master

Updates #4945.
Updates #4982.

* commit '739e0098ec127045197ea697bae78acb2bd2c729':
  all: imp code, wording
  home: fix empty svcs
  bugfix: Fixed bug which was causing clients to continue following global service blocks even when user opted to not do that
@EugeneOne1 EugeneOne1 reopened this Oct 3, 2022
@EugeneOne1 EugeneOne1 added bug P3: Medium and removed waiting for data Waiting for users to provide more data. labels Oct 3, 2022
@ainar-g ainar-g added this to the v0.107.15 milestone Oct 3, 2022
@EugeneOne1
Copy link
Member

EugeneOne1 commented Oct 3, 2022

@ishanjain28, well, after digging further, I can confirm the bug. It seems editing the client via UI (at runtime) sets inproper blocked services slice. You may have noticed we've merged your PR, but also modified it a bit. The latest edge build (as per HEAD) should now work as intended, could you please check it again?

UPD: the latest release version contains the fix as well.

@ishanjain28
Copy link
Contributor Author

Hey, It works perfectly for me now. Thank you!

@ainar-g ainar-g closed this as completed Oct 5, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants