On Nov 15, 2005, at 6:27 PM, Jim Rees wrote:

CheckHost in fact already runs with the host held. I was wondering whether it was really necessary to keep locking and unlocking the hash table but
decided to play it safe for now and leave it as-is.

Doing some research into lock debugging on Solaris, I came across a new utility on Solaris 10 which uses Dtrace to instrument a running process.

man plockstat

I'll try using it if (when) things hang here again.

Here's an example of it running against the fileserver process on one of our AFS servers:

[EMAIL PROTECTED]>plockstat -p 15036
^C
Mutex block

Count     nsec Lock                         Caller
------------------------------------------------------------------------ -------
    2  1177064 fileserver`vol_glock_mutex   fileserver`VGetVolume+0x13
1 883084 fileserver`host_glock_mutex fileserver`BreakCallBack +0x5e
    6   681057 fileserver`host_glock_mutex  fileserver`h_Lock_r+0x61
1 626845 fileserver`host_glock_mutex fileserver`AddCallBack1 +0x13
    1   578742 0x8b60348                    fileserver`ubik_Call+0x26
1 472418 fileserver`host_glock_mutex fileserver`h_FindClient_r +0x608 4 370074 fileserver`host_glock_mutex fileserver`CallPreamble +0x2c
    6   310114 fileserver`host_glock_mutex  fileserver`GetClient+0x17
1 299881 fileserver`rx_stats_mutex fileserver`rxi_SendList +0x2a8 4 155413 fileserver`vol_glock_mutex fileserver`VVnodeWriteToRead_r+0x266 1 154461 fileserver`vol_glock_mutex fileserver`VAdjustDiskUsage+0x12 2 139791 fileserver`rx_stats_mutex fileserver`rxi_ReadPacket +0x1bc 1 92994 fileserver`host_glock_mutex fileserver`MultiBreakCallBack_r+0x2e4
    1    90630 libc.so.1`libc_malloc_lock   fileserver`rxi_Start+0x31a
    2    87102 fileserver`vol_glock_mutex   fileserver`VGetVnode+0x13
2 84733 fileserver`vol_glock_mutex fileserver`VVnodeWriteToRead+0x13
    2    69585 fileserver`host_glock_mutex  fileserver`GetRights+0xec
13 68516 fileserver`vol_glock_mutex fileserver`VGetVnode_r +0x71c
    5    59303 fileserver`vol_glock_mutex   fileserver`VPutVnode+0x12
3 51464 fileserver`rx_stats_mutex fileserver`rxi_AllocPacketTSFPQ+0x37 2 49638 fileserver`rx_stats_mutex fileserver`ReturnToServerPool+0x23 1 41909 fileserver`vol_glock_mutex fileserver`VGetVnode_r +0x4ca 2 36799 fileserver`vol_glock_mutex fileserver`VVnodeWriteToRead+0x13 3 36217 fileserver`rx_stats_mutex fileserver`rxi_SendPacket +0x24a 1 32362 fileserver`fileproc_glock_mutex fileserver`common_FetchData64+0x27 1 31798 fileserver`rx_serverPool_lock fileserver`rxi_AttachServerProc+0x30 1 31062 fileserver`rx_stats_mutex fileserver`rxi_SendPacketList+0x381 1 22981 0x9e61614 fileserver`rxi_SendList +0x3a3 6 17154 fileserver`vol_glock_mutex fileserver`VGetVnode_r +0x71c 2 16334 fileserver`host_glock_mutex fileserver`CallPostamble +0x14 3 13548 fileserver`rx_stats_mutex fileserver`rxi_AllocPacketTSFPQ+0x37
    8    13114 fileserver`vol_glock_mutex   fileserver`VPutVnode+0x12
1 9272 fileserver`rx_stats_mutex fileserver`rxi_ServerProc +0xf7 3 8949 fileserver`host_glock_mutex fileserver`CallPreamble +0x2c
    4     8796 fileserver`host_glock_mutex  fileserver`GetClient+0x17
    6     8743 fileserver`host_glock_mutex  fileserver`h_Lock_r+0x61
    1     8563 fileserver`ih_glock_mutex    fileserver`ih_open+0x3c
