Send TZ in timestamps to logstash

[viq]

Logstash by itself takes care of conversion of timestamps to UTC, with how it was logstash was showing wrong time for the events.

[s0undt3ch]

I wasn't sending any TZ info, so which conversion was being done?!

[viq]

It was being sent as UTC, without any timezone info. Seeing as I'm CEST events that just happened logstash (kibana) was showing as having happened as an hour ago, as on input it assumes (I think..) that dates are sent in local time.

[s0undt3ch]

datetime.fromtimestamp doesn't carry any TZ info either. So, if you have 2 minions in different timezones?

[viq]

In that case probably a modification to example logstash config should be done, applying filter from http://logstash.net/docs/1.2.2/filters/date#timezone

I guess something like:

filter {
  date {
    type => "zeromq-type"
    timezone => "UTC"
  }
}

[s0undt3ch]

I'm changing the code to include the timezone in the timestamp.

In [9]: class UTC(datetime.tzinfo):
           def utcoffset(self, dt):
               return datetime.timedelta(0)
           def dst(self, dt):
               return datetime.timedelta(0)

In [10]: print datetime.datetime.now(UTC())
2013-12-10 15:55:38.301780+00:00

In [11]: print datetime.datetime.utcnow()
2013-12-10 15:55:43.008449

[s0undt3ch]

Would this fix it?

[s0undt3ch]

Or the filter would still be required?

[viq]

If you could show me how to change the code to try that I'll get back to you with the result.

[s0undt3ch]

I'll get that to you in about 30 mins or so...

[viq]

I wonder if that matters - /etc/localtime points at local time zone, not UTC.

[viq]

It most likely is a case of PEBKAC but I still wasn't able to adjust the date displayed with filter. https://gist.github.com/viq/7893190 is what I'm trying.

[s0undt3ch]

You're feeding logstash from salt? or from syslog?

[viq]

Both. But salt logs go directly from salt via a zeromq socket as described at http://docs.saltstack.com/ref/configuration/logging/handlers/salt.log.handlers.logstash_mod.html

[viq]

Sorry, will have to get back to it tomorrow.

[s0undt3ch]

diff --git a/salt/log/handlers/logstash_mod.py b/salt/log/handlers/logstash_mod.py
index 3781a74..e41a767 100644
--- a/salt/log/handlers/logstash_mod.py
+++ b/salt/log/handlers/logstash_mod.py
@@ -116,13 +116,20 @@ import json
 import socket
 import logging
 import logging.handlers
-from datetime import datetime
+import datetime

 # Import salt libs
 from salt._compat import string_types
 from salt.log.setup import LOG_LEVELS
 from salt.log.mixins import NewStyleClassMixIn

+# Import 3rd-party libs
+try:
+    from pytz import utc as _UTC
+    HAS_PYTZ = True
+except ImportError:
+    HAS_PYTZ = False
+
 log = logging.getLogger(__name__)

 # Define the module's virtual name
@@ -214,7 +221,10 @@ class LogstashFormatter(logging.Formatter, NewStyleClassMixIn):
         super(LogstashFormatter, self).__init__(fmt=None, datefmt=None)

     def formatTime(self, record, datefmt=None):
-        return datetime.utcfromtimestamp(record.created).isoformat()
+        timestamp = datetime.datetime.utcfromtimestamp(record.created)
+        if HAS_PYTZ:
+            return _UTC.localize(timestamp).isoformat()
+        return '{0}+00:00'.format(timestamp.isoformat())

     def format(self, record):
         host = socket.getfqdn()

That's the patch to test, if you can...

[s0undt3ch]

Updated for readability.

[viq]

With this change and no date filter the messages are showing up with proper time.
Thank you!

[s0undt3ch]

Want to update this PR with the fix? Or want me to?

Pedro Algarvio @ Phone

----- Reply message -----
From: "viq" notifications@github.com
To: "saltstack/salt" salt@noreply.github.com
Cc: "Pedro Algarvio" pedro@algarvio.me
Subject: [salt] Don't send timestamps to logstash in UTC (#9140)
Date: Wed, Dec 11, 2013 11:09
With this change and no date filter the messages are showing up with proper time.

—
Reply to this email directly or view it on GitHub.

[viq]

Still learning the ropes with git, I'll try to, but if you beat me to it feel free :)

[viq]

Uhm, I think I've done it.

[s0undt3ch]

Yep! You have!!!!

[s0undt3ch]

Thank you for the contribution!

[viq]

I just spotted it, you did all the hard work ;) Thank you :)

[s0undt3ch]

Nah! The hard part is finding out why it's failing 😄

[UtahDave]

Hey, @s0undt3ch This pull req is causing this issue now: #9180