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.

Sign up for GitHub

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

Jump to bottom

net/http: panic when reading request body #7527

Closed
gopherbot opened this issue Mar 12, 2014 · 7 comments
Closed

net/http: panic when reading request body #7527

gopherbot opened this issue Mar 12, 2014 · 7 comments
Labels
FrozenDueToAge

Comments

@gopherbot
Copy link

by dimitrij.denissenko@blacksquaremedia.com:

What does 'go version' print?

go version go1.2 linux/amd64

What happened?

In my http server, I am trying to read the http.Request.Body via
ioutil.ReadAll(req.Body). Rarely, it causes an unexpected panic:

panic: runtime error: invalid memory address or nil pointer dereference [recovered]
    panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x20 pc=0x5e65ca]
goroutine 1918503 [running]:
runtime.panic(0x7c3560, 0xd59d88)
  /home/user/.gvm/gos/go1.2/src/pkg/runtime/panic.c:266 +0xb6
io/ioutil.func·001()
  /home/user/.gvm/gos/go1.2/src/pkg/io/ioutil/ioutil.go:29 +0xf0
runtime.panic(0x7c3560, 0xd59d88)
  /home/user/.gvm/gos/go1.2/src/pkg/runtime/panic.c:248 +0x106
bufio.(*Reader).fill(0xc2101b1c00)
  /home/user/.gvm/gos/go1.2/src/pkg/bufio/bufio.go:91 +0x10a
bufio.(*Reader).Read(0xc2101b1c00, 0xc2119bde00, 0x1e5, 0x200, 0x1e5, ...)
  /home/user/.gvm/gos/go1.2/src/pkg/bufio/bufio.go:159 +0x1a4
io.(*LimitedReader).Read(0xc2107532e0, 0xc2119bde00, 0x200, 0x200, 0xc2119bde00, ...)
  /home/user/.gvm/gos/go1.2/src/pkg/io/io.go:398 +0xbb
net/http.(*body).Read(0xc2109ee4e0, 0xc2119bde00, 0x200, 0x200, 0x1, ...)
  /home/user/.gvm/gos/go1.2/src/pkg/net/http/transfer.go:534 +0x96
bytes.(*Buffer).ReadFrom(0xc21344b1c0, 0x7fe124670ee0, 0xc2109ee4e0, 0x0, 0x0, ...)
  /home/user/.gvm/gos/go1.2/src/pkg/bytes/buffer.go:169 +0x1f7
io/ioutil.readAll(0x7fe124670ee0, 0xc2109ee4e0, 0x200, 0x0, 0x0, ...)
  /home/user/.gvm/gos/go1.2/src/pkg/io/ioutil/ioutil.go:32 +0x156
io/ioutil.ReadAll(0x7fe124670ee0, 0xc2109ee4e0, 0x5320e1b2, 0x2a5129fd, 0x48349e, ...)
  /home/user/.gvm/gos/go1.2/src/pkg/io/ioutil/ioutil.go:41 +0x3f

What should have happened instead?

The documentation http://golang.org/src/pkg/net/http/request.go?#L114 suggests that a
server body must never be nil.
@davecheney
Copy link
Contributor

Comment 1:

Can you please provide a code sample which demonstrates this issue.
Could you also attach the entire panic message from the issue report above.

Status changed to WaitingForReply.

@gopherbot
Copy link
Author

Comment 2 by dimitrij.denissenko@blacksquaremedia.com:

Unfortunately there are limitations to what I can expose as it is a proprietary client
app, but please see a different panic message from the same app. There are dozens of
goroutines, so I have copied the first few as all the others are in a runnable state.
Here is the code which causes this is:
// proprietary.com/client/app/protocol.ParseRequest
func ParseRequest(reader io.Reader) ... {
  dec := json.NewDecoder(reader)
  if err = dec.Decode(&req); err != nil {
    return nil, err
  }
  ...
}
// proprietary.com/client/app.(*Parser).Parse
func (p *Parser) Parse(rd io.Reader) .... {
  req, err := protocol.ParseRequest(rd)
  ...
}
// proprietary.com/client/app.(*Mux).Handle
func (m *Mux) Handle(w http.ResponseWriter, req *http.Request) {
  data, err := DefaultParser.Parse(req.Body)
  ...
}
The panic message:
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x20 pc=0x5e65ca]
goroutine 8761184 [running]:
runtime.panic(0x7c3560, 0xd59d88)
        /home/user/.gvm/gos/go1.2/src/pkg/runtime/panic.c:266 +0xb6
