git.saurik.com Git - apple/xnu.git/blob

1 /*

3 *

4 * @APPLE_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. Please obtain a copy of the License at

10 * http://www.opensource.apple.com/apsl/ and read it before using this

11 * file.

12 *

13 * The Original Code and all software distributed under the License are

14 * distributed on an 'AS IS' basis, WITHOUT WARRANTY OF ANY KIND, EITHER

15 * EXPRESS OR IMPLIED, AND APPLE HEREBY DISCLAIMS ALL SUCH WARRANTIES,

16 * INCLUDING WITHOUT LIMITATION, ANY WARRANTIES OF MERCHANTABILITY,

17 * FITNESS FOR A PARTICULAR PURPOSE, QUIET ENJOYMENT OR NON-INFRINGEMENT.

18 * Please see the License for the specific language governing rights and

19 * limitations under the License.

20 *

21 * @APPLE_LICENSE_HEADER_END@

22 */

24 #include <stdbool.h>

25 #include <firehose/tracepoint_private.h>

26 #include <kern/assert.h>

27 #include <kern/counter.h>

28 #include <kern/locks.h>

29 #include <pexpert/pexpert.h>

30 #include <sys/param.h>

32 #if __has_feature(ptrauth_calls)

33 #include <mach/vm_param.h>

34 #include <ptrauth.h>

35 #endif /* __has_feature(ptrauth_calls) */

37 #include "log_encode.h"

38 #include "log_mem.h"

 #define isdigit(ch) (((ch) >= '0') && ((ch) <= '9'))

41 #define log_context_cursor(ctx) &(ctx)->ctx_hdr->hdr_data[(ctx)->ctx_content_off]

43 extern boolean_t doprnt_hide_pointers;

45 SCALABLE_COUNTER_DEFINE(oslog_p_fmt_invalid_msgcount);

46 SCALABLE_COUNTER_DEFINE(oslog_p_fmt_max_args_msgcount);

47 SCALABLE_COUNTER_DEFINE(oslog_p_truncated_msgcount);

49 static bool

 is_kernel_pointer(void *arg, size_t arg_len)

51 {

         if (arg_len < sizeof(void *)) {

53 return false;

54 }

56 unsigned long long value = 0;

         assert(arg_len <= sizeof(value));

         (void) memcpy(&value, arg, arg_len);

60 #if __has_feature(ptrauth_calls)

61 /**

62 * Strip out the pointer authentication code before

63 * checking whether the pointer is a kernel address.

64 */

         value = (unsigned long long)VM_KERNEL_STRIP_PTR(value);

66 #endif /* __has_feature(ptrauth_calls) */

         return value >= VM_MIN_KERNEL_AND_KEXT_ADDRESS && value <= VM_MAX_KERNEL_ADDRESS;

69 }

71 static void

 log_context_cursor_advance(os_log_context_t ctx, size_t amount)

73 {

74 ctx->ctx_content_off += amount;

         assert(log_context_cursor(ctx) <= (ctx->ctx_buffer + ctx->ctx_buffer_sz));

76 }

78 static bool

 log_fits(os_log_context_t ctx, size_t data_size)

80 {

         return (ctx->ctx_content_off + data_size) <= ctx->ctx_content_sz;

82 }

84 static bool

 log_fits_cmd(os_log_context_t ctx, size_t data_size)

86 {

         return log_fits(ctx, sizeof(*ctx->ctx_hdr) + data_size);

88 }

90 static void

 log_range_update(os_log_fmt_range_t range, uint16_t offset, uint16_t length)

92 {

93 range->offset = offset;

94 /*

95 * Truncated flag may have already been set earlier, hence do not

96 * overwrite it blindly.

97 */

         if (length < range->length) {

99 range->truncated = true;

100 }

101 range->length = length;

102 }

103

104 /*

105 * Stores a command in the main section. The value itself is wrapped in

106 * the os_log_fmt_cmd_t struct.

107 */

108 static void

 log_add_cmd(os_log_context_t ctx, os_log_fmt_cmd_type_t type, uint8_t flags,

     void *arg, size_t arg_size)

111 {

112 os_log_fmt_cmd_t cmd;

         const size_t cmd_sz = sizeof(*cmd) + arg_size;

114

         assert(log_fits_cmd(ctx, cmd_sz));

116 assert(arg_size <= UINT8_MAX);

117

         cmd = (os_log_fmt_cmd_t)log_context_cursor(ctx);

119 cmd->cmd_type = type;

120 cmd->cmd_flags = flags;

         cmd->cmd_size = (uint8_t)arg_size;

         (void) memcpy(cmd->cmd_data, arg, cmd->cmd_size);

123

         assert(cmd_sz == sizeof(*cmd) + cmd->cmd_size);

125 log_context_cursor_advance(ctx, cmd_sz);

126 }

