1 #include <stdio.h>
2 #include <unistd.h>
3
4 #include <mach/mach.h>
5 #include <mach/mach_time.h>
6 #include <sys/time.h>
7 #include <spawn.h>
8 #include <sys/wait.h>
9 #include <stdio.h>
10 #include <unistd.h>
11 #include <stdlib.h>
12 #include <time.h>
13 #include <errno.h>
14 #include <sys/event.h>
15
16 #include <darwintest.h>
17
18 extern char **environ;
19
20 static mach_timebase_info_data_t tb_info;
21 static const uint64_t one_mil = 1000LL * 1000LL;
22
23 #define tick_to_ns(ticks) (((ticks) * tb_info.numer) / (tb_info.denom))
24 #define tick_to_ms(ticks) (tick_to_ns(ticks)/one_mil)
25
26 #define ns_to_tick(ns) ((ns) * tb_info.denom / tb_info.numer)
27 #define ms_to_tick(ms) (ns_to_tick((ms) * one_mil))
28
29 static uint64_t
time_delta_ms(void)30 time_delta_ms(void)
31 {
32 uint64_t abs_now = mach_absolute_time();
33 uint64_t cnt_now = mach_continuous_time();
34 return tick_to_ms(cnt_now) - tick_to_ms(abs_now);
35 }
36
37 T_GLOBAL_META(T_META_RADAR_COMPONENT_NAME("xnu"),
38 T_META_RADAR_COMPONENT_VERSION("kevent"));
39
40 static int run_sleep_tests = 0;
41
42 static int
trigger_sleep(int for_secs)43 trigger_sleep(int for_secs)
44 {
45 if (!run_sleep_tests) {
46 return 0;
47 }
48
49 // sleep for 1 seconds each iteration
50 char buf[10];
51 snprintf(buf, 10, "%d", for_secs);
52
53 T_LOG("Sleepeing for %s seconds...", buf);
54
55 int spawn_ret, pid;
56 char *const pmset1_args[] = {"/usr/bin/pmset", "relative", "wake", buf, NULL};
57 T_ASSERT_POSIX_ZERO((spawn_ret = posix_spawn(&pid, pmset1_args[0], NULL, NULL, pmset1_args, environ)), NULL);
58
59 T_ASSERT_EQ(waitpid(pid, &spawn_ret, 0), pid, NULL);
60 T_ASSERT_EQ(spawn_ret, 0, NULL);
61
62 char *const pmset2_args[] = {"/usr/bin/pmset", "sleepnow", NULL};
63 T_ASSERT_POSIX_ZERO((spawn_ret = posix_spawn(&pid, pmset2_args[0], NULL, NULL, pmset2_args, environ)), NULL);
64
65 T_ASSERT_EQ(waitpid(pid, &spawn_ret, 0), pid, NULL);
66 T_ASSERT_EQ(spawn_ret, 0, NULL);
67
68 return 0;
69 }
70
71 // waits up to 30 seconds for system to sleep
72 // returns number of seconds it took for sleep to be entered
73 // or -1 if sleep wasn't accomplished
74 static int
wait_for_sleep()75 wait_for_sleep()
76 {
77 if (!run_sleep_tests) {
78 return 0;
79 }
80
81 uint64_t before_diff = time_delta_ms();
82
83 for (int i = 0; i < 30; i++) {
84 uint64_t after_diff = time_delta_ms();
85
86 // on OSX, there's enough latency between calls to MCT and MAT
87 // when the system is going down for sleep for values to diverge a few ms
88 if (llabs((int64_t)before_diff - (int64_t)after_diff) > 2) {
89 return i + 1;
90 }
91
92 sleep(1);
93 T_LOG("waited %d seconds for sleep...", i + 1);
94 }
95 return -1;
96 }
97
98 T_DECL(kevent_continuous_time_periodic_tick, "kevent(EVFILT_TIMER with NOTE_MACH_CONTINUOUS_TIME)", T_META_LTEPHASE(LTE_POSTINIT), T_META_TAG_VM_PREFERRED){
99 mach_timebase_info(&tb_info);
100 int kq;
101 T_ASSERT_POSIX_SUCCESS((kq = kqueue()), NULL);
102
103 struct kevent64_s kev = {
104 .ident = 1,
105 .filter = EVFILT_TIMER,
106 .flags = EV_ADD | EV_RECEIPT,
107 .fflags = NOTE_SECONDS | NOTE_MACH_CONTINUOUS_TIME,
108 .data = 4,
109 };
110 T_LOG("EV_SET(&kev, 1, EVFILT_TIMER, EV_ADD, NOTE_SECONDS | NOTE_MACH_CONTINUOUS_TIME, 4, 0, 0, 0);");
111
112 T_ASSERT_EQ(kevent64(kq, &kev, 1, &kev, 1, 0, NULL), 1, NULL);
113 T_ASSERT_EQ(0ll, kev.data, "No error returned");
114
115 uint64_t abs_then = mach_absolute_time();
116 uint64_t cnt_then = mach_continuous_time();
117
118 trigger_sleep(1);
119 int sleep_secs = wait_for_sleep();
120
121 T_WITH_ERRNO; T_ASSERT_EQ(kevent64(kq, NULL, 0, &kev, 1, 0, NULL), 1, "kevent() should have returned one event");
122 T_LOG("event = {.ident = %llx, .filter = %d, .flags = %d, .fflags = %d, .data = %lld, .udata = %lld}", kev.ident, kev.filter, kev.flags, kev.fflags, kev.data, kev.udata);
123 T_ASSERT_EQ(kev.flags & EV_ERROR, 0, "event should not have EV_ERROR set: %s", kev.flags & EV_ERROR ? strerror((int)kev.data) : "no error");
124
125 uint64_t abs_now = mach_absolute_time();
126 uint64_t cnt_now = mach_continuous_time();
127 uint64_t ct_ms_progressed = tick_to_ms(cnt_now - cnt_then);
128 uint64_t ab_ms_progressed = tick_to_ms(abs_now - abs_then);
129
130 T_LOG("ct progressed %llu ms, abs progressed %llu ms", ct_ms_progressed, tick_to_ms(abs_now - abs_then));
131
132 if (run_sleep_tests) {
133 T_ASSERT_GT(llabs((int64_t)ct_ms_progressed - (int64_t)ab_ms_progressed), 500LL, "should have > 500ms difference between MCT and MAT");
134 } else {
135 T_ASSERT_LT(llabs((int64_t)ct_ms_progressed - (int64_t)ab_ms_progressed), 10LL, "should have < 10ms difference between MCT and MAT");
136 }
137
138 if (sleep_secs < 4) {
139 T_ASSERT_LT(llabs((int64_t)ct_ms_progressed - 4000), 100LL, "mach_continuous_time should progress ~4 seconds (+/- 100ms) between sleeps");
140 }
141
142 sleep(1);
143
144 kev = (struct kevent64_s){
145 .ident = 1,
146 .filter = EVFILT_TIMER,
147 .flags = EV_DELETE | EV_RECEIPT,
148 };
149 T_LOG("EV_SET(&kev, 1, EVFILT_TIMER, EV_DELETE, 0, 0, 0);");
150 T_ASSERT_EQ(kevent64(kq, &kev, 1, &kev, 1, 0, NULL), 1, NULL);
151 T_ASSERT_EQ(0ll, kev.data, "No error returned");
152
153 T_ASSERT_POSIX_ZERO(close(kq), NULL);
154 }
155
156 T_DECL(kevent_continuous_time_absolute, "kevent(EVFILT_TIMER with NOTE_MACH_CONTINUOUS_TIME and NOTE_ABSOLUTE)", T_META_LTEPHASE(LTE_POSTINIT), T_META_TAG_VM_PREFERRED){
157 mach_timebase_info(&tb_info);
158
159 int kq;
160 T_ASSERT_POSIX_SUCCESS((kq = kqueue()), NULL);
161
162 struct timeval tv;
163 gettimeofday(&tv, NULL);
164 int64_t nowus = (int64_t)tv.tv_sec * USEC_PER_SEC + (int64_t)tv.tv_usec;
165 int64_t fire_at = (3 * USEC_PER_SEC) + nowus;
166
167 uint64_t cnt_now = mach_continuous_time();
168 uint64_t cnt_then = cnt_now + ms_to_tick(3000);
169
170 T_LOG("currently is %llu, firing at %llu", nowus, fire_at);
171
172 struct kevent64_s kev = {
173 .ident = 2,
174 .filter = EVFILT_TIMER,
175 .flags = EV_ADD | EV_RECEIPT,
176 .fflags = NOTE_MACH_CONTINUOUS_TIME | NOTE_ABSOLUTE | NOTE_USECONDS,
177 .data = fire_at,
178 };
179 T_LOG("EV_SET(&kev, 2, EVFILT_TIMER, EV_ADD, NOTE_MACH_CONTINUOUS_TIME | NOTE_ABSOLUTE | NOTE_USECONDS, fire_at, 0);");
180
181 T_ASSERT_EQ(kevent64(kq, &kev, 1, &kev, 1, 0, NULL), 1, NULL);
182 T_ASSERT_EQ(0ll, kev.data, "No error returned");
183
184 T_LOG("testing NOTE_MACH_CONTINUOUS_TIME | NOTE_ABSOLUTE between sleep");
185
186 trigger_sleep(1);
187
188 struct timespec timeout = {
189 .tv_sec = 10,
190 .tv_nsec = 0,
191 };
192 struct kevent64_s event = {0};
193 T_ASSERT_EQ(kevent64(kq, NULL, 0, &event, 1, 0, &timeout), 1, "kevent() should have returned one event");
194 T_LOG("event = {.ident = %llx, .filter = %d, .flags = %d, .fflags = %d, .data = %lld, .udata = %lld}", event.ident, event.filter, event.flags, event.fflags, event.data, event.udata);
195 T_ASSERT_EQ(event.flags & EV_ERROR, 0, "event should not have EV_ERROR set: %s", event.flags & EV_ERROR ? strerror((int)event.data) : "no error");
196
197 uint64_t elapsed_ms = tick_to_ms(mach_continuous_time() - cnt_now);
198 int64_t missed_by = tick_to_ns((int64_t)mach_continuous_time() - (int64_t)cnt_then) / 1000000;
199
200 // ~1/2 second is about as good as we'll get
201 T_ASSERT_LT(llabs(missed_by), 500LL, "timer should pop 3 sec in the future, popped after %lldms", elapsed_ms);
202
203 T_ASSERT_EQ(event.data, 1LL, NULL);
204
205 T_ASSERT_EQ(event.ident, 2ULL, NULL);
206
207 // try getting a periodic tick out of kq
208 T_ASSERT_EQ(kevent64(kq, NULL, 0, &event, 1, 0, &timeout), 0, NULL);
209 T_ASSERT_EQ(event.flags & EV_ERROR, 0, "event should not have EV_ERROR set: %s", event.flags & EV_ERROR ? strerror((int)event.data) : "no error");
210
211 T_ASSERT_POSIX_ZERO(close(kq), NULL);
212 }
213
214 T_DECL(kevent_continuous_time_pops, "kevent(EVFILT_TIMER with NOTE_MACH_CONTINUOUS_TIME with multiple pops)", T_META_LTEPHASE(LTE_POSTINIT), T_META_TAG_VM_PREFERRED){
215 // have to throttle rate at which pmset is called
216 sleep(2);
217
218 mach_timebase_info(&tb_info);
219
220 int kq;
221 T_ASSERT_POSIX_SUCCESS((kq = kqueue()), NULL);
222
223 // test that periodic ticks accumulate while asleep
224 struct kevent64_s kev = {
225 .ident = 3,
226 .filter = EVFILT_TIMER,
227 .flags = EV_ADD | EV_RECEIPT,
228 .fflags = NOTE_MACH_CONTINUOUS_TIME,
229 .data = 100,
230 };
231 T_LOG("EV_SET(&kev, 3, EVFILT_TIMER, EV_ADD, NOTE_MACH_CONTINUOUS_TIME, 100, 0);");
232
233 // wait for first pop, then sleep
234 T_ASSERT_EQ(kevent64(kq, &kev, 1, &kev, 1, 0, NULL), 1, NULL);
235 T_ASSERT_EQ(0ll, kev.data, "No error returned");
236
237 struct kevent64_s event = {0};
238 T_ASSERT_EQ(kevent64(kq, NULL, 0, &event, 1, 0, NULL), 1, "kevent() should have returned one event");
239 T_LOG("event = {.ident = %llx, .filter = %d, .flags = %d, .fflags = %d, .data = %lld, .udata = %llu}", event.ident, event.filter, event.flags, event.fflags, event.data, event.udata);
240 T_ASSERT_EQ(event.flags & EV_ERROR, 0, "should not have EV_ERROR set: %s", event.flags & EV_ERROR ? strerror((int)event.data) : "no error");
241 T_ASSERT_EQ(event.ident, 3ULL, NULL);
242
243 uint64_t cnt_then = mach_continuous_time();
244 trigger_sleep(2);
245
246 int sleep_secs = 0;
247 if (run_sleep_tests) {
248 sleep_secs = wait_for_sleep();
249 } else {
250 // simulate 2 seconds of system "sleep"
251 sleep(2);
252 }
253
254 uint64_t cnt_now = mach_continuous_time();
255
256 uint64_t ms_elapsed = tick_to_ms(cnt_now - cnt_then);
257 if (run_sleep_tests) {
258 T_ASSERT_LT(llabs((int64_t)ms_elapsed - 2000LL), 500LL, "slept for %llums, expected 2000ms (astris is connected?)", ms_elapsed);
259 }
260
261 T_ASSERT_EQ(kevent64(kq, NULL, 0, &event, 1, 0, NULL), 1, "kevent() should have returned one event");
262 T_LOG("event = {.ident = %llx, .filter = %d, .flags = %d, .fflags = %d, .data = %lld, .udata = %llu}", event.ident, event.filter, event.flags, event.fflags, event.data, event.udata);
263 T_ASSERT_EQ(event.ident, 3ULL, NULL);
264
265 uint64_t expected_pops = ms_elapsed / 100;
266 uint64_t got_pops = (uint64_t)event.data;
267
268 T_ASSERT_GE(got_pops, expected_pops - 1, "tracking pops while asleep");
269 T_ASSERT_POSIX_ZERO(close(kq), NULL);
270 }
271