Repository navigation
Webserver shows wrong datetime (timezone) in log #19342
Description
Apache Airflow version
2.2.1 (latest released)
Operating System
Ubuntu 20.04.2 (docker)
Versions of Apache Airflow Providers
- apache-airflow-providers-amazon==2.3.0
- apache-airflow-providers-ftp==2.0.1
- apache-airflow-providers-http==2.0.1
- apache-airflow-providers-imap==2.0.1
- apache-airflow-providers-mongo==2.1.0
- apache-airflow-providers-postgres==2.3.0
- apache-airflow-providers-sqlite==2.0.1
Deployment
Docker-Compose
Deployment details
Docker image build on Ubuntu 20.04 -> installed apache airflow via pip.
Localtime in image changed to Europe/Moscow.
Log format ariflow.cfg option:
log_format = %%(asctime)s %%(filename)s:%%(lineno)d %%(levelname)s - %%(message)s
What happened
For my purposes it's more usefull to run dags when it's midnight in my timezone.
So I changed default_timezone option in airflow.cfg to "Europe/Moscow" and also changed /etc/localtime in my docker image.
It works nice:
- dags with @daily schedule_interval runs at midnight
- python`s datetime.now() get me my localtime by default
- airflow webserver shows all time correctly when I change timezone in right top corner
... except one thing.
Python logging module saves asctime without timezone (for example "2021-10-31 18:25:42,550").
And when I open task`s log in web interface, it shifts this time forward by three hours (for my timzone), but it's already in my timzone.
It is a little bit confusing :(
What you expected to happen
I expected to see my timezone in logs :)
I see several solutions for that:
- any possibility to turn that shift off?
- setup logging timezone in airflow.cfg?
That problem is gone when I change system (in container) /etc/localtime to UTC.
But this is very problematic because of the ability to affect a lot of python tasks.
How to reproduce
- build docker container with different /etc/localtime
FROM ubuntu:20.04
ARG DEBIAN_FRONTEND=noninteractive
RUN apt-get update && apt-get install -y apt-utils locales tzdata
&& locale-gen en_US.UTF-8
&& ln -sf /usr/share/zoneinfo/Europe/Moscow /etc/localtime
ENV LANG=en_US.UTF-8 LANGUAGE=en_US:en AIRFLOW_GPL_UNIDECODE=yesRUN apt-get install -y
python3-pip
&& python3 -m pip install --upgrade pip setuptools wheel
&& pip3 install --no-cache-dir
apache-airflow-providers-amazon
apache-airflow-providers-mongo
apache-airflow-providers-postgres
apache-airflow==2.2.1
celery
... anything else
- run webserver / scheduler / celery worker inside
- open web page -> trigger dag with python operator which prints something via logging
- open done dag -> task log -> find asctime mark in log
- switch timezone in web interface
- watch how airflow thinks that asctime in log in UTC, but it's not
Anything else
No response
Are you willing to submit PR?
- Yes I am willing to submit a PR!
Code of Conduct
- I agree to follow this project's Code of Conduct
Activity
boring-cyborg commentedon Oct 31, 2021
Thanks for opening your first issue here! Be sure to follow the issue template!
Smirn08 commentedon Oct 31, 2021
Faced the same thing on 2.2.0, but did not issue the problem.
Looks relevant. Thanks @sartyukhov
calfzhou commentedon Nov 2, 2021
2.2.0 and 2.2.1 both facing the same issue.
bbovenzi commentedon Nov 3, 2021
I believe it is an issue with the added
+00:00on this line if someone wants to try a fix.EricGao888 commentedon Nov 4, 2021
I'm interested in this issue, will try to give a fix. Thx.
Fix log timezone in task log view (#19342) (#19401)
aborigine commentedon Nov 17, 2021
I followed the merge code, but not fix this issue, the webserver still shows wrong datetime in log
calfzhou commentedon Nov 23, 2021
What's your server's timezone and Airflow config's default timezone?
sartyukhov commentedon Nov 23, 2021
Has this patch been added to the 2.2.2? Because the bug is still exists in it.
calfzhou commentedon Nov 23, 2021
it seems not. The pr was merged into
mainbranch, not included in release2.2.2.aborigine commentedon Nov 23, 2021
I know what's the problem, I should change the js file tiLog.478df866123cef0b0eae.js under 'airflow/www/static/dist' directly instead of 'airflow/www/static/js/ti_log.js'. Once I restart the webserver, the datetime became the right one. Thanks for your reply anyway.
bbovenzi commentedon Nov 23, 2021
Sounds like webpack wasn't rebuilding the files. In the future, you can run
airflow webserver -dand inairflow/wwwrunyarn devto see your changes.aborigine commentedon Nov 24, 2021
Got it, and thank you so much. I don't know much about front-end development.
siddarthjha commentedon Dec 9, 2021
Hey, Can you tell me what changes do I have to do in this .js file. I am not familiar to javascript. I did the changes in “ti_log.js”. But the logs are same. Can you please tell the changes to be done in tiLog.478df866123cef0eae.js
calfzhou commentedon Dec 9, 2021
siddarthjha commentedon Dec 9, 2021
Thank you
mashirali commentedon Feb 3, 2022
airflow db shell
mysql> drop database airflow;
mysql> create database airflow;
mysql> grant all on airflow.* to 'airflow'@'localhost' identified by '123456!a';
mysql> flush privileges;
mysql> grant all on airflow.* to 'airflow'@'%' identified by '123456!a';
mysql> flush privileges;
mysql> show global variables like '%timestamp%';
+---------------------------------+-------+
| Variable_name | Value |
+---------------------------------+-------+
| explicit_defaults_for_timestamp | OFF |
| log_timestamps | UTC |
+---------------------------------+-------+
2 rows in set (0.00 sec)
mysql> set global explicit_defaults_for_timestamp =1;
Query OK, 0 rows affected (0.00 sec)