blob: b2749af5eb7726af6942988f3cb99f12e3527e5a [file] [log] [blame]
Stephan Pleines682928d2024-05-31 20:43:48 -07001#include <inttypes.h>
Austin Schuh5af45eb2019-09-16 20:54:18 -07002#include <sys/signalfd.h>
Stephan Pleines682928d2024-05-31 20:43:48 -07003#include <unistd.h>
Tyler Chatowbf0609c2021-07-31 16:13:27 -07004
Stephan Pleines682928d2024-05-31 20:43:48 -07005#include <algorithm>
Austin Schuh5af45eb2019-09-16 20:54:18 -07006#include <chrono>
Stephan Pleines682928d2024-05-31 20:43:48 -07007#include <compare>
Tyler Chatowbf0609c2021-07-31 16:13:27 -07008#include <csignal>
Austin Schuh5af45eb2019-09-16 20:54:18 -07009#include <random>
Stephan Pleines682928d2024-05-31 20:43:48 -070010#include <ratio>
Austin Schuh5af45eb2019-09-16 20:54:18 -070011#include <thread>
12
Philipp Schrader790cb542023-07-05 21:06:52 -070013#include "gflags/gflags.h"
Stephan Pleines682928d2024-05-31 20:43:48 -070014#include "glog/logging.h"
Philipp Schrader790cb542023-07-05 21:06:52 -070015
Austin Schuh5af45eb2019-09-16 20:54:18 -070016#include "aos/events/epoll.h"
Austin Schuh5af45eb2019-09-16 20:54:18 -070017#include "aos/ipc_lib/latency_lib.h"
18#include "aos/logging/implementations.h"
Austin Schuh5af45eb2019-09-16 20:54:18 -070019#include "aos/realtime.h"
20#include "aos/time/time.h"
21
22// This is a demo program which uses Real-Time posix signals to communicate.
23// It measures both latency of a random timer thread, and latency of the
24// signals.
25//
26// To enable function graph:
27// echo "function_graph" > current_tracer
28
29DEFINE_bool(sender, true, "If true, send signals to the other process.");
30DEFINE_int32(other_pid, -1, "PID of other process to ping");
31DEFINE_int32(seconds, 10, "Duration of the test to run");
32DEFINE_int32(
33 latency_threshold, 1000,
34 "Disable tracing when anything takes more than this many microseoncds");
35DEFINE_int32(core, 7, "Core to pin to");
36DEFINE_int32(sender_priority, 53, "RT priority to send at");
37DEFINE_int32(receiver_priority, 52, "RT priority to receive at");
38DEFINE_int32(timer_priority, 51, "RT priority to spin the timer at");
39
40DEFINE_bool(log_latency, false, "If true, log the latency");
41
42const uint32_t kSignalNumber = SIGRTMIN + 1;
43const uint32_t kQuitSignalNumber = SIGRTMIN + 2;
44
45namespace chrono = ::std::chrono;
46
47namespace aos {
48
49void SenderThread() {
50 const monotonic_clock::time_point end_time =
51 monotonic_clock::now() + chrono::seconds(FLAGS_seconds);
52 // Standard mersenne_twister_engine seeded with 0
53 ::std::mt19937 generator(0);
54
55 // Sleep between 1 and 15 ms.
56 ::std::uniform_int_distribution<> distribution(1000, 15000);
57
58 int pid = getpid();
59 if (FLAGS_other_pid != -1) {
60 pid = FLAGS_other_pid;
61 }
62 AOS_LOG(INFO, "Current PID: %d\n", pid);
63
Austin Schuh9014e3b2020-11-21 14:26:07 -080064 SetCurrentThreadAffinity(MakeCpusetFromCpus({FLAGS_core}));
Austin Schuh5af45eb2019-09-16 20:54:18 -070065 SetCurrentThreadRealtimePriority(FLAGS_sender_priority);
66 while (true) {
67 const monotonic_clock::time_point wakeup_time =
68 monotonic_clock::now() + chrono::microseconds(distribution(generator));
69
70 ::std::this_thread::sleep_until(wakeup_time);
71 const monotonic_clock::time_point monotonic_now = monotonic_clock::now();
72 sigval s;
73 s.sival_int = static_cast<uint32_t>(
74 static_cast<uint64_t>(monotonic_now.time_since_epoch().count()) &
75 0xfffffffful);
76
77 PCHECK(sigqueue(pid, kSignalNumber, s));
78
79 if (monotonic_now > end_time) {
80 break;
81 }
82 }
83
84 {
85 sigval s;
86 s.sival_int = 0;
87 PCHECK(sigqueue(pid, kQuitSignalNumber, s));
88 }
89 UnsetCurrentThreadRealtimePriority();
90}
91
92void ReceiverThread() {
93 int signalfd_fd;
94 Tracing t;
95 t.Start();
96
97 sigset_t x;
98 sigemptyset(&x);
99 sigaddset(&x, kSignalNumber);
100 sigaddset(&x, kQuitSignalNumber);
101
102 PCHECK(signalfd_fd = signalfd(-1, &x, SFD_NONBLOCK | SFD_CLOEXEC));
103 chrono::nanoseconds max_wakeup_latency = chrono::nanoseconds(0);
104
105 chrono::nanoseconds sum_latency = chrono::nanoseconds(0);
106 int latency_count = 0;
107
108 internal::EPoll epoll;
109
110 epoll.OnReadable(signalfd_fd, [&t, &epoll, &max_wakeup_latency, &sum_latency,
111 &latency_count, signalfd_fd]() {
112 const monotonic_clock::time_point monotonic_now = monotonic_clock::now();
113 signalfd_siginfo si;
114 const int ret =
115 read(signalfd_fd, static_cast<void *>(&si), sizeof(signalfd_siginfo));
116 CHECK_EQ(ret, static_cast<int>(sizeof(signalfd_siginfo)));
117
118 if (si.ssi_signo == kQuitSignalNumber) {
119 epoll.Quit();
120 return;
121 }
122
123 int64_t wakeup_latency_int64 =
124 static_cast<int64_t>(monotonic_now.time_since_epoch().count()) &
125 0xfffffffful;
126
127 wakeup_latency_int64 -= static_cast<int64_t>(si.ssi_int);
128
129 if (wakeup_latency_int64 > 0x80000000l) {
130 wakeup_latency_int64 -= 0x100000000l;
131 }
132
133 const chrono::nanoseconds wakeup_latency(wakeup_latency_int64);
134
135 sum_latency += wakeup_latency;
136 ++latency_count;
137
138 max_wakeup_latency = ::std::max(wakeup_latency, max_wakeup_latency);
139
140 if (wakeup_latency > chrono::microseconds(FLAGS_latency_threshold)) {
141 t.Stop();
142 AOS_LOG(INFO, "Stopped tracing, latency %" PRId64 "\n",
143 static_cast<int64_t>(wakeup_latency.count()));
144 }
145
146 if (FLAGS_log_latency) {
147 AOS_LOG(INFO, "signo: %d, sending pid: %d, dt: %8d.%03d\n", si.ssi_signo,
148 si.ssi_pid, static_cast<int>(wakeup_latency_int64 / 1000),
149 static_cast<int>(wakeup_latency_int64 % 1000));
150 }
151 });
152
Austin Schuh9014e3b2020-11-21 14:26:07 -0800153 SetCurrentThreadAffinity(MakeCpusetFromCpus({FLAGS_core}));
Austin Schuh5af45eb2019-09-16 20:54:18 -0700154 SetCurrentThreadRealtimePriority(FLAGS_receiver_priority);
155 epoll.Run();
156 UnsetCurrentThreadRealtimePriority();
157 epoll.DeleteFd(signalfd_fd);
158
159 const chrono::nanoseconds average_latency = sum_latency / latency_count;
160
161 AOS_LOG(INFO,
162 "Max signal wakeup latency: %d.%03d microseconds, average: %d.%03d "
163 "microseconds\n",
164 static_cast<int>(max_wakeup_latency.count() / 1000),
165 static_cast<int>(max_wakeup_latency.count() % 1000),
166 static_cast<int>(average_latency.count() / 1000),
167 static_cast<int>(average_latency.count() % 1000));
168
169 PCHECK(close(signalfd_fd));
170}
171
172int Main(int /*argc*/, char ** /*argv*/) {
173 sigset_t x;
174 sigemptyset(&x);
175 sigaddset(&x, kSignalNumber);
176 sigaddset(&x, kQuitSignalNumber);
177 pthread_sigmask(SIG_BLOCK, &x, NULL);
178
179 AOS_LOG(INFO, "Main!\n");
180 ::std::thread t([]() {
181 TimerThread(monotonic_clock::now() + chrono::seconds(FLAGS_seconds),
182 FLAGS_timer_priority);
183 });
184
185 ::std::thread st([]() { SenderThread(); });
186
187 ReceiverThread();
188 st.join();
189
190 t.join();
191 return 0;
192}
193
194} // namespace aos
195
196int main(int argc, char **argv) {
197 ::gflags::ParseCommandLineFlags(&argc, &argv, true);
198
Austin Schuh5af45eb2019-09-16 20:54:18 -0700199 return ::aos::Main(argc, argv);
200}