Command executed twice

[chrisjaure]

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.

[jdrago999]

Hi @chrisjaure -

Is this still happening?

Can you paste the output of your logs?

Thanks!

[chrisjaure]

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.

[jsguy]

I'm seeing this as well.

Here's my log:

stderr: npm WARN app@0.0.27 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 app@0.0.27 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...

[raedle]

Hi, Is the issue solved? Cheers

[jsguy]

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]

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.

[joaoanes]

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.

[jsguy]

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

[joaoanes]

@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!

[jsguy]

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

[hoanghuynh]

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.