search

AdguardTeam / AdGuardHome

Network-wide ads & trackers blocking DNS server
https://adguard.com/adguard-home.html
GNU General Public License v3.0
24.44k stars 1.77k forks source link

Crash after around 12 hours runtime #1073

Closed kaeltis closed 4 years ago

kaeltis commented 4 years ago

Issue Details

Expected Behavior

AdGuardHome should be running 24/7 without issues.

Actual Behavior

After about 12 hours of runtime, the DNS part seems to crash (it doesn't respond to queries anymore) while the Webinterface keeps working. After restarting the service it's working again.

I've attached the log, but I'm not sure if the error in the log is directly related, since it crashed before without outputting anything to the log.

Additional Information

2019/10/15 20:28:36 [info] Service control action: run
2019/10/15 20:28:36 [info] AdGuard Home, version v0.98.1-175-g4536, channel release

2019/10/15 20:28:36 [info] AdGuard Home is running as a service
2019/10/15 20:28:36 [info] Added 5 client aliases from /etc/hosts
2019/10/15 20:28:36 [info] Added 0 client aliases from 'arp -a' command output
2019/10/15 20:28:36 [info] AdGuard Home is available on the following addresses:
2019/10/15 20:28:36 [info] Go to http://127.0.0.1:80
2019/10/15 20:28:36 [info] Go to http://172.27.10.11:80
2019/10/15 20:28:36 [info] Upstream 0: https://1.1.1.1:443/dns-query
2019/10/15 20:28:36 [info] Upstream 1: https://1.0.0.1:443/dns-query
2019/10/15 20:28:36 [info] Starting the DNS proxy server
2019/10/15 20:28:36 [info] Ratelimit is enabled and set to 20 rps
2019/10/15 20:28:36 [info] The server is configured to refuse ANY requests
2019/10/15 20:28:36 [info] DNS cache is enabled
2019/10/15 20:28:36 [info] Creating the UDP server socket
2019/10/15 20:28:36 [info] Listening to udp://[::]:53
2019/10/15 20:28:36 [info] Creating the TCP server socket
2019/10/15 20:28:36 [info] Listening to tcp://[::]:53
2019/10/15 20:28:36 [info] Entering the UDP listener loop on [::]:53
2019/10/15 20:28:36 [info] Entering the tcp listener loop on [::]:53
2019/10/15 21:28:36 [info] Added 5 client aliases from /etc/hosts
2019/10/15 21:28:41 [info] Added 0 client aliases from 'arp -a' command output
2019/10/15 22:28:41 [info] Added 5 client aliases from /etc/hosts
2019/10/15 22:28:46 [info] Added 0 client aliases from 'arp -a' command output
2019/10/15 23:28:46 [info] Added 5 client aliases from /etc/hosts
2019/10/15 23:28:52 [info] Added 0 client aliases from 'arp -a' command output
2019/10/16 00:28:52 [info] Added 5 client aliases from /etc/hosts
2019/10/16 00:28:57 [info] Added 0 client aliases from 'arp -a' command output
2019/10/16 01:28:57 [info] Added 5 client aliases from /etc/hosts
2019/10/16 01:29:02 [info] Added 0 client aliases from 'arp -a' command output
2019/10/16 02:29:02 [info] Added 5 client aliases from /etc/hosts
2019/10/16 02:29:08 [info] Added 0 client aliases from 'arp -a' command output
2019/10/16 03:29:08 [info] Added 5 client aliases from /etc/hosts
2019/10/16 03:29:13 [info] Added 0 client aliases from 'arp -a' command output
2019/10/16 04:29:13 [info] Added 5 client aliases from /etc/hosts
2019/10/16 04:29:18 [info] Added 0 client aliases from 'arp -a' command output
2019/10/16 05:29:18 [info] Added 5 client aliases from /etc/hosts
2019/10/16 05:29:23 [info] Added 0 client aliases from 'arp -a' command output
2019/10/16 06:29:23 [info] Added 5 client aliases from /etc/hosts
2019/10/16 06:29:29 [info] Added 0 client aliases from 'arp -a' command output
2019/10/16 07:29:29 [info] Added 5 client aliases from /etc/hosts
2019/10/16 07:29:34 [info] Added 0 client aliases from 'arp -a' command output
2019/10/16 08:29:34 [info] Added 5 client aliases from /etc/hosts
2019/10/16 08:29:40 [info] Added 0 client aliases from 'arp -a' command output
+0x291
runtime.(*mheap).alloc_m(0x11d8980, 0x60006f7, 0x101, 0x0)
        /opt/go1.13.1/src/runtime/mheap.go:1015 +0xc2
runtime.(*mheap).alloc.func1()
        /opt/go1.13.1/src/runtime/mheap.go:1086 +0x4c
runtime.(*mheap).alloc(0x11d8980, 0x60006f7, 0xc000000101, 0xc0000d2380)
        /opt/go1.13.1/src/runtime/mheap.go:1085 +0x8a
runtime.largeAlloc(0xc000ded380, 0x450100, 0xc000b64000)
        /opt/go1.13.1/src/runtime/malloc.go:1138 +0x97
runtime.mallocgc.func1()
        /opt/go1.13.1/src/runtime/malloc.go:1033 +0x46
runtime.systemstack(0x1c100000000)
        /opt/go1.13.1/src/runtime/asm_amd64.s:370 +0x66
runtime.mstart()
        /opt/go1.13.1/src/runtime/proc.go:1146

goroutine 244866 [running]:
runtime.systemstack_switch()
        /opt/go1.13.1/src/runtime/asm_amd64.s:330 fp=0xc000a49928 sp=0xc000a49920 pc=0x4590a0
runtime.mallocgc(0xc000ded380, 0x0, 0x0, 0x1)
        /opt/go1.13.1/src/runtime/malloc.go:1032 +0x895 fp=0xc000a499c8 sp=0xc000a49928 pc=0x40c4b5
runtime.slicebytetostring(0xc000a49a38, 0xc000ded380, 0xc000ded380, 0x0, 0x0, 0x0)
        /opt/go1.13.1/src/runtime/string.go:102 +0x9f fp=0xc000a499f8 sp=0xc000a499c8 pc=0x44792f
github.com/AdguardTeam/golibs/cache.(*cache).Set(0xc00011ab40, 0xc000afcf60, 0x2a, 0x30, 0xc000b64600, 0x5a1, 0x5a1, 0x7f32ac1196d0)
        /root/go/pkg/mod/github.com/!adguard!team/golibs@v0.2.1/cache/cache_data.go:98 +0x1de fp=0xc000a49a88 sp=0xc000a499f8 pc=0x87871e
github.com/AdguardTeam/dnsproxy/proxy.(*cache).Set(0xc00001f530, 0xc0000ce750)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/cache.go:79 +0x165 fp=0xc000a49b30 sp=0xc000a49a88 pc=0x8f7c25
github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).Resolve(0xc0000b2000, 0xc000c84280, 0xc000c84300, 0x0)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:396 +0x4b9 fp=0xc000a49c10 sp=0xc000a49b30 pc=0x8fc979
github.com/AdguardTeam/AdGuardHome/dnsforward.(*Server).handleDNSRequest(0xc0000b6b00, 0xc0000b2000, 0xc000c84280, 0x0, 0x0)
        /usr/local/src/AdGuardHome/dnsforward/dnsforward.go:421 +0x43e fp=0xc000a49dd8 sp=0xc000a49c10 pc=0x904e5e
