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.

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

Intermittent Events #479

Closed
hoffoo opened this issue Nov 18, 2014 · 3 comments · Fixed by #489
Closed

Intermittent Events #479

hoffoo opened this issue Nov 18, 2014 · 3 comments · Fixed by #489
Labels
type/bug Feature does not function as expected

Comments

@hoffoo
Copy link
Contributor

hoffoo commented Nov 18, 2014

I am having a problem where events are not always fired. Here is my attempt to reproduce the issue:

==> WARNING: Bootstrap mode enabled! Do not enable unless necessary
==> WARNING: It is highly recommended to set GOMAXPROCS higher than 1
==> Starting Consul agent...
==> Starting Consul agent RPC...
==> Consul agent running!
         Node name: 'fatpad'
        Datacenter: 'dc1'
            Server: true (bootstrap: true)
       Client Addr: 127.0.0.1 (HTTP: 8500, DNS: 8600, RPC: 8400)
      Cluster Addr: 192.168.1.102 (LAN: 8301, WAN: 8302)
    Gossip encrypt: false, RPC-TLS: false, TLS-Incoming: false

==> Log data will now stream in as it occurs:

    2014/11/18 12:06:14 [INFO] serf: EventMemberJoin: fatpad 192.168.1.102
    2014/11/18 12:06:14 [INFO] serf: EventMemberJoin: fatpad.dc1 192.168.1.102
    2014/11/18 12:06:14 [INFO] raft: Node at 192.168.1.102:8300 [Follower] entering Follower state
    2014/11/18 12:06:14 [INFO] consul: adding server fatpad (Addr: 192.168.1.102:8300) (DC: dc1)
    2014/11/18 12:06:14 [INFO] consul: adding server fatpad.dc1 (Addr: 192.168.1.102:8300) (DC: dc1)
    2014/11/18 12:06:15 [DEBUG] dns: request for {_test.consul. 255 1} (33.4us)
    2014/11/18 12:06:15 [DEBUG] dns: request for {_test.consul. 255 1} (54.09us)
    2014/11/18 12:06:15 [ERR] agent: failed to sync remote state: No cluster leader
    2014/11/18 12:06:15 [DEBUG] http: Request /v1/event/list?name=ev4 (37.656us)
    2014/11/18 12:06:15 [DEBUG] http: Request /v1/event/list?name=ev3 (24.788us)
    2014/11/18 12:06:15 [DEBUG] http: Request /v1/event/list?name=ev2 (27.39us)
    2014/11/18 12:06:15 [DEBUG] http: Request /v1/event/list?name=ev1 (11.524us)
    2014/11/18 12:06:15 [DEBUG] agent: watch handler 'touch /tmp/o' output: 

    2014/11/18 12:06:15 [ERR] agent: Failed to invoke watch handler 'touch /tmp/o': write |1: broken pipe
    2014/11/18 12:06:15 [DEBUG] agent: watch handler 'touch /tmp/o' output: 
    2014/11/18 12:06:15 [ERR] agent: Failed to invoke watch handler 'touch /tmp/o': write |1: broken pipe
    2014/11/18 12:06:15 [DEBUG] agent: watch handler 'touch /tmp/o' output: 
    2014/11/18 12:06:15 [ERR] agent: Failed to invoke watch handler 'touch /tmp/o': write |1: broken pipe
    2014/11/18 12:06:15 [DEBUG] agent: watch handler 'touch /tmp/o' output: 
    2014/11/18 12:06:16 [WARN] raft: Heartbeat timeout reached, starting election
    2014/11/18 12:06:16 [INFO] raft: Node at 192.168.1.102:8300 [Candidate] entering Candidate state
    2014/11/18 12:06:16 [DEBUG] raft: Votes needed: 1
    2014/11/18 12:06:16 [DEBUG] raft: Vote granted. Tally: 1
    2014/11/18 12:06:16 [INFO] raft: Election won. Tally: 1
    2014/11/18 12:06:16 [INFO] raft: Node at 192.168.1.102:8300 [Leader] entering Leader state
    2014/11/18 12:06:16 [INFO] consul: cluster leadership acquired
    2014/11/18 12:06:16 [INFO] consul: New leader elected: fatpad
    2014/11/18 12:06:16 [INFO] raft: Disabling EnableSingleNode (bootstrap)
    2014/11/18 12:06:16 [DEBUG] raft: Node 192.168.1.102:8300 updated peer set (2): [192.168.1.102:8300]
    2014/11/18 12:06:16 [INFO] consul: member 'fatpad' joined, marking health alive
    2014/11/18 12:06:19 [INFO] agent: Synced service 'consul'

