Ceph » Linux kernel client

I'm adding a conditional skip to FullnessTestCase, so when testing a kernel that's meant to support ENOSPC handling, don't forget to remove that check.

Ok, I've looked over the kernel patches and started backporting them, and also on the userland equivalents. There has been quite a bit of overhaul of the osd handling code via some of Ilya's recent patchsets so it doesn't quite apply directly. I'm working through the differences.

What I don't quite get is why we have this complex system for handling ENOSPC errors. What's wrong with just sending the requests and waiting for them to get back an error in this case? Are the OSDs not able to enforce that for some reason?

This was quite a while ago. But generally, the OSDs don't send back errors; they just block. We also want to return ENOSPC in some other situations (not for filesystem quotas, since there's EQUOTA, but I think maybe pool quotas?). We don't want to wait "forever" in those cases since it takes up memory, and applications have some chance of handling ENOSPC correctly (unlike certain other kinds of things).

We also need to undo https://github.com/ceph/ceph-qa-suite/pull/1156/commits/c5f6dfc14f47cca251dcac5c53f6369fd36ace1a and https://github.com/ceph/ceph-qa-suite/pull/1156/commits/989ecd6b1aafc132b08cbcb7500f593db0ce0fed when this ticket is done (for testing).

Yeah, I'll get there eventually on the testcases. For now I'm just doing "by hand" testing to work out the problems in the patchset.

What I'm doing now is just mounting an already-filled cephfs mount and trying to write to a file there with dd. That immediately gets stuck like this, even with the patchset I have:

$ cat /proc/1481/stack
[<ffffffffc089f81c>] wait_request_timeout+0x3c/0xa0 [libceph]
[<ffffffffc089f893>] ceph_osdc_wait_request+0x13/0x20 [libceph]
[<ffffffffc08fde1b>] ceph_pool_perm_check+0x93b/0x990 [ceph]
[<ffffffffc090532b>] ceph_get_caps+0x4b/0x3b0 [ceph]
[<ffffffffc08f5cb6>] ceph_write_iter+0x346/0xbe0 [ceph]
[<ffffffff8f25e875>] __vfs_write+0xe5/0x160
[<ffffffff8f25f0f5>] vfs_write+0xb5/0x1a0
[<ffffffff8f260575>] SyS_write+0x55/0xc0
[<ffffffff8f83edf7>] entry_SYSCALL_64_fastpath+0x1a/0xa9
[<ffffffffffffffff>] 0xffffffffffffffff

It's only during the first cap request that we figure out that the pool is already at capacity, but we're stuck waiting on it anyway.

Evidently the OSD code sets the flags to -1 on incremental map updates?

[  399.831509] libceph:  ceph_osdc_handle_map have 35
[  399.831510] libceph:   1 inc maps
[  399.831511] libceph:  applying incremental map 36 len 357
[  399.831513] libceph:  osdmap_apply_incremental ffff978db3ceea1c to ffff978db3ceeb81 len 357
[  399.831515] libceph:  osdmap_apply_incremental: old_flags 0x38000 new_flags = 0xffffffff

The new_flags value is just after we decode it from the packet, so that does seem like what the OSD is sending. When it's <0, then the flags value is ignored, so I guess this is deliberate.

I'll look at the ceph code tomorrow to see if I can figure this part out.

Ok, opened up a bug to track the problem I was seeing. dis and sage set me right on IRC though. John's original series didn't have anything for the POOL_FULL flag, which was added after he had posted the original series.

I've gone back over the code and I think I get it a bit more now. I'm revising the set now but I think that's what I was missing.

One thing that I'm not yet sure of in either patch series is whether we have the potential for races here between a map update coming in and the request being put in the tree. Still sorting that piece out by attempting to clarify the locking.

Ok, and now I think I see part of the fundamental issue and that may not have been a problem with the older request handling code. In any case...

So what happens is that we're merrily sending write requests to the OSD, and then we get a map update back really quickly, after the last write completes but before the next one goes out. So, that calls the mds callback to kill off the writes, but there's nothing there -- we're still returning back to userland and waiting for the next syscall.

