[ ssic-linux-Bugs-1698889 ] CFS token livelock on VFS I_LOCK

Bugs item #1698889, was opened at 2007-04-11 22:22
Message generated for change (Comment added) made by rogertsang
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=405834&aid=1698889&group_id=32541

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: Filesystem
Group: None
>Status: Closed
>Resolution: Out of Date
Priority: 3
Private: No
Submitted By: Roger Tsang (rogertsang)
Assigned to: Nobody/Anonymous (nobody)
Summary: CFS token livelock on VFS I_LOCK

Initial Comment:
node 1 icssvr_daemon was processing RETURN from node 3 while rm was sending GIVEBACK to node 3.  The livelock occured when node 1 icssvr_daemon's find_inode_fast is waiting for I_LOCK on the inode that node 1 rm is putting while this rm is waiting for node 3 client which is waiting for GRANT(?) from node 1 icssvr_daemon.  This goes in a circle but the interesting thing is I do not see node 1 rm stack will reset I_LOCK at this point.

The likely place where I_LOCK gets reset is VFS writeback, but writeback already has been done at this stage.  So I think cfs_clear_inode just has to clear the I_LOCK before sending giveback and to be safe to giveback while inside inode_lock if possible, if cfsd_proc_tokmsg is inode_lock free.

Below is from node 1.

Stack traceback for pid 65933
0xf6f0b670    65933        2  1    0   R  0xf6f0b840 *icssvr_daemon
EBP        EIP        Function (args)
0xf6f0dcec 0xc011eff0 sys_sched_yield
           0xc03ee595 yield+0x15 (0xf7c914fc, 0x3, 0x0, 0xf6f0b670, 0xc0139dc0)
0xf6f0dd40 0xc0180daf __wait_on_freeing_inode+0x7f (0xf7c913d4, 0xc24ce7a0, 0x20f8f, 0xf6e42a00)
0xf6f0dd58 0xc017fe4e find_inode_fast+0x4e (0xf6e42a00, 0xc24ce7a0, 0x20f8f, 0x20f8f, 0xf6e42a00)
0xf6f0dd78 0xc018039e ilookup+0x5e (0xf6e42a00, 0x20f8f, 0x2002, 0x0)
0xf6f0dd90 0xc028a4e0 clifhtoip+0x30 (0xf6dc4ec0, 0xf6eb0380, 0x34, 0xf6f0ddc0, 0xc03bef99)
0xf6f0dddc 0xc028933c cfs_tokmsg+0x6c (0xf6dc4ec0, 0x1, 0x2002, 0x4, 0x0)
0xf6f0de24 0xc028913d _cfs_tokmsg+0x7d (0xf6dc4ec0, 0x4, 0xf6dc4f04, 0xf6f0dec0, 0xf6f0de58)
0xf6f0de60 0xc027a06c tokseq_accept+0x15c (0xf7c6ab00, 0x3, 0x67, 0xc02890c0, 0xf6dc4ec0)
0xf6f0de8c 0xc02891ad _cfs_tokmsg_seq+0x6d (0xf6dc4ec0)
0xf6f0de98 0xc0285d91 cfsd_proc_tokmsg_0+0x11 (0xf6dc4ec0, 0x0, 0xf6dc4ec0, 0xf6f793a0, 0xf6eac044)
0xf6f0deec 0xc0209145 icsnsc_rpc_dispatch+0x115 (0xa0001, 0xd, 0xf6f0df24, 0xf6f793a0, 0xf6f0df20)
0xf6f0df58 0xc0208bad svr_icsnsc_rcall+0xbd
           0xc0101e55 kernel_thread_helper+0x5

