这里在Basis,我们正在构建一个专注于生产和测试的机器人框架。在这方面,测试中的确定性是我们的主要目标之一。本文将重点介绍Basis如何不仅在测试中实现确定性,而且利用它来以闪电般的速度运行你的测试。
以下是预览:
replay |
deterministic_replay |
---|---|
背景
机器人技术中的确定性问题一直存在,无论是在实时运行还是测试中。本文旨在展示一种用于测试/模拟的解决方案。
主要问题包括:
- ROS 和其他机器人框架没有任何方式能在测试模式下确定性地运行。
- 机器人和开发者工作站之间的代码运行速度不一致是一个问题。
- CI 和机器人上的代码运行速度不一致是一个大问题,在CI硬件上节省成本或为加速测试时间而使用过多并行都会加剧这一问题。
- 在低层面上,即使在同一系统上运行相同的代码,由于传输层和调度的非确定性也会表现出不同的行为。
结果,创建机器人的集成测试很糟糕,并且现有的工具也效果不佳。CI 上的集成测试可能如下所示:
- 启动一些进程编排器(ROS Master等)
- 使用自定义启动文件启动机器人的某个子集
- 如果你幸运,有人在主启动文件中添加了一个测试标志
- 如果你不幸,有一个单独的测试启动文件可能已经过时,与实际运行在机器人上的不同步
- 以慢于实时的速度重放一些记录的数据试图避开传输/调度的非确定性
- 需要等待更久因为测试是以慢于实时速度运行的
- 你的测试失败了CI
- 希望测试清理能真正杀死所有被测试启动的进程
- 在你的开发桌面重复上述步骤
- 测试成功(或者随机性地没成功)
- 重新在CI上运行测试,等待更长时间
- 测试成功
- 感到无奈,放弃,并合并代码,如果
main
分支再次失败则责备仿真团队。
最终,这种情况会让工程团队忽视测试结果,并且不鼓励创建更大/更复杂的测试和模拟。当测试失败时,是因为框架的问题还是实际的机器人代码?特别是在安全关键环境中,重要的是排除测试中的随机因素。
Basis 的目标是每次都让测试给出相同的结果。未来还将包含其他类型的确定性(例如代码在重放时的运行时间和实时一致)。
非确定性的源头
非确定性来自多种源头。
目前Basis的主要焦点(也是这篇文章的重点)是非确定性中的传输层相关问题和调度相关的非确定性。
传输层上的非确定性包含网络堆栈中的不确定性,套接字处理顺序,两个消息同时到来时会发生什么等等。
调度非确定性包括线程相关的问题、测试执行之间的性能差异等。
还有其他的一些非确定性来源:
- 调用
random()
- 使用系统时钟
- 使用网络资源
- 数据竞争
- 编译器标志
- 宇宙射线
- 指针比较
这些我都曾在测试环境见过。
我们如何解决这个问题?
几个规则:
- 所有要以确定性运行的代码都是对消息或定时器的响应(在Basis术语中,一切都是在处理程序Handlers内运行)
- 不允许处理器之间使用侧通道通信。使用主题 -Basis支持仅运行时主题(原始C++结构体),因此请使用它们。
- 这不是严格的事实——同一单元中的处理程序会在同一个C++类中共享变量,这是一种侧通道通信。这对于复杂单元尤其是一个问题,该单元允许并发执行处理程序。我们最终会提供工具来帮助解决这种问题。
- (与第2条共同考虑)机器人代码不知道订阅者和发布者的概念。它们从主题获取输入消息作为输入,并将输出消息发送到主题作为输出。
- 这并不能阻止关心这些概念的工具,它只是意味着这些工具不能作为测试的一部分确定性地运行。
- 这确实意味着外部触发的代码(传感器驱动)不会是确定性的,但这对于大多数测试不是问题。
- 所有处理程序都有与其相关的元数据描述其输入,输出和执行条件。
- 所有单元(可以理解为ROS节点)都可以动态加载并包含元数据
- 处理程序内部的代码是确定性的(当然如此)。
基于这些规则,可以构建一个计划程序,查看要运行的请求单元,查看任何要重放的数据的内容,并以正确(和确定的)顺序及正确的数据适当调用每个处理程序。Basis 是从零开始为支持这种用例构建的。
演示
让我们演示Basis是如何帮助实现确定性的。首先我们将记录一些现场运行的数据。然后我们将对该数据运行 replay
测试,找出测试过程中的问题。最后,我们将展示 deterministic_replay
解决这些问题的过程。
记录一些数据
下面是一个想要做一些工作的Basis单元示例。这个单元将接收一条消息,等待100毫秒(执行“工作”),然后退出,允许其他回调继续执行。
threading_model:
single
cpp_includes:
- simple_pub_sub.pb.h
handlers:
OnChatter:
sync:
type: all
inputs:
/chatter:
type: protobuf:StringMessage
OnChatter::Output simple_sub::OnChatter(const OnChatter::Input &input) {
// Convert protobuf nanoseconds into a basis timestamp
auto send_stamp = basis::core::MonotonicTime::FromNanoseconds(input.chatter->send_stamp());
BASIS_LOG_INFO("OnChatter: {} {}", input.chatter->message(), send_stamp.ToSeconds());
// Calculate delay between "now" and when the message was sent
basis::core::Duration delay = input.time - send_stamp;
if (delay > basis::core::Duration::FromSeconds(0.2)) {
BASIS_LOG_WARN("/chatter delayed by {:.2f}s - queueing has occured", delay.ToSeconds());
}
constexpr int work_time_ms = 2000;
BASIS_LOG_INFO("Doing {} ms worth of work", work_time_ms);
std::this_thread::sleep_for(std::chrono::milliseconds(work_time_ms));
return OnChatter::Output();
}
这个单元和另一个按1Hz频率在 /chatter
生产的单元一起运行将会得到类似的控制台输出:
[124998.122650826] [launch] [info] 录制 (异步) 到 /tmp/demo_124998.122377076.mcap
[124998.126956742] [launch] [info] 运行带有 2 个组件的进程
[124998.130765492] [launch] [info] 启动带有组件 /opt/basis/unit/simple_sub.unit.so 的线程
[124998.134928909] [launch] [info] 启动带有组件 /opt/basis/unit/simple_pub.unit.so 的线程
[124999.137999076] [/simple_pub] [info] PublishAt1Hz
[124999.138074076] [/simple_sub] [info] OnChatter: Hello, world! 124999.138065618
[124999.138080410] [/simple_sub] [info] 处理 100 毫秒的工作
[125000.136988785] [/simple_pub] [info] PublishAt1Hz
[125000.137143077] [/simple_sub] [info] OnChatter: Hello, world! 125000.137124493
[125000.137151452] [/simple_sub] [info] 处理 100 毫秒的工作
[125001.136178202] [/simple_pub] [info] PublishAt1Hz
[125001.136319869] [/simple_sub] [info] OnChatter: Hello, world! 125001.136305744
[125001.136327452] [/simple_sub] [info] 处理 100 毫秒的工作
[125002.137870703] [/simple_pub] [info] PublishAt1Hz
[125002.138054536] [/simple_sub] [info] OnChatter: Hello, world! 125002.137991619
...
回放数据
非常好,但假设这是一个录制在机器人上的数据。我们可能会运行 replay /tmp/demo_124998.122377076.mcap
,并伴随着 simple_sub
。如果两个环境中的硬件相似,我们可能会看到这样的结果:
[125458.039238910] [launch] [info] 运行带有 1 个组件的进程
[125458.040486243] [launch] [info] 启动带有组件 /opt/basis/unit/simple_sub.unit.so 的线程
[124998.307061284] [launch] [info] simple_sub 检测到重放重置,正在重启 ...
(请注意这里的时间跳变,我们得到了一个新的模拟时间步)
[124998.977061284] [launch] [info] 运行带有 1 个组件的进程
[124998.977061284] [launch] [info] 启动带有组件 /opt/basis/unit/simple_sub.unit.so 的线程
[125001.137061284] [/simple_sub] [info] OnChatter: Hello, world! 125001.137061284
[125001.137061284] [/simple_sub] [info] 处理 100 毫秒的工作
[125002.147061284] [/simple_sub] [info] OnChatter: Hello, world! 125002.147061284
[125002.147061284] [/simple_sub] [info] 处理 100 毫秒的工作
[125003.147061284] [/simple_sub] [info] OnChatter: Hello, world! 125003.147061284
[125003.147061284] [/simple_sub] [info] 处理 100 毫秒的工作
...
问题 1 - 缺失数据,非确定性
重新运行几次后,我们发现了第一个问题 - 有时我们错过了测试的第一个消息,并且看到输出如下:
[125002.147061284] [/simple_sub] [info] OnChatter: Hello, world! 125002.147061284
用 mcap-cli
快速检查一下发现 ...
basis@aee413836118:/basis/demos/simple_pub_sub/build$ ~/mcap-linux-arm64 cat --json /tmp/demo_124998.122377076.mcap --topics /chatter
{"topic":"/chatter","sequence":0,"log_time":124999.138044993,"publish_time":124999.138044993,"data":{"sendStamp":"124999137959660", "message":"Hello, world!"}}
{"topic":"/chatter","sequence":0,"log_time":125000.137092327,"publish_time":125000.137092327,"data":{"sendStamp":"125000136919993", "message":"Hello, world!"}}
{"topic":"/chatter","sequence":0,"log_time":125001.136257244,"publish_time":125001.136257244,"data":{"sendStamp":"125001136105286", "message":"Hello, world!"}}
...
有几个消息从测试中丢失了。即使我们最完整的重放也缺少 124999
和 125000
。
问题 2 - 性能差异可能导致非确定性
如果我们的测试环境变慢(过载 CI、不同的/没有 GPU、更少的 CPU 核心)。在这种情况下,假设处理需要 2000 毫秒,并且设置 constexpr int work_time_ms = 2000;
。
再运行一次相同的重放测试。
[125002.147061284] [/simple_sub] [info] OnChatter: Hello, world! 125002.137789828
[125002.147061284] [/simple_sub] [info] 处理 2000 毫秒的工作
[125004.147061284] [/simple_sub] [info] OnChatter: Hello, world! 125003.137948037
[125004.147061284] [/simple_sub] [warning] /chatter 延迟了 1.01 秒 - 队列已溢出
[125004.147061284] [/simple_sub] [info] 处理 2000 毫秒的工作
[125006.147061284] [/simple_sub] [info] OnChatter: Hello, world! 125004.13672012
[125006.147061284] [/simple_sub] [warning] /chatter 延迟了 2.01 秒 - 队列已溢出
[125006.147061284] [/simple_sub] [info] 处理 2000 毫秒的工作
[125008.147061284] [/simple_sub] [info] OnChatter: Hello, world! 125005.136193412
[125008.147061284] [/simple_sub] [warning] /c