From: John L. <le...@mo...> - 2003-10-15 19:26:21
|
On Wed, Oct 15, 2003 at 06:11:45PM +0100, John Levon wrote: > I'll see if I can get a detailed log if/when things go wrong. OK, here we go. This is a loaded machine, and no interrupts are occurring beyond an initial flurry. Before starting up oprofiled I did a pfmdbg --off then --on First, oprofiled.log oprofiled started Wed Oct 15 13:04:12 2003 kernel pointer size: 8 Running perfmon child on CPU0. Waiting on CPU0 Perfmon child up on CPU0 Running perfmon child on CPU1. Waiting on CPU1 Perfmon child up on CPU1 PFM_START on CPU0 PFM_START on CPU1 Shows that both children started up and injected a PFM_START successfully. This is /proc/perfmon afterwards : model : Itanium 2 fastctxsw : No ovfl_mask : 0x7fffffffffff CPU0 overflow intrs : 29 CPU0 overflow cycles : 27532 CPU0 overflow min : 448 CPU0 overflow max : 5197 CPU0 smpl handler calls : 29 CPU0 smpl handler cycles : 8385 CPU0 spurious intrs : 0 CPU0 sysupdt count : 6560 CPU0 sysupdt cycles : 103194 CPU0 syst_wide : 1 CPU0 dcr_pp : 1 CPU0 exclude idle : 0 CPU0 owner : 7935 CPU0 context : e00000027e97c000 CPU0 activations : 0 CPU1 overflow intrs : 425 CPU1 overflow cycles : 422963 CPU1 overflow min : 533 CPU1 overflow max : 4879 CPU1 smpl handler calls : 425 CPU1 smpl handler cycles : 129930 CPU1 spurious intrs : 0 CPU1 sysupdt count : 5320 CPU1 sysupdt cycles : 84516 CPU1 syst_wide : 1 CPU1 dcr_pp : 1 CPU1 exclude idle : 0 CPU1 owner : 7938 CPU1 context : e000000277bfa000 CPU1 activations : 0 proc_sessions : 0 sys_sessions : 2 sys_use_dbregs : 0 ptrace_use_dbregs : 0 format : 77-7a-6e-61-20-65-73-69-74-6e-72-20-61-65-0a-6c oprofile_format format : 4d-72-be-c0-06-64-41-43-82-b4-d3-fd-27-24-3c-97 default_format Note the initial flurry of interrupts, but then nothing. Finally, /var/log/messages during this startup period. Note some of it is a bit inter-mixed due to the two children racing to enter stuff in the kernel syslog. This shows that both children have called pfm_start properly etc. Sorry, it's basically impossible to get a debug_ovfl log - even with 20 ints/s (setting CPU_CYCLES:95000000 on my 900 Mhz CPUs), the machine gets so badly flooded it's not possible to get info out of. And I've yet to get overflow info for one of the "some interrupts on a CPU and then nothing" cases. Is there anybody else has actually tried a system-wide session with perfmon on 2.6 across all CPUs ? Is this new territory here ? Oct 15 13:04:12 easement kernel: perfmon debugging off (timing reset) Oct 15 13:04:12 easement kernel: perfmon debugging on (timing reset) Oct 15 13:04:12 easement kernel: sys_perfmonctl.4835: CPU0 [7831] cmd=pfm_debug ret=0 Oct 15 13:04:12 easement kernel: sys_perfmonctl.4728: CPU0 [7935] cmd=pfm_context_create idx=8 valid=1 narg=0x1 argsz=128 count=1 Oct 15 13:04:12 easement kernel: pfm_ctx_getsize.2539: CPU0 [7935] arg_size=0 Oct 15 13:04:12 easement kernel: sys_perfmonctl.4782: CPU0 [7935] [7935] restart_args sz=128 xtra_sz=0 Oct 15 13:04:12 easement kernel: pfm_context_alloc.854: CPU0 [7935] alloc ctx @e00000027e97c000 Oct 15 13:04:12 easement kernel: pfm_alloc_fd.2143: CPU0 [7935] new inode ino=73454 @e0000040fd8d0b00 Oct 15 13:04:12 easement kernel: pfm_setup_buffer_fmt.2436: CPU0 [7935] [7935] after validate(0x2,0,0000000000000000)=0 Oct 15 13:04:12 easement kernel: pfm_context_create.2716: CPU0 [7935] ctx=e00000027e97c000 flags=0x2 system=1 notify_block=0 excl_idle=0 unsecure=0 no_msg=0 ctx_fd=6 Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[1]=0x0 Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[2]=0x0 Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[3]=0x0 Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[4]=0x800000 Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[5]=0x0 Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[6]=0x0 Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[7]=0x0 Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[8]=0xffffffff3fffffff Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[9]=0xffffffff3ffffffc Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[10]=0x0 Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[11]=0x0 Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[12]=0x0 Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[13]=0x2078fefefefe Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[14]=0xdb60db60db60db6 Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2476: CPU0 [7935] pmc[15]=0xfffffff0 Oct 15 13:04:12 easement kernel: pfm_reset_pmu_state.2512: CPU0 [7935] <6> all_pmcs=0xfffe all_pmds=0x3ffff Oct 15 13:04:12 easement kernel: sys_perfmonctl.4835: CPU0 [7935] cmd=pfm_context_create ret=0 Oct 15 13:04:12 easement kernel: sys_perfmonctl.4728: CPU0 [7935] cmd=pfm_write_pmcs idx=1 valid=1 narg=0xffffffff argsz=160 count=1 Oct 15 13:04:12 easement kernel: sys_perfmonctl.4809: CPU0 [7935] spinlock_irq_save ctx e00000027e97c000 by [7935] Oct 15 13:04:12 easement kernel: sys_perfmonctl.4809: CPU0 [7935] spinlocked ctx e00000027e97c000 by [7935] Oct 15 13:04:12 easement kernel: pfm_check_task_state.4648: CPU0 [7935] context 6 no task, state=1 Oct 15 13:04:12 easement kernel: pfm_mck_reserved.92: CPU0 [7935] pmc[4]=0x801269, mask=0xfffff7f, reset=0x800000, val=0x801269 Oct 15 13:04:12 easement kernel: pfm_write_pmcs.3063: CPU0 [7935] pmc[4]=0x801269 loaded=0 access_pmu=0 all_pmcs=0xfffe used_pmds=0x10 eventid=0 smpl_pmds=0x0 reset_pmds=0x0 reloads_pmcs=0x0 used_monitors=0x10 ovfl_regs=0x0 Oct 15 13:04:12 easement kernel: sys_perfmonctl.4824: CPU0 [7935] [7935] context unlocked Oct 15 13:04:12 easement kernel: sys_perfmonctl.4825: CPU0 [7935] spinlock_irq_restore ctx e00000027e97c000 by [7935] Oct 15 13:04:12 easement kernel: sys_perfmonctl.4835: CPU0 [7935] cmd=pfm_write_pmcs ret=0 Oct 15 13:04:12 easement kernel: sys_perfmonctl.4728: CPU0 [7935] cmd=pfm_write_pmds idx=2 valid=1 narg=0xffffffff argsz=160 count=1 Oct 15 13:04:12 easement kernel: sys_perfmonctl.4809: CPU0 [7935] spinlock_irq_save ctx e00000027e97c000 by [7935] Oct 15 13:04:12 easement kernel: sys_perfmonctl.4809: CPU0 [7935] spinlocked ctx e00000027e97c000 by [7935] Oct 15 13:04:12 easement kernel: pfm_check_task_state.4648: CPU0 [7935] context 6 no task, state=1 Oct 15 13:04:12 easement kernel: pfm_write_pmds.3246: CPU0 [7935] pmd[4]=0xfffffffffff92230 loaded=0 access_pmu=0, hw_value=0xfffffffffff92230 ctx_pmd=0xfffffffffff92230 short_reset=0xfffffffffff92230 long_reset=0x0 notify=N used_pmds=0x10 reset_pmds=0x0 reload_pmds=0x0 all_pmds=0x3ffff ovfl_regs=0x0 Oct 15 13:04:13 easement kernel: sys_perfmonctl.4824: CPU0 [7935] [7935] context unlocked Oct 15 13:04:13 easement kernel: sys_perfmonctl.4825: CPU0 [7935] spinlock_irq_restore ctx e00000027e97c000 by [7935] Oct 15 13:04:13 easement kernel: sys_perfmonctl.4835: CPU0 [7935] cmd=pfm_write_pmds ret=0 Oct 15 13:04:13 easement kernel: sys_perfmonctl.4728: CPU0 [7935] cmd=pfm_context_load idx=16 valid=1 narg=0x1 argsz=32 count=1 Oct 15 13:04:13 easement kernel: sys_perfmonctl.4809: CPU0 [7935] spinlock_irq_save ctx e00000027e97c000 by [7935] Oct 15 13:04:13 easement kernel: sys_perfmonctl.4809: CPU0 [7935] spinlocked ctx e00000027e97c000 by [7935] Oct 15 13:04:13 easement kernel: pfm_check_task_state.4648: CPU0 [7935] context 6 no task, state=1 Oct 15 13:04:13 easement kernel: pfm_context_load.4176: CPU0 [7935] load_pid [7935] Oct 15 13:04:13 easement kernel: pfm_bad_permissions.2376: CPU0 [7935] [7935] cur: uid=0 gid=0 task: euid=0 suid=0 uid=0 egid=0 sgid=0 Oct 15 13:04:13 easement kernel: pfm_reserve_session.1314: CPU0 [7935] in sys_sessions=0 task_sessions=0 dbregs=0 syswide=1 cpu=0 Oct 15 13:04:13 easement kernel: pfm_reserve_session.1328: CPU0 [7935] reserving system wide session on CPU0 currently on CPU0 Oct 15 13:04:13 easement kernel: pfm_reserve_session.1344: CPU0 [7935] out sys_sessions=1 task_sessions=0 dbregs=0 syswide=1 cpu=0 Oct 15 13:04:13 easement kernel: pfm_context_load.4249: CPU0 [7935] [7935] before cmpxchg() old_ctx=0000000000000000 new_ctx=e00000027e97c000 Oct 15 13:04:13 easement kernel: pfm_reset_msgq.791: CPU0 [7935] ctx=e00000027e97c000 msgq reset Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1070: CPU0 [7935] mask=0x3ffff Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[0]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[1]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[2]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[3]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[4]=0x7ffffff92230 soft_val=0xffff800000000000 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[5]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[6]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[7]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[8]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[9]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[10]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[11]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[12]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[13]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[14]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[15]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[16]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmds.1091: CPU0 [7935] pmd[17]=0x0 soft_val=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1105: CPU0 [7935] mask=0xfffe Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[0]=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[1]=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[2]=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[3]=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[4]=0x801269 Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[5]=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[6]=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[7]=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[8]=0xffffffff3fffffff Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[9]=0xffffffff3ffffffc Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[10]=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[11]=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[12]=0x0 Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[13]=0x2078fefefefe Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[14]=0xdb60db60db60db6 Oct 15 13:04:13 easement kernel: pfm_copy_pmcs.1110: CPU0 [7935] pmc[15]=0xfffffff0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1048: CPU0 [7935] mask=0x3ffff Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[0]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[1]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[2]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[3]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[4]=0x7ffffff92230 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[5]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[6]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[7]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[8]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[9]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[10]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[11]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[12]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[13]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[14]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[15]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[16]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmds.1053: CPU0 [7935] pmd[17]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1121: CPU0 [7935] mask=0xfffe Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[1]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[2]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[3]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[4]=0x801269 Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[5]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[6]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[7]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[8]=0xffffffff3fffffff Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[9]=0xffffffff3ffffffc Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[10]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[11]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[12]=0x0 Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[13]=0x2078fefefefe Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[14]=0xdb60db60db60db6 Oct 15 13:04:13 easement kernel: pfm_restore_pmcs.1125: CPU0 [7935] pmc[15]=0xfffffff0 oct 15 13:04:13 easement kernel: pfm_context_load.4331: CPU0 [7935] context loaded on PMU for [7935] Oct 15 13:04:13 easement kernel: sys_perfmonctl.4824: CPU0 [7935] [7935] context unlocked Oct 15 13:04:13 easement kernel: sys_perfmonctl.4825: CPU0 [7935] spinlock_irq_restore ctx e00000027e97c000 by [7935] Oct 15 13:04:13 easement kernel: sys_perfmonctl.4835: CPU0 [7935] cmd=pfm_context_load ret=0 Oct 15 13:04:14 easement kernel: sys_perfmonctl.4728: CPU1 [7938] cmd=pfm_context_create idx=8 valid=1 narg=0x1 argsz=128 count=1 Oct 15 13:04:14 easement kernel: pfm_ctx_getsize.2539: CPU1 [7938] arg_size=0 Oct 15 13:04:14 easement kernel: sys_perfmonctl.4782: CPU1 [7938] [7938] restart_args sz=128 xtra_sz=0 Oct 15 13:04:14 easement kernel: pfm_context_alloc.854: CPU1 [7938] alloc ctx @e000000277bfa000 Oct 15 13:04:14 easement kernel: pfm_alloc_fd.2143: CPU1 [7938] new inode ino=73457 @e0000040fd8d0d80 Oct 15 13:04:14 easement kernel: pfm_setup_buffer_fmt.2436: CPU1 [7938] [7938] after validate(0x2,0,0000000000000000)=0 Oct 15 13:04:14 easement kernel: pfm_context_create.2716: CPU1 [7938] ctx=e000000277bfa000 flags=0x2 system=1 notify_block=0 excl_idle=0 unsecure=0 no_msg=0 ctx_fd=6 Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[1]=0x0 Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[2]=0x0 Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[3]=0x0 Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[4]=0x800000 Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[5]=0x0 Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[6]=0x0 Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[7]=0x0 Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[8]=0xffffffff3fffffff Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[9]=0xffffffff3ffffffc Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[10]=0x0 Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[11]=0x0 Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[12]=0x0 Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[13]=0x2078fefefefe Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[14]=0xdb60db60db60db6 Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2476: CPU1 [7938] pmc[15]=0xfffffff0 Oct 15 13:04:14 easement kernel: pfm_reset_pmu_state.2512: CPU1 [7938] <6> all_pmcs=0xfffe all_pmds=0x3ffff Oct 15 13:04:14 easement kernel: sys_perfmonctl.4835: CPU1 [7938] cmd=pfm_context_create ret=0 Oct 15 13:04:14 easement kernel: sys_perfmonctl.4728: CPU1 [7938] cmd=pfm_write_pmcs idx=1 valid=1 narg=0xffffffff argsz=160 count=1 Oct 15 13:04:14 easement kernel: sys_perfmonctl.4809: CPU1 [7938] spinlock_irq_save ctx e000000277bfa000 by [7938] Oct 15 13:04:14 easement kernel: sys_perfmonctl.4809: CPU1 [7938] spinlocked ctx e000000277bfa000 by [7938] Oct 15 13:04:14 easement kernel: pfm_check_task_state.4648: CPU1 [7938] context 6 no task, state=1 Oc:1 t 15 13:04:14 easement kernel: pfm_mck_reserved.92: CPU1 [7938] pmc[4]=0x801269, mask=0xfffff7f, reset=0x800000, val=0x801269 Oct 15 13:04:14 easement kernel: pfm_write_pmcs.3063: CPU1 [7938] pmc[4]=0x801269 loaded=0 access_pmu=0 all_pmcs=0xfffe used_pmds=0x10 eventid=0 smpl_pmds=0x0 reset_pmds=0x0 reloads_pmcs=0x0 used_monitors=0x10 ovfl_regs=0x0 Oct 15 13:04:14 easement kernel: sys_perfmonctl.4824: CPU1 [7938] [7938] context unlocked Oct 15 13:04:14 easement kernel: sys_perfmonctl.4825: CPU1 [7938] spinlock_irq_restore ctx e000000277bfa000 by [7938] Oct 15 13:04:14 easement kernel: sys_perfmonctl.4835: CPU1 [7938] cmd=pfm_write_pmcs ret=0 Oct 15 13:04:14 easement kernel: sys_perfmonctl.4728: CPU1 [7938] cmd=pfm_write_pmds idx=2 valid=1 narg=0xffffffff argsz=160 count=1 Oct 15 13:04:14 easement kernel: sys_perfmonctl.4809: CPU1 [7938] spinlock_irq_save ctx e000000277bfa000 by [7938] Oct 15 13:04:14 easement kernel: sys_perfmonctl.4809: CPU1 [7938] spinlocked ctx e000000277bfa000 by [7938] Oct 15 13:04:14 easement kernel: pfm_check_task_state.4648: CPU1 [7938] context 6 no task, state=1 Oct 15 13:04:14 easement kernel: pfm_write_pmds.3246: CPU1 [7938] pmd[4]=0xfffffffffff92230 loaded=0 access_pmu=0, hw_value=0xfffffffffff92230 ctx_pmd=0xfffffffffff92230 short_reset=0xfffffffffff92230 long_reset=0x0 notify=N used_pmds=0x10 reset_pmds=0x0 reload_pmds=0x0 all_pmds=0x3ffff ovfl_regs=0x0 Oct 15 13:04:14 easement kernel: sys_perfmonctl.4824: CPU1 [7938] [7938] context unlocked Oct 15 13:04:14 easement kernel: sys_perfmonctl.4825: CPU1 [7938] spinlock_irq_restore ctx e000000277bfa000 by [7938] Oct 15 13:04:14 easement kernel: sys_perfmonctl.4835: CPU1 [7938] cmd=pfm_write_pmds ret=0 Oct 15 13:04:14 easement kernel: sys_perfmonctl.4728: CPU1 [7938] cmd=pfm_context_load idx=16 valid=1 narg=0x1 argsz=32 count=1 Oct 15 13:04:14 easement kernel: sys_perfmonctl.4809: CPU1 [7938] spinlock_irq_save ctx e000000277bfa000 by [7938] Oct 15 13:04:14 easement kernel: sys_perfmonctl.4809: CPU1 [7938] spinlocked ctx e000000277bfa000 by [7938] Oct 15 13:04:14 easement kernel: pfm_check_task_state.4648: CPU1 [7938] context 6 no task, state=1 Oct 15 13:04:14 easement kernel: pfm_context_load.4176: CPU1 [7938] load_pid [7938] Oct 15 13:04:14 easement kernel: pfm_bad_permissions.2376: CPU1 [7938] [7938] cur: uid=0 gid=0 task: euid=0 suid=0 uid=0 egid=0 sgid=0 Oct 15 13:04:14 easement kernel: pfm_reserve_session.1314: CPU1 [7938] in sys_sessions=1 task_sessions=0 dbregs=0 syswide=1 cpu=1 Oct 15 13:04:14 easement kernel: pfm_reserve_session.1328: CPU1 [7938] reserving system wide session on CPU1 currently on CPU1 Oct 15 13:04:14 easement kernel: pfm_reserve_session.1344: CPU1 [7938] out sys_sessions=2 task_sessions=0 dbregs=0 syswide=1 cpu=1 Oct 15 13:04:14 easement kernel: pfm_context_load.4249: CPU1 [7938] [7938] before cmpxchg() old_ctx=0000000000000000 new_ctx=e000000277bfa000 Oct 15 13:04:14 easement kernel: pfm_reset_msgq.791: CPU1 [7938] ctx=e000000277bfa000 msgq reset Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1070: CPU1 [7938] mask=0x3ffff Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[0]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[1]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[2]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[3]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[4]=0x7ffffff92230 soft_val=0xffff800000000000 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[5]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[6]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[7]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[8]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[9]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[10]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[11]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[12]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[13]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[14]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[15]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[16]=0x0 soft_val=0x0 Oct 15 13:04:14 easement kernel: pfm_copy_pmds.1091: CPU1 [7938] pmd[17]=0x0 soft_val=0x0 Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1105: CPU1 [7938] mask=0xfffe Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[0]=0x0 Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[1]=0x0 Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[2]=0x0 Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[3]=0x0 Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[4]=0x801269 Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[5]=0x0 Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[6]=0x0 Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[7]=0x0 Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[8]=0xffffffff3fffffff Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[9]=0xffffffff3ffffffc Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[10]=0x0 Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[11]=0x0 Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[12]=0x0 Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[13]=0x2078fefefefe Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[14]=0xdb60db60db60db6 Oct 15 13:04:15 easement kernel: pfm_copy_pmcs.1110: CPU1 [7938] pmc[15]=0xfffffff0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1048: CPU1 [7938] mask=0x3ffff Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[0]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[1]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[2]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[3]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[4]=0x7ffffff92230 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[5]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[6]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[7]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[8]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[9]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[10]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[11]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[12]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[13]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[14]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[15]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[16]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmds.1053: CPU1 [7938] pmd[17]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1121: CPU1 [7938] mask=0xfffe Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[1]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[2]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[3]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[4]=0x801269 Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[5]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[6]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[7]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[8]=0xffffffff3fffffff Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[9]=0xffffffff3ffffffc Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[10]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[11]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[12]=0x0 Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[13]=0x2078fefefefe Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[14]=0xdb60db60db60db6 Oct 15 13:04:15 easement kernel: pfm_restore_pmcs.1125: CPU1 [7938] pmc[15]=0xfffffff0 Oct 15 13:04:15 easement kernel: pfm_context_load.4331: CPU1 [7938] context loaded on PMU for [7938] Oct 15 13:04:15 easement kernel: sys_perfmonctl.4824: CPU1 [7938] [7938] context unlocked Oct 15 13:04:15 easement kernel: sys_perfmonctl.4825: CPU1 [7938] spinlock_irq_restore ctx e000000277bfa000 by [7938] Oct 15 13:04:15 easement kernel: sys_perfmonctl.4835: CPU1 [7938] cmd=pfm_context_load ret=0 Oct 15 13:04:16 easement kernel: sys_perfmonctl.4728: CPU0 [7935] sys_perfmonctl.4728: CPU1 [7938] cmd=pfm_start idx=5 valid=1 narg=0x0 argsz=0 count=0 Oct 15 13:04:16 easement kernel: sys_perfmonctl.4809: CPU1 [7938] spinlock_irq_save ctx e000000277bfa000 by [7938] Oct 15 13:04:16 easement kernel: sys_perfmonctl.4809: CPU1 [7938] spinlocked ctx e000000277bfa000 by [7938] Oct 15 13:04:16 easement kernel: pfm_check_task_state.4656: CPU1 [7938] context 6 state=2 [7938] task_state=0 must_stop=8 Oct 15 13:04:16 easement kernel: sys_perfmonctl.4824: CPU1 [7938] [7938] context unlocked Oct 15 13:04:16 easement kernel: sys_perfmonctl.4825: CPU1 [7938] spinlock_irq_restore ctx e000000277bfa000 by [7938] Oct 15 13:04:16 easement kernel: sys_perfmonctl.4835: CPU1 [7938] cmd=pfm_start ret=0 Oct 15 13:04:16 easement kernel: cmd=pfm_start idx=5 valid=1 narg=0x0 argsz=0 count=0 Oct 15 13:04:16 easement kernel: sys_perfmonctl.4809: CPU0 [7935] spinlock_irq_save ctx e00000027e97c000 by [7935] Oct 15 13:04:16 easement kernel: sys_perfmonctl.4809: CPU0 [7935] spinlocked ctx e00000027e97c000 by [7935] Oct 15 13:04:16 easement kernel: pfm_check_task_state.4656: CPU0 [7935] context 6 state=2 [7935] task_state=0 must_stop=8 Oct 15 13:04:16 easement kernel: sys_perfmonctl.4824: CPU0 [7935] [7935] context unlocked Oct 15 13:04:16 easement kernel: sys_perfmonctl.4825: CPU0 [7935] spinlock_irq_restore ctx e00000027e97c000 by [7935] Oct 15 13:04:16 easement kernel: sys_perfmonctl.4835: CPU0 [7935] cmd=pfm_start ret=0 -- Khendon's Law: If the same point is made twice by the same person, the thread is over. |