This is an automated email from the ASF dual-hosted git repository.
pierrejeambrun pushed a commit to branch v2-10-test
in repository https://gitbox.apache.org/repos/asf/airflow.git
The following commit(s) were added to refs/heads/v2-10-test by this push:
new 294683aa708 Fix wrong display of multiline messages in the log after
filtering (#44457)
294683aa708 is described below
commit 294683aa708d0ca6e410cfd1448889a09c96a9f6
Author: LIU ZHE YOU <[email protected]>
AuthorDate: Tue Dec 3 21:35:19 2024 +0800
Fix wrong display of multiline messages in the log after filtering (#44457)
* Fix Logs/utils
* Fix test for Logs/utils
* Fix by Review Comment
- Added red color styling to lines based on the `currentLevel`
- Added comments for new regExp
* Refactor Logs/utils test cases
---
.../dag/details/taskInstance/Logs/utils.test.tsx | 80 +++++++++++---
.../js/dag/details/taskInstance/Logs/utils.ts | 115 +++++++++++----------
airflow/www/static/js/utils/index.test.ts | 6 ++
airflow/www/static/js/utils/index.ts | 6 +-
4 files changed, 140 insertions(+), 67 deletions(-)
diff --git a/airflow/www/static/js/dag/details/taskInstance/Logs/utils.test.tsx
b/airflow/www/static/js/dag/details/taskInstance/Logs/utils.test.tsx
index 8e577068d27..57cad4314f6 100644
--- a/airflow/www/static/js/dag/details/taskInstance/Logs/utils.test.tsx
+++ b/airflow/www/static/js/dag/details/taskInstance/Logs/utils.test.tsx
@@ -19,27 +19,60 @@
/* global describe, test, expect */
+import { AnsiUp } from "ansi_up";
import { LogLevel, parseLogs } from "./utils";
-const mockTaskLog = `
-5d28cfda3219
+const mockTaskLogInfoBegin = `5d28cfda3219
*** Reading local file:
/root/airflow/logs/dag_id=test_ui_grid/run_id=scheduled__2022-06-03T00:00:00+00:00/task_id=section_1.get_entry_group/attempt=1.log
[2022-06-04 00:00:01,901] {taskinstance.py:1132} INFO - Dependencies all met
for <TaskInstance: test_ui_grid.section_1.get_entry_group
scheduled__2022-06-03T00:00:00+00:00 [queued]>
[2022-06-04 00:00:01,906] {taskinstance.py:1132} INFO - Dependencies all met
for <TaskInstance: test_ui_grid.section_1.get_entry_group
scheduled__2022-06-03T00:00:00+00:00 [queued]>
[2022-06-04 00:00:01,906] {taskinstance.py:1329} INFO -
---------------------------------------------------------------------------------
[2022-06-04 00:00:01,906] {taskinstance.py:1330} INFO - Starting attempt 1 of 1
[2022-06-04 00:00:01,906] {taskinstance.py:1331} INFO -
---------------------------------------------------------------------------------
-[2022-06-04 00:00:01,916] {taskinstance.py:1350} INFO - Executing
<Task(BashOperator): section_1.get_entry_group> on 2022-06-03 00:00:00+00:00
+`;
+const mockTaskLogErrorWithTraceback = `[2022-06-04 00:00:01,910]
{taskinstance.py:3311} ERROR - Task failed with exception
+Traceback (most recent call last):
+ File "/opt/airflow/airflow/models/taskinstance.py", line 767, in
_execute_task
+ result = _execute_callable(context=context, **execute_callable_kwargs)
+ File "/opt/airflow/airflow/models/taskinstance.py", line 733, in
_execute_callable
+ return ExecutionCallableRunner(
+ File "/opt/airflow/airflow/utils/operator_helpers.py", line 252, in run
+ return self.func(*args, **kwargs)
+ File "/opt/airflow/airflow/models/baseoperator.py", line 422, in wrapper
+ return func(self, *args, **kwargs)
+ File "/opt/airflow/airflow/operators/python.py", line 505, in execute
+ return super().execute(context=serializable_context)
+ File "/opt/airflow/airflow/models/baseoperator.py", line 422, in wrapper
+ return func(self, *args, **kwargs)
+ File "/opt/airflow/airflow/operators/python.py", line 238, in execute
+ return_value = self.execute_callable()
+ File "/opt/airflow/airflow/operators/python.py", line 870, in
execute_callable
+ result = self._execute_python_callable_in_subprocess(python_path)
+ File "/opt/airflow/airflow/operators/python.py", line 588, in
_execute_python_callable_in_subprocess
+ raise AirflowException(error_msg) from None
+airflow.exceptions.AirflowException: Process returned non-zero exit status 1.
+This is log line 1
+This is log line 2
+This is log line 3
+This is log line 4
+This is log line 5
+`;
+const mockTaskLogWarning = `[2022-06-04 00:00:02,010] {taskinstance.py:1548}
WARNING - Exporting env vars: AIRFLOW_CTX_DAG_OWNER=***
AIRFLOW_CTX_DAG_ID=test_ui_grid`;
+const mockTaskLogInfoEndWithWarningAndUrl = `[2022-06-04 00:00:01,914]
{taskinstance.py:1225} INFO - Marking task as FAILED.
dag_id=reproduce_log_error_dag, task_id=reproduce_log_error_python_task2,
run_id=manual__2024-11-30T02:18:22.203608+00:00,
execution_date=20241130T021822, start_date=20241130T021842,
end_date=20241130T021844
[2022-06-04 00:00:01,919] {standard_task_runner.py:52} INFO - Started process
41646 to run task
[2022-06-04 00:00:01,920] {standard_task_runner.py:80} INFO - Running: ['***',
'tasks', 'run', 'test_ui_grid', 'section_1.get_entry_group',
'scheduled__2022-06-03T00:00:00+00:00', '--job-id', '1626', '--raw',
'--subdir', 'DAGS_FOLDER/test_ui_grid.py', '--cfg-path', '/tmp/tmpte7k80ur']
[2022-06-04 00:00:01,921] {standard_task_runner.py:81} INFO - Job 1626:
Subtask section_1.get_entry_group
[2022-06-04 00:00:01,921] {dagbag.py:507} INFO - Filling up the DagBag from
/files/dags/test_ui_grid.py
[2022-06-04 00:00:01,964] {task_command.py:377} INFO - Running <TaskInstance:
test_ui_grid.section_1.get_entry_group scheduled__2022-06-03T00:00:00+00:00
[running]> on host 5d28cfda3219
-[2022-06-04 00:00:02,010] {taskinstance.py:1548} WARNING - Exporting env vars:
AIRFLOW_CTX_DAG_OWNER=*** AIRFLOW_CTX_DAG_ID=test_ui_grid
-[2024-07-01 00:00:02,010] {taskinstance.py:1548} INFO - Url parsing test =>
"https://apple.com";, "https://google.com";,
https://something.logs/_dashboard/?_g=(filters:!(),refreshInterval:(pause:!t,value:0),time:(from:now-1d,to:now))&_a=(columns:!(_source),filters:!(('$state':(store:appState))))
-`;
+${mockTaskLogWarning}
+[2024-07-01 00:00:02,010] {taskinstance.py:1548} INFO - Url parsing test =>
"https://apple.com";, "https://google.com";,
https://something.logs/_dashboard/?_g=(filters:!(),refreshInterval:(pause:!t,value:0),time:(from:now-1d,to:now))&_a=(columns:!(_source),filters:!(('$state':(store:appState))))`;
+
+const mockTaskLog =
`${mockTaskLogInfoBegin}${mockTaskLogErrorWithTraceback}${mockTaskLogInfoEndWithWarningAndUrl}`;
+const ansiUp = new AnsiUp();
+const parseExpectedLogs = (logs: string) => {
+ ansiUp.url_allowlist = {};
+ return logs.split("\n").map((line) => ansiUp.ansi_to_html(line));
+};
describe("Test Logs Utils.", () => {
test("parseLogs function replaces datetimes", () => {
@@ -65,13 +98,18 @@ describe("Test Logs Utils.", () => {
test.each([
{
logLevelFilters: [LogLevel.INFO],
- expectedNumberOfLines: 12,
+ expectedNumberOfLines: 14,
expectedNumberOfFileSources: 4,
+ expectedLogs:
`${mockTaskLogInfoBegin}${mockTaskLogInfoEndWithWarningAndUrl.replace(
+ mockTaskLogWarning,
+ ""
+ )}`,
},
{
logLevelFilters: [LogLevel.WARNING],
expectedNumberOfLines: 1,
expectedNumberOfFileSources: 1,
+ expectedLogs: mockTaskLogWarning,
},
])(
"Filtering logs on $logLevelFilters level should return
$expectedNumberOfLines lines and $expectedNumberOfFileSources file sources",
@@ -79,6 +117,7 @@ describe("Test Logs Utils.", () => {
logLevelFilters,
expectedNumberOfLines,
expectedNumberOfFileSources,
+ expectedLogs,
}) => {
const { parsedLogs, fileSources } = parseLogs(
mockTaskLog,
@@ -91,8 +130,11 @@ describe("Test Logs Utils.", () => {
expect(fileSources).toHaveLength(expectedNumberOfFileSources);
expect(parsedLogs).toBeDefined();
const lines = parsedLogs!.split("\n");
+ const expectedLines = parseExpectedLogs(expectedLogs);
expect(lines).toHaveLength(expectedNumberOfLines);
- lines.forEach((line) => expect(line).toContain(logLevelFilters[0]));
+ lines.forEach((line, index) => {
+ expect(line).toContain(expectedLines[index]);
+ });
}
);
@@ -104,6 +146,14 @@ describe("Test Logs Utils.", () => {
["taskinstance.py"],
[]
);
+ const expectedLogs = `[2022-06-04 00:00:01,901] {taskinstance.py:1132}
INFO - Dependencies all met for <TaskInstance:
test_ui_grid.section_1.get_entry_group scheduled__2022-06-03T00:00:00+00:00
[queued]>
+[2022-06-04 00:00:01,906] {taskinstance.py:1132} INFO - Dependencies all met
for <TaskInstance: test_ui_grid.section_1.get_entry_group
scheduled__2022-06-03T00:00:00+00:00 [queued]>
+[2022-06-04 00:00:01,906] {taskinstance.py:1329} INFO -
+[2022-06-04 00:00:01,906] {taskinstance.py:1330} INFO - Starting attempt 1 of 1
+[2022-06-04 00:00:01,906] {taskinstance.py:1331} INFO -
+${mockTaskLogErrorWithTraceback}
+${mockTaskLogWarning}
+[2024-07-01 00:00:02,010] {taskinstance.py:1548} INFO -`; // Ignore matching
for transformed hyperlinks; only verify that all the correct lines are returned.
expect(fileSources).toEqual([
"dagbag.py",
@@ -112,8 +162,11 @@ describe("Test Logs Utils.", () => {
"taskinstance.py",
]);
const lines = parsedLogs!.split("\n");
- expect(lines).toHaveLength(8);
- lines.forEach((line) => expect(line).toContain("taskinstance.py"));
+ const expectedLines = parseExpectedLogs(expectedLogs);
+ expect(lines).toHaveLength(34);
+ lines.forEach((line, index) => {
+ expect(line).toContain(expectedLines[index]);
+ });
});
test("parseLogs function with filter on log level and file source", () => {
@@ -145,7 +198,8 @@ describe("Test Logs Utils.", () => {
[]
);
- const lines = parsedLogs!.split("\n");
+ // remove the last line which is empty
+ const lines = parsedLogs!.split("\n").filter((line) => line.length > 0);
expect(lines[lines.length - 1]).toContain(
'<a href="https://apple.com"; target="_blank" rel="noopener noreferrer"
style="color: blue; text-decoration: underline;">https://apple.com</a>'
);
diff --git a/airflow/www/static/js/dag/details/taskInstance/Logs/utils.ts
b/airflow/www/static/js/dag/details/taskInstance/Logs/utils.ts
index f5340f0afb8..b35a713484e 100644
--- a/airflow/www/static/js/dag/details/taskInstance/Logs/utils.ts
+++ b/airflow/www/static/js/dag/details/taskInstance/Logs/utils.ts
@@ -59,7 +59,7 @@ export const logGroupEnd = / INFO -
(::|##\[])endgroup(::|\])/g;
export const parseLogs = (
data: string | undefined,
timezone: string | null,
- logLevelFilters: Array<LogLevel>,
+ logLevelFilters: Array<string>,
fileSourceFilters: Array<string>,
unfoldedLogGroups: Array<string>
) => {
@@ -79,6 +79,8 @@ export const parseLogs = (
const parsedLines: Array<string> = [];
const fileSources: Set<string> = new Set();
+ const targetLogLevels: Set<string> = new Set(logLevelFilters);
+ const targetFileSources: Set<string> = new Set(fileSourceFilters);
const ansiUp = new AnsiUp();
ansiUp.url_allowlist = {};
@@ -87,24 +89,20 @@ export const parseLogs = (
// Coloring (blue-60 as chakra style, is #0060df) and style such that log
group appears like a link
const logGroupStyle = "color:#0060df;cursor:pointer;font-weight:bold;";
+ // Example Log Format: [2021-08-26 00:00:00,000] {filename.py:42} INFO - Log
message
+ const regExp = /\[(.*?)\] \{(.*?)\} (.*?) -/;
+ let currentLevel: LogLevel = LogLevel.INFO;
+ let currentFileSource = "";
lines.forEach((line) => {
let parsedLine = line;
-
- // Apply log level filter.
- if (
- logLevelFilters.length > 0 &&
- logLevelFilters.every((level) => !line.includes(level))
- ) {
- return;
- }
-
- const regExp = /\[(.*?)\] \{(.*?)\}/;
const matches = line.match(regExp);
- let logGroup = "";
+ let fileSource = "";
if (matches) {
// Replace UTC with the local timezone.
const dateTime = matches[1];
- [logGroup] = matches[2].split(":");
+ [fileSource] = matches[2].split(":");
+ const logLevel = matches[3];
+
if (dateTime && timezone) {
// @ts-ignore
const localDateTime = moment
@@ -115,50 +113,63 @@ export const parseLogs = (
parsedLine = line.replace(dateTime, localDateTime);
}
- fileSources.add(logGroup);
+ // The `currentLogLevel` and `currentFileSource` should remain same
+ // until a new `logLevel` or `fileSource` is encountered.
+ currentLevel = logLevel as LogLevel;
+ currentFileSource = fileSource;
}
+ // Apply log level filter.
+ if (logLevelFilters.length > 0 && !targetLogLevels.has(currentLevel)) {
+ return;
+ }
+ if (fileSource) {
+ // Only add file source if it is not empty.
+ fileSources.add(fileSource);
+ }
+ // Apply file source filter.
if (
- fileSourceFilters.length === 0 ||
- fileSourceFilters.some((fileSourceFilter) =>
- line.includes(fileSourceFilter)
- )
+ fileSourceFilters.length > 0 &&
+ !targetFileSources.has(currentFileSource)
) {
- parsedLine = highlightByKeywords(
- parsedLine,
- errorKeywords,
- warningKeywords,
- logGroupStart,
- logGroupEnd
- );
- // for lines with color convert to nice HTML
- const coloredLine = ansiUp.ansi_to_html(parsedLine);
-
- // for lines with links, transform to hyperlinks
- const lineWithHyperlinks = coloredLine
- .replace(
- urlRegex,
- (url) =>
- `<a href="${url}" target="_blank" rel="noopener noreferrer"
style="color: blue; text-decoration: underline;">${url}</a>`
- )
- .replace(logGroupStart, (textLine) => {
- const unfoldIdSuffix = "_unfold";
- const foldIdSuffix = "_fold";
- const gName = textLine.substring(17);
- const gId = gName.replace(/\W+/g, "_").toLowerCase();
- const isFolded = unfoldedLogGroups.indexOf(gId) === -1;
- const ufDisplay = isFolded ? "" : "display:none;";
- const unfold = `<span id="${gId}${unfoldIdSuffix}"
style="${ufDisplay}${logGroupStyle}"> ▶ ${gName}</span>`;
- const fDisplay = isFolded ? "display:none;" : "";
- const fold = `<span style="${fDisplay}"><span
id="${gId}${foldIdSuffix}" style="${logGroupStyle}"> ▼ ${gName}</span>`;
- return unfold + fold;
- })
- .replace(
- logGroupEnd,
- " <span style='color:#0060df;'>▲▲▲ Log group
end</span></span>"
- );
- parsedLines.push(lineWithHyperlinks);
+ return;
}
+
+ parsedLine = highlightByKeywords(
+ parsedLine,
+ currentLevel,
+ errorKeywords,
+ warningKeywords,
+ logGroupStart,
+ logGroupEnd
+ );
+ // for lines with color convert to nice HTML
+ const coloredLine = ansiUp.ansi_to_html(parsedLine);
+
+ // for lines with links, transform to hyperlinks
+ const lineWithHyperlinks = coloredLine
+ .replace(
+ urlRegex,
+ (url) =>
+ `<a href="${url}" target="_blank" rel="noopener noreferrer"
style="color: blue; text-decoration: underline;">${url}</a>`
+ )
+ .replace(logGroupStart, (textLine) => {
+ const unfoldIdSuffix = "_unfold";
+ const foldIdSuffix = "_fold";
+ const gName = textLine.substring(17);
+ const gId = gName.replace(/\W+/g, "_").toLowerCase();
+ const isFolded = unfoldedLogGroups.indexOf(gId) === -1;
+ const ufDisplay = isFolded ? "" : "display:none;";
+ const unfold = `<span id="${gId}${unfoldIdSuffix}"
style="${ufDisplay}${logGroupStyle}"> ▶ ${gName}</span>`;
+ const fDisplay = isFolded ? "display:none;" : "";
+ const fold = `<span style="${fDisplay}"><span
id="${gId}${foldIdSuffix}" style="${logGroupStyle}"> ▼ ${gName}</span>`;
+ return unfold + fold;
+ })
+ .replace(
+ logGroupEnd,
+ " <span style='color:#0060df;'>▲▲▲ Log group
end</span></span>"
+ );
+ parsedLines.push(lineWithHyperlinks);
});
return {
diff --git a/airflow/www/static/js/utils/index.test.ts
b/airflow/www/static/js/utils/index.test.ts
index 569d3af98b5..26b1fd6d840 100644
--- a/airflow/www/static/js/utils/index.test.ts
+++ b/airflow/www/static/js/utils/index.test.ts
@@ -163,6 +163,7 @@ describe("Test highlightByKeywords", () => {
const expected = `\x1b[1m\x1b[31mline with Error\x1b[39m\x1b[0m`;
const highlightedLine = highlightByKeywords(
originalLine,
+ "",
["error"],
["warn"],
logGroupStart,
@@ -175,6 +176,7 @@ describe("Test highlightByKeywords", () => {
const expected = `\x1b[1m\x1b[33mline with Warning\x1b[39m\x1b[0m`;
const highlightedLine = highlightByKeywords(
originalLine,
+ "",
["error"],
["warn"],
logGroupStart,
@@ -187,6 +189,7 @@ describe("Test highlightByKeywords", () => {
const expected = `\x1b[1m\x1b[31mline with error Warning\x1b[39m\x1b[0m`;
const highlightedLine = highlightByKeywords(
originalLine,
+ "",
["error"],
["warn"],
logGroupStart,
@@ -198,6 +201,7 @@ describe("Test highlightByKeywords", () => {
const originalLine = " INFO - ::group::error";
const highlightedLine = highlightByKeywords(
originalLine,
+ "",
["error"],
["warn"],
logGroupStart,
@@ -209,6 +213,7 @@ describe("Test highlightByKeywords", () => {
const originalLine = " INFO - ::endgroup::";
const highlightedLine = highlightByKeywords(
originalLine,
+ "",
["endgroup"],
["warn"],
logGroupStart,
@@ -220,6 +225,7 @@ describe("Test highlightByKeywords", () => {
const originalLine = "sample line";
const highlightedLine = highlightByKeywords(
originalLine,
+ "",
["error"],
["warn"],
logGroupStart,
diff --git a/airflow/www/static/js/utils/index.ts
b/airflow/www/static/js/utils/index.ts
index 8bef31a8582..2742612dc8a 100644
--- a/airflow/www/static/js/utils/index.ts
+++ b/airflow/www/static/js/utils/index.ts
@@ -20,6 +20,7 @@
import Color from "color";
import type { DagRun, RunOrdering, Task, TaskInstance } from "src/types";
+import { LogLevel } from "src/dag/details/taskInstance/Logs/utils";
import useOffsetTop from "./useOffsetTop";
// Delay in ms for various hover actions
@@ -187,6 +188,7 @@ const toSentenceCase = (camelCase: string): string => {
const highlightByKeywords = (
parsedLine: string,
+ currentLogLevel: string,
errorKeywords: string[],
warningKeywords: string[],
logGroupStart: RegExp,
@@ -205,7 +207,7 @@ const highlightByKeywords = (
lowerParsedLine.includes(keyword)
);
- if (containsError) {
+ if (containsError || currentLogLevel === (LogLevel.ERROR as string)) {
return red(parsedLine);
}
@@ -213,7 +215,7 @@ const highlightByKeywords = (
lowerParsedLine.includes(keyword)
);
- if (containsWarning) {
+ if (containsWarning || currentLogLevel === (LogLevel.WARNING as string)) {
return yellow(parsedLine);
}