github.com/AdguardTeam/AdGuardHome/dnsforward.(*Server).handleDNSRequest-fm(0xc0000b2000, 0xc000c84280, 0xc0002c7aa0, 0x0)
        /usr/local/src/AdGuardHome/dnsforward/dnsforward.go:382 +0x3e fp=0xc000a49e10 sp=0xc000a49dd8 pc=0x90813e
github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).handleDNSRequest(0xc0000b2000, 0xc000c84280, 0x37, 0x37)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:927 +0x209 fp=0xc000a49ea8 sp=0xc000a49e10 pc=0x901409
github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).handleUDPPacket(0xc0000b2000, 0xc00092c3c0, 0x37, 0x37, 0xd9cbc0, 0xc0002c7aa0, 0xc000082038)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:638 +0x218 fp=0xc000a49f60 sp=0xc000a49ea8 pc=0x8fec18
github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpPacketLoop.func1(0xc0000b2000, 0xc00092c3c0, 0x37, 0x37, 0xd9cbc0, 0xc0002c7aa0, 0xc000082038)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:606 +0x6b fp=0xc000a49fa8 sp=0xc000a49f60 pc=0x90288b
runtime.goexit()
        /opt/go1.13.1/src/runtime/asm_amd64.s:1357 +0x1 fp=0xc000a49fb0 sp=0xc000a49fa8 pc=0x45aff1
created by github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpPacketLoop
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:605 +0x33c

goroutine 1 [chan receive, 518 minutes]:
github.com/kardianos/service.(*systemd).Run.func1()
        /root/go/pkg/mod/github.com/kardianos/service@v0.0.0-20181115005516-4c239ee84e7b/service_systemd_linux.go:192 +0xbd
