Files
xen/tools/xentrace/formats
T
Dario Faggioli dae7b62e97 credit2: fix credit reset happening too few times
There is a bug in commit 5e4b419966 ("xen: credit2: only reset
credit on reset condition"). In fact, the aim of that commit was to
make sure that we do not perform too many credit reset operations
(which are not super cheap, and in an hot-path). But the check used
to determine whether a reset is necessary was the wrong one.

In fact, knowing just that some vCPUs have been skipped, while
traversing the runqueue (in runq_candidate()), is not enough. We
need to check explicitly whether the first vCPU in the runqueue
has a negative amount of credit.

Since a trace record is changed, this patch updates xentrace format file
and xenalyze as well

This should be backported.

Signed-off-by: Dario Faggioli <dfaggioli@suse.com>
Acked-by: George Dunlap <george.dunlap@citrix.com>
2020-04-03 10:46:53 +02:00

226 lines
21 KiB
Plaintext

0x00000000 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) unknown (0x%(event)016x) [ 0x%(1)08x 0x%(2)08x 0x%(3)08x 0x%(4)08x 0x%(5)08x 0x%(6)08x 0x%(7)08x ]
0x0001f001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) lost_records 0x%(1)08x
0x0001f002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) wrap_buffer 0x%(1)08x
0x0001f003 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) cpu_change 0x%(1)08x
0x0001f004 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) trace_irq [ vector = %(1)d, count = %(2)d, tot_cycles = 0x%(3)08x, max_cycles = 0x%(4)08x ]
0x00021002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) continue_running [ dom:vcpu = 0x%(1)08x ]
0x00021011 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) running_to_runnable [ dom:vcpu = 0x%(1)08x ]
0x00021021 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) running_to_blocked [ dom:vcpu = 0x%(1)08x ]
0x00021031 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) running_to_offline [ dom:vcpu = 0x%(1)08x ]
0x00021101 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) runnable_to_running [ dom:vcpu = 0x%(1)08x ]
0x00021121 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) runnable_to_blocked [ dom:vcpu = 0x%(1)08x ]
0x00021131 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) runnable_to_offline [ dom:vcpu = 0x%(1)08x ]
0x00021201 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) blocked_to_running [ dom:vcpu = 0x%(1)08x ]
0x00021211 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) blocked_to_runnable [ dom:vcpu = 0x%(1)08x ]
0x00021231 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) blocked_to_offline [ dom:vcpu = 0x%(1)08x ]
0x00021301 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) offline_to_running [ dom:vcpu = 0x%(1)08x ]
0x00021311 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) offline_to_runnable [ dom:vcpu = 0x%(1)08x ]
0x00021321 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) offline_to_blocked [ dom:vcpu = 0x%(1)08x ]
0x00028001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) sched_add_domain [ domid = 0x%(1)08x ]
0x00028002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) sched_rem_domain [ domid = 0x%(1)08x ]
0x00028003 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_sleep [ dom:vcpu = 0x%(1)04x%(2)04x ]
0x00028004 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_wake [ dom:vcpu = 0x%(1)04x%(2)04x ]
0x00028005 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) do_yield [ dom:vcpu = 0x%(1)04x%(2)04x ]
0x00028006 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) do_block [ dom:vcpu = 0x%(1)04x%(2)04x ]
0x00028007 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_shutdown [ dom:vcpu = 0x%(1)04x%(2)04x, reason = 0x%(3)08x ]
0x00028008 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) sched_ctl
0x00028009 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) sched_adjdom [ domid = 0x%(1)08x ]
0x0002800a CPU%(cpu)d %(tsc)d (+%(reltsc)8d) __enter_scheduler [ prev<dom:vcpu> = 0x%(1)04x%(2)04x, next<dom:vcpu> = 0x%(3)04x%(4)04x ]
0x0002800b CPU%(cpu)d %(tsc)d (+%(reltsc)8d) s_timer_fn
0x0002800c CPU%(cpu)d %(tsc)d (+%(reltsc)8d) t_timer_fn
0x0002800d CPU%(cpu)d %(tsc)d (+%(reltsc)8d) dom_timer_fn
0x0002800e CPU%(cpu)d %(tsc)d (+%(reltsc)8d) switch_infprev [ dom:vcpu = 0x%(1)04x%(2)04x, runtime = %(3)d ]
0x0002800f CPU%(cpu)d %(tsc)d (+%(reltsc)8d) switch_infnext [ new_dom:vcpu = 0x%(1)04x%(2)04x, time = %(3)d, r_time = %(4)d ]
0x00028010 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_shutdown_code [ dom:vcpu = 0x%(1)04x%(2)04x, reason = 0x%(3)08x ]
0x00028011 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) switch_infcont [ dom:vcpu = 0x%(1)04x%(2)04x, runtime = %(3)d, r_time = %(4)d ]
0x00022001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:sched_tasklet
0x00022002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:account_start [ dom:vcpu = 0x%(1)04x%(2)04x, active = %(3)d ]
0x00022003 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:account_stop [ dom:vcpu = 0x%(1)04x%(2)04x, active = %(3)d ]
0x00022004 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:stolen_vcpu [ dom:vcpu = 0x%(2)04x%(3)04x, from = %(1)d ]
0x00022005 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:picked_cpu [ dom:vcpu = 0x%(1)04x%(2)04x, cpu = %(3)d ]
0x00022006 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:tickle [ cpu = %(1)d ]
0x00022007 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:boost [ dom:vcpu = 0x%(1)04x%(2)04x ]
0x00022008 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:unboost [ dom:vcpu = 0x%(1)04x%(2)04x ]
0x00022009 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:schedule [ cpu[16]:tasklet[8]:idle[8] = %(1)08x ]
0x0002200A CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:ratelimit [ dom:vcpu = 0x%(1)08x, runtime = %(2)d ]
0x0002200B CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched:steal_check [ peer_cpu = %(1)d, checked = %(2)d ]
0x00022201 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:tick
0x00022202 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:runq_pos [ dom:vcpu = 0x%(1)08x, pos = %(2)d]
0x00022203 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:credit burn [ dom:vcpu = 0x%(1)08x, credit = %(2)d, budget = %(3)d, delta = %(4)d ]
0x00022204 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:credit_add
0x00022205 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:tickle_check [ dom:vcpu = 0x%(1)08x, credit = %(2)d, score = %(3)d ]
0x00022206 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:tickle [ cpu = %(1)d ]
0x00022207 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:credit_reset [ dom:vcpu = 0x%(1)08x, cr_start = %(2)d, cr_end = %(3)d ]
0x00022208 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:sched_tasklet
0x00022209 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:update_load
0x0002220a CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:runq_assign [ dom:vcpu = 0x%(1)08x, rq_id = %(2)d ]
0x0002220b CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:updt_vcpu_load [ dom:vcpu = 0x%(3)08x, vcpuload = 0x%(2)08x%(1)08x, wshift = %(4)d ]
0x0002220c CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:updt_runq_load [ rq_load[16]:rq_id[8]:wshift[8] = 0x%(5)08x, rq_avgload = 0x%(2)08x%(1)08x, b_avgload = 0x%(4)08x%(3)08x ]
0x0002220d CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:tickle_new [ dom:vcpu = 0x%(1)08x, processor = %(2)d credit = %(3)d ]
0x0002220e CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:runq_max_weight [ rq_id[16]:max_weight[16] = 0x%(1)08x ]
0x0002220f CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:migrrate [ dom:vcpu = 0x%(1)08x, rq_id[16]:trq_id[16] = 0x%(2)08x ]
0x00022210 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:load_check [ lrq_id[16]:orq_id[16] = 0x%(1)08x, delta = %(2)d ]
0x00022211 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:load_balance [ l_bavgload = 0x%(2)08x%(1)08x, o_bavgload = 0x%(4)08x%(3)08x, lrq_id[16]:orq_id[16] = 0x%(5)08x ]
0x00022212 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:pick_cpu [ b_avgload = 0x%(2)08x%(1)08x, dom:vcpu = 0x%(3)08x, rq_id[16]:new_cpu[16] = %(4)d ]
0x00022213 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:runq_candidate [ dom:vcpu = 0x%(1)08x, credit = %(3)d, tickled_cpu = %(2)d ]
0x00022214 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:schedule [ rq:cpu = 0x%(1)08x, tasklet[8]:idle[8]:smt_idle[8]:tickled[8] = %(2)08x ]
0x00022215 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:ratelimit [ dom:vcpu = 0x%(1)08x, runtime = %(2)d ]
0x00022216 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) csched2:runq_cand_chk [ dom:vcpu = 0x%(1)08x ]
0x00022801 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:tickle [ cpu = %(1)d ]
0x00022802 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:runq_pick [ dom:vcpu = 0x%(1)08x, cur_deadline = 0x%(3)08x%(2)08x, cur_budget = 0x%(5)08x%(4)08x ]
0x00022803 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:burn_budget [ dom:vcpu = 0x%(1)08x, cur_budget = 0x%(3)08x%(2)08x, delta = %(4)d ]
0x00022804 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:repl_budget [ dom:vcpu = 0x%(1)08x, cur_deadline = 0x%(3)08x%(2)08x, cur_budget = 0x%(5)08x%(4)08x ]
0x00022805 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:sched_tasklet
0x00022806 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtds:schedule [ cpu[16]:tasklet[8]:idle[4]:tickled[4] = %(1)08x ]
0x00022A01 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) null:pick_cpu [ dom:vcpu = 0x%(1)08x, new_cpu = %(2)d ]
0x00022A02 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) null:assign [ dom:vcpu = 0x%(1)08x, cpu = %(2)d ]
0x00022A03 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) null:deassign [ dom:vcpu = 0x%(1)08x, cpu = %(2)d ]
0x00022A04 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) null:migrate [ dom:vcpu = 0x%(1)08x, new_cpu:cpu = 0x%(2)08x ]
0x00022A05 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) null:schedule [ cpu[16]:tasklet[16] = %(1)08x, dom:vcpu = 0x%(2)08x ]
0x00022A06 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) null:sched_tasklet
0x00041001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_create [ dom = 0x%(1)08x ]
0x00041002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) domain_destroy [ dom = 0x%(1)08x ]
0x00081001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) VMENTRY
0x00081002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) VMEXIT [ exitcode = 0x%(1)08x, rIP = 0x%(2)08x ]
0x00081102 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) VMEXIT [ exitcode = 0x%(1)08x, rIP = 0x%(3)08x%(2)08x ]
0x00081401 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) nVMENTRY
0x00081402 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) nVMEXIT [ exitcode = 0x%(1)08x, rIP = 0x%(2)08x ]
0x00081502 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) nVMEXIT [ exitcode = 0x%(1)08x, rIP = 0x%(3)08x%(2)08x ]
0x00082001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) PF_XEN [ errorcode = 0x%(2)02x, virt = 0x%(1)08x ]
0x00082101 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) PF_XEN [ errorcode = 0x%(3)02x, virt = 0x%(2)08x%(1)08x ]
0x00082002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) PF_INJECT [ errorcode = 0x%(1)02x, virt = 0x%(2)08x ]
0x00082102 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) PF_INJECT [ errorcode = 0x%(1)02x, virt = 0x%(3)08x%(2)08x ]
0x00082003 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) INJ_EXC [ vector = 0x%(1)02x, errorcode = 0x%(2)04x ]
0x00082004 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) INJ_VIRQ [ vector = 0x%(1)02x, fake = %(2)d ]
0x00082005 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) REINJ_VIRQ [ vector = 0x%(1)02x ]
0x00082006 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) IO_READ [ port = 0x%(1)04x, size = %(2)d ]
0x00082007 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) IO_WRITE [ port = 0x%(1)04x, size = %(2)d ]
0x00082008 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) CR_READ [ CR# = %(1)d, value = 0x%(2)08x ]
0x00082108 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) CR_READ [ CR# = %(1)d, value = 0x%(3)08x%(2)08x ]
0x00082009 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) CR_WRITE [ CR# = %(1)d, value = 0x%(2)08x ]
0x00082109 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) CR_WRITE [ CR# = %(1)d, value = 0x%(3)08x%(2)08x ]
0x0008200A CPU%(cpu)d %(tsc)d (+%(reltsc)8d) DR_READ
0x0008200B CPU%(cpu)d %(tsc)d (+%(reltsc)8d) DR_WRITE
0x0008200C CPU%(cpu)d %(tsc)d (+%(reltsc)8d) MSR_READ [ MSR# = 0x%(1)08x, value = 0x%(3)08x%(2)08x ]
0x0008200D CPU%(cpu)d %(tsc)d (+%(reltsc)8d) MSR_WRITE [ MSR# = 0x%(1)08x, value = 0x%(3)08x%(2)08x ]
0x0008200E CPU%(cpu)d %(tsc)d (+%(reltsc)8d) CPUID [ func = 0x%(1)08x, eax = 0x%(2)08x, ebx = 0x%(3)08x, ecx=0x%(4)08x, edx = 0x%(5)08x ]
0x0008200F CPU%(cpu)d %(tsc)d (+%(reltsc)8d) INTR [ vector = 0x%(1)02x ]
0x00082010 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) NMI
0x00082011 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) SMI
0x00082012 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) VMMCALL [ func = 0x%(1)08x ]
0x00082013 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) HLT [ intpending = %(1)d ]
0x00082014 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) INVLPG [ is invlpga? = %(1)d, virt = 0x%(2)08x ]
0x00082114 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) INVLPG [ is invlpga? = %(1)d, virt = 0x%(3)08x%(2)08x ]
0x00082015 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) MCE
0x00082016 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) IOPORT_READ [ port = 0x%(1)04x, data = 0x%(2)08x ]
0x00082216 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) IOPORT_WRITE [ port = 0x%(1)04x, data = 0x%(2)08x ]
0x00082017 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) MMIO_READ [ port = 0x%(1)08x, data = 0x%(2)08x ]
0x00082217 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) MMIO_WRITE [ port = 0x%(1)08x, data = 0x%(2)08x ]
0x00082018 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) CLTS
0x00082019 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) LMSW [ value = 0x%(1)08x ]
0x00082119 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) LMSW [ value = 0x%(2)08x%(1)08x ]
0x0008201a CPU%(cpu)d %(tsc)d (+%(reltsc)8d) RDTSC [ value = 0x%(2)08x%(1)08x ]
0x00082020 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) INTR_WINDOW [ value = 0x%(1)08x ]
0x00082021 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) NPF [ gpa = 0x%(2)08x%(1)08x mfn = 0x%(4)08x%(3)08x qual = 0x%(5)04x p2mt = 0x%(6)04x ]
0x00082023 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) TRAP [ vector = 0x%(1)02x ]
0x0010f001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) page_grant_map [ domid = %(1)d ]
0x0010f002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) page_grant_unmap [ domid = %(1)d ]
0x0010f003 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) page_grant_transfer [ domid = %(1)d ]
0x00201001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) hypercall [ eip = 0x%(1)08x, eax = 0x%(2)08x ]
0x00201101 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) hypercall [ rip = 0x%(2)08x%(1)08x, eax = 0x%(3)08x ]
0x00201003 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) trap [ eip = 0x%(1)08x, trapnr:error = 0x%(2)08x ]
0x00201103 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) trap [ rip = 0x%(2)08x%(1)08x, trapnr:error = 0x%(3)08x ]
0x00201004 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) page_fault [ eip = 0x%(1)08x, addr = 0x%(2)08x, error = 0x%(3)08x ]
0x00201104 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) page_fault [ rip = 0x%(2)08x%(1)08x, addr = 0x%(4)08x%(3)08x, error = 0x%(5)08x ]
0x00201005 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) forced_invalid_op [ eip = 0x%(1)08x ]
0x00201105 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) forced_invalid_op [ rip = 0x%(2)08x%(1)08x ]
0x00201006 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) emulate_privop [ eip = 0x%(1)08x ]
0x00201106 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) emulate_privop [ rip = 0x%(2)08x%(1)08x ]
0x00201007 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) emulate_4G [ eip = 0x%(1)08x ]
0x00201107 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) emulate_4G [ rip = 0x%(2)08x%(1)08x ]
0x00201008 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) math_state_restore
0x00201108 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) math_state_restore
0x00201009 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) paging_fixup [ eip = 0x%(1)08x, addr = 0x%(2)08x ]
0x00201109 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) paging_fixup [ rip = 0x%(2)08x%(1)08x, addr = 0x%(4)08x%(3)08x ]
0x0020100a CPU%(cpu)d %(tsc)d (+%(reltsc)8d) gdt_ldt_mapping_fault [ eip = 0x%(1)08x, offset = 0x%(2)08x ]
0x0020110a CPU%(cpu)d %(tsc)d (+%(reltsc)8d) gdt_ldt_mapping_fault [ rip = 0x%(2)08x%(1)08x, offset = 0x%(4)08x%(3)08x ]
0x0020100b CPU%(cpu)d %(tsc)d (+%(reltsc)8d) ptwr_emulation [ addr = 0x%(3)08x, eip = 0x%(4)08x, npte = 0x%(2)08x%(1)08x ]
0x0020110b CPU%(cpu)d %(tsc)d (+%(reltsc)8d) ptwr_emulation [ addr = 0x%(4)08x%(3)08x, rip = 0x%(6)08x%(5)08x, npte = 0x%(2)08x%(1)08x ]
0x0020100c CPU%(cpu)d %(tsc)d (+%(reltsc)8d) ptwr_emulation_pae [ addr = 0x%(3)08x, eip = 0x%(4)08x, npte = 0x%(2)08x%(1)08x ]
0x0020110c CPU%(cpu)d %(tsc)d (+%(reltsc)8d) ptwr_emulation_pae [ addr = 0x%(4)08x%(3)08x, rip = 0x%(6)08x%(5)08x, npte = 0x%(2)08x%(1)08x ]
0x0020100d CPU%(cpu)d %(tsc)d (+%(reltsc)8d) hypercall [ op = 0x%(1)08x ]
0x0020200e CPU%(cpu)d %(tsc)d (+%(reltsc)8d) hypercall [ op = 0x%(1)08x ]
0x0040f001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_not_shadow [ gl1e = 0x%(2)08x%(1)08x, va = 0x%(3)08x, flags = 0x%(4)08x ]
0x0040f101 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_not_shadow [ gl1e = 0x%(2)08x%(1)08x, va = 0x%(4)08x%(3)08x, flags = 0x%(5)08x ]
0x0040f002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_fast_propagate [ va = 0x%(1)08x ]
0x0040f102 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_fast_propagate [ va = 0x%(2)08x%(1)08x ]
0x0040f003 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_fast_mmio [ va = 0x%(1)08x ]
0x0040f103 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_fast_mmio [ va = 0x%(2)08x%(1)08x ]
0x0040f004 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_false_fast_path [ va = 0x%(1)08x ]
0x0040f104 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_false_fast_path [ va = 0x%(2)08x%(1)08x ]
0x0040f005 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_mmio [ va = 0x%(1)08x ]
0x0040f105 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_mmio [ va = 0x%(2)08x%(1)08x ]
0x0040f006 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_fixup [ gl1e = 0x%(1)08x, va = 0x%(2)08x, flags = 0x%(3)08x ]
0x0040f106 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_fixup [ gl1e = 0x%(2)08x%(1)08x, va = 0x%(4)08x%(3)08x, flags = 0x%(3)08x ]
0x0040f007 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_domf_dying [ va = 0x%(1)08x ]
0x0040f107 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_domf_dying [ va = 0x%(2)08x%(1)08x ]
0x0040f008 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate [ gl1e = 0x%(1)08x, write_val = 0x%(2)08x, va = 0x%(3)08x, flags = 0x%(4)08x ]
0x0040f108 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate [ gl1e = 0x%(2)08x%(1)08x, write_val = 0x%(4)08x%(3)08x, va = 0x%(6)08x%(5)08x, flags = 0x%(7)08x ]
0x0040f009 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_unshadow_user [ va = 0x%(1)08x, gfn = 0x%(2)08x ]
0x0040f109 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_unshadow_user [ va = 0x%(2)08x%(1)08x, gfn = 0x%(4)08x%(3)08x ]
0x0040f00a CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_unshadow_evtinj [ va = 0x%(1)08x, gfn = 0x%(2)08x ]
0x0040f10a CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_unshadow_evtinj [ va = 0x%(2)08x%(1)08x, gfn = 0x%(4)08x%(3)08x ]
0x0040f00b CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_unshadow_unhandled [ va = 0x%(1)08x, gfn = 0x%(2)08x ]
0x0040f10b CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_unshadow_unhandled [ va = 0x%(2)08x%(1)08x, gfn = 0x%(4)08x%(3)08x ]
0x0040f00c CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_wrmap_bf [ gfn = 0x%(1)08x ]
0x0040f10c CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_wrmap_bf [ gfn = 0x%(2)08x%(1)08x ]
0x0040f00d CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_prealloc_unpin [ gfn = 0x%(1)08x ]
0x0040f10d CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_prealloc_unpin [ gfn = 0x%(2)08x%(1)08x ]
0x0040f00e CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_resync_full [ gfn = 0x%(1)08x ]
0x0040f10e CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_resync_full [ gfn = 0x%(2)08x%(1)08x ]
0x0040f00f CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_resync_only [ gfn = 0x%(1)08x ]
0x0040f10f CPU%(cpu)d %(tsc)d (+%(reltsc)8d) shadow_emulate_resync_only [ gfn = 0x%(2)08x%(1)08x ]
0x00801001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) cpu_freq_change [ %(1)dMHz -> %(2)dMHz ]
0x00801002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) cpu_idle_entry [ C0 -> C%(1)d, acpi_pm_tick = %(2)d, expected = %(3)dus, predicted = %(4)dus ]
0x00801003 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) cpu_idle_exit [ C%(1)d -> C0, acpi_pm_tick = %(2)d, irq = %(3)d %(4)d %(5)d %(6)d ]
0x00802001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) cleanup_move_delayed [ irq = %(1)d, vector 0x%(2)x on CPU%(3)d ]
0x00802002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) cleanup_move [ irq = %(1)d, vector 0x%(2)x on CPU%(3)d ]
0x00802003 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) bind_vector [ irq = %(1)d = vector 0x%(2)x, CPU mask: 0x%(3)08x ]
0x00802004 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) clear_vector [ irq = %(1)d = vector 0x%(2)x, CPU mask: 0x%(3)08x ]
0x00802005 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) move_vector [ irq = %(1)d had vector 0x%(2)x on CPU%(3)d ]
0x00802006 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) assign_vector [ irq = %(1)d = vector 0x%(2)x, CPU mask: 0x%(3)08x ]
0x00802007 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) bogus_vector [ 0x%(1)x ]
0x00802008 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) do_irq [ irq = %(1)d, began = %(2)dus, ended = %(3)dus ]
0x00084001 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) hpet create [ tn = %(1)d, irq = %(2)d, delta = 0x%(4)08x%(3)08x, period = 0x%(6)08x%(5)08x ]
0x00084002 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) pit create [ delta = 0x%(1)016x, period = 0x%(2)016x ]
0x00084003 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtc create [ delta = 0x%(1)016x , period = 0x%(2)016x ]
0x00084004 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) vlapic create [ delta = 0x%(2)08x%(1)08x , period = 0x%(4)08x%(3)08x, irq = %(5)d ]
0x00084005 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) hpet destroy [ tn = %(1)d ]
0x00084006 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) pit destroy [ ]
0x00084007 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) rtc destroy [ ]
0x00084008 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) vlapic destroy [ ]
0x00084009 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) pit callback [ ]
0x0008400a CPU%(cpu)d %(tsc)d (+%(reltsc)8d) vlapic callback [ ]
0x0008400b CPU%(cpu)d %(tsc)d (+%(reltsc)8d) vpic_update_int_output [ int_output = %(1)d, is_master = %(2)d, irq = %(3)d ]
0x0008400c CPU%(cpu)d %(tsc)d (+%(reltsc)8d) vpic vcpu_kick [ irq = %(1)d ]
0x0008400d CPU%(cpu)d %(tsc)d (+%(reltsc)8d) __vpic_intack [ is_master = %(1)d, irq = %(2)d ]
0x0008400e CPU%(cpu)d %(tsc)d (+%(reltsc)8d) vpic_irq_positive_edge [ irq = %(1)d ]
0x0008400f CPU%(cpu)d %(tsc)d (+%(reltsc)8d) vpic_irq_negative_edge [ irq = %(1)d ]
0x00084010 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) vpic_ack_pending_irq [ accept_pic_intr = %(1)d, int_output = %(2)d ]
0x00084011 CPU%(cpu)d %(tsc)d (+%(reltsc)8d) vlapic_accept_pic_intr [ i8259_target = %(1)d, accept_pic_int = %(2)d ]