rt-thread icon indicating copy to clipboard operation
rt-thread copied to clipboard

Published 20 hours ago • verified publisher icon RT-Thread

[重新报告]启用ulog , CmBacktrace,出现错误时,不断重复打印 ps 内容,和 `[rt_sem_take]: scheduler is not available`

Open dongly opened this issue 3 years ago • 6 comments
trafficstars

从上次报告后,一直未解决,且issue已经关闭,故重新报告 Originally posted by @dongly in https://github.com/RT-Thread/rt-thread/issues/5584#issuecomment-1037948249

  • 出现断言时,不断重复打印 ps 内容,和 [rt_sem_take]: scheduler is not available
  • 重现步骤:
    • 版本 rt-thread v4.1.1
    • 启用ulog , CmBacktrace lastest
    • 测试BSP stm32l475-atk-pandora
    • 编译器 GCC v10.2.1
    • 终端运行命令:
msh >cmb_test DIVBYZERO
  • .config
CONFIG_RT_NAME_MAX=8
CONFIG_RT_ALIGN_SIZE=4
CONFIG_RT_THREAD_PRIORITY_32=y
CONFIG_RT_THREAD_PRIORITY_MAX=32
CONFIG_RT_TICK_PER_SECOND=1000
CONFIG_RT_USING_OVERFLOW_CHECK=y
CONFIG_RT_USING_HOOK=y
CONFIG_RT_HOOK_USING_FUNC_PTR=y
CONFIG_RT_USING_IDLE_HOOK=y
CONFIG_RT_IDLE_HOOK_LIST_SIZE=4
CONFIG_IDLE_THREAD_STACK_SIZE=256
CONFIG_RT_USING_TIMER_SOFT=y
CONFIG_RT_TIMER_THREAD_PRIO=4
CONFIG_RT_TIMER_THREAD_STACK_SIZE=512
CONFIG_RT_KSERVICE_USING_STDLIB=y
CONFIG_RT_DEBUG=y
CONFIG_RT_DEBUG_COLOR=y
CONFIG_RT_USING_SEMAPHORE=y
CONFIG_RT_USING_MUTEX=y
CONFIG_RT_USING_EVENT=y
CONFIG_RT_USING_MAILBOX=y
CONFIG_RT_USING_MESSAGEQUEUE=y
CONFIG_RT_USING_MEMPOOL=y
CONFIG_RT_USING_SMALL_MEM=y
CONFIG_RT_USING_SMALL_MEM_AS_HEAP=y
CONFIG_RT_USING_HEAP=y
CONFIG_RT_USING_DEVICE=y
CONFIG_RT_USING_CONSOLE=y
CONFIG_RT_CONSOLEBUF_SIZE=256
CONFIG_RT_CONSOLE_DEVICE_NAME="uart1"
CONFIG_RT_VER_NUM=0x40101
CONFIG_ARCH_ARM=y
CONFIG_RT_USING_CPU_FFS=y
CONFIG_ARCH_ARM_CORTEX_M=y
CONFIG_ARCH_ARM_CORTEX_M4=y
CONFIG_RT_USING_COMPONENTS_INIT=y
CONFIG_RT_USING_USER_MAIN=y
CONFIG_RT_MAIN_THREAD_STACK_SIZE=2048
CONFIG_RT_MAIN_THREAD_PRIORITY=10
CONFIG_RT_USING_MSH=y
CONFIG_RT_USING_FINSH=y
CONFIG_FINSH_USING_MSH=y
CONFIG_FINSH_THREAD_NAME="tshell"
CONFIG_FINSH_THREAD_PRIORITY=20
CONFIG_FINSH_THREAD_STACK_SIZE=4096
CONFIG_FINSH_USING_HISTORY=y
CONFIG_FINSH_HISTORY_LINES=5
CONFIG_FINSH_USING_SYMTAB=y
CONFIG_FINSH_CMD_SIZE=80
CONFIG_MSH_USING_BUILT_IN_COMMANDS=y
CONFIG_FINSH_USING_DESCRIPTION=y
CONFIG_FINSH_ARG_MAX=10
CONFIG_RT_USING_DFS=y
CONFIG_DFS_USING_POSIX=y
CONFIG_DFS_USING_WORKDIR=y
CONFIG_DFS_FILESYSTEMS_MAX=4
CONFIG_DFS_FILESYSTEM_TYPES_MAX=4
CONFIG_DFS_FD_MAX=16
CONFIG_RT_USING_DEVICE_IPC=y
CONFIG_RT_USING_SYSTEM_WORKQUEUE=y
CONFIG_RT_SYSTEM_WORKQUEUE_STACKSIZE=2048
CONFIG_RT_SYSTEM_WORKQUEUE_PRIORITY=23
CONFIG_RT_USING_SERIAL=y
CONFIG_RT_USING_SERIAL_V1=y
CONFIG_RT_SERIAL_USING_DMA=y
CONFIG_RT_SERIAL_RB_BUFSZ=64
CONFIG_RT_USING_PIN=y
CONFIG_RT_LIBC_DEFAULT_TIMEZONE=8
CONFIG_RT_USING_ULOG=y
CONFIG_ULOG_OUTPUT_LVL_D=y
CONFIG_ULOG_OUTPUT_LVL=7
CONFIG_ULOG_ASSERT_ENABLE=y
CONFIG_ULOG_LINE_BUF_SIZE=128
CONFIG_ULOG_USING_COLOR=y
CONFIG_ULOG_OUTPUT_TIME=y
CONFIG_ULOG_OUTPUT_LEVEL=y
CONFIG_ULOG_OUTPUT_TAG=y
CONFIG_ULOG_BACKEND_USING_CONSOLE=y
CONFIG_PKG_USING_CMBACKTRACE=y
CONFIG_PKG_CMBACKTRACE_PLATFORM_M4=y
CONFIG_PKG_CMBACKTRACE_DUMP_STACK=y
CONFIG_PKG_CMBACKTRACE_PRINT_ENGLISH=y
CONFIG_PKG_CMBACKTRACE_PATH="/packages/tools/CmBacktrace"
CONFIG_PKG_USING_CMBACKTRACE_LATEST_VERSION=y
CONFIG_PKG_CMBACKTRACE_VER="latest"
CONFIG_PKG_CMBACKTRACE_VER_NUM=0x99999
CONFIG_SOC_FAMILY_STM32=y
CONFIG_SOC_SERIES_STM32L4=y
CONFIG_SOC_STM32L475VE=y
CONFIG_BOARD_STM32L475_ATK_PANDORA=y
CONFIG_BSP_USING_STLINK_TO_USART=y
CONFIG_BSP_USING_GPIO=y
CONFIG_BSP_USING_UART=y
CONFIG_BSP_USING_UART1=y
  • 错误信息
