jschniper / gelf_logger

An Elixir Logger backend for GELF
MIT License
29 stars 27 forks source link

Unix time stamp #1

Closed dbreen1 closed 8 years ago

dbreen1 commented 8 years ago

On several machines here at work, the UNIX Timestamp calculation seems to be incorrect. This is causing graylog to ignore the messages. Pulling the project down and using the erlang os module timestamp seems to fix the problem. Could we change timestamp to:

timestamp: :os.system_time(:seconds)

I am not sure what the issue is with the current way of calculating the timestamp but it seems we could save complexity by just using the already built in functionality.

jschniper commented 8 years ago

Just out of curiosity, have you tried:

config :logger, utc_log: true

I don't necessarily mind making the change but I was trying to keep the original timestamp value that was passed into the event handler.

Let me know if that fixes your issue. If you need more information, take a look at the Runtime Configuration section of http://elixir-lang.org/docs/stable/logger/Logger.html

dbreen1 commented 8 years ago

Thanks for getting back to me.

Yes, I tried that, still doens't show up in graylog.

Not sure what differences there are between the way you calculated the timestamp and what :os.system_time(:seconds) returns. For now i'll keep with the :os.system_time change and if I can spare time it would be interesting to dive in and find out what differences there are.

Cheers for your help.

jschniper commented 8 years ago

I'll spend some time today trying to reproduce the problem. I'm not actually generating a timestamp but simply using the one that is passed into the event handler so I'll have to see if I can figure out why it's not correct.

If you find anything out, let me know.

jschniper commented 8 years ago

So I was thinking, the messages should still appear in Graylog but they'd simply have the wrong date. Are you certain they aren't making it at all?

Quick Edit:

Going back to the source of the timestamp: https://github.com/elixir-lang/elixir/blob/master/lib/logger/lib/logger/utils.ex#L240

It looks as though, :os.timestamp is being used instead of :os.system_time but after trying both I end up with matching erlang datetime tuples. I'm still a little stumped as to why the messages aren't appearing in Graylog. Do you mind letting me know what the timezone settings are on the machine sending the message and the machine receiving the meesage?

abhurtun commented 8 years ago

I have a pull request that i would like to submit @jschniper that will fix this issue If you can give me permissin i could submit the request @jschniper

jschniper commented 8 years ago

You shouldn't need any special privileges. Just fork the project, commit your changes and then submit the pull request. Let me know if you run into any problems.

abhurtun commented 8 years ago

@jschniper can please review the pull request

jschniper commented 8 years ago

@abhurtun, I'm bit uncomfortable with this change because I'd prefer to use the timestamp that is passed into the event handler. Were you experiencing the same problem as @dbreen1? If so can you provide some more background about your server configuration so that I can try to reproduce this problem?

abhurtun commented 8 years ago

@jschniper @dbreen1 and I work in the same company and we have the same problem as he explained previously the unit test are passing so I can say with confidence that its not breaking any functionality

abhurtun commented 8 years ago

@jschniper The change would help to reduce complexity in the code and make it more robust for different environments please let me know if you want for me info

jschniper commented 8 years ago

Sorry I've been unavailable the past few days. I'm not fond of making this change because I'd prefer to keep using the timestamp that is passed into the event handler.

Please take a look at https://github.com/elixir-lang/elixir/blob/master/lib/logger/lib/logger/utils.ex#L240

This is the code used to generate the timestamp passed into the event handler. So from my perspective, there is either a problem with the code in the Elixir Logger or there is something about your environment that is causing this issue. I've generated the timestamp using both :os.timestamp and :os.system_time and the results match in the end so I'm thinking the issue might be something particular to your environment.

The other thing that has me baffled is that even if the timestamp was wrong, Graylog should still accept the log message and just file it away at some offset from where you are expecting it.

It's not so much that your code is wrong but that it shouldn't be necessary. So, if you can provide me with some information about your environment, I'll be happy to dig into this problem some more. I think all I really need to know is the timezone of the server sending the message and the timezone of the server receiving the message.

abhurtun commented 8 years ago

Not required, I got to the bottom of this issue was due to using an old version of greylog Please close issue

jschniper commented 8 years ago

@abhurtun, thanks for looking into it. I'll dig into your new issue either later today or tomorrow.

rubiyz commented 7 years ago

The

config :logger, utc_log: true

saved my day, but I had some trouble to find out this information. It might be helpful to add it directly in the documentation. It was exactly the fix for events not displayed in graylog2.

jschniper commented 7 years ago

@rubiyz, I added some documentation per your suggestion. I'm not sure it's clear enough and I may go back and add a troubleshooting section at a later date.

rubiyz commented 7 years ago

@jschniper, thank you for the quick update. Looks like the modification in the documentation would help quickly figure out the solution for this issue.