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

Removes an invisible control character from our log output #104

Merged
merged 1 commit into from
Aug 4, 2018

Conversation

RobRuana
Copy link
Contributor

@RobRuana RobRuana commented Aug 4, 2018

Ho ho! What is this? It looks as though nothing has changed!

Turns out, there was an invisible control character in our logging output:
screen shot 2018-08-03 at 10 39 25 pm 2

@EliAndrewC this is definitely a change you'll want to pull upstream.

Not sure why the logs were coming out clean in Python 3.4 but were being garbled in Python 3.6. This was breaking our elastalert/logstash/kibana slack notifications. Tracking down this invisible control character comprised about 4 hours of work. I suppose this is why it's so hard for software engineers to accurately estimate the amount of time a task will take. Who could possibly foresee that an invisible control character inserted into the source code over two years ago would suddenly break our log notifications?

The logging for the current deployment follows this chain: stdout -> syslog -> /var/log/*.log -> filebeat -> tcp -> elk stack -> slack. It was... tedious trying to track down which part of that chain was failing. Especially when I could watch the logs being properly shipped from one place to the next.

The logs made it all the way to elastalert and it would just say, "no matching rules". I compared the logs being shipped from our old servers to the logs being shipped from our new servers. They were visually identical. Well, almost identical.

I happened to notice that all of the tracebacks had "#36" at the end of every line. Weird... I also happened to remember that we wrote our own log handler to indent multiline messages. Okay, I figured maybe we weren't handling unicode properly, and something changed between Python 3.4 and 3.6.

Side note: printing stdout to the console was no help at all. The control character doesn't show up in the console (at least not in Apple Terminal).

I opened up sideboard/internal/logging.py. Everything looked fine. Except... wait... that's when I noticed the control character in the screenshot above!

I wanna give Sublime Text a big shoutout for doing the right thing by displaying invisible characters in the text editor! Best text editor I've ever used. Worth every penny. I don't think I would have ever figured this out if I hadn't been using Sublime Text.

@RobRuana RobRuana merged commit 08b5009 into master Aug 4, 2018
@RobRuana RobRuana deleted the removes_invisible_control_char branch August 4, 2018 04:16
@kitsuta
Copy link
Member

kitsuta commented Aug 4, 2018

Oh goodness, that is wild. Awesome job! 🎉

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

2 participants