nil pointer dereference on consul exec

[zkrapavickas]

If you have a question, please direct it to the
consul mailing list if it hasn't been
addressed in either the FAQ or in one
of the Consul Guides.

When filing a bug, please include the following:

consul version for both Client and Server

Client: 0.7.2
Server: 0.7.2

consul info for both Client and Server

Client:

agent:
        check_monitors = 0
        check_ttls = 0
        checks = 0
        services = 0
build:
        prerelease =
        revision = 'a9afa0c
        version = 0.7.2
consul:
        known_servers = 3
        server = false
runtime:
        arch = amd64
        cpu_count = 2
        goroutines = 36
        max_procs = 2
        os = linux
        version = go1.7.3
serf_lan:
        encrypted = true
        event_queue = 0
        event_time = 28
        failed = 0
        health_score = 0
        intent_queue = 0
        left = 0
        member_time = 4
        members = 4
        query_queue = 0
        query_time = 1

Server:

agent:
        check_monitors = 0
        check_ttls = 0
        checks = 0
        services = 1
build:
        prerelease =
        revision = 'a9afa0c
        version = 0.7.2
consul:
        bootstrap = false
        known_datacenters = 1
        leader = true
        leader_addr = x.x.x.219:8300
        server = true
raft:
        applied_index = 30533
        commit_index = 30533
        fsm_pending = 0
        last_contact = 0
        last_log_index = 30533
        last_log_term = 19
        last_snapshot_index = 24577
        last_snapshot_term = 6
        latest_configuration = [{Suffrage:Voter ID:x.x.x.216:8300 Address:x.x.x.216:8300} {Suffrage:Voter ID:x.x.x.219:8300 Address:x.x.x.219:8300} {Suffrage:Voter ID:x.x.x.215:8300 Address:x.x.x.215:8300}]
        latest_configuration_index = 5
        num_peers = 2
        protocol_version = 1
        protocol_version_max = 3
        protocol_version_min = 0
        snapshot_version_max = 1
        snapshot_version_min = 0
        state = Leader
        term = 19
runtime:
        arch = amd64
        cpu_count = 2
        goroutines = 76
        max_procs = 2
        os = linux
        version = go1.7.3
serf_lan:
        encrypted = true
        event_queue = 0
        event_time = 28
        failed = 0
        health_score = 0
        intent_queue = 0
        left = 0
        member_time = 4
        members = 4
        query_queue = 0
        query_time = 1
serf_wan:
        encrypted = true
        event_queue = 0
        event_time = 1
        failed = 0
        health_score = 0
        intent_queue = 0
        left = 0
        member_time = 1
        members = 1
        query_queue = 0
        query_time = 1

Operating system and Environment details

Centos 7

Description of the Issue (and unexpected/desired result)

Executing "consul exec -node="^test" 'ls'" on client crashes random server. In this example node filtered to "^test", node with this name doesn't exists, random server crashes even when filter specifies existing node. No problems when executed on server node.

Reproduction steps

Setup:
3 x server (v0.7.2)
1 x client (v0.7.2)

Log Fragments or Link to gist

Crashed server log:

2016/12/30 13:55:06 [DEBUG] serf: messageUserEventType: consul:event:_rexec
2016/12/30 13:55:06 [DEBUG] consul: User event: _rexec
2016/12/30 13:55:06 [DEBUG] serf: messageUserEventType: consul:event:_rexec
2016/12/30 13:55:06 [DEBUG] serf: messageUserEventType: consul:event:_rexec
2016/12/30 13:55:06 [DEBUG] serf: messageUserEventType: consul:event:_rexec
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x20 pc=0x639cbd]
goroutine 101 [running]:
panic(0xd5a540, 0xc42000e020)
/goroot/src/runtime/panic.go:500 +0x1a1
github.com/hashicorp/consul/consul.(*Session).Apply(0xc42006c300, 0xc4200a1290, 0xc4202ba0f0, 0x0, 0x0)
/gopath/src/github.com/hashicorp/consul/consul/session_endpoint.go:46 +0x30d
reflect.Value.call(0xc42021a840, 0xc42006c660, 0x13, 0xe830f5, 0x4, 0xc420373dd8, 0x3, 0x3, 0xa3dc7f, 0xc4201bac00, ...)
/goroot/src/reflect/value.go:434 +0x5c8
reflect.Value.Call(0xc42021a840, 0xc42006c660, 0x13, 0xc420373dd8, 0x3, 0x3, 0xc4202ba0f0, 0x16, 0xc42026bf80)
/goroot/src/reflect/value.go:302 +0xa4
net/rpc.(*service).call(0xc420169e40, 0xc420169940, 0xc4204e0118, 0xc42021ed80, 0xc42026bf80, 0xd8b6c0, 0xc4200a1290, 0x16, 0xcb9f00, 0xc4202ba0f0, ...)
/goroot/src/net/rpc/server.go:383 +0x148
net/rpc.(*Server).ServeRequest(0xc420169940, 0x13a37e0, 0xc4201bac00, 0x3f800000, 0x0)
/goroot/src/net/rpc/server.go:498 +0x270
github.com/hashicorp/consul/consul.(*Server).handleConsulConn(0xc4202081e0, 0x13a7fc0, 0xc4204d8000)
/gopath/src/github.com/hashicorp/consul/consul/rpc.go:163 +0x12f
created by github.com/hashicorp/consul/consul.(*Server).handleMultiplexV2
/gopath/src/github.com/hashicorp/consul/consul/rpc.go:148 +0x1bd

Include appropriate Client or Server log fragments. If the log is longer
than a few dozen lines, please include the URL to the
gist.

TIP: Use -log-level=TRACE on the client and server to capture the maximum log detail.

[deckarep]

Trying to help triage this issue...hopefully this is helpful.

This is panicking because: https://github.com/hashicorp/consul/blob/v0.7.2/consul/session_endpoint.go#L42 is a valid case where an err is not returned but a session was not found, therefore the lookup was successful but no session exists.

Here is where the StateStore can possibly return such a case: https://github.com/hashicorp/consul/blob/v0.7.2/consul/state/state_store.go#L1537

I don't yet know enough about this code to submit a patch but the fix may be at least as simple as checking both that no error occurred and additionally checking that existing is not nil then returning a meaningful error instead of just panicking.

[slackpad]

@deckarep indeed that was it - thanks for the triage. PR incoming for this now.

[deckarep]

Alright! Glad to hear that @slackpad!