nil pointer dereference on server restart

[nikitug]

Hi,

We got a nil pointer dereference:

[05/26/14 14:52:48] [INFO] Loading configuration file /opt/influxdb/shared/config.toml

+---------------------------------------------+
|  _____        __ _            _____  ____   |
| |_   _|      / _| |          |  __ \|  _ \  |
|   | |  _ __ | |_| |_   ___  _| |  | | |_) | |
|   | | | '_ \|  _| | | | \ \/ / |  | |  _ <  |
|  _| |_| | | | | | | |_| |>  <| |__| | |_) | |
| |_____|_| |_|_| |_|\__,_/_/\_\_____/|____/  |
+---------------------------------------------+

[2014/05/26 14:52:48 MSK] [INFO] (main.setupLogging:53) Redirectoring logging to /opt/influxdb/shared/log.txt
[2014/05/26 14:52:48 MSK] [INFO] (main.main:120) Starting Influx Server InfluxDB v0.7.0 (git: 696d61d) (leveldb: 1.15) bound to 0.0.0.0...
[2014/05/26 14:52:48 MSK] [INFO] (server.NewServer:35) Opening database at /opt/influxdb/shared/data/db
[2014/05/26 14:52:48 MSK] [INFO] (wal.NewWAL:40) Opening wal in /opt/influxdb/shared/data/wal
[2014/05/26 14:52:48 MSK] [INFO] (coordinator.NewRaftServer:79) Using /dev/urandom to initialize the raft server name
[2014/05/26 14:52:48 MSK] [INFO] (coordinator.NewRaftServer:104) Setting raft name to 60bed40d5e6946a3
[2014/05/26 14:52:48 MSK] [INFO] (api/http.(*HttpServer).EnableSsl:62) Ssl will be disabled since the ssl port or certificate path weren't set
[2014/05/26 14:52:48 MSK] [INFO] (coordinator.(*RaftServer).Serve:513) Initializing Raft HTTP server
[2014/05/26 14:52:48 MSK] [INFO] (coordinator.(*RaftServer).Serve:524) Raft Server Listening at 0.0.0.0:8090
[2014/05/26 14:52:48 MSK] [INFO] (coordinator.(*RaftServer).startRaft:353) Initializing Raft Server: http://prs-0-1.msk:8090
[2014/05/26 14:52:48 MSK] [INFO] (coordinator.(*RaftServer).startRaft:398) (raft:60bed40d5e6946a3) Attempting to join leader: prs-0-2.msk:8090
[2014/05/26 14:52:48 MSK] [INFO] (coordinator.(*RaftServer).startRaft:401) Joined: prs-0-2.msk:8090
[2014/05/26 14:52:48 MSK] [INFO] (server.(*Server).ListenAndServe:87) Waiting for local server to be added
[2014/05/26 14:54:26 MSK] [INFO] (main.waitForSignals:24) Received signal: terminated
[2014/05/26 14:54:26 MSK] [INFO] (server.(*Server).Stop:163) Stopping server
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x30 pc=0x47ead4]

goroutine 10 [running]:
runtime.panic(0x8955c0, 0x10237c8)
    /home/vagrant/bin/go/src/pkg/runtime/panic.c:266 +0xb6
coordinator.(*ProtobufServer).Close(0xc2100cd200)
    /home/vagrant/influxdb/src/coordinator/protobuf_server.go:34 +0x34
server.(*Server).Stop(0xc2100784d0)
    /home/vagrant/influxdb/src/server/server.go:179 +0x2ce
main.waitForSignals(0x7f035be602a0, 0xc2100784d0)
    /home/vagrant/influxdb/src/daemon/null_profiler.go:27 +0x295
created by main.startProfiler
    /home/vagrant/influxdb/src/daemon/null_profiler.go:15 +0x38

goroutine 1 [chan receive]:
server.(*Server).ListenAndServe(0xc2100784d0, 0xc2100784d0, 0x0)
    /home/vagrant/influxdb/src/server/server.go:88 +0xcf
main.main()
    /home/vagrant/influxdb/src/daemon/influxd.go:158 +0xd17

goroutine 3 [syscall]:
os/signal.loop()
    /home/vagrant/bin/go/src/pkg/os/signal/signal_unix.go:21 +0x1e
created by os/signal.init·1
    /home/vagrant/bin/go/src/pkg/os/signal/signal_unix.go:27 +0x31

goroutine 4 [chan receive]:
code.google.com/p/log4go.ConsoleLogWriter.run(0xc210069000, 0x7f035be57110, 0xc210000008)
    /home/vagrant/influxdb/src/code.google.com/p/log4go/termlog.go:27 +0x60
created by code.google.com/p/log4go.NewConsoleLogWriter
    /home/vagrant/influxdb/src/code.google.com/p/log4go/termlog.go:19 +0x67

