consul monitor doesn't respond to SIGINT/TERM until initial log lines come in

[c4milo]

When running consul monitor on machines with acl tokens without enough privileges, it blocks forever and doesn't respond to SIGINT or SIGTERM signals.

Reproduction steps

1. Provision a Consul cluster with ACLs enabled
2. Create an ACL token without permissions to see other nodes
3. Run a client agent with token created in 2.
4. Run consul monitor

Expected behavior

Exit immediately with a message indicating the lack of permissions.

consul version for both Client and Server

Client: v1.0.6
Server: v1.0.6

[banks]

I think the ACL part is even a red-herring I just tested master locally and consul monitor doesn't respond to SIGINT even with ACLs disabled on the agent.

I've edited the title to make the scope clearer.

Thanks for the report!

[banks]

Breadcrumbs: note that we do register monitor for shutdown handling here:

consul/command/commands_oss.go

Line 78 in 521e46c

Register("monitor", func(ui cli.Ui) (cli.Command, error) { return monitor.New(ui, MakeShutdownCh()), nil })

And that includes os.Interrupt and syscall.SIGTERM:

consul/command/registry.go

Line 51 in 521e46c

signal.Notify(signalCh, os.Interrupt, syscall.SIGTERM)

[banks]

It seems that this only happens when there is no output yet. In my case there was only debug events in the log and i wasn't useing debug level so it hung uninteruptible. As soon as I allow DEBUG level I saw logs and Ctrl-C works fine.

In your case here @c4milo the ACL issue prevents any logs from ever being fetched causing same issue.

[banks]

This is caused by the call to the monitor API here:

consul/command/monitor/monitor.go

Line 57 in 4c90fbf

logCh, err := client.Agent().Monitor(c.logLevel, eventDoneCh, nil)

Being made before shutdownCh is being selected on.

In turn the agent calls the monitor API which effectively blocks until some matching log lines come in:

~/s/g/s/g/h/consul (fix-monitor-sigint-3891 ⚡☡=) curl -v 'localhost:8500/v1/agent/monitor?loglevel=ERR'
*   Trying ::1...
* TCP_NODELAY set
* Connection failed
* connect to ::1 port 8500 failed: Connection refused
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 8500 (#0)
> GET /v1/agent/monitor?loglevel=ERR HTTP/1.1
> Host: localhost:8500
> User-Agent: curl/7.54.0
> Accept: */*
>
^C⏎

Note that not even response headers were returned immediately. It seems like it would be a nicer API for a streaming response to have the headers return immediately and the the body only stream in as there is content. That seems to be what our own client is expecting.

PR incoming.

[c4milo]

Nice! thank you @banks!

[banks]

@c4milo just checking that did actually fix you're issue right? I think the ACL thin was unrelated but just wanted to check!

[c4milo]

@banks, I haven't had a chance to build a custom binary with this fix yet, I'll report back once I can do that. In the mean time, I believe you missed adding an entry in the CHANGELOG :)

[banks]

Great catch @c4milo thanks ;)

[MichaelSteffens]

It looks like this fix is almost the same as the one proposed with #3695 last November, attempting to fix #3317 submitted in July. So presumably these can both be closed now.

[banks]

@MichaelSteffens good catch yep those are all obsolete here now thanks.

[MichaelSteffens]

Confirmed: As expected this fix does also fix #3317. @banks thanks!