9 Unstar Star 13 Fork 4

OpenHarmony / hiviewdfx_frameworks_hilog_lite

日志模块是有速度限制的!

任务
已完成
Siwei Xu  Opened this issue

该问题是怎么引起的?

使用 hilog_lite 模块的的接口打印日志,你发现一段时间后少了一些日志!

【原因分析】文件base\hiviewdfx\frameworks\hilog_lite\mini\hiview_log.c 中:

void HiLogPrintf(uint8 module, uint8 level, const char *nums, const char *fmt, ...)
{
    static char newFmt[] = "The number of parameters is invalid.";
    HiLogContent logContent = { 0 };
    int32 argsNum = (nums - FUN_ARG_S);
    if (argsNum < 0 || argsNum > LOG_MULTI_PARA_MAX) {
        fmt = newFmt;
        argsNum = 0;
    }

    if (g_hiviewConfig.logSwitch == HIVIEW_FEATURE_OFF || !CheckParameters(module, level) ||
        LogIsLimited(module) || !LOG_IS_OUTPUT(module)) {
        // 这里限制了Log速度
        return;
    }

    HiLogCommon *pCommon = &(logContent.commonContent);
    pCommon->head = LOG_INFO_HEAD;
    pCommon->module = module;
    pCommon->level = level;
    pCommon->fmt = fmt;
    pCommon->valueNumber = (uint8)argsNum;
    pCommon->task = (uint8)HIVIEW_GetTaskId();
    pCommon->time = (uint32)(HIVIEW_GetCurrentTime() / MS_PER_SECOND);

    uint8 i = 0;
    va_list args;
    va_start(args, fmt);
    while (i < argsNum) {
        logContent.values[i++] = va_arg(args, uint32);
    }
    va_end(args);

    OutputLog((uint8 *)&logContent, sizeof(HiLogCommon) + sizeof(uint32) * argsNum);
}

具体限额:

#define LOG_LIMIT_CHECK_DURATION   60   /* seconds */
#define LOG_LIMIT_LEVEL1           6    /* Maximum number of log records in a check period. */
#define LOG_LIMIT_LEVEL2           30
#define LOG_LIMIT_LEVEL3           60
#define LOG_LIMIT_LEVEL4           120
#define LOG_LIMIT_DEFAULT          LOG_LIMIT_LEVEL2

void InitLogLimit(void)
{
    ...
    
    ...
    SetLimitThreshold(HILOG_MODULE_HIVIEW, LOG_LIMIT_LEVEL3);
    SetLimitThreshold(HILOG_MODULE_APP, LOG_LIMIT_LEVEL2);
    HILOG_DEBUG(HILOG_MODULE_HIVIEW, "log limit init success.");
}

重现步骤

复现代码:

#include <stdio.h>
#include <unistd.h>
#include <string.h>

#include "ohos_init.h"
#include "cmsis_os2.h"
#include "wifiiot_gpio.h"
#include "wifiiot_gpio_ex.h"

#include "wifiiot_uart.h"
#include "wifiiot_watchdog.h"
#include "log.h"

#define UI_TASK_STACK_SIZE 10240
#define UI_TASK_PRIO 25

static char text[128];

static void DemoTask(void* arg)
{
    (void) arg;
    int lightState = 0;

    while (1) {
        uint32_t kernelTicks = osKernelGetTickCount();
        uint32_t systemTicks = osKernelGetSysTimerCount();

        lightState = !lightState;
        GpioSetOutputVal(WIFI_IOT_IO_NAME_GPIO_9, lightState);

        // use hilog
        HILOG_INFO(HILOG_MODULE_APP, "ticks: %u, %u", kernelTicks, systemTicks);

        // use stdio
        printf("puts| ticks: %u, %u\r\n", kernelTicks, systemTicks);

        // use UART write
        snprintf(text, sizeof(text), "UART| ticks: %u, %u\r\n", kernelTicks, systemTicks);
        UartWrite(WIFI_IOT_UART_IDX_0, (const unsigned char *)text, strlen(text));
        usleep(300*1000);
    }
}