github.com/kardianos/service.(*systemd).Run(0xc00001ec30, 0x11ef290, 0xc0000962c0)
        /root/go/pkg/mod/github.com/kardianos/service@v0.0.0-20181115005516-4c239ee84e7b/service_systemd_linux.go:193 +0xbe
github.com/AdguardTeam/AdGuardHome/home.handleServiceControlAction(0x7ffcc73c8f47, 0x3)
        /usr/local/src/AdGuardHome/home/service.go:88 +0x848
github.com/AdguardTeam/AdGuardHome/home.Main(0xd8a610, 0x11, 0xd85228, 0x7)
        /usr/local/src/AdGuardHome/home/home.go:54 +0x13b
main.main()
        main.go:17 +0x5d

goroutine 6 [syscall, 518 minutes]:
os/signal.signal_recv(0x0)
        /opt/go1.13.1/src/runtime/sigqueue.go:147 +0x9c
os/signal.loop()
        /opt/go1.13.1/src/os/signal/signal_unix.go:23 +0x22
created by os/signal.init.0
        /opt/go1.13.1/src/os/signal/signal_unix.go:29 +0x41

goroutine 8 [IO wait, 239 minutes]:
internal/poll.runtime_pollWait(0x7f32a9e18ea8, 0x72, 0x0)
        /opt/go1.13.1/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc0000db218, 0x72, 0x0, 0x0, 0xb08d75)
        /opt/go1.13.1/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
        /opt/go1.13.1/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc0000db200, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
        /opt/go1.13.1/src/internal/poll/fd_unix.go:384 +0x1f8
net.(*netFD).accept(0xc0000db200, 0xc00030db58, 0x6ddbb4, 0xc0000d80a0)
        /opt/go1.13.1/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc00012e6c0, 0x5da5d79e, 0xc00030db58, 0x4860b6)
        /opt/go1.13.1/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc00012e6c0, 0xc00030dba8, 0x18, 0xc0001f6000, 0x6dd0ce)
        /opt/go1.13.1/src/net/tcpsock.go:261 +0x47
net/http.(*Server).Serve(0xc0000d8000, 0xda1340, 0xc00012e6c0, 0x0, 0x0)
        /opt/go1.13.1/src/net/http/server.go:2896 +0x286
net/http.(*Server).ListenAndServe(0xc0000d8000, 0xc0000d8000, 0x7)
        /opt/go1.13.1/src/net/http/server.go:2825 +0xb7
github.com/AdguardTeam/AdGuardHome/home.run(0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
        /usr/local/src/AdGuardHome/home/home.go:191 +0x861
created by github.com/AdguardTeam/AdGuardHome/home.(*program).Start
        /usr/local/src/AdGuardHome/home/service.go:28 +0x90

goroutine 34 [chan receive, 518 minutes]:
github.com/AdguardTeam/AdGuardHome/home.run.func1()
        /usr/local/src/AdGuardHome/home/home.go:97 +0x36
created by github.com/AdguardTeam/AdGuardHome/home.run
        /usr/local/src/AdGuardHome/home/home.go:96 +0x2e4

goroutine 35 [sleep, 37 minutes]:
runtime.goparkunlock(...)
        /opt/go1.13.1/src/runtime/proc.go:310
time.Sleep(0x34630b8a000)
        /opt/go1.13.1/src/runtime/time.go:105 +0x157
github.com/AdguardTeam/AdGuardHome/home.(*clientsContainer).periodicUpdate(0x11c6480)
        /usr/local/src/AdGuardHome/home/clients.go:100 +0x5a
created by github.com/AdguardTeam/AdGuardHome/home.(*clientsContainer).Init
        /usr/local/src/AdGuardHome/home/clients.go:92 +0xa1

goroutine 16 [IO wait]:
internal/poll.runtime_pollWait(0x7f32a9e18d08, 0x72, 0x0)
        /opt/go1.13.1/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc0001d5218, 0x72, 0xff00, 0xffff, 0x0)
        /opt/go1.13.1/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
        /opt/go1.13.1/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).ReadFrom(0xc0001d5200, 0xc000791f89, 0xffff, 0xffff, 0x0, 0x0, 0x0, 0x0, 0x0)
        /opt/go1.13.1/src/internal/poll/fd_unix.go:219 +0x1c3
net.(*netFD).readFrom(0xc0001d5200, 0xc000791f89, 0xffff, 0xffff, 0x37, 0x40bf36, 0xc00092ca40, 0x40, 0x0)
        /opt/go1.13.1/src/net/fd_unix.go:208 +0x5b