msh />cmb_test DIVBYZERO
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
tshell    20  running 0x000000c8 0x00001000    06%   0x00000007 OK
sys work  23  suspend 0x00000084 0x00000800    06%   0x0000000a OK
tidle0    31  ready   0x0000005c 0x00000100    54%   0x00000012 OK
timer      4  suspend 0x0000007c 0x00000200    24%   0x00000009 OK
main      10  suspend 0x000000b0 0x00000800    15%   0x00000014 OK
Function[rt_mutex_take]: scheduler is not available
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
tshell    20  running 0x000000c8 0x00001000    06%   0x00000007 OK
sys work  23  suspend 0x00000084 0x00000800    06%   0x0000000a OK
tidle0    31  ready   0x0000005c 0x00000100    54%   0x00000012 OK
timer      4  suspend 0x0000007c 0x00000200    24%   0x00000009 OK
main      10  suspend 0x000000b0 0x00000800    15%   0x00000014 OK
Function[rt_mutex_take]: scheduler is not available
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
tshell    20  running 0x000000c8 0x00001000    06%   0x00000007 OK
sys work  23  suspend 0x00000084 0x00000800    06%   0x0000000a OK
tidle0    31  ready   0x0000005c 0x00000100    54%   0x00000012 OK
timer      4  suspend 0x0000007c 0x00000200    24%   0x00000009 OK
main      10  suspend 0x000000b0 0x00000800    15%   0x00000014 OK
Function[rt_mutex_take]: scheduler is not available
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
tshell    20  running 0x000000c8 0x00001000    06%   0x00000007 OK
sys work  23  suspend 0x00000084 0x00000800    06%   0x0000000a OK
tidle0    31  ready   0x0000005c 0x00000100    54%   0x00000012 OK
timer      4  suspend 0x0000007c 0x00000200    24%   0x00000009 OK
main      10  suspend 0x000000b0 0x00000800    15%   0x00000014 OK
Function[rt_mutex_take]: scheduler is not available
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
tshell    20  running 0x000000c8 0x00001000    06%   0x00000007 OK
sys work  23  suspend 0x00000084 0x00000800    06%   0x0000000a OK
tidle0    31  ready   0x0000005c 0x00000100    54%   0x00000012 OK
timer      4  suspend 0x0000007c 0x00000200    24%   0x00000009 OK
main      10  suspend 0x000000b0 0x00000800    15%   0x00000014 OK
Function[rt_mutex_take]: scheduler is not available
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
tshell    20  running 0x000000c8 0x00001000    06%   0x00000007 OK
sys work  23  suspend 0x00000084 0x00000800    06%   0x0000000a OK
tidle0    31  ready   0x0000005c 0x00000100    54%   0x00000012 OK
timer      4  suspend 0x0000007c 0x00000200    24%   0x00000009 OK
main      10  suspend 0x000000b0 0x00000800    15%   0x00000014 OK
Function[rt_mutex_take]: scheduler is not available
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
tshell    20  running 0x000000c8 0x00001000    06%   0x00000007 OK
sys work  23  suspend 0x00000084 0x00000800    06%   0x0000000a OK
tidle0    31  ready   0x0000005c 0x00000100    54%   0x00000012 OK
timer      4  suspend 0x0000007c 0x00000200    24%   0x00000009 OK
main      10  suspend 0x000000b0 0x00000800    15%   0x00000014 OK
Function[rt_mutex_take]: scheduler is not available
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
tshell    20  running 0x000000c8 0x00001000    06%   0x00000007 OK
sys work  23  suspend 0x00000084 0x00000800    06%   0x0000000a OK
tidle0    31  ready   0x0000005c 0x00000100    54%   0x00000012 OK
timer      4  suspend 0x0000007c 0x00000200    24%   0x00000009 OK
main      10  suspend 0x000000b0 0x00000800    15%   0x00000014 OK
Function[rt_mutex_take]: scheduler is not available
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
tshell    20  running 0x000000c8 0x00001000    06%   0x00000007 OK
sys work  23  suspend 0x00000084 0x00000800    06%   0x0000000a OK
tidle0    31  ready   0x0000005c 0x00000100    54%   0x00000012 OK
timer      4  suspend 0x0000007c 0x00000200    24%   0x00000009 OK
main      10  suspend 0x000000b0 0x00000800    15%   0x00000014 OK
Function[rt_mutex_take]: scheduler is not available
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
tshell    20  running 0x000000c8 0x00001000    06%   0x00000007 OK
sys work  23  suspend 0x00000084 0x00000800    06%   0x0000000a OK
tidle0    31  ready   0x0000005c 0x00000100    54%   0x00000012 OK
timer      4  suspend 0x0000007c 0x00000200    24%   0x00000009 OK
main      10  suspend 0x000000b0 0x00000800    15%   0x00000014 OK
Function[rt_mutex_take]: scheduler is not available
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---