bufio.(*Reader).fill(0xc211a1c000)
        /home/user/.gvm/gos/go1.2/src/pkg/bufio/bufio.go:91 +0x10a
bufio.(*Reader).Read(0xc211a1c000, 0xc210a86000, 0x200, 0x200, 0x200, ...)
        /home/user/.gvm/gos/go1.2/src/pkg/bufio/bufio.go:159 +0x1a4
io.(*LimitedReader).Read(0xc2144bdae0, 0xc210a86000, 0x200, 0x200, 0x200, ...)
        /home/user/.gvm/gos/go1.2/src/pkg/io/io.go:398 +0xbb
net/http.(*body).Read(0xc210ab4a80, 0xc210a86000, 0x200, 0x200, 0x0, ...)
        /home/user/.gvm/gos/go1.2/src/pkg/net/http/transfer.go:534 +0x96
encoding/json.(*Decoder).readValue(0xc215022c40, 0x8, 0xc21196d900, 0xba)
        /home/user/.gvm/gos/go1.2/src/pkg/encoding/json/stream.go:124 +0x4af
encoding/json.(*Decoder).Decode(0xc215022c40, 0x6d6760, 0xc210261628, 0x14e6413c,
0x42723e)
        /home/user/.gvm/gos/go1.2/src/pkg/encoding/json/stream.go:44 +0x57
proprietary.com/client/app/protocol.ParseRequest(0x7ff17152a0e0, 0xc210ab4a80,
0xc200000000, 0x0, 0x0)
        /home/user/app/releases/20140312144700/_vendor/src/proprietary.com/client/app/protocol/request.go:34 +0xb0
proprietary.com/client/app.(*Parser).Parse(0xd580e0, 0x7ff17152a0e0, 0xc210ab4a80,
0xc2102606c0, 0x0, ...)
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/parser.go:133 +0xc2
proprietary.com/client/app.(*Mux).Handle(0xc210000ab0, 0x7ff179ba4e50, 0xc2144bdb00,
0xc2155a1c30, 0x7ff179b9d758, ...)
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/mux.go:128 +0x270
proprietary.com/client/app.func·008(0x7ff179ba4e50, 0xc2144bdb00, 0xc2155a1c30)
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/mux.go:792 +0x54
net/http.HandlerFunc.ServeHTTP(0xc2100956e0, 0x7ff179ba4e50, 0xc2144bdb00, 0xc2155a1c30)
        /home/user/.gvm/gos/go1.2/src/pkg/net/http/server.go:1220 +0x40
proprietary.com/client/app/utils.func·002()
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/utils/timeout.go:27 +0x86
created by proprietary.com/client/app/utils.(*timeoutHandler).ServeHTTP
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/utils/timeout.go:29 +0x134
goroutine 1 [IO wait]:
net.runtime_pollWait(0x7ff179b9e780, 0x72, 0x0)
        /home/user/.gvm/gos/go1.2/src/pkg/runtime/netpoll.goc:116 +0x6a
net.(*pollDesc).Wait(0xc210097c30, 0x72, 0x7ff179b9d180, 0xb)
        /home/user/.gvm/gos/go1.2/src/pkg/net/fd_poll_runtime.go:81 +0x34
net.(*pollDesc).WaitRead(0xc210097c30, 0xb, 0x7ff179b9d180)
        /home/user/.gvm/gos/go1.2/src/pkg/net/fd_poll_runtime.go:86 +0x30