127

128 /*

129 * Collect details about argument which needs to be stored in the pubdata

130 * section.

131 */

132 static void

 log_collect_public_range_data(os_log_context_t ctx, os_log_fmt_range_t range, void *arg)

134 {

         ctx->ctx_pubdata[ctx->ctx_pubdata_cnt++] = (char *)arg;

136 ctx->ctx_pubdata_sz += range->length;

137 }

138

139 static void

 log_add_range_data(os_log_context_t ctx, os_log_fmt_range_t range, void *arg)

141 {

         assert(log_fits(ctx, range->length));

         (void) memcpy(log_context_cursor(ctx), arg, range->length);

         log_context_cursor_advance(ctx, range->length);

145 }

146

147 static struct os_log_fmt_range_s

 log_create_range(os_log_context_t ctx, size_t arg_len)

149 {

         const size_t final_arg_len = MIN(arg_len, UINT16_MAX);

151

152 return (struct os_log_fmt_range_s) {

153 .offset = ctx->ctx_pubdata_sz,

                        .length = (uint16_t)final_arg_len,

155 .truncated = (final_arg_len < arg_len)

156 };

157 }

158

159 static int

 log_add_range_arg(os_log_context_t ctx, os_log_fmt_cmd_type_t type, os_log_fmt_cmd_flags_t flags,

     void *arg, size_t arg_len)

162 {

163 struct os_log_fmt_range_s range;

164

         if (!log_fits_cmd(ctx, sizeof(range))) {

166 return ENOMEM;

167 }

168

         range = log_create_range(ctx, arg_len);

170

171 if (flags == OSLF_CMD_FLAG_PUBLIC) {

                 if (ctx->ctx_pubdata_cnt == OS_LOG_MAX_PUB_ARGS) {

173 return ENOMEM;

174 }

                 assert(ctx->ctx_pubdata_cnt < OS_LOG_MAX_PUB_ARGS);

                 log_collect_public_range_data(ctx, &range, arg);

177 }

         log_add_cmd(ctx, type, flags, &range, sizeof(range));

179 ctx->ctx_hdr->hdr_cmd_cnt++;

180

181 return 0;

182 }

183

184 /*

185 * Adds a scalar argument value to the main section.

186 */

187 static int

 log_add_arg(os_log_context_t ctx, os_log_fmt_cmd_type_t type, void *arg, size_t arg_len)

189 {

         assert(type == OSLF_CMD_TYPE_COUNT || type == OSLF_CMD_TYPE_SCALAR);

191 assert(arg_len < UINT16_MAX);

192

         if (log_fits_cmd(ctx, arg_len)) {

                 log_add_cmd(ctx, type, OSLF_CMD_FLAG_PUBLIC, arg, arg_len);

195 ctx->ctx_hdr->hdr_cmd_cnt++;

196 return 0;

197 }

198

199 return ENOMEM;

200 }

201

202 static void

203 log_encode_public_data(os_log_context_t ctx)

204 {

205 const uint16_t orig_content_off = ctx->ctx_content_off;

206 os_log_fmt_hdr_t const hdr = ctx->ctx_hdr;

207 os_log_fmt_cmd_t cmd = (os_log_fmt_cmd_t)hdr->hdr_data;

208

         assert(ctx->ctx_pubdata_cnt <= hdr->hdr_cmd_cnt);

210

         for (int i = 0, pub_i = 0; i < hdr->hdr_cmd_cnt; i++, cmd = (os_log_fmt_cmd_t)(cmd->cmd_data + cmd->cmd_size)) {

                 if (cmd->cmd_type != OSLF_CMD_TYPE_STRING) {

213 continue;

214 }

215

                 os_log_fmt_range_t const range __attribute__((aligned(8))) = (os_log_fmt_range_t)&cmd->cmd_data;

217

218 // Fix offset and length of the argument data in the hdr.

                 log_range_update(range, ctx->ctx_content_off - orig_content_off,

                     MIN(range->length, ctx->ctx_content_sz - ctx->ctx_content_off));

221

222 if (range->truncated) {

223 ctx->ctx_truncated = true;

224 }

225

                 assert(pub_i < ctx->ctx_pubdata_cnt);

                 log_add_range_data(ctx, range, ctx->ctx_pubdata[pub_i++]);

228 }

229 }

230

231 static bool

 log_expand(os_log_context_t ctx, size_t new_size)