dongly avatar Aug 23 '22 02:08 dongly

怀疑与 https://github.com/armink-rtt-pkgs/CmBacktrace/issues/13 是同一个问题

dongly avatar Aug 23 '22 08:08 dongly

https://club.rt-thread.org/index.html 论坛问问看。

supperthomas avatar Aug 25 '22 14:08 supperthomas

https://club.rt-thread.org/ask/question/c17e5242cdccfa72.html

dongly avatar Oct 14 '22 00:10 dongly

ulog 有个 ulog_output_lock_enabled API ，用于开关 ulog 的日志锁，该功能就是专为异常日志设计的

可以在 rt_cm_backtrace_exception_hook 中使用该 API 关掉日志锁试试

armink avatar Oct 16 '22 04:10 armink

根据这个问题 > https://github.com/armink-rtt-pkgs/CmBacktrace/issues/13 我提了个pr > https://github.com/armink-rtt-pkgs/CmBacktrace/pull/14

wdfk-prog avatar Dec 26 '22 07:12 wdfk-prog

  • 我找到你说的那个问题的原因了

  • 是因为ulog_flush函数中有对所有ULOG文件后端进行刷新的操作

  • 如果挂载的后端操作刚好又有互斥量操作,就会发生你说的情况.(比如日志输出到文件系统中) image

  • 将文件后端取消使能或者注销掉的话,就能正常输出 image

wdfk-prog avatar Dec 26 '22 07:12 wdfk-prog

谢谢,迟点试试,最近身体不舒服

dongly avatar Dec 29 '22 07:12 dongly