Star582
726
代码
代码
Issues59
Pull Requests161
Actions
项目讨论
Wiki
分析
Star582
726
已合并
fix: aclAppLog 超长日志改用截断而非丢弃整条日志(#555) #2850
GuoWenbo创建于 6月16日
fix: aclAppLog 超长日志改用截断而非丢弃整条日志(#555) #2850
已合并
GuoWenbo创建于 6月16日
从GuoWenbo/runtimefix/issue-555-aclapplog-truncate-910合入到cann/runtime9.1.0
共 5 个文件变更+123-17
Minclude/external/acl/acl_base_rt.h+4-0
@@ -353,6 +353,10 @@ ACL_FUNC_VISIBILITY size_t aclDataTypeSize(aclDataType dataType);
353 * @param line [IN] Number of source lines where the log is located353 * @param line [IN] Number of source lines where the log is located
354 * @param fmt [IN] the format of current log354 * @param fmt [IN] the format of current log
355 * @param ... [IN] the value of current log355 * @param ... [IN] the value of current log
356+ *
357+ * @attention The formatted log string is limited to 1024 bytes (including the terminating null
358+ * character). Content exceeding this limit will be truncated (with a trailing
359+ * "...[truncated]" mark) rather than discarded.
356 */360 */
357ACL_FUNC_VISIBILITY void aclAppLog(aclLogLevel logLevel, const char *func, const char *file, uint32_t line,361ACL_FUNC_VISIBILITY void aclAppLog(aclLogLevel logLevel, const char *func, const char *file, uint32_t line,
358 const char *fmt, ...);362 const char *fmt, ...);
Msrc/acl/aclrt_impl/log.cpp+30-13
@@ -13,6 +13,18 @@
13#include "acl_rt_impl.h"13#include "acl_rt_impl.h"
14#include "common/log_inner.h"14#include "common/log_inner.h"
15 15 
16+namespace {
17+constexpr const char_t *const TRUNCATED_MARK = "...[truncated]";
18+constexpr size_t TRUNCATED_MARK_LEN = 14U; // strlen("...[truncated]")
19+ 
20+// 在缓冲区尾部覆盖写入截断标记，标记连同结尾 '\0' 仍落在 MAX_LOG_STRING 预算内，避免被下游二次截断。
21+void AppendTruncatedMark(char_t *const buf)
22+{
23+ (void)strcpy_s(&buf[acl::MAX_LOG_STRING - 1U - TRUNCATED_MARK_LEN],
24+ TRUNCATED_MARK_LEN + 1U, TRUNCATED_MARK);
25+}
26+} // namespace
27+ 
16#ifdef __cplusplus28#ifdef __cplusplus
17extern "C" {29extern "C" {
18#endif30#endif
@@ -25,21 +37,26 @@ void aclAppLogImpl(aclLogLevel logLevel, const char *func, const char *file, uin
25 if (!acl::AclLog::IsLogOutputEnable(logLevel)) {37 if (!acl::AclLog::IsLogOutputEnable(logLevel)) {
26 return;38 return;
27 }39 }
40+ // 使用 vsnprintf_truncated_s / snprintf_truncated_s 而非 vsnprintf_s / sprintf_s：
41+ // 后者在内容超长时返回 -1 并丢弃整条日志，前者会截断保留内容（截断时返回 MAX_LOG_STRING - 1）。
28 char_t str[acl::MAX_LOG_STRING] = {};42 char_t str[acl::MAX_LOG_STRING] = {};
29- int32_t printRet = vsnprintf_s(str, static_cast<size_t>(acl::MAX_LOG_STRING),43+ const int32_t bodyRet = vsnprintf_truncated_s(str, static_cast<size_t>(acl::MAX_LOG_STRING), fmt, args);
30- static_cast<size_t>(acl::MAX_LOG_STRING - 1U), fmt, args);44+ if (bodyRet == -1) {
31- if (printRet != -1) {45+ // 仅在格式化字符串非法（如包含 %n）时进入此分支，给出准确提示。
32- char_t strLog[acl::MAX_LOG_STRING] = {};46+ acl::AclLog::ACLSaveLog(ACL_ERROR, "aclAppLog format string is invalid");
33- printRet = sprintf_s(strLog, static_cast<size_t>(acl::MAX_LOG_STRING), "%d %s:%s:%u: \"%s\"",47+ return;
34- acl::AclLog::GetTid(), func, file, line, str);
35- if (printRet != -1) {
36- acl::AclLog::ACLSaveLog(logLevel, strLog);
37- } else {
38- acl::AclLog::ACLSaveLog(ACL_ERROR, "aclAppLog call sprintf_s failed");
39- }
40- } else {
41- acl::AclLog::ACLSaveLog(ACL_ERROR, "aclAppLog call vsnprintf_s failed");
42 }48 }
49+ 
50+ char_t strLog[acl::MAX_LOG_STRING] = {};
51+ const int32_t headRet = snprintf_truncated_s(strLog, static_cast<size_t>(acl::MAX_LOG_STRING),
52+ "%d %s:%s:%u: \"%s\"", acl::AclLog::GetTid(), func, file, line, str);
53+ 
54+ // 正文或头部拼接发生截断时，在最终串尾部补写截断标记，提示用户内容不完整。
55+ if ((bodyRet >= static_cast<int32_t>(acl::MAX_LOG_STRING - 1U)) ||
56+ (headRet >= static_cast<int32_t>(acl::MAX_LOG_STRING - 1U))) {
57+ AppendTruncatedMark(strLog);
58+ }
59+ acl::AclLog::ACLSaveLog(logLevel, strLog);
43 return;60 return;
44}61}
45#ifdef __cplusplus62#ifdef __cplusplus
Atests/depends/slog/inc/slog_stub_log_capture.h+18-0
@@ -0,0 +1,18 @@
1+/**
2+ * Copyright (c) 2025 Huawei Technologies Co., Ltd.
3+ * This program is free software, you can redistribute it and/or modify it under the terms and conditions of
4+ * CANN Open Software License Agreement Version 2.0 (the "License").
5+ * Please refer to the License for details. You may not use this file except in compliance with the License.
6+ * THIS SOFTWARE IS PROVIDED ON AN "AS IS" BASIS, WITHOUT WARRANTIES OF ANY KIND, EITHER EXPRESS OR IMPLIED,
7+ * INCLUDING BUT NOT LIMITED TO NON-INFRINGEMENT, MERCHANTABILITY, OR FITNESS FOR A PARTICULAR PURPOSE.
8+ * See LICENSE in the root of the software repository for the full text of the License.
9+ */
10+ 
11+#ifndef TESTS_DEPENDS_SLOG_STUB_LOG_CAPTURE_H_
12+#define TESTS_DEPENDS_SLOG_STUB_LOG_CAPTURE_H_
13+ 
14+// slog stub 捕获最近一次 DlogRecord 落盘的日志内容，供单测断言使用。
15+// 通过头文件声明的函数接口访问，避免在测试源文件中以 extern 声明引用外部变量（G.EXP.05-CPP）。
16+const char *DlogStubGetLastLogMsg();
17+ 
18+#endif // TESTS_DEPENDS_SLOG_STUB_LOG_CAPTURE_H_
Mtests/depends/slog/src/slog_stub.cpp+20-2
@@ -14,21 +14,39 @@
14#include <stdarg.h>14#include <stdarg.h>
15#include <stdio.h>15#include <stdio.h>
16#include <string.h>16#include <string.h>
17+#include <securec.h>
17#include "acl_stub.h"18#include "acl_stub.h"
19+#include "slog/inc/slog_stub_log_capture.h"
18 20 
19void dlog_init(){}21void dlog_init(){}
20 22 
21-int aclStub::dlog_getlevel(int module_id, int *enable_event){ 23+int aclStub::dlog_getlevel(int module_id, int *enable_event){
22 return DLOG_DEBUG;24 return DLOG_DEBUG;
23}25}
24 26 
25-int dlog_getlevel(int module_id, int *enable_event){ 27+int dlog_getlevel(int module_id, int *enable_event){
26 return MockFunctionTest::aclStubInstance().dlog_getlevel(module_id, enable_event);28 return MockFunctionTest::aclStubInstance().dlog_getlevel(module_id, enable_event);
27}29}
28 30 
31+namespace {
32+constexpr int LOG_MSG_MAX = 4096;
33+char g_lastLogMsg[LOG_MSG_MAX] = {0};
34+}
35+ 
29int g_logLevel = DLOG_ERROR;36int g_logLevel = DLOG_ERROR;
30void DlogRecord(int moduleId, int level, const char *fmt, ...) {37void DlogRecord(int moduleId, int level, const char *fmt, ...) {
31 g_logLevel = level;38 g_logLevel = level;
39+ va_list args;
40+ va_start(args, fmt);
41+ int ret = vsnprintf_s(g_lastLogMsg, sizeof(g_lastLogMsg), sizeof(g_lastLogMsg) - 1U, fmt, args);
42+ va_end(args);
43+ if (ret < 0) {
44+ g_lastLogMsg[0] = '\0';
45+ }
46+}
47+ 
48+const char *DlogStubGetLastLogMsg() {
49+ return g_lastLogMsg;
32}50}
33 51 
34void DlogErrorInner(int module_id, const char *fmt, ...){}52void DlogErrorInner(int module_id, const char *fmt, ...){}
Mtests/ut/acl/testcase/acl_common_unittest.cpp+51-2
@@ -34,6 +34,7 @@
34#include "runtime/config.h"34#include "runtime/config.h"
35#include "utils/file_utils.h"35#include "utils/file_utils.h"
36#include "acl_stub.h"36#include "acl_stub.h"
37+#include "slog/inc/slog_stub_log_capture.h"
37#include "utils/hash_utils.h"38#include "utils/hash_utils.h"
38 39 
39#include "base/err_mgr.h"40#include "base/err_mgr.h"
@@ -2708,7 +2709,7 @@ TEST_F(UTEST_ACL_Common, aclAppLog_succ)
2708 EXPECT_TRUE(g_logLevel == ACL_ERROR);2709 EXPECT_TRUE(g_logLevel == ACL_ERROR);
2709}2710}
2710 2711 
2711-TEST_F(UTEST_ACL_Common, aclAppLog_failed_1000bytes)2712+TEST_F(UTEST_ACL_Common, aclAppLog_truncate_1000bytes)
2712{2713{
2713 aclLogLevel level = ACL_ERROR;2714 aclLogLevel level = ACL_ERROR;
2714 const char *func = "UserFunc";2715 const char *func = "UserFunc";
@@ -2726,10 +2727,11 @@ TEST_F(UTEST_ACL_Common, aclAppLog_failed_1000bytes)
2726 "0123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789"2727 "0123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789"
2727 "0123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789";2728 "0123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789";
2728 aclAppLog(level, func, file, line, fmt);2729 aclAppLog(level, func, file, line, fmt);
2730+ // 超长日志被截断后仍按原 level 落盘，不再被强制成 ERROR 误报。
2729 EXPECT_TRUE(g_logLevel == ACL_ERROR);2731 EXPECT_TRUE(g_logLevel == ACL_ERROR);
2730}2732}
2731 2733 
2732-TEST_F(UTEST_ACL_Common, aclAppLog_failed_1100bytes)2734+TEST_F(UTEST_ACL_Common, aclAppLog_truncate_1100bytes)
2733{2735{
2734 aclLogLevel level = ACL_ERROR;2736 aclLogLevel level = ACL_ERROR;
2735 const char *func = "UserFunc";2737 const char *func = "UserFunc";
@@ -2748,7 +2750,54 @@ TEST_F(UTEST_ACL_Common, aclAppLog_failed_1100bytes)
2748 "0123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789"2750 "0123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789"
2749 "0123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789";2751 "0123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456789";
2750 aclAppLog(level, func, file, line, fmt);2752 aclAppLog(level, func, file, line, fmt);
2753+ // 超长日志被截断后仍按原 level 落盘，不再被丢弃或误报。
2751 EXPECT_TRUE(g_logLevel == ACL_ERROR);2754 EXPECT_TRUE(g_logLevel == ACL_ERROR);
2755+ // 超长日志被截断后尾部应追加截断标记，提示用户内容不完整。
2756+ EXPECT_TRUE(strstr(DlogStubGetLastLogMsg(), "...[truncated]") != nullptr);
2757+}
2758+ 
2759+TEST_F(UTEST_ACL_Common, aclAppLog_truncate_keep_level)
2760+{
2761+ // 验证超长日志被截断后仍按调用级别输出，不会被强制成 ACL_ERROR。
2762+ aclLogLevel level = ACL_INFO;
2763+ const char *func = "UserFunc";
2764+ const char *file = "main.cpp";
2765+ uint32_t line = 88U;
2766+ const std::string fmt(1100U, 'a');
2767+ aclAppLog(level, func, file, line, fmt.c_str());
2768+ EXPECT_TRUE(g_logLevel == ACL_INFO);
2769+ // 截断标记应落在 MAX_LOG_STRING 预算内，最终落盘的日志总长不超过 1024 字节。
2770+ EXPECT_TRUE(strstr(DlogStubGetLastLogMsg(), "...[truncated]") != nullptr);
2771+ EXPECT_TRUE(strlen(DlogStubGetLastLogMsg()) < 1024U);
2772+}
2773+ 
2774+TEST_F(UTEST_ACL_Common, aclAppLog_short_keep_level)
2775+{
2776+ // 正常短日志按调用级别输出，且不追加截断标记。
2777+ aclLogLevel level = ACL_INFO;
2778+ const char *func = "UserFunc";
2779+ const char *file = "main.cpp";
2780+ uint32_t line = 88U;
2781+ aclAppLog(level, func, file, line, "short message");
2782+ EXPECT_TRUE(g_logLevel == ACL_INFO);
2783+ EXPECT_TRUE(strstr(DlogStubGetLastLogMsg(), "...[truncated]") == nullptr);
2784+}
2785+ 
2786+TEST_F(UTEST_ACL_Common, aclAppLog_invalid_format)
2787+{
2788+ // 非法格式化字符串（含 %n，安全函数会拒绝并返回 -1）应输出准确的错误提示。
2789+ // 运行时构造格式串，避免触发编译期 -Wformat 告警。
2790+ aclLogLevel level = ACL_ERROR;
2791+ const char *func = "UserFunc";
2792+ const char *file = "main.cpp";
2793+ uint32_t line = 88U;
2794+ char fmt[8] = {};
2795+ fmt[0] = '%';
2796+ fmt[1] = 'n';
2797+ int dummy = 0;
2798+ aclAppLog(level, func, file, line, fmt, &dummy);
2799+ EXPECT_TRUE(g_logLevel == ACL_ERROR);
2800+ EXPECT_TRUE(strstr(DlogStubGetLastLogMsg(), "format string is invalid") != nullptr);
2752}2801}
2753 2802 
2754TEST_F(UTEST_ACL_Common, FormatStr_failed_1100bytes)2803TEST_F(UTEST_ACL_Common, FormatStr_failed_1100bytes)