net.(*UDPConn).readFrom(0xc000082038, 0xc000791f89, 0xffff, 0xffff, 0x4371ee, 0xc000791ee8, 0x458330, 0xc000791f30)
        /opt/go1.13.1/src/net/udpsock_posix.go:47 +0x6a
net.(*UDPConn).ReadFrom(0xc000082038, 0xc000791f89, 0xffff, 0xffff, 0x37, 0x37, 0xd9cbc0, 0xc000184630, 0xc000082038)
        /opt/go1.13.1/src/net/udpsock.go:121 +0x5d
github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpPacketLoop(0xc0000b2000, 0xc000082038)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:597 +0x12c
created by github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).startListeners
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:568 +0x585

goroutine 65 [IO wait, 20 minutes]:
internal/poll.runtime_pollWait(0x7f32a9e18c38, 0x72, 0x0)
        /opt/go1.13.1/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc0001d5298, 0x72, 0x0, 0x0, 0xb08d75)
        /opt/go1.13.1/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
        /opt/go1.13.1/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Accept(0xc0001d5280, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
        /opt/go1.13.1/src/internal/poll/fd_unix.go:384 +0x1f8
net.(*netFD).accept(0xc0001d5280, 0x37e11d600, 0x0, 0x0)
        /opt/go1.13.1/src/net/fd_unix.go:238 +0x42
net.(*TCPListener).accept(0xc000256a00, 0xc0003e1f08, 0xc0003e1f10, 0x28)
        /opt/go1.13.1/src/net/tcpsock_posix.go:139 +0x32
net.(*TCPListener).Accept(0xc000256a00, 0xce7628, 0xc0000b2000, 0xdaa760, 0xc000b940b8)
        /opt/go1.13.1/src/net/tcpsock.go:261 +0x47
github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).tcpPacketLoop(0xc0000b2000, 0xda1340, 0xc000256a00, 0xb07915, 0x3)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:671 +0xf6
created by github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).startListeners
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:572 +0x556

goroutine 11 [sleep]:
runtime.goparkunlock(...)
        /opt/go1.13.1/src/runtime/proc.go:310
time.Sleep(0x3b9aca00)
        /opt/go1.13.1/src/runtime/time.go:105 +0x157
github.com/AdguardTeam/AdGuardHome/stats.(*statsCtx).periodicFlush(0xc00026a000)
        /usr/local/src/AdGuardHome/stats/stats_unit.go:221 +0x96
created by github.com/AdguardTeam/AdGuardHome/stats.createObject
        /usr/local/src/AdGuardHome/stats/stats_unit.go:120 +0x220

goroutine 12 [chan receive, 518 minutes]:
github.com/AdguardTeam/AdGuardHome/querylog.(*queryLog).periodicRotate(0xc00010c090)
        /usr/local/src/AdGuardHome/querylog/querylog_file.go:170 +0x75
created by github.com/AdguardTeam/AdGuardHome/querylog.newQueryLog
        /usr/local/src/AdGuardHome/querylog/qlog.go:50 +0x107

goroutine 13 [chan receive, 518 minutes]:
github.com/AdguardTeam/AdGuardHome/dnsfilter.(*Dnsfilter).filtersInitializer(0xc00026e120)
        /usr/local/src/AdGuardHome/dnsfilter/dnsfilter.go:242 +0x49
created by github.com/AdguardTeam/AdGuardHome/dnsfilter.New
        /usr/local/src/AdGuardHome/dnsfilter/dnsfilter.go:1033 +0x272

goroutine 14 [chan receive, 517 minutes]:
github.com/AdguardTeam/AdGuardHome/home.(*RDNS).workerLoop(0xc0002c69c0)
        /usr/local/src/AdGuardHome/home/rdns.go:128 +0x56
created by github.com/AdguardTeam/AdGuardHome/home.InitRDNS
        /usr/local/src/AdGuardHome/home/rdns.go:52 +0x2eb

goroutine 15 [chan receive, 518 minutes]:
github.com/AdguardTeam/AdGuardHome/home.(*Whois).workerLoop(0xc0002c6a20)
        /usr/local/src/AdGuardHome/home/whois.go:211 +0x45
created by github.com/AdguardTeam/AdGuardHome/home.initWhois
        /usr/local/src/AdGuardHome/home/whois.go:36 +0xc0

goroutine 19 [sleep, 38 minutes]:
runtime.goparkunlock(...)
        /opt/go1.13.1/src/runtime/proc.go:310
time.Sleep(0x34630b8a000)
        /opt/go1.13.1/src/runtime/time.go:105 +0x157
github.com/AdguardTeam/AdGuardHome/home.periodicallyRefreshFilters()
        /usr/local/src/AdGuardHome/home/filter.go:188 +0x36
