From bf894d794f652c31dc487bb620165b31650f2263 Mon Sep 17 00:00:00 2001 From: Randil Date: Tue, 14 Jan 2025 15:47:28 +0530 Subject: [PATCH 01/18] [Automated] Update the native jar versions --- ballerina/Dependencies.toml | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ballerina/Dependencies.toml b/ballerina/Dependencies.toml index 03acf776..46802152 100644 --- a/ballerina/Dependencies.toml +++ b/ballerina/Dependencies.toml @@ -5,7 +5,7 @@ [ballerina] dependencies-toml-version = "2" -distribution-version = "2201.11.0-20241121-075100-c4c87cbc" +distribution-version = "2201.11.0-20241218-101200-109f6cc7" [[package]] org = "ballerina" From e6560726a1260dd2c1bdcb15d021b4a6cbafb62d Mon Sep 17 00:00:00 2001 From: Randil Date: Tue, 14 Jan 2025 19:29:22 +0530 Subject: [PATCH 02/18] Update Ballerina.toml version and add raw template logging functionality --- ballerina/natives.bal | 74 ++++++++++++++++--- ballerina/tests/log_test.bal | 50 ++++++------- integration-tests/Ballerina.toml | 8 +- .../samples/print-functions/raw_template.bal | 40 ++++++++++ integration-tests/tests/tests_json.bal | 50 ++++++------- integration-tests/tests/tests_logfmt.bal | 73 +++++++++++------- 6 files changed, 202 insertions(+), 93 deletions(-) create mode 100644 integration-tests/tests/resources/samples/print-functions/raw_template.bal diff --git a/ballerina/natives.bal b/ballerina/natives.bal index 5668d051..c71d7844 100644 --- a/ballerina/natives.bal +++ b/ballerina/natives.bal @@ -15,9 +15,9 @@ // under the License. import ballerina/io; -import ballerina/observe; import ballerina/jballerina.java; import ballerina/lang.value; +import ballerina/observe; # Represents log level types. enum LogLevel { @@ -28,7 +28,16 @@ enum LogLevel { } # A value of `anydata` type or a function pointer. -public type Value anydata|Valuer; +public type Value anydata|Valuer|PrintableRawTemplate; + +# Represents raw templates for logging. +# e.g: `The input value is ${val}` +# + strings - String values of the template as an array +# + insertions - Parameterized values/expressions after evaluations as an array +public type PrintableRawTemplate object { + public string[] & readonly strings; + public anydata[] insertions; +}; # A function, which returns `anydata` type. public type Valuer isolated function () returns anydata; @@ -82,19 +91,53 @@ public enum FileWriteOption { APPEND } +class PrintableRawTemplateImpl { + *object:RawTemplate; + public Value[] insertions; + + public isolated function init(PrintableRawTemplate printableRawTemplate) { + self.strings = printableRawTemplate.strings; + self.insertions = printableRawTemplate.insertions; + } + + public isolated function toString() returns string { + Value[] templateInsertions = self.insertions; + string[] templateStrings = self.strings; + string templatedString = templateStrings[0]; + foreach int i in 1 ..< (templateStrings.length()) { + Value templateInsert = templateInsertions[i - 1]; + if templateInsert is PrintableRawTemplate { + templatedString += new PrintableRawTemplateImpl(templateInsert).toString() + templateStrings[i]; + } else if templateInsert is Valuer { + templatedString += templateInsert().toString() + templateStrings[i]; + } else { + templatedString += templateInsert.toString() + templateStrings[i]; + } + } + return templatedString; + } +} + +isolated function processMessage(string|PrintableRawTemplate msg) returns string { + if msg is PrintableRawTemplate { + return new PrintableRawTemplateImpl(msg).toString(); + } + return msg; +} + # Prints debug logs. # ```ballerina -# log:printDebug("debug message", id = 845315) +# log:printDebug(`Debug message with value: ${value}`, id = 845315) # ``` # # + msg - The message to be logged # + 'error - The error struct to be logged # + stackTrace - The error stack trace to be logged # + keyValues - The key-value pairs to be logged -public isolated function printDebug(string msg, error? 'error = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { +public isolated function printDebug(string|PrintableRawTemplate msg, error? 'error = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { // Added `stackTrace` as an optional param due to https://github.com/ballerina-platform/ballerina-lang/issues/34572 if isLogLevelEnabled(DEBUG, getModuleName(keyValues)) { - print(DEBUG, msg, 'error, stackTrace, keyValues); + print(DEBUG, processMessage(msg), 'error, stackTrace, keyValues); } } @@ -108,9 +151,9 @@ public isolated function printDebug(string msg, error? 'error = (), error:StackF # + 'error - The error struct to be logged # + stackTrace - The error stack trace to be logged # + keyValues - The key-value pairs to be logged -public isolated function printError(string msg, error? 'error = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { +public isolated function printError(string|PrintableRawTemplate msg, error? 'error = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { if isLogLevelEnabled(ERROR, getModuleName(keyValues)) { - print(ERROR, msg, 'error, stackTrace, keyValues); + print(ERROR, processMessage(msg), 'error, stackTrace, keyValues); } } @@ -123,9 +166,9 @@ public isolated function printError(string msg, error? 'error = (), error:StackF # + 'error - The error struct to be logged # + stackTrace - The error stack trace to be logged # + keyValues - The key-value pairs to be logged -public isolated function printInfo(string msg, error? 'error = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { +public isolated function printInfo(string|PrintableRawTemplate msg, error? 'error = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { if isLogLevelEnabled(INFO, getModuleName(keyValues)) { - print(INFO, msg, 'error, stackTrace, keyValues); + print(INFO, processMessage(msg), 'error, stackTrace, keyValues); } } @@ -138,9 +181,9 @@ public isolated function printInfo(string msg, error? 'error = (), error:StackFr # + 'error - The error struct to be logged # + stackTrace - The error stack trace to be logged # + keyValues - The key-value pairs to be logged -public isolated function printWarn(string msg, error? 'error = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { +public isolated function printWarn(string|PrintableRawTemplate msg, error? 'error = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { if isLogLevelEnabled(WARN, getModuleName(keyValues)) { - print(WARN, msg, 'error, stackTrace, keyValues); + print(WARN, processMessage(msg), 'error, stackTrace, keyValues); } } @@ -187,7 +230,14 @@ isolated function print(string logLevel, string msg, error? err = (), error:Stac logRecord["stackTrace"] = stackTraceArray; } foreach [string, Value] [k, v] in keyValues.entries() { - anydata value = v is Valuer ? v() : v; + anydata value; + if v is Valuer { + value = v(); + } else if v is PrintableRawTemplate { + value = processMessage(v); + } else { + value = v; + } logRecord[k] = value; } if observe:isTracingEnabled() { diff --git a/ballerina/tests/log_test.bal b/ballerina/tests/log_test.bal index 9b831a93..d6a32e39 100644 --- a/ballerina/tests/log_test.bal +++ b/ballerina/tests/log_test.bal @@ -52,7 +52,7 @@ isolated function testPrintLogFmtExtern() { message: "debug message" }; test:assertEquals(printLogFmt(logRecord1), - "time=2021-05-04T10:32:13.220+05:30 level=DEBUG module=foo/bar message=\"debug message\""); + "time=2021-05-04T10:32:13.220+05:30 level=DEBUG module=foo/bar message=\"debug message\""); LogRecord logRecord2 = { time: "2021-05-04T10:32:13.220+05:30", level: "INFO", @@ -60,7 +60,7 @@ isolated function testPrintLogFmtExtern() { message: "debug message" }; test:assertEquals(printLogFmt(logRecord2), - "time=2021-05-04T10:32:13.220+05:30 level=INFO module=foo/bar message=\"debug message\""); + "time=2021-05-04T10:32:13.220+05:30 level=INFO module=foo/bar message=\"debug message\""); LogRecord logRecord3 = { time: "2021-05-04T10:32:13.220+05:30", level: "DEBUG", @@ -68,7 +68,7 @@ isolated function testPrintLogFmtExtern() { message: "debug message" }; test:assertEquals(printLogFmt(logRecord3), - "time=2021-05-04T10:32:13.220+05:30 level=DEBUG module=\"\" message=\"debug message\""); + "time=2021-05-04T10:32:13.220+05:30 level=DEBUG module=\"\" message=\"debug message\""); LogRecord logRecord4 = { time: "2021-05-04T10:32:13.220+05:30", level: "DEBUG", @@ -78,46 +78,46 @@ isolated function testPrintLogFmtExtern() { "id": 845315 }; test:assertEquals(printLogFmt(logRecord4), - "time=2021-05-04T10:32:13.220+05:30 level=DEBUG module=foo/bar message=\"debug message\" username=\"Alex\" id=845315"); + "time=2021-05-04T10:32:13.220+05:30 level=DEBUG module=foo/bar message=\"debug message\" username=\"Alex\" id=845315"); } public isolated function main() { error err = error("bad sad"); printDebug("something went wrong", 'error = err, stackTrace = err.stackTrace(), username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); printError("something went wrong", 'error = err, stackTrace = err.stackTrace(), username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); printInfo("something went wrong", 'error = err, stackTrace = err.stackTrace(), username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); printWarn("something went wrong", 'error = err, stackTrace = err.stackTrace(), username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); var result1 = setOutputFile("./foo/bar.log"); test:assertFalse(result1 is error); printInfo("something went wrong", 'error = err, username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); var result2 = setOutputFile("./foo/bar.log", APPEND); test:assertFalse(result2 is error); printInfo("something went wrong", 'error = err, username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); var result3 = setOutputFile("./foo/bar.log", OVERWRITE); test:assertFalse(result3 is error); printInfo("something went wrong", 'error = err, username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); var result4 = setOutputFile("./foo/bar.bal", OVERWRITE); test:assertTrue(result4 is error); diff --git a/integration-tests/Ballerina.toml b/integration-tests/Ballerina.toml index dffd6200..b769e6cd 100644 --- a/integration-tests/Ballerina.toml +++ b/integration-tests/Ballerina.toml @@ -1,20 +1,20 @@ [package] org = "ballerina" name = "integration_tests" -version = "@toml.version@" +version = "2.11.0" [[platform.java21.dependency]] groupId = "io.ballerina.stdlib" artifactId = "log-native" -path = "../native/build/libs/log-native-@project.version@.jar" +path = "../native/build/libs/log-native-2.11.0-SNAPSHOT.jar" [[platform.java21.dependency]] groupId = "io.ballerina.stdlib" artifactId = "log-test-utils" scope = "testOnly" -path = "../test-utils/build/libs/log-test-utils-@project.version@.jar" +path = "../test-utils/build/libs/log-test-utils-2.11.0-SNAPSHOT.jar" [[platform.java21.dependency]] groupId = "io.ballerina.stdlib" artifactId = "io-native" -path = "./lib/io-native-@io.native.version@.jar" +path = "./lib/io-native-1.7.0-20241218-111600-1da6a3f.jar" diff --git a/integration-tests/tests/resources/samples/print-functions/raw_template.bal b/integration-tests/tests/resources/samples/print-functions/raw_template.bal new file mode 100644 index 00000000..803c95f6 --- /dev/null +++ b/integration-tests/tests/resources/samples/print-functions/raw_template.bal @@ -0,0 +1,40 @@ +import ballerina/log; + +type HttpError error>; + +public function main() { + string name = "Alex92"; + int id = 845315; + boolean active = true; + + log:printError(string `Status: ${active} for user ${name} with ID ${id}`); + // log:printDebug(string `User ${name} with ID ${id} encountered an error`, id=343434); + + // error e = error("bad sad"); + // log:printError(string `Error occurred: ${e.message()}`); + + // map httpError = { + // "code": 403, + // "details": "Authentication failed" + // }; + // HttpError err = error(httpError.toJsonString()); + // log:printError(string `HTTP Error: ${err.message()}`); + + // // Testing escaping in raw templates + // log:printError(string `Special chars: \t\n\r\\\"`); + + // f1(); +} + +// function f1() { +// f2(); +// } + +// function f2() { +// f3(); +// } + +// function f3() { +// string stackTrace = "asdasdasd"; +// log:printError(string `Stack trace error: ${stackTrace}`); +// } diff --git a/integration-tests/tests/tests_json.bal b/integration-tests/tests/tests_json.bal index 97e609ac..fbe76338 100644 --- a/integration-tests/tests/tests_json.bal +++ b/integration-tests/tests/tests_json.bal @@ -14,8 +14,8 @@ // specific language governing permissions and limitations // under the License. -import ballerina/lang.'value; import ballerina/io; +import ballerina/lang.'value; import ballerina/test; const string CONFIG_DEBUG_JSON = "tests/resources/config/json/log-levels/debug/Config.toml"; @@ -67,7 +67,7 @@ public function testPrintDebugJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], "\", \"level\":\"DEBUG\", \"module\":\"\", \"message\":\"debug log\"}"); validateLogJson(logLines[6], "\", \"level\":\"DEBUG\", \"module\":\"\", \"message\":\"debug log\", \"username\":\"Alex92\", \"id\":845315, \"foo\":true}"); @@ -88,7 +88,7 @@ public function testPrintErrorJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], "\", \"level\":\"ERROR\", \"module\":\"\", \"message\":\"error log\"}"); validateLogJson(logLines[6], "\", \"level\":\"ERROR\", \"module\":\"\", \"message\":\"error log\", \"username\":\"Alex92\", \"id\":845315, \"foo\":true}"); @@ -109,7 +109,7 @@ public function testPrintInfoJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], "\", \"level\":\"INFO\", \"module\":\"\", \"message\":\"info log\"}"); validateLogJson(logLines[6], "\", \"level\":\"INFO\", \"module\":\"\", \"message\":\"info log\", \"username\":\"Alex92\", \"id\":845315, \"foo\":true}"); @@ -130,7 +130,7 @@ public function testPrintWarnJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], "\", \"level\":\"WARN\", \"module\":\"\", \"message\":\"warn log\"}"); validateLogJson(logLines[6], "\", \"level\":\"WARN\", \"module\":\"\", \"message\":\"warn log\", \"username\":\"Alex92\", \"id\":845315, \"foo\":true}"); @@ -151,7 +151,7 @@ public function testErrorLevelJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 6, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_JSON); } @@ -165,7 +165,7 @@ public function testWarnLevelJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 7, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_JSON); validateLogJson(logLines[6], MESSAGE_WARN_JSON); @@ -180,7 +180,7 @@ public function testInfoLevelJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 8, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_JSON); validateLogJson(logLines[6], MESSAGE_WARN_JSON); @@ -196,7 +196,7 @@ public function testDebugLevelJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 9, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_JSON); validateLogJson(logLines[6], MESSAGE_WARN_JSON); @@ -214,7 +214,7 @@ public function testProjectWithoutLogLevelJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 14, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_MAIN_JSON); validateLogJson(logLines[6], MESSAGE_WARN_MAIN_JSON); @@ -230,14 +230,14 @@ public function testProjectWithoutLogLevelJson() returns error? { @test:Config {} public function testProjectWithGlobalLogLevelJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_PROJECT_GLOBAL_LEVEL_JSON}, (), - "run", temp_dir_path + "/log-project"); + "run", temp_dir_path + "/log-project"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 11, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_MAIN_JSON); validateLogJson(logLines[6], MESSAGE_WARN_MAIN_JSON); @@ -250,14 +250,14 @@ public function testProjectWithGlobalLogLevelJson() returns error? { @test:Config {} public function testProjectWithGlobalAndDefualtPackageLogLevelJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_PROJECT_GLOBAL_AND_DEFAULT_PACKAGE_LEVEL_JSON}, - (), "run", temp_dir_path + "/log-project"); + (), "run", temp_dir_path + "/log-project"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 12, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_MAIN_JSON); validateLogJson(logLines[6], MESSAGE_WARN_MAIN_JSON); @@ -271,14 +271,14 @@ public function testProjectWithGlobalAndDefualtPackageLogLevelJson() returns err @test:Config {} public function testProjectWithGlobalAndModuleLogLevelsJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_PROJECT_GLOBAL_AND_MODULE_LEVEL_JSON}, (), - "run", temp_dir_path + "/log-project"); + "run", temp_dir_path + "/log-project"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 12, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_MAIN_JSON); validateLogJson(logLines[6], MESSAGE_WARN_MAIN_JSON); @@ -292,20 +292,20 @@ public function testProjectWithGlobalAndModuleLogLevelsJson() returns error? { @test:Config {} public function testObservabilityJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_OBSERVABILITY_PROJECT_JSON}, (), - "run", temp_dir_path + "/observability-project-json"); + "run", temp_dir_path + "/observability-project-json"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 9, INCORRECT_NUMBER_OF_LINES); io:ReadableByteChannel readableOutResult = result.stdout(); io:ReadableCharacterChannel sc2 = new (readableOutResult, UTF_8); string outText2 = check sc2.read(100000); - string[] ioLines = re`\n`.split(outText2); + string[] ioLines = re `\n`.split(outText2); string spanContext = ioLines[ioLines.length() - 1]; validateLogJson(logLines[5], string `", "level":"ERROR", "module":"myorg/myproject", "message":"error log", ${spanContext}}`); validateLogJson(logLines[6], string `", "level":"WARN", "module":"myorg/myproject", "message":"warn log", ${spanContext}}`); @@ -316,7 +316,7 @@ public function testObservabilityJson() returns error? { @test:Config {} public function testSetOutputFileSingleFileOverwriteJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_JSON}, (), "run", - FILE_WRITE_OUTPUT_OVERWRITE_INPUT_FILE_JSON); + FILE_WRITE_OUTPUT_OVERWRITE_INPUT_FILE_JSON); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -335,7 +335,7 @@ public function testSetOutputFileSingleFileOverwriteJson() returns error? { @test:Config {} public function testSetOutputFileSingleFileAppendJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_JSON}, (), "run", - FILE_WRITE_OUTPUT_APPEND_INPUT_FILE_JSON); + FILE_WRITE_OUTPUT_APPEND_INPUT_FILE_JSON); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -355,7 +355,7 @@ public function testSetOutputFileSingleFileAppendJson() returns error? { @test:Config {} public function testSetOutputFileProjectOverwriteJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_JSON}, (), "run", - temp_dir_path + "/file-write-project/overwrite-json"); + temp_dir_path + "/file-write-project/overwrite-json"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -382,7 +382,7 @@ public function testSetOutputFileProjectOverwriteJson() returns error? { @test:Config {} public function testSetOutputFileProjectOverwriteJson2() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_JSON}, (), "run", - temp_dir_path + "/file-write-project/overwrite-json2"); + temp_dir_path + "/file-write-project/overwrite-json2"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -405,7 +405,7 @@ public function testSetOutputFileProjectOverwriteJson2() returns error? { @test:Config {} public function testSetOutputFileProjectAppendJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_JSON}, (), "run", - temp_dir_path + "/file-write-project/append-json"); + temp_dir_path + "/file-write-project/append-json"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -433,7 +433,7 @@ public function testSetOutputFileProjectAppendJson() returns error? { @test:Config {} public function testSetOutputFileProjectAppendJson2() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_JSON}, (), "run", - temp_dir_path + "/file-write-project/append-json2"); + temp_dir_path + "/file-write-project/append-json2"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); diff --git a/integration-tests/tests/tests_logfmt.bal b/integration-tests/tests/tests_logfmt.bal index cb235cc9..4a20e10d 100644 --- a/integration-tests/tests/tests_logfmt.bal +++ b/integration-tests/tests/tests_logfmt.bal @@ -14,8 +14,8 @@ // specific language governing permissions and limitations // under the License. -import ballerina/jballerina.java; import ballerina/io; +import ballerina/jballerina.java; import ballerina/test; const string UTF_8 = "UTF-8"; @@ -25,6 +25,7 @@ const string PRINT_INFO_FILE = "tests/resources/samples/print-functions/info.bal const string PRINT_WARN_FILE = "tests/resources/samples/print-functions/warn.bal"; const string PRINT_DEBUG_FILE = "tests/resources/samples/print-functions/debug.bal"; const string PRINT_ERROR_FILE = "tests/resources/samples/print-functions/error.bal"; +const string PRINT_RAW_TEMPLATE_FILE = "tests/resources/samples/print-functions/raw_template.bal"; const string LOG_LEVEL_FILE = "tests/resources/samples/log-levels/main.bal"; const string FILE_WRITE_OUTPUT_OVERWRITE_INPUT_FILE_LOGFMT = "tests/resources/samples/file-write-output/single-file/overwrite-logfmt.bal"; @@ -78,7 +79,7 @@ public function testPrintDebugLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], " level=DEBUG module=\"\" message=\"debug log\""); validateLog(logLines[6], " level=DEBUG module=\"\" message=\"debug log\" username=\"Alex92\" id=845315 foo=true"); @@ -99,7 +100,7 @@ public function testPrintErrorLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], " level=ERROR module=\"\" message=\"error log\""); validateLog(logLines[6], " level=ERROR module=\"\" message=\"error log\" username=\"Alex92\" id=845315 foo=true"); @@ -120,7 +121,7 @@ public function testPrintInfoLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], " level=INFO module=\"\" message=\"info log\""); validateLog(logLines[6], " level=INFO module=\"\" message=\"info log\" username=\"Alex92\" id=845315 foo=true"); @@ -141,7 +142,7 @@ public function testPrintWarnLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], " level=WARN module=\"\" message=\"warn log\""); validateLog(logLines[6], " level=WARN module=\"\" message=\"warn log\" username=\"Alex92\" id=845315 foo=true"); @@ -162,7 +163,7 @@ public function testErrorLevelLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 6, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_LOGFMT); } @@ -176,7 +177,7 @@ public function testWarnLevelLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 7, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_LOGFMT); @@ -191,7 +192,7 @@ public function testInfoLevelLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 8, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_LOGFMT); @@ -207,7 +208,7 @@ public function testDebugLevelLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 9, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_LOGFMT); @@ -215,6 +216,22 @@ public function testDebugLevelLogfmt() returns error? { validateLog(logLines[8], MESSAGE_DEBUG_LOGFMT); } +@test:Config {} +public function testPrintRawTemplate() returns error? { + Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_ERROR_LOGFMT}, (), "run", PRINT_RAW_TEMPLATE_FILE); + Process result = check execResult; + int _ = check result.waitForExit(); + int _ = check result.exitCode(); + io:ReadableByteChannel readableResult = result.stderr(); + io:ReadableCharacterChannel sc = new (readableResult, UTF_8); + string outText = check sc.read(100000); + string[] logLines = re `\n`.split(outText.trim()); + + // test:assertEquals(logLines.length(), 2, "Incorrect number of log lines"); + // validateLog(logLines[4], " level=DEBUG module=\"\" message=\"User Alex92 with ID 845315 encountered an error\""); + validateLog(logLines[4], " level=ERROR module=\"\" message=\"Status: true for user Alex92 with ID 845315\""); +} + @test:Config {} public function testProjectWithoutLogLevelLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {}, (), "run", temp_dir_path @@ -225,7 +242,7 @@ public function testProjectWithoutLogLevelLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 14, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_MAIN_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_MAIN_LOGFMT); @@ -241,14 +258,14 @@ public function testProjectWithoutLogLevelLogfmt() returns error? { @test:Config {} public function testProjectWithGlobalLogLevelLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_PROJECT_GLOBAL_LEVEL_LOGFMT}, (), - "run", temp_dir_path + "/log-project"); + "run", temp_dir_path + "/log-project"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 11, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_MAIN_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_MAIN_LOGFMT); @@ -261,14 +278,14 @@ public function testProjectWithGlobalLogLevelLogfmt() returns error? { @test:Config {} public function testProjectWithGlobalAndDefualtPackageLogLevelLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_PROJECT_GLOBAL_AND_DEFAULT_PACKAGE_LEVEL_LOGFMT}, - (), "run", temp_dir_path + "/log-project"); + (), "run", temp_dir_path + "/log-project"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 12, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_MAIN_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_MAIN_LOGFMT); @@ -282,14 +299,14 @@ public function testProjectWithGlobalAndDefualtPackageLogLevelLogfmt() returns e @test:Config {} public function testProjectWithGlobalAndModuleLogLevelsLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_PROJECT_GLOBAL_AND_MODULE_LEVEL_LOGFMT}, (), - "run", temp_dir_path + "/log-project"); + "run", temp_dir_path + "/log-project"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 12, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_MAIN_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_MAIN_LOGFMT); @@ -303,20 +320,20 @@ public function testProjectWithGlobalAndModuleLogLevelsLogfmt() returns error? { @test:Config {} public function testObservabilityLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_OBSERVABILITY_PROJECT_LOGFMT}, (), - "run", temp_dir_path + "/observability-project-logfmt"); + "run", temp_dir_path + "/observability-project-logfmt"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re`\n`.split(outText.trim()); + string[] logLines = re `\n`.split(outText.trim()); test:assertEquals(logLines.length(), 9, INCORRECT_NUMBER_OF_LINES); io:ReadableByteChannel readableOutResult = result.stdout(); io:ReadableCharacterChannel sc2 = new (readableOutResult, UTF_8); string outText2 = check sc2.read(100000); - string[] ioLines = re`\n`.split(outText2.trim()); + string[] ioLines = re `\n`.split(outText2.trim()); string spanContext = ioLines[ioLines.length() - 1]; // last line validateLog(logLines[5], string ` level=ERROR module=myorg/myproject message="error log" ${spanContext}`); validateLog(logLines[6], string ` level=WARN module=myorg/myproject message="warn log" ${spanContext}`); @@ -327,7 +344,7 @@ public function testObservabilityLogfmt() returns error? { @test:Config {} public function testSetOutputFileSingleFileOverwriteLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", - FILE_WRITE_OUTPUT_OVERWRITE_INPUT_FILE_LOGFMT); + FILE_WRITE_OUTPUT_OVERWRITE_INPUT_FILE_LOGFMT); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -346,7 +363,7 @@ public function testSetOutputFileSingleFileOverwriteLogfmt() returns error? { @test:Config {} public function testSetOutputFileSingleFileAppendLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", - FILE_WRITE_OUTPUT_APPEND_INPUT_FILE_LOGFMT); + FILE_WRITE_OUTPUT_APPEND_INPUT_FILE_LOGFMT); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -366,7 +383,7 @@ public function testSetOutputFileSingleFileAppendLogfmt() returns error? { @test:Config {} public function testSetOutputFileProjectOverwriteLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", - temp_dir_path + "/file-write-project/overwrite-logfmt"); + temp_dir_path + "/file-write-project/overwrite-logfmt"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -393,7 +410,7 @@ public function testSetOutputFileProjectOverwriteLogfmt() returns error? { @test:Config {} public function testSetOutputFileProjectOverwriteLogfmt2() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", - temp_dir_path + "/file-write-project/overwrite-logfmt2"); + temp_dir_path + "/file-write-project/overwrite-logfmt2"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -416,7 +433,7 @@ public function testSetOutputFileProjectOverwriteLogfmt2() returns error? { @test:Config {} public function testSetOutputFileProjectAppendLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", - temp_dir_path + "/file-write-project/append-logfmt"); + temp_dir_path + "/file-write-project/append-logfmt"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -444,7 +461,7 @@ public function testSetOutputFileProjectAppendLogfmt() returns error? { @test:Config {} public function testSetOutputFileProjectAppendLogfmt2() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", - temp_dir_path + "/file-write-project/append-logfmt2"); + temp_dir_path + "/file-write-project/append-logfmt2"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -466,12 +483,14 @@ public function testSetOutputFileProjectAppendLogfmt2() returns error? { } isolated function validateLog(string log, string output) { - test:assertTrue(log.includes("time="), "log does not contain the time"); + test:assertTrue(log.includes("time="), "log does not contain the time" + "this is what we got" + log); test:assertTrue(log.includes(output), string `log: ${log} does not contain the output: ${output}`); } function exec(@untainted string command, @untainted map env = {}, - @untainted string? dir = (), @untainted string... args) returns Process|error = @java:Method { + @untainted string? dir = (), @untainted + string... args) returns Process|error = @java:Method { name: "exec", 'class: "io.ballerina.stdlib.log.testutils.nativeimpl.Exec" } external; + From 3c924f1ed09a66b79e976b5e414e3bbff304ef52 Mon Sep 17 00:00:00 2001 From: Randil Date: Tue, 14 Jan 2025 20:30:54 +0530 Subject: [PATCH 03/18] Add test for raw template check (ERROR LEVEL) --- .../samples/log-levels-raw-template/main.bal | 27 +++++++++++++ .../samples/print-functions/raw_template.bal | 40 ------------------- integration-tests/tests/tests_logfmt.bal | 13 +++--- 3 files changed, 34 insertions(+), 46 deletions(-) create mode 100644 integration-tests/tests/resources/samples/log-levels-raw-template/main.bal delete mode 100644 integration-tests/tests/resources/samples/print-functions/raw_template.bal diff --git a/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal b/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal new file mode 100644 index 00000000..44d984df --- /dev/null +++ b/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal @@ -0,0 +1,27 @@ +// Copyright (c) 2021 WSO2 Inc. (http://www.wso2.org) All Rights Reserved. +// +// WSO2 Inc. 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 ballerina/log; + +public function main() { + string myname = "Alex92"; + int myage = 25; + log:printError(string `My name is ${myname} and my age is ${myage}`); + log:printWarn("warn log"); + log:printInfo("info log"); + log:printDebug("debug log"); +} + diff --git a/integration-tests/tests/resources/samples/print-functions/raw_template.bal b/integration-tests/tests/resources/samples/print-functions/raw_template.bal deleted file mode 100644 index 803c95f6..00000000 --- a/integration-tests/tests/resources/samples/print-functions/raw_template.bal +++ /dev/null @@ -1,40 +0,0 @@ -import ballerina/log; - -type HttpError error>; - -public function main() { - string name = "Alex92"; - int id = 845315; - boolean active = true; - - log:printError(string `Status: ${active} for user ${name} with ID ${id}`); - // log:printDebug(string `User ${name} with ID ${id} encountered an error`, id=343434); - - // error e = error("bad sad"); - // log:printError(string `Error occurred: ${e.message()}`); - - // map httpError = { - // "code": 403, - // "details": "Authentication failed" - // }; - // HttpError err = error(httpError.toJsonString()); - // log:printError(string `HTTP Error: ${err.message()}`); - - // // Testing escaping in raw templates - // log:printError(string `Special chars: \t\n\r\\\"`); - - // f1(); -} - -// function f1() { -// f2(); -// } - -// function f2() { -// f3(); -// } - -// function f3() { -// string stackTrace = "asdasdasd"; -// log:printError(string `Stack trace error: ${stackTrace}`); -// } diff --git a/integration-tests/tests/tests_logfmt.bal b/integration-tests/tests/tests_logfmt.bal index 4a20e10d..6958c99a 100644 --- a/integration-tests/tests/tests_logfmt.bal +++ b/integration-tests/tests/tests_logfmt.bal @@ -27,6 +27,7 @@ const string PRINT_DEBUG_FILE = "tests/resources/samples/print-functions/debug.b const string PRINT_ERROR_FILE = "tests/resources/samples/print-functions/error.bal"; const string PRINT_RAW_TEMPLATE_FILE = "tests/resources/samples/print-functions/raw_template.bal"; const string LOG_LEVEL_FILE = "tests/resources/samples/log-levels/main.bal"; +const string LOG_LEVEL_RAW_TEMPLATE_FILE = "tests/resources/samples/log-levels-raw-template/main.bal"; const string FILE_WRITE_OUTPUT_OVERWRITE_INPUT_FILE_LOGFMT = "tests/resources/samples/file-write-output/single-file/overwrite-logfmt.bal"; const string FILE_WRITE_OUTPUT_APPEND_INPUT_FILE_LOGFMT = "tests/resources/samples/file-write-output/single-file/append-logfmt.bal"; @@ -52,6 +53,8 @@ const string MESSAGE_WARN_LOGFMT = " level=WARN module=\"\" message=\"warn log\" const string MESSAGE_INFO_LOGFMT = " level=INFO module=\"\" message=\"info log\""; const string MESSAGE_DEBUG_LOGFMT = " level=DEBUG module=\"\" message=\"debug log\""; +const string MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT = " level=ERROR module=\"\" message=\"My name is Alex92 and my age is 25\""; + const string MESSAGE_ERROR_MAIN_LOGFMT = " level=ERROR module=myorg/myproject message=\"error log\\t\\n\\r\\\\\\\"\""; const string MESSAGE_WARN_MAIN_LOGFMT = " level=WARN module=myorg/myproject message=\"warn log\\t\\n\\r\\\\\\\"\""; const string MESSAGE_INFO_MAIN_LOGFMT = " level=INFO module=myorg/myproject message=\"info log\\t\\n\\r\\\\\\\"\""; @@ -217,8 +220,8 @@ public function testDebugLevelLogfmt() returns error? { } @test:Config {} -public function testPrintRawTemplate() returns error? { - Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_ERROR_LOGFMT}, (), "run", PRINT_RAW_TEMPLATE_FILE); +public function testErrorLevelRawTemplateLogfmt() returns error? { + Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_ERROR_LOGFMT}, (), "run", LOG_LEVEL_RAW_TEMPLATE_FILE); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -226,10 +229,8 @@ public function testPrintRawTemplate() returns error? { io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); string[] logLines = re `\n`.split(outText.trim()); - - // test:assertEquals(logLines.length(), 2, "Incorrect number of log lines"); - // validateLog(logLines[4], " level=DEBUG module=\"\" message=\"User Alex92 with ID 845315 encountered an error\""); - validateLog(logLines[4], " level=ERROR module=\"\" message=\"Status: true for user Alex92 with ID 845315\""); + test:assertEquals(logLines.length(), 6, INCORRECT_NUMBER_OF_LINES); + validateLog(logLines[5], MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT); } @test:Config {} From cb4e3390fcbdeba7175710dc64870f0a7d0083f1 Mon Sep 17 00:00:00 2001 From: Randil Date: Tue, 14 Jan 2025 20:50:03 +0530 Subject: [PATCH 04/18] Enhance logging messages in raw template with prefixes and add tests for warn, info, and debug levels --- .../samples/log-levels-raw-template/main.bal | 8 +-- integration-tests/tests/tests_logfmt.bal | 53 ++++++++++++++++++- 2 files changed, 56 insertions(+), 5 deletions(-) diff --git a/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal b/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal index 44d984df..cf27610c 100644 --- a/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal +++ b/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal @@ -19,9 +19,9 @@ import ballerina/log; public function main() { string myname = "Alex92"; int myage = 25; - log:printError(string `My name is ${myname} and my age is ${myage}`); - log:printWarn("warn log"); - log:printInfo("info log"); - log:printDebug("debug log"); + log:printError(string `error: My name is ${myname} and my age is ${myage}`); + log:printWarn(string `warning: My name is ${myname} and my age is ${myage}`); + log:printInfo(string `info: My name is ${myname} and my age is ${myage}`); + log:printDebug(string `debug: My name is ${myname} and my age is ${myage}`); } diff --git a/integration-tests/tests/tests_logfmt.bal b/integration-tests/tests/tests_logfmt.bal index 6958c99a..ae5f719d 100644 --- a/integration-tests/tests/tests_logfmt.bal +++ b/integration-tests/tests/tests_logfmt.bal @@ -53,7 +53,10 @@ const string MESSAGE_WARN_LOGFMT = " level=WARN module=\"\" message=\"warn log\" const string MESSAGE_INFO_LOGFMT = " level=INFO module=\"\" message=\"info log\""; const string MESSAGE_DEBUG_LOGFMT = " level=DEBUG module=\"\" message=\"debug log\""; -const string MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT = " level=ERROR module=\"\" message=\"My name is Alex92 and my age is 25\""; +const string MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT = " level=ERROR module=\"\" message=\"error: My name is Alex92 and my age is 25\""; +const string MESSAGE_WARN_RAW_TEMPLATE_LOGFMT = " level=WARN module=\"\" message=\"warning: My name is Alex92 and my age is 25\""; +const string MESSAGE_INFO_RAW_TEMPLATE_LOGFMT = " level=INFO module=\"\" message=\"info: My name is Alex92 and my age is 25\""; +const string MESSAGE_DEBUG_RAW_TEMPLATE_LOGFMT = " level=DEBUG module=\"\" message=\"debug: My name is Alex92 and my age is 25\""; const string MESSAGE_ERROR_MAIN_LOGFMT = " level=ERROR module=myorg/myproject message=\"error log\\t\\n\\r\\\\\\\"\""; const string MESSAGE_WARN_MAIN_LOGFMT = " level=WARN module=myorg/myproject message=\"warn log\\t\\n\\r\\\\\\\"\""; @@ -233,6 +236,54 @@ public function testErrorLevelRawTemplateLogfmt() returns error? { validateLog(logLines[5], MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT); } +@test:Config {} +public function testWarnLevelRawTemplateLogfmt() returns error? { + Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_WARN_LOGFMT}, (), "run", LOG_LEVEL_RAW_TEMPLATE_FILE); + Process result = check execResult; + int _ = check result.waitForExit(); + int _ = check result.exitCode(); + io:ReadableByteChannel readableResult = result.stderr(); + io:ReadableCharacterChannel sc = new (readableResult, UTF_8); + string outText = check sc.read(100000); + string[] logLines = re `\n`.split(outText.trim()); + test:assertEquals(logLines.length(), 7, INCORRECT_NUMBER_OF_LINES); + validateLog(logLines[5], MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT); + validateLog(logLines[6], MESSAGE_WARN_RAW_TEMPLATE_LOGFMT); +} + +@test:Config {} +public function testInfoLevelRawTemplateLogfmt() returns error? { + Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_INFO_LOGFMT}, (), "run", LOG_LEVEL_RAW_TEMPLATE_FILE); + Process result = check execResult; + int _ = check result.waitForExit(); + int _ = check result.exitCode(); + io:ReadableByteChannel readableResult = result.stderr(); + io:ReadableCharacterChannel sc = new (readableResult, UTF_8); + string outText = check sc.read(100000); + string[] logLines = re `\n`.split(outText.trim()); + test:assertEquals(logLines.length(), 8, INCORRECT_NUMBER_OF_LINES); + validateLog(logLines[5], MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT); + validateLog(logLines[6], MESSAGE_WARN_RAW_TEMPLATE_LOGFMT); + validateLog(logLines[7], MESSAGE_INFO_RAW_TEMPLATE_LOGFMT); +} + +@test:Config {} +public function testDebugLevelRawTemplateLogfmt() returns error? { + Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", LOG_LEVEL_RAW_TEMPLATE_FILE); + Process result = check execResult; + int _ = check result.waitForExit(); + int _ = check result.exitCode(); + io:ReadableByteChannel readableResult = result.stderr(); + io:ReadableCharacterChannel sc = new (readableResult, UTF_8); + string outText = check sc.read(100000); + string[] logLines = re `\n`.split(outText.trim()); + test:assertEquals(logLines.length(), 9, INCORRECT_NUMBER_OF_LINES); + validateLog(logLines[5], MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT); + validateLog(logLines[6], MESSAGE_WARN_RAW_TEMPLATE_LOGFMT); + validateLog(logLines[7], MESSAGE_INFO_RAW_TEMPLATE_LOGFMT); + validateLog(logLines[8], MESSAGE_DEBUG_RAW_TEMPLATE_LOGFMT); +} + @test:Config {} public function testProjectWithoutLogLevelLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {}, (), "run", temp_dir_path From 146da4221a6f50c6ed32a3722f852cd530fe5a8c Mon Sep 17 00:00:00 2001 From: Randil Date: Tue, 14 Jan 2025 21:08:57 +0530 Subject: [PATCH 05/18] Revert autoformat --- ballerina/tests/log_test.bal | 50 +++++++++++++------------- integration-tests/tests/tests_json.bal | 50 +++++++++++++------------- 2 files changed, 50 insertions(+), 50 deletions(-) diff --git a/ballerina/tests/log_test.bal b/ballerina/tests/log_test.bal index d6a32e39..9b831a93 100644 --- a/ballerina/tests/log_test.bal +++ b/ballerina/tests/log_test.bal @@ -52,7 +52,7 @@ isolated function testPrintLogFmtExtern() { message: "debug message" }; test:assertEquals(printLogFmt(logRecord1), - "time=2021-05-04T10:32:13.220+05:30 level=DEBUG module=foo/bar message=\"debug message\""); + "time=2021-05-04T10:32:13.220+05:30 level=DEBUG module=foo/bar message=\"debug message\""); LogRecord logRecord2 = { time: "2021-05-04T10:32:13.220+05:30", level: "INFO", @@ -60,7 +60,7 @@ isolated function testPrintLogFmtExtern() { message: "debug message" }; test:assertEquals(printLogFmt(logRecord2), - "time=2021-05-04T10:32:13.220+05:30 level=INFO module=foo/bar message=\"debug message\""); + "time=2021-05-04T10:32:13.220+05:30 level=INFO module=foo/bar message=\"debug message\""); LogRecord logRecord3 = { time: "2021-05-04T10:32:13.220+05:30", level: "DEBUG", @@ -68,7 +68,7 @@ isolated function testPrintLogFmtExtern() { message: "debug message" }; test:assertEquals(printLogFmt(logRecord3), - "time=2021-05-04T10:32:13.220+05:30 level=DEBUG module=\"\" message=\"debug message\""); + "time=2021-05-04T10:32:13.220+05:30 level=DEBUG module=\"\" message=\"debug message\""); LogRecord logRecord4 = { time: "2021-05-04T10:32:13.220+05:30", level: "DEBUG", @@ -78,46 +78,46 @@ isolated function testPrintLogFmtExtern() { "id": 845315 }; test:assertEquals(printLogFmt(logRecord4), - "time=2021-05-04T10:32:13.220+05:30 level=DEBUG module=foo/bar message=\"debug message\" username=\"Alex\" id=845315"); + "time=2021-05-04T10:32:13.220+05:30 level=DEBUG module=foo/bar message=\"debug message\" username=\"Alex\" id=845315"); } public isolated function main() { error err = error("bad sad"); printDebug("something went wrong", 'error = err, stackTrace = err.stackTrace(), username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); printError("something went wrong", 'error = err, stackTrace = err.stackTrace(), username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); printInfo("something went wrong", 'error = err, stackTrace = err.stackTrace(), username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); printWarn("something went wrong", 'error = err, stackTrace = err.stackTrace(), username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); var result1 = setOutputFile("./foo/bar.log"); test:assertFalse(result1 is error); printInfo("something went wrong", 'error = err, username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); var result2 = setOutputFile("./foo/bar.log", APPEND); test:assertFalse(result2 is error); printInfo("something went wrong", 'error = err, username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); var result3 = setOutputFile("./foo/bar.log", OVERWRITE); test:assertFalse(result3 is error); printInfo("something went wrong", 'error = err, username = "Alex92", admin = true, id = 845315, - attempts = isolated function() returns int { - return 3; - }); + attempts = isolated function() returns int { + return 3; + }); var result4 = setOutputFile("./foo/bar.bal", OVERWRITE); test:assertTrue(result4 is error); diff --git a/integration-tests/tests/tests_json.bal b/integration-tests/tests/tests_json.bal index fbe76338..97e609ac 100644 --- a/integration-tests/tests/tests_json.bal +++ b/integration-tests/tests/tests_json.bal @@ -14,8 +14,8 @@ // specific language governing permissions and limitations // under the License. -import ballerina/io; import ballerina/lang.'value; +import ballerina/io; import ballerina/test; const string CONFIG_DEBUG_JSON = "tests/resources/config/json/log-levels/debug/Config.toml"; @@ -67,7 +67,7 @@ public function testPrintDebugJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], "\", \"level\":\"DEBUG\", \"module\":\"\", \"message\":\"debug log\"}"); validateLogJson(logLines[6], "\", \"level\":\"DEBUG\", \"module\":\"\", \"message\":\"debug log\", \"username\":\"Alex92\", \"id\":845315, \"foo\":true}"); @@ -88,7 +88,7 @@ public function testPrintErrorJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], "\", \"level\":\"ERROR\", \"module\":\"\", \"message\":\"error log\"}"); validateLogJson(logLines[6], "\", \"level\":\"ERROR\", \"module\":\"\", \"message\":\"error log\", \"username\":\"Alex92\", \"id\":845315, \"foo\":true}"); @@ -109,7 +109,7 @@ public function testPrintInfoJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], "\", \"level\":\"INFO\", \"module\":\"\", \"message\":\"info log\"}"); validateLogJson(logLines[6], "\", \"level\":\"INFO\", \"module\":\"\", \"message\":\"info log\", \"username\":\"Alex92\", \"id\":845315, \"foo\":true}"); @@ -130,7 +130,7 @@ public function testPrintWarnJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], "\", \"level\":\"WARN\", \"module\":\"\", \"message\":\"warn log\"}"); validateLogJson(logLines[6], "\", \"level\":\"WARN\", \"module\":\"\", \"message\":\"warn log\", \"username\":\"Alex92\", \"id\":845315, \"foo\":true}"); @@ -151,7 +151,7 @@ public function testErrorLevelJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 6, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_JSON); } @@ -165,7 +165,7 @@ public function testWarnLevelJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 7, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_JSON); validateLogJson(logLines[6], MESSAGE_WARN_JSON); @@ -180,7 +180,7 @@ public function testInfoLevelJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 8, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_JSON); validateLogJson(logLines[6], MESSAGE_WARN_JSON); @@ -196,7 +196,7 @@ public function testDebugLevelJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 9, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_JSON); validateLogJson(logLines[6], MESSAGE_WARN_JSON); @@ -214,7 +214,7 @@ public function testProjectWithoutLogLevelJson() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 14, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_MAIN_JSON); validateLogJson(logLines[6], MESSAGE_WARN_MAIN_JSON); @@ -230,14 +230,14 @@ public function testProjectWithoutLogLevelJson() returns error? { @test:Config {} public function testProjectWithGlobalLogLevelJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_PROJECT_GLOBAL_LEVEL_JSON}, (), - "run", temp_dir_path + "/log-project"); + "run", temp_dir_path + "/log-project"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 11, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_MAIN_JSON); validateLogJson(logLines[6], MESSAGE_WARN_MAIN_JSON); @@ -250,14 +250,14 @@ public function testProjectWithGlobalLogLevelJson() returns error? { @test:Config {} public function testProjectWithGlobalAndDefualtPackageLogLevelJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_PROJECT_GLOBAL_AND_DEFAULT_PACKAGE_LEVEL_JSON}, - (), "run", temp_dir_path + "/log-project"); + (), "run", temp_dir_path + "/log-project"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 12, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_MAIN_JSON); validateLogJson(logLines[6], MESSAGE_WARN_MAIN_JSON); @@ -271,14 +271,14 @@ public function testProjectWithGlobalAndDefualtPackageLogLevelJson() returns err @test:Config {} public function testProjectWithGlobalAndModuleLogLevelsJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_PROJECT_GLOBAL_AND_MODULE_LEVEL_JSON}, (), - "run", temp_dir_path + "/log-project"); + "run", temp_dir_path + "/log-project"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 12, INCORRECT_NUMBER_OF_LINES); validateLogJson(logLines[5], MESSAGE_ERROR_MAIN_JSON); validateLogJson(logLines[6], MESSAGE_WARN_MAIN_JSON); @@ -292,20 +292,20 @@ public function testProjectWithGlobalAndModuleLogLevelsJson() returns error? { @test:Config {} public function testObservabilityJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_OBSERVABILITY_PROJECT_JSON}, (), - "run", temp_dir_path + "/observability-project-json"); + "run", temp_dir_path + "/observability-project-json"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 9, INCORRECT_NUMBER_OF_LINES); io:ReadableByteChannel readableOutResult = result.stdout(); io:ReadableCharacterChannel sc2 = new (readableOutResult, UTF_8); string outText2 = check sc2.read(100000); - string[] ioLines = re `\n`.split(outText2); + string[] ioLines = re`\n`.split(outText2); string spanContext = ioLines[ioLines.length() - 1]; validateLogJson(logLines[5], string `", "level":"ERROR", "module":"myorg/myproject", "message":"error log", ${spanContext}}`); validateLogJson(logLines[6], string `", "level":"WARN", "module":"myorg/myproject", "message":"warn log", ${spanContext}}`); @@ -316,7 +316,7 @@ public function testObservabilityJson() returns error? { @test:Config {} public function testSetOutputFileSingleFileOverwriteJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_JSON}, (), "run", - FILE_WRITE_OUTPUT_OVERWRITE_INPUT_FILE_JSON); + FILE_WRITE_OUTPUT_OVERWRITE_INPUT_FILE_JSON); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -335,7 +335,7 @@ public function testSetOutputFileSingleFileOverwriteJson() returns error? { @test:Config {} public function testSetOutputFileSingleFileAppendJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_JSON}, (), "run", - FILE_WRITE_OUTPUT_APPEND_INPUT_FILE_JSON); + FILE_WRITE_OUTPUT_APPEND_INPUT_FILE_JSON); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -355,7 +355,7 @@ public function testSetOutputFileSingleFileAppendJson() returns error? { @test:Config {} public function testSetOutputFileProjectOverwriteJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_JSON}, (), "run", - temp_dir_path + "/file-write-project/overwrite-json"); + temp_dir_path + "/file-write-project/overwrite-json"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -382,7 +382,7 @@ public function testSetOutputFileProjectOverwriteJson() returns error? { @test:Config {} public function testSetOutputFileProjectOverwriteJson2() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_JSON}, (), "run", - temp_dir_path + "/file-write-project/overwrite-json2"); + temp_dir_path + "/file-write-project/overwrite-json2"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -405,7 +405,7 @@ public function testSetOutputFileProjectOverwriteJson2() returns error? { @test:Config {} public function testSetOutputFileProjectAppendJson() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_JSON}, (), "run", - temp_dir_path + "/file-write-project/append-json"); + temp_dir_path + "/file-write-project/append-json"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -433,7 +433,7 @@ public function testSetOutputFileProjectAppendJson() returns error? { @test:Config {} public function testSetOutputFileProjectAppendJson2() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_JSON}, (), "run", - temp_dir_path + "/file-write-project/append-json2"); + temp_dir_path + "/file-write-project/append-json2"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); From 80085d68270e29ac9f74b0128dcc2398d15ac5d5 Mon Sep 17 00:00:00 2001 From: Randil Date: Tue, 14 Jan 2025 21:10:20 +0530 Subject: [PATCH 06/18] Fix regex syntax in logfmt test cases for consistent line splitting --- integration-tests/tests/tests_logfmt.bal | 34 ++++++++++++------------ 1 file changed, 17 insertions(+), 17 deletions(-) diff --git a/integration-tests/tests/tests_logfmt.bal b/integration-tests/tests/tests_logfmt.bal index ae5f719d..d532a470 100644 --- a/integration-tests/tests/tests_logfmt.bal +++ b/integration-tests/tests/tests_logfmt.bal @@ -85,7 +85,7 @@ public function testPrintDebugLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], " level=DEBUG module=\"\" message=\"debug log\""); validateLog(logLines[6], " level=DEBUG module=\"\" message=\"debug log\" username=\"Alex92\" id=845315 foo=true"); @@ -106,7 +106,7 @@ public function testPrintErrorLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], " level=ERROR module=\"\" message=\"error log\""); validateLog(logLines[6], " level=ERROR module=\"\" message=\"error log\" username=\"Alex92\" id=845315 foo=true"); @@ -127,7 +127,7 @@ public function testPrintInfoLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], " level=INFO module=\"\" message=\"info log\""); validateLog(logLines[6], " level=INFO module=\"\" message=\"info log\" username=\"Alex92\" id=845315 foo=true"); @@ -148,7 +148,7 @@ public function testPrintWarnLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 13, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], " level=WARN module=\"\" message=\"warn log\""); validateLog(logLines[6], " level=WARN module=\"\" message=\"warn log\" username=\"Alex92\" id=845315 foo=true"); @@ -169,7 +169,7 @@ public function testErrorLevelLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 6, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_LOGFMT); } @@ -183,7 +183,7 @@ public function testWarnLevelLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 7, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_LOGFMT); @@ -198,7 +198,7 @@ public function testInfoLevelLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 8, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_LOGFMT); @@ -214,7 +214,7 @@ public function testDebugLevelLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 9, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_LOGFMT); @@ -231,7 +231,7 @@ public function testErrorLevelRawTemplateLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 6, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT); } @@ -245,7 +245,7 @@ public function testWarnLevelRawTemplateLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 7, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_RAW_TEMPLATE_LOGFMT); @@ -260,7 +260,7 @@ public function testInfoLevelRawTemplateLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 8, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_RAW_TEMPLATE_LOGFMT); @@ -276,7 +276,7 @@ public function testDebugLevelRawTemplateLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 9, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_RAW_TEMPLATE_LOGFMT); @@ -294,7 +294,7 @@ public function testProjectWithoutLogLevelLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 14, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_MAIN_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_MAIN_LOGFMT); @@ -317,7 +317,7 @@ public function testProjectWithGlobalLogLevelLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 11, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_MAIN_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_MAIN_LOGFMT); @@ -337,7 +337,7 @@ public function testProjectWithGlobalAndDefualtPackageLogLevelLogfmt() returns e io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 12, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_MAIN_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_MAIN_LOGFMT); @@ -358,7 +358,7 @@ public function testProjectWithGlobalAndModuleLogLevelsLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 12, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_MAIN_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_MAIN_LOGFMT); @@ -379,7 +379,7 @@ public function testObservabilityLogfmt() returns error? { io:ReadableByteChannel readableResult = result.stderr(); io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); - string[] logLines = re `\n`.split(outText.trim()); + string[] logLines = re`\n`.split(outText.trim()); test:assertEquals(logLines.length(), 9, INCORRECT_NUMBER_OF_LINES); io:ReadableByteChannel readableOutResult = result.stdout(); From 678ae266527979ff904aa9a7f6094f95f5eae7a5 Mon Sep 17 00:00:00 2001 From: Randil Date: Tue, 14 Jan 2025 21:16:33 +0530 Subject: [PATCH 07/18] Update Ballerina.toml and logfmt tests to use dynamic versioning and improve code formatting --- integration-tests/Ballerina.toml | 8 ++++---- integration-tests/tests/tests_logfmt.bal | 23 +++++++++++------------ 2 files changed, 15 insertions(+), 16 deletions(-) diff --git a/integration-tests/Ballerina.toml b/integration-tests/Ballerina.toml index b769e6cd..a4b2c935 100644 --- a/integration-tests/Ballerina.toml +++ b/integration-tests/Ballerina.toml @@ -1,20 +1,20 @@ [package] org = "ballerina" name = "integration_tests" -version = "2.11.0" +version = "@toml.version@" [[platform.java21.dependency]] groupId = "io.ballerina.stdlib" artifactId = "log-native" -path = "../native/build/libs/log-native-2.11.0-SNAPSHOT.jar" +path = "../native/build/libs/log-native-@project.version@.jar" [[platform.java21.dependency]] groupId = "io.ballerina.stdlib" artifactId = "log-test-utils" scope = "testOnly" -path = "../test-utils/build/libs/log-test-utils-2.11.0-SNAPSHOT.jar" +path = "../test-utils/build/libs/log-test-utils-@project.version@.jar" [[platform.java21.dependency]] groupId = "io.ballerina.stdlib" artifactId = "io-native" -path = "./lib/io-native-1.7.0-20241218-111600-1da6a3f.jar" +path = "./lib/io-native-@io.native.version@.jar" \ No newline at end of file diff --git a/integration-tests/tests/tests_logfmt.bal b/integration-tests/tests/tests_logfmt.bal index d532a470..1360e443 100644 --- a/integration-tests/tests/tests_logfmt.bal +++ b/integration-tests/tests/tests_logfmt.bal @@ -310,7 +310,7 @@ public function testProjectWithoutLogLevelLogfmt() returns error? { @test:Config {} public function testProjectWithGlobalLogLevelLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_PROJECT_GLOBAL_LEVEL_LOGFMT}, (), - "run", temp_dir_path + "/log-project"); + "run", temp_dir_path + "/log-project"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -330,7 +330,7 @@ public function testProjectWithGlobalLogLevelLogfmt() returns error? { @test:Config {} public function testProjectWithGlobalAndDefualtPackageLogLevelLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_PROJECT_GLOBAL_AND_DEFAULT_PACKAGE_LEVEL_LOGFMT}, - (), "run", temp_dir_path + "/log-project"); + (), "run", temp_dir_path + "/log-project"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -351,7 +351,7 @@ public function testProjectWithGlobalAndDefualtPackageLogLevelLogfmt() returns e @test:Config {} public function testProjectWithGlobalAndModuleLogLevelsLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_PROJECT_GLOBAL_AND_MODULE_LEVEL_LOGFMT}, (), - "run", temp_dir_path + "/log-project"); + "run", temp_dir_path + "/log-project"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -372,7 +372,7 @@ public function testProjectWithGlobalAndModuleLogLevelsLogfmt() returns error? { @test:Config {} public function testObservabilityLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_OBSERVABILITY_PROJECT_LOGFMT}, (), - "run", temp_dir_path + "/observability-project-logfmt"); + "run", temp_dir_path + "/observability-project-logfmt"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -385,7 +385,7 @@ public function testObservabilityLogfmt() returns error? { io:ReadableByteChannel readableOutResult = result.stdout(); io:ReadableCharacterChannel sc2 = new (readableOutResult, UTF_8); string outText2 = check sc2.read(100000); - string[] ioLines = re `\n`.split(outText2.trim()); + string[] ioLines = re`\n`.split(outText2.trim()); string spanContext = ioLines[ioLines.length() - 1]; // last line validateLog(logLines[5], string ` level=ERROR module=myorg/myproject message="error log" ${spanContext}`); validateLog(logLines[6], string ` level=WARN module=myorg/myproject message="warn log" ${spanContext}`); @@ -435,7 +435,7 @@ public function testSetOutputFileSingleFileAppendLogfmt() returns error? { @test:Config {} public function testSetOutputFileProjectOverwriteLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", - temp_dir_path + "/file-write-project/overwrite-logfmt"); + temp_dir_path + "/file-write-project/overwrite-logfmt"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -462,7 +462,7 @@ public function testSetOutputFileProjectOverwriteLogfmt() returns error? { @test:Config {} public function testSetOutputFileProjectOverwriteLogfmt2() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", - temp_dir_path + "/file-write-project/overwrite-logfmt2"); + temp_dir_path + "/file-write-project/overwrite-logfmt2"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -485,7 +485,7 @@ public function testSetOutputFileProjectOverwriteLogfmt2() returns error? { @test:Config {} public function testSetOutputFileProjectAppendLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", - temp_dir_path + "/file-write-project/append-logfmt"); + temp_dir_path + "/file-write-project/append-logfmt"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -513,7 +513,7 @@ public function testSetOutputFileProjectAppendLogfmt() returns error? { @test:Config {} public function testSetOutputFileProjectAppendLogfmt2() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", - temp_dir_path + "/file-write-project/append-logfmt2"); + temp_dir_path + "/file-write-project/append-logfmt2"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -535,13 +535,12 @@ public function testSetOutputFileProjectAppendLogfmt2() returns error? { } isolated function validateLog(string log, string output) { - test:assertTrue(log.includes("time="), "log does not contain the time" + "this is what we got" + log); + test:assertTrue(log.includes("time="), "log does not contain the time"); test:assertTrue(log.includes(output), string `log: ${log} does not contain the output: ${output}`); } function exec(@untainted string command, @untainted map env = {}, - @untainted string? dir = (), @untainted - string... args) returns Process|error = @java:Method { + @untainted string? dir = (), @untainted string... args) returns Process|error = @java:Method { name: "exec", 'class: "io.ballerina.stdlib.log.testutils.nativeimpl.Exec" } external; From b40b92df5d4437e67adce30df9bc807e6e90b570 Mon Sep 17 00:00:00 2001 From: Randil Date: Tue, 14 Jan 2025 21:19:26 +0530 Subject: [PATCH 08/18] Fix indentation in logfmt test cases for improved readability --- integration-tests/tests/tests_logfmt.bal | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/integration-tests/tests/tests_logfmt.bal b/integration-tests/tests/tests_logfmt.bal index 1360e443..bd00af80 100644 --- a/integration-tests/tests/tests_logfmt.bal +++ b/integration-tests/tests/tests_logfmt.bal @@ -330,7 +330,7 @@ public function testProjectWithGlobalLogLevelLogfmt() returns error? { @test:Config {} public function testProjectWithGlobalAndDefualtPackageLogLevelLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_PROJECT_GLOBAL_AND_DEFAULT_PACKAGE_LEVEL_LOGFMT}, - (), "run", temp_dir_path + "/log-project"); + (), "run", temp_dir_path + "/log-project"); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -396,7 +396,7 @@ public function testObservabilityLogfmt() returns error? { @test:Config {} public function testSetOutputFileSingleFileOverwriteLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", - FILE_WRITE_OUTPUT_OVERWRITE_INPUT_FILE_LOGFMT); + FILE_WRITE_OUTPUT_OVERWRITE_INPUT_FILE_LOGFMT); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -415,7 +415,7 @@ public function testSetOutputFileSingleFileOverwriteLogfmt() returns error? { @test:Config {} public function testSetOutputFileSingleFileAppendLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", - FILE_WRITE_OUTPUT_APPEND_INPUT_FILE_LOGFMT); + FILE_WRITE_OUTPUT_APPEND_INPUT_FILE_LOGFMT); Process result = check execResult; int _ = check result.waitForExit(); int _ = check result.exitCode(); @@ -540,7 +540,7 @@ isolated function validateLog(string log, string output) { } function exec(@untainted string command, @untainted map env = {}, - @untainted string? dir = (), @untainted string... args) returns Process|error = @java:Method { + @untainted string? dir = (), @untainted string... args) returns Process|error = @java:Method { name: "exec", 'class: "io.ballerina.stdlib.log.testutils.nativeimpl.Exec" } external; From 436adcf509157f00b912402a19c1cbd529baa567 Mon Sep 17 00:00:00 2001 From: Randil Date: Tue, 14 Jan 2025 21:21:03 +0530 Subject: [PATCH 09/18] Fix formatting in exec function signature for consistency --- integration-tests/tests/tests_logfmt.bal | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/integration-tests/tests/tests_logfmt.bal b/integration-tests/tests/tests_logfmt.bal index bd00af80..eecd537b 100644 --- a/integration-tests/tests/tests_logfmt.bal +++ b/integration-tests/tests/tests_logfmt.bal @@ -540,7 +540,7 @@ isolated function validateLog(string log, string output) { } function exec(@untainted string command, @untainted map env = {}, - @untainted string? dir = (), @untainted string... args) returns Process|error = @java:Method { + @untainted string? dir = (), @untainted string... args) returns Process|error = @java:Method { name: "exec", 'class: "io.ballerina.stdlib.log.testutils.nativeimpl.Exec" } external; From d54ed1eb3115c5d9e0b7ba4b11d6d09671be274c Mon Sep 17 00:00:00 2001 From: Randil Tharusha <51049280+randilt@users.noreply.github.com> Date: Thu, 16 Jan 2025 17:27:14 +0530 Subject: [PATCH 10/18] Apply suggestions from code review Co-authored-by: Danesh Kuruppu --- ballerina/natives.bal | 9 +-------- 1 file changed, 1 insertion(+), 8 deletions(-) diff --git a/ballerina/natives.bal b/ballerina/natives.bal index c71d7844..c967f2d9 100644 --- a/ballerina/natives.bal +++ b/ballerina/natives.bal @@ -230,14 +230,7 @@ isolated function print(string logLevel, string msg, error? err = (), error:Stac logRecord["stackTrace"] = stackTraceArray; } foreach [string, Value] [k, v] in keyValues.entries() { - anydata value; - if v is Valuer { - value = v(); - } else if v is PrintableRawTemplate { - value = processMessage(v); - } else { - value = v; - } + anydata value = v is Valuer ? v() : processMessage(v); logRecord[k] = value; } if observe:isTracingEnabled() { From 113f52cb8811b2cac9db7bcc7a3306a4d81715ec Mon Sep 17 00:00:00 2001 From: Randil Date: Thu, 16 Jan 2025 17:29:31 +0530 Subject: [PATCH 11/18] Add comment for raw templates in logging for clarity --- ballerina/natives.bal | 1 + 1 file changed, 1 insertion(+) diff --git a/ballerina/natives.bal b/ballerina/natives.bal index c71d7844..c2dc77e4 100644 --- a/ballerina/natives.bal +++ b/ballerina/natives.bal @@ -31,6 +31,7 @@ enum LogLevel { public type Value anydata|Valuer|PrintableRawTemplate; # Represents raw templates for logging. +# # e.g: `The input value is ${val}` # + strings - String values of the template as an array # + insertions - Parameterized values/expressions after evaluations as an array From 687823298918b960a6f2520eecef5c84fdbd25e7 Mon Sep 17 00:00:00 2001 From: Randil Date: Thu, 16 Jan 2025 18:30:08 +0530 Subject: [PATCH 12/18] Refactor logging functions to directly print messages and enhance log formatting for key-value pairs --- ballerina/natives.bal | 21 +++++++++++------ .../samples/log-levels-raw-template/main.bal | 1 + integration-tests/tests/tests_logfmt.bal | 23 +++++++++++++++++-- 3 files changed, 36 insertions(+), 9 deletions(-) diff --git a/ballerina/natives.bal b/ballerina/natives.bal index df892d9f..160125ba 100644 --- a/ballerina/natives.bal +++ b/ballerina/natives.bal @@ -138,7 +138,7 @@ isolated function processMessage(string|PrintableRawTemplate msg) returns string public isolated function printDebug(string|PrintableRawTemplate msg, error? 'error = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { // Added `stackTrace` as an optional param due to https://github.com/ballerina-platform/ballerina-lang/issues/34572 if isLogLevelEnabled(DEBUG, getModuleName(keyValues)) { - print(DEBUG, processMessage(msg), 'error, stackTrace, keyValues); + print(DEBUG, msg, 'error, stackTrace, keyValues); } } @@ -154,7 +154,7 @@ public isolated function printDebug(string|PrintableRawTemplate msg, error? 'err # + keyValues - The key-value pairs to be logged public isolated function printError(string|PrintableRawTemplate msg, error? 'error = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { if isLogLevelEnabled(ERROR, getModuleName(keyValues)) { - print(ERROR, processMessage(msg), 'error, stackTrace, keyValues); + print(ERROR, msg, 'error, stackTrace, keyValues); } } @@ -169,7 +169,7 @@ public isolated function printError(string|PrintableRawTemplate msg, error? 'err # + keyValues - The key-value pairs to be logged public isolated function printInfo(string|PrintableRawTemplate msg, error? 'error = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { if isLogLevelEnabled(INFO, getModuleName(keyValues)) { - print(INFO, processMessage(msg), 'error, stackTrace, keyValues); + print(INFO, msg, 'error, stackTrace, keyValues); } } @@ -184,7 +184,7 @@ public isolated function printInfo(string|PrintableRawTemplate msg, error? 'erro # + keyValues - The key-value pairs to be logged public isolated function printWarn(string|PrintableRawTemplate msg, error? 'error = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { if isLogLevelEnabled(WARN, getModuleName(keyValues)) { - print(WARN, processMessage(msg), 'error, stackTrace, keyValues); + print(WARN, msg, 'error, stackTrace, keyValues); } } @@ -213,12 +213,12 @@ public isolated function setOutputFile(string path, FileWriteOption option = APP } } -isolated function print(string logLevel, string msg, error? err = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { +isolated function print(string logLevel, string|PrintableRawTemplate msg, error? err = (), error:StackFrame[]? stackTrace = (), *KeyValues keyValues) { LogRecord logRecord = { time: getCurrentTime(), level: logLevel, module: getModuleNameExtern() == "." ? "" : getModuleNameExtern(), - message: msg + message: msg is PrintableRawTemplate ? processMessage(msg) : msg }; if err is error { logRecord.'error = getFullErrorDetails(err); @@ -231,7 +231,14 @@ isolated function print(string logLevel, string msg, error? err = (), error:Stac logRecord["stackTrace"] = stackTraceArray; } foreach [string, Value] [k, v] in keyValues.entries() { - anydata value = v is Valuer ? v() : processMessage(v); + anydata value; + if v is Valuer { + value = v(); + } else if v is PrintableRawTemplate { + value = processMessage(v); + } else { + value = v; + } logRecord[k] = value; } if observe:isTracingEnabled() { diff --git a/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal b/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal index cf27610c..e2599ef2 100644 --- a/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal +++ b/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal @@ -23,5 +23,6 @@ public function main() { log:printWarn(string `warning: My name is ${myname} and my age is ${myage}`); log:printInfo(string `info: My name is ${myname} and my age is ${myage}`); log:printDebug(string `debug: My name is ${myname} and my age is ${myage}`); + log:printInfo("User details", details = string `name: ${myname}, age: ${myage}`); } diff --git a/integration-tests/tests/tests_logfmt.bal b/integration-tests/tests/tests_logfmt.bal index eecd537b..0793e5cc 100644 --- a/integration-tests/tests/tests_logfmt.bal +++ b/integration-tests/tests/tests_logfmt.bal @@ -57,6 +57,7 @@ const string MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT = " level=ERROR module=\"\" messa const string MESSAGE_WARN_RAW_TEMPLATE_LOGFMT = " level=WARN module=\"\" message=\"warning: My name is Alex92 and my age is 25\""; const string MESSAGE_INFO_RAW_TEMPLATE_LOGFMT = " level=INFO module=\"\" message=\"info: My name is Alex92 and my age is 25\""; const string MESSAGE_DEBUG_RAW_TEMPLATE_LOGFMT = " level=DEBUG module=\"\" message=\"debug: My name is Alex92 and my age is 25\""; +const string MESSAGE_KEY_VALUE_PAIR_LOGFMT = " level=INFO module=\"\" message=\"User details\" details=\"name: Alex92, age: 25\""; const string MESSAGE_ERROR_MAIN_LOGFMT = " level=ERROR module=myorg/myproject message=\"error log\\t\\n\\r\\\\\\\"\""; const string MESSAGE_WARN_MAIN_LOGFMT = " level=WARN module=myorg/myproject message=\"warn log\\t\\n\\r\\\\\\\"\""; @@ -261,7 +262,7 @@ public function testInfoLevelRawTemplateLogfmt() returns error? { io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); string[] logLines = re`\n`.split(outText.trim()); - test:assertEquals(logLines.length(), 8, INCORRECT_NUMBER_OF_LINES); + test:assertEquals(logLines.length(), 9, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_RAW_TEMPLATE_LOGFMT); validateLog(logLines[7], MESSAGE_INFO_RAW_TEMPLATE_LOGFMT); @@ -277,13 +278,31 @@ public function testDebugLevelRawTemplateLogfmt() returns error? { io:ReadableCharacterChannel sc = new (readableResult, UTF_8); string outText = check sc.read(100000); string[] logLines = re`\n`.split(outText.trim()); - test:assertEquals(logLines.length(), 9, INCORRECT_NUMBER_OF_LINES); + test:assertEquals(logLines.length(), 10, INCORRECT_NUMBER_OF_LINES); + validateLog(logLines[5], MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT); + validateLog(logLines[6], MESSAGE_WARN_RAW_TEMPLATE_LOGFMT); + validateLog(logLines[7], MESSAGE_INFO_RAW_TEMPLATE_LOGFMT); + validateLog(logLines[8], MESSAGE_DEBUG_RAW_TEMPLATE_LOGFMT); +} +@test:Config {} +public function testRawTemplateKeyValuePair() returns error? { + Process|error execResult = exec(bal_exec_path, {BAL_CONFIG_FILES: CONFIG_DEBUG_LOGFMT}, (), "run", LOG_LEVEL_RAW_TEMPLATE_FILE); + Process result = check execResult; + int _ = check result.waitForExit(); + int _ = check result.exitCode(); + io:ReadableByteChannel readableResult = result.stderr(); + io:ReadableCharacterChannel sc = new (readableResult, UTF_8); + string outText = check sc.read(100000); + string[] logLines = re`\n`.split(outText.trim()); + test:assertEquals(logLines.length(), 10, INCORRECT_NUMBER_OF_LINES); validateLog(logLines[5], MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT); validateLog(logLines[6], MESSAGE_WARN_RAW_TEMPLATE_LOGFMT); validateLog(logLines[7], MESSAGE_INFO_RAW_TEMPLATE_LOGFMT); validateLog(logLines[8], MESSAGE_DEBUG_RAW_TEMPLATE_LOGFMT); + validateLog(logLines[9], MESSAGE_KEY_VALUE_PAIR_LOGFMT); } + @test:Config {} public function testProjectWithoutLogLevelLogfmt() returns error? { Process|error execResult = exec(bal_exec_path, {}, (), "run", temp_dir_path From f2c2b1d02aaf3acf573474dd075fc53b714be828 Mon Sep 17 00:00:00 2001 From: Randil Date: Thu, 16 Jan 2025 18:33:35 +0530 Subject: [PATCH 13/18] Simplify value assignment in print function using ternary operators for improved readability --- ballerina/natives.bal | 9 +-------- 1 file changed, 1 insertion(+), 8 deletions(-) diff --git a/ballerina/natives.bal b/ballerina/natives.bal index 160125ba..d7d13cb9 100644 --- a/ballerina/natives.bal +++ b/ballerina/natives.bal @@ -231,14 +231,7 @@ isolated function print(string logLevel, string|PrintableRawTemplate msg, error? logRecord["stackTrace"] = stackTraceArray; } foreach [string, Value] [k, v] in keyValues.entries() { - anydata value; - if v is Valuer { - value = v(); - } else if v is PrintableRawTemplate { - value = processMessage(v); - } else { - value = v; - } + anydata value = v is Valuer ? v() : v is PrintableRawTemplate ? processMessage(v) : v; logRecord[k] = value; } if observe:isTracingEnabled() { From 7abe61190daf05fe0773ccc2a6b236193f6bb13d Mon Sep 17 00:00:00 2001 From: Randil Date: Thu, 16 Jan 2025 19:53:55 +0530 Subject: [PATCH 14/18] Refactor print function to always process messages, simplifying message handling --- ballerina/natives.bal | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ballerina/natives.bal b/ballerina/natives.bal index d7d13cb9..b57d80f6 100644 --- a/ballerina/natives.bal +++ b/ballerina/natives.bal @@ -218,7 +218,7 @@ isolated function print(string logLevel, string|PrintableRawTemplate msg, error? time: getCurrentTime(), level: logLevel, module: getModuleNameExtern() == "." ? "" : getModuleNameExtern(), - message: msg is PrintableRawTemplate ? processMessage(msg) : msg + message: processMessage(msg) }; if err is error { logRecord.'error = getFullErrorDetails(err); From cf176c154ea437aab0a4439d25e17d256dc1be22 Mon Sep 17 00:00:00 2001 From: Randil Date: Fri, 17 Jan 2025 09:37:04 +0530 Subject: [PATCH 15/18] Refactor processMessage function to use a concise arrow function syntax for improved readability --- ballerina/natives.bal | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-) diff --git a/ballerina/natives.bal b/ballerina/natives.bal index b57d80f6..267d7053 100644 --- a/ballerina/natives.bal +++ b/ballerina/natives.bal @@ -119,12 +119,8 @@ class PrintableRawTemplateImpl { } } -isolated function processMessage(string|PrintableRawTemplate msg) returns string { - if msg is PrintableRawTemplate { - return new PrintableRawTemplateImpl(msg).toString(); - } - return msg; -} +isolated function processMessage(string|PrintableRawTemplate msg) returns string => + msg is PrintableRawTemplate ? new PrintableRawTemplateImpl(msg).toString() : msg; # Prints debug logs. # ```ballerina From 53785075eb352fc4c3b6f8878d02cbb8b25a132b Mon Sep 17 00:00:00 2001 From: Randil Date: Fri, 17 Jan 2025 10:07:22 +0530 Subject: [PATCH 16/18] Change insertions type in PrintableRawTemplate from anydata[] to Value[] for improved type safety --- ballerina/natives.bal | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ballerina/natives.bal b/ballerina/natives.bal index 267d7053..2da99fef 100644 --- a/ballerina/natives.bal +++ b/ballerina/natives.bal @@ -37,7 +37,7 @@ public type Value anydata|Valuer|PrintableRawTemplate; # + insertions - Parameterized values/expressions after evaluations as an array public type PrintableRawTemplate object { public string[] & readonly strings; - public anydata[] insertions; + public Value[] insertions; }; # A function, which returns `anydata` type. From e4147fd3ae58f553d629d6b3992ed3bd80b366a5 Mon Sep 17 00:00:00 2001 From: Randil Date: Fri, 17 Jan 2025 14:22:40 +0530 Subject: [PATCH 17/18] Add support for logging raw template values in log APIs and update related tests --- changelog.md | 5 ++ ballerina/natives.bal | 51 +++++++++---------- .../samples/log-levels-raw-template/main.bal | 13 +++-- integration-tests/tests/tests_logfmt.bal | 2 +- 4 files changed, 37 insertions(+), 34 deletions(-) diff --git a/ changelog.md b/ changelog.md index 2ec1bc87..961e48c6 100644 --- a/ changelog.md +++ b/ changelog.md @@ -1,6 +1,11 @@ # Change Log This file contains all the notable changes done to the Ballerina TCP package through the releases. +## [Unreleased] + +### Added +- [Support logging raw template value in log APIs](https://github.com/ballerina-platform/ballerina-library/issues/3331) + ## [2.5.1] - 2023-01-04 ### Removed diff --git a/ballerina/natives.bal b/ballerina/natives.bal index 2da99fef..d587531c 100644 --- a/ballerina/natives.bal +++ b/ballerina/natives.bal @@ -27,15 +27,16 @@ enum LogLevel { WARN } -# A value of `anydata` type or a function pointer. +# A value of `anydata` type or a function pointer or raw template. public type Value anydata|Valuer|PrintableRawTemplate; # Represents raw templates for logging. -# +# # e.g: `The input value is ${val}` # + strings - String values of the template as an array # + insertions - Parameterized values/expressions after evaluations as an array public type PrintableRawTemplate object { + *object:RawTemplate; public string[] & readonly strings; public Value[] insertions; }; @@ -92,35 +93,29 @@ public enum FileWriteOption { APPEND } -class PrintableRawTemplateImpl { - *object:RawTemplate; - public Value[] insertions; - - public isolated function init(PrintableRawTemplate printableRawTemplate) { - self.strings = printableRawTemplate.strings; - self.insertions = printableRawTemplate.insertions; - } - - public isolated function toString() returns string { - Value[] templateInsertions = self.insertions; - string[] templateStrings = self.strings; - string templatedString = templateStrings[0]; - foreach int i in 1 ..< (templateStrings.length()) { - Value templateInsert = templateInsertions[i - 1]; - if templateInsert is PrintableRawTemplate { - templatedString += new PrintableRawTemplateImpl(templateInsert).toString() + templateStrings[i]; - } else if templateInsert is Valuer { - templatedString += templateInsert().toString() + templateStrings[i]; - } else { - templatedString += templateInsert.toString() + templateStrings[i]; - } - } - return templatedString; +# Process the raw template and return the processed string. +# +# + template - The raw template to be processed +# + return - The processed string +isolated function processTemplate(PrintableRawTemplate template) returns string { + string[] templateStrings = template.strings; + Value[] insertions = template.insertions; + string result = templateStrings[0]; + + foreach int i in 1 ..< templateStrings.length() { + Value insertion = insertions[i - 1]; + string insertionStr = insertion is PrintableRawTemplate ? + processTemplate(insertion) : + insertion is Valuer ? + insertion().toString() : + insertion.toString(); + result += insertionStr + templateStrings[i]; } + return result; } isolated function processMessage(string|PrintableRawTemplate msg) returns string => - msg is PrintableRawTemplate ? new PrintableRawTemplateImpl(msg).toString() : msg; + msg !is string ? processTemplate(msg) : msg; # Prints debug logs. # ```ballerina @@ -227,7 +222,7 @@ isolated function print(string logLevel, string|PrintableRawTemplate msg, error? logRecord["stackTrace"] = stackTraceArray; } foreach [string, Value] [k, v] in keyValues.entries() { - anydata value = v is Valuer ? v() : v is PrintableRawTemplate ? processMessage(v) : v; + anydata value = v is Valuer ? v() : v is PrintableRawTemplate ? processMessage(v) : v; logRecord[k] = value; } if observe:isTracingEnabled() { diff --git a/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal b/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal index e2599ef2..a933fe26 100644 --- a/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal +++ b/integration-tests/tests/resources/samples/log-levels-raw-template/main.bal @@ -19,10 +19,13 @@ import ballerina/log; public function main() { string myname = "Alex92"; int myage = 25; - log:printError(string `error: My name is ${myname} and my age is ${myage}`); - log:printWarn(string `warning: My name is ${myname} and my age is ${myage}`); - log:printInfo(string `info: My name is ${myname} and my age is ${myage}`); - log:printDebug(string `debug: My name is ${myname} and my age is ${myage}`); - log:printInfo("User details", details = string `name: ${myname}, age: ${myage}`); + string action1 = "action1"; + string action2 = "action2"; + string action3 = "action3"; + log:printError(`error: My name is ${myname} and my age is ${myage}`); + log:printWarn(`warning: My name is ${myname} and my age is ${myage}`); + log:printInfo(`info: My name is ${myname} and my age is ${myage}`); + log:printDebug(`debug: My name is ${myname} and my age is ${myage}`); + log:printInfo("User details", details = `name: ${myname}, age: ${myage}`, actions = `actions: ${action1}, ${action2}, ${action3}`); } diff --git a/integration-tests/tests/tests_logfmt.bal b/integration-tests/tests/tests_logfmt.bal index 0793e5cc..6bf9d028 100644 --- a/integration-tests/tests/tests_logfmt.bal +++ b/integration-tests/tests/tests_logfmt.bal @@ -57,7 +57,7 @@ const string MESSAGE_ERROR_RAW_TEMPLATE_LOGFMT = " level=ERROR module=\"\" messa const string MESSAGE_WARN_RAW_TEMPLATE_LOGFMT = " level=WARN module=\"\" message=\"warning: My name is Alex92 and my age is 25\""; const string MESSAGE_INFO_RAW_TEMPLATE_LOGFMT = " level=INFO module=\"\" message=\"info: My name is Alex92 and my age is 25\""; const string MESSAGE_DEBUG_RAW_TEMPLATE_LOGFMT = " level=DEBUG module=\"\" message=\"debug: My name is Alex92 and my age is 25\""; -const string MESSAGE_KEY_VALUE_PAIR_LOGFMT = " level=INFO module=\"\" message=\"User details\" details=\"name: Alex92, age: 25\""; +const string MESSAGE_KEY_VALUE_PAIR_LOGFMT = " level=INFO module=\"\" message=\"User details\" details=\"name: Alex92, age: 25\" actions=\"actions: action1, action2, action3\""; const string MESSAGE_ERROR_MAIN_LOGFMT = " level=ERROR module=myorg/myproject message=\"error log\\t\\n\\r\\\\\\\"\""; const string MESSAGE_WARN_MAIN_LOGFMT = " level=WARN module=myorg/myproject message=\"warn log\\t\\n\\r\\\\\\\"\""; From 3ec3b582653aacf553a83e8736beeb5c6ea0f20a Mon Sep 17 00:00:00 2001 From: Randil Tharusha <51049280+randilt@users.noreply.github.com> Date: Fri, 17 Jan 2025 14:43:43 +0530 Subject: [PATCH 18/18] Update printDebug function documentation Co-authored-by: Krishnananthalingam Tharmigan <63336800+TharmiganK@users.noreply.github.com> --- ballerina/natives.bal | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ballerina/natives.bal b/ballerina/natives.bal index d587531c..d40ebdc4 100644 --- a/ballerina/natives.bal +++ b/ballerina/natives.bal @@ -119,7 +119,7 @@ isolated function processMessage(string|PrintableRawTemplate msg) returns string # Prints debug logs. # ```ballerina -# log:printDebug(`Debug message with value: ${value}`, id = 845315) +# log:printDebug("debug message", id = 845315) # ``` # # + msg - The message to be logged