Allow customizing date/timestamp in access logs

[tuukkamustonen]

There is only %(t)s that is fixed to Apache log format (see https://github.com/benoitc/gunicorn/blob/master/gunicorn/glogging.py#L331-L333).

I would like to add millisecond precision to my access logs (to get them better ordered with other logs in Splunk).

I am personally only interested in millis, but someone else might have different needs. Would it be possible to reveal whole https://docs.python.org/2/library/time.html#time.strftime or would it introduce security/performance concerns?

[berkerpeksag]

Thanks for the report!

Would overriding the Logger.now() method and passing the new subclass to the logger_class setting work for your use case?

[tuukkamustonen]

Yeah, I guess I could do that as a workaround. Thanks for the pointer.

Would you agree that customizing time without need for custom logger_class would be a nice feature, though?

[berkerpeksag]

I couldn't think of an API to achieve that without introducing another setting :) Do you have an API idea that makes customizing easier?

[tuukkamustonen]

Unfortunately no, nothing clean at least. I think it would need custom preprocessing or something like:

class AtomDict(dict):
    def __getitem__(self, key):
        if key.startswith('strftime'):  # bad for performance
            format_string = key[9:-1]  # could be grabbed via regex, but would be even slower I guess
            return datetime.datetime.now().strftime(format_string)
        return super().__getitem__(key)

'%(strftime[%d/%b/%Y:%H:%M:%S.%f %z])s' % AtomDict()
'13/Feb/2017:13:18:47.538607 '

I think just adding (yet) another setting is the way to go here... oh, and to use datetime.datetime.now().strftime() instead of time.strftime() that cannot print out millis/micros.

[tuukkamustonen]

Looks like %z does not work the same way in datetime module and I assume there are other differences as well. Would need something like http://stackoverflow.com/a/25421145/165629 also?

Switching would break backwards-compatibility. So, maybe --time-format would assume datetime.strftime() instead and override t atom only if defined?

[JonathanHuot]

The ideal solution will be to replace the current Atoms-things into a clean class AccessFormatter(logging.Formatter). That way, we could both:

• change format in logging configuration: replace useless %(message)s in formatter_access section into something customizable like, and also specify a datefmt applicable for %(t)s, see logconfig.ini:

[formatter_access]
format=%(h)s %(l)s %(u)s %(t)s "%(r)s" %(s)s %(b)s "%(f)s" "%(a)s
datefmt=%Y-%m-%d:%H:%M:%S
class=gunicorn.glogging.AccessFormatter

• let the users develop their own custom fields with a base class AccessFormatter, and then use it later in the log format (like mentioned above):

class CustomFormatter(AccessFormatter):
    converter = time.gmtime  # convert time into UTC

  def format(self, record):
        record.foo = <custom>
        record.bar = <custom>
        return super().format(record)

Thoughts?

[berkerpeksag]

@JonathanHuot I like your suggestion, thanks. Feel free to send a PR.

[benoitc]

Nothing stop to support another format but i would like to keep the access log format though as it is pretty standard. Keep in mind that gunicorn is a server first that happens to be written in python. The op don’t have to know python for it.

For ms why not supporting this format setting from apache ˋ%{format}t` where format can be seq’ msec’ usec’ ... http://httpd.apache.org/docs/current/mod/mod_log_config.html

?

[inge4pres]

We're effectively trying to setup a custom-formatted datetime in accesslog using apache format mentioned in the bottom section of the doc

Timestamp including milliseconds "%{%d/%b/%Y %T}t.%{msec_frac}t %{%z}t"

We're trying to setup this configuration using

access_log_format=%(%{%d/%b/%Y %T}t.%{msec_frac}t %{%z}t)s | %(r)s | ...

but we happen to have a blank sign "-" printed instead of the expected time. Is anyone having the same issue? Or is anyone aware if it's possible to adapt the source code to apply this formatting?

Thank you

[tuukkamustonen]

Which docs are you referring to?

[inge4pres]

HI @tuukkamustonen I'm referring to the page linked by @benoitc http://httpd.apache.org/docs/current/mod/mod_log_config.html It was my understanding that Gunicorn is now accepting the Apache log format in the accesslog configuration, did I misunderstand?

[tuukkamustonen]

Uh, I somehow missed that link... anyway, I think it was just a thought/suggestion - gunicorn doesn't actually support it (yet).

[inge4pres]

😢 so we're doomed to create our own logging class... ok thank you all

[jeffrey4l]

one workaround to custom the access log datefmt in gunicorn.conf.py

import datetime
from gunicorn.glogging import Logger


class CustomLogger(Logger):

    def now(self):
        return datetime.datetime.utcnow().isoformat(sep=' ', timespec='milliseconds')

logger_class = CustomLogger