> > > I get hangs on an amd64 SMP machine, the console prints message about > > > recursive locking and the machine never recovers. I looked for > > > existing bugs but it seems your bug database on sourceforge is empty. > > > > > It would help if you could post the kernel message about the locking > > problem. > > I'll collect screenshots of the messages and the backtrace next week.
I tried to reproduce this yesterday. I had to use a slightly different sequence of actions and now I don't get a system hang from kernel locking, instead I get memory corruption (on the heap) in the process being attached to. I attached the perfmon debug output from this run. The last entry (last two seconds) is the one that killed the target process. Also, once I get back to the original pattern that got the kernel hang from incorrect locking, how do I get a Linux kernel backtrace in this situation? I don't have a panic, the kernel is in a wedged state after printing its message about locking errors. How do I get a break here and is there a chance that the backtrace is useful? Remember we'll be in long after the damage is done and we'll most likely be in an unrelated thread. Excuse me ignorance, I'm normally a FreeBSD guy. I should also mention that I could get all the perfmon data I wanted with neither problem by building and booting into a non-SMP build of the same kernel, using just one processor. So both problems seem to be a SMP safety problem and perfmon2 as such works fine for me. Martin Here's the debug. Again, this is from the situation where I get heap corruption in the target process, not the situation where the kernel hangs. Aug 11 10:47:01 jul kernel: perfmon: __pfm_getinfo_evtsets.655: CPU0 [13578]: se t 0 flags=0x0 eff_usec=0 runs=0 Aug 11 10:47:01 jul kernel: perfmon: __pfm_close.534: CPU0 [13578]: ctx_state=1 is_system=0 is_current=1 Aug 11 10:47:01 jul kernel: perfmon: __pfm_close.602: CPU0 [13578]: ctx_state=1 free_possible=1 can_unload=1 Aug 11 10:47:01 jul kernel: perfmon: pfm_context_free.115: CPU0 [13578]: free ct x @ffff81003c35c000 Aug 11 10:47:01 jul kernel: perfmon: pfm_context_alloc.364: CPU0 [13578]: alloc ctx @ffff81003c35c000 Aug 11 10:47:01 jul kernel: perfmon: pfm_alloc_fd.770: CPU0 [13578]: new inode i no=2435074 @ffff8100d789f810 Aug 11 10:47:01 jul kernel: perfmon: pfm_find_set.483: CPU0 [13578]: looking for set=0 Aug 11 10:47:01 jul kernel: perfmon: pfm_find_set.544: CPU0 [13578]: set_id=0 si ze=2584 view=ffff810030a7e968 remap=0 mmap_offs=0 Aug 11 10:47:01 jul kernel: perfmon: pfm_init_evtset.461: CPU0 [13578]: set0 pmc 0=0x100000 Aug 11 10:47:01 jul kernel: perfmon: pfm_init_evtset.461: CPU0 [13578]: set0 pmc 1=0x100000 Aug 11 10:47:01 jul kernel: perfmon: pfm_init_evtset.461: CPU0 [13578]: set0 pmc 2=0x100000 Aug 11 10:47:01 jul kernel: perfmon: pfm_init_evtset.461: CPU0 [13578]: set0 pmc 3=0x100000 Aug 11 10:47:01 jul kernel: perfmon: __pfm_create_context.2504: CPU0 [13578]: ct x=ffff81003c35c000 flags=0x0 system=0 notify_block=0 no_msg=0 use_fmt=0 remap=0 ctx_fd=3 mode=0 Aug 11 10:47:01 jul kernel: perfmon: pfm_check_task_state.46: CPU0 [13578]: stat e=1 [-1] task_state=-1 check_mask=0x2 Aug 11 10:47:01 jul kernel: perfmon: __pfm_create_evtsets.563: CPU0 [13578]: set _id=0 Aug 11 10:47:01 jul kernel: perfmon: pfm_find_set.483: CPU0 [13578]: looking for set=0 Aug 11 10:47:01 jul kernel: perfmon: __pfm_change_evtset.436: CPU0 [13578]: set 0 flags=0x0 id_next=0 req_usec=0jiffies=0 runs=0 HZ=250 TICK_NSEC=4000250 eff_us ec=0 Aug 11 10:47:01 jul kernel: perfmon: pfm_init_evtset.461: CPU0 [13578]: set0 pmc 0=0x100000 Aug 11 10:47:01 jul kernel: perfmon: pfm_init_evtset.461: CPU0 [13578]: set0 pmc 1=0x100000 Aug 11 10:47:01 jul kernel: perfmon: pfm_init_evtset.461: CPU0 [13578]: set0 pmc 2=0x100000 Aug 11 10:47:01 jul kernel: perfmon: pfm_init_evtset.461: CPU0 [13578]: set0 pmc 3=0x100000 Aug 11 10:47:01 jul kernel: perfmon: pfm_check_task_state.46: CPU0 [13578]: stat e=1 [-1] task_state=-1 check_mask=0x1 Aug 11 10:47:01 jul kernel: perfmon: pfm_find_set.483: CPU0 [13578]: looking for set=0 Aug 11 10:47:01 jul kernel: perfmon: __pfm_write_pmcs.1831: CPU0 [13578]: set0 p mc0=0x5100c4 a_pmu=0 u_pmcs=0x1 nu_pmcs=1 Aug 11 10:47:01 jul kernel: perfmon: __pfm_write_pmcs.1831: CPU0 [13578]: set0 p mc1=0x5100c5 a_pmu=0 u_pmcs=0x3 nu_pmcs=2 Aug 11 10:47:01 jul kernel: perfmon: __pfm_write_pmcs.1831: CPU0 [13578]: set0 p mc2=0x5100c6 a_pmu=0 u_pmcs=0x7 nu_pmcs=3 Aug 11 10:47:01 jul kernel: perfmon: __pfm_write_pmcs.1831: CPU0 [13578]: set0 p mc3=0x5100c7 a_pmu=0 u_pmcs=0xf nu_pmcs=4 Aug 11 10:47:01 jul kernel: perfmon: pfm_check_task_state.46: CPU0 [13578]: stat e=1 [-1] task_state=-1 check_mask=0x1 Aug 11 10:47:01 jul kernel: perfmon: pfm_find_set.483: CPU0 [13578]: looking for set=0 Aug 11 10:47:01 jul kernel: perfmon: __pfm_write_pmds.1669: CPU0 [13578]: set0 p md0=0x0 flags=0x0 a_pmu=0 hw_pmd=0x0 ctx_pmd=0x0 s_reset=0x0 l_reset=0x0 u_pmds= 0x1 nu_pmds=1 s_pmds=0x0 r_pmds=0x0 o_pmds=0x0 o_thres=0 compat=0 eventid=0 Aug 11 10:47:01 jul kernel: perfmon: __pfm_write_pmds.1669: CPU0 [13578]: set0 p md1=0x0 flags=0x0 a_pmu=0 hw_pmd=0x0 ctx_pmd=0x0 s_reset=0x0 l_reset=0x0 u_pmds= 0x3 nu_pmds=2 s_pmds=0x0 r_pmds=0x0 o_pmds=0x0 o_thres=0 compat=0 eventid=0 Aug 11 10:47:01 jul kernel: perfmon: __pfm_write_pmds.1669: CPU0 [13578]: set0 p md2=0x0 flags=0x0 a_pmu=0 hw_pmd=0x0 ctx_pmd=0x0 s_reset=0x0 l_reset=0x0 u_pmds= 0x7 nu_pmds=3 s_pmds=0x0 r_pmds=0x0 o_pmds=0x0 o_thres=0 compat=0 eventid=0 Aug 11 10:47:01 jul kernel: perfmon: __pfm_write_pmds.1669: CPU0 [13578]: set0 p md3=0x0 flags=0x0 a_pmu=0 hw_pmd=0x0 ctx_pmd=0x0 s_reset=0x0 l_reset=0x0 u_pmds= 0xf nu_pmds=4 s_pmds=0x0 r_pmds=0x0 o_pmds=0x0 o_thres=0 compat=0 eventid=0 Aug 11 10:47:01 jul kernel: perfmon: pfm_check_task_state.46: CPU0 [13578]: stat e=1 [-1] task_state=-1 check_mask=0x1 Aug 11 10:47:01 jul kernel: perfmon: pfm_find_set.483: CPU0 [13578]: looking for set=0 Aug 11 10:47:01 jul kernel: perfmon: pfm_prepare_sets.101: CPU0 [13578]: set0 sw _next=0 Aug 11 10:47:01 jul kernel: perfmon: pfm_load_context_thread.2006: CPU0 [13578]: load_pid [10936] set=0 runs=0 set_flags=0x0 Aug 11 10:47:02 jul kernel: perfmon: pfm_bad_permissions.1862: CPU0 [13578]: cur : euid=613 uid=613 gid=613 task: euid=613 suid=613 uid=613 egid=613 cap:613 sgid =0 Aug 11 10:47:02 jul kernel: perfmon: pfm_task_incompatible.1921: CPU0 [13578]: b efore wait_inactive() task [10936] state=8 Aug 11 10:47:02 jul kernel: perfmon: pfm_task_incompatible.1928: CPU0 [13578]: a fter wait_inactive() task [10936] state=8 Aug 11 10:47:02 jul kernel: perfmon: pfm_reserve_session.151: CPU0 [13578]: in s ys_sessions=0 task_sessions=0 syswide=0 cpu=4294967295 Aug 11 10:47:02 jul kernel: perfmon: pfm_reserve_session.192: CPU0 [13578]: out sys_sessions=0 task_sessions=1 syswide=0 cpu=4294967295 Aug 11 10:47:02 jul kernel: perfmon: pfm_load_context_thread.2041: CPU0 [13578]: before cmpxchg() old_ctx=0000000000000000 new_ctx=ffff81003c35c000 Aug 11 10:47:02 jul kernel: perfmon: pfm_load_context_thread.2123: CPU0 [13578]: context loaded next ctxswin for [10936] Aug 11 10:47:02 jul kernel: perfmon: pfm_check_task_exist.1984: CPU0 [13578]: re t=0 ctx=ffff81003c35c000 Aug 11 10:47:02 jul kernel: perfmon: pfm_check_task_state.46: CPU0 [13578]: stat e=2 [10936] task_state=8 check_mask=0x1 Aug 11 10:47:02 jul kernel: perfmon: pfm_check_task_state.123: CPU0 [13578]: goi ng wait_inactive for [10936] state=8 flags=0x296 Aug 11 10:47:02 jul kernel: perfmon: __pfm_start.1061: CPU0 [13578]: cur_set=0 r eq_set=0 Aug 11 10:47:05 jul kernel: perfmon: __pfm_exit_thread.673: CPU1 [10936]: state= 2 Aug 11 10:47:05 jul kernel: perfmon: __pfm_unload_context.2281: CPU1 [10936]: ct x_state=2 task [10936] Aug 11 10:47:05 jul kernel: perfmon: __pfm_stop.1170: CPU1 [10936]: ctx_task=[10 936] ctx_state=2 is_system=0 Aug 11 10:47:05 jul kernel: perfmon: pfm_save_pmds_release.581: CPU1 [10936]: re leased ownership Aug 11 10:47:05 jul kernel: perfmon: pfm_flush_pmds.611: CPU1 [10936]: active_se t=0 Aug 11 10:47:05 jul kernel: perfmon: pfm_release_session.223: CPU1 [10936]: in s ys_sessions=0 task_sessions=1 syswide=0 cpu=0 Aug 11 10:47:05 jul kernel: perfmon: pfm_release_session.238: CPU1 [10936]: out sys_sessions=0 task_sessions=0 syswide=0 cpu=0 Aug 11 10:47:05 jul kernel: perfmon: __pfm_unload_context.2335: CPU1 [10936]: do ne, state was 2 Aug 11 10:47:05 jul kernel: perfmon: pfm_get_new_msg.73: CPU1 [10936]: head=0 ta il=0 Aug 11 10:47:05 jul kernel: perfmon: pfm_get_new_msg.83: CPU1 [10936]: head=0 ta il=1 msg=0 Aug 11 10:47:05 jul kernel: perfmon: pfm_end_notify_user.944: CPU1 [10936]: end msg: msg=ffff81003c35c0c8 no_msg=0 Aug 11 10:47:05 jul kernel: perfmon: pfm_notify_user.861: CPU1 [10936]: waking u p somebody Aug 11 10:47:05 jul kernel: perfmon: pfm_check_task_state.46: CPU0 [13578]: stat e=1 [-1] task_state=-1 check_mask=0x1 Aug 11 10:47:05 jul kernel: perfmon: pfm_find_set.483: CPU0 [13578]: looking for set=0 Aug 11 10:47:05 jul kernel: perfmon: __pfm_read_pmds.1403: CPU0 [13578]: set0 pm d0=0x1a9305cd switch_thres=0 Aug 11 10:47:05 jul kernel: perfmon: __pfm_read_pmds.1403: CPU0 [13578]: set0 pm d1=0x1757583 switch_thres=0 Aug 11 10:47:05 jul kernel: perfmon: __pfm_read_pmds.1403: CPU0 [13578]: set0 pm d2=0x41c4 switch_thres=0 Aug 11 10:47:05 jul kernel: perfmon: __pfm_read_pmds.1403: CPU0 [13578]: set0 pm d3=0xd21b switch_thres=0 Aug 11 10:47:05 jul kernel: perfmon: pfm_check_task_state.46: CPU0 [13578]: stat e=1 [-1] task_state=-1 check_mask=0x0 Aug 11 10:47:05 jul kernel: perfmon: __pfm_getinfo_evtsets.603: CPU0 [13578]: se t_id=0 Aug 11 10:47:05 jul kernel: perfmon: __pfm_getinfo_evtsets.655: CPU0 [13578]: se t 0 flags=0x0 eff_usec=0 runs=1 Aug 11 10:47:05 jul kernel: perfmon: __pfm_close.534: CPU0 [13578]: ctx_state=1 is_system=0 is_current=1 Aug 11 10:47:05 jul kernel: perfmon: __pfm_close.602: CPU0 [13578]: ctx_state=1 free_possible=1 can_unload=1 Aug 11 10:47:05 jul kernel: perfmon: pfm_context_free.115: CPU0 [13578]: free ct x @ffff81003c35c000 -- %%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%% Martin Cracauer <[email protected]> http://www.cons.org/cracauer/ FreeBSD - where you want to go, today. http://www.freebsd.org/ _______________________________________________ perfmon mailing list [email protected] http://www.hpl.hp.com/hosted/linux/mail-archives/perfmon/