created by github.com/AdguardTeam/AdGuardHome/home.initFiltering
        /usr/local/src/AdGuardHome/home/filter.go:31 +0x67

goroutine 21 [sync.Cond.Wait, 518 minutes]:
runtime.goparkunlock(...)
        /opt/go1.13.1/src/runtime/proc.go:310
sync.runtime_notifyListWait(0xc0001a0010, 0x0)
        /opt/go1.13.1/src/runtime/sema.go:510 +0xf8
sync.(*Cond).Wait(0xc0001a0000)
        /opt/go1.13.1/src/sync/cond.go:56 +0x9d
github.com/AdguardTeam/AdGuardHome/home.httpServerLoop()
        /usr/local/src/AdGuardHome/home/home.go:211 +0x47
created by github.com/AdguardTeam/AdGuardHome/home.run
        /usr/local/src/AdGuardHome/home/home.go:180 +0x6fd

goroutine 67 [select, 38 minutes]:
github.com/patrickmn/go-cache.(*janitor).Run(0xc0001a2910, 0xc0001a0c40)
        /root/go/pkg/mod/github.com/patrickmn/go-cache@v2.1.0+incompatible/cache.go:1079 +0xd5
created by github.com/patrickmn/go-cache.runJanitor
        /root/go/pkg/mod/github.com/patrickmn/go-cache@v2.1.0+incompatible/cache.go:1099 +0xa9

goroutine 244880 [select]:
golang.org/x/net/http2.(*ClientConn).roundTrip(0xc000b2b080, 0xc000b32c00, 0x0, 0x0, 0x0, 0x0)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:1084 +0x9a0
golang.org/x/net/http2.(*Transport).RoundTripOpt(0xc00011b6e0, 0xc000b32c00, 0xc0003de700, 0x6cf465, 0x0, 0xc000abe000)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:447 +0x172
golang.org/x/net/http2.(*Transport).RoundTrip(...)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:408
golang.org/x/net/http2.noDialH2RoundTripper.RoundTrip(0xc00011b6e0, 0xc000b32c00, 0xc0009922a0, 0x5, 0xc000abe088)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:2567 +0x3e
net/http.(*Transport).roundTrip(0xc000bdc780, 0xc000b32c00, 0xc000184720, 0xc0003d7ad8, 0xc0003d7af0)
        /opt/go1.13.1/src/net/http/transport.go:485 +0xd0a
net/http.(*Transport).RoundTrip(0xc000bdc780, 0xc000b32c00, 0xc000bdc780, 0xbf61a1d4fb3c7919, 0x1c46b6fa69b8)
        /opt/go1.13.1/src/net/http/roundtrip.go:17 +0x35
net/http.send(0xc000b32b00, 0xd96300, 0xc000bdc780, 0xbf61a1d4fb3c7919, 0x1c46b6fa69b8, 0x11d2560, 0xc000b940b0, 0xbf61a1d4fb3c7919, 0x1, 0x0)
        /opt/go1.13.1/src/net/http/client.go:250 +0x43a
net/http.(*Client).send(0xc000cf8fc0, 0xc000b32b00, 0xbf61a1d4fb3c7919, 0x1c46b6fa69b8, 0x11d2560, 0xc000b940b0, 0x0, 0x1, 0xaf6ae0)
        /opt/go1.13.1/src/net/http/client.go:174 +0xfa
net/http.(*Client).do(0xc000cf8fc0, 0xc000b32b00, 0x0, 0x0, 0x0)
        /opt/go1.13.1/src/net/http/client.go:641 +0x3ce
net/http.(*Client).Do(...)
        /opt/go1.13.1/src/net/http/client.go:509
github.com/AdguardTeam/dnsproxy/upstream.(*dnsOverHTTPS).exchangeHTTPSClient(0xc00001f260, 0xc0007ba900, 0xc000cf8fc0, 0x0, 0x0, 0x0)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/upstream/upstream_doh.go:68 +0x25c
github.com/AdguardTeam/dnsproxy/upstream.(*dnsOverHTTPS).Exchange(0xc00001f260, 0xc0007ba900, 0xc000d557c0, 0x858d30, 0xc000b8e800)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/upstream/upstream_doh.go:42 +0x6c
github.com/AdguardTeam/dnsproxy/upstream.exchangeAsync(0xd9c140, 0xc00001f260, 0xc0007ba900, 0xc00011aa20)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/upstream/parallel.go:67 +0x3f
created by github.com/AdguardTeam/dnsproxy/upstream.ExchangeParallel
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/upstream/parallel.go:41 +0xd4