goroutine 5 [syscall]:
runtime.goexit()
    /home/vagrant/bin/go/src/pkg/runtime/proc.c:1394

goroutine 6 [runnable]:
bytes.func·001()
    /home/vagrant/bin/go/src/pkg/bytes/buffer.go:186
bytes.makeSlice(0x93, 0xc210158320, 0x93, 0x93)
    /home/vagrant/bin/go/src/pkg/bytes/buffer.go:192 +0x82
bytes.(*Buffer).grow(0xc210116770, 0x13, 0x2)
    /home/vagrant/bin/go/src/pkg/bytes/buffer.go:99 +0x200
bytes.(*Buffer).WriteString(0xc210116770, 0x95c370, 0x13, 0x4, 0x0, ...)
    /home/vagrant/bin/go/src/pkg/bytes/buffer.go:136 +0x4b
code.google.com/p/log4go.FormatLogRecord(0x95d0b0, 0x14, 0xc2100cd040, 0x1a, 0x1)
    /home/vagrant/influxdb/src/code.google.com/p/log4go/pattlog.go:82 +0xbbc
code.google.com/p/log4go.func·002()
    /home/vagrant/influxdb/src/code.google.com/p/log4go/filelog.go:105 +0x54b
created by code.google.com/p/log4go.NewFileLogWriter
    /home/vagrant/influxdb/src/code.google.com/p/log4go/filelog.go:116 +0x2d1

goroutine 7 [chan receive]:
wal.(*WAL).processEntries(0xc2100d3180)
    /home/vagrant/influxdb/src/wal/wal.go:252 +0x3f
created by wal.NewWAL
    /home/vagrant/influxdb/src/wal/wal.go:103 +0x9f3

goroutine 8 [sleep]:
time.Sleep(0x8bb2c97000)
    /tmp/makerelease886106415/go/src/pkg/runtime/time.goc:31 +0x31
cluster.func·001()
    /home/vagrant/influxdb/src/cluster/cluster_configuration.go:132 +0x35
created by cluster.(*ClusterConfiguration).CreateFutureShardsAutomaticallyBeforeTimeComes
    /home/vagrant/influxdb/src/cluster/cluster_configuration.go:137 +0x63

goroutine 11 [runnable]:
net.(*netFD).readUnlock(0xc210078540)
    /home/vagrant/bin/go/src/pkg/net/fd_unix.go:129
net.(*netFD).accept(0xc210078540, 0xa0b740, 0x0, 0x7f035be66be8, 0xc2100cde40)
    /home/vagrant/bin/go/src/pkg/net/fd_unix.go:406 +0x83
net.(*TCPListener).AcceptTCP(0xc210000158, 0x5cfd0b, 0x7f035bcb1ed0, 0x5cfd0b)
    /home/vagrant/bin/go/src/pkg/net/tcpsock_posix.go:233 +0x47
net.(*TCPListener).Accept(0xc210000158, 0x7f035be61728, 0xc2100c9150, 0xc2100d3280, 0x0)
    /home/vagrant/bin/go/src/pkg/net/tcpsock_posix.go:243 +0x27
net/http.(*Server).Serve(0xc2100ce280, 0x7f035be60320, 0xc210000158, 0x0, 0x0)
    /home/vagrant/bin/go/src/pkg/net/http/server.go:1622 +0x91
coordinator.func·007()
    /home/vagrant/influxdb/src/coordinator/raft_server.go:527 +0x3a
created by coordinator.(*RaftServer).Serve
    /home/vagrant/influxdb/src/coordinator/raft_server.go:531 +0x4d9

goroutine 14 [select]:
coordinator.(*RaftServer).CompactLog(0xc21006a210)
    /home/vagrant/influxdb/src/coordinator/raft_server.go:317 +0x2ef
created by coordinator.(*RaftServer).startRaft
    /home/vagrant/influxdb/src/coordinator/raft_server.go:371 +0x375

goroutine 19 [finalizer wait]:
runtime.park(0x451a00, 0x103a8d8, 0x1025308)
    /home/vagrant/bin/go/src/pkg/runtime/proc.c:1342 +0x66
runfinq()
    /home/vagrant/bin/go/src/pkg/runtime/mgc0.c:2279 +0x84
runtime.goexit()
    /home/vagrant/bin/go/src/pkg/runtime/proc.c:1394

It happened on restart when running server was unable to communicate to seed-servers.

InfluxDB v0.7.0 (git: 696d61d) (leveldb: 1.15)

Do you need some additional details regarding this issue?

[jvshahid]

@nikitug it looks like something is sending a signal to the process and killing it.

[nikitug]

@jvshahid yes, that's what happen on service restart. But shouldn't kill be handled correctly without failing?