net.(*netFD).accept(0xc210097bd0, 0x938758, 0x0, 0x7ff179b9d180, 0xb)
        /home/user/.gvm/gos/go1.2/src/pkg/net/fd_unix.go:382 +0x2c2
net.(*UnixListener).AcceptUnix(0xc21010e7a0, 0x4d284b, 0x7ff1799fdcf0, 0x4d284b)
        /home/user/.gvm/gos/go1.2/src/pkg/net/unixsock_posix.go:283 +0x4b
net.(*UnixListener).Accept(0xc21010e7a0, 0x0, 0x0, 0x0, 0x0)
        /home/user/.gvm/gos/go1.2/src/pkg/net/unixsock_posix.go:294 +0x4b
net/http.(*Server).Serve(0xc210099780, 0x7ff179ba43f0, 0xc21010e7a0, 0x0, 0x0)
        /home/user/.gvm/gos/go1.2/src/pkg/net/http/server.go:1622 +0x91
proprietary.com/client/app.(*Mux).ListenAndServe(0xc210000ab0, 0xc210000940, 0x4,
0x7fff18194e9c, 0x15, ...)
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/mux.go:108 +0x2bb
proprietary.com/client/app.(*app).Run(0xd5fcc0, 0x7fff18194e9c, 0x15, 0x7fff18194e7f,
0x16)
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/app.go:85 +0x767
main.main()
        /home/user/app/releases/20140312144700/worker/worker.go:17 +0x63
goroutine 3 [syscall]:
os/signal.loop()
        /home/user/.gvm/gos/go1.2/src/pkg/os/signal/signal_unix.go:21 +0x1e
created by os/signal.init·1
        /home/user/.gvm/gos/go1.2/src/pkg/os/signal/signal_unix.go:27 +0x31
goroutine 4 [chan receive]:
github.com/golang/glog.(*loggingT).flushDaemon(0xd5fe00)
        /home/user/app/releases/20140312144700/_vendor/src/github.com/golang/glog/glog.go:839 +0x50
created by github.com/golang/glog.init·1
        /home/user/app/releases/20140312144700/_vendor/src/github.com/golang/glog/glog.go:406 +0x276
goroutine 5 [syscall]:
runtime.goexit()
        /home/user/.gvm/gos/go1.2/src/pkg/runtime/proc.c:1394
goroutine 9 [chan receive]:
database/sql.(*DB).connectionOpener(0xc21004bb00)
        /home/user/.gvm/gos/go1.2/src/pkg/database/sql/sql.go:574 +0x3e
created by database/sql.Open
        /home/user/.gvm/gos/go1.2/src/pkg/database/sql/sql.go:436 +0x24d
goroutine 11 [finalizer wait]:
runtime.park(0x40aa00, 0xd5dc18, 0xd5b8c8)
        /home/user/.gvm/gos/go1.2/src/pkg/runtime/proc.c:1342 +0x66
runfinq()
        /home/user/.gvm/gos/go1.2/src/pkg/runtime/mgc0.c:2276 +0x84
runtime.goexit()
        /home/user/.gvm/gos/go1.2/src/pkg/runtime/proc.c:1394

@gopherbot
Copy link
Author

Comment 3 by dimitrij.denissenko@blacksquaremedia.com:

Unfortunately there are limitations to what I can expose as it is a proprietary client
app, but please see a different panic message from the same app. There are dozens of
goroutines, so I have copied the first few as all the others are in a runnable state.
Here is the code which causes this is:
// proprietary.com/client/app.(*Mux).Handle
func (m *Mux) Handle(w http.ResponseWriter, req *http.Request) {
  data, err := DefaultParser.Parse(req.Body)
  ...
}
// proprietary.com/client/app.(*Parser).Parse
func (p *Parser) Parse(rd io.Reader) .... {
  req, err := protocol.ParseRequest(rd)
  ...
}
// proprietary.com/client/app/protocol.ParseRequest
func ParseRequest(reader io.Reader) ... {
  dec := json.NewDecoder(reader)
  if err = dec.Decode(&req); err != nil { // -> PANIC (see below)
    return nil, err
  }
  ...
}
The panic message:
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x20 pc=0x5e65ca]
goroutine 8761184 [running]:
runtime.panic(0x7c3560, 0xd59d88)
        /home/user/.gvm/gos/go1.2/src/pkg/runtime/panic.c:266 +0xb6
