ncruces / go-dns

net.Resolvers with caching, opportunistic encryption, and DoT/DoH
https://pkg.go.dev/github.com/ncruces/go-dns
MIT License
41 stars 8 forks source link

Redirect of panic (via unix.Dup2) not working after DoT resolve #13

Closed powellnorma closed 1 year ago

powellnorma commented 1 year ago

I found a weird bug, do you have any idea what may causes this?

main.go:

package main

import (
    "fmt"
    "log"
    "net"
    "os"

    dns "github.com/ncruces/go-dns"
    "golang.org/x/sys/unix"
)

func hasArg(val string) bool {
    for _, argI := range os.Args[1:] {
        if val == argI {
            return true
        }
    }
    return false
}

func LogStderrToFile(dstFile string) {
    f, err := os.OpenFile(dstFile, os.O_WRONLY|os.O_CREATE|os.O_TRUNC, 0666)
    if err != nil {
        log.Fatalf("OpenFile failed: %v", err)
    }

    err = unix.Dup2(int(f.Fd()), int(os.Stderr.Fd()))
    if err != nil {
        log.Fatalf("Dup2 failed: %v", err)
    }

    os.Stderr = f

    if hasArg("also-redirect-log") {
        log.SetOutput(f)
    }
}

func main() {
    path := "/tmp/test.log"
    fmt.Printf("redirect stderr to: %s\n", path)
    LogStderrToFile(path)

    if hasArg("DoT") {
        resolver, err := dns.NewDoTResolver("cloudflare-dns.com", dns.DoTAddresses("1.1.1.1", "1.0.0.1"), dns.DoTCache())
        if err != nil {
            panic(err)
        }
        net.DefaultResolver = resolver
    }

    addrs, _ := net.LookupHost("www.wikipedia.org")
    fmt.Printf("addrs: %v\n", addrs)

    panic("test")
}

Results:

$ go run main.go; echo --; cat /tmp/test.log 
redirect stderr to: /tmp/test.log
addrs: [2a02:ec80:300:ed1a::1 185.15.59.224]
exit status 2
--
panic: test

goroutine 1 [running]:
main.main()
    /src/main.go:56 +0x1a5

$ go run main.go also-redirect-log; echo --; cat /tmp/test.log 
redirect stderr to: /tmp/test.log
addrs: [2a02:ec80:300:ed1a::1 185.15.59.224]
exit status 2
--
panic: test

goroutine 1 [running]:
main.main()
    /src/main.go:56 +0x1a5

$ go run main.go DoT; echo --; cat /tmp/test.log 
redirect stderr to: /tmp/test.log
addrs: [2a02:ec80:300:ed1a::1 185.15.59.224]
exit status 2
--
panic: test

goroutine 1 [running]:
main.main()
    /src/main.go:56 +0x1a5

$ go run main.go also-redirect-log DoT; echo --; cat /tmp/test.log 
redirect stderr to: /tmp/test.log
addrs: [2a02:ec80:300:ed1a::1 185.15.59.224]
exit status 2
--

$

So when using both also-redirect-log (log.SetOutput) and DoT (NewDoTResolver), the panic is not logged to the file.

ncruces commented 1 year ago

No. No idea.

powellnorma commented 1 year ago

It doesn't happen when using the default resolver, though - Weird

Are you able to reproduce it? I use go1.21.4

Will you have any time/desire to investigate this? Do you think it could be a bug in the go runtime somehow?

ncruces commented 1 year ago

No, I can't reproduce it.

$ go version
go version go1.21.4 darwin/amd64
powellnorma commented 1 year ago

Hm, I tested it in another linux environment: go version go1.19.5 linux/amd64

In there go run main.go also-redirect-log DoT also generates an empty /tmp/test.log file.

So I guess it is linux only. Do you by any chance have a linux system you could test this with?

In case this library is not doing anything "low level" regarding logging / file handle manipulation, it must come from golang.org/x/net, as that is the only dependency used here, right?

ncruces commented 1 year ago

That dependency is a test dependency only. And no, the library is not doing anything weird.

powellnorma commented 1 year ago

Got resolved - It was due to garbage collection of the overwritten os.Stderr (see https://github.com/golang/go/issues/64555#issuecomment-1842115871)