consul watch does not trigger the child process when acl_default_policy is set to deny

[nanoz]

consul version

Client: v0.9.0
Server: v0.9.0

consul info

Client:

agent:
	check_monitors = 0
	check_ttls = 0
	checks = 0
	services = 0
build:
	prerelease =
	revision = b79d951
	version = 0.9.0
consul:
	bootstrap = true
	known_datacenters = 1
	leader = true
	leader_addr = 10.72.152.206:8300
	server = true
raft:
	applied_index = 161
	commit_index = 161
	fsm_pending = 0
	last_contact = 0
	last_log_index = 161
	last_log_term = 2
	last_snapshot_index = 0
	last_snapshot_term = 0
	latest_configuration = [{Suffrage:Voter ID:10.72.152.206:8300 Address:10.72.152.206:8300}]
	latest_configuration_index = 1
	num_peers = 0
	protocol_version = 2
	protocol_version_max = 3
	protocol_version_min = 0
	snapshot_version_max = 1
	snapshot_version_min = 0
	state = Leader
	term = 2
runtime:
	arch = amd64
	cpu_count = 2
	goroutines = 100
	max_procs = 2
	os = linux
	version = go1.8.3
serf_lan:
	coordinate_resets = 0
	encrypted = true
	event_queue = 0
	event_time = 13
	failed = 0
	health_score = 0
	intent_queue = 0
	left = 0
	member_time = 697
	members = 3
	query_queue = 0
	query_time = 1
serf_wan:
	coordinate_resets = 0
	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

Server:

agent:
	check_monitors = 0
	check_ttls = 0
	checks = 0
	services = 0
build:
	prerelease =
	revision = b79d951
	version = 0.9.0
consul:
	bootstrap = true
	known_datacenters = 1
	leader = true
	leader_addr = 10.72.152.206:8300
	server = true
raft:
	applied_index = 162
	commit_index = 162
	fsm_pending = 0
	last_contact = 0
	last_log_index = 162
	last_log_term = 2
	last_snapshot_index = 0
	last_snapshot_term = 0
	latest_configuration = [{Suffrage:Voter ID:10.72.152.206:8300 Address:10.72.152.206:8300}]
	latest_configuration_index = 1
	num_peers = 0
	protocol_version = 2
	protocol_version_max = 3
	protocol_version_min = 0
	snapshot_version_max = 1
	snapshot_version_min = 0
	state = Leader
	term = 2
runtime:
	arch = amd64
	cpu_count = 2
	goroutines = 99
	max_procs = 2
	os = linux
	version = go1.8.3
serf_lan:
	coordinate_resets = 0
	encrypted = true
	event_queue = 0
	event_time = 13
	failed = 0
	health_score = 0
	intent_queue = 0
	left = 0
	member_time = 697
	members = 3
	query_queue = 0
	query_time = 1
serf_wan:
	coordinate_resets = 0
	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

Server runs on Debian Jessie, client is on mac with CONSUL_HTTP_ADDR and CONSUL_HTTP_TOKEN correctly set. Here is the ACL configuration :

{
  "acl_enforce_version_8": true,

  "acl_datacenter": "dc1",
  "acl_default_policy": "deny",
  "acl_down_policy": "extend-cache",
  "acl_ttl": "30s",
}

Description of the Issue (and unexpected/desired result)

Consul watch does not trigger when acl_default_policy is set to deny, even with a master token or with every ACL set to write. I could work around that problem by setting acl_default_policy to allow, but I would prefer to set the proper ACL policy to get it to work.

Reproduction steps

consul watch -type=keyprefix -prefix="services/restart/" echo reload

consul kv put services/restart/test hi

Log Fragments

Server log for consul watch :

Aug 11 12:31:03 admin-10-72-152-206 consul[17113]: 2017/08/11 12:31:03 [DEBUG] http: Request GET /v1/agent/self (693.758µs) from=10.72.140.144:49230
Aug 11 12:31:03 admin-10-72-152-206 consul[17113]: 2017/08/11 12:31:03 [DEBUG] http: Request GET /v1/kv/services/restart/?recurse= (94.493µs) from=10.72.140.144:49231
Aug 11 12:31:31 admin-10-72-152-206 consul[17113]: 2017/08/11 12:31:31 [DEBUG] http: Request GET /v1/kv/services/restart/?recurse=&stale= (97.595µs) from=10.72.154.45:10530

Server log when consul kv put is executed :

Aug 11 12:32:13 admin-10-72-152-206 consul[17113]: 2017/08/11 12:32:13 [DEBUG] http: Request GET /v1/kv/services/restart/?index=121&recurse= (1m9.162114879s) from=10.72.140.144:49231
Aug 11 12:32:13 admin-10-72-152-206 consul[17113]: 2017/08/11 12:32:13 [DEBUG] http: Request GET /v1/kv/services/restart/?index=121&recurse=&stale= (41.121869994s) from=10.72.154.45:10530
Aug 11 12:32:13 admin-10-72-152-206 consul[17113]: 2017/08/11 12:32:13 [DEBUG] http: Request GET /v1/kv/services/restart/?index=121&recurse= (1m21.367793019s) from=10.72.140.144:49227
Aug 11 12:32:13 admin-10-72-152-206 consul[17113]: 2017/08/11 12:32:13 [DEBUG] http: Request GET /v1/kv/services/restart/?index=121&recurse=&stale= (5.985543051s) from=10.72.154.45:10570
Aug 11 12:32:13 admin-10-72-152-206 consul[17113]: 2017/08/11 12:32:13 [DEBUG] http: Request GET /v1/kv/services/restart/?index=121&recurse=&stale= (1m15.481924391s) from=10.72.154.45:10500
Aug 11 12:32:13 admin-10-72-152-206 consul[17113]: 2017/08/11 12:32:13 [DEBUG] http: Request PUT /v1/kv/services/restart/my-sample-service/dev/my-sample-service-stable (5.636545ms) from=10.72.154.45:10580

[preetapan]

@nanoz Thanks for reporting this. This behavior seems to only affect happen with watches done via consul watch. We will look into fixing it in an upcoming release.

As a work around, you could define the same watch inside the agent's config file. I was able to do that with your example above and saw it invoke the watch handler every time the key changed. Example config:

"watches":[
{
  "type": "keyprefix",
  "prefix": "services/restart",
  "handler": "/path/to/watch/handler"
}

[nanoz]

Thanks for the quick reply !

I tried to reproduce the problem with consul watch for this bug report, but I actually have the problem on Nomad's template stanza, which subscribes to keys using consul-template internally. So I can't really use this workaround :)