Stack traceback for pid 67462
0xf7c236f0    67462    66604  0    0   R  0xf7c238c0  rm
EBP        EIP        Function (args)
0xf7e9fc2c 0xc03edade schedule+0x31e (0x0, 0xf7ec0d00, 0x0, 0xf7c236f0, 0xf7ec0c2c)
0xf7e9fc84 0xc020371c icscli_wait+0xcc (0xf7ec0c00, 0x2, 0xc0203460, 0x0, 0xf7e9fd44)
0xf7e9fd04 0xc02089a9 cli_icsnsc_rcall+0x299 (0x3, 0xf7e9fd38, 0xa0001, 0xe, 0x0)
0xf7e9fd70 0xc0208f4b nsc_rcall+0xeb (0x10a0003, 0xe, 0xc0291ec0, 0xf7e9fdc8, 0xc0290a00)
0xf7e9fe64 0xc028cd9d cfstok_send+0x16d (0xf6dce100, 0x66, 0x1001, 0x4, 0x0)
0xf7e9fea0 0xc0274e46 process_msgs+0x146 (0x1, 0xf7c91334, 0x1, 0x1, 0xf7c913d4)
0xf7e9fed4 0xc028cbee cfstok_giveback+0x9e (0xf7c913d4, 0x0, 0x0, 0x2, 0xf7c913d4)
0xf7e9fef0 0xc027a526 cfs_clear_inode+0x36 (0xf7c913d4, 0xf7c913d4, 0xc027a480)
0xf7e9ff04 0xc017f846 clear_inode+0xd6 (0xf7c913d4, 0x0, 0x0, 0x2, 0xf7c913d4)
0xf7e9ff20 0xc027a4bc cfs_delete_inode+0x3c (0xf7c913d4, 0xc27a2168, 0xf7e9ff40, 0xf7c913d4, 0xf6898000)
0xf7e9ff3c 0xc0180711 generic_delete_inode+0x71 (0xf7c913d4)
0xf7e9ff48 0xc01808e8 generic_drop_inode+0x18 (0xf7c913d4, 0xc04e9bac, 0x0)
0xf7e9ff5c 0xc0180961 iput+0x61 (0xf7c913d4, 0xc27a2168, 0xc27a2168, 0xf6f3830c, 0xc24fef80)
0xf7e9ffbc 0xc017571e sys_unlink+0xee
           0xc0105305 sysenter_past_esp+0x52


inode (0xf7c913d4)
    i_ino = 135055
    i_count = 3
    i_mode = 0x8180
    i_nlink = 0
    i_uid = 0
    i_gid = 0
    i_rdev = 0
    i_size = 32768
    i_sem:
        count = 1
        sleepers= 0
    i_op = 0xc0550360
    i_fop = 0xc05502e0
    i_sb = 0xf6e42a00
    i_pipe = 0x00000000
    i_bdev = 0x00000000
    i_state = 0x10
    i_flags = 0x2
    i_sock = 0
    i_writecount = 0
    i_generation = 0
    u = 0xf7c91510
Function print_inode returned 0x0

----------------------------------------------------------------------

>Comment By: Roger Tsang (rogertsang)
Date: 2007-08-12 20:54

Message:
Logged In: YES 
user_id=1246761
Originator: YES

It has been a few months already and haven't run into this bug.

----------------------------------------------------------------------

Comment By: Roger Tsang (rogertsang)
Date: 2007-04-19 23:21

Message:
Logged In: YES 
user_id=1246761
Originator: YES

Some process must be stuck doing writeback; and probably waiting for block
device.  Need to reproduce bug, but not certain if this can be reproduced
without simulating hardware failure.

----------------------------------------------------------------------

Comment By: Roger Tsang (rogertsang)
Date: 2007-04-13 07:23

Message:
Logged In: YES 
user_id=1246761
Originator: YES

Looks like node1 has a memory problem.  If so, this bug report is
invalid.

Oops: 0000 [#1]
SMP
Modules linked in: drbd cpufreq_ondemand tun ipt_REJECT ipt_state
ipt_multiport iptable_filter ipt_MASQUERADE iptable_nat ip_conntrack
ip_tables softdog xfs exportfs dm_mod uhci_hcd ehci_hcd usbcore via_rhine
sk98lin r8169 forcedeth
CPU:    0
EIP:    0060:[<00000000>]    Not tainted VLI
EFLAGS: 00010202   (2.6.11-ssi5.12)
EIP is at 0x0
eax: f93573a0   ebx: f51681b4   ecx: f2c0c08c   edx: c24d7f60
esi: f2c0c000   edi: f76cdce0   ebp: f76cdca4   esp: f76cdc68
ds: 007b   es: 007b   ss: 0068
Process mount (pid: 77043, threadinfo=f76cc000 task=f7f99670)
Stack: c0286777 f51681b4 7837c809 00000000 00000010 c04e8900 00000000
000000d0
       00000046 00000000 f6d4d600 f76cc000 f54e7cc0 00000001 00000001
f76cdd08
       c028d8b2 f76cdce0 f76cdccc f76cdcd0 c0647444 f5c60b40 00000010
f76cdd14
Call Trace:
 [<c010623f>] show_stack+0x7f/0xa0
 [<c01063e6>] show_registers+0x166/0x230
 [<c0106786>] die+0xf6/0x1c0
 [<c011b34d>] do_page_fault+0x45d/0x652
 [<c0105e9f>] error_code+0x2b/0x30
 [<c028d8b2>] cfstok_start_svrcfstok+0xf2/0x100
 [<c028d928>] cfstok_rebuild_tokens+0x68/0x140
 [<c0293e44>] cfs_rebuild_tokens+0x64/0x140

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=405834&aid=1698889&group_id=32541

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >>  http://get.splunk.com/