This is an automated email from the ASF dual-hosted git repository.
uranusjr pushed a commit to branch main
in repository https://gitbox.apache.org/repos/asf/airflow.git
The following commit(s) were added to refs/heads/main by this push:
new 7de050ceeb Add %z for %(asctime)s to fix timezone for logs on UI
(#24373)
7de050ceeb is described below
commit 7de050ceeb381fb7959b65acd7008e85b430c46f
Author: Ko HanJong <[email protected]>
AuthorDate: Fri Jun 24 22:17:24 2022 +0900
Add %z for %(asctime)s to fix timezone for logs on UI (#24373)
---
airflow/config_templates/airflow_local_settings.py | 12 +++++--
airflow/config_templates/config.yml | 6 ++++
airflow/config_templates/default_airflow.cfg | 1 +
airflow/utils/log/colored_log.py | 4 +++
airflow/utils/log/timezone_aware.py | 39 ++++++++++++++++++++++
.../details/content/taskInstance/Logs/utils.js | 34 +++++++++++++++----
airflow/www/static/js/ti_log.js | 21 ++++++++++--
newsfragments/24373.significant.rst | 23 +++++++++++++
8 files changed, 129 insertions(+), 11 deletions(-)
diff --git a/airflow/config_templates/airflow_local_settings.py
b/airflow/config_templates/airflow_local_settings.py
index 6684fd18e5..141f52939e 100644
--- a/airflow/config_templates/airflow_local_settings.py
+++ b/airflow/config_templates/airflow_local_settings.py
@@ -31,13 +31,16 @@ from airflow.exceptions import AirflowException
# settings.py and cli.py. Please see AIRFLOW-1455.
LOG_LEVEL: str = conf.get_mandatory_value('logging', 'LOGGING_LEVEL').upper()
-
# Flask appbuilder's info level log is very verbose,
# so it's set to 'WARN' by default.
FAB_LOG_LEVEL: str = conf.get_mandatory_value('logging',
'FAB_LOGGING_LEVEL').upper()
LOG_FORMAT: str = conf.get_mandatory_value('logging', 'LOG_FORMAT')
+LOG_FORMATTER_CLASS: str = conf.get_mandatory_value(
+ 'logging', 'LOG_FORMATTER_CLASS',
fallback='airflow.utils.log.timezone_aware.TimezoneAware'
+)
+
COLORED_LOG_FORMAT: str = conf.get_mandatory_value('logging',
'COLORED_LOG_FORMAT')
COLORED_LOG: bool = conf.getboolean('logging', 'COLORED_CONSOLE_LOG')
@@ -60,10 +63,13 @@ DEFAULT_LOGGING_CONFIG: Dict[str, Any] = {
'version': 1,
'disable_existing_loggers': False,
'formatters': {
- 'airflow': {'format': LOG_FORMAT},
+ 'airflow': {
+ 'format': LOG_FORMAT,
+ 'class': LOG_FORMATTER_CLASS,
+ },
'airflow_coloured': {
'format': COLORED_LOG_FORMAT if COLORED_LOG else LOG_FORMAT,
- 'class': COLORED_FORMATTER_CLASS if COLORED_LOG else
'logging.Formatter',
+ 'class': COLORED_FORMATTER_CLASS if COLORED_LOG else
LOG_FORMATTER_CLASS,
},
},
'filters': {
diff --git a/airflow/config_templates/config.yml
b/airflow/config_templates/config.yml
index 1225c73a97..f7c48c1fa1 100644
--- a/airflow/config_templates/config.yml
+++ b/airflow/config_templates/config.yml
@@ -633,6 +633,12 @@
type: string
example: ~
default: "%%(asctime)s %%(levelname)s - %%(message)s"
+ - name: log_formatter_class
+ description: ~
+ version_added: 2.3.3
+ type: string
+ example: ~
+ default: "airflow.utils.log.timezone_aware.TimezoneAware"
- name: task_log_prefix_template
description: |
Specify prefix pattern like mentioned below with stream handler
TaskHandlerWithCustomFormatter
diff --git a/airflow/config_templates/default_airflow.cfg
b/airflow/config_templates/default_airflow.cfg
index 214890947b..d990010790 100644
--- a/airflow/config_templates/default_airflow.cfg
+++ b/airflow/config_templates/default_airflow.cfg
@@ -349,6 +349,7 @@ colored_formatter_class =
airflow.utils.log.colored_log.CustomTTYColoredFormatte
# Format of Log line
log_format = [%%(asctime)s] {{%%(filename)s:%%(lineno)d}} %%(levelname)s -
%%(message)s
simple_log_format = %%(asctime)s %%(levelname)s - %%(message)s
+log_formatter_class = airflow.utils.log.timezone_aware.TimezoneAware
# Specify prefix pattern like mentioned below with stream handler
TaskHandlerWithCustomFormatter
# Example: task_log_prefix_template =
{{ti.dag_id}}-{{ti.task_id}}-{{execution_date}}-{{try_number}}
diff --git a/airflow/utils/log/colored_log.py b/airflow/utils/log/colored_log.py
index d1adb0859b..f77af382b6 100644
--- a/airflow/utils/log/colored_log.py
+++ b/airflow/utils/log/colored_log.py
@@ -43,6 +43,10 @@ class CustomTTYColoredFormatter(TTYColoredFormatter):
traceback.
"""
+ # copy of airflow.utils.log.timezone_aware.TimezoneAware
+ default_time_format = '%Y-%m-%d %H:%M:%S%z'
+ default_msec_format = '%s %03dms'
+
def __init__(self, *args, **kwargs):
kwargs["stream"] = sys.stdout or kwargs.get("stream")
kwargs["log_colors"] = DEFAULT_COLORS
diff --git a/airflow/utils/log/timezone_aware.py
b/airflow/utils/log/timezone_aware.py
new file mode 100644
index 0000000000..a25ac49ef8
--- /dev/null
+++ b/airflow/utils/log/timezone_aware.py
@@ -0,0 +1,39 @@
+#
+# Licensed to the Apache Software Foundation (ASF) under one
+# or more contributor license agreements. See the NOTICE file
+# distributed with this work for additional information
+# regarding copyright ownership. The ASF licenses this file
+# to you under the Apache License, Version 2.0 (the
+# "License"); you may not use this file except in compliance
+# with the License. You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing,
+# software distributed under the License is distributed on an
+# "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
+# KIND, either express or implied. See the License for the
+# specific language governing permissions and limitations
+# under the License.
+import logging
+
+
+class TimezoneAware(logging.Formatter):
+ """
+ Override `default_time_format` and `default_msec_format` to specify utc
offset.
+
+ utc offset is the matter, without it, time conversion could be wrong.
With this Formatter, `%(asctime)s`
+ will be formatted containing utc offset. (e.g. 2022-06-12 13:00:00+0000
123ms)
+
+ moments.js couldn't parse milliseconds comes after utc offset, so it would
be ideal `%(asctime)s`
+ formatted with millisecond comes before utc offset in th first place. (e.g
2022-06-12 13:00:00.123+0000)
+ But python standard lib doesn't support format like that.
+
+ Omitting milliseconds is possible by assigning `default_msec_format` to
`None`. But this requires
+ python3.9 or higher, so we can't omit milliseconds until dropping support
3.8 or under.
+
+ Therefore, to use in moments.js, formatted `%(asctime)s` has to be
re-formatted by javascript side.
+ """
+
+ default_time_format = '%Y-%m-%d %H:%M:%S%z'
+ default_msec_format = '%s %03dms'
diff --git
a/airflow/www/static/js/grid/details/content/taskInstance/Logs/utils.js
b/airflow/www/static/js/grid/details/content/taskInstance/Logs/utils.js
index 0b6d3de4dd..0678f520a2 100644
--- a/airflow/www/static/js/grid/details/content/taskInstance/Logs/utils.js
+++ b/airflow/www/static/js/grid/details/content/taskInstance/Logs/utils.js
@@ -48,17 +48,39 @@ export const parseLogs = (data, timezone, logLevelFilter,
fileSourceFilter) => {
}
const regExp = /\[(.*?)\] \{(.*?)\}/;
+ // e.g) '2022-06-15 10:30:06,020' or '2022-06-15 10:30:06+0900'
+ const dateRegex = /(\d{4}[./-]\d{2}[./-]\d{2}
\d{2}:\d{2}:\d{2})((,\d{3})|([+-]\d{4} \d{3}ms))/;
+ // above regex is a kind of duplication of 'dateRegex'
+ // in airflow/www/static/js/tl_log.js
const matches = line.match(regExp);
let logGroup = '';
if (matches) {
- // Replace UTC with the local timezone.
+ // Replace system timezone with user selected timezone.
const dateTime = matches[1];
- [logGroup] = matches[2].split(':');
- if (dateTime && timezone) {
- const localDateTime =
moment.utc(dateTime).tz(timezone).format(defaultFormatWithTZ);
- parsedLine = line.replace(dateTime, localDateTime);
- }
+ // e.g) '2022-06-15 10:30:06,020' or '2022-06-15 10:30:06+0900 123ms'
+ const dateMatches = dateTime?.match(dateRegex);
+ if (dateMatches) {
+ const [date, msecOrUTCOffset] = [dateMatches[1], dateMatches[2]];
+ if (msecOrUTCOffset.startsWith(',')) { // e.g) date='2022-06-15
10:30:06', msecOrUTCOffset=',020'
+ // for backward compatibility. (before 2.3.3)
+ // keep previous behavior if utcoffset not found. (consider it UTC)
+ //
+ if (dateTime && timezone) { // dateTime === fullMatch
+ const localDateTime =
moment.utc(dateTime).tz(timezone).format(defaultFormatWithTZ);
+ parsedLine = line.replace(dateTime, localDateTime);
+ }
+ } else {
+ // e.g) date='2022-06-15 10:30:06', msecOrUTCOffset='+0900 123ms'
+ // (formatted by airflow.utils.log.timezone_aware.TimezoneAware)
(since 2.3.3)
+ const [utcoffset, threeDigitMs] = msecOrUTCOffset.split(' ');
+ const msec = threeDigitMs.replace(/\D+/g, ''); // drop 'ms'
+ // e.g) datetime='2022-06-15 10:30:06.123+0900'
+ const localDateTime =
moment(`${date}.${msec}${utcoffset}`).tz(timezone).format(defaultFormatWithTZ);
+ parsedLine = line.replace(dateTime, localDateTime);
+ }
+ }
+ [logGroup] = matches[2].split(':');
fileSources.add(logGroup);
}
if (!fileSourceFilter || fileSourceFilter === logGroup) {
diff --git a/airflow/www/static/js/ti_log.js b/airflow/www/static/js/ti_log.js
index 1bf6b501a6..b6faa129b4 100644
--- a/airflow/www/static/js/ti_log.js
+++ b/airflow/www/static/js/ti_log.js
@@ -102,7 +102,9 @@ function autoTailingLog(tryNumber, metadata = null,
autoTailing = false) {
// Detect urls and log timestamps
const urlRegex =
/http(s)?:\/\/[\w.-]+(\.?:[\w.-]+)*([/?#][\w\-._~:/?#[\]@!$&'()*+,;=.%]+)?/g;
- const dateRegex = /\d{4}[./-]\d{2}[./-]\d{2} \d{2}:\d{2}:\d{2},\d{3}/g;
+ const dateRegex = /(\d{4}[./-]\d{2}[./-]\d{2}
\d{2}:\d{2}:\d{2})((,\d{3})|([+-]\d{4} \d{3}ms))/g;
+ // above regex is a kind of duplication of 'dateRegex'
+ // in
airflow/www/static/js/grid/details/content/taskinstance/Logs/utils.js
res.message.forEach((item) => {
const logBlockElementId = `try-${tryNumber}-${item[0]}`;
@@ -120,7 +122,22 @@ function autoTailingLog(tryNumber, metadata = null,
autoTailing = false) {
const escapedMessage = escapeHtml(item[1]);
const linkifiedMessage = escapedMessage
.replace(urlRegex, (url) => `<a href="${url}"
target="_blank">${url}</a>`)
- .replaceAll(dateRegex, (date) => `<time datetime="${date}+00:00"
data-with-tz="true">${formatDateTime(`${date}+00:00`)}</time>`);
+ .replaceAll(dateRegex, (dateMatches, date, msecOrUTCOffset) => {
+ // e.g) '2022-06-15 10:30:06,020' or '2022-06-15 10:30:06+0900
123ms'
+ if (msecOrUTCOffset.startsWith(',')) { // e.g) date='2022-06-15
10:30:06', msecOrUTCOffset=',020'
+ // for backward compatibility. (before 2.3.3)
+ // keep previous behavior if utcoffset not found.
+ //
+ return `<time datetime="${dateMatches}+00:00"
data-with-tz="true">${formatDateTime(`${dateMatches}+00:00`)}</time>`;
+ }
+ // e.g) date='2022-06-15 10:30:06', msecOrUTCOffset='+0900 123ms'
+ // (formatted by airflow.utils.log.timezone_aware.TimezoneAware)
(since 2.3.3)
+ const [utcoffset, threeDigitMs] = msecOrUTCOffset.split(' ');
+ const msec = threeDigitMs.replace(/\D+/g, ''); // drop 'ms'
+ const dateTime = `${date}.${msec}${utcoffset}`; // e.g)
datetime='2022-06-15 10:30:06.123+0900'
+ //
+ return `<time datetime="${dateTime}"
data-with-tz="true">${formatDateTime(`${dateTime}`)}</time>`;
+ });
logBlock.innerHTML += `${linkifiedMessage}\n`;
});
diff --git a/newsfragments/24373.significant.rst
b/newsfragments/24373.significant.rst
new file mode 100644
index 0000000000..3c7cb9becd
--- /dev/null
+++ b/newsfragments/24373.significant.rst
@@ -0,0 +1,23 @@
+Added new config ``[logging]log_formatter_class`` to fix timezone display for
logs on UI
+
+If you are using a custom Formatter subclass in your
``[logging]logging_config_class``, please inherit from
``airflow.utils.log.timezone_aware.TimezoneAware`` instead of
``logging.Formatter``.
+For example, in your ``custom_config.py``:
+
+.. code-block:: python
+
+ from airflow.utils.log.timezone_aware import TimezoneAware
+
+ # before
+ class YourCustomFormatter(logging.Formatter):
+ ...
+
+
+ # after
+ class YourCustomFormatter(TimezoneAware):
+ ...
+
+
+ AIRFLOW_FORMATTER = LOGGING_CONFIG["formatters"]["airflow"]
+ AIRFLOW_FORMATTER["class"] =
"somewhere.your.custom_config.YourCustomFormatter"
+ # or use TimezoneAware class directly. If you don't have custom Formatter.
+ AIRFLOW_FORMATTER["class"] =
"airflow.utils.log.timezone_aware.TimezoneAware"