233 {

         assert(new_size > ctx->ctx_buffer_sz);

235

236 if (!oslog_is_safe()) {

237 return false;

238 }

239

240 size_t final_size = new_size;

241

         void *buf = logmem_alloc(ctx->ctx_logmem, &final_size);

243 if (!buf) {

244 return false;

245 }

246 assert(final_size >= new_size);

247

248 // address length header + already stored data

         const size_t hdr_size = (uint8_t *)ctx->ctx_hdr - ctx->ctx_buffer;

         const size_t copy_size = hdr_size + sizeof(*ctx->ctx_hdr) + ctx->ctx_content_sz;

251 assert(copy_size <= new_size);

         (void) memcpy(buf, ctx->ctx_buffer, copy_size);

253

254 if (ctx->ctx_allocated) {

                 logmem_free(ctx->ctx_logmem, ctx->ctx_buffer, ctx->ctx_buffer_sz);

256 }

257

258 ctx->ctx_buffer = buf;

259 ctx->ctx_buffer_sz = final_size;

         ctx->ctx_content_sz = (uint16_t)(ctx->ctx_buffer_sz - hdr_size - sizeof(*ctx->ctx_hdr));

         ctx->ctx_hdr = (os_log_fmt_hdr_t)&ctx->ctx_buffer[hdr_size];

262 ctx->ctx_allocated = true;

263

264 return true;

265 }

266

267 static int

 log_encode_fmt_arg(void *arg, size_t arg_len, os_log_fmt_cmd_type_t type, os_log_context_t ctx)

269 {

270 int rc = 0;

271

272 switch (type) {

273 case OSLF_CMD_TYPE_COUNT:

274 case OSLF_CMD_TYPE_SCALAR:

275 // Scrub kernel pointers.

                 if (doprnt_hide_pointers && is_kernel_pointer(arg, arg_len)) {

                         rc = log_add_range_arg(ctx, type, OSLF_CMD_FLAG_PRIVATE, NULL, 0);

278 ctx->ctx_hdr->hdr_flags |= OSLF_HDR_FLAG_HAS_PRIVATE;

279 } else {

                         rc = log_add_arg(ctx, type, arg, arg_len);

281 }

282 break;

283 case OSLF_CMD_TYPE_STRING:

                 rc = log_add_range_arg(ctx, type, OSLF_CMD_FLAG_PUBLIC, arg, arg_len);

285 ctx->ctx_hdr->hdr_flags |= OSLF_HDR_FLAG_HAS_NON_SCALAR;

286 break;

287 default:

288 panic("Unsupported log value type");

289 }

290

291 return rc;

292 }

293

294 static int

 log_encode_fmt(os_log_context_t ctx, const char *format, va_list args)