Eventually, the next write call comes in, and sees that the pool is full. The request handling code basically inserts the request into the tree but doesn't send it in that case, but now we've already run the thing that completes all of the writes with ENOSPC. This one just sits there...

I think it's fine to kill off writes that have already been submitted when the new map update comes in, but we also either need to allow the requests to return ENOSPC OSD writes (maybe conditionally based on a flag in ceph_osd_request?).

Alternately, we could try to rerun ceph_osdc_complete_writes to catch any that have crept through, but I'm not sure what we'd use as a trigger for it to run, and that's less responsive anyway.

v1 of the patch series:

http://marc.info/?l=ceph-devel&m=148492546411549&w=2

v2 of the series:

http://marc.info/?l=ceph-devel&m=148638777409413&w=2

Up to v6 of the set now, just re-posted it today. The main difference from v5 is some changes to address Ilya's comments.

Ilya seems to be OK with v7 of the set, and I merged that into the kernel testing branch yesterday. How do we turn on the tests -ENOSPC tests in the kernel client QA runs?

Ok, hit a deadlock in testing today. Yay for lockdep. I'll have to look at how to fix this:

[  774.924131] =============================================                    
[  774.929530] [ INFO: possible recursive locking detected ]                    
[  774.934922] 4.11.0-rc3-ceph-g504bd80520a1 #1 Not tainted                     
[  774.940232] ---------------------------------------------                    
[  774.945622] kworker/7:1/80 is trying to acquire lock:                        
[  774.950668]  (&osdc->lock){++++..}, at: [<ffffffffa054cba3>] send_cap_msg+0x393/0x450 [ceph]
[  774.959126]                                                                  
but task is already holding lock:                                               
[  774.964949]  (&osdc->lock){++++..}, at: [<ffffffffa04e8b8c>] ceph_osdc_handle_map+0x6c/0x990 [libceph]
[  774.974268]                                                                  
other info that might help us debug this:                                       
[  774.980786]  Possible unsafe locking scenario:                               

[  774.986696]        CPU0                                                      
[  774.989139]        ----                                                      
[  774.991583]   lock(&osdc->lock);                                             
[  774.994808]   lock(&osdc->lock);                                             
[  774.998033]                                                                  
 *** DEADLOCK ***                                                               

[  775.003951]  May be due to missing lock nesting notation                     