bufio.(*Reader).fill(0xc211a1c000)
        /home/user/.gvm/gos/go1.2/src/pkg/bufio/bufio.go:91 +0x10a
bufio.(*Reader).Read(0xc211a1c000, 0xc210a86000, 0x200, 0x200, 0x200, ...)
        /home/user/.gvm/gos/go1.2/src/pkg/bufio/bufio.go:159 +0x1a4
io.(*LimitedReader).Read(0xc2144bdae0, 0xc210a86000, 0x200, 0x200, 0x200, ...)
        /home/user/.gvm/gos/go1.2/src/pkg/io/io.go:398 +0xbb
net/http.(*body).Read(0xc210ab4a80, 0xc210a86000, 0x200, 0x200, 0x0, ...)
        /home/user/.gvm/gos/go1.2/src/pkg/net/http/transfer.go:534 +0x96
encoding/json.(*Decoder).readValue(0xc215022c40, 0x8, 0xc21196d900, 0xba)
        /home/user/.gvm/gos/go1.2/src/pkg/encoding/json/stream.go:124 +0x4af
encoding/json.(*Decoder).Decode(0xc215022c40, 0x6d6760, 0xc210261628, 0x14e6413c,
0x42723e)
        /home/user/.gvm/gos/go1.2/src/pkg/encoding/json/stream.go:44 +0x57
proprietary.com/client/app/protocol.ParseRequest(0x7ff17152a0e0, 0xc210ab4a80,
0xc200000000, 0x0, 0x0)
        /home/user/app/releases/20140312144700/_vendor/src/proprietary.com/client/app/protocol/request.go:34 +0xb0
proprietary.com/client/app.(*Parser).Parse(0xd580e0, 0x7ff17152a0e0, 0xc210ab4a80,
0xc2102606c0, 0x0, ...)
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/parser.go:133 +0xc2
proprietary.com/client/app.(*Mux).Handle(0xc210000ab0, 0x7ff179ba4e50, 0xc2144bdb00,
0xc2155a1c30, 0x7ff179b9d758, ...)
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/mux.go:128 +0x270
proprietary.com/client/app.func·008(0x7ff179ba4e50, 0xc2144bdb00, 0xc2155a1c30)
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/mux.go:792 +0x54
net/http.HandlerFunc.ServeHTTP(0xc2100956e0, 0x7ff179ba4e50, 0xc2144bdb00, 0xc2155a1c30)
        /home/user/.gvm/gos/go1.2/src/pkg/net/http/server.go:1220 +0x40
proprietary.com/client/app/utils.func·002()
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/utils/timeout.go:27 +0x86
created by proprietary.com/client/app/utils.(*timeoutHandler).ServeHTTP
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/utils/timeout.go:29 +0x134
goroutine 1 [IO wait]:
net.runtime_pollWait(0x7ff179b9e780, 0x72, 0x0)
        /home/user/.gvm/gos/go1.2/src/pkg/runtime/netpoll.goc:116 +0x6a
net.(*pollDesc).Wait(0xc210097c30, 0x72, 0x7ff179b9d180, 0xb)
        /home/user/.gvm/gos/go1.2/src/pkg/net/fd_poll_runtime.go:81 +0x34
net.(*pollDesc).WaitRead(0xc210097c30, 0xb, 0x7ff179b9d180)
        /home/user/.gvm/gos/go1.2/src/pkg/net/fd_poll_runtime.go:86 +0x30
net.(*netFD).accept(0xc210097bd0, 0x938758, 0x0, 0x7ff179b9d180, 0xb)
        /home/user/.gvm/gos/go1.2/src/pkg/net/fd_unix.go:382 +0x2c2