goroutine 244879 [select]:
golang.org/x/net/http2.(*ClientConn).roundTrip(0xc0001f7200, 0xc0000deb00, 0x0, 0x0, 0x0, 0x0)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:1084 +0x9a0
golang.org/x/net/http2.(*Transport).RoundTripOpt(0xc0001b20c0, 0xc0000deb00, 0xc0003b4700, 0x6cf465, 0x0, 0xc000abe120)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:447 +0x172
golang.org/x/net/http2.(*Transport).RoundTrip(...)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:408
golang.org/x/net/http2.noDialH2RoundTripper.RoundTrip(0xc0001b20c0, 0xc0000deb00, 0xc000762070, 0x5, 0xc000abe1a8)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:2567 +0x3e
net/http.(*Transport).roundTrip(0xc000967b80, 0xc0000deb00, 0xc000aecd20, 0xc000ee0508, 0xc000ee0510)
        /opt/go1.13.1/src/net/http/transport.go:485 +0xd0a
net/http.(*Transport).RoundTrip(0xc000967b80, 0xc0000deb00, 0xc000967b80, 0xbf61a1d4fb3df280, 0x1c46b6fbe31e)
        /opt/go1.13.1/src/net/http/roundtrip.go:17 +0x35
net/http.send(0xc0000dea00, 0xd96300, 0xc000967b80, 0xbf61a1d4fb3df280, 0x1c46b6fbe31e, 0x11d2560, 0xc000082118, 0xbf61a1d4fb3df280, 0x1, 0x0)
        /opt/go1.13.1/src/net/http/client.go:250 +0x43a
net/http.(*Client).send(0xc000aec9f0, 0xc0000dea00, 0xbf61a1d4fb3df280, 0x1c46b6fbe31e, 0x11d2560, 0xc000082118, 0x0, 0x1, 0xaf6ae0)
        /opt/go1.13.1/src/net/http/client.go:174 +0xfa
net/http.(*Client).do(0xc000aec9f0, 0xc0000dea00, 0x0, 0x0, 0x0)
        /opt/go1.13.1/src/net/http/client.go:641 +0x3ce
net/http.(*Client).Do(...)
        /opt/go1.13.1/src/net/http/client.go:509
github.com/AdguardTeam/dnsproxy/upstream.(*dnsOverHTTPS).exchangeHTTPSClient(0xc00001f080, 0xc0007ba900, 0xc000aec9f0, 0x0, 0x0, 0x0)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/upstream/upstream_doh.go:68 +0x25c
github.com/AdguardTeam/dnsproxy/upstream.(*dnsOverHTTPS).Exchange(0xc00001f080, 0xc0007ba900, 0x37, 0xd9cbc0, 0xc000184630)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/upstream/upstream_doh.go:42 +0x6c
github.com/AdguardTeam/dnsproxy/upstream.exchangeAsync(0xd9c140, 0xc00001f080, 0xc0007ba900, 0xc00011aa20)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/upstream/parallel.go:67 +0x3f
created by github.com/AdguardTeam/dnsproxy/upstream.ExchangeParallel
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/upstream/parallel.go:41 +0xd4

goroutine 226689 [IO wait]:
internal/poll.runtime_pollWait(0x7f32a9e184e8, 0x72, 0xffffffffffffffff)
        /opt/go1.13.1/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc0000db998, 0x72, 0xf00, 0xfed, 0xffffffffffffffff)
        /opt/go1.13.1/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
        /opt/go1.13.1/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc0000db980, 0xc000954000, 0xfed, 0xfed, 0x0, 0x0, 0x0)
        /opt/go1.13.1/src/internal/poll/fd_unix.go:169 +0x1cf
net.(*netFD).Read(0xc0000db980, 0xc000954000, 0xfed, 0xfed, 0x203000, 0x0, 0xf26)
        /opt/go1.13.1/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc000b94030, 0xc000954000, 0xfed, 0xfed, 0x0, 0x0, 0x0)
        /opt/go1.13.1/src/net/net.go:184 +0x68
crypto/tls.(*atLeastReader).Read(0xc00045ab20, 0xc000954000, 0xfed, 0xfed, 0x140, 0xc000111180, 0xc0003e0970)
        /opt/go1.13.1/src/crypto/tls/conn.go:780 +0x60
bytes.(*Buffer).ReadFrom(0xc0000d2cd8, 0xd95cc0, 0xc00045ab20, 0x409f15, 0xa53ca0, 0xae4d20)
        /opt/go1.13.1/src/bytes/buffer.go:204 +0xb4
