1 #include <dispatch/dispatch.h>
2 #include <os/assumes.h>
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
16 os_redirect_assumes(_launchd_os_redirect);
17
18 const char *launchd_username = "unknown";
19 const 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
_launchd_open_log_once(void * ctx)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
_launchd_shutdown_start_once(void * ctx)60 _launchd_shutdown_start_once(void *ctx __attribute__((unused)))
61 {
62 _launchd_shutdown_start = runtime_get_wall_time();
63 }
64
65 int
runtime_setlogmask(int maskpri)66 runtime_setlogmask(int maskpri)
67 {
68 _launchd_log_up2 = maskpri;
69 return _launchd_log_up2;
70 }
71
72 static bool
_logmsg_add(struct launchd_syslog_attr * attr,int err_num,const char * msg)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
_logmsg_remove(struct logmsg_s * lm)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
_launchd_os_redirect(const char * message)121 _launchd_os_redirect(const char *message)
122 {
123 launchd_syslog(LOG_ERR, "%s", message);
124 return true;
125 }
126
127 void
launchd_syslog(int pri,const char * message,...)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
launchd_vsyslog(struct launchd_syslog_attr * attr,const char * fmt,va_list args)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, "%-8zd %-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
_launchd_log_pack(vm_offset_t * outval,mach_msg_type_number_t * outvalCnt)243 _launchd_log_pack(vm_offset_t *outval, mach_msg_type_number_t *outvalCnt)
244 {
245 struct logmsg_s *lm;
246 uint8_t *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 = (uint8_t *)*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
_launchd_log_uncork_pending_drain(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) {
297 (void)os_assumes_zero(errno);
298 }
299 (void)os_assumes_zero(launchd_mport_deallocate(tmp_port));
300 }
301
302 mig_deallocate(outval, outvalCnt);
303 }
304
305 void
launchd_log_push(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
launchd_log_forward(uid_t forward_uid,gid_t forward_gid,vm_offset_t inval,mach_msg_type_number_t invalCnt)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 = (struct logmsg_s *)((uint64_t *)lm_walk + lm_walk->obj_sz/8)) {
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
350 if (lm_walk->obj_sz < sizeof(struct logmsg_s)) {
351 launchd_syslog(LOG_WARNING, "Received bytes %zu are less than expected bytes %lu.", lm_walk->obj_sz, sizeof(struct logmsg_s));
352 break;
353 }
354
355 if (!(lm = malloc(lm_walk->obj_sz))) {
356 launchd_syslog(LOG_WARNING, "Failed to allocate %zu 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
launchd_log_drain(mach_port_t srp,vm_offset_t * outval,mach_msg_type_number_t * outvalCnt)382 launchd_log_drain(mach_port_t srp, vm_offset_t *outval, mach_msg_type_number_t *outvalCnt)
383 {
384 (void)os_assumes_zero(launchd_drain_reply_port);
385
386 if ((_launchd_logq_cnt == 0) || launchd_shutting_down) {
387 launchd_drain_reply_port = srp;
388 (void)os_assumes_zero(launchd_mport_notify_req(launchd_drain_reply_port, MACH_NOTIFY_DEAD_NAME));
389
390 return MIG_NO_REPLY;
391 }
392
393 return _launchd_log_pack(outval, outvalCnt);
394 }
395
396 void
launchd_closelog(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 }
406