1 8258 fileserver`vol_glock_mutex fileserver`VAllocVnode_r +0x472 2 7757 fileserver`vol_glock_mutex fileserver`VVnodeWriteToRead_r+0x266 1 7454 fileserver`rx_stats_mutex fileserver`rxi_SendList +0x5b
    1     7425 fileserver`ih_glock_mutex    fileserver`ih_release+0x37
    1     7045 fileserver`ih_glock_once     libc.so.1`pthread_once+0x2c
2 6125 fileserver`host_glock_mutex fileserver`AddCallBack1 +0x13
    2     5944 fileserver`ih_glock_mutex    fileserver`ih_copy+0x27
    1     5415 fileserver`vol_glock_mutex   fileserver`VPutVolume+0x12

Mutex spin

Count     nsec Lock                         Caller
------------------------------------------------------------------------ -------
    1    17615 fileserver`freeSQEList_lock  fileserver`rx_GetCall+0x3a5
1 9766 fileserver`vol_glock_mutex fileserver`VAdjustDiskUsage+0x12 1 9230 fileserver`host_glock_mutex fileserver`DeleteFileCallBacks+0x14
    1     8195 fileserver`vol_glock_mutex   fileserver`VPutVolume+0x12
1 7711 0x932821c fileserver`rxi_CheckConnReach+0x3e 26 7529 fileserver`vol_glock_mutex fileserver`VGetVnode_r +0x71c
    2     7324 fileserver`ih_glock_mutex    fileserver`ih_open+0x3c
    9     6985 fileserver`vol_glock_mutex   fileserver`VGetVnode+0x13
1 6612 fileserver`fileproc_glock_mutex fileserver`common_FetchData64+0x27b 1 6588 fileserver`host_glock_mutex fileserver`h_GetHost_r +0x3af 1 6185 fileserver`fileproc_glock_mutex fileserver`SRXAFS_FetchStatus+0xb8
   84     6084 fileserver`host_glock_mutex  fileserver`h_Lock_r+0x61
1 5975 0x99929f0 fileserver`rx_GetSpecific +0x14 1 5912 fileserver`host_glock_mutex fileserver`MultiBreakCallBack_r+0x364
   39     5639 fileserver`ih_glock_once     libc.so.1`pthread_once+0x2c
   24     5597 fileserver`vol_glock_mutex   fileserver`VPutVnode+0x12
3 5551 fileserver`fileproc_glock_mutex fileserver`FetchData_RXStyle+0x2d2 1 5531 0x932177c fileserver`rxi_SendList +0x281
   15     5474 fileserver`rx_stats_mutex    fileserver`rxi_Start+0x433
3 5468 fileserver`host_glock_mutex fileserver`BreakCallBack +0x5e 2 5457 fileserver`fileproc_glock_mutex fileserver`SAFSS_FetchStatus+0x75 1 5420 fileserver`rxevent_lock fileserver`rxevent_RaiseEvents+0x117
   16     5356 fileserver`rx_serverPool_lock fileserver`rx_GetCall+0xa1
2 5316 0x9a018b8 fileserver`rxi_FindConnection+0x36e 2 5099 fileserver`vol_glock_mutex fileserver`VPutVnode_r +0x367 15 5095 fileserver`vol_glock_mutex fileserver`VGetVnode_r +0x4ca 14 5062 fileserver`rx_stats_mutex fileserver`rxi_ReceiveDataPacket+0x16
    6     5037 fileserver`ih_glock_mutex    fileserver`fd_close+0x37
33 5033 fileserver`host_glock_mutex fileserver`CallPreamble +0x2c 4 5028 fileserver`vol_glock_mutex fileserver`VVnodeWriteToRead_r+0x266 52 4926 fileserver`host_glock_mutex fileserver`CallPostamble +0x14
   38     4889 fileserver`host_glock_mutex  fileserver`GetRights+0xec
