github-webhook icon indicating copy to clipboard operation
github-webhook copied to clipboard

Command executed twice

Open chrisjaure opened this issue 8 years ago • 11 comments

Is there any reason why the same command would be executed twice from a single event? In the logs, there's only a second difference between the two executions.

chrisjaure avatar Aug 19 '15 17:08 chrisjaure

Hi @chrisjaure -

Is this still happening?

Can you paste the output of your logs?

Thanks!

jdrago999 avatar Mar 12 '16 20:03 jdrago999

I'll have to set up a test env again since I'm not using this module anymore. I'll update you when I've got some results.

chrisjaure avatar Mar 17 '16 15:03 chrisjaure

I'm seeing this as well.

Here's my log:

stderr: npm WARN [email protected] No repository field. event="push", match="ref == "refs/heads/master" && repository.name == "myproject"", exec="sudo /home/myprojectuser/install.sh" Tue Aug 23 2016 06:08:26 GMT+0000 (UTC) Took 11595 ms stderr: npm WARN [email protected] No repository field. event="push", match="ref == "refs/heads/master" && repository.name == "myproject"", exec="sudo /home/myprojectuser/install.sh" Tue Aug 23 2016 06:08:38 GMT+0000 (UTC) Took 11908 ms

It simply runs the install.sh twice, right after eachother, ie: it seems it waits till the first one is done...

jsguy avatar Aug 23 '16 06:08 jsguy

Hi, Is the issue solved? Cheers

raedle avatar Dec 08 '16 13:12 raedle

No, still happening. Not sure if it's an issue with your script or github. Easiest fix would be the ability to debounce consecutive requests.

jsguy avatar Dec 08 '16 19:12 jsguy

eg: wait X milliseconds before executing, and if a new event comes in, discard the first one. X milliseconds should be configurable, like so:

{
  "port": 9999,
  "path": "/webhook",
  "secret": "mygithubsecret",
  "log": "/var/log/webhook.log",
  "rules": [{
    "event": "push",
    "match": "ref == \"refs/heads/master\" && repository.name == \"myrepo\"",
    "exec": "echo yay!",
    "debounce": 5000,
    "maxdebounce": 3
  }]
}

This would wait 5 seconds, and if no further matching requests have come in, execute the hook. maxdebounce would mean we'd wait for no more than 3 consecutive events before executing - this stops us from waiting indefinitely, if events keep on coming.

jsguy avatar Dec 11 '16 22:12 jsguy

This might be sort of a graveyard digger bit, but the problem still exists. I've checked and it's the server's problem - only one request gets sent by GH according to my investigation, so why it's executing twice is sort of a mystery.

However, I didn't fix it - instead of diving deep into the code, I added a step to my exec block that prevents me from executing twice based on the commit SHA.

joaoanes avatar Feb 15 '17 11:02 joaoanes

@joaoanes That's quite interesting, can you please provide a few more details on how you did that?

jsguy avatar Feb 15 '17 21:02 jsguy

@jsguy I've set up github-webhook to run a script on push that basically kicks off a build process, and I save build logs named after its commit SHA for each build, which I check before building.

The first step in my build process is checking if there's a build log for that SHA (AKA checking if there's a $SHA.log file on the build logs folder), and if there is, check if the last line of the log is equal to something akin to "Build done successfully!", which I add to the log on a successful build. If all of that is true, I drop the build and return immediately, which prevents the double execution, and also prevents double building if a developer pushes the same commit twice (due to force pushes or something like it).

It's not fancy, but it works for us!

joaoanes avatar Feb 16 '17 04:02 joaoanes

@joaoanes Thanks for that, sounds quite neat, I'll try the same.

jsguy avatar Feb 16 '17 04:02 jsguy

Seems like this block of codes causes the command to be executed twice:

  eventKeys.forEach(function (key) {
    handler.on(key, function (event) {
      eventsDebug(JSON.stringify(event))
      handleRules(logStream, options.rules, event)
    })
  })

When you set up a rule for event type push for example, the handler would match both push and *, hence it calls handleRules twice and causes the command to be executed twice.

A quick fix is to remove event * from the list of eventKeys (events.json) because we handle that special event in handleRules already.

hoanghuynh avatar Apr 26 '17 11:04 hoanghuynh