Webserver shows wrong datetime (timezone) in log #23796

Activity

1. freshlu11

   added

   area:core

   kind:bugThis is a clearly a bugThis is a clearly a bug

   on May 19, 2022
2. boring-cyborg commented on May 19, 2022

   

   boring-cyborgBot

   on May 19, 2022

   More actions

   Thanks for opening your first issue here! Be sure to follow the issue template!
3. bbovenzi

   added

   area:UIRelated to UI/UX. For Frontend Developers.Related to UI/UX. For Frontend Developers.

   and removed

   area:core

   on May 20, 2022
4. potiuk

   added

   good first issue

   on Jun 1, 2022
5. tanelk commented on Jun 4, 2022

   

   tanelk

   on Jun 4, 2022

   Contributor

   More actions

   Just to document the history:

   This was initially fixed in #19401 and then reverted in #23075

   For some users the logs are in the server time and for others the logs are in UTC.
   Should we have a separate configuration option so we wont have to "fix" it back and forth anymore?

   Also a side note - I think #19401 was a partial fix as it does not take in account that the offset for a timezone can change.
6. uranusjr commented on Jun 6, 2022

   

   uranusjr

   on Jun 6, 2022

   Member

   More actions

   It sounds like a configuration is the only way to satisfy all use cases. There’s no way Airflow can automatically know what timezone the log files use otherwise.
7. rino0601 commented on Jun 8, 2022

   

   rino0601

   on Jun 8, 2022

   Last edited by rino0601

   Contributor

   More actions

   I found workaround. via configuration. here's how:

   1. write ${PYTHONPATH}/airflow_local_settings.py

   import logging
   import time
   from copy import deepcopy
   
   from airflow.config_templates.airflow_local_settings import DEFAULT_LOGGING_CONFIG
   LOGGING_CONFIG = deepcopy(DEFAULT_LOGGING_CONFIG)
   
   # from https://stackoverflow.com/a/60342048
   class UTCFormatter(logging.Formatter):
       converter = time.gmtime  # this makes logger's asctime as UTC
   
   LOGGING_CONFIG['formatters']['airflow']['class'] = 'airflow_local_settings.UTCFormatter'

   2. Edit airflow.cfg

   [logging]
   logging_config_class = airflow_local_settings.LOGGING_CONFIG

   working as same as #20315

   3. then

   

   ---

   I have tried something like [2022-06-08 10:45:01+09:00] by appending %z to datefmt on logging.Filter. but regex in airflow/www/static/js/ti_log.js couldn't understand it.

   👍React with 👍1Reacted by Hiram711
8. rino0601 commented on Jun 10, 2022

   

   rino0601

   on Jun 10, 2022

   Contributor

   More actions

   I've create PR #24373 for this issue.

   @tanelk @uranusjr could you take a look?
9. hwooson12 commented on Jun 13, 2022

   

   hwooson12

   on Jun 13, 2022

   Contributor

   More actions

   @uranusjr
   I think it is wrong that Airflow basically assumes all timezone in logging is UTC. The idea of converting logging time as the timezone that users select from the browser UI was very good but the problem is that all system timezone is not UTC. So we could see wrong time in the log files because it is converted on only the frontend side without any clue of timezone. Even though Airflow does not automatically know what timezone the log files use, at least we can leave timezone information on the log files by fixing default log format class which means Airflow knows what timezone is so that it can be handled by using only Javascript.
10. uranusjr commented on Jun 13, 2022

    

    uranusjr

    on Jun 13, 2022

    Member

    More actions

    I never waid assuming UTC is right, but the problem is the frontend doesn’t know what timezone the log files used. Appending %z in the timestamp actually sounds like the best solution, if we can change the frontend code to correctly parse them. The formatter patch mentioned above should also solve the issue (by making the log files always use UTC), but I’m not sure it’s a desired outcome for a lot of people—if people want to read logs in the web UI in their own timezone, I would expect they also want the actual log files display the server timezone as well.
11. rino0601 commented on Jun 14, 2022

    

    rino0601

    on Jun 14, 2022

    Contributor

    More actions

    @uranusjr Seems to need more explain about PR, let me supplement that.

    In the comment above, I found a way to do it only with configuration, so I used time.gmtime to always output utc regardless of the system settings. The reason I had to do that was because the regular expression of UI could not be changed with configuration .

    While writing PR , I was also able to edit the UI regex, so I didn't have to lock the log to UTC, so I didn't use time.gmtime (to allow users to get log files that use server timezone ).

    Instead, I override the default_time_format to append %z to the %(asctime)s output of the log file. Also, in python 3.7 and 3.8, default_msec_format cannot be omitted, so I set it to an appropriate value so that it does not interfere with the regular expression of the UI.

    Thankfully moments.js can handle both +00:00 and +0000(python %z style) properly.

    
    https://jsfiddle.net/wbqs84x3/

    Since we are already using moments.js in updateAllDateTimes at www/static/js/datetime_utils.js,

    airflow/airflow/www/static/js/datetime_utils.js

    Line 79 in fe2ef0f

    const dt = moment($el.attr('datetime'));

    all I have to do is pass in a datetime string that moments.js can recognize. This was achieved by fixing the regex in www/static/js/ti_log.js
12. uranusjr

    closed this as completedin #24373on Jun 24, 2022