1 4837 0x9a018b8 fileserver`rxi_ReceiveDataPacket+0x108 3 4815 fileserver`rx_stats_mutex fileserver`rxi_SendAck +0x585 3 4754 0x932177c fileserver`rxi_ReadPacket +0x20e 6 4715 fileserver`rx_stats_mutex fileserver`rxi_SendPacketList+0x381
    1     4694 libc.so.1`libc_malloc_lock   fileserver`osi_free+0x4f
1 4674 0x99929f0 fileserver`rxi_ReceivePacket+0x74e
    3     4671 fileserver`ih_glock_mutex    fileserver`ih_release+0x37
   20     4671 fileserver`host_glock_mutex  fileserver`GetClient+0x17
5 4640 fileserver`fileproc_glock_mutex fileserver`SetVolumeSync+0x12 3 4603 fileserver`vol_glock_mutex fileserver`VVnodeWriteToRead+0x13
   25     4593 fileserver`vol_glock_mutex   fileserver`VGetVolume+0x13
2 4528 fileserver`rx_stats_mutex fileserver`rxi_AllocPacketNoLock+0x37 23 4438 fileserver`host_glock_mutex fileserver`AddCallBack1 +0x13
    2     4346 libc.so.1`libc_malloc_lock   fileserver`rxi_Start+0x4c4
59 4162 fileserver`rx_stats_mutex fileserver`rxi_SendList +0x2a8 4 4155 fileserver`rx_serverPool_lock fileserver`rxi_AttachServerProc+0x30 70 4012 fileserver`rx_stats_mutex fileserver`rxi_AllocPacketTSFPQ+0x37 15 3881 fileserver`rxevent_lock fileserver`_rxevent_Post +0x16
    1     3853 fileserver`ih_glock_mutex    fileserver`ih_copy+0x27
51 3824 fileserver`rx_stats_mutex fileserver`rxi_ReadPacket +0x1bc
   19     3663 fileserver`rx_stats_mutex    fileserver`QuotaOK+0x26
1 3651 0x9a018b8 fileserver`rx_GetSpecific +0x14 23 3492 fileserver`rx_stats_mutex fileserver`rxi_SendPacket +0x24a 4 3466 fileserver`rx_stats_mutex fileserver`rxi_ComputeRoundTripTime+0x7 29 3458 fileserver`rx_stats_mutex fileserver`rxi_SendList +0x5b
    2     3404 fileserver`ih_glock_mutex    fileserver`ih_fdclose+0x1d1
48 3394 fileserver`rx_stats_mutex fileserver`ReturnToServerPool+0x23
    2     3358 libc.so.1`libc_malloc_lock   fileserver`rxi_Start+0x31a
20 3342 fileserver`rx_stats_mutex fileserver`rxi_ReceiveAckPacket+0x29 10 3340 fileserver`rxevent_lock fileserver`rxevent_Cancel_1+0x5a 4 3339 fileserver`fileproc_glock_mutex fileserver`SRXAFS_FetchStatus+0x16
    3     3303 libc.so.1`libc_malloc_lock   fileserver`rxi_Start+0x4c4
26 3301 fileserver`rx_stats_mutex fileserver`rxi_ServerProc +0xf7
    2     3283 fileserver`ih_glock_mutex    fileserver`ih_open+0x13a
    1     3276 fileserver`afs_bufferLock+0x4 fileserver`DRead+0x353
    1     3165 fileserver`freeSQEList_lock  fileserver`rx_GetCall+0x17
1 3123 fileserver`host_glock_mutex fileserver`h_FindClient_r +0x608
    2     3041 libc.so.1`libc_malloc_lock   fileserver`rxi_Start+0x31a
    1     2914 0x8bbb3dc                    fileserver`h_Lock_r+0x27
    4     2908 libc.so.1`libc_malloc_lock   fileserver`rxi_Start+0x31a
    1     2904 libc.so.1`libc_malloc_lock   fileserver`osi_alloc+0x47
1 2899 0x932177c fileserver`rxi_ResetCall +0x8b 1 2868 0x92d2c54 fileserver`rxi_ReadPacket +0x20e 2 2832 0x932177c fileserver`rxi_SendList +0x2d
    2     2616 fileserver`ih_glock_mutex    fileserver`ih_init+0x4d
