1 /*
2 * Copyright (c) 2023 Apple Inc. All rights reserved.
3 *
4 * @APPLE_OSREFERENCE_LICENSE_HEADER_START@
5 *
6 * This file contains Original Code and/or Modifications of Original Code
7 * as defined in and that are subject to the Apple Public Source License
8 * Version 2.0 (the 'License'). You may not use this file except in
9 * compliance with the License. The rights granted to you under the License
10 * may not be used to create, or enable the creation or redistribution of,
11 * unlawful or unlicensed copies of an Apple operating system, or to
12 * circumvent, violate, or enable the circumvention or violation of, any
13 * terms of an Apple operating system software license agreement.
14 *
15 * Please obtain a copy of the License at
16 * http://www.opensource.apple.com/apsl/ and read it before using this file.
17 *
18 * The Original Code and all software distributed under the License are
19 * distributed on an 'AS IS' basis, WITHOUT WARRANTY OF ANY KIND, EITHER
20 * EXPRESS OR IMPLIED, AND APPLE HEREBY DISCLAIMS ALL SUCH WARRANTIES,
21 * INCLUDING WITHOUT LIMITATION, ANY WARRANTIES OF MERCHANTABILITY,
22 * FITNESS FOR A PARTICULAR PURPOSE, QUIET ENJOYMENT OR NON-INFRINGEMENT.
23 * Please see the License for the specific language governing rights and
24 * limitations under the License.
25 *
26 * @APPLE_OSREFERENCE_LICENSE_HEADER_END@
27 */
28 #include <libproc.h>
29 #include <mach/mach.h>
30 #include <mach/mach_time.h>
31 #include <mach/task.h>
32 #include <mach/task_info.h>
33 #include <mach-o/dyld.h>
34 #include <notify.h>
35 #include <signal.h>
36 #include <stdint.h>
37 #include <strings.h>
38 #include <sys/sysctl.h>
39 #include <sys/types.h>
40 #include <TargetConditionals.h>
41 #include <unistd.h>
42
43 #include <darwintest.h>
44 #include <darwintest_utils.h>
45
46 T_GLOBAL_META(
47 T_META_NAMESPACE("kern.task"),
48 T_META_RADAR_COMPONENT_NAME("xnu"),
49 T_META_RADAR_COMPONENT_VERSION("performance"),
50 T_META_OWNER("jarrad"),
51 T_META_RUN_CONCURRENTLY(true),
52 T_META_ASROOT(true),
53 // rdar://112041307
54 T_META_REQUIRES_SYSCTL_EQ("kern.hv_vmm_present", 0));
55
56 // sleep for 1 sec between suspend/resume
57 static unsigned int sleep_duration = 1;
58
59 static uint64_t
get_thread_id(void)60 get_thread_id(void)
61 {
62 kern_return_t kr;
63 mach_msg_type_number_t count = THREAD_IDENTIFIER_INFO_COUNT;
64 thread_identifier_info_data_t data;
65 kr = thread_info(mach_thread_self(), THREAD_IDENTIFIER_INFO, (thread_info_t)&data, &count);
66 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "thread_info");
67 return data.thread_id;
68 }
69
70 static void
get_procname(char * dest,size_t size)71 get_procname(char *dest, size_t size)
72 {
73 int ret;
74 ret = proc_name(getpid(), dest, (uint32_t)size);
75 T_QUIET; T_ASSERT_GE(ret, 0, "proc_name");
76 }
77
78 static void
get_stats(task_t task,task_suspend_stats_t _Nonnull out)79 get_stats(task_t task, task_suspend_stats_t _Nonnull out)
80 {
81 kern_return_t kr;
82 mach_msg_type_number_t count = TASK_SUSPEND_STATS_INFO_COUNT;
83
84 kr = task_info(task, TASK_SUSPEND_STATS_INFO, (task_info_t)out, &count);
85 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "task_info(TASK_SUSPEND_STATS_INFO)");
86 }
87
88 static void
get_sources(task_t task,task_suspend_source_t _Nonnull out)89 get_sources(task_t task, task_suspend_source_t _Nonnull out)
90 {
91 kern_return_t kr;
92 mach_msg_type_number_t count = TASK_SUSPEND_SOURCES_INFO_COUNT;
93
94 kr = task_info(task, TASK_SUSPEND_SOURCES_INFO, (task_info_t)out, &count);
95 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "task_info(TASK_SUSPEND_SOURCES_INFO)");
96 }
97
98 static void
log_stats(mach_timebase_info_data_t timebase,uint64_t now,const char * name,task_suspend_stats_t _Nonnull stats)99 log_stats(mach_timebase_info_data_t timebase, uint64_t now, const char *name, task_suspend_stats_t _Nonnull stats)
100 {
101 uint64_t last_start_ago = (now - stats->tss_last_start) * timebase.numer / timebase.denom;
102 uint64_t last_end_ago = (now - stats->tss_last_end) * timebase.numer / timebase.denom;
103 uint64_t last_duration = (stats->tss_last_end - stats->tss_last_start) * timebase.numer / timebase.denom;
104 uint64_t total_duration = (stats->tss_duration) * timebase.numer / timebase.denom;
105
106 uint64_t nanosec = 1000000000llu;
107 T_LOG("%s: %8lld suspensions, %10lld.%09lld total secs, last start %lld.%09lld secs ago, last end %lld.%09lld secs ago, %lld.%09lld secs long",
108 name, stats->tss_count,
109 total_duration / nanosec, total_duration % nanosec,
110 last_start_ago / nanosec, last_start_ago % nanosec,
111 last_end_ago / nanosec, last_end_ago % nanosec,
112 last_duration / nanosec, last_duration % nanosec);
113 }
114
115 static void
log_sources(mach_timebase_info_data_t timebase,uint64_t now,const char * name,task_suspend_source_array_t _Nonnull sources)116 log_sources(mach_timebase_info_data_t timebase, uint64_t now, const char *name, task_suspend_source_array_t _Nonnull sources)
117 {
118 uint64_t nanosec = 1000000000llu;
119 for (int i = 0; i < TASK_SUSPEND_SOURCES_MAX; i++) {
120 task_suspend_source_t source = &sources[i];
121 uint64_t source_ago = (now - source->tss_time) * timebase.numer / timebase.denom;
122 T_LOG("%s suspender #%d: start %lld.%09lld secs ago, pid %d, tid %llu, procname \"%s\"",
123 name, i, source_ago / nanosec, source_ago % nanosec, source->tss_pid, source->tss_tid, source->tss_procname);
124 }
125 }
126
127 static void
log_time(mach_timebase_info_data_t timebase,uint64_t now,uint64_t time,const char * name)128 log_time(mach_timebase_info_data_t timebase, uint64_t now, uint64_t time, const char *name)
129 {
130 uint64_t nanosec = 1000000000llu;
131 uint64_t time_ago = (now - time) * timebase.numer / timebase.denom;
132 T_LOG("%s: %lld.%09lld secs ago",
133 name, time_ago / nanosec, time_ago % nanosec);
134 }
135
136 static void
verify_source(task_suspend_source_t source)137 verify_source(task_suspend_source_t source)
138 {
139 char procname[65];
140 get_procname(procname, sizeof(procname));
141
142 T_EXPECT_EQ(source->tss_pid, getpid(), "suspend source should mark suspender as current task");
143 T_EXPECT_EQ(source->tss_tid, get_thread_id(), "suspend source should mark suspender as current thread");
144 T_EXPECT_GT(source->tss_time, 0ull, "suspend source should have non-zero time");
145 T_EXPECT_EQ_STR(source->tss_procname, procname, "suspend source should have procname matching current proc");
146 }
147
148 static void
verify_stats(mach_timebase_info_data_t timebase,task_suspend_stats_t _Nonnull pre,task_suspend_stats_t _Nonnull post)149 verify_stats(mach_timebase_info_data_t timebase, task_suspend_stats_t _Nonnull pre, task_suspend_stats_t _Nonnull post)
150 {
151 uint64_t now = mach_absolute_time();
152
153 log_stats(timebase, now, " pre", pre);
154 log_stats(timebase, now, " post", post);
155
156 int64_t delta_suspensions = (int64_t)(post->tss_count - pre->tss_count);
157 int64_t delta_duration = (int64_t)(post->tss_duration - pre->tss_duration) * (int64_t)timebase.numer / (int64_t)timebase.denom;
158 int64_t delta_nsec = delta_duration % 1000000000ll;
159 if (delta_nsec < 0) {
160 delta_nsec += 1000000000ll;
161 }
162 T_LOG("delta: %+8lld suspensions, %+10lld.%09lld total nsecs", delta_suspensions, delta_duration / 1000000000ll, delta_nsec);
163
164 T_EXPECT_LT(pre->tss_count, post->tss_count, "suspension count should increase when task is suspended");
165 T_EXPECT_LT(pre->tss_duration, post->tss_duration, "suspension duration should increase when task is suspended");
166 T_EXPECT_LT(post->tss_last_start, post->tss_last_end, "post: suspension should take time");
167 }
168
169 static int
spawn_helper(char * helper)170 spawn_helper(char *helper)
171 {
172 char **launch_tool_args;
173 char testpath[PATH_MAX];
174 uint32_t testpath_buf_size;
175 int ret;
176 pid_t child_pid;
177
178 testpath_buf_size = sizeof(testpath);
179 ret = _NSGetExecutablePath(testpath, &testpath_buf_size);
180 T_QUIET; T_ASSERT_POSIX_ZERO(ret, "_NSGetExecutablePath");
181 T_LOG("Executable path: %s", testpath);
182 launch_tool_args = (char *[]){
183 testpath,
184 "-n",
185 helper,
186 NULL
187 };
188
189 // Spawn the child process
190 ret = dt_launch_tool(&child_pid, launch_tool_args, false, NULL, NULL);
191 if (ret != 0) {
192 T_LOG("dt_launch tool returned %d with error code %d", ret, errno);
193 }
194 T_QUIET; T_ASSERT_POSIX_SUCCESS(child_pid, "dt_launch_tool");
195
196 return child_pid;
197 }
198
199 static void
wakeup_helper(pid_t pid)200 wakeup_helper(pid_t pid)
201 {
202 int ret = kill(pid, SIGKILL);
203 T_QUIET; T_ASSERT_POSIX_ZERO(ret, "kill()");
204 }
205
206 T_HELPER_DECL(wait_for_finished,
207 "spin waiting for signal",
208 T_META_CHECK_LEAKS(false))
209 {
210 pause();
211 exit(0);
212 }
213
214 T_DECL(get_suspend_stats,
215 "test that task suspension statistics can be read out")
216 {
217 mach_timebase_info_data_t timebase = {0, 0};
218 mach_timebase_info(&timebase);
219
220 struct task_suspend_stats_s stats;
221
222 get_stats(current_task(), &stats);
223 log_stats(timebase, mach_absolute_time(), "stats", &stats);
224 }
225
226 T_DECL(get_suspend_sources,
227 "test that task suspension debug info can be read out")
228 {
229 mach_timebase_info_data_t timebase = {0, 0};
230 mach_timebase_info(&timebase);
231
232 task_suspend_source_array_t sources;
233
234 get_sources(current_task(), sources);
235 log_sources(timebase, mach_absolute_time(), "sources", sources);
236 }
237
238 T_DECL(suspend_stats_update_on_pidsuspend,
239 "test that task suspension info are updated on pidsuspend")
240 {
241 kern_return_t kr;
242 pid_t child_pid;
243 task_t child_task;
244 int rc;
245 struct task_suspend_stats_s pre, post;
246 task_suspend_source_array_t sources;
247 mach_timebase_info_data_t timebase = {0, 0};
248
249 mach_timebase_info(&timebase);
250
251 child_pid = spawn_helper("wait_for_finished");
252 kr = task_for_pid(mach_task_self(), child_pid, &child_task);
253 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "task_for_pid(%d)", child_pid);
254
255 get_stats(child_task, &pre);
256
257 T_LOG("Suspending helper...");
258 rc = pid_suspend(child_pid);
259 T_QUIET; T_ASSERT_POSIX_SUCCESS(rc, "pid_suspend");
260
261 T_LOG("Sleeping %d sec...", sleep_duration);
262 sleep(sleep_duration);
263
264 T_LOG("Resuming helper...");
265 rc = pid_resume(child_pid);
266 T_QUIET; T_ASSERT_POSIX_SUCCESS(rc, "pid_resume");
267
268 get_stats(child_task, &post);
269 verify_stats(timebase, &pre, &post);
270 get_sources(child_task, sources);
271 log_sources(timebase, mach_absolute_time(), "sources", sources);
272 verify_source(&sources[0]);
273
274 wakeup_helper(child_pid);
275 mach_port_deallocate(mach_task_self(), child_task);
276 }
277
278 T_DECL(suspend_stats_update_on_task_suspend,
279 "test that task suspension info are updated on task_suspend")
280 {
281 kern_return_t kr;
282 pid_t child_pid;
283 task_t child_task;
284 struct task_suspend_stats_s pre, post;
285 task_suspend_source_array_t sources;
286 mach_timebase_info_data_t timebase = {0, 0};
287
288 mach_timebase_info(&timebase);
289
290 child_pid = spawn_helper("wait_for_finished");
291 kr = task_for_pid(mach_task_self(), child_pid, &child_task);
292 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "task_for_pid(%d)", child_pid);
293
294 get_stats(child_task, &pre);
295
296 T_LOG("Suspending helper...");
297 kr = task_suspend(child_task);
298 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "task_suspend");
299
300 T_LOG("Sleeping %d sec...", sleep_duration);
301 sleep(sleep_duration);
302
303 T_LOG("Resuming helper...");
304 kr = task_resume(child_task);
305 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "task_resume");
306
307 get_stats(child_task, &post);
308 verify_stats(timebase, &pre, &post);
309 get_sources(child_task, sources);
310 log_sources(timebase, mach_absolute_time(), "sources", sources);
311 verify_source(&sources[0]);
312
313 wakeup_helper(child_pid);
314 mach_port_deallocate(mach_task_self(), child_task);
315 }
316
317 T_DECL(suspend_stats_update_on_forkcorpse,
318 "test that task suspension info are updated on fork corpse")
319 {
320 kern_return_t kr;
321 pid_t child_pid;
322 task_t child_task;
323 mach_port_t cp;
324 struct task_suspend_stats_s pre, post;
325 task_suspend_source_array_t sources;
326 mach_timebase_info_data_t timebase = {0, 0};
327
328 mach_timebase_info(&timebase);
329
330 child_pid = spawn_helper("wait_for_finished");
331 kr = task_for_pid(mach_task_self(), child_pid, &child_task);
332 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "task_for_pid(%d)", child_pid);
333
334 get_stats(child_task, &pre);
335
336 T_LOG("Generating corpse of helper...");
337 kr = task_generate_corpse(child_task, &cp);
338 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "task_generate_corpse");
339
340 get_stats(child_task, &post);
341 verify_stats(timebase, &pre, &post);
342 get_sources(child_task, sources);
343 log_sources(timebase, mach_absolute_time(), "sources", sources);
344 verify_source(&sources[0]);
345
346 kr = mach_port_deallocate(mach_task_self(), cp);
347 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "mach_port_deallocate");
348
349 wakeup_helper(child_pid);
350 kr = mach_port_deallocate(mach_task_self(), child_task);
351 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "mach_port_deallocate");
352 }
353
354 #define NUM_SUSPEND_RESUME (TASK_SUSPEND_SOURCES_MAX * 2)
355 T_DECL(suspend_source_created_for_every_suspend,
356 "test that suspend sources are created for every suspend call")
357 {
358 kern_return_t kr;
359 pid_t child_pid;
360 task_t child_task;
361 struct task_suspend_stats_s pre, post;
362 task_suspend_source_array_t sources;
363 mach_timebase_info_data_t timebase = {0, 0};
364 uint64_t first_suspend_time = 0;
365
366 mach_timebase_info(&timebase);
367
368 child_pid = spawn_helper("wait_for_finished");
369 kr = task_for_pid(mach_task_self(), child_pid, &child_task);
370 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "task_for_pid(%d)", child_pid);
371
372 get_stats(child_task, &pre);
373
374 T_LOG("Suspending helper...");
375
376 for (int i = 0; i < NUM_SUSPEND_RESUME; i++) {
377 kr = task_suspend(child_task);
378 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "task_suspend");
379 if (i == 0) {
380 first_suspend_time = mach_absolute_time();
381 }
382 }
383
384 T_LOG("Sleeping %d sec...", sleep_duration);
385 sleep(sleep_duration);
386
387 T_LOG("Resuming helper...");
388 for (int i = 0; i < NUM_SUSPEND_RESUME; i++) {
389 kr = task_resume(child_task);
390 T_QUIET; T_ASSERT_MACH_SUCCESS(kr, "task_resume");
391 }
392
393 uint64_t now = mach_absolute_time();
394
395 get_stats(child_task, &post);
396 verify_stats(timebase, &pre, &post);
397 get_sources(child_task, sources);
398 log_sources(timebase, now, "sources", sources);
399 log_time(timebase, now, first_suspend_time, "first_suspend");
400
401 for (int i = 0; i < TASK_SUSPEND_SOURCES_MAX; i++) {
402 T_LOG("Verifying suspender no. %d", i);
403 task_suspend_source_t source = &sources[i];
404 verify_source(source);
405 T_EXPECT_LT(source->tss_time, post.tss_last_end, "suspend source timestamp should be < last suspension end");
406 T_EXPECT_GT(source->tss_time, first_suspend_time, "suspend source timestamp should be > first suspend");
407 }
408
409 wakeup_helper(child_pid);
410 mach_port_deallocate(mach_task_self(), child_task);
411 }
412