static void StartDemoTask(void)
{
    GpioInit();
    IoSetFunc(WIFI_IOT_IO_NAME_GPIO_9, WIFI_IOT_IO_FUNC_GPIO_9_GPIO);
    GpioSetDir(WIFI_IOT_IO_NAME_GPIO_9, WIFI_IOT_GPIO_DIR_OUT);

    WatchDogDisable();

    osThreadAttr_t attr;
    attr.name = "DemoTask";
    attr.attr_bits = 0U;
    attr.cb_mem = NULL;
    attr.cb_size = 0U;
    attr.stack_mem = NULL;
    attr.stack_size = UI_TASK_STACK_SIZE;
    attr.priority = UI_TASK_PRIO;
    if (osThreadNew(DemoTask, NULL, &attr) == NULL) {
        printf("[StartDemoTask] Falied to create task for DemoTask!\n");
    }
}

APP_FEATURE_INIT(StartDemoTask);

报错信息

ready to OS start
sdk ver:Hi3861V100R001C00SPC025 2020-09-03 18:10:00
formatting spiffs...
FileSystem mount ok.
wifi init success!

puts| ticks: 35, 57398720
UART| ticks: 35, 57398720
00 00:00:00 0 68 D 0/HIVIEW: hilog init success.
00 00:00:00 0 68 D 0/HIVIEW: log limit init success.
00 00:00:00 0 68 I 1/SAMGR: Bootstrap core services(count:3).
00 00:00:00 0 68 I 1/SAMGR: Init service:0x4aebdc TaskPool:0xfa2a4
00 00:00:00 0 68 I 1/SAMGR: Init service:0x4aec00 TaskPool:0xfa914
00 00:00:00 0 68 I 1/SAMGR: Init service:0x4aed10 TaskPool:0xfaad4
00 00:00:00 0 100 I 1/SAMGR: Init service 0x4aec00 <time: 0ms> success!
00 00:00:00 0 0 I 1/SAMGR: Init service 0x4aebdc <time: 0ms> success!
00 00:00:00 0 200 D 0/HIVIEW: hiview init success.
00 00:00:00 0 200 I 1/SAMGR: Init service 0x4aed10 <time: 0ms> success!
00 00:00:00 0 200 I 1/SAMGR: Initialized all core system services!
00 00:00:00 0 0 I 1/SAMGR: Bootstrap system and application services(count:0).
00 00:00:00 0 0 I 1/SAMGR: Initialized all system and application services!
00 00:00:00 0 0 I 1/SAMGR: Bootstrap dynamic registered services(count:0).
00 00:00:00 0 68 I 4/APP: ticks: 35, 57398720
puts| ticks: 65, 104011520
UART| ticks: 65, 104011520
puts| ticks: 95, 152009440
UART| ticks: 95, 152009440
puts| ticks: 125, 200009120
UART| ticks: 125, 200009120
puts| ticks: 155, 248009600
UART| ticks: 155, 248009600
puts| ticks: 185, 296017920
UART| ticks: 185, 296017920
puts| ticks: 215, 344009280
UART| ticks: 215, 344009280
puts| ticks: 245, 392009920
UART| ticks: 245, 392009920
00 00:00:00 0 68 I 4/APP: ticks: 65, 104011520
00 00:00:00 0 68 I 4/APP: ticks: 95, 152009440
00 00:00:00 0 68 I 4/APP: ticks: 125, 200009120
00 00:00:00 0 68 I 4/APP: ticks: 155, 248009600
00 00:00:00 0 68 I 4/APP: ticks: 185, 296017920
00 00:00:00 0 68 I 4/APP: ticks: 215, 344009280
00 00:00:00 0 68 I 4/APP: ticks: 245, 392009920
puts| ticks: 275, 440009760
UART| ticks: 275, 440009760
puts| ticks: 305, 488009440
UART| ticks: 305, 488009440
puts| ticks: 335, 536031040
UART| ticks: 335, 536031040
puts| ticks: 365, 584009280
UART| ticks: 365, 584009280
puts| ticks: 395, 632009120
UART| ticks: 395, 632009120
puts| ticks: 425, 680009280
UART| ticks: 425, 680009280
puts| ticks: 455, 728009760
UART| ticks: 455, 728009760
00 00:00:00 0 68 I 4/APP: ticks: 275, 440009760
00 00:00:00 0 68 I 4/APP: ticks: 305, 488009440
00 00:00:00 0 68 I 4/APP: ticks: 335, 536031040
00 00:00:00 0 68 I 4/APP: ticks: 365, 584009280
00 00:00:00 0 68 I 4/APP: ticks: 395, 632009120
00 00:00:00 0 68 I 4/APP: ticks: 425, 680009280
00 00:00:00 0 68 I 4/APP: ticks: 455, 728009760
puts| ticks: 485, 776018240
UART| ticks: 485, 776018240
puts| ticks: 515, 824009600
UART| ticks: 515, 824009600
puts| ticks: 545, 872009440
UART| ticks: 545, 872009440
puts| ticks: 575, 920009440
UART| ticks: 575, 920009440
puts| ticks: 605, 968009600
UART| ticks: 605, 968009600
puts| ticks: 635, 1016037120
UART| ticks: 635, 1016037120
puts| ticks: 665, 1064009280
UART| ticks: 665, 1064009280
00 00:00:00 0 68 I 4/APP: ticks: 485, 776018240
00 00:00:00 0 68 I 4/APP: ticks: 515, 824009600
00 00:00:00 0 68 I 4/APP: ticks: 545, 872009440
00 00:00:00 0 68 I 4/APP: ticks: 575, 920009440
00 00:00:00 0 68 I 4/APP: ticks: 605, 968009600
00 00:00:00 0 68 I 4/APP: ticks: 635, 1016037120
00 00:00:00 0 68 I 4/APP: ticks: 665, 1064009280
puts| ticks: 695, 1112009600
UART| ticks: 695, 1112009600
puts| ticks: 725, 1160009280
UART| ticks: 725, 1160009280
puts| ticks: 755, 1208009440
UART| ticks: 755, 1208009440
puts| ticks: 785, 1256017280
UART| ticks: 785, 1256017280
puts| ticks: 815, 1304009280
UART| ticks: 815, 1304009280
puts| ticks: 845, 1352009920
UART| ticks: 845, 1352009920
puts| ticks: 875, 1400009600
UART| ticks: 875, 1400009600
00 00:00:00 0 68 I 4/APP: ticks: 695, 1112009600
00 00:00:00 0 68 I 4/APP: ticks: 725, 1160009280
00 00:00:00 0 68 I 4/APP: ticks: 755, 1208009440
00 00:00:00 0 68 I 4/APP: ticks: 785, 1256017280
00 00:00:00 0 68 I 4/APP: ticks: 815, 1304009280
00 00:00:00 0 68 I 4/APP: ticks: 845, 1352009920
00 00:00:00 0 68 I 4/APP: ticks: 875, 1400009600
puts| ticks: 905, 1448009440
UART| ticks: 905, 1448009440
puts| ticks: 935, 1496031200
UART| ticks: 935, 1496031200
puts| ticks: 965, 1544009440
UART| ticks: 965, 1544009440
puts| ticks: 995, 1592009280
UART| ticks: 995, 1592009280
puts| ticks: 1025, 1640009600
UART| ticks: 1025, 1640009600
puts| ticks: 1055, 1688009920
UART| ticks: 1055, 1688009920
puts| ticks: 1085, 1736017440
UART| ticks: 1085, 1736017440
puts| ticks: 1115, 1784009280
UART| ticks: 1115, 1784009280
puts| ticks: 1145, 1832009280
UART| ticks: 1145, 1832009280
puts| ticks: 1175, 1880009280
UART| ticks: 1175, 1880009280
puts| ticks: 1205, 1928009280
UART| ticks: 1205, 1928009280
puts| ticks: 1235, 1976036320
UART| ticks: 1235, 1976036320
puts| ticks: 1265, 2024009120
UART| ticks: 1265, 2024009120
puts| ticks: 1295, 2072009280
UART| ticks: 1295, 2072009280
puts| ticks: 1325, 2120009120
UART| ticks: 1325, 2120009120
puts| ticks: 1355, 2168009600
UART| ticks: 1355, 2168009600
puts| ticks: 1385, 2216016960
UART| ticks: 1385, 2216016960
puts| ticks: 1415, 2264009440
UART| ticks: 1415, 2264009440
puts| ticks: 1445, 2312009920
UART| ticks: 1445, 2312009920
puts| ticks: 1475, 2360009440
UART| ticks: 1475, 2360009440
puts| ticks: 1505, 2408009120
UART| ticks: 1505, 2408009120
puts| ticks: 1535, 2456029920
UART| ticks: 1535, 2456029920
puts| ticks: 1565, 2504009280
UART| ticks: 1565, 2504009280
puts| ticks: 1595, 2552009280
UART| ticks: 1595, 2552009280
puts| ticks: 1625, 2600009280
UART| ticks: 1625, 2600009280
puts| ticks: 1655, 2648009760
UART| ticks: 1655, 2648009760
puts| ticks: 1685, 2696017440
UART| ticks: 1685, 2696017440
puts| ticks: 1715, 2744009280
UART| ticks: 1715, 2744009280
puts| ticks: 1745, 2792009120
UART| ticks: 1745, 2792009120
puts| ticks: 1775, 2840009280
UART| ticks: 1775, 2840009280
puts| ticks: 1805, 2888009120
UART| ticks: 1805, 2888009120
puts| ticks: 1835, 2936035200
UART| ticks: 1835, 2936035200
puts| ticks: 1865, 2984009120
UART| ticks: 1865, 2984009120
puts| ticks: 1895, 3032009120
UART| ticks: 1895, 3032009120
puts| ticks: 1925, 3080009440
UART| ticks: 1925, 3080009440
puts| ticks: 1955, 3128009280
UART| ticks: 1955, 3128009280
puts| ticks: 1985, 3176017440
UART| ticks: 1985, 3176017440
puts| ticks: 2015, 3224009440
UART| ticks: 2015, 3224009440
puts| ticks: 2045, 3272009760
UART| ticks: 2045, 3272009760
puts| ticks: 2075, 3320009280
UART| ticks: 2075, 3320009280
puts| ticks: 2105, 3368009280
UART| ticks: 2105, 3368009280
puts| ticks: 2135, 3416030080
UART| ticks: 2135, 3416030080
puts| ticks: 2165, 3464009280
UART| ticks: 2165, 3464009280
puts| ticks: 2195, 3512009280
UART| ticks: 2195, 3512009280
puts| ticks: 2225, 3560009280
UART| ticks: 2225, 3560009280
puts| ticks: 2255, 3608009600
UART| ticks: 2255, 3608009600
Attachments
5200794 stesen 1599180294 19406 swxu 1602213630 total 2 participants

Comments (1)

5200794 stesen 1599180294
stesen 2020-09-24 19:57 member

是的,此处会主动丢弃日志。日志缓冲区满也会导致旧日志被丢弃。

Sign in to comment

Assignees
Labels
Not set
Projects
Milestones
Branches
Planed to start
Not set
Planed to end
Not set
Top level
Priority
1
https://git.oschina.net/openharmony/hiviewdfx_frameworks_hilog_lite.git
git@git.oschina.net:openharmony/hiviewdfx_frameworks_hilog_lite.git
openharmony
hiviewdfx_frameworks_hilog_lite
hiviewdfx_frameworks_hilog_lite

Search

132457 8cb2edc1 1899542 131848 70c8d3a4 1899542