crypto/tls.(*Conn).readFromUntil(0xc0000d2a80, 0xd96260, 0xc000b94030, 0x5, 0xc000b94030, 0x9)
        /opt/go1.13.1/src/crypto/tls/conn.go:802 +0xec
crypto/tls.(*Conn).readRecordOrCCS(0xc0000d2a80, 0x0, 0x0, 0x0)
        /opt/go1.13.1/src/crypto/tls/conn.go:609 +0x124
crypto/tls.(*Conn).readRecord(...)
        /opt/go1.13.1/src/crypto/tls/conn.go:577
crypto/tls.(*Conn).Read(0xc0000d2a80, 0xc000277000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
        /opt/go1.13.1/src/crypto/tls/conn.go:1255 +0x161
bufio.(*Reader).Read(0xc000322300, 0xc00031c118, 0x9, 0x9, 0xc0003e0d10, 0x0, 0x864d52)
        /opt/go1.13.1/src/bufio/bufio.go:226 +0x26a
io.ReadAtLeast(0xd95b40, 0xc000322300, 0xc00031c118, 0x9, 0x9, 0x9, 0xc0000520e0, 0x0, 0xd95e00)
        /opt/go1.13.1/src/io/io.go:310 +0x87
io.ReadFull(...)
        /opt/go1.13.1/src/io/io.go:329
golang.org/x/net/http2.readFrameHeader(0xc00031c118, 0x9, 0x9, 0xd95b40, 0xc000322300, 0x0, 0x0, 0xc0001f3d70, 0x0)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/frame.go:237 +0x87
golang.org/x/net/http2.(*Framer).ReadFrame(0xc00031c0e0, 0xc0001f3d70, 0x0, 0x0, 0x0)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/frame.go:492 +0xa1
golang.org/x/net/http2.(*clientConnReadLoop).run(0xc0003e0fb8, 0x0, 0x0)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:1710 +0x8c
golang.org/x/net/http2.(*ClientConn).readLoop(0xc0001f7200)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:1638 +0xa3
created by golang.org/x/net/http2.(*Transport).newClientConn
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:673 +0x62f

goroutine 244913 [select]:
net/http.setRequestCancel.func3(0x0, 0xc000184720, 0xc0001965a0, 0xc0003d7ad8, 0xc00094b0e0)
        /opt/go1.13.1/src/net/http/client.go:321 +0xcf
created by net/http.setRequestCancel
        /opt/go1.13.1/src/net/http/client.go:320 +0x24b

goroutine 244878 [chan receive]:
github.com/AdguardTeam/dnsproxy/upstream.ExchangeParallel(0xc0002569e0, 0x2, 0x2, 0xc0007ba900, 0xc000c3aab0, 0x2a, 0x11f06a0, 0x0, 0x30)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/upstream/parallel.go:47 +0x142
github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).exchange(0xc0000b2000, 0xc0007ba900, 0xc0002569e0, 0x2, 0x2, 0x2, 0xc0003deba0, 0x9a1453, 0xc0003d7a80, 0x10)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:415 +0x427
github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).Resolve(0xc0000b2000, 0xc000c84780, 0xc000c84800, 0x0)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:377 +0x10a
github.com/AdguardTeam/AdGuardHome/dnsforward.(*Server).handleDNSRequest(0xc0000b6b00, 0xc0000b2000, 0xc000c84780, 0x0, 0x0)
        /usr/local/src/AdGuardHome/dnsforward/dnsforward.go:421 +0x43e
github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).handleDNSRequest(0xc0000b2000, 0xc000c84780, 0x37, 0x37)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:927 +0x209
github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).handleUDPPacket(0xc0000b2000, 0xc00092ca40, 0x37, 0x37, 0xd9cbc0, 0xc000184630, 0xc000082038)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:638 +0x218
github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpPacketLoop.func1(0xc0000b2000, 0xc00092ca40, 0x37, 0x37, 0xd9cbc0, 0xc000184630, 0xc000082038)
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:606 +0x6b
created by github.com/AdguardTeam/dnsproxy/proxy.(*Proxy).udpPacketLoop
        /root/go/pkg/mod/github.com/!adguard!team/dnsproxy@v0.19.5/proxy/proxy.go:605 +0x33c

goroutine 207211 [IO wait]:
internal/poll.runtime_pollWait(0x7f32a9e18828, 0x72, 0xffffffffffffffff)
        /opt/go1.13.1/src/runtime/netpoll.go:184 +0x55
internal/poll.(*pollDesc).wait(0xc0001d5e18, 0x72, 0xf00, 0xfee, 0xffffffffffffffff)
        /opt/go1.13.1/src/internal/poll/fd_poll_runtime.go:87 +0x45
