--- /dev/null
+//
+// MessagePrinting.h
+// msa
+//
+// Created by James McIlree on 2/5/14.
+// Copyright (c) 2014 Apple. All rights reserved.
+//
+
+#ifndef __msa__MessagePrinting__
+#define __msa__MessagePrinting__
+
+char* print_mach_msg_header(char*, char*, const Globals&);
+char* print_thread_set_voucher_header(char* buf, char* buf_end, const Globals& globals);
+const char* qos_to_string(uint32_t qos);
+const char* qos_to_short_string(uint32_t qos);
+const char* role_to_string(uint32_t role);
+const char* role_to_short_string(uint32_t role);
+void print_base_empty(PrintBuffer& buffer, const Globals& globals, uintptr_t event_index, const char* type, bool should_newline);
+
+template <typename SIZE>
+void print_base(PrintBuffer& buffer,
+ const Globals& globals,
+ AbsTime timestamp,
+ const MachineThread<SIZE>* thread,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ const char* type,
+ bool should_newline)
+{
+ // Base Header is... (32)
+ //
+ // Time(µS) Type Thread ThreadVoucher AppType Process ;;
+ // 123456789abcdef0 1234567890123456789012 1234567890 123456789abcdef0 12345678901234567 123456789012345678901234 12
+ // 14.11 mach_msg_send 18FB voucher-133 AdaptiveDaemon TextEdit (231) ;;
+ // 18.11 mach_msg_recv 18FB 0 InteractiveDaemon configd (19981) ;;
+
+ // Base Header is... (64)
+ //
+ // Time(µS) Type Thread ThreadVoucher AppType Process ;;
+ // 123456789abcdef0 1234567890123456789012 1234567890 123456789abcdef0 12345678901234567 123456789012345678901234 12
+ // 14.11 mach_msg_send 18FB voucher-133 AdaptiveDaemon TextEdit (231) ;;
+ // 18.11 mach_msg_recv 18FB 0 InteractiveDaemon configd (19981) ;;
+
+ //
+ // [Index]
+ //
+ if (globals.should_print_event_index()) {
+ buffer.printf("%8llu ", (uint64_t)event_index);
+ }
+
+ //
+ // Time
+ //
+ if (globals.should_print_mach_absolute_timestamps()) {
+ if (globals.beginning_of_time().value() == 0)
+ buffer.printf("%16llX ", (timestamp - globals.beginning_of_time()).value());
+ else
+ buffer.printf("%16llu ", (timestamp - globals.beginning_of_time()).value());
+ } else {
+ NanoTime ntime = (timestamp - globals.beginning_of_time()).nano_time(globals.timebase());
+ buffer.printf("%16.2f ", (double)ntime.value() / 1000.0);
+ }
+
+ //
+ // beg/end/---
+ //
+ buffer.printf("%3s ", event.is_func_start() ? "beg" : (event.is_func_end() ? "end" : "---"));
+
+ //
+ // Type Code, Thread
+ //
+
+ // This assert doesn't handle utf8...
+ ASSERT(strlen(type) <= 22, "Sanity");
+ if (SIZE::is_64_bit)
+ buffer.printf("%22s %10llX ", type, (uint64_t)thread->tid());
+ else
+ buffer.printf("%22s %10llX ", type, (uint64_t)thread->tid());
+
+ //
+ // ThreadVoucher
+ //
+ auto thread_voucher = (thread) ? thread->voucher(timestamp) : &Machine<SIZE>::UnsetVoucher;
+
+ if (thread_voucher->is_unset()) {
+ buffer.printf("%16s ", "-");
+ } else if (thread_voucher->is_null()) {
+ buffer.printf("%16s ", "0");
+ } else {
+ char voucher_id[32];
+ snprintf(voucher_id, sizeof(voucher_id), "voucher-%u", thread_voucher->id());
+ buffer.printf("%16s ", voucher_id);
+ }
+
+ //
+ // AppType
+ //
+ const char* apptype_string = nullptr;
+ switch (thread->process().apptype()) {
+ case -1:
+ apptype_string = "-";
+ break;
+ case TASK_APPTYPE_NONE:
+ apptype_string = "None";
+ break;
+ case TASK_APPTYPE_DAEMON_INTERACTIVE:
+ apptype_string = "InteractiveDaemon";
+ break;
+ case TASK_APPTYPE_DAEMON_STANDARD:
+ apptype_string = "StandardDaemon";
+ break;
+ case TASK_APPTYPE_DAEMON_ADAPTIVE:
+ apptype_string = "AdaptiveDaemon";
+ break;
+ case TASK_APPTYPE_DAEMON_BACKGROUND:
+ apptype_string = "BackgroundDaemon";
+ break;
+ case TASK_APPTYPE_APP_DEFAULT:
+ apptype_string = "App";
+ break;
+ case TASK_APPTYPE_APP_TAL:
+ apptype_string = "TALApp";
+ break;
+ default:
+ apptype_string = "???";
+ break;
+ }
+ buffer.printf("%17s ", apptype_string);
+
+ //
+ // Process
+ //
+ char process_name[32];
+
+ // Should not ever fail, but...
+ if (thread) {
+ const MachineProcess<SIZE>& process = thread->process();
+ snprintf(process_name, sizeof(process_name), "%s (%d)", process.name(), process.pid());
+ } else {
+ snprintf(process_name, sizeof(process_name), "???");
+ }
+
+ if (should_newline)
+ buffer.printf("%24s ;;\n", process_name);
+ else
+ buffer.printf("%24s ;; ", process_name);
+}
+
+template <typename SIZE>
+void print_mach_msg(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ bool is_send,
+ const MachineMachMsg<SIZE>* mach_msg)
+{
+ // Mach Msg Header is... (32)
+ //
+ // ;; Message From/To MsgID MsgVoucher DeliveryTime FLAGS
+ // 12 123456789012345678901234567 123456789ab 123456789abcdef0 1234567890123 ...
+ // ;; -> configd (19981) 55 - - ONEWAY, IMP-DONATING
+ // ;; <- TextEdit (231) 55 voucher-133 120080 VOUCHER-PROVIDED-BY-KERNEL, VOUCHER-REFUSED
+
+ // Mach Msg Header is... (64)
+ //
+ // ;; Message From/To MsgID MsgVoucher DeliveryTime FLAGS
+ // 12 123456789012345678901234567 123456789ab 123456789abcdef0 1234567890123 ...
+ // ;; -> configd (19981) 55 - - ONEWAY, IMP-DONATING
+ // ;; <- TextEdit (231) 55 voucher-133 120080 VOUCHER-PROVIDED-BY-KERNEL, VOUCHER-REFUSED
+
+ print_base(buffer, globals, event.timestamp(), machine.thread(event.tid(), event.timestamp()), event, event_index, is_send ? "mach_msg_send" : "mach_msg_recv", false);
+
+ //
+ // Message From/To
+ //
+ {
+ char from_to_name[32];
+ const MachineThread<SIZE>* from_to_thread = NULL;
+ const char* from_to_direction;
+
+ if (is_send) {
+ from_to_direction = "->";
+ if (mach_msg->has_receiver())
+ from_to_thread = machine.thread(mach_msg->recv_tid(), mach_msg->recv_time());
+ } else {
+ from_to_direction = "<-";
+ if (mach_msg->has_sender())
+ from_to_thread = machine.thread(mach_msg->send_tid(), mach_msg->send_time());
+ }
+
+ if (from_to_thread) {
+ const MachineProcess<SIZE>& from_to_process = from_to_thread->process();
+ snprintf(from_to_name, sizeof(from_to_name), "%s %s (%d)", from_to_direction, from_to_process.name(), from_to_process.pid());
+ } else {
+ // (???) is a trigraph, break up by escaping one of the ?
+ snprintf(from_to_name, sizeof(from_to_name), "%s ??? (??\?)", from_to_direction);
+ }
+
+ buffer.printf("%-27s ", from_to_name);
+ }
+
+ //
+ // MsgID
+ //
+
+ char msg_id[32];
+ snprintf(msg_id, sizeof(msg_id), "msg-%u", mach_msg->id());
+ buffer.printf("%11s ", msg_id);
+
+ //
+ // MsgVoucher
+ //
+ // We want to differentiate between sending a NULL voucher and not having msgh_bits set.
+ // We will show a NULL voucher as 0, but if msgh_bits says no voucher was sent, we will show "-"
+ //
+
+ MachineVoucher<SIZE>* msg_voucher = (is_send) ? mach_msg->send_voucher() : mach_msg->recv_voucher();
+
+ if (msg_voucher->is_unset()) {
+ buffer.printf("%16s ", "-");
+ } else if (msg_voucher->is_null()) {
+ buffer.printf("%16s ", "0");
+ } else {
+ char voucher_id[32];
+ snprintf(voucher_id, sizeof(voucher_id), "voucher-%u", msg_voucher->id());
+ buffer.printf("%16s ", voucher_id);
+ }
+
+ //
+ // DeliveryTime
+ //
+
+ if (!is_send) {
+ if (mach_msg->has_sender()) {
+ NanoTime ntime = (mach_msg->recv_time() - mach_msg->send_time()).nano_time(globals.timebase());
+ buffer.printf("%13.2f ", (double)ntime.value() / 1000.0);
+ } else {
+ buffer.printf("%13s ", "?");
+ }
+ } else {
+ buffer.printf("%13s ", "-");
+ }
+
+ //
+ // FLAGS
+ //
+ const char* separator = "";
+
+ if (is_send) {
+ if (!MACH_MSGH_BITS_HAS_LOCAL(mach_msg->send_msgh_bits())) {
+ buffer.printf("%sONEWAY", separator);
+ separator = ", ";
+ }
+
+ if (MACH_MSGH_BITS_RAISED_IMPORTANCE(mach_msg->send_msgh_bits())) {
+ buffer.printf("%sMSGH_BITS_RAISED_IMPORTANCE", separator);
+ separator = ", ";
+ }
+
+ if (MACH_MSGH_BITS_HOLDS_IMPORTANCE_ASSERTION(mach_msg->send_msgh_bits())) {
+ buffer.printf("%sMSGH_BITS_HOLDS_IMPORTANCE_ASSERTION", separator);
+ separator = ", ";
+ }
+ } else {
+ if (mach_msg->is_voucher_refused()) {
+ // FIX ME!
+ // Need to test this... Can we tell if a voucher was refused without the
+ // send voucher?
+ //
+ if (mach_msg->has_non_null_send_voucher() || mach_msg->has_non_null_recv_voucher()) {
+ buffer.printf("%sVOUCHER-REFUSED", separator);
+ }
+
+ separator = ", ";
+ }
+ if (MACH_MSGH_BITS_RAISED_IMPORTANCE(mach_msg->recv_msgh_bits())) {
+ buffer.printf("%sMSGH_BITS_RAISED_IMPORTANCE", separator);
+ separator = ", ";
+ }
+
+ if (MACH_MSGH_BITS_HOLDS_IMPORTANCE_ASSERTION(mach_msg->recv_msgh_bits())) {
+ buffer.printf("%sMSGH_BITS_HOLDS_IMPORTANCE_ASSERTION", separator);
+ separator = ", ";
+ }
+ }
+
+ //
+ // MsgVoucher transformation
+ //
+ {
+ char transformed_voucher[32];
+
+ if (mach_msg->has_sender() && mach_msg->has_receiver()) {
+ auto send_voucher = mach_msg->send_voucher();
+ auto recv_voucher = mach_msg->recv_voucher();
+
+ if (send_voucher != recv_voucher) {
+ auto changed_voucher = (is_send) ? recv_voucher : send_voucher;
+ auto changed_tense = (is_send) ? "becomes" : "was";
+
+ if (changed_voucher->is_unset()) {
+ snprintf(transformed_voucher, sizeof(transformed_voucher), "(%s -)", changed_tense);
+ } else if (changed_voucher->is_null()) {
+ snprintf(transformed_voucher, sizeof(transformed_voucher), "(%s 0)", changed_tense);
+ } else {
+ snprintf(transformed_voucher, sizeof(transformed_voucher), "(%s voucher-%u)", changed_tense, changed_voucher->id());
+ }
+
+ buffer.printf("%sVOUCHER_CHANGED %s", separator, transformed_voucher);
+ }
+ }
+ }
+
+ buffer.printf("\n");
+}
+
+template <typename SIZE>
+void print_boost(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ pid_t boost_receiver_pid,
+ bool is_boost)
+{
+
+ // Base Header is... (32)
+ //
+ // ;;
+ // 12
+ // ;; BOOST foobard (338)
+
+ // Base Header is... (64)
+ //
+ // ;;
+ // 12
+ // ;; BOOST foobard (338)
+
+
+ print_base(buffer, globals, event.timestamp(), machine.thread(event.tid(), event.timestamp()), event, event_index, is_boost ? "boost" : "unboost", false);
+
+ //
+ // Boost target
+ //
+
+ const MachineProcess<SIZE>* target = machine.process(boost_receiver_pid, event.timestamp());
+ const char* target_name;
+
+ if (target) {
+ target_name = target->name();
+ } else {
+ target_name = "???";
+ }
+
+ const char* action = is_boost ? "BOOST" : "UNBOOST";
+
+ buffer.printf("%s %s (%d)\n", action, target_name, boost_receiver_pid);
+}
+
+template <typename SIZE>
+void print_impdelv(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ pid_t sender_pid,
+ uint32_t importance_delivery_result)
+{
+ print_base(buffer, globals, event.timestamp(), machine.thread(event.tid(), event.timestamp()), event, event_index, "importance_delivered", false);
+
+ //
+ // Importance sender
+ //
+ const char* sender_name = "???";
+ if (const MachineProcess<SIZE>* sender = machine.process(sender_pid, event.timestamp())) {
+ sender_name = sender->name();
+ }
+
+ // 0: BOOST NOT APPLIED
+ // 1: BOOST EXTERNALIZED
+ // 2: LIVE_IMPORTANCE_LINKAGE!
+
+ switch (importance_delivery_result) {
+ case 0:
+ buffer.printf("importance from %s (%d) was not applied\n", sender_name, sender_pid);
+ break;
+ case 1:
+ buffer.printf("importance from %s (%d) was externalized\n", sender_name, sender_pid);
+ break;
+ case 2:
+ buffer.printf("linked to %s (%d)'s live importance chain\n", sender_name, sender_pid);
+ break;
+
+ default:
+ ASSERT(false, "Unknown importance delivery result value");
+ buffer.printf("Unknown importance delivery result value\n");
+ break;
+ }
+}
+
+template <typename SIZE>
+void print_generic(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ const char* type)
+{
+ print_base(buffer, globals, event.timestamp(), machine.thread(event.tid(), event.timestamp()), event, event_index, type, true);
+}
+
+template <typename SIZE>
+void print_importance_assert(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ const char* type,
+ std::unordered_map<pid_t, std::pair<uint32_t, uint32_t>>& task_importance)
+{
+ // All callers must have the following trace event data:
+ //
+ // ignored, target_pid, internal_count, external_count
+
+ // First check if anything changed
+ pid_t target_pid = (pid_t)event.arg2();
+ if (target_pid < 1)
+ return;
+
+ bool must_print = false;
+ auto it = task_importance.find(target_pid);
+ if (it == task_importance.end()) {
+ it = task_importance.emplace(target_pid, std::pair<uint32_t, uint32_t>(0, 0)).first;
+ // The very first time we see data for an app, we always want to print it.
+ must_print = true;
+ }
+
+ auto old_importance = it->second;
+ auto new_importance = std::pair<uint32_t, uint32_t>((uint32_t)event.arg3(), (uint32_t)event.arg4());
+ if (must_print || old_importance != new_importance) {
+ const MachineThread<SIZE>* event_thread = machine.thread(event.tid(), event.timestamp());
+ print_base(buffer, globals, event.timestamp(), event_thread, event, event_index, type, false);
+
+ const MachineProcess<SIZE>* target = machine.process(target_pid, event.timestamp());
+ const char* target_name;
+
+ if (target) {
+ target_name = target->name();
+ } else {
+ target_name = "???";
+ }
+
+ int internal_delta = new_importance.first - old_importance.first;
+ int external_delta = new_importance.second - old_importance.second;
+
+ char internal_sign = internal_delta >= 0 ? '+' : '-';
+ char external_sign = external_delta >= 0 ? '+' : '-';
+
+ char internal_changed_buf[32];
+ char external_changed_buf[32];
+
+ if (internal_delta != 0) {
+ snprintf(internal_changed_buf, sizeof(internal_changed_buf), " (%c%u)", internal_sign, abs(internal_delta));
+ } else {
+ internal_changed_buf[0] = 0;
+ }
+
+ if (external_delta != 0) {
+ snprintf(external_changed_buf, sizeof(external_changed_buf), " (%c%u)", external_sign, abs(external_delta));
+ } else {
+ external_changed_buf[0] = 0;
+ }
+
+ buffer.printf("%s (%d) internal: %u%s external: %u%s\n",
+ target_name, target_pid,
+ new_importance.first, internal_changed_buf,
+ new_importance.second, external_changed_buf);
+
+ it->second = new_importance;
+ }
+}
+
+template <typename SIZE>
+void print_watchport_importance_transfer(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index)
+{
+ // event data is
+ //
+ // proc_selfpid(), pid, boost, released_pid, 0);
+
+ // Did any importance transfer?
+ if (event.arg3() == 0)
+ return;
+
+ // Do we have a valid pid?
+ pid_t dest_pid = (pid_t)event.arg2();
+ if (dest_pid < 1)
+ return;
+
+ const MachineThread<SIZE>* event_thread = machine.thread(event.tid(), event.timestamp());
+ print_base(buffer, globals, event.timestamp(), event_thread, event, event_index, "importance_watchport", false);
+
+ const char* dest_name;
+ if (const MachineProcess<SIZE>* dest = machine.process(dest_pid, event.timestamp())) {
+ dest_name = dest->name();
+ } else {
+ dest_name = "???";
+ }
+
+ buffer.printf("%s (%d) receives %d importance via watchport\n",
+ dest_name, dest_pid, (int)event.arg3());
+}
+
+template <typename SIZE>
+void print_importance_send_failed(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index)
+{
+ print_base(buffer, globals, event.timestamp(), machine.thread(event.tid(), event.timestamp()), event, event_index, "impsend", false);
+
+ //
+ // Currently, the IMP_MSG_SEND trace data is not accurate.
+ //
+
+ buffer.printf("Backed out importance (may be resent) - TIMED_OUT, NO_BUFFER, or SEND_INTERRUPTED\n");
+}
+
+#if 0
+
+template <typename SIZE>
+void print_trequested_task(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ pid_t pid,
+ struct task_requested_policy new_task_requested,
+ struct task_requested_policy original_task_requested)
+{
+ // Many of these events would print nothing, we want to make sure there is something to print first.
+
+ char description[512];
+ char* cursor = description;
+ char* cursor_end = cursor + sizeof(description);
+ uint32_t description_count = 0;
+
+ if (new_task_requested.t_role != original_task_requested.t_role) {
+ const char* role = "???";
+ switch (new_task_requested.t_role) {
+ // This is seen when apps are terminating
+ case TASK_UNSPECIFIED:
+ role = "unspecified";
+ break;
+
+ case TASK_FOREGROUND_APPLICATION:
+ role = "foreground";
+ break;
+
+ case TASK_BACKGROUND_APPLICATION:
+ role = "background";
+ break;
+
+ case TASK_CONTROL_APPLICATION:
+ role = "control-application";
+ break;
+
+ case TASK_GRAPHICS_SERVER:
+ role = "graphics-server";
+ break;
+
+ case TASK_THROTTLE_APPLICATION:
+ role = "throttle-application";
+ break;
+
+ case TASK_NONUI_APPLICATION:
+ role = "nonui-application";
+ break;
+
+ case TASK_DEFAULT_APPLICATION:
+ role = "default-application";
+ break;
+
+ default:
+ ASSERT(false, "Unexpected app role");
+ break;
+ }
+ cursor += snprintf(cursor, cursor_end - cursor, "%sROLE:%s", description_count++ == 0 ? "" : ", ", role);
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_task_requested.int_darwinbg != original_task_requested.int_darwinbg) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%s%sINT_DARWINBG", description_count++ == 0 ? "" : ", ", new_task_requested.int_darwinbg ? "" : "!");
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_task_requested.ext_darwinbg != original_task_requested.ext_darwinbg) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%s%sEXT_DARWINBG", description_count++ == 0 ? "" : ", ", new_task_requested.ext_darwinbg ? "" : "!");
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_task_requested.t_int_gpu_deny != original_task_requested.t_int_gpu_deny) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sINT_GPU_DENY", description_count++ == 0 ? "" : ", ");
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_task_requested.t_ext_gpu_deny != original_task_requested.t_ext_gpu_deny) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sEXT_GPU_DENY", description_count++ == 0 ? "" : ", ");
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_task_requested.t_tal_enabled != original_task_requested.t_tal_enabled) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sTAL_ENABLED", description_count++ == 0 ? "" : ", ");
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_task_requested.t_sfi_managed != original_task_requested.t_sfi_managed) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sSFI_MANAGED", description_count++ == 0 ? "" : ", ");
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_task_requested.t_sup_active != original_task_requested.t_sup_active) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sAPPNAP", description_count++ == 0 ? "" : ", ");
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_task_requested.t_base_latency_qos != original_task_requested.t_base_latency_qos) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sBASE_LATENCY_QOS:%s", description_count++ == 0 ? "" : ", ", qos_to_string(new_task_requested.t_base_latency_qos));
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_task_requested.t_over_latency_qos != original_task_requested.t_over_latency_qos) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sOVERRIDE_LATENCY_QOS:%s", description_count++ == 0 ? "" : ", ", qos_to_string(new_task_requested.t_over_latency_qos));
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_task_requested.t_base_through_qos != original_task_requested.t_base_through_qos) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sBASE_THROUGHPUT_QOS:%s", description_count++ == 0 ? "" : ", ", qos_to_string(new_task_requested.t_base_through_qos));
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_task_requested.t_over_through_qos != original_task_requested.t_over_through_qos) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sOVERRIDE_THROUGHPUT_QOS:%s", description_count++ == 0 ? "" : ", ", qos_to_string(new_task_requested.t_over_through_qos));
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_task_requested.t_qos_clamp != original_task_requested.t_qos_clamp) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sQOS_CLAMP:%s", description_count++ == 0 ? "" : ", ", qos_to_string(new_task_requested.t_qos_clamp));
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (description_count) {
+ print_base(buffer, globals, event.timestamp(), machine.thread(event.tid(), event.timestamp()), event_index, "task_trequested", false);
+
+ ASSERT(pid != -1, "Sanity");
+
+ const char* target_name;
+ if (const MachineProcess<SIZE>* target = machine.process(pid, event.timestamp())) {
+ target_name = target->name();
+ } else {
+ target_name = "???";
+ }
+
+ buffer.printf("%s (%d) requests %s\n", target_name, pid, description);
+ }
+}
+
+struct task_requested_policy {
+ /* Task and thread policy (inherited) */
+ uint64_t int_darwinbg :1, /* marked as darwinbg via setpriority */
+ ext_darwinbg :1,
+ int_iotier :2, /* IO throttle tier */
+ ext_iotier :2,
+ int_iopassive :1, /* should IOs cause lower tiers to be throttled */
+ ext_iopassive :1,
+ bg_iotier :2, /* what IO throttle tier should apply to me when I'm darwinbg? (pushed to threads) */
+ terminated :1, /* all throttles should be removed for quick exit or SIGTERM handling */
+
+ /* Thread only policy */
+ th_pidbind_bg :1, /* thread only: task i'm bound to is marked 'watchbg' */
+ th_workq_bg :1, /* thread only: currently running a background priority workqueue */
+ thrp_qos :3, /* thread only: thread qos class */
+ thrp_qos_relprio :4, /* thread only: thread qos relative priority (store as inverse, -10 -> 0xA) */
+ thrp_qos_override :3, /* thread only: thread qos class override */
+
+ /* Task only policy */
+ t_apptype :3, /* What apptype did launchd tell us this was (inherited) */
+ t_boosted :1, /* Has a non-zero importance assertion count */
+ t_int_gpu_deny :1, /* don't allow access to GPU */
+ t_ext_gpu_deny :1,
+ t_role :3, /* task's system role */
+ t_tal_enabled :1, /* TAL mode is enabled */
+ t_base_latency_qos :3, /* Timer latency QoS */
+ t_over_latency_qos :3, /* Timer latency QoS override */
+ t_base_through_qos :3, /* Computation throughput QoS */
+ t_over_through_qos :3, /* Computation throughput QoS override */
+ t_sfi_managed :1, /* SFI Managed task */
+ t_qos_clamp :3, /* task qos clamp */
+
+ /* Task only: suppression policies (non-embedded only) */
+ t_sup_active :1, /* Suppression is on */
+ t_sup_lowpri_cpu :1, /* Wants low priority CPU (MAXPRI_THROTTLE) */
+ t_sup_timer :3, /* Wanted timer throttling QoS tier */
+ t_sup_disk :1, /* Wants disk throttling */
+ t_sup_cpu_limit :1, /* Wants CPU limit (not hooked up yet)*/
+ t_sup_suspend :1, /* Wants to be suspended */
+ t_sup_throughput :3, /* Wants throughput QoS tier */
+ t_sup_cpu :1, /* Wants suppressed CPU priority (MAXPRI_SUPPRESSED) */
+ t_sup_bg_sockets :1, /* Wants background sockets */
+
+ reserved :2;
+};
+#endif
+
+template <typename SIZE>
+void print_appnap(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ bool is_appnap_active,
+ std::unordered_map<pid_t, bool>& task_appnap_state,
+ std::unordered_map<pid_t, TaskRequestedPolicy>& task_requested_state)
+{
+ //
+ // event args are:
+ //
+ // self_pid, audit_token_pid_from_task(task), trequested_0(task, NULL), trequested_1(task, NULL)
+ //
+ auto pid = (pid_t)event.arg2();
+ auto trequested_0 = event.arg3();
+ auto trequested_1 = event.arg4();
+ auto task_requested = (SIZE::is_64_bit) ? TaskRequestedPolicy(trequested_0) : TaskRequestedPolicy((Kernel32::ptr_t)trequested_0, (Kernel32::ptr_t)trequested_1);
+ auto should_print = false;
+
+ ASSERT(pid != -1, "Sanity");
+
+ // If the appnap state changed, we want to print this event.
+ auto appnap_it = task_appnap_state.find(pid);
+ if (appnap_it == task_appnap_state.end()) {
+ should_print = true;
+ task_appnap_state.emplace(pid, is_appnap_active);
+ } else {
+ if (appnap_it->second != is_appnap_active) {
+ should_print = true;
+ appnap_it->second = is_appnap_active;
+ }
+ }
+
+ // If the task_requested state changed, we want to print this event.
+ auto requested_it = task_requested_state.find(pid);
+ if (requested_it == task_requested_state.end()) {
+ should_print = true;
+ task_requested_state.emplace(pid, task_requested);
+ } else {
+ if (requested_it->second != task_requested) {
+ should_print = true;
+ requested_it->second = task_requested;
+ }
+ }
+
+ if (should_print) {
+ print_base(buffer, globals, event.timestamp(), machine.thread(event.tid(), event.timestamp()), event, event_index, "imp_supression", false);
+
+ const char* name;
+ if (auto target = machine.process(pid, event.timestamp())) {
+ name = target->name();
+ } else {
+ name = "???";
+ }
+ buffer.printf("%s (%d) AppNap is %s\n", name, pid, is_appnap_active ? "ON" : "OFF");
+ print_trequested_task(buffer, globals, machine, event, event_index, pid, task_requested);
+ }
+}
+
+template <typename SIZE>
+void print_trequested_task(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ pid_t pid,
+ TaskRequestedPolicy task_requested)
+{
+
+ ASSERT(pid != -1, "Sanity");
+ const char* target_name;
+ if (const MachineProcess<SIZE>* target = machine.process(pid, event.timestamp())) {
+ target_name = target->name();
+ } else {
+ target_name = "???";
+ }
+
+ struct task_requested_policy trp = task_requested.as_struct();
+
+ print_base_empty(buffer, globals, event_index, "task_trequested", false);
+ buffer.printf("%s (%d) requests%s%s%s%s%s%s%s%s%s%s%s%s%s%s%s%s%s\n",
+ target_name, pid,
+ trp.int_darwinbg ? " IntDBG" : "",
+ trp.ext_darwinbg ? " ExtDBG" : "",
+ trp.int_iopassive ? " IntIOPass" : "",
+ trp.ext_iopassive ? " ExtIOPass" : "",
+ trp.terminated ? " Term" : "",
+ trp.t_boosted ? " Boost" : "",
+ trp.t_int_gpu_deny ? " IntDenyGPU" : "",
+ trp.t_ext_gpu_deny ? " ExtDenyGPU" : "",
+ trp.t_tal_enabled ? " TAL" : "",
+ trp.t_sfi_managed ? " SFI" : "",
+ // Below here is AppNap only...
+ trp.t_sup_active ? " AppNap" : "",
+ trp.t_sup_lowpri_cpu ? " SupLowPriCPU" : "",
+ trp.t_sup_disk ? " SupDisk" : "",
+ trp.t_sup_cpu_limit ? " SupCPULim" : "",
+ trp.t_sup_suspend ? " SupSusp" : "",
+ trp.t_sup_cpu ? " SupCPU" : "",
+ trp.t_sup_bg_sockets ? " SupBGSck" : "");
+
+ print_base_empty(buffer, globals, event_index, "task_trequested", false);
+ buffer.printf("%s (%d) requests QOS (SupTHR/SupTMR/LAT/OVERLAT/THR/OVERTHR/CLAMP) %s/%s/%s/%s/%s/%s/%s int_IOTier:%d ext_IOTier:%d bg_IOTier:%d\n",
+ target_name, pid,
+ qos_to_string(trp.t_sup_throughput),
+ qos_to_string(trp.t_sup_timer),
+ qos_to_string(trp.t_base_latency_qos),
+ qos_to_string(trp.t_over_latency_qos),
+ qos_to_string(trp.t_base_through_qos),
+ qos_to_string(trp.t_over_through_qos),
+ qos_to_string(trp.t_qos_clamp),
+ trp.int_iotier,
+ trp.ext_iotier,
+ trp.bg_iotier);
+}
+
+template <typename SIZE>
+void print_trequested_thread(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ const MachineThread<SIZE>* thread,
+ struct task_requested_policy new_thread_requested,
+ struct task_requested_policy original_thread_requested)
+{
+ ASSERT(thread, "Sanity");
+
+ // Many of these events would print nothing, we want to make sure there is something to print first.
+
+ char description[512];
+ char* cursor = description;
+ char* cursor_end = cursor + sizeof(description);
+ uint32_t description_count = 0;
+
+ if (new_thread_requested.int_darwinbg != original_thread_requested.int_darwinbg) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sINT_DARWINBG", description_count++ == 0 ? "" : ", ");
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_thread_requested.ext_darwinbg != original_thread_requested.ext_darwinbg) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sEXT_DARWINBG", description_count++ == 0 ? "" : ", ");
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_thread_requested.th_pidbind_bg != original_thread_requested.th_pidbind_bg) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sPIDBIND_BG", description_count++ == 0 ? "" : ", ");
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_thread_requested.th_workq_bg != original_thread_requested.th_workq_bg) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sWORKQ_BG", description_count++ == 0 ? "" : ", ");
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_thread_requested.thrp_qos != original_thread_requested.thrp_qos) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sTHREAD_QOS:%s", description_count++ == 0 ? "" : ", ", qos_to_string(new_thread_requested.thrp_qos));
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_thread_requested.thrp_qos_relprio != original_thread_requested.thrp_qos_relprio) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sTHREAD_QOS_RELATIVE_PRIORITY:%d", description_count++ == 0 ? "" : ", ", -new_thread_requested.thrp_qos_relprio);
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (new_thread_requested.thrp_qos_override != original_thread_requested.thrp_qos_override) {
+ cursor += snprintf(cursor, cursor_end - cursor, "%sTHREAD_OVERRIDE_QOS:%s", description_count++ == 0 ? "" : ", ", qos_to_string(new_thread_requested.thrp_qos_override));
+ GUARANTEE(cursor < cursor_end);
+ }
+
+ if (description_count) {
+ print_base(buffer, globals, event.timestamp(), machine.thread(event.tid(), event.timestamp()), event_index, "thread_trequested", false);
+ ASSERT(thread->process().pid() != -1, "Sanity");
+ buffer.printf("%s (%d) %llX requests %s\n", thread->process().name(), thread->process().pid(), (uint64_t)thread->tid(), description);
+ }
+}
+
+template <typename SIZE>
+void print_teffective_task(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ pid_t pid,
+ TaskEffectivePolicy task_effective)
+{
+ ASSERT(pid != -1, "Sanity");
+ const char* target_name;
+ if (const MachineProcess<SIZE>* target = machine.process(pid, event.timestamp())) {
+ target_name = target->name();
+ } else {
+ target_name = "???";
+ }
+
+ struct task_effective_policy tep = task_effective.as_struct();
+
+ print_base_empty(buffer, globals, event_index, "task_teffective", false);
+ buffer.printf("%s (%d) is%s%s%s%s%s%s%s%s%s%s%s%s%s%s\n",
+ target_name, pid,
+ tep.darwinbg ? " DarwinBG" : "",
+ tep.t_sup_active ? " AppNap" : "",
+ tep.lowpri_cpu ? " LowPri" : "",
+ tep.io_passive ? " IOPass" : "",
+ tep.all_sockets_bg ? " ASckBG" : "",
+ tep.new_sockets_bg ? " NSckBG" : "",
+ tep.terminated ? " Term" : "",
+ tep.qos_ui_is_urgent ? " QOSUiIsUrg" : "",
+ tep.t_gpu_deny ? " GPUDeny" : "",
+ tep.t_suspended ? " SupSusp" : "",
+ tep.t_watchers_bg ? " WchrsBG" : "",
+ tep.t_suppressed_cpu ? " SupCPU" : "",
+ tep.t_sfi_managed ? " SFI" : "",
+ tep.t_live_donor ? " LiveImpDnr" : "");
+
+ print_base_empty(buffer, globals, event_index, "task_teffective", false);
+ buffer.printf("%s (%d) is Role:%s LAT/THR/CLAMP/CEIL:%s/%s/%s/%s IOTier:%d BG_IOTier:%d\n",
+ target_name, pid,
+ role_to_string(tep.t_role),
+ qos_to_string(tep.t_latency_qos),
+ qos_to_string(tep.t_through_qos),
+ qos_to_string(tep.t_qos_clamp),
+ qos_to_string(tep.t_qos_ceiling),
+ tep.io_tier,
+ tep.bg_iotier);
+}
+
+template <typename SIZE>
+void print_teffective_thread(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ const MachineThread<SIZE>* thread,
+ TaskEffectivePolicy thread_effective)
+{
+ ASSERT(thread, "Sanity");
+
+ const char* target_name = thread->process().name();
+
+ struct task_effective_policy tep = thread_effective.as_struct();
+
+ print_base_empty(buffer, globals, event_index, "thread_teffective", false);
+ buffer.printf("%s (%d) %llX is%s%s%s%s%s%s%s%s\n",
+ target_name, thread->process().pid(), (uint64_t)thread->tid(),
+ tep.darwinbg ? " DarwinBG" : "",
+ tep.t_sup_active ? " AppNap" : "",
+ tep.lowpri_cpu ? " LowPri" : "",
+ tep.io_passive ? " IOPass" : "",
+ tep.all_sockets_bg ? " ASckBG" : "",
+ tep.new_sockets_bg ? " NSckBG" : "",
+ tep.terminated ? " Term" : "",
+ tep.qos_ui_is_urgent ? " QOSUiIsUrg" : "");
+
+ print_base_empty(buffer, globals, event_index, "thread_teffective", false);
+ buffer.printf("%s (%d) %llX is QOS:%s QOS_relprio:%d\n",
+ target_name, thread->process().pid(), (uint64_t)thread->tid(),
+ qos_to_string(tep.thep_qos),
+ tep.thep_qos_relprio);
+}
+
+template <typename SIZE>
+void print_importance_apptype(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index)
+{
+ print_base(buffer, globals, event.timestamp(), machine.thread(event.tid(), event.timestamp()), event, event_index, "set_apptype", false);
+
+ //
+ // trace args are:
+ //
+ // selfpid, targetpid, trequested(targetpid, NULL), is_importance_receiver
+
+ //
+ // QoS clamp
+ //
+ // Can only be determined on K64, the bits needed are trimmed off in
+ // K32 tracepoints.
+
+ char qos_clamp[32];
+ qos_clamp[0] = 0;
+ if (SIZE::is_64_bit) {
+ uint32_t qos_level = (event.arg3() & POLICY_REQ_QOS_CLAMP_MASK) >> POLICY_REQ_QOS_CLAMP_SHIFT;
+ if (qos_level != THREAD_QOS_UNSPECIFIED) {
+ snprintf(qos_clamp, sizeof(qos_clamp), ", clamped to %s", qos_to_string(qos_level));
+ }
+ }
+
+ pid_t target_pid = (pid_t)event.arg2();
+ const char* target_name;
+
+ if (target_pid != -1 ) {
+ if (const MachineProcess<SIZE>* target = machine.process(target_pid, event.timestamp())) {
+ target_name = target->name();
+ } else {
+ target_name = "???";
+ }
+ } else {
+ target_name = "NULL-Task";
+ }
+
+ const char* apptype = "???";
+ switch (event.dbg_code()) {
+ case TASK_APPTYPE_NONE:
+ apptype = "None";
+ break;
+ case TASK_APPTYPE_DAEMON_INTERACTIVE:
+ apptype = "InteractiveDaemon";
+ break;
+ case TASK_APPTYPE_DAEMON_STANDARD:
+ apptype = "StandardDaemon";
+ break;
+ case TASK_APPTYPE_DAEMON_ADAPTIVE:
+ apptype = "AdaptiveDaemon";
+ break;
+ case TASK_APPTYPE_DAEMON_BACKGROUND:
+ apptype = "BackgroundDaemon";
+ break;
+ case TASK_APPTYPE_APP_DEFAULT:
+ apptype = "App";
+ break;
+ case TASK_APPTYPE_APP_TAL:
+ apptype = "TALApp";
+ break;
+ default:
+ break;
+ }
+
+ const char* imp_recv = "";
+ if (event.arg4()) {
+ imp_recv = ", receives importance";
+ }
+ buffer.printf("Set %s (%d) to %s%s%s\n", target_name, target_pid, apptype, imp_recv, qos_clamp);
+}
+
+template <typename SIZE>
+void print_importance_update_task(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ const char* type,
+ std::unordered_map<pid_t, std::pair<TaskEffectivePolicy, uint32_t>>& task_effective_state)
+{
+ //
+ // event args are:
+ //
+ // targetpid, teffective_0(task, NULL), teffective_1(task, NULL), tpriority(task, THREAD_NULL)
+ //
+ auto pid = (pid_t)event.arg1();
+ auto teffective_0 = event.arg2();
+ auto teffective_1 = event.arg3();
+ auto priority = (uint32_t)event.arg4();
+ auto task_effective_policy = (SIZE::is_64_bit) ? TaskEffectivePolicy(teffective_0) : TaskEffectivePolicy((Kernel32::ptr_t)teffective_0, (Kernel32::ptr_t)teffective_1);
+ auto state = std::pair<TaskEffectivePolicy, uint32_t>(task_effective_policy, priority);
+ auto should_print = false;
+
+ ASSERT(pid != -1, "Sanity");
+
+ // Verify that some state changed before printing.
+ auto it = task_effective_state.find(pid);
+ if (it == task_effective_state.end()) {
+ should_print = true;
+ task_effective_state.emplace(pid, state);
+ } else {
+ if (it->second != state) {
+ should_print = true;
+ it->second = state;
+ }
+ }
+
+ if (should_print) {
+ print_base(buffer, globals, event.timestamp(), machine.thread(event.tid(), event.timestamp()), event, event_index, type, false);
+
+ const char* name;
+ if (auto target = machine.process(pid, event.timestamp())) {
+ name = target->name();
+ } else {
+ name = "???";
+ }
+
+ buffer.printf("%s (%d) base priority is %d\n", name, pid, priority);
+
+ print_teffective_task(buffer, globals, machine, event, event_index, pid, task_effective_policy);
+ }
+}
+
+template <typename SIZE>
+void print_importance_update_thread(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ const char* type,
+ std::unordered_map<typename SIZE::ptr_t, std::pair<TaskEffectivePolicy, uint32_t>>& thread_effective_state)
+{
+ //
+ // event args are:
+ //
+ // targettid, teffective_0(task, thread), teffective_1(task, thread), tpriority(task, thread)
+ //
+
+ if (const MachineThread<SIZE>* thread = machine.thread(event.arg1(), event.timestamp())) {
+ auto pid = thread->process().pid();
+ auto teffective_0 = event.arg2();
+ auto teffective_1 = event.arg3();
+ auto priority = (uint32_t)event.arg4();
+ auto thread_effective_policy = (SIZE::is_64_bit) ? TaskEffectivePolicy(teffective_1) : TaskEffectivePolicy((Kernel32::ptr_t)teffective_0, (Kernel32::ptr_t)teffective_1);
+ auto state = std::pair<TaskEffectivePolicy, uint32_t>(thread_effective_policy, priority);
+ auto should_print = false;
+
+ // Verify that some state changed before printing.
+ auto it = thread_effective_state.find(thread->tid());
+ if (it == thread_effective_state.end()) {
+ should_print = true;
+ thread_effective_state.emplace(thread->tid(), state);
+ } else {
+ if (it->second != state) {
+ should_print = true;
+ it->second = state;
+ }
+ }
+
+ if (should_print) {
+ print_base(buffer, globals, event.timestamp(), machine.thread(event.tid(), event.timestamp()), event, event_index, type, false);
+ buffer.printf("%s (%d) %llX base priority is %d\n", thread->process().name(), pid, (uint64_t)thread->tid(), priority);
+
+ print_teffective_thread(buffer, globals, machine, event, event_index, thread, thread_effective_policy);
+ }
+ }
+}
+
+template <typename SIZE>
+void print_fork(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ const MachineProcess<SIZE>& child_process)
+{
+ print_base(buffer, globals, event.timestamp(), machine.thread(event.tid(), event.timestamp()), event, event_index, "fork", false);
+
+ //
+ // Other process
+ //
+
+ buffer.printf("Create %s (%d)\n", child_process.name(), child_process.pid());
+}
+
+template <typename SIZE>
+void print_exit(PrintBuffer& buffer,
+ const Globals& globals,
+ const KDEvent<SIZE>& event,
+ const MachineThread<SIZE>* thread,
+ uintptr_t event_index)
+{
+ ASSERT(thread, "Sanity");
+
+ print_base(buffer, globals, event.timestamp(), thread, event, event_index, "exit", false);
+
+ //
+ // exit code
+ //
+
+ int exit_status = thread->process().exit_status();
+
+ if (WIFEXITED(exit_status)) {
+ buffer.printf("returned %d\n", WEXITSTATUS(exit_status));
+ } else if (WIFSIGNALED(exit_status)) {
+ buffer.printf("SIGNAL: %s\n", strsignal(WTERMSIG(exit_status)));
+ } else {
+ buffer.printf("Unhandled exit status %x\n", (uint32_t)exit_status);
+ }
+}
+
+template <typename SIZE>
+void print_voucher(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ const char* type,
+ const MachineVoucher<SIZE>* voucher,
+ bool is_create)
+{
+ print_base(buffer, globals, event.timestamp(), machine.thread(event.tid(), event.timestamp()), event, event_index, type, false);
+
+ //
+ // Calculate lifetime
+ //
+
+ char lifetime[32];
+ AbsInterval timespan = voucher->timespan();
+
+ //
+ // Voucher created before the trace starts will have a starting time
+ // of 0; Vouchers that are still alive will have a max of UINT64_MAX.
+ //
+ if (timespan.location() == AbsTime(0) || timespan.max() == AbsTime(UINT64_MAX)) {
+ snprintf(lifetime, sizeof(lifetime), "???");
+ } else {
+ NanoTime t1 = timespan.length().nano_time(globals.timebase());
+ snprintf(lifetime, sizeof(lifetime), "%0.2f", (double)t1.value() / NANOSECONDS_PER_MICROSECOND);
+ }
+
+
+ //
+ // Voucher addr
+ //
+ if (is_create) {
+ buffer.printf("Create voucher-%u @ %llX, lifetime will be %s µs, now %u vouchers\n", voucher->id(), (uint64_t)voucher->address(), lifetime, (uint32_t)event.arg3());
+ } else {
+ buffer.printf("Destroy voucher-%u @ %llX, lifetime was %s µs, now %u vouchers\n", voucher->id(), (uint64_t)voucher->address(), lifetime, (uint32_t)event.arg3());
+ }
+}
+
+template <typename SIZE>
+void print_voucher_contents(PrintBuffer& buffer,
+ const Globals& globals,
+ const Machine<SIZE>& machine,
+ const KDEvent<SIZE>& event,
+ uintptr_t event_index,
+ const MachineVoucher<SIZE>* voucher)
+{
+ const uint8_t* bytes = voucher->content_bytes();
+ uint32_t bytes_required = voucher->content_size();
+
+ ASSERT(bytes_required, "Printing empty voucher");
+
+ unsigned int used_size = 0;
+ mach_voucher_attr_recipe_t recipe = NULL;
+ while (bytes_required > used_size) {
+ recipe = (mach_voucher_attr_recipe_t)&bytes[used_size];
+
+ switch (recipe->key) {
+ case MACH_VOUCHER_ATTR_KEY_NONE:
+ ASSERT(false, "No key in recipe");
+ break;
+
+ case MACH_VOUCHER_ATTR_KEY_ATM:
+ print_base_empty(buffer, globals, event_index, "voucher_create", false);
+ buffer.printf(" voucher-%u | ATM ID %llu\n", voucher->id(), *(uint64_t *)(uintptr_t)recipe->content);
+ break;
+
+ case MACH_VOUCHER_ATTR_KEY_IMPORTANCE:
+ print_base_empty(buffer, globals, event_index, "voucher_create", false);
+ buffer.printf(" voucher-%u | %s\n", voucher->id(), (char *)recipe->content);
+ break;
+
+ case MACH_VOUCHER_ATTR_KEY_BANK:
+ // Spacing and newline is different because that is how BANK formats it :-(
+ print_base_empty(buffer, globals, event_index, "voucher_create", false);
+ buffer.printf(" voucher-%u |%s", voucher->id(), (char *)recipe->content);
+ break;
+
+ case MACH_VOUCHER_ATTR_KEY_USER_DATA:
+ for (uint32_t offset=0; offset<recipe->content_size; offset += 16) {
+ uint8_t* data = ((uint8_t*)recipe->content) + offset;
+ size_t data_remaining = std::min(recipe->content_size - offset, (uint32_t)16);
+
+ print_base_empty(buffer, globals, event_index, "voucher_create", false);
+ buffer.printf(" voucher-%u | UserData: %04u ", voucher->id(), offset);
+
+ // 16 * 3 == 48, 16 chars to spare
+ char hex_buffer[64];
+ // Hex data.
+ for (uint32_t cursor = 0; cursor<data_remaining; cursor++) {
+ char* hex_buffer_tmp = &hex_buffer[cursor * 3];
+ size_t hex_buffer_tmp_size = sizeof(hex_buffer) - cursor * 3;
+ snprintf(hex_buffer_tmp, hex_buffer_tmp_size, "%02x ", data[cursor]);
+ }
+
+ char ascii_buffer[24];
+ for (uint32_t cursor = 0; cursor<data_remaining; cursor++) {
+ if (isprint(data[cursor]))
+ ascii_buffer[cursor] = data[cursor];
+ else
+ ascii_buffer[cursor] = '.';
+ }
+ ascii_buffer[data_remaining] = 0;
+
+ buffer.printf("%-48s %-16s\n", hex_buffer, ascii_buffer);
+ }
+ break;
+
+ default:
+ print_base_empty(buffer, globals, event_index, "voucher_create", false);
+ buffer.printf(" voucher-%u | UNKNOWN key-%u command-%u size-%u\n", voucher->id(), recipe->key, recipe->command, recipe->content_size);
+ break;
+ }
+
+ used_size += sizeof(mach_voucher_attr_recipe_data_t) + recipe->content_size;
+ }
+}
+
+#endif /* defined(__msa__MessagePrinting__) */