[  775.010730] 5 locks held by kworker/7:1/80:                                  
[  775.014907]  #0:  ("ceph-msgr"){++++.+}, at: [<ffffffff810ca5a3>] process_one_work+0x1f3/0x630
[  775.023513]  #1:  ((&(&con->work)->work)){+.+.+.}, at: [<ffffffff810ca5a3>] process_one_work+0x1f3/0x630
[  775.032987]  #2:  (&osdc->lock){++++..}, at: [<ffffffffa04e8b8c>] ceph_osdc_handle_map+0x6c/0x990 [libceph]
[  775.042729]  #3:  (&s->s_mutex){+.+...}, at: [<ffffffffa05514b1>] ceph_check_caps+0xc41/0xd10 [ceph]
[  775.051873]  #4:  (&mdsc->snap_rwsem){++++..}, at: [<ffffffffa0550d64>] ceph_check_caps+0x4f4/0xd10 [ceph]
[  775.061528]                                                                  
stack backtrace:                                                                
[  775.065882] CPU: 7 PID: 80 Comm: kworker/7:1 Not tainted 4.11.0-rc3-ceph-g504bd80520a1 #1
[  775.074055] Hardware name: Supermicro SYS-5018R-WR/X10SRW-F, BIOS 1.0c 09/07/2015
[  775.081546] Workqueue: ceph-msgr ceph_con_workfn [libceph]                   
[  775.087029] Call Trace:                                                      
[  775.089488]  dump_stack+0x85/0xc4                                            
[  775.092805]  __lock_acquire+0xc83/0x1630                                     
[  775.096731]  lock_acquire+0x197/0x1f0                                        
[  775.100405]  ? send_cap_msg+0x393/0x450 [ceph]                               
[  775.104852]  down_read+0x4c/0x70                                             
[  775.108090]  ? send_cap_msg+0x393/0x450 [ceph]                               
[  775.112544]  send_cap_msg+0x393/0x450 [ceph]                                 
[  775.116822]  ? ceph_check_caps+0x4f4/0xd10 [ceph]                            
[  775.121534]  ? ceph_check_caps+0x4f4/0xd10 [ceph]                            
[  775.126251]  __send_cap+0x2be/0x530 [ceph]                                   
[  775.130357]  ? __mark_caps_flushing+0x1e3/0x310 [ceph]                       
[  775.135503]  ? __mark_caps_flushing+0xbc/0x310 [ceph]                        
[  775.140552]  ? _raw_spin_unlock+0x27/0x40                                    
[  775.144573]  ceph_check_caps+0x5ec/0xd10 [ceph]                              
[  775.149115]  ? ceph_put_wrbuffer_cap_refs+0x34e/0x370 [ceph]                 
[  775.154782]  ceph_put_wrbuffer_cap_refs+0x14f/0x370 [ceph]                   
[  775.160276]  ? ceph_release_pages+0x95/0xc0 [ceph]                           
[  775.165071]  ? unlock_page_memcg+0xa3/0xb0                                   
[  775.169171]  ? test_clear_page_writeback+0x2c8/0x2e0                         
[  775.174143]  writepages_finish+0x2ce/0x430 [ceph]                            
[  775.178858]  ? finish_read+0x2b0/0x2b0 [ceph]                                
[  775.183229]  __complete_request+0x2e/0xb0 [libceph]                          
[  775.188117]  ? finish_request+0xc0/0x140 [libceph]                           
[  775.192918]  complete_request+0x34/0xb0 [libceph]                            
[  775.197632]  ? cancel_map_check+0x25/0xb0 [libceph]                          
[  775.202519]  abort_request+0x30/0x90 [libceph]                               
[  775.206973]  ? maybe_request_map+0x9c/0x150 [libceph]                        
[  775.212027]  ceph_osdc_handle_map+0x4de/0x990 [libceph]                      
[  775.217255]  ? inet_recvmsg+0x1a6/0x1f0                                      
[  775.221104]  dispatch+0x45/0x530 [libceph]                                   
[  775.225203]  ? __mutex_unlock_slowpath+0x52/0x2a0                            
[  775.229917]  ceph_con_workfn+0xef3/0x31d0 [libceph]                          
[  775.234802]  process_one_work+0x32f/0x630                                    
[  775.238809]  ? process_one_work+0x1f3/0x630                                  
[  775.242997]  worker_thread+0x2b9/0x4a0                                       
[  775.246748]  kthread+0x12d/0x140                                             
[  775.249980]  ? process_one_work+0x630/0x630                                  
[  775.254164]  ? kthread_stop+0x280/0x280                                      
[  775.257998]  ret_from_fork+0x31/0x40                                         

Ok, I see the problem. I added a down_read for the osdc->epoch_barrier fetch to send_cap_msg. That's dumb -- I'll just have it do a READ_ONCE there, which should be fine for the case where we're not holding the osdc->lock in any way.

But...there is another problem here. When we cancel a write, we can end up sending a cap message and possibly release some caps. We won't yet have updated the epoch barrier, however. I think that means that we ought to set the epoch barrier before cancelling anything so the MDS knows that it should gate these caps on the map epoch we have. Does that make sense?

If so, we can do a scan of the list and see if there is anything to be aborted. If so, we'll update the epoch barrier first and then abort the requests.

I've changed the code in testing to set the barrier first, and added a patch to return writeback errors on close, which seems to be what some of the testcases expect. That allows the failing testcases to pass. The big question is whether we really do want the kernel to return writeback errors on close.

For now, that is a per-fs decision, so we can make it work either way. Most likely though, we'll want to bring the fuse fs and and the kernel client into sync in this regard.