internal/poll.(*pollDesc).waitRead(...)
        /opt/go1.13.1/src/internal/poll/fd_poll_runtime.go:92
internal/poll.(*FD).Read(0xc0001d5e00, 0xc00045c000, 0xfee, 0xfee, 0x0, 0x0, 0x0)
        /opt/go1.13.1/src/internal/poll/fd_unix.go:169 +0x1cf
net.(*netFD).Read(0xc0001d5e00, 0xc00045c000, 0xfee, 0xfee, 0x203000, 0x0, 0xfe9)
        /opt/go1.13.1/src/net/fd_unix.go:202 +0x4f
net.(*conn).Read(0xc00000f310, 0xc00045c000, 0xfee, 0xfee, 0x0, 0x0, 0x0)
        /opt/go1.13.1/src/net/net.go:184 +0x68
crypto/tls.(*atLeastReader).Read(0xc000270ba0, 0xc00045c000, 0xfee, 0xfee, 0x1f, 0xd95e00, 0xc0003b9970)
        /opt/go1.13.1/src/crypto/tls/conn.go:780 +0x60
bytes.(*Buffer).ReadFrom(0xc000041ad8, 0xd95cc0, 0xc000270ba0, 0x409f15, 0xa53ca0, 0xae4d20)
        /opt/go1.13.1/src/bytes/buffer.go:204 +0xb4
crypto/tls.(*Conn).readFromUntil(0xc000041880, 0xd96260, 0xc00000f310, 0x5, 0xc00000f310, 0x9)
        /opt/go1.13.1/src/crypto/tls/conn.go:802 +0xec
crypto/tls.(*Conn).readRecordOrCCS(0xc000041880, 0x0, 0x0, 0x43f6cf)
        /opt/go1.13.1/src/crypto/tls/conn.go:609 +0x124
crypto/tls.(*Conn).readRecord(...)
        /opt/go1.13.1/src/crypto/tls/conn.go:577
crypto/tls.(*Conn).Read(0xc000041880, 0xc000276000, 0x1000, 0x1000, 0x0, 0x0, 0x0)
        /opt/go1.13.1/src/crypto/tls/conn.go:1255 +0x161
bufio.(*Reader).Read(0xc000b9c120, 0xc00031c038, 0x9, 0x9, 0xc0003b9d10, 0x0, 0x864d52)
        /opt/go1.13.1/src/bufio/bufio.go:226 +0x26a
io.ReadAtLeast(0xd95b40, 0xc000b9c120, 0xc00031c038, 0x9, 0x9, 0x9, 0xc0000520e0, 0x0, 0xd95e00)
        /opt/go1.13.1/src/io/io.go:310 +0x87
io.ReadFull(...)
        /opt/go1.13.1/src/io/io.go:329
golang.org/x/net/http2.readFrameHeader(0xc00031c038, 0x9, 0x9, 0xd95b40, 0xc000b9c120, 0x0, 0x0, 0xc000aeca80, 0x0)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/frame.go:237 +0x87
golang.org/x/net/http2.(*Framer).ReadFrame(0xc00031c000, 0xc000aeca80, 0x0, 0x0, 0x0)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/frame.go:492 +0xa1
golang.org/x/net/http2.(*clientConnReadLoop).run(0xc0003b9fb8, 0x84e15d, 0xc00011b6e0)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:1710 +0x8c
golang.org/x/net/http2.(*ClientConn).readLoop(0xc000b2b080)
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:1638 +0xa3
created by golang.org/x/net/http2.(*Transport).newClientConn
        /root/go/pkg/mod/golang.org/x/net@v0.0.0-20191002035440-2ec189313ef0/http2/transport.go:673 +0x62f

goroutine 244883 [select]:
net/http.setRequestCancel.func3(0x0, 0xc000aecd20, 0xc0000a44b0, 0xc000ee0508, 0xc00007dbc0)
        /opt/go1.13.1/src/net/http/client.go:321 +0xcf
created by net/http.setRequestCancel
        /opt/go1.13.1/src/net/http/client.go:320 +0x24b
ameshkov commented 4 years ago

@Kaeltis could you please set the logging level to verbose in the configuration file and try reproducing this again?

I don't yet understand what exactly is the problem, no deadlocks in the stack traces.

Also, you might want to wait a little bit until #1041 is done and we start building AGH with Go 1.13.

kaeltis commented 4 years ago

I won't be home the rest of the week - next week I'll compile the most recent version and leave it running in verbose.

szolin commented 4 years ago

Closing as duplicate: https://github.com/AdguardTeam/AdGuardHome/issues/1074 If the issue persists, please reopen the issue or open a new one.