+/* * Copyright (c) 2019 Apple Inc. All rights reserved. */
+
#include <stddef.h>
#undef offset
#include <kern/kalloc.h>
#include <kern/clock.h>
#include <kern/assert.h>
+#include <kern/task.h>
#include <firehose/tracepoint_private.h>
#include <firehose/chunk_private.h>
extern void bsd_log_unlock(void);
extern void logwakeup(struct msgbuf *);
-decl_lck_spin_data(extern, oslog_stream_lock)
+decl_lck_spin_data(extern, oslog_stream_lock);
#define stream_lock() lck_spin_lock(&oslog_stream_lock)
#define stream_unlock() lck_spin_unlock(&oslog_stream_lock)
static void
_os_log_with_args_internal(os_log_t oslog __unused, os_log_type_t type __unused,
- const char *format, va_list args, void *addr, void *dso);
+ const char *format, va_list args, void *addr, void *dso, bool driverKit, bool addcr);
static void
-_os_log_to_msgbuf_internal(const char *format, va_list args, bool safe, bool logging);
+_os_log_to_msgbuf_internal(const char *format, va_list args, bool safe, bool logging, bool addcr);
static void
_os_log_to_log_internal(os_log_t oslog, os_log_type_t type,
- const char *format, va_list args, void *addr, void *dso);
+ const char *format, va_list args, void *addr, void *dso, bool driverKit);
static void
_os_log_actual(os_log_t oslog, os_log_type_t type, const char *format, void
- *dso, void *addr, os_log_buffer_context_t context);
+ *dso, void *addr, os_log_buffer_context_t context, bool driverKit);
bool
os_log_info_enabled(os_log_t log __unused)
va_start(args, message);
- _os_log_with_args_internal(log, type, message, args, addr, dso);
+ _os_log_with_args_internal(log, type, message, args, addr, dso, FALSE, FALSE);
va_end(args);
return;
}
+__attribute__((noinline, not_tail_called)) int
+_os_log_internal_driverKit(void *dso, os_log_t log, uint8_t type, const char *message, ...)
+{
+ va_list args;
+ void *addr = __builtin_return_address(0);
+ bool driverKitLog = FALSE;
+
+ /*
+ * We want to be able to identify dexts from the logs.
+ *
+ * Usually the addr is used to understand if the log line
+ * was generated by a kext or the kernel main executable.
+ * Logd uses copyKextUUIDForAddress with the addr specified
+ * in the log line to retrieve the kext UUID of the sender.
+ *
+ * Dext however are not loaded in kernel space so they do not
+ * have a kernel range of addresses.
+ *
+ * To make the same mechanism work, OSKext fakes a kernel
+ * address range for dexts using the loadTag,
+ * so we just need to use the loadTag as addr here
+ * to allow logd to retrieve the correct UUID.
+ *
+ * NOTE: loadTag is populated in the task when the dext is matching,
+ * so if log lines are generated before the matching they will be
+ * identified as kernel main executable.
+ */
+ task_t self_task = current_task();
+
+ /*
+ * Only dextis are supposed to use this log path.
+ */
+ if (!task_is_driver(self_task)) {
+ return EPERM;
+ }
+
+ uint64_t loadTag = get_task_loadTag(self_task);
+ if (loadTag != 0) {
+ driverKitLog = TRUE;
+ addr = (void*) loadTag;
+ }
+ va_start(args, message);
+
+ _os_log_with_args_internal(log, type, message, args, addr, dso, driverKitLog, true);
+
+ va_end(args);
+
+ return 0;
+}
+
#pragma mark - shim functions
__attribute__((noinline, not_tail_called)) void
addr = __builtin_return_address(0);
}
- _os_log_with_args_internal(oslog, type, format, args, addr, NULL);
+ _os_log_with_args_internal(oslog, type, format, args, addr, NULL, FALSE, FALSE);
}
static void
_os_log_with_args_internal(os_log_t oslog, os_log_type_t type,
- const char *format, va_list args, void *addr, void *dso)
+ const char *format, va_list args, void *addr, void *dso, bool driverKit, bool addcr)
{
uint32_t logging_config = atm_get_diagnostic_config();
boolean_t safe;
}
if (oslog != &_os_log_replay) {
- _os_log_to_msgbuf_internal(format, args, safe, logging);
+ _os_log_to_msgbuf_internal(format, args, safe, logging, addcr);
}
if (safe && logging) {
- _os_log_to_log_internal(oslog, type, format, args, addr, dso);
+ _os_log_to_log_internal(oslog, type, format, args, addr, dso, driverKit);
}
}
static void
-_os_log_to_msgbuf_internal(const char *format, va_list args, bool safe, bool logging)
+_os_log_to_msgbuf_internal(const char *format, va_list args, bool safe, bool logging, bool addcr)
{
static int msgbufreplay = -1;
va_list args_copy;
}
va_copy(args_copy, args);
- vprintf_log_locked(format, args_copy);
+ vprintf_log_locked(format, args_copy, addcr);
va_end(args_copy);
#if DEVELOPMENT || DEBUG
static void
_os_log_to_log_internal(os_log_t oslog, os_log_type_t type,
- const char *format, va_list args, void *addr, void *dso)
+ const char *format, va_list args, void *addr, void *dso, bool driverKit)
{
struct os_log_buffer_context_s context;
unsigned char buffer_data[OS_LOG_BUFFER_MAX_SIZE] __attribute__((aligned(8)));
if (!_os_trace_addr_in_text_segment(dso, format)) {
return;
}
-
- void *dso_addr = (void *) OSKextKextForAddress(addr);
- if (dso != dso_addr) {
- return;
+ if (!driverKit) {
+ void *dso_addr = (void *) OSKextKextForAddress(addr);
+ if (dso != dso_addr) {
+ return;
+ }
}
#endif /* FIREHOSE_USES_SHARED_CACHE */
va_copy(args_copy, args);
- (void)hw_atomic_add(&oslog_p_total_msgcount, 1);
+ os_atomic_inc(&oslog_p_total_msgcount, relaxed);
if (_os_log_encode(format, args_copy, 0, &context)) {
- _os_log_actual(oslog, type, format, dso, addr, &context);
+ _os_log_actual(oslog, type, format, dso, addr, &context, driverKit);
} else {
- (void)hw_atomic_add(&oslog_p_error_count, 1);
+ os_atomic_inc(&oslog_p_error_count, relaxed);
}
va_end(args_copy);
static inline size_t
_os_trace_write_location_for_address(uint8_t buf[static sizeof(uint64_t)],
- void *dso, const void *address, firehose_tracepoint_flags_t *flags)
+ void *dso, const void *address, firehose_tracepoint_flags_t *flags, __unused bool driverKit)
{
+ uintptr_t shift_addr = (uintptr_t)address - (uintptr_t)dso;
#if FIREHOSE_USES_SHARED_CACHE
+
*flags = _firehose_tracepoint_flags_pc_style_shared_cache;
- memcpy(buf, (uint32_t[]){ (uintptr_t)address - (uintptr_t)dso },
+ memcpy(buf, (uint32_t[]){ shift_addr },
sizeof(uint32_t));
return sizeof(uint32_t);
#else /* FIREHOSE_USES_SHARED_CACHE */
kernel_mach_header_t *mh = dso;
- if (mh->filetype == MH_EXECUTE) {
+ /*
+ * driverKit will have the dso set as MH_EXECUTE
+ * (it is logging from a syscall in the kernel)
+ * but needs logd to parse the address as an
+ * absolute pc.
+ */
+ if (mh->filetype == MH_EXECUTE && !driverKit) {
*flags = _firehose_tracepoint_flags_pc_style_main_exe;
-
- memcpy(buf, (uint32_t[]){ (uintptr_t)address - (uintptr_t)dso },
- sizeof(uint32_t));
+ memcpy(buf, (uint32_t[]){ shift_addr}, sizeof(uint32_t));
return sizeof(uint32_t);
} else {
*flags = _firehose_tracepoint_flags_pc_style_absolute;
- memcpy(buf, (uintptr_t[]){ VM_KERNEL_UNSLIDE(address) }, sizeof(uintptr_t));
+ if (!driverKit) {
+ shift_addr = VM_KERNEL_UNSLIDE(address);
+ } else {
+ shift_addr = (uintptr_t) address;
+ }
+ memcpy(buf, (uintptr_t[]){ shift_addr }, sizeof(uintptr_t));
#if __LP64__
return 6; // 48 bits are enough
#else
static void
_os_log_actual(os_log_t oslog __unused, os_log_type_t type, const char *format,
- void *dso, void *addr, os_log_buffer_context_t context)
+ void *dso, void *addr, os_log_buffer_context_t context, bool driverKit)
{
firehose_stream_t stream;
firehose_tracepoint_flags_t flags = 0;
uint64_t thread_id;
// dso == the start of the binary that was loaded
- addr_len = _os_trace_write_location_for_address(buffdata, dso, addr, &flags);
+ addr_len = _os_trace_write_location_for_address(buffdata, dso, addr, &flags, driverKit);
buffdata_sz = _os_log_buffer_pack(buffdata + addr_len,
sizeof(buffdata) - addr_len, context);
if (buffdata_sz == 0) {
timestamp = firehose_tracepoint_time(firehose_activity_flags_default);
thread_id = thread_tid(current_thread());
- // create trace_id after we've set additional flags
- trace_id.ftid_value = FIREHOSE_TRACE_ID_MAKE(firehose_tracepoint_namespace_log,
- type, flags, _os_trace_offset(dso, format, flags));
+ if (driverKit) {
+ // set FIREHOSE_TRACEPOINT_PC_DYNAMIC_BIT so logd will not try to find the format string in
+ // the executable text
+ trace_id.ftid_value = FIREHOSE_TRACE_ID_MAKE(firehose_tracepoint_namespace_log,
+ type, flags, (uintptr_t) addr | FIREHOSE_TRACEPOINT_PC_DYNAMIC_BIT);
+ } else {
+ // create trace_id after we've set additional flags
+ trace_id.ftid_value = FIREHOSE_TRACE_ID_MAKE(firehose_tracepoint_namespace_log,
+ type, flags, _os_trace_offset(dso, format, (_firehose_tracepoint_flags_activity_t)flags));
+ }
if (FALSE) {
firehose_debug_trace(stream, trace_id.ftid_value, timestamp,
if (slowpath(ft_size + publen > _firehose_chunk_payload_size)) {
// We'll need to have some handling here. For now - return 0
- (void)hw_atomic_add(&oslog_p_error_count, 1);
+ os_atomic_inc(&oslog_p_error_count, relaxed);
return 0;
}
if (!fastpath(ft)) {
if (oslog_boot_done) {
if (stream == firehose_stream_metadata) {
- (void)hw_atomic_add(&oslog_p_metadata_dropped_msgcount, 1);
+ os_atomic_inc(&oslog_p_metadata_dropped_msgcount, relaxed);
} else {
// If we run out of space in the persistence buffer we're
// dropping the message.
- (void)hw_atomic_add(&oslog_p_dropped_msgcount, 1);
+ os_atomic_inc(&oslog_p_dropped_msgcount, relaxed);
}
return 0;
}
offset = firehose_chunk_tracepoint_try_reserve(fbc, stamp,
firehose_stream_persist, 0, publen, 0, NULL);
if (offset <= 0) {
- (void)hw_atomic_add(&oslog_p_boot_dropped_msgcount, 1);
+ os_atomic_inc(&oslog_p_boot_dropped_msgcount, relaxed);
return 0;
}
thread_tid(current_thread()), offset);
memcpy(ft->ft_data, pubdata, publen);
firehose_chunk_tracepoint_end(fbc, ft, ftid);
- (void)hw_atomic_add(&oslog_p_saved_msgcount, 1);
+ os_atomic_inc(&oslog_p_saved_msgcount, relaxed);
return ftid.ftid_value;
}
if (!oslog_boot_done) {
__firehose_buffer_tracepoint_flush(ft, ftid);
if (stream == firehose_stream_metadata) {
- (void)hw_atomic_add(&oslog_p_metadata_saved_msgcount, 1);
+ os_atomic_inc(&oslog_p_metadata_saved_msgcount, relaxed);
} else {
- (void)hw_atomic_add(&oslog_p_saved_msgcount, 1);
+ os_atomic_inc(&oslog_p_saved_msgcount, relaxed);
}
return ftid.ftid_value;
}
m_entry = oslog_stream_create_buf_entry(oslog_stream_link_type_metadata, ftid,
stamp, pubdata, publen);
if (!m_entry) {
- (void)hw_atomic_add(&oslog_s_error_count, 1);
+ os_atomic_inc(&oslog_s_error_count, relaxed);
goto finish;
}
T_LOG("Doing os_log of %llu TESTLOG msgs for fn " ident, count); \
for (uint64_t i = 0; i < count; i++) \
{ \
- datalen = snprintf(databuffer, sizeof(databuffer), TESTOSLOGFMT(ident), uniqid, i + 1, count); \
+ datalen = scnprintf(databuffer, sizeof(databuffer), TESTOSLOGFMT(ident), uniqid, i + 1, count); \
checksum = crc32(0, databuffer, datalen); \
callout_f(OS_LOG_DEFAULT, TESTOSLOG(ident), checksum, uniqid, i + 1, count); \
/*T_LOG(TESTOSLOG(ident), checksum, uniqid, i + 1, count);*/ \
T_ASSERT_NE_UINT(0, uniqid, "random number should not be zero");
T_ASSERT_NE_ULLONG(0, a, "absolute time should not be zero");
- datalen = snprintf(databuffer, sizeof(databuffer), TESTOSLOGFMT("printf_only"), uniqid, seqno, total_seqno);
+ datalen = scnprintf(databuffer, sizeof(databuffer), TESTOSLOGFMT("printf_only"), uniqid, seqno, total_seqno);
checksum = crc32(0, databuffer, datalen);
printf(TESTOSLOG("printf_only") "mat%llu\n", checksum, uniqid, seqno, total_seqno, a);
seqno += 1;
- datalen = snprintf(databuffer, sizeof(databuffer), TESTOSLOGFMT("printf_only"), uniqid, seqno, total_seqno);
+ datalen = scnprintf(databuffer, sizeof(databuffer), TESTOSLOGFMT("printf_only"), uniqid, seqno, total_seqno);
checksum = crc32(0, databuffer, datalen);
printf(TESTOSLOG("printf_only") "mat%llu\n", checksum, uniqid, seqno, total_seqno, a);
- datalen = snprintf(databuffer, sizeof(databuffer), "kernel^0^test^printf_only#mat%llu", a);
+ datalen = scnprintf(databuffer, sizeof(databuffer), "kernel^0^test^printf_only#mat%llu", a);
match_count = find_pattern_in_buffer(databuffer, datalen, total_seqno);
T_EXPECT_EQ_UINT(match_count, 2, "verify printf_only goes to systemlog buffer");
total_msg = oslog_p_total_msgcount;
saved_msg = oslog_p_saved_msgcount;
dropped_msg = oslog_p_dropped_msgcount;
- datalen = snprintf(databuffer, sizeof(databuffer), TESTOSLOGFMT("oslog_info"), uniqid, seqno, total_seqno);
+ datalen = scnprintf(databuffer, sizeof(databuffer), TESTOSLOGFMT("oslog_info"), uniqid, seqno, total_seqno);
checksum = crc32(0, databuffer, datalen);
os_log_info(log_handle, TESTOSLOG("oslog_info") "mat%llu", checksum, uniqid, seqno, total_seqno, a);
T_EXPECT_GE_UINT((oslog_p_total_msgcount - total_msg), 1, "total message count in buffer");
- datalen = snprintf(databuffer, sizeof(databuffer), "kernel^0^test^oslog_info#mat%llu", a);
+ datalen = scnprintf(databuffer, sizeof(databuffer), "kernel^0^test^oslog_info#mat%llu", a);
match_count = find_pattern_in_buffer(databuffer, datalen, total_seqno);
T_EXPECT_EQ_UINT(match_count, 1, "verify oslog_info does not go to systemlog buffer");
{
uint32_t uniqid = RandomULong();
test_oslog_debug_helper(uniqid, 100);
- (void)hw_atomic_add(&_test_log_loop_count, 100);
+ os_atomic_add(&_test_log_loop_count, 100, relaxed);
}
kern_return_t
projects / apple / xnu.git / blobdiff