1 2527 0x939555c fileserver`rxi_SendList +0x2d 1 2495 0x932177c fileserver`rxi_SendPacket +0x27a 1 2369 0x9e61614 fileserver`rxi_SendList +0x3a3

Mutex unsuccessful spin

Count     nsec Lock                         Caller
------------------------------------------------------------------------ ------- 1 16706 fileserver`rx_stats_mutex fileserver`rxi_SendPacketList+0x381 1 16350 fileserver`rx_serverPool_lock fileserver`rxi_AttachServerProc+0x30
    2    14818 fileserver`host_glock_mutex  fileserver`GetRights+0xec
6 14724 fileserver`rx_stats_mutex fileserver`rxi_AllocPacketTSFPQ+0x37 1 14414 0x9e61614 fileserver`rxi_SendList +0x3a3 1 14086 fileserver`rx_stats_mutex fileserver`rxi_SendList +0x5b 4 13965 fileserver`vol_glock_mutex fileserver`VVnodeWriteToRead+0x13 19 13818 fileserver`vol_glock_mutex fileserver`VGetVnode_r +0x71c 1 13653 fileserver`vol_glock_mutex fileserver`VAllocVnode_r +0x472 1 13529 fileserver`vol_glock_mutex fileserver`VAdjustDiskUsage+0x12 1 13485 fileserver`vol_glock_mutex fileserver`VGetVnode_r +0x4ca
    2    13400 fileserver`vol_glock_mutex   fileserver`VGetVnode+0x13
    1    13338 fileserver`ih_glock_mutex    fileserver`ih_open+0x3c
   13    12966 fileserver`vol_glock_mutex   fileserver`VPutVnode+0x12
3 12947 fileserver`rx_stats_mutex fileserver`rxi_SendPacket +0x24a 1 12883 fileserver`rx_stats_mutex fileserver`rxi_ServerProc +0xf7 7 12754 fileserver`host_glock_mutex fileserver`CallPreamble +0x2c 6 12591 fileserver`vol_glock_mutex fileserver`VVnodeWriteToRead_r+0x266
    1    12207 fileserver`ih_glock_once     libc.so.1`pthread_once+0x2c
   10    12184 fileserver`host_glock_mutex  fileserver`GetClient+0x17
   12    12130 fileserver`host_glock_mutex  fileserver`h_Lock_r+0x61
1 12066 fileserver`host_glock_mutex fileserver`BreakCallBack +0x5e
    1    11744 fileserver`ih_glock_mutex    fileserver`ih_release+0x37
1 11574 fileserver`host_glock_mutex fileserver`h_FindClient_r +0x608 2 11367 fileserver`host_glock_mutex fileserver`CallPostamble +0x14
    1    11257 fileserver`vol_glock_mutex   fileserver`VPutVolume+0x12
    2    10954 fileserver`ih_glock_mutex    fileserver`ih_copy+0x27
1 10881 fileserver`rx_stats_mutex fileserver`rxi_SendList +0x2a8 3 10770 fileserver`host_glock_mutex fileserver`AddCallBack1 +0x13 1 10744 fileserver`host_glock_mutex fileserver`MultiBreakCallBack_r+0x2e4
    1    10262 0x8b60348                    fileserver`ubik_Call+0x26
2 9832 fileserver`rx_stats_mutex fileserver`ReturnToServerPool+0x23 2 7506 fileserver`rx_stats_mutex fileserver`rxi_ReadPacket +0x1bc 1 6146 fileserver`fileproc_glock_mutex fileserver`common_FetchData64+0x27
    1     4702 libc.so.1`libc_malloc_lock   fileserver`rxi_Start+0x31a
    2     4531 fileserver`vol_glock_mutex   fileserver`VGetVolume+0x13


--
Dale Ghent
UNIX Systems Specialist
UMBC - Office of Information Technology
ECS 201 - x51705


_______________________________________________
OpenAFS-devel mailing list
[email protected]
https://lists.openafs.org/mailman/listinfo/openafs-devel

Reply via email to