~ $ consul event -name ev1
    2014/11/18 12:06:34 [DEBUG] http: Request /v1/agent/self (321.754us)
    2014/11/18 12:06:34 [DEBUG] http: Request /v1/event/fire/ev1 (84.887us)
    2014/11/18 12:06:34 [DEBUG] consul: user event: ev1
    2014/11/18 12:06:34 [DEBUG] agent: new event: ev1 (ed491faf-2052-b568-bbfc-c7a5e1daafe6)
    2014/11/18 12:06:34 [DEBUG] http: Request /v1/event/list?index=1&name=ev1 (19.393839072s)
    2014/11/18 12:06:34 [DEBUG] agent: watch handler 'touch /tmp/o' output: 

~ $ consul event -name ev1
    2014/11/18 12:06:40 [DEBUG] http: Request /v1/agent/self (94.42us)
    2014/11/18 12:06:40 [DEBUG] http: Request /v1/event/fire/ev1 (59.958us)
    2014/11/18 12:06:40 [DEBUG] consul: user event: ev1
    2014/11/18 12:06:40 [DEBUG] agent: new event: ev1 (fa9eadb7-15dc-1956-7144-d7cfef5b4aec)
    2014/11/18 12:06:40 [DEBUG] http: Request /v1/event/list?index=6248137598754626190&name=ev1 (5.611784027s)
    2014/11/18 12:06:40 [DEBUG] agent: watch handler 'touch /tmp/o' output: 

~ $ consul event -name ev2
    2014/11/18 12:06:45 [DEBUG] http: Request /v1/agent/self (63.288us)
    2014/11/18 12:06:45 [DEBUG] http: Request /v1/event/fire/ev2 (53.413us)
    2014/11/18 12:06:45 [DEBUG] consul: user event: ev2
    2014/11/18 12:06:45 [DEBUG] agent: new event: ev2 (dad711f7-338c-8d64-40cb-6a7b58d42c28)
    2014/11/18 12:06:45 [DEBUG] http: Request /v1/event/list?index=1&name=ev2 (30.690529179s)
    2014/11/18 12:06:45 [DEBUG] agent: watch handler 'touch /tmp/o' output: 

~ $ consul event -name ev1
    2014/11/18 12:06:50 [DEBUG] http: Request /v1/agent/self (161.602us)
    2014/11/18 12:06:50 [DEBUG] http: Request /v1/event/fire/ev1 (131.574us)
    2014/11/18 12:06:50 [DEBUG] consul: user event: ev1
    2014/11/18 12:06:50 [DEBUG] agent: new event: ev1 (3a4564be-c187-a892-2772-28b4d0cdabfc)
    2014/11/18 12:06:50 [DEBUG] http: Request /v1/event/list?index=10077501776212743098&name=ev1 (10.122385391s)
    2014/11/18 12:06:50 [DEBUG] agent: watch handler 'touch /tmp/o' output: 

~ $ consul event -name ev1
    2014/11/18 12:06:56 [DEBUG] http: Request /v1/agent/self (83.935us)
    2014/11/18 12:06:56 [DEBUG] http: Request /v1/event/fire/ev1 (68.127us)
    2014/11/18 12:06:56 [DEBUG] consul: user event: ev1
    2014/11/18 12:06:56 [DEBUG] agent: new event: ev1 (ab01c528-fcfb-7c08-5178-379ae0382d13)

~ $ consul event -name ev1
    2014/11/18 12:07:07 [DEBUG] http: Request /v1/agent/self (221.767us)
    2014/11/18 12:07:07 [DEBUG] http: Request /v1/event/fire/ev1 (69.685us)
    2014/11/18 12:07:07 [DEBUG] consul: user event: ev1
    2014/11/18 12:07:07 [DEBUG] agent: new event: ev1 (b2cfd8e2-6024-e477-6336-e59cdb435c0c)
    2014/11/18 12:07:07 [DEBUG] http: Request /v1/event/list?index=2105234956942443374&name=ev1 (17.310499899s)
    2014/11/18 12:07:07 [DEBUG] agent: watch handler 'touch /tmp/o' output: 

~ $ consul event -name ev2
    2014/11/18 12:07:16 [DEBUG] http: Request /v1/agent/self (131.314us)
    2014/11/18 12:07:16 [DEBUG] http: Request /v1/event/fire/ev2 (83.639us)
    2014/11/18 12:07:16 [DEBUG] consul: user event: ev2
    2014/11/18 12:07:16 [DEBUG] agent: new event: ev2 (27034d69-f2c2-7203-849c-c3e1c765d6b7)

