ozw1z5rd opened a new issue #10797: URL: https://github.com/apache/airflow/issues/10797
**Apache Airflow version**: 1.10.10 **Kubernetes version (if you are using kubernetes)** (use `kubectl version`): none **Environment**: - **Cloud provider or hardware configuration**: - **OS** (e.g. from /etc/os-release): NAME="CentOS Linux" VERSION="7 (Core)" ID="centos" ID_LIKE="rhel fedora" VERSION_ID="7" PRETTY_NAME="CentOS Linux 7 (Core)" ANSI_COLOR="0;31" CPE_NAME="cpe:/o:centos:centos:7" HOME_URL="https://www.centos.org/"; BUG_REPORT_URL="https://bugs.centos.org/"; CENTOS_MANTISBT_PROJECT="CentOS-7" CENTOS_MANTISBT_PROJECT_VERSION="7" REDHAT_SUPPORT_PRODUCT="centos" REDHAT_SUPPORT_PRODUCT_VERSION="7" - **Kernel** (e.g. `uname -a`): Linux mid1-e-1 3.10.0-514.2.2.el7.x86_64 #1 SMP Tue Dec 6 23:06:41 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux - **Install tools**: pip yum - **Others**: **What happened**: I have these rows inside the job table: ``` JOB '3814948','MNT-NOP','success','LocalTaskJob','2020-09-08 02:43:26.593079','2020-09-08 02:43:46.619759','2020-09-08 02:43:36.608666','NoneType','mid1-a128-3.buongiorno.com','jmailer' '3814947','MNT-NOP','success','LocalTaskJob','2020-09-08 02:43:25.837834','2020-09-08 02:43:45.866320','2020-09-08 02:43:35.854978','NoneType','mid1-a128-2.buongiorno.com','jmailer' '3814946','MNT-NOP','success','LocalTaskJob','2020-09-08 02:43:25.784078','2020-09-08 02:43:45.801048','2020-09-08 02:43:35.790911','NoneType','mid1-a128-1.buongiorno.com','jmailer' ``` Please, pay attention to the date after the word LocalTaskJob. All they are almost equal. The same thing is also reported in the task instance table: ``` TASK_INSTANCE 'do_nothing','MNT-NOP','2020-09-08 02:20:00.000000','2020-09-08 02:43:25.803751','2020-09-08 02:43:30.962179','5.15843','success','1','mid1-a128-1.buongiorno.com','jmailer','3814946','default_pool','airflow','1','BashOperator','2020-09-08 02:43:24.060644','32567','5',?,'1' 'do_nothing','MNT-NOP','2020-09-08 02:10:00.000000','2020-09-08 02:43:25.856946','2020-09-08 02:43:31.007805','5.15086','success','1','mid1-a128-2.buongiorno.com','jmailer','3814947','default_pool','airflow','1','BashOperator','2020-09-08 02:43:24.060590','13823','5',?,'1' 'do_nothing','MNT-NOP','2020-09-08 02:30:00.000000','2020-09-08 02:43:26.613788','2020-09-08 02:43:31.781167','5.16738','success','1','mid1-a128-3.buongiorno.com','jmailer','3814948','default_pool','airflow','1','BashOperator','2020-09-08 02:43:24.060668','24060','5',?,'1' ``` This is the scheduler log, host runs in UTC. ``` 020-09-08 02:21:05,699 INFO - 1 tasks up for execution: <TaskInstance: MNT-NOP.do_nothing 2020-09-08 02:10:00+00:00 [scheduled]> 2020-09-08 02:21:05,715 INFO - Figuring out tasks to run in Pool(name=default_pool) with 100 open slots and 1 task instances ready to be queued 2020-09-08 02:21:05,716 INFO - DAG MNT-NOP has 0/32 running and queued tasks 2020-09-08 02:21:05,723 INFO - Setting the following tasks to queued state: <TaskInstance: MNT-NOP.do_nothing 2020-09-08 02:10:00+00:00 [scheduled]> 2020-09-08 02:21:05,731 INFO - Setting the following 1 tasks to queued state: <TaskInstance: MNT-NOP.do_nothing 2020-09-08 02:10:00+00:00 [queued]> 2020-09-08 02:21:05,731 INFO - Sending ('MNT-NOP', 'do_nothing', datetime.datetime(2020, 9, 8, 2, 10, tzinfo=<Timezone [UTC]>), 1L) to executor with priority 1 and queue airflow 2020-09-08 02:21:05,732 INFO - Adding to queue: ['airflow', 'run', 'MNT-NOP', 'do_nothing', '2020-09-08T02:10:00+00:00', '--local', '--pool', 'default_pool', '-sd', u'/jhub/_prod/server_global_unifieddata_hadoop_airflow_dags/lib/dags/MNT-NOP.py'] 2020-09-08 02:23:11,951 INFO - Executor reports execution of MNT-NOP.do_nothing execution_date=2020-09-08 02:10:00+00:00 exited with status success for try_number 1 2020-09-08 02:31:48,317 INFO - 1 tasks up for execution: <TaskInstance: MNT-NOP.do_nothing 2020-09-08 02:20:00+00:00 [scheduled]> 2020-09-08 02:31:48,317 INFO - 1 tasks up for execution: <TaskInstance: MNT-NOP.do_nothing 2020-09-08 02:20:00+00:00 [scheduled]> 2020-09-08 02:31:48,324 INFO - Figuring out tasks to run in Pool(name=default_pool) with 100 open slots and 1 task instances ready to be queued 2020-09-08 02:31:48,324 INFO - DAG MNT-NOP has 0/32 running and queued tasks 2020-09-08 02:31:48,336 INFO - Setting the following tasks to queued state: <TaskInstance: MNT-NOP.do_nothing 2020-09-08 02:20:00+00:00 [scheduled]> 2020-09-08 02:31:48,348 INFO - Setting the following 1 tasks to queued state: <TaskInstance: MNT-NOP.do_nothing 2020-09-08 02:20:00+00:00 [queued]> 2020-09-08 02:31:48,349 INFO - Sending ('MNT-NOP', 'do_nothing', datetime.datetime(2020, 9, 8, 2, 20, tzinfo=<Timezone [UTC]>), 1L) to executor with priority 1 and queue airflow 2020-09-08 02:31:48,349 INFO - Adding to queue: ['airflow', 'run', 'MNT-NOP', 'do_nothing', '2020-09-08T02:20:00+00:00', '--local', '--pool', 'default_pool', '-sd', u'/jhub/_prod/server_global_unifieddata_hadoop_airflow_dags/lib/dags/MNT-NOP.py'] 2020-09-08 02:34:12,582 INFO - Executor reports execution of MNT-NOP.do_nothing execution_date=2020-09-08 02:20:00+00:00 exited with status success for try_number 1 2020-09-08 02:40:36,829 INFO - 1 tasks up for execution: <TaskInstance: MNT-NOP.do_nothing 2020-09-08 02:30:00+00:00 [scheduled]> 2020-09-08 02:40:36,842 INFO - Figuring out tasks to run in Pool(name=default_pool) with 100 open slots and 1 task instances ready to be queued 2020-09-08 02:40:36,843 INFO - DAG MNT-NOP has 0/32 running and queued tasks 2020-09-08 02:40:36,860 INFO - Setting the following tasks to queued state: <TaskInstance: MNT-NOP.do_nothing 2020-09-08 02:30:00+00:00 [scheduled]> 2020-09-08 02:40:36,877 INFO - Setting the following 1 tasks to queued state: <TaskInstance: MNT-NOP.do_nothing 2020-09-08 02:30:00+00:00 [queued]> 2020-09-08 02:40:36,878 INFO - Sending ('MNT-NOP', 'do_nothing', datetime.datetime(2020, 9, 8, 2, 30, tzinfo=<Timezone [UTC]>), 1L) to executor with priority 1 and queue airflow 2020-09-08 02:40:36,879 INFO - Adding to queue: ['airflow', 'run', 'MNT-NOP', 'do_nothing', '2020-09-08T02:30:00+00:00', '--local', '--pool', 'default_pool', '-sd', u'/jhub/_prod/server_global_unifieddata_hadoop_airflow_dags/lib/dags/MNT-NOP.py'] ``` And this is the dag_run table, the timestamp extracted are in CEST, the run_id is reporting the datetime in UTC. ``` DAG_RUN '812895','MNT-NOP','2020-09-08 04:40:00.000000','success','scheduled__2020-09-08T02:40:00+00:00','0',?,'2020-09-08 04:53:02.817183','2020-09-08 04:50:56.682782' '812887','MNT-NOP','2020-09-08 04:30:00.000000','success','scheduled__2020-09-08T02:30:00+00:00','0',?,'2020-09-08 04:42:32.295858','2020-09-08 04:40:26.077977' '812886','MNT-NOP','2020-09-08 04:20:00.000000','success','scheduled__2020-09-08T02:20:00+00:00','0',?,'2020-09-08 04:34:02.276413','2020-09-08 04:31:42.676393' '812884','MNT-NOP','2020-09-08 04:10:00.000000','success','scheduled__2020-09-08T02:10:00+00:00','0',?,'2020-09-08 04:23:01.140613','2020-09-08 04:20:59.959911' '812881','MNT-NOP','2020-09-08 04:00:00.000000','success','scheduled__2020-09-08T02:00:00+00:00','0',?,'2020-09-08 04:14:36.636117','2020-09-08 04:12:30.623165' ``` And these timestamp are ok with the scheduler log, for example: '812886', <-- id 'MNT-NOP' ,'2020-09-08 04:20:00.000000', 'success', 'scheduled__2020-09-08T02:20:00+00:00', '0' ,? ,'2020-09-08 **04:34:02**.276413', <---- END_DATE 4:34 = 2:34 UTC 2020-09-08 **02:34:12**,582 INFO - Executor reports execution of MNT-NOP.do_nothing execution_date=2020-09-08 02:20:00+00:00 exited with status success for try_number 1 '2020-09-08 **04:31:42**.676393' <--- START_DATE 4.31 = 2.31 UTC 2020-09-08 **02:31:48**,349 INFO - Sending ('MNT-NOP', 'do_nothing', datetime.datetime(2020, 9, 8, 2, 20, tzinfo=<Timezone [UTC]>), 1L) to executor with priority 1 and queue airflow 2020-09-08 **02:31:48**,349 INFO - Adding to queue: ['airflow', 'run', 'MNT-NOP', 'do_nothing', '2020-09-08T02:20:00+00:00', '--local', '--pool', 'default_pool', '-sd', u'/jhub/_prod/server_global_unifieddata_hadoop_airflow_dags/lib/dags/MNT-NOP.py'] **What you expected to happen**: The job table updated with the correct timestamps **How to reproduce it**: No idea, although I have to say that this issue is impacting a DAG which runs every 10 minutes and the issue raises only around at 2:30 UTC. **Anything else we need to know**: ---------------------------------------------------------------- This is an automated message from the Apache Git Service. To respond to the message, please log on to GitHub and use the URL above to go to the specific comment. For queries about this service, please contact Infrastructure at: [email protected]
