[LU-2576] Hangs in osc_enter_cache due to dirty pages not being flushed

• Type: Bug
• Resolution: Fixed
• Priority: Blocker
• Fix Version/s: Lustre 2.4.0
• Affects Version/s: Lustre 2.4.0
• Labels: MB ptr sequoia topsequoia
• Severity: 3
• Assignee: Niu Yawei (Inactive)
• Reporter: Prakash Surya (Inactive)

Description

We've had reports of IO writes hanging in Sequoia, and after some initial debugging, have narrowed the hung threads to getting stuck with the following stack trace:

 sysiod        S 00000fffa842633c     0 27910   3135 0x00000000                    
 Call Trace:                                                                       
 [c0000003ee34e480] [c0000003ee34e590] 0xc0000003ee34e590 (unreliable)             
 [c0000003ee34e650] [c000000000009b8c] .__switch_to+0xc4/0x100                     
 [c0000003ee34e6e0] [c0000000004364c8] .schedule+0x858/0x9c0                       
 [c0000003ee34e990] [8000000000a720c0] .cfs_waitq_wait+0x10/0x30 [libcfs]          
 [c0000003ee34ea00] [8000000004533560] .osc_enter_cache+0x880/0x12c0 [osc]         
 [c0000003ee34ebd0] [800000000453b210] .osc_queue_async_io+0xd10/0x1a40 [osc]   
 [c0000003ee34edf0] [8000000004516fe8] .osc_page_cache_add+0xf8/0x2a0 [osc]        
 [c0000003ee34eeb0] [80000000024468b8] .cl_page_cache_add+0xe8/0x3b0 [obdclass] 
 [c0000003ee34efe0] [8000000004facae8] .lov_page_cache_add+0xc8/0x340 [lov]        
 [c0000003ee34f0b0] [80000000024468b8] .cl_page_cache_add+0xe8/0x3b0 [obdclass] 
 [c0000003ee34f1e0] [80000000067ecda4] .vvp_io_commit_write+0x474/0x8a0 [lustre]
 [c0000003ee34f300] [800000000246098c] .cl_io_commit_write+0x11c/0x2d0 [obdclass]
 [c0000003ee34f3c0] [80000000067af410] .ll_commit_write+0x120/0x3e0 [lustre]       
 [c0000003ee34f490] [80000000067d1634] .ll_write_end+0x34/0x80 [lustre]            
 [c0000003ee34f520] [c000000000098bac] .generic_file_buffered_write+0x1ec/0x374 
 [c0000003ee34f660] [c000000000099290] .__generic_file_aio_write+0x374/0x3d8       
 [c0000003ee34f760] [c00000000009936c] .generic_file_aio_write+0x78/0xe8           
 [c0000003ee34f810] [80000000067eff9c] .vvp_io_write_start+0xfc/0x3e0 [lustre]  
 [c0000003ee34f8e0] [800000000245aedc] .cl_io_start+0xcc/0x220 [obdclass]          
 [c0000003ee34f980] [8000000002462cf4] .cl_io_loop+0x194/0x2c0 [obdclass]          
 [c0000003ee34fa30] [800000000676a278] .ll_file_io_generic+0x498/0x670 [lustre] 
 [c0000003ee34fb30] [800000000676a8d4] .ll_file_aio_write+0x1d4/0x3a0 [lustre]  
 [c0000003ee34fc00] [800000000676abf0] .ll_file_write+0x150/0x320 [lustre]         
 [c0000003ee34fce0] [c0000000000d5968] .vfs_write+0xd0/0x1c4                       
 [c0000003ee34fd80] [c0000000000d5b58] .SyS_write+0x54/0x98                        
 [c0000003ee34fe30] [c000000000000580] syscall_exit+0x0/0x2c

The specific line it's stuck at is here:

(gdb) l *osc_enter_cache+0x880
0x47f50 is in osc_enter_cache (/builddir/build/BUILD/lustre-2.3.56/lustre/osc/osc_cache.c:1526).
1521    /builddir/build/BUILD/lustre-2.3.56/lustre/osc/osc_cache.c: No such file or directory.
        in /builddir/build/BUILD/lustre-2.3.56/lustre/osc/osc_cache.c

1523                 CDEBUG(D_CACHE, "%s: sleeping for cache space @ %p for %p\n",   
1524                        cli->cl_import->imp_obd->obd_name, &ocw, oap);           
1525                                                                                 
1526                 rc = l_wait_event(ocw.ocw_waitq,                                
1527                                   cfs_list_empty(&ocw.ocw_entry), &lwi);        
1528                                                                                 
1529                 client_obd_list_lock(&cli->cl_loi_list_lock);                   
1530                 cfs_list_del_init(&ocw.ocw_entry); 

There were specific OSCs on a couple of the problem clients showing outstanding dirty pages for a significant amount of time:

seqlac2@root:pdsh -w vulcanio[42-43] 'grep -v 0 /proc/fs/lustre/osc/*/cur_dirty_bytes' | dshbak -c
----------------                                                                
vulcanio42                                                                      
----------------                                                                
/proc/fs/lustre/osc/ls1-OST0026-osc-c0000003c1100000/cur_dirty_bytes:65536         
/proc/fs/lustre/osc/ls1-OST0027-osc-c0000003c1100000/cur_dirty_bytes:65536         
/proc/fs/lustre/osc/ls1-OST0028-osc-c0000003c1100000/cur_dirty_bytes:65536         
/proc/fs/lustre/osc/ls1-OST002b-osc-c0000003c1100000/cur_dirty_bytes:65536         
----------------                                                                
vulcanio43                                                                      
----------------                                                                
/proc/fs/lustre/osc/ls1-OST0053-osc-c0000003e336b000/cur_dirty_bytes:65536

Manually dropping caches on the problem clients seems to have cleared things up:

# echo 3 > /proc/sys/vm/drop_caches

In case it is useful, attached is a dump of the lustre pages taken prior to dropping caches on one of the problem clients:

# cat /proc/fs/lustre/llite/ls1-c0000003e336b000/dump_page_cache > vulcanio43-dump_page_cache-`date +%s`

I also ran the same command after dropping caches, but the file was empty, so there's no reason to post it.

Issue Links

• is related to: LU-3261 Threads stuck in osc_enter_cache when testing LU-1669
• is related to: LU-3416 Hangs on write in osc_enter_cache()
• is related to: LU-3277 LU-2139 may cause the performance regression
• is related to: LU-2139 Tracking unstable pages