WIP: Update bot code to log the content of the received text message
Summary
This pull request updates bot code to log the actual received message content inside the event handler.
Keep in mind that the code is not the final version. I just opened the PR and included something to get the discussions going and I'm open to improving / changing it.
Context, Background
Older versions of hubot-slack logged the actual message content, but the newer ones don't.
Older versions:
...
[Tue Nov 13 2018 17:22:34 GMT+0000 (UTC)] DEBUG No listeners executed; falling back to catch-all
[Tue Nov 13 2018 17:22:35 GMT+0000 (UTC)] DEBUG Received message: '
Action st2.executions.get completed.
...
Recent versions:
...
[Tue Nov 13 2018 17:26:28 GMT+0000 (Coordinated Universal Time)] DEBUG SlackClient#send() room: C066X08KY, message: [object Object]
[Tue Nov 13 2018 17:26:29 GMT+0000 (Coordinated Universal Time)] DEBUG Received text message in channel: C066X08KY, from: U6L3A6MK7 (human)
[Tue Nov 13 2018 17:26:29 GMT+0000 (Coordinated Universal Time)] DEBUG No listeners executed; falling back to catch-all' does not contain 'details available at'
...
Not having the direct access to the message content makes debugging and other things harder / impossible. We also have some tests which need to assert on the raw text message value and recent versions make that impossible.
The message content is logged under debug log level (same as in the past) so it should have no "negative" security implications or consequences (even if the message contains sensitive data, that's the whole point of the debug log level - to log as much context as possible to make debugging easier / possible and debug shouldn't be used in production).
Requirements (place an x in each [ ])
- [x] I've read and understood the Contributing Guidelines and have done my best effort to follow them.
- [x] I've read and agree to the Code of Conduct.
Codecov Report
Merging #544 into master will increase coverage by
0.08%. The diff coverage is100%.
@@ Coverage Diff @@
## master #544 +/- ##
==========================================
+ Coverage 85.55% 85.63% +0.08%
==========================================
Files 6 6
Lines 353 355 +2
Branches 79 79
==========================================
+ Hits 302 304 +2
Misses 29 29
Partials 22 22
| Impacted Files | Coverage Δ | |
|---|---|---|
| src/bot.coffee | 74.22% <100%> (+0.54%) |
:arrow_up: |
Continue to review full report at Codecov.
Legend - Click here to learn more
Δ = absolute <relative> (impact),ø = not affected,? = missing dataPowered by Codecov. Last update a442154...641f531. Read the comment docs.
Thanks for taking the time to demonstrate this idea with a code contribution. I think this is an interesting discussion.
The main reason we removed the logging (even under the debug log level) of message content was that it was just too easy to expose sensitive data in production, for seemingly not a great benefit. We're willing to re-evaluate that decision in light of your interest in better debugging capabilities.
Some background information for you: we find that Hubot is most commonly used as an internal app. That means it's authorized as a bot user against one workspace, and only will ever be on that one workspace. That also means Hubot is exposed to a large stream of information (RTM is a broad firehose) in the company. What this adds up to is that even a developer who is still implementing a script or debugging a script is exposed to a ton of actual message content, some of which is considered sensitive by their own teammates. Consider the situation where the Hubot bot user is invited into a private channel where some people are discussing a secret project that's not ready to be shared with the rest of the company. A developer who happens to be working on a script and running locally in debug mode would see those very private messages fly by in their console. Of course a developer who wants to read every message and has access to the bot token could go out of their way to see these message whether we log them or not, it's just a lot easier to unintentionally do this (and maybe even panic about it) with logging included in the adapter.
I understand your need for a better debugging solution. I would propose that if you need logging in order to debug script issues, as someone who knows what they are doing you could use a listener middleware to accomplish this. An excerpt from the Hubot docs suggests this as a use case it was designed for:
Listener middleware inserts logic between the listener matching a message and the listener executing. This allows you to create extensions that run for every matching script. Examples include centralized authorization policies, rate limiting, logging, and metrics. Middleware is implemented like other hubot scripts: instead of using the hear and respond methods, middleware is registered using listenerMiddleware.
In fact, the first example in that section might be exactly what you're looking for.