[bug][v4.1.0-beta] IIC 初始化出现断言 Function[rt_sem_take] shall not be used before scheduler start #5584

dongly · 2022-02-06T14:29:10Z

重现步骤:
- 版本 rt-thread v4.1.0-beta
- 启用IIC
- 测试BSP stm32f407-atk-explorer
- 编译器 GCC v10.2.1
错误信息

Function[rt_sem_take] shall not be used before scheduler start
(0) assertion failed at function:rt_sem_take, line number:489

BUG定位
- 跟踪到出错点在
  
  rt-thread/components/drivers/i2c/i2c_core.c
  
  Line 33 in a0fadd4
  
  LOG_I("I2C bus [%s] registered", bus_name);
- 注释该行后正常

The text was updated successfully, but these errors were encountered:

dongly · 2022-02-06T14:54:31Z

分析代码,以下代码也会出错

rt-thread/bsp/at32/Libraries/rt_drivers/drv_soft_i2c.c

Line 209 in a0fadd4

LOG_D("software simulation %s init done, pin scl: %d, pin sda %d",
rt-thread/bsp/stm32/libraries/HAL_Drivers/drv_soft_i2c.c

Line 211 in a0fadd4

LOG_D("software simulation %s init done, pin scl: %d, pin sda %d",
rt-thread/bsp/gd32/libraries/gd32_drivers/drv_soft_i2c.c

Line 191 in a0fadd4

LOG_D("software simulation %s init done, pin scl: %d, pin sda %d",
其他 BSP 没看

mysterywolf · 2022-02-08T21:24:37Z

最近爆出了好多这种断言，看来内核增强安全检查是正确的
https://club.rt-thread.org/ask/question/434519.html
https://club.rt-thread.org/ask/question/434558.html
https://gitee.com/rtthread/rt-thread/issues/I4RVIU

dongly · 2022-02-09T01:25:16Z

建议开启GCC 的编译参数"-W",开启后有不少的警告,有潜在的风险.而lwIP,即使开启"-Wall",一个警告也没有

mysterywolf · 2022-02-09T02:15:32Z

#4740 (comment)

mysterywolf · 2022-02-09T02:17:22Z

#5576

mysterywolf · 2022-02-09T04:18:56Z

https://club.rt-thread.org/ask/article/3374.html

Guozhanxin · 2022-02-09T06:08:00Z

没有复现这个问题。。。

mysterywolf · 2022-02-09T06:10:54Z

@Guozhanxin 问题的关键不是iic，是mem，出出在这里已经定位到问题的原因了#4740 (comment) ， iic出现断言只不过是个表象，看上面的链接，还有LED初始化的时候出现断言的。

Guozhanxin · 2022-02-09T07:27:03Z

我发现是没开ulog的问题，所以没复现，修了一个了。#5589

thewon86 · 2022-02-10T06:51:35Z

最近爆出了好多这种断言，看来内核增强安全检查是正确的 https://club.rt-thread.org/ask/question/434519.html https://club.rt-thread.org/ask/question/434558.html https://gitee.com/rtthread/rt-thread/issues/I4RVIU

增加的那些检测，明面上告诉大家别这么用，但是，最终 rtt 带头违规使用，然后用 rt_thread_self() != RT_NULL 打补丁去纠正违规行为。
这个问题，我很久之前就考虑过，论坛上的第二篇文章。

个人理解，ulog 和 malloc 的问题都可以通过调整系统初始化流程得到完美解决。

Guozhanxin · 2022-02-10T07:23:57Z

最近爆出了好多这种断言，看来内核增强安全检查是正确的 https://club.rt-thread.org/ask/question/434519.html https://club.rt-thread.org/ask/question/434558.html https://gitee.com/rtthread/rt-thread/issues/I4RVIU

增加的那些检测，明面上告诉大家别这么用，但是，最终 rtt 带头违规使用，然后用 rt_thread_self() != RT_NULL 打补丁去纠正违规行为。这个问题，我很久之前就考虑过，论坛上的第二篇文章。

个人理解，ulog 和 malloc 的问题都可以通过调整系统初始化流程得到完美解决。

问题确实是启动流程的问题，但是由idle线程初始化串口和堆，感觉不太好弄，也不好兼容之前的版本

mysterywolf · 2022-02-10T09:21:44Z

内核这块如果有大改动的话得动smart合并进来之后才能有大的改动，现在内核已经进入冻结状态了，尽量保持少量修改。否则并入smart会导致冲突。

thewon86 · 2022-02-10T09:33:54Z

最近爆出了好多这种断言，看来内核增强安全检查是正确的 https://club.rt-thread.org/ask/question/434519.html https://club.rt-thread.org/ask/question/434558.html https://gitee.com/rtthread/rt-thread/issues/I4RVIU

增加的那些检测，明面上告诉大家别这么用，但是，最终 rtt 带头违规使用，然后用 rt_thread_self() != RT_NULL 打补丁去纠正违规行为。这个问题，我很久之前就考虑过，论坛上的第二篇文章。
个人理解，ulog 和 malloc 的问题都可以通过调整系统初始化流程得到完美解决。

问题确实是启动流程的问题，但是由idle线程初始化串口和堆，感觉不太好弄，也不好兼容之前的版本

idle 可以只负责启动 main timer 俩线程，线程栈还是可以控制在某个范围内。
包括 board 初始化在内的绝大多数初始化过程都可以在 main 线程进行，这要求 main 线程栈要够用。
保证 idle 线程运行起来的要求很低，基本上时钟配置好了之后，堆，串口控制台，pin 这些都可以不要求的。用最少的资源把系统跑起来，其它的硬件资源初始化控制在线程上下文中进行初始化。这样可以减少很多麻烦。

兼容性问题，内核被 bsp 拖累了。

mysterywolf · 2022-02-10T09:50:34Z

兼容性问题，内核被 bsp 拖累了。

没关系，如果这个初始化更合理的话，在5.0.0版本中是可以大幅度修改的，但是需要等熊大那边把smart先并进来，现在只能先小幅度修改一下。

dongly · 2022-02-13T09:08:57Z

出现断言时,不断重复打印 ps 内容,和 [rt_sem_take]: scheduler is not available
重现步骤:
- 版本 rt-thread master 或 v4.1.0-beta
- 启用ulog , CmBacktrace v1.4.0
- 测试BSP stm32f407-atk-explorer
- 编译器 GCC v10.2.1
- 插入代码:

RT_ASSERT(RT_FALSE);

错误信息

thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
hx1_pars  10  suspend 0x000000f0 0x00000800    15%   0x00000001 000
hx1_rev    8  ready   0x000000d8 0x00000800    14%   0x00000001 000
telnet    26  ready   0x00000048 0x00001000    01%   0x00000064 000
acon      19  ready   0x00000044 0x00000800    03%   0x00000064 000
ebThread  30  ready   0x00000048 0x00000100    28%   0x0000000a 000
phy       30  ready   0x00000048 0x00000400    07%   0x00000002 000
sys work  23  ready   0x00000084 0x00000af0    04%   0x0000000a 000
tcpip     10  suspend 0x000000f8 0x00000800    18%   0x00000014 000
etx       12  suspend 0x000000b4 0x00000800    08%   0x00000010 000
erx       12  suspend 0x000000c4 0x00000800    09%   0x00000010 000
tidle0    31  ready   0x00000064 0x00000400    10%   0x0000000a 000
main      10  running 0x00000348 0x00000c00    56%   0x00000012 000
Function[rt_sem_take]: scheduler is not available
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
hx1_pars  10  suspend 0x000000f0 0x00000800    15%   0x00000001 000
hx1_rev    8  ready   0x000000d8 0x00000800    14%   0x00000001 000
telnet    26  ready   0x00000048 0x00001000    01%   0x00000064 000
acon      19  ready   0x00000044 0x00000800    03%   0x00000064 000
ebThread  30  ready   0x00000048 0x00000100    28%   0x0000000a 000
phy       30  ready   0x00000048 0x00000400    07%   0x00000002 000
sys work  23  ready   0x00000084 0x00000af0    04%   0x0000000a 000
tcpip     10  suspend 0x000000f8 0x00000800    18%   0x00000014 000
etx       12  suspend 0x000000b4 0x00000800    08%   0x00000010 000
erx       12  suspend 0x000000c4 0x00000800    09%   0x00000010 000
tidle0    31  ready   0x00000064 0x00000400    10%   0x0000000a 000
main      10  running 0x00000348 0x00000c00    62%   0x00000012 000
Function[rt_sem_take]: scheduler is not available
thread   pri  status      sp     stack size max used left tick  error
-------- ---  ------- ---------- ----------  ------  ---------- ---
hx1_pars  10  suspend 0x000000f0 0x00000800    15%   0x00000001 000
hx1_rev    8  ready   0x000000d8 0x00000800    14%   0x00000001 000
telnet    26  ready   0x00000048 0x00001000    01%   0x00000064 000
acon      19  ready   0x00000044 0x00000800    03%   0x00000064 000
ebThread  30  ready   0x00000048 0x00000100    28%   0x0000000a 000

mysterywolf · 2022-02-14T22:06:54Z

你再同步一下最新的代码试一下，这个已经修掉了

dongly · 2022-02-14T23:59:23Z

我用的就是最新版的代码 49ccbdb

thewon86 · 2022-02-15T00:28:33Z

我用的就是最新版的代码 49ccbdb

先关掉 RT_DEBUG 吧。
目测是 RT_ASSERT 里调用了 rt_sem_take 又触发了 RT_ASSERT ，这样引起的递归调用。

thewon86 · 2022-02-15T00:29:08Z

调整系统初始化流程势在必行了

dongly · 2022-02-15T00:59:15Z

我用的就是最新版的代码 49ccbdb

先关掉 RT_DEBUG 吧。目测是 RT_ASSERT 里调用了 rt_sem_take 又触发了 RT_ASSERT ，这样引起的递归调用。

是 RT_ASSERT 调用了ulog,ulog 调用rt_sem_take 触发的

dongly · 2022-02-15T01:06:59Z

停用 CmBacktrace 可以了.但这个仍是问题

dongly · 2022-02-15T01:09:17Z

调整系统初始化流程势在必行了

这个问题与初始化顺序无关吧?

Guozhanxin · 2022-02-15T01:27:59Z

拉一下最新的代码，ulog的问题已经修复了

dongly · 2022-02-15T01:32:54Z

拉一下最新的代码，ulog的问题已经修复了

我用的就是最新版的代码 49ccbdb

thewon86 · 2022-02-15T02:16:14Z

出问题的地方，任务调度还没运行呢吧。
假设，任务调度运行起来了。再使用 RT_ASSERT 就没这么多问题。
RT_ASSERT 引起 rt_assert_handler 函数调用，进而执行 rt_assert_hook
开启 cmbt 的时候，就相当于执行 assert_hook 。它调用了 rt_enter_critical list_thread cmb_println 三个函数，第二个就是你看到的循环 ps。
如果同时开启了 ulog 。cmb_println 函数等价于调用 ulog_e 。后面再调用 rt_sem_take 或者其它地方也有 RT_ASSERT 失败的时候，就会再次回到 assert_hook，之后就是死循环。
这一切的根源就是“任务调度运行前，调用多任务系统 api”引起的。你说这个跟启动顺序有没有关系？

看来，RT_ASSERT 里面也得添加个 rt_thread_self() != RT_NULL 判断了。

dongly · 2022-02-15T03:09:25Z

在 main() 中插入 RT_ASSERT(RT_FALSE); 的.此时任务调度已经运行,是RT_ASSERT使其关闭了?报警是[rt_sem_take]: scheduler is not available ,而不是Function[rt_sem_take] shall not be used before scheduler start

thewon86 · 2022-02-15T03:18:19Z

在 main() 中插入 RT_ASSERT(RT_FALSE); 的.此时任务调度已经运行,是RT_ASSERT使其关闭了?

这就不对了啊，这个时候调用 rt_sem_take 是没有限制的，这时候不应该出现“Function[rt_sem_take]: scheduler is not available” 这句错误提示信息的。
调度器启动，但是这个时候判断结果是不可用？这好像变另外一个问题了。

thewon86 · 2022-02-15T03:24:35Z

        if (rt_critical_level() != 0)                                         \
        {                                                                     \
            rt_kprintf("Function[%s]: scheduler is not available\n",          \
                    __FUNCTION__);                                            \
            RT_ASSERT(0)                                                      \
        }

是因为这个 rt_critical_level，上面 assert_hook 。它调用了 rt_enter_critical list_thread cmb_println 三个函数，第一个就进入了临界区。这个。。。后面 RT_ASSERT 肯定出现 “scheduler is not available” 这个错误信息。

问题还是 RT_ASSERT 之后出现了新的 RT_ASSERT

mysterywolf · 2022-02-15T22:06:13Z

@Guozhanxin 郭老师，俺建议组织社区开一次会吧，感觉这个问题没有彻底解决，包括讨论一下出出说的重新捋一下初始化流程这事。
此外，我觉得目前函数的安全检查这块还是有问题，还得优化；以及assert的使用场合也需要讨论一下。

Guozhanxin · 2022-02-16T01:24:33Z

@Guozhanxin 郭老师，俺建议组织社区开一次会吧，感觉这个问题没有彻底解决，包括讨论一下出出说的重新捋一下初始化流程这事。此外，我觉得目前函数的安全检查这块还是有问题，还得优化；以及assert的使用场合也需要讨论一下。

可以啊，你来组织也一样，我还没仔细看cmbacktrace的问题呢，先搞个共享文档收集议题好了

Guozhanxin · 2022-02-17T01:53:16Z

        if (rt_critical_level() != 0)                                         \
        {                                                                     \
            rt_kprintf("Function[%s]: scheduler is not available\n",          \
                    __FUNCTION__);                                            \
            RT_ASSERT(0)                                                      \
        }      
是因为这个 rt_critical_level，上面 assert_hook 。它调用了 rt_enter_critical list_thread cmb_println 三个函数，第一个就进入了临界区。这个。。。后面 RT_ASSERT 肯定出现 “scheduler is not available” 这个错误信息。

问题还是 RT_ASSERT 之后出现了新的 RT_ASSERT

我看了下这个问题，其实还是使用锁和系统上下文不匹配的问题。

如果某一个api允许在不同的上下文环境下被调用的话，就应该考虑这个问题。
目前系统的上下文是下面两种情况的组合：

调度器是否可用？（起没起来，有没有被锁定）
在中断还是线程的上下文

但是目前很多代码只检查第二种情况，没有考虑第一种情况。是不是在调度器里加一个api用来检测调度器是否可用？rt_scheduler_available()

Guozhanxin · 2022-02-17T02:11:32Z

想到两种方法，

修改ulog，让其支持在锁调度的情况下使用；
或者cm_backtrace 里把锁调度改成关中断？
不过感觉，ulog在关中断的情况下使用也会有问题。

thewon86 · 2022-02-22T10:32:53Z

Guozhanxin · 2022-03-17T06:50:12Z

信号量是特殊的，它被设计为在系统启动前也可以使用。已经还原了有关信号量的修改 #5682

liuduanfei · 2022-10-11T09:02:30Z

这个在信号量部分的文档里面有说明嘛？为啥这样设计？。🤔

…

---原始邮件--- 发件人: ***@***.***> 发送时间: 2022年3月17日(周四) 下午2:50 收件人: ***@***.***>; 抄送: ***@***.***>; 主题: Re: [RT-Thread/rt-thread] [bug][v4.1.0-beta] IIC 初始化出现断言 Function[rt_sem_take] shall not be used before scheduler start (Issue #5584) 信号量是特殊的，它被设计为在系统启动前也可以使用。已经还原了有关信号量的修改 #5682 — Reply to this email directly, view it on GitHub, or unsubscribe. Triage notifications on the go with GitHub Mobile for iOS or Android. You are receiving this because you are subscribed to this thread.Message ID: ***@***.***>

mysterywolf added the v4.1.0 label Feb 7, 2022

mysterywolf added the important label Feb 8, 2022

mysterywolf added crucial and removed important labels Feb 15, 2022

Guozhanxin mentioned this issue Mar 10, 2022

v4.1.0 特性征集与讨论 | v4.1.0 discussion #5342

Closed

24 tasks

Guozhanxin closed this as completed Mar 17, 2022

dongly mentioned this issue Aug 23, 2022

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

Closed

[bug][v4.1.0-beta] IIC 初始化出现断言 Function[rt_sem_take] shall not be used before scheduler start #5584

[bug][v4.1.0-beta] IIC 初始化出现断言 Function[rt_sem_take] shall not be used before scheduler start #5584

Comments

dongly commented Feb 6, 2022 • edited Loading

dongly commented Feb 6, 2022

mysterywolf commented Feb 8, 2022 • edited Loading

dongly commented Feb 9, 2022 • edited Loading

mysterywolf commented Feb 9, 2022

mysterywolf commented Feb 9, 2022

mysterywolf commented Feb 9, 2022

Guozhanxin commented Feb 9, 2022

mysterywolf commented Feb 9, 2022 • edited Loading

Guozhanxin commented Feb 9, 2022 • edited Loading

thewon86 commented Feb 10, 2022

Guozhanxin commented Feb 10, 2022

mysterywolf commented Feb 10, 2022

thewon86 commented Feb 10, 2022

mysterywolf commented Feb 10, 2022

dongly commented Feb 13, 2022 • edited Loading

mysterywolf commented Feb 14, 2022

dongly commented Feb 14, 2022

thewon86 commented Feb 15, 2022

thewon86 commented Feb 15, 2022

dongly commented Feb 15, 2022

dongly commented Feb 15, 2022

dongly commented Feb 15, 2022

Guozhanxin commented Feb 15, 2022

dongly commented Feb 15, 2022

thewon86 commented Feb 15, 2022

dongly commented Feb 15, 2022 • edited Loading

thewon86 commented Feb 15, 2022

thewon86 commented Feb 15, 2022

mysterywolf commented Feb 15, 2022 • edited Loading

Guozhanxin commented Feb 16, 2022

Guozhanxin commented Feb 17, 2022 • edited Loading

Guozhanxin commented Feb 17, 2022

thewon86 commented Feb 22, 2022

Guozhanxin commented Mar 17, 2022

liuduanfei commented Oct 11, 2022 via email

dongly commented Feb 6, 2022 •

edited

Loading

mysterywolf commented Feb 8, 2022 •

edited

Loading

dongly commented Feb 9, 2022 •

edited

Loading

mysterywolf commented Feb 9, 2022 •

edited

Loading

Guozhanxin commented Feb 9, 2022 •

edited

Loading

dongly commented Feb 13, 2022 •

edited

Loading

dongly commented Feb 15, 2022 •

edited

Loading

mysterywolf commented Feb 15, 2022 •

edited

Loading

Guozhanxin commented Feb 17, 2022 •

edited

Loading