From d098f118e7c9b964a34843890291f77fe7b2e2d4 Mon Sep 17 00:00:00 2001
From: Maksymilian Knust <m.knust@samsung.com>
Date: Tue, 25 Jun 2024 12:01:54 +0200
Subject: [PATCH 1/5] Unify stdio logging
Darwin now uses the same stdio logging implementation as other platforms.
Logs are colorized and contain timestamps.
On linux and darwin, pid and tid are also logged.
---
src/platform/logging/BUILD.gn | 6 +-
src/platform/logging/impl/stdio/Logging.cpp | 49 ++++++++++++-
.../logging/impl/stdio/darwin/Logging.cpp | 72 -------------------
3 files changed, 49 insertions(+), 78 deletions(-)
delete mode 100644 src/platform/logging/impl/stdio/darwin/Logging.cpp
diff --git a/src/platform/logging/BUILD.gn b/src/platform/logging/BUILD.gn
index 6b914cab7357d2..632c4ee5353224 100644
--- a/src/platform/logging/BUILD.gn
+++ b/src/platform/logging/BUILD.gn
@@ -109,11 +109,7 @@ if (current_os == "android") {
stdio_archive = "$root_out_dir/liblogging-stdio.a"
source_set("stdio") {
- if (chip_device_platform == "darwin") {
- sources = [ "impl/stdio/darwin/Logging.cpp" ]
- } else {
- sources = [ "impl/stdio/Logging.cpp" ]
- }
+ sources = [ "impl/stdio/Logging.cpp" ]
deps = [
":headers",
diff --git a/src/platform/logging/impl/stdio/Logging.cpp b/src/platform/logging/impl/stdio/Logging.cpp
index c403c29b913293..65bfe94b00b8e9 100644
--- a/src/platform/logging/impl/stdio/Logging.cpp
+++ b/src/platform/logging/impl/stdio/Logging.cpp
@@ -4,17 +4,64 @@
#include <lib/support/logging/Constants.h>
+#include <inttypes.h>
#include <stdio.h>
+#include <time.h>
+
+#if defined(__APPLE__)
+#include <pthread.h>
+#include <unistd.h>
+#elif defined(__gnu_linux__)
+#include <sys/syscall.h>
+#include <unistd.h>
+#endif
namespace chip {
namespace Logging {
namespace Platform {
+// TODO: investigate whether pw_chrono or pw_log could be used here
void LogV(const char * module, uint8_t category, const char * msg, va_list v)
{
+#if defined(_POSIX_THREAD_SAFE_FUNCTIONS)
+ flockfile(stdout);
+#endif
+
+ switch (category)
+ {
+ case kLogCategory_Error:
+ printf("\033[1;31m");
+ break;
+ case kLogCategory_Progress:
+ printf("\033[0;32m");
+ break;
+ case kLogCategory_Detail:
+ printf("\033[0;34m");
+ break;
+ }
+
+#if defined(__APPLE__) || defined(__gnu_linux__)
+ timespec ts;
+ timespec_get(&ts, TIME_UTC);
+ printf("[%lld.%06ld] ", static_cast<long long>(ts.tv_sec), static_cast<long>(ts.tv_nsec / 1000));
+#endif
+
+#if defined(__APPLE__)
+ uint64_t ktid;
+ pthread_threadid_np(nullptr, &ktid);
+ printf("[%lld:%lld] ", static_cast<long long>(getpid()), static_cast<long long>(ktid));
+#elif defined(__gnu_linux__) && !defined(__NuttX__)
+ // TODO: change to getpid() and gettid() after glib upgrade
+ printf("[%lld:%lld] ", static_cast<long long>(syscall(SYS_getpid)), static_cast<long long>(syscall(SYS_gettid)));
+#endif
+
printf("CHIP:%s: ", module);
vprintf(msg, v);
- printf("\n");
+ printf("\033[0m\n");
+
+#if defined(_POSIX_THREAD_SAFE_FUNCTIONS)
+ funlockfile(stdout);
+#endif
}
} // namespace Platform
diff --git a/src/platform/logging/impl/stdio/darwin/Logging.cpp b/src/platform/logging/impl/stdio/darwin/Logging.cpp
deleted file mode 100644
index 49c58eea1d7bba..00000000000000
--- a/src/platform/logging/impl/stdio/darwin/Logging.cpp
+++ /dev/null
@@ -1,72 +0,0 @@
-/*
- *
- * Copyright (c) 2022 Project CHIP Authors
- *
- * Licensed 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.
- */
-
-#include <platform/logging/LogV.h>
-
-#include <lib/core/CHIPConfig.h>
-#include <lib/support/logging/Constants.h>
-#include <pthread.h>
-#include <stdio.h>
-#include <sys/time.h>
-#include <unistd.h>
-
-namespace chip {
-namespace Logging {
-namespace Platform {
-
-void LogV(const char * module, uint8_t category, const char * msg, va_list v)
-{
- timeval time;
- gettimeofday(&time, nullptr);
- long ms = (time.tv_sec * 1000) + (time.tv_usec / 1000);
-
- uint64_t ktid;
- pthread_threadid_np(nullptr, &ktid);
-
- char formattedMsg[CHIP_CONFIG_LOG_MESSAGE_MAX_SIZE];
- int32_t prefixLen =
- snprintf(formattedMsg, sizeof(formattedMsg), "[%ld] [%lld:%lld] [%s] ", ms, (long long) getpid(), (long long) ktid, module);
- if (prefixLen < 0)
- {
- // This should not happen
- return;
- }
-
- if (static_cast<size_t>(prefixLen) >= sizeof(formattedMsg))
- {
- prefixLen = sizeof(formattedMsg) - 1;
- }
-
- vsnprintf(formattedMsg + prefixLen, sizeof(formattedMsg) - static_cast<size_t>(prefixLen), msg, v);
-
- switch (category)
- {
- case kLogCategory_Error:
- printf("\033[1;31m%s\033[0m\n", formattedMsg);
- break;
- case kLogCategory_Progress:
- printf("\033[0;32m%s\033[0m\n", formattedMsg);
- break;
- case kLogCategory_Detail:
- printf("\033[0;34m%s\033[0m\n", formattedMsg);
- break;
- }
-}
-
-} // namespace Platform
-} // namespace Logging
-} // namespace chip
From 25cacdc1f76c5941ab746571b5fa2bbc9cd730b3 Mon Sep 17 00:00:00 2001
From: Maksymilian Knust <m.knust@samsung.com>
Date: Wed, 26 Jun 2024 09:56:07 +0200
Subject: [PATCH 2/5] Darwin formatting
---
src/platform/logging/impl/stdio/Logging.cpp | 5 +++--
1 file changed, 3 insertions(+), 2 deletions(-)
diff --git a/src/platform/logging/impl/stdio/Logging.cpp b/src/platform/logging/impl/stdio/Logging.cpp
index 65bfe94b00b8e9..99c7cd5e136ccb 100644
--- a/src/platform/logging/impl/stdio/Logging.cpp
+++ b/src/platform/logging/impl/stdio/Logging.cpp
@@ -23,6 +23,7 @@ namespace Platform {
// TODO: investigate whether pw_chrono or pw_log could be used here
void LogV(const char * module, uint8_t category, const char * msg, va_list v)
{
+ // Stdout needs to be locked, because it's printed in pieces
#if defined(_POSIX_THREAD_SAFE_FUNCTIONS)
flockfile(stdout);
#endif
@@ -43,7 +44,7 @@ void LogV(const char * module, uint8_t category, const char * msg, va_list v)
#if defined(__APPLE__) || defined(__gnu_linux__)
timespec ts;
timespec_get(&ts, TIME_UTC);
- printf("[%lld.%06ld] ", static_cast<long long>(ts.tv_sec), static_cast<long>(ts.tv_nsec / 1000));
+ printf("[%lld] ", static_cast<long long>(ts.tv_sec * 1000 + ts.tv_nsec / 1000000));
#endif
#if defined(__APPLE__)
@@ -55,7 +56,7 @@ void LogV(const char * module, uint8_t category, const char * msg, va_list v)
printf("[%lld:%lld] ", static_cast<long long>(syscall(SYS_getpid)), static_cast<long long>(syscall(SYS_gettid)));
#endif
- printf("CHIP:%s: ", module);
+ printf("[%s] ", module);
vprintf(msg, v);
printf("\033[0m\n");
From 0c80072f38031de1b0bc3d4a0f34ccab701a75fb Mon Sep 17 00:00:00 2001
From: Maksymilian Knust <m.knust@samsung.com>
Date: Wed, 26 Jun 2024 11:30:27 +0200
Subject: [PATCH 3/5] Fix cirque test driver
---
src/test_driver/linux-cirque/helper/CHIPTestBase.py | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/src/test_driver/linux-cirque/helper/CHIPTestBase.py b/src/test_driver/linux-cirque/helper/CHIPTestBase.py
index 7fd0c81e86f3ca..ea45a62221e7e5 100644
--- a/src/test_driver/linux-cirque/helper/CHIPTestBase.py
+++ b/src/test_driver/linux-cirque/helper/CHIPTestBase.py
@@ -145,7 +145,7 @@ def reset_thread_devices(self, devices: Union[List[str], str]):
self.assertTrue(self.wait_for_device_output(
device_id, "Thread Border Router started on AIL", 10))
self.assertTrue(self.wait_for_device_output(
- device_id, "CHIP:SVR: Server Listening...", 15))
+ device_id, "[SVR] Server Listening...", 15))
# Clear default Thread network commissioning data
self.logger.info("Resetting thread network on {}".format(
self.get_device_pretty_id(device_id)))
From f5a7159d7c22c9fd49acf82ca8ca909a041888c7 Mon Sep 17 00:00:00 2001
From: Maksymilian Knust <maks@knust.one>
Date: Thu, 27 Jun 2024 01:05:03 +0200
Subject: [PATCH 4/5] Log seconds and milliseconds
---
src/platform/logging/impl/stdio/Logging.cpp | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/src/platform/logging/impl/stdio/Logging.cpp b/src/platform/logging/impl/stdio/Logging.cpp
index 99c7cd5e136ccb..af2ee16cd339d6 100644
--- a/src/platform/logging/impl/stdio/Logging.cpp
+++ b/src/platform/logging/impl/stdio/Logging.cpp
@@ -44,7 +44,7 @@ void LogV(const char * module, uint8_t category, const char * msg, va_list v)
#if defined(__APPLE__) || defined(__gnu_linux__)
timespec ts;
timespec_get(&ts, TIME_UTC);
- printf("[%lld] ", static_cast<long long>(ts.tv_sec * 1000 + ts.tv_nsec / 1000000));
+ printf("[%lld.%ld] ", static_cast<long long>(ts.tv_sec), static_cast<long>(ts.tv_nsec / 1000000));
#endif
#if defined(__APPLE__)
From d8c9c2e767313f2f04ffd49900ae5f7a0ff2f0ab Mon Sep 17 00:00:00 2001
From: Maksymilian Knust <m.knust@samsung.com>
Date: Thu, 27 Jun 2024 01:15:11 +0200
Subject: [PATCH 5/5] Update Logging.cpp
---
src/platform/logging/impl/stdio/Logging.cpp | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)
diff --git a/src/platform/logging/impl/stdio/Logging.cpp b/src/platform/logging/impl/stdio/Logging.cpp
index af2ee16cd339d6..26e050f0286f9f 100644
--- a/src/platform/logging/impl/stdio/Logging.cpp
+++ b/src/platform/logging/impl/stdio/Logging.cpp
@@ -44,7 +44,7 @@ void LogV(const char * module, uint8_t category, const char * msg, va_list v)
#if defined(__APPLE__) || defined(__gnu_linux__)
timespec ts;
timespec_get(&ts, TIME_UTC);
- printf("[%lld.%ld] ", static_cast<long long>(ts.tv_sec), static_cast<long>(ts.tv_nsec / 1000000));
+ printf("[%lld.%03ld] ", static_cast<long long>(ts.tv_sec), static_cast<long>(ts.tv_nsec / 1000000));
#endif
#if defined(__APPLE__)