net.(*UnixListener).AcceptUnix(0xc21010e7a0, 0x4d284b, 0x7ff1799fdcf0, 0x4d284b)
        /home/user/.gvm/gos/go1.2/src/pkg/net/unixsock_posix.go:283 +0x4b
net.(*UnixListener).Accept(0xc21010e7a0, 0x0, 0x0, 0x0, 0x0)
        /home/user/.gvm/gos/go1.2/src/pkg/net/unixsock_posix.go:294 +0x4b
net/http.(*Server).Serve(0xc210099780, 0x7ff179ba43f0, 0xc21010e7a0, 0x0, 0x0)
        /home/user/.gvm/gos/go1.2/src/pkg/net/http/server.go:1622 +0x91
proprietary.com/client/app.(*Mux).ListenAndServe(0xc210000ab0, 0xc210000940, 0x4,
0x7fff18194e9c, 0x15, ...)
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/mux.go:108 +0x2bb
proprietary.com/client/app.(*app).Run(0xd5fcc0, 0x7fff18194e9c, 0x15, 0x7fff18194e7f,
0x16)
        /home/user/app/releases/20140312144700/src/proprietary.com/client/app/app.go:85 +0x767
main.main()
        /home/user/app/releases/20140312144700/worker/worker.go:17 +0x63
goroutine 3 [syscall]:
os/signal.loop()
        /home/user/.gvm/gos/go1.2/src/pkg/os/signal/signal_unix.go:21 +0x1e
created by os/signal.init·1
        /home/user/.gvm/gos/go1.2/src/pkg/os/signal/signal_unix.go:27 +0x31
goroutine 4 [chan receive]:
github.com/golang/glog.(*loggingT).flushDaemon(0xd5fe00)
        /home/user/app/releases/20140312144700/_vendor/src/github.com/golang/glog/glog.go:839 +0x50
created by github.com/golang/glog.init·1
        /home/user/app/releases/20140312144700/_vendor/src/github.com/golang/glog/glog.go:406 +0x276
goroutine 5 [syscall]:
runtime.goexit()
        /home/user/.gvm/gos/go1.2/src/pkg/runtime/proc.c:1394
goroutine 9 [chan receive]:
database/sql.(*DB).connectionOpener(0xc21004bb00)
        /home/user/.gvm/gos/go1.2/src/pkg/database/sql/sql.go:574 +0x3e
created by database/sql.Open
        /home/user/.gvm/gos/go1.2/src/pkg/database/sql/sql.go:436 +0x24d
goroutine 11 [finalizer wait]:
runtime.park(0x40aa00, 0xd5dc18, 0xd5b8c8)
        /home/user/.gvm/gos/go1.2/src/pkg/runtime/proc.c:1342 +0x66
runfinq()
        /home/user/.gvm/gos/go1.2/src/pkg/runtime/mgc0.c:2276 +0x84
runtime.goexit()
        /home/user/.gvm/gos/go1.2/src/pkg/runtime/proc.c:1394

@gopherbot
Copy link
Author

Comment 4 by dimitrij.denissenko@blacksquaremedia.com:

Any comments/suggestions? Do you need more information or was that sufficient?

@bradfitz
Copy link
Contributor

bradfitz commented Apr 3, 2014

Comment 5:

My first guess is that you have a data race.  Have you run your code under the race
detector?
Without a minimal repro that crashes at tip, I'm inclined to say that it's a bug in your
code, but I would love to be proven wrong.

@olov
Copy link

olov commented Apr 23, 2014

Comment 6:

I just filed issue #7848 with a minimal test case. This issue is most likely related to
it.

@rsc
Copy link
Contributor

rsc commented May 21, 2014

Comment 7:

Status changed to Duplicate.

Merged into issue #7848.

@rsc rsc mentioned this issue Dec 8, 2014
Closed
@golang golang locked and limited conversation to collaborators Jun 25, 2016
This issue was closed.
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@bradfitz @davecheney @olov @rsc @gopherbot