296 {

         const char *percent = strchr(format, '%');

298

299 while (percent != NULL) {

300 ++percent;

301

                 if (percent[0] == '%') {

                         percent = strchr(percent + 1, '%'); // Find next format after %%

304 continue;

305 }

306

307 struct os_log_format_value_s value;

308 int type = OST_INT;

309 int prec = 0;

310 char ch;

311

                 for (bool done = false; !done; percent++) {

313 int err = 0;

314

                         switch (ch = percent[0]) {

316 /* type of types or other */

317 case 'l': // longer

318 type++;

319 break;

320

321 case 'h': // shorter

322 type--;

323 break;

324

325 case 'z':

326 type = OST_SIZE;

327 break;

328

329 case 'j':

330 type = OST_INTMAX;

331 break;

332

333 case 't':

334 type = OST_PTRDIFF;

335 break;

336

337 case 'q':

338 type = OST_LONGLONG;

339 break;

340

341 case '.': // precision

                                 if ((percent[1]) == '*') {

                                         prec = va_arg(args, int);

                                         err = log_encode_fmt_arg(&prec, sizeof(prec), OSLF_CMD_TYPE_COUNT, ctx);

                                         if (slowpath(err)) {

346 return err;

347 }

348 percent++;

349 continue;

350 } else {

351 // we have to read the precision and do the right thing

                                         const char *fmt = percent + 1;

353 prec = 0;

                                         while (isdigit(ch = *fmt++)) {

                                                 prec = 10 * prec + (ch - '0');

356 }

357

                                         if (prec > 1024) {

359 prec = 1024;

360 }

361

                                         err = log_encode_fmt_arg(&prec, sizeof(prec), OSLF_CMD_TYPE_COUNT, ctx);

363 }

364 break;

365

366 case '-': // left-align

367 case '+': // force sign

368 case ' ': // prefix non-negative with space

369 case '#': // alternate

                         case '\'': // group by thousands

371 break;

372

373 /* fixed types */

374 case 'd': // integer

375 case 'i': // integer

376 case 'o': // octal

377 case 'u': // unsigned

378 case 'x': // hex

379 case 'X': // upper-hex

380 switch (type) {

381 case OST_CHAR:

                                         value.type.ch = (char) va_arg(args, int);

                                         err = log_encode_fmt_arg(&value.type.ch, sizeof(value.type.ch), OSLF_CMD_TYPE_SCALAR, ctx);

384 break;

385

386 case OST_SHORT:

                                         value.type.s = (short) va_arg(args, int);

                                         err = log_encode_fmt_arg(&value.type.s, sizeof(value.type.s), OSLF_CMD_TYPE_SCALAR, ctx);

389 break;

390

391 case OST_INT:

                                         value.type.i = va_arg(args, int);

                                         err = log_encode_fmt_arg(&value.type.i, sizeof(value.type.i), OSLF_CMD_TYPE_SCALAR, ctx);

394 break;

395

396 case OST_LONG:

                                         value.type.l = va_arg(args, long);

                                         err = log_encode_fmt_arg(&value.type.l, sizeof(value.type.l), OSLF_CMD_TYPE_SCALAR, ctx);

399 break;

400

401 case OST_LONGLONG:

                                         value.type.ll = va_arg(args, long long);

                                         err = log_encode_fmt_arg(&value.type.ll, sizeof(value.type.ll), OSLF_CMD_TYPE_SCALAR, ctx);

404 break;

405

406 case OST_SIZE:

                                         value.type.z = va_arg(args, size_t);

                                         err = log_encode_fmt_arg(&value.type.z, sizeof(value.type.z), OSLF_CMD_TYPE_SCALAR, ctx);

409 break;

410

411 case OST_INTMAX:

                                         value.type.im = va_arg(args, intmax_t);

                                         err = log_encode_fmt_arg(&value.type.im, sizeof(value.type.im), OSLF_CMD_TYPE_SCALAR, ctx);

414 break;

415

416 case OST_PTRDIFF:

                                         value.type.pd = va_arg(args, ptrdiff_t);

                                         err = log_encode_fmt_arg(&value.type.pd, sizeof(value.type.pd), OSLF_CMD_TYPE_SCALAR, ctx);

419 break;

420

421 default:

422 return EINVAL;

423 }

424 done = true;

425 break;

426

427 case 'p': // pointer

                                 value.type.p = va_arg(args, void *);

                                 err = log_encode_fmt_arg(&value.type.p, sizeof(value.type.p), OSLF_CMD_TYPE_SCALAR, ctx);

430 done = true;

431 break;

432

433 case 'c': // char

                                 value.type.ch = (char) va_arg(args, int);

                                 err = log_encode_fmt_arg(&value.type.ch, sizeof(value.type.ch), OSLF_CMD_TYPE_SCALAR, ctx);

436 done = true;

437 break;

438

439 case 's': // string

                                 value.type.pch = va_arg(args, char *);

                                 if (prec == 0 && value.type.pch) {

                                         prec = (int) strlen(value.type.pch) + 1;

443 }

                                 err = log_encode_fmt_arg(value.type.pch, prec, OSLF_CMD_TYPE_STRING, ctx);

445 prec = 0;

446 done = true;

447 break;

448

449 case 'm':

                                 value.type.i = 0; // Does %m make sense in the kernel?

                                 err = log_encode_fmt_arg(&value.type.i, sizeof(value.type.i), OSLF_CMD_TYPE_SCALAR, ctx);

452 done = true;

453 break;

454

455 default:

                                 if (isdigit(ch)) { // [0-9]

457 continue;

458 }

459 return EINVAL;

460 }

461

                         if (slowpath(err)) {

463 return err;

464 }

465

466 if (done) {

                                 percent = strchr(percent, '%'); // Find next format

468 break;

469 }

470 }

471 }

472

473 return 0;

474 }

475

476 static inline size_t

 write_address_location(uint8_t buf[static sizeof(uint64_t)],

     void *dso, const void *address, firehose_tracepoint_flags_t *flags, bool driverKit)