~ $ consul event -name ev2
    2014/11/18 12:07:22 [DEBUG] http: Request /v1/agent/self (173.366us)
    2014/11/18 12:07:22 [DEBUG] http: Request /v1/event/fire/ev2 (60.984us)
    2014/11/18 12:07:22 [DEBUG] consul: user event: ev2
    2014/11/18 12:07:22 [DEBUG] agent: new event: ev2 (3e81be09-3b62-559c-efeb-1bf6ed677166)

~ $ consul event -name ev3
    2014/11/18 12:07:27 [DEBUG] http: Request /v1/agent/self (62.558us)
    2014/11/18 12:07:27 [DEBUG] http: Request /v1/event/fire/ev3 (40.183us)
    2014/11/18 12:07:27 [DEBUG] consul: user event: ev3
    2014/11/18 12:07:27 [DEBUG] agent: new event: ev3 (027caaf7-1ebc-6625-3a17-5a139e20d2e3)
    2014/11/18 12:07:27 [DEBUG] http: Request /v1/event/list?index=1&name=ev3 (1m12.658166871s)
    2014/11/18 12:07:27 [DEBUG] agent: watch handler 'touch /tmp/o' output: 

~ $ consul event -name ev3
    2014/11/18 12:07:30 [DEBUG] http: Request /v1/agent/self (77.657us)
    2014/11/18 12:07:30 [DEBUG] http: Request /v1/event/fire/ev3 (42.547us)
    2014/11/18 12:07:30 [DEBUG] consul: user event: ev3
    2014/11/18 12:07:30 [DEBUG] agent: new event: ev3 (8a2c5392-61be-fd5a-faff-c26216edb015)

~ $ consul event -name ev1
    2014/11/18 12:07:49 [DEBUG] http: Request /v1/agent/self (195.768us)
    2014/11/18 12:07:49 [DEBUG] http: Request /v1/event/fire/ev1 (164.775us)
    2014/11/18 12:07:49 [DEBUG] consul: user event: ev1
    2014/11/18 12:07:49 [DEBUG] agent: new event: ev1 (2230be73-1a83-22bd-04e8-430457ed45f5)
    2014/11/18 12:07:49 [DEBUG] http: Request /v1/event/list?index=18048723828464636187&name=ev1 (42.389372998s)
    2014/11/18 12:07:49 [DEBUG] agent: watch handler 'touch /tmp/o' output: 

~ $ consul event -name ev3
    2014/11/18 12:07:54 [DEBUG] http: Request /v1/agent/self (108.406us)
    2014/11/18 12:07:54 [DEBUG] http: Request /v1/event/fire/ev1 (81.266us)
    2014/11/18 12:07:54 [DEBUG] consul: user event: ev1
    2014/11/18 12:07:54 [DEBUG] agent: new event: ev1 (6d3ee6e0-3c87-1c5f-c8fa-565d7cb1c6ba)
    2014/11/18 12:07:54 [DEBUG] http: Request /v1/event/list?index=15130192037647202427&name=ev1 (4.261430265s)
    2014/11/18 12:07:54 [DEBUG] agent: watch handler 'touch /tmp/o' output: 

~ $ consul event -name ev3
    2014/11/18 12:07:56 [DEBUG] http: Request /v1/agent/self (229.921us)
    2014/11/18 12:07:56 [DEBUG] http: Request /v1/event/fire/ev3 (135.251us)
    2014/11/18 12:07:56 [DEBUG] consul: user event: ev3
    2014/11/18 12:07:56 [DEBUG] agent: new event: ev3 (7419ce88-8471-1730-e5da-7a20e638fb6b)

This is with watches like this

{
    "watches": [
        {"type":"event", "name":"ev1", "handler": "touch /tmp/o"},
        {"type":"event", "name":"ev2", "handler": "touch /tmp/o"},
        {"type":"event", "name":"ev3", "handler": "touch /tmp/o"},
        {"type":"event", "name":"ev4", "handler": "touch /tmp/o"}
    ]
}

Thanks!

@ryanuber
Copy link
Member

I've reproduced this - marking as a bug. Thanks!

@ryanuber
Copy link
Member

@hoffoo this is fixed in master and will be in the next release!

@hoffoo
Copy link
Contributor Author

hoffoo commented Nov 21, 2014

very cool, thanks @ryanuber !

duckhan pushed a commit to duckhan/consul that referenced this issue Oct 24, 2021
duckhan pushed a commit to duckhan/consul that referenced this issue Oct 24, 2021
* Support HA for the endpoints controller

- The controller manager allows for multiple instances of the controller to run using leader election. By configuring leader election, one of the instances of the controller (the leader) will run the reconciler. All instances can serve the webhook though, but only on the instances will inject the containers per request.

This requires additional priveleges from an RBAC perspective that will be a part of a helm commit.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type/bug Feature does not function as expected
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants