air-verse / air

☁️ Live reload for Go apps
GNU General Public License v3.0
18.11k stars 812 forks source link

Panic in proxy handler #634

Open jtackaberry opened 2 months ago

jtackaberry commented 2 months ago

Given the following configuration using v1.52.3

root = "."

[build]
  bin = "myproject"
  cmd = "make"
  delay = 200
  exclude_dir = ["vendor"]
  include_ext = ["go", "html", "css"]
  stop_on_error = true
  send_interrupt = true
  kill_delay = 500000000 # nanosecond

[log]
  time = true

[misc]
  clean_on_exit = true

[proxy]
  enabled = true
  proxy_port = 8080
  app_port = 7070

I sometimes observe the following panic:

2024/08/21 10:50:12 http: panic serving 127.0.0.1:44908: runtime error: invalid memory address or nil pointer dereference
goroutine 47 [running]:
net/http.(*conn).serve.func1()
        /opt/go-1.22.4/src/net/http/server.go:1898 +0xbe
panic({0x860820?, 0xc9e4d0?})
        /opt/go-1.22.4/src/runtime/panic.go:770 +0x132
github.com/air-verse/air/runner.(*Proxy).proxyHandler(0xc0001dc210, {0x99b2e0, 0xc0000b00e0}, 0xc0003acc60)
        /home/jtackaberry/src/go/pkg/mod/github.com/air-verse/air@v1.52.3/runner/proxy.go:122 +0x599
net/http.HandlerFunc.ServeHTTP(0xcb58a0?, {0x99b2e0?, 0xc0000b00e0?}, 0x7bef5a?)
        /opt/go-1.22.4/src/net/http/server.go:2166 +0x29
net/http.(*ServeMux).ServeHTTP(0x46bfb9?, {0x99b2e0, 0xc0000b00e0}, 0xc0003acc60)
        /opt/go-1.22.4/src/net/http/server.go:2683 +0x1ad
net/http.serverHandler.ServeHTTP({0xc0002ac0c0?}, {0x99b2e0?, 0xc0000b00e0?}, 0x6?)
        /opt/go-1.22.4/src/net/http/server.go:3137 +0x8e
net/http.(*conn).serve(0xc0001c65a0, {0x99bb50, 0xc0000b42a0})
        /opt/go-1.22.4/src/net/http/server.go:2039 +0x5e8
created by net/http.(*Server).Serve in goroutine 32
        /opt/go-1.22.4/src/net/http/server.go:3285 +0x4b4
rweir commented 1 month ago

I noticed this too, and it's fairly reproducible - about 50% of the times I start air and so some HTTP request to the proxy port while it's starting up, I'll get this error.

the traceback points to this bit of code:

defer resp.Body.Close()

after adding some printf, it's because resp is nil by the time this defer runs. I assumed it was the resp getting cleaned up somehow before the defer runs, but just fixing the defer by making it a nested function that checks resp and resp.Body aren't nil reveals there's a similar issue below. I think the error handling above isn't quite right. it will loop 10 times, with a 100ms wait between each, and after that it will proceed, even if it received (a wrapped) ECONNREFUSED error, thus resp can be nil when we fall off the end of the for loop and proceed in to the "happy case".

so! what to do? two obvious options:

first: increase the timeout or retry count. currently it only gives your service 1000ms (1s) to respond to queries or you get the panic. or at least make one or the other configurable. or use exponential-capped backoff to get a longer total wait when it's slow.

second: check if resp == nil after the for loop, and then do something other than panic. return an error to the client? I suspect this is a bit complex with the reload JS - if we return a blank error page then that's the end of automatic reloads until a manual one happens. something like this:

if resp == nil {
    http.Error(w, "proxy handler: unable to reach app", http.StatusInternalServerError)
    return
}

just gets you an error page in the browser that can't automatically reload. returning a custom HTML page that just embeds the reload logic to start the process over again might work but is maybe a bit too cute.

istyf commented 1 week ago

This issue seems to have been fixed by #635 that was released in 1.61.0.