479 {

         uintptr_t shift_addr = (uintptr_t)address - (uintptr_t)dso;

481

482 kc_format_t kcformat = KCFormatUnknown;

         __assert_only bool result = PE_get_primary_kc_format(&kcformat);

484 assert(result);

485

         if (kcformat == KCFormatStatic || kcformat == KCFormatKCGEN) {

487 *flags = _firehose_tracepoint_flags_pc_style_shared_cache;

                 memcpy(buf, (uint32_t[]){ (uint32_t)shift_addr }, sizeof(uint32_t));

489 return sizeof(uint32_t);

490 }

491

492 /*

493 * driverKit will have the dso set as MH_EXECUTE (it is logging from a

494 * syscall in the kernel) but needs logd to parse the address as an

495 * absolute pc.

496 */

497 kernel_mach_header_t *mh = dso;

         if (mh->filetype == MH_EXECUTE && !driverKit) {

499 *flags = _firehose_tracepoint_flags_pc_style_main_exe;

                 memcpy(buf, (uint32_t[]){ (uint32_t)shift_addr }, sizeof(uint32_t));

501 return sizeof(uint32_t);

502 }

503

504 *flags = _firehose_tracepoint_flags_pc_style_absolute;

         shift_addr = driverKit ? (uintptr_t)address : VM_KERNEL_UNSLIDE(address);

         size_t len = sizeof(uintptr_t);

507

508 #if __LP64__

509 len = 6; // 48 bits are enough

510 #endif

         memcpy(buf, (uintptr_t[]){ shift_addr }, len);

512

513 return len;

514 }

515

516 static void

 os_log_encode_location(os_log_context_t ctx, void *addr, void *dso, bool driverKit,

518 firehose_tracepoint_flags_t *ft_flags)

519 {

         const size_t hdr_size = write_address_location(ctx->ctx_buffer, dso, addr, ft_flags, driverKit);

         ctx->ctx_hdr = (os_log_fmt_hdr_t)&ctx->ctx_buffer[hdr_size];

         ctx->ctx_content_sz = (uint16_t)(ctx->ctx_buffer_sz - hdr_size - sizeof(*ctx->ctx_hdr));

523 }

524

525 /*

526 * Encodes argument (meta)data into a format consumed by libtrace. Stores

527 * metadada for all arguments first. Metadata also include scalar argument

528 * values. Second step saves data which are encoded separately from respective

529 * metadata (like strings).

530 */

531 bool

 os_log_context_encode(os_log_context_t ctx, const char *fmt, va_list args, void *addr, void *dso, bool driverKit)

533 {

         os_log_encode_location(ctx, addr, dso, driverKit, &ctx->ctx_ft_flags);

535

536 va_list args_copy;

537 va_copy(args_copy, args);

538

         int rc = log_encode_fmt(ctx, fmt, args);

540

541 va_end(args_copy);

542

543 switch (rc) {

544 case EINVAL:

545 // Bogus/Unsupported fmt string

546 counter_inc(&oslog_p_fmt_invalid_msgcount);

547 return false;

548 case ENOMEM:

549 /*

550 * The fmt contains unreasonable number of arguments (> 32) and

551 * we ran out of space. We could call log_expand()

552 * here and retry. However, using such formatting strings rather

553 * seem like a misuse of the logging system, hence error.

554 */

555 counter_inc(&oslog_p_fmt_max_args_msgcount);

556 return false;

557 case 0:

558 break;

559 default:

560 panic("unhandled return value");

561 }

562

         if (ctx->ctx_pubdata_sz == 0) {

564 goto finish;

565 }

566

         if (!log_fits(ctx, ctx->ctx_pubdata_sz)) {

                 size_t space_needed = log_context_cursor(ctx) + ctx->ctx_pubdata_sz - ctx->ctx_buffer;

                 space_needed = MIN(space_needed, logmem_max_size(ctx->ctx_logmem));

                 (void) log_expand(ctx, space_needed);

571 }

572

573 log_encode_public_data(ctx);

574

575 if (ctx->ctx_truncated) {

576 counter_inc(&oslog_p_truncated_msgcount);

577 }

578 finish:

         ctx->ctx_content_sz = (uint16_t)(log_context_cursor(ctx) - ctx->ctx_buffer);

580 ctx->ctx_content_off = 0;

581 return true;

582 }

583

584 void

 os_log_context_init(os_log_context_t ctx, logmem_t *logmem, uint8_t *buffer, size_t buffer_sz)

586 {

587 assert(logmem);

588 assert(buffer);

         assert(buffer_sz > 0);

590

         bzero(ctx, sizeof(*ctx));

592 ctx->ctx_logmem = logmem;

593 ctx->ctx_buffer = buffer;

594 ctx->ctx_buffer_sz = buffer_sz;

595 }

596

597 void

598 os_log_context_free(os_log_context_t ctx)

599 {

600 if (ctx->ctx_allocated) {

                 logmem_free(ctx->ctx_logmem, ctx->ctx_buffer, ctx->ctx_buffer_sz);

602 }

603 }