Hubot Executes listener callback twice for a message.

Description

When sending a message to hugo with a custom script that has a robot.respondfunction, hubot seems to receive the message twice and as a result executes the listener callback twice as well.

This only happens with one script that has an external dependency. With other scripts hugo does not exhibit this behavior.

In the script with the faulty behavior, I send a POST message using the library needle. I'm using this script with Rocket.Chat.

Everything below robot.respond create_regex, (msg) -> is executed twice.

needle = require('needle')
url = "http://192.168.89.254:8181/"

module.exports = (robot) ->
  create_regex = /\bget-asl ([0-9]{2}-[0-9]{6}-[0-9]{3}) ([0]?[1-9]|[1|2][0-9]|[3][0|1])[./-]([0]?[1-9]|[1][0-2])[./-]([0-9]{4}|[0-9]{2})\b/i
  robot.respond create_regex, (msg) ->

    projectId = msg.match[1]
[...]

    needle.request 'post', url, formData, params, (err, res) ->
      if not err and res.statusCode == 200
        deleteId = res.body['sha']
        msg.reply "Response"
      else
         msg.reply "Something failed: " + err

But the same issue happens, when I comment out the needle.request portion of the code.

The message is the following.

@hugo get-asl 77-777777-777 02.02.2022

The regex is:

/\bget-asl ([0-9]{2}-[0-9]{6}-[0-9]{3}) ([0]?[1-9]|[1|2][0-9]|[3][0|1])[./-]([0]?[1-9]|[1][0-2])[./-]([0-9]{4}|[0-9]{2})\b/i

The following are the log messages I see with Debug enabled.

hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO Message received with ID id
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO Message receive callback id emrW8QxHyJofyNaoR ts Wed Aug 03 2022 17:55:26 GMT+0000 (UTC)
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO [Incoming] username: @hugo get-asl 77-777777-777 02.02.2022
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO Checking to see if method: getRoomNameById exists
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO Looking up Room Name for: qPhHiuEkucK5KgSxp
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO setting roomName: asltest
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO Message sent to hubot brain.
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] DEBUG Message '@hugo get-asl 77-777777-777 02.02.2022' matched regex //^\s*[@]?hugo[:,]?\s*(?:\bget-asl ([0-9]{2}-[0-9]{6}-[0-9]{3}) ([0]?[1-9]|[1|2][0-9]|[3][0|1])[.\/-]([0]?[1-9]|[1][0-2])[.\/-]([0-9]{4}|[0-9]{2})\b)/i/; listener.options = { id: null }
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] DEBUG Executing listener callback for Message '@hugo get-asl 77-777777-777 02.02.2022'
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] DEBUG Message '@hugo get-asl 77-777777-777 02.02.2022' matched regex //^\s*[@]?hugo[:,]?\s*(?:\bget-asl ([0-9]{2}-[0-9]{6}-[0-9]{3}) ([0]?[1-9]|[1|2][0-9]|[3][0|1])[.\/-]([0]?[1-9]|[1][0-2])[.\/-]([0-9]{4}|[0-9]{2})\b)/i/; listener.options = { id: null }
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] DEBUG Executing listener callback for Message '@hugo get-asl 77-777777-777 02.02.2022'
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO reply
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO Sending Message To Room: asltest
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO Looking up Room ID for: asltest
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO reply
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO Sending Message To Room: asltest
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO Looking up Room ID for: asltest
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] DEBUG Preparing message from string
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] DEBUG Preparing message from string
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO Message received with ID id
hubot_1               | [Wed Aug 03 2022 17:55:27 GMT+0000 (UTC)] INFO Message received with ID id

The following screenshot also shows the behavior. The first message get's the response from the needle.request. In the second message, the needle.request is commented out.

The third request is another script where a cat pic is returned. The cat pic is returned only once by the bot.

hugo-issue

Expected behavior

The bot only executed the listener callback once.

hubotio / hubot

Hubot Executes listener callback twice for a message. #1571

Description

Expected behavior