]>
Commit | Line | Data |
---|---|---|
eabd1701 | 1 | #include <dispatch/dispatch.h> |
95379394 | 2 | #include <os/assumes.h> |
eabd1701 A |
3 | #include "job_reply.h" |
4 | ||
5 | #include "launchd.h" | |
6 | #include "launch_internal.h" | |
7 | #include "vproc_internal.h" | |
8 | #include "log.h" | |
9 | ||
10 | #define ROUND_TO_64BIT_WORD_SIZE(x) ((x + 7) & ~7) | |
11 | #define LAUNCHD_DEBUG_LOG "launchd-debug.%s.log" | |
12 | #define LAUNCHD_PERF_LOG "launchd-perf.%s.log" | |
13 | #define LAUNCHD_SHUTDOWN_LOG "launchd-shutdown.%s.log" | |
14 | #define LAUNCHD_LOWLEVEL_LOG "launchd-lowlevel.%s.log" | |
15 | ||
95379394 A |
16 | os_redirect_assumes(_launchd_os_redirect); |
17 | ||
eabd1701 A |
18 | char *launchd_username = "unknown"; |
19 | char *launchd_label = "com.apple.launchd.unknown"; | |
20 | mach_port_t launchd_drain_reply_port; | |
21 | bool launchd_var_available = false; | |
22 | int64_t launchd_system_start; | |
23 | ||
24 | static FILE *_launchd_shutdown_log; | |
25 | static FILE *_launchd_debug_log; | |
26 | static FILE *_launchd_perf_log; | |
27 | static STAILQ_HEAD(, logmsg_s) _launchd_logq = STAILQ_HEAD_INITIALIZER(_launchd_logq); | |
28 | static size_t _launchd_logq_sz; | |
29 | static size_t _launchd_logq_cnt; | |
30 | static int _launchd_log_up2 = LOG_UPTO(LOG_NOTICE); | |
31 | ||
32 | static int64_t _launchd_shutdown_start; | |
33 | ||
34 | struct _launchd_open_log_ctx_s { | |
35 | const char *path; | |
36 | FILE **filep; | |
37 | }; | |
38 | ||
39 | static void | |
40 | _launchd_open_log_once(void *ctx) | |
41 | { | |
42 | struct _launchd_open_log_ctx_s *ctx2 = ctx; | |
43 | const char *path = ctx2->path; | |
44 | FILE **filep = ctx2->filep; | |
45 | ||
46 | char saved[PATH_MAX]; | |
47 | snprintf(saved, sizeof(saved), "%s.1", path); | |
48 | (void)rename(path, saved); | |
49 | ||
50 | FILE *file = fopen(path, "w"); | |
51 | if (file) { | |
52 | (void)_fd(fileno(file)); | |
53 | *filep = file; | |
54 | } else if (launchd_console) { | |
55 | fprintf(launchd_console, "Could not open %s: %d: %s\n", path, errno, strerror(errno)); | |
56 | } | |
57 | } | |
58 | ||
59 | static void | |
60 | _launchd_shutdown_start_once(void *ctx __attribute__((unused))) | |
61 | { | |
62 | _launchd_shutdown_start = runtime_get_wall_time(); | |
63 | } | |
64 | ||
65 | int | |
66 | runtime_setlogmask(int maskpri) | |
67 | { | |
68 | _launchd_log_up2 = maskpri; | |
69 | return _launchd_log_up2; | |
70 | } | |
71 | ||
72 | static bool | |
73 | _logmsg_add(struct launchd_syslog_attr *attr, int err_num, const char *msg) | |
74 | { | |
75 | size_t lm_sz = sizeof(struct logmsg_s) + strlen(msg) + strlen(attr->from_name) + strlen(attr->about_name) + strlen(attr->session_name) + 4; | |
76 | char *data_off; | |
77 | struct logmsg_s *lm; | |
78 | ||
79 | /* Force the unpacking for the log_drain cause unalignment faults. */ | |
80 | lm_sz = ROUND_TO_64BIT_WORD_SIZE(lm_sz); | |
81 | ||
82 | if (unlikely((lm = calloc(1, lm_sz)) == NULL)) { | |
83 | return false; | |
84 | } | |
85 | ||
86 | data_off = lm->data; | |
87 | ||
88 | lm->when = runtime_get_wall_time(); | |
89 | lm->from_pid = attr->from_pid; | |
90 | lm->about_pid = attr->about_pid; | |
91 | lm->err_num = err_num; | |
92 | lm->pri = attr->priority; | |
93 | lm->obj_sz = lm_sz; | |
94 | lm->msg = data_off; | |
95 | data_off += sprintf(data_off, "%s", msg) + 1; | |
96 | lm->from_name = data_off; | |
97 | data_off += sprintf(data_off, "%s", attr->from_name) + 1; | |
98 | lm->about_name = data_off; | |
99 | data_off += sprintf(data_off, "%s", attr->about_name) + 1; | |
100 | lm->session_name = data_off; | |
101 | data_off += sprintf(data_off, "%s", attr->session_name) + 1; | |
102 | ||
103 | STAILQ_INSERT_TAIL(&_launchd_logq, lm, sqe); | |
104 | _launchd_logq_sz += lm_sz; | |
105 | _launchd_logq_cnt++; | |
106 | ||
107 | return true; | |
108 | } | |
109 | ||
110 | static void | |
111 | _logmsg_remove(struct logmsg_s *lm) | |
112 | { | |
113 | STAILQ_REMOVE(&_launchd_logq, lm, logmsg_s, sqe); | |
114 | _launchd_logq_sz -= lm->obj_sz; | |
115 | _launchd_logq_cnt--; | |
116 | ||
117 | free(lm); | |
118 | } | |
119 | ||
120 | bool | |
95379394 | 121 | _launchd_os_redirect(const char *message) |
eabd1701 A |
122 | { |
123 | launchd_syslog(LOG_ERR, "%s", message); | |
124 | return true; | |
125 | } | |
126 | ||
127 | void | |
128 | launchd_syslog(int pri, const char *message, ...) | |
129 | { | |
130 | struct launchd_syslog_attr attr = { | |
131 | .from_name = launchd_label, | |
132 | .about_name = launchd_label, | |
133 | .session_name = pid1_magic ? "System" : "Background", | |
134 | .priority = pri, | |
135 | .from_uid = launchd_uid, | |
136 | .from_pid = getpid(), | |
137 | .about_pid = getpid(), | |
138 | }; | |
139 | ||
140 | va_list ap; | |
141 | ||
142 | va_start(ap, message); | |
143 | launchd_vsyslog(&attr, message, ap); | |
144 | va_end(ap); | |
145 | } | |
146 | ||
147 | void | |
148 | launchd_vsyslog(struct launchd_syslog_attr *attr, const char *fmt, va_list args) | |
149 | { | |
150 | int saved_errno = errno; | |
151 | char message[2048]; | |
152 | ||
153 | static dispatch_once_t perf_once = 0; | |
154 | static dispatch_once_t shutdown_once = 0; | |
155 | static dispatch_once_t shutdown_start_once = 0; | |
156 | static dispatch_once_t debug_once = 0; | |
157 | ||
158 | bool echo2console = (attr->priority & LOG_CONSOLE); | |
159 | attr->priority &= ~LOG_CONSOLE; | |
160 | if (attr->priority == LOG_APPLEONLY && launchd_apple_internal) { | |
161 | attr->priority = LOG_NOTICE; | |
162 | } | |
163 | ||
164 | FILE *log2here = NULL; | |
165 | ||
166 | /* launchctl is responsible for mounting /var as read-write. So we need to | |
167 | * wait until /var/log is available before trying to log anything to our log | |
168 | * anything to our auxilliary log files. This is kind of a hack because | |
169 | * we'll lose the first few relevant messages at boot for debug and | |
170 | * performance logging, but the loss isn't too bad. | |
171 | */ | |
172 | if (launchd_var_available) { | |
173 | /* This file is for logging low-level errors where we can't necessarily be | |
174 | * assured that we can write to the console or use syslog. | |
175 | */ | |
176 | char *store = launchd_copy_persistent_store(LAUNCHD_PERSISTENT_STORE_LOGS, NULL); | |
177 | char path[PATH_MAX]; | |
178 | ||
179 | if (attr->priority == LOG_PERF) { | |
180 | if (launchd_log_perf) { | |
181 | (void)snprintf(path, sizeof(path), "%s" LAUNCHD_PERF_LOG, store, launchd_username); | |
182 | ||
183 | struct _launchd_open_log_ctx_s ctx2 = { | |
184 | .path = path, | |
185 | .filep = &_launchd_perf_log, | |
186 | }; | |
187 | dispatch_once_f(&perf_once, &ctx2, _launchd_open_log_once); | |
188 | log2here = _launchd_perf_log; | |
189 | } | |
190 | ||
191 | // Don't log performance messages to the normal syslog store. | |
192 | attr->priority = LOG_DEBUG + 1; | |
193 | } else { | |
194 | if (launchd_shutting_down && launchd_log_shutdown) { | |
195 | dispatch_once_f(&shutdown_start_once, NULL, _launchd_shutdown_start_once); | |
196 | ||
197 | (void)snprintf(path, sizeof(path), "%s" LAUNCHD_SHUTDOWN_LOG, store, launchd_username); | |
198 | ||
199 | struct _launchd_open_log_ctx_s ctx2 = { | |
200 | .path = path, | |
201 | .filep = &_launchd_shutdown_log, | |
202 | }; | |
203 | dispatch_once_f(&shutdown_once, &ctx2, _launchd_open_log_once); | |
204 | log2here = _launchd_shutdown_log; | |
205 | } else if (launchd_log_debug) { | |
206 | (void)snprintf(path, sizeof(path), "%s" LAUNCHD_DEBUG_LOG, store, launchd_username); | |
207 | ||
208 | struct _launchd_open_log_ctx_s ctx2 = { | |
209 | .path = path, | |
210 | .filep = &_launchd_debug_log, | |
211 | }; | |
212 | dispatch_once_f(&debug_once, &ctx2, _launchd_open_log_once); | |
213 | log2here = _launchd_debug_log; | |
214 | } | |
215 | } | |
216 | ||
217 | free(store); | |
218 | ||
219 | } | |
220 | ||
221 | vsnprintf(message, sizeof(message), fmt, args); | |
222 | if (echo2console && launchd_console) { | |
223 | fprintf(launchd_console, "%-32s %-8u %-64s %-8u %s\n", attr->from_name, attr->from_pid, attr->about_name, attr->about_pid, message); | |
224 | } | |
225 | ||
226 | if (log2here) { | |
227 | int64_t delta = 0; | |
228 | if (log2here == _launchd_shutdown_log) { | |
229 | delta = runtime_get_wall_time() - _launchd_shutdown_start; | |
230 | } else { | |
231 | delta = runtime_get_wall_time() - launchd_system_start; | |
232 | } | |
233 | ||
234 | fprintf(log2here, "%-8lld %-32s %-8u %-24s %-8u %s\n", delta, attr->from_name, attr->from_pid, attr->about_name, attr->about_pid, message); | |
235 | } | |
236 | ||
237 | if ((LOG_MASK(attr->priority) & _launchd_log_up2)) { | |
238 | _logmsg_add(attr, saved_errno, message); | |
239 | } | |
240 | } | |
241 | ||
242 | static kern_return_t | |
243 | _launchd_log_pack(vm_offset_t *outval, mach_msg_type_number_t *outvalCnt) | |
244 | { | |
245 | struct logmsg_s *lm; | |
246 | void *offset; | |
247 | ||
248 | *outvalCnt = _launchd_logq_sz; | |
249 | ||
250 | mig_allocate(outval, *outvalCnt); | |
251 | ||
252 | if (unlikely(*outval == 0)) { | |
253 | return 1; | |
254 | } | |
255 | ||
256 | offset = (void *)*outval; | |
257 | while ((lm = STAILQ_FIRST(&_launchd_logq))) { | |
258 | lm->from_name_offset = lm->from_name - (char *)lm; | |
259 | lm->about_name_offset = lm->about_name - (char *)lm; | |
260 | lm->msg_offset = lm->msg - (char *)lm; | |
261 | lm->session_name_offset = lm->session_name - (char *)lm; | |
262 | ||
263 | memcpy(offset, lm, lm->obj_sz); | |
264 | ||
265 | offset += lm->obj_sz; | |
266 | ||
267 | _logmsg_remove(lm); | |
268 | } | |
269 | ||
270 | return 0; | |
271 | } | |
272 | ||
273 | static void | |
274 | _launchd_log_uncork_pending_drain(void) | |
275 | { | |
276 | mach_msg_type_number_t outvalCnt; | |
277 | mach_port_t tmp_port; | |
278 | vm_offset_t outval; | |
279 | ||
280 | if (!launchd_drain_reply_port) { | |
281 | return; | |
282 | } | |
283 | ||
284 | if (_launchd_logq_cnt == 0) { | |
285 | return; | |
286 | } | |
287 | ||
288 | if (_launchd_log_pack(&outval, &outvalCnt) != 0) { | |
289 | return; | |
290 | } | |
291 | ||
292 | tmp_port = launchd_drain_reply_port; | |
293 | launchd_drain_reply_port = MACH_PORT_NULL; | |
294 | ||
295 | if (unlikely(errno = job_mig_log_drain_reply(tmp_port, 0, outval, outvalCnt))) { | |
296 | if (errno != MACH_SEND_INVALID_DEST) { | |
95379394 | 297 | (void)os_assumes_zero(errno); |
eabd1701 | 298 | } |
95379394 | 299 | (void)os_assumes_zero(launchd_mport_deallocate(tmp_port)); |
eabd1701 A |
300 | } |
301 | ||
302 | mig_deallocate(outval, outvalCnt); | |
303 | } | |
304 | ||
305 | void | |
306 | launchd_log_push(void) | |
307 | { | |
308 | vm_offset_t outval = 0; | |
309 | mach_msg_type_number_t outvalCnt = 0; | |
310 | ||
311 | if (!pid1_magic) { | |
312 | if (_launchd_perf_log) { | |
313 | (void)fflush(_launchd_perf_log); | |
314 | } | |
315 | if (_launchd_shutdown_log) { | |
316 | (void)fflush(_launchd_shutdown_log); | |
317 | } | |
318 | if (_launchd_debug_log) { | |
319 | (void)fflush(_launchd_debug_log); | |
320 | } | |
321 | ||
322 | if (_launchd_logq_cnt && _launchd_log_pack(&outval, &outvalCnt) == 0) { | |
323 | (void)_vprocmgr_log_forward(inherited_bootstrap_port, (void *)outval, outvalCnt); | |
324 | mig_deallocate(outval, outvalCnt); | |
325 | } | |
326 | } else { | |
327 | _launchd_log_uncork_pending_drain(); | |
328 | } | |
329 | } | |
330 | ||
331 | kern_return_t | |
332 | launchd_log_forward(uid_t forward_uid, gid_t forward_gid, vm_offset_t inval, mach_msg_type_number_t invalCnt) | |
333 | { | |
334 | struct logmsg_s *lm, *lm_walk; | |
335 | mach_msg_type_number_t data_left = invalCnt; | |
336 | ||
337 | if (inval == 0) { | |
338 | return 0; | |
339 | } | |
340 | ||
341 | for (lm_walk = (struct logmsg_s *)inval; (data_left > 0) && (lm_walk->obj_sz <= data_left); lm_walk = ((void *)lm_walk + lm_walk->obj_sz)) { | |
342 | /* malloc(3) returns non-NULL when you ask for zero bytes. If our object | |
343 | * is zero bytes, something is wrong. | |
344 | */ | |
345 | if (lm_walk->obj_sz == 0) { | |
346 | launchd_syslog(LOG_WARNING, "Encountered a log message of size 0 with %u bytes left in forwarded data. Ignoring remaining messages.", data_left); | |
347 | break; | |
348 | } | |
349 | ||
5f168eaf A |
350 | if (lm_walk->obj_sz < sizeof(struct logmsg_s)) { |
351 | launchd_syslog(LOG_WARNING, "Received bytes %llu are less than expected bytes %lu.", lm_walk->obj_sz, sizeof(struct logmsg_s)); | |
352 | break; | |
353 | } | |
354 | ||
eabd1701 A |
355 | if (!(lm = malloc(lm_walk->obj_sz))) { |
356 | launchd_syslog(LOG_WARNING, "Failed to allocate %llu bytes for log message with %u bytes left in forwarded data. Ignoring remaining messages.", lm_walk->obj_sz, data_left); | |
357 | break; | |
358 | } | |
359 | ||
360 | memcpy(lm, lm_walk, lm_walk->obj_sz); | |
361 | lm->sender_uid = forward_uid; | |
362 | lm->sender_gid = forward_gid; | |
363 | ||
364 | lm->from_name += (size_t)lm; | |
365 | lm->about_name += (size_t)lm; | |
366 | lm->msg += (size_t)lm; | |
367 | lm->session_name += (size_t)lm; | |
368 | ||
369 | STAILQ_INSERT_TAIL(&_launchd_logq, lm, sqe); | |
370 | _launchd_logq_sz += lm->obj_sz; | |
371 | _launchd_logq_cnt++; | |
372 | ||
373 | data_left -= lm->obj_sz; | |
374 | } | |
375 | ||
376 | mig_deallocate(inval, invalCnt); | |
377 | ||
378 | return 0; | |
379 | } | |
380 | ||
381 | kern_return_t | |
382 | launchd_log_drain(mach_port_t srp, vm_offset_t *outval, mach_msg_type_number_t *outvalCnt) | |
383 | { | |
95379394 | 384 | (void)os_assumes_zero(launchd_drain_reply_port); |
eabd1701 A |
385 | |
386 | if ((_launchd_logq_cnt == 0) || launchd_shutting_down) { | |
387 | launchd_drain_reply_port = srp; | |
95379394 | 388 | (void)os_assumes_zero(launchd_mport_notify_req(launchd_drain_reply_port, MACH_NOTIFY_DEAD_NAME)); |
eabd1701 A |
389 | |
390 | return MIG_NO_REPLY; | |
391 | } | |
392 | ||
393 | return _launchd_log_pack(outval, outvalCnt); | |
394 | } | |
395 | ||
396 | void | |
397 | launchd_closelog(void) | |
398 | { | |
399 | launchd_log_push(); | |
400 | ||
401 | if (_launchd_shutdown_log) { | |
402 | (void)fflush(_launchd_shutdown_log); | |
403 | (void)runtime_fsync(fileno(_launchd_shutdown_log)); | |
404 | } | |
405 | } |