On Tue, Apr 15, 2014 at 8:55 PM, Kenneth Waegeman <[email protected]> wrote: > Hi, > > We are back to our MDS problem. > > This time we used the kernel client to connect to the cluster. We started > again filling the cluster with rsync, and got problems after about 48h. The > MDS crashed again with core dump like before. > I removed the client connection, and restarted the MDS's. The first MDS got > killed by oom-killer when it used 8G of RAM. The backup MDS took over, and I > stopped the OSDs(with noout set) on that host so there was more RAM for > testing the MDS. The MDS started again to fill the memory, this time to 30G. > (We have 32G) > Meanwhile, I saw some interesting rados statistics: > The metadata pool was heavily decreasing in KB, and increasing in object > count. > > pool name category KB objects clones > degraded unfound rd rd KB wr wr KB > data - 17707360279 11641299 0 > 11667979 0 70364 0 15904215 17711309640 > metadata - 95833067 405395 0 > 484371 0 273320 925385352 12283908 271184622 > > Tue Apr 15 12:55:34 2014 > > pool name category KB objects clones > degraded unfound rd rd KB wr wr KB > data - 17707360279 11667145 0 > 11719671 0 95576 0 17619242 17711309640 > metadata - 49677494 494630 0 > 662841 0 294946 1013866123 12748893 271914066 > > > After oom-killer killed ceph-mds again: > > Out of memory: Kill process 40776 (ceph-mds) score 808 or sacrifice child > Killed process 40776, UID 0, (ceph-mds) total-vm:31382436kB, > anon-rss:29960904kB, file-rss:20kB python[42731] trap invalid opcode > ip:7f62ddd8ffc1 sp:7f62ccef6488 error:0 > > > this reduction was still going on (no clients connected): > > Tue Apr 15 13:20:24 2014 > > pool name category KB objects clones > degraded unfound rd rd KB wr wr KB > data - 17707360279 11686446 0 > 11758273 0 95576 0 18447710 17711309640 > metadata - 26526902 523234 0 > 720049 0 294946 1013866123 12886549 271914355 > > Tue Apr 15 13:34:49 2014 > > pool name category KB objects clones > degraded unfound rd rd KB wr wr KB > data - 17707360279 11707425 0 > 11800231 0 95576 0 18989100 17711309640 > metadata - 12612790 543214 0 > 760009 0 294946 1013866123 12977285 271914524 > > > > The MDS didn't crash anymore and stopped increasing RAM at 20G > Until it eventually stabilized: > > > Tue Apr 15 13:47:35 2014 > > pool name category KB objects clones > degraded unfound rd rd KB wr wr KB > data - 17707360279 11720750 0 > 11826881 0 95576 0 19346286 17711309640 > metadata - 126985 579061 0 > 831703 0 294946 1013866123 13146061 272057126 > > > The MDS is now only using <200m and idle > > Does this looks familiar to someone? > > It looks like the MDS is unable to process the requests, and therefore tried > to allocate more memory until it resolved? > >
Looks like the MDS journal becomes too large. So far there is no mechanism to throttle client request when MDS can't trim log fast enough. The fix should be easy. Regards Yan, Zheng > Thanks! > > Kenneth > > ----- Message from Stijn De Weirdt <[email protected]> --------- > Date: Fri, 04 Apr 2014 20:31:34 +0200 > From: Stijn De Weirdt <[email protected]> > > Subject: Re: [ceph-users] ceph 0.78 mon and mds crashing (bus error) > To: "Yan, Zheng" <[email protected]> > Cc: [email protected] > > > >> hi yan, >> >> (taking the list in CC) >> >> On 04/04/2014 04:44 PM, Yan, Zheng wrote: >>> >>> On Thu, Apr 3, 2014 at 2:52 PM, Stijn De Weirdt <[email protected]> >>> wrote: >>>> >>>> hi, >>>> >>>> latest pprof output attached. >>>> >>>> this is no kernel client, this is ceph-fuse on EL6. starting the mds >>>> without >>>> any ceph-fuse mounts works without issue. mounting ceph-fuse afterwards >>>> also >>>> works fine. simple filesystem operations work as expected. >>>> >>>> we'll check the state of the fuse mount via fusectl once we've >>>> reproduced >>>> the issue. >>> >>> >>> One dark side of fuse client is that there is no way to purge inodes >>> in kernel inode caches. Each cached inode in kernel pins corresponding >>> inode in ceph-mds. I think that's why ceph-fuse and ceph-mds use so >>> many memory. Could you try executing "echo 3 > >>> /proc/sys/vm/drop_caches" periodically on the ceph-fuse mount machine. >> >> thanks a lot for the suggestion. that night very well explain the issue. >> we're currently trying looking into other issues that we tought was related >> (extremely low mdtest performance), but we will retry your suggestion when >> we start to reproduce the condition >> >> >> >> stijn >> >>> >>> Regards >>> Yan, Zheng >>> >>>> >>>> >>>> stijn >>>> >>>> >>>> On 04/03/2014 02:39 AM, Yan, Zheng wrote: >>>>> >>>>> >>>>> which version of kernel client did you use? please send out context of >>>>> client node's /sys/kernel/debug/ceph/*/caps when the MDS uses lots >>>>> memory. >>>>> >>>>> Regards >>>>> Yan, Zheng >>>>> >>>>> On Thu, Apr 3, 2014 at 2:58 AM, Stijn De Weirdt >>>>> <[email protected]> >>>>> wrote: >>>>>> >>>>>> >>>>>> wow. kudos for integrating this in ceph. more projects should do it >>>>>> like >>>>>> that! >>>>>> >>>>>> anyway, in attachement a gzipped ps file. heap is at 4.4GB, top >>>>>> reports >>>>>> 6.5GB mem usage. >>>>>> >>>>>> care to point out what to look for? i'll send a new one when the usage >>>>>> is >>>>>> starting to cause swapping. >>>>>> >>>>>> thanks, >>>>>> >>>>>> stijn >>>>>> >>>>>> >>>>>> On 04/02/2014 06:35 PM, Gregory Farnum wrote: >>>>>>> >>>>>>> >>>>>>> >>>>>>> Did you see >>>>>>> http://ceph.com/docs/master/rados/troubleshooting/memory-profiling? >>>>>>> That should have what you need to get started, although you'll also >>>>>>> need to learn the basics of using the heap analysis tools elsewhere. >>>>>>> -Greg >>>>>>> Software Engineer #42 @ http://inktank.com | http://ceph.com >>>>>>> >>>>>>> >>>>>>> On Wed, Apr 2, 2014 at 9:23 AM, Stijn De Weirdt >>>>>>> <[email protected]> >>>>>>> wrote: >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> hi, >>>>>>>> >>>>>>>> >>>>>>>>>> 1) How big and what shape the filesystem is. Do you have some >>>>>>>>>> extremely large directory that the MDS keeps trying to load and >>>>>>>>>> then >>>>>>>>>> dump? >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> anyway to extract this from the mds without having to start it? as >>>>>>>>> it >>>>>>>>> was an rsync operation, i can try to locate possible candidates on >>>>>>>>> the >>>>>>>>> source filesystem, but what would be considered "large"? >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> total number of files 13M, spread over 800k directories, but it's >>>>>>>> unclear >>>>>>>> how far the sync was at time of failing. i've not found a good way >>>>>>>> to >>>>>>>> for >>>>>>>> directories with lots of files and/or subdirs. >>>>>>>> >>>>>>>> >>>>>>>>> >>>>>>>>>> 2) Use tcmalloc's heap analyzer to see where all the memory is >>>>>>>>>> being >>>>>>>>>> allocated. >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> we'll giv ethat a try >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> >>>>>>>> i run ceph-mds with HEAPCHECK=normal (via the init script), but how >>>>>>>> can >>>>>>>> we >>>>>>>> "stop" mds without killing it? the heapchecker only seems to dump at >>>>>>>> the >>>>>>>> end >>>>>>>> of a run, maybe there's a way to have intermediate dump like >>>>>>>> valgrind, >>>>>>>> but >>>>>>>> the documentation is not very helpful. >>>>>>>> >>>>>>>> stijn >>>>>>>> >>>>>>>> >>>>>>>>> >>>>>>>>>> 3) Look through the logs for when the beacon fails (the first of >>>>>>>>>> "mds.0.16 is_laggy 600.641332 > 15 since last acked beacon") and >>>>>>>>>> see >>>>>>>>>> if there's anything tell-tale going on at the time. >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> anything in particular we should be looking for? >>>>>>>>> >>>>>>>>> the log goes as follows: >>>>>>>>> mds starts around 11:43 >>>>>>>>> ... >>>>>>>>> >>>>>>>>>> 2014-04-01 11:44:23.658583 7ffec89c6700 1 mds.0.server >>>>>>>>>> reconnect_clients -- 1 sessions >>>>>>>>>> 2014-04-01 11:44:41.212488 7ffec89c6700 0 log [DBG] : reconnect >>>>>>>>>> by >>>>>>>>>> client.4585 10.141.8.199:0/3551 after 17.553854 >>>>>>>>>> 2014-04-01 11:44:45.692237 7ffec89c6700 1 mds.0.10 reconnect_done >>>>>>>>>> 2014-04-01 11:44:45.996384 7ffec89c6700 1 mds.0.10 handle_mds_map >>>>>>>>>> i >>>>>>>>>> am now mds.0.10 >>>>>>>>>> 2014-04-01 11:44:45.996388 7ffec89c6700 1 mds.0.10 handle_mds_map >>>>>>>>>> state change up:reconnect --> up:rejoin >>>>>>>>>> 2014-04-01 11:44:45.996390 7ffec89c6700 1 mds.0.10 rejoin_start >>>>>>>>>> 2014-04-01 11:49:53.158471 7ffec89c6700 1 mds.0.10 >>>>>>>>>> rejoin_joint_start >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> then lots (4667 lines) of >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> 2014-04-01 11:50:10.237035 7ffebc844700 0 -- >>>>>>>>>> 10.141.8.180:6837/55117 >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> 10.141.8.180:6789/0 pipe(0x38a7da00 sd=104 :41115 s=4 pgs=0 cs=0 >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> l=1 c=0x6513e8840).connect got RESETSESSION but no longer >>>>>>>>>> connecting >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> with one intermediate >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> 2014-04-01 11:51:50.181354 7ffebcf4b700 0 -- >>>>>>>>>> 10.141.8.180:6837/55117 >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> 10.141.8.180:6789/0 pipe(0x10e282580 sd=103 :0 s=1 pgs=0 cs=0 >>>>>>>>>>>> l=1 >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> c=0xc77d5ee0).fault >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> then sudden change >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> 2014-04-01 11:57:30.440554 7ffebcd49700 0 -- >>>>>>>>>> 10.141.8.180:6837/55117 >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> 10.141.8.182:6789/0 pipe(0xa1534100 sd=104 :48176 s=4 pgs=0 cs=0 >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> l=1 c=0xd99b11e0).connect got RESETSESSION but no longer >>>>>>>>>> connecting >>>>>>>>>> 2014-04-01 11:57:30.722607 7ffebec68700 0 -- >>>>>>>>>> 10.141.8.180:6837/55117 >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> 10.141.8.181:6789/0 pipe(0x1ce98a00 sd=104 :48235 s=1 pgs=0 cs=0 >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> l=1 c=0xc48a3f40).connect got BADAUTHORIZER >>>>>>>>>> 2014-04-01 11:57:30.722669 7ffebec68700 0 -- >>>>>>>>>> 10.141.8.180:6837/55117 >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> 10.141.8.181:6789/0 pipe(0x1ce98a00 sd=104 :48235 s=1 pgs=0 cs=0 >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> l=1 c=0xc48a3f40).connect got BADAUTHORIZER >>>>>>>>>> 2014-04-01 11:57:30.722885 7ffebec68700 0 -- >>>>>>>>>> 10.141.8.180:6837/55117 >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> 10.141.8.181:6789/0 pipe(0x1ce98a00 sd=57 :48237 s=1 pgs=0 cs=0 >>>>>>>>>>>> l=1 >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> c=0xc48a3f40).connect got BADAUTHORIZER >>>>>>>>>> 2014-04-01 11:57:30.722945 7ffebec68700 0 -- >>>>>>>>>> 10.141.8.180:6837/55117 >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> 10.141.8.181:6789/0 pipe(0x1ce98a00 sd=57 :48237 s=1 pgs=0 cs=0 >>>>>>>>>>>> l=1 >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> c=0xc48a3f40).connect got BADAUTHORIZER >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> followed by lots of >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> 2014-04-01 11:57:30.738562 7ffebec68700 0 -- >>>>>>>>>> 10.141.8.180:6837/55117 >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> 10.141.8.181:6789/0 pipe(0xead9fa80 sd=57 :0 s=1 pgs=0 cs=0 l=1 >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> c=0x10e5d280).fault >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> with sporadic >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> 2014-04-01 11:57:32.431219 7ffebeb67700 0 -- >>>>>>>>>> 10.141.8.180:6837/55117 >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> 10.141.8.182:6789/0 pipe(0xef85cd80 sd=103 :41218 s=4 pgs=0 cs=0 >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> l=1 c=0x130590dc0).connect got RESETSESSION but no longer >>>>>>>>>> connecting >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> until the dmup >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> 2014-04-01 11:59:27.612850 7ffebea66700 0 -- >>>>>>>>>> 10.141.8.180:6837/55117 >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> 10.141.8.181:6789/0 pipe(0xe3036400 sd=103 :0 s=1 pgs=0 cs=0 l=1 >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> c=0xa7be300).fault >>>>>>>>>> 2014-04-01 11:59:27.639009 7ffec89c6700 -1 mds/CDir.cc: In >>>>>>>>>> function >>>>>>>>>> 'void CDir::_omap_fetched(ceph::bufferlist&, >>>>>>>>>> std::map<std::basic_string<char, std::char_traits<char>, >>>>>>>>>> std::allocator\ >>>>>>>>>> <char> >, ceph::buffer::list, std::less<std::basic_string<char, >>>>>>>>>> std::char_traits<char>, std::allocator<char> > >, >>>>>>>>>> std::allocator<std::pair<const std::basic_string<char, >>>>>>>>>> std::char_trait\ >>>>>>>>>> s<char>, std::allocator<char> >, ceph::buffer::list> > >&, const >>>>>>>>>> std::string&, int)' thread 7ffec89c6700 time 2014-04-01 >>>>>>>>>> 11:59:27.620684 >>>>>>>>>> mds/CDir.cc: 1474: FAILED assert(r == 0 || r == -2 || r == -61) >>>>>>>>>> >>>>>>>>>> ceph version 0.78 (f6c746c314d7b87b8419b6e584c94bfe4511dbd4) >>>>>>>>>> 1: (CDir::_omap_fetched(ceph::buffer::list&, >>>>>>>>>> std::map<std::string, >>>>>>>>>> ceph::buffer::list, std::less<std::string>, >>>>>>>>>> std::allocator<std::pair<std::string const, ceph::buffer::list> > >>>>>>>>>> >&, >>>>>>>>>> st\ >>>>>>>>>> d::string const&, int)+0x4d71) [0x77c3c1] >>>>>>>>>> 2: (Context::complete(int)+0x9) [0x56bb79] >>>>>>>>>> 3: (Objecter::handle_osd_op_reply(MOSDOpReply*)+0x11a6) >>>>>>>>>> [0x806dd6] >>>>>>>>>> 4: (MDS::handle_core_message(Message*)+0x9c7) [0x5901d7] >>>>>>>>>> 5: (MDS::_dispatch(Message*)+0x2f) [0x59028f] >>>>>>>>>> 6: (MDS::ms_dispatch(Message*)+0x1ab) [0x591d4b] >>>>>>>>>> 7: (DispatchQueue::entry()+0x582) [0x902072] >>>>>>>>>> 8: (DispatchQueue::DispatchThread::entry()+0xd) [0x85ef4d] >>>>>>>>>> 9: /lib64/libpthread.so.0() [0x34c36079d1] >>>>>>>>>> 10: (clone()+0x6d) [0x34c32e8b6d] >>>>>>>>>> NOTE: a copy of the executable, or `objdump -rdS <executable>` >>>>>>>>>> is >>>>>>>>>> needed to interpret this. >>>>>>>>>> >>>>>>>>>> --- begin dump of recent events --- >>>>>>>>>> -10000> 2014-04-01 11:59:27.137779 7ffec89c6700 5 mds.0.10 >>>>>>>>>> initiating >>>>>>>>>> monitor reconnect; maybe we're not the slow one >>>>>>>>>> -9999> 2014-04-01 11:59:27.137787 7ffec89c6700 10 >>>>>>>>>> monclient(hunting): >>>>>>>>>> _reopen_session rank -1 name >>>>>>>>>> -9998> 2014-04-01 11:59:27.137790 7ffec89c6700 1 -- >>>>>>>>>> 10.141.8.180:6837/55117 mark_down 0x1326be460 -- 0x2cae5f00 >>>>>>>>>> -9997> 2014-04-01 11:59:27.137807 7ffebf672700 2 -- >>>>>>>>>> 10.141.8.180:6837/55117 >> 10.141.8.181:6789/0 pipe(0x2cae5f00 >>>>>>>>>> sd=57 >>>>>>>>>> :0 s=4 pgs=0 cs=0 l=1 c=0x1326be460).connect error 10.141.8.1\ >>>>>>>>>> 81:6789/0, 104: Connection reset by peer >>>>>>>>>> -9996> 2014-04-01 11:59:27.137819 7ffebf672700 3 -- >>>>>>>>>> 10.141.8.180:6837/55117 >> 10.141.8.181:6789/0 pipe(0x2cae5f00 >>>>>>>>>> sd=57 >>>>>>>>>> :0 s=4 pgs=0 cs=0 l=1 c=0x1326be460).connect fault, but state\ >>>>>>>>>> = closed != connecting, stopping >>>>>>>>>> -9995> 2014-04-01 11:59:27.137824 7ffec89c6700 10 >>>>>>>>>> monclient(hunting): >>>>>>>>>> picked mon.ceph003 con 0x3af54ba0 addr 10.141.8.182:6789/0 >>>>>>>>>> -9994> 2014-04-01 11:59:27.137832 7ffec89c6700 10 >>>>>>>>>> monclient(hunting): >>>>>>>>>> _send_mon_message to mon.ceph003 at 10.141.8.182:6789/0 >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>> >>>>>>>>>> -Greg >>>>>>>>>> Software Engineer #42 @ http://inktank.com | http://ceph.com >>>>>>>>>> >>>>>>>>>> >>>>>>>>>> On Wed, Apr 2, 2014 at 3:39 AM, Kenneth Waegeman >>>>>>>>>> <[email protected]> wrote: >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> ----- Message from Gregory Farnum <[email protected]> --------- >>>>>>>>>>> Date: Tue, 1 Apr 2014 09:03:17 -0700 >>>>>>>>>>> From: Gregory Farnum <[email protected]> >>>>>>>>>>> >>>>>>>>>>> Subject: Re: [ceph-users] ceph 0.78 mon and mds crashing (bus >>>>>>>>>>> error) >>>>>>>>>>> To: "Yan, Zheng" <[email protected]> >>>>>>>>>>> Cc: Kenneth Waegeman <[email protected]>, >>>>>>>>>>> ceph-users >>>>>>>>>>> <[email protected]> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>>> On Tue, Apr 1, 2014 at 7:12 AM, Yan, Zheng <[email protected]> >>>>>>>>>>>> wrote: >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> On Tue, Apr 1, 2014 at 10:02 PM, Kenneth Waegeman >>>>>>>>>>>>> <[email protected]> wrote: >>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> >>>>>>>>>>>>>> After some more searching, I've found that the source of the >>>>>>>>>>>>>> problem is >>>>>>>>>>>>>> with >>>>>>>>>>>>>> the mds and not the mon.. The mds crashes, generates a core >>>>>>>>>>>>>> dump >>>>>>>>>>>>>> that >>>>>>>>>>>>>> eats >>>>>>>>>>>>>> the local space, and in turn the monitor (because of leveldb) >>>>>>>>>>>>>> crashes. >>>>>>>>>>>>>> >>>>>>>>>>>>>> The error in the mds log of one host: >>>>>>>>>>>>>> >>>>>>>>>>>>>> 2014-04-01 15:46:34.414615 7f870e319700 0 -- >>>>>>>>>>>>>> 10.141.8.180:6836/13152 >> >>>>>>>>>>>>>> 10.141.8.180:6789/0 pipe(0x517371180 sd=54 :42439 s=4 pgs=0 >>>>>>>>>>>>>> cs=0 >>>>>>>>>>>>>> l=1 >>>>>>>>>>>>>> c=0x147ac780).connect got RESETSESSION but no longer >>>>>>>>>>>>>> connecting >>>>>>>>>>>>>> 2014-04-01 15:46:34.438792 7f871194f700 0 -- >>>>>>>>>>>>>> 10.141.8.180:6836/13152 >> >>>>>>>>>>>>>> 10.141.8.180:6789/0 pipe(0x1b099f580 sd=8 :43150 s=4 pgs=0 >>>>>>>>>>>>>> cs=0 >>>>>>>>>>>>>> l=1 >>>>>>>>>>>>>> c=0x1fd44360).connect got RESETSESSION but no longer >>>>>>>>>>>>>> connecting >>>>>>>>>>>>>> 2014-04-01 15:46:34.439028 7f870e319700 0 -- >>>>>>>>>>>>>> 10.141.8.180:6836/13152 >> >>>>>>>>>>>>>> 10.141.8.182:6789/0 pipe(0x13aa64880 sd=54 :37085 s=4 pgs=0 >>>>>>>>>>>>>> cs=0 >>>>>>>>>>>>>> l=1 >>>>>>>>>>>>>> c=0x1fd43de0).connect got RESETSESSION but no longer >>>>>>>>>>>>>> connecting >>>>>>>>>>>>>> 2014-04-01 15:46:34.468257 7f871b7ae700 -1 mds/CDir.cc: In >>>>>>>>>>>>>> function >>>>>>>>>>>>>> 'void >>>>>>>>>>>>>> CDir::_omap_fetched(ceph::bufferlist&, >>>>>>>>>>>>>> std::map<std::basic_string<char, >>>>>>>>>>>>>> std::char_traits<char>, std::allocator<char> >, >>>>>>>>>>>>>> ceph::buffer::list, >>>>>>>>>>>>>> std::less<std::basic_string<char, std::char_traits<char>, >>>>>>>>>>>>>> std::allocator<char> > >, std::allocator<std::pair<const >>>>>>>>>>>>>> std::basic_string<char, std::char_traits<char>, >>>>>>>>>>>>>> std::allocator<char> >, >>>>>>>>>>>>>> ceph::buffer::list> > >&, const std::string&, int)' thread >>>>>>>>>>>>>> 7f871b7ae700 >>>>>>>>>>>>>> time >>>>>>>>>>>>>> 2014-04-01 15:46:34.448320 >>>>>>>>>>>>>> mds/CDir.cc: 1474: FAILED assert(r == 0 || r == -2 || r == >>>>>>>>>>>>>> -61) >>>>>>>>>>>>>> >>>>>>>>>>>>> >>>>>>>>>>>>> could you use gdb to check what is value of variable 'r' . >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> >>>>>>>>>>>> If you look at the crash dump log you can see the return value >>>>>>>>>>>> in >>>>>>>>>>>> the >>>>>>>>>>>> osd_op_reply message: >>>>>>>>>>>> -1> 2014-04-01 15:46:34.440860 7f871b7ae700 1 -- >>>>>>>>>>>> 10.141.8.180:6836/13152 <== osd.3 10.141.8.180:6827/4366 33077 >>>>>>>>>>>> ==== >>>>>>>>>>>> osd_op_reply(4179177 100001f2ef1.00000000 [omap-get-header >>>>>>>>>>>> 0~0,omap-get-vals 0~16] v0'0 uv0 ack = -108 (Cannot send after >>>>>>>>>>>> transport endpoint shutdown)) v6 ==== 229+0+0 (958358678 0 0) >>>>>>>>>>>> 0x2cff7aa80 con 0x37ea3c0 >>>>>>>>>>>> >>>>>>>>>>>> -108, which is ESHUTDOWN, but we also use it (via the 108 >>>>>>>>>>>> constant, >>>>>>>>>>>> I >>>>>>>>>>>> think because ESHUTDOWN varies across platforms) as >>>>>>>>>>>> EBLACKLISTED. >>>>>>>>>>>> So it looks like this is itself actually a symptom of another >>>>>>>>>>>> problem >>>>>>>>>>>> that is causing the MDS to get timed out on the monitor. If a >>>>>>>>>>>> core >>>>>>>>>>>> dump is "eating the local space", maybe the MDS is stuck in an >>>>>>>>>>>> infinite allocation loop of some kind? How big are your disks, >>>>>>>>>>>> Kenneth? Do you have any information on how much CPU/memory the >>>>>>>>>>>> MDS >>>>>>>>>>>> was using before this? >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> I monitored the mds process after restart: >>>>>>>>>>> >>>>>>>>>>> PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ >>>>>>>>>>> COMMAND >>>>>>>>>>> 19215 root 20 0 6070m 5.7g 5236 S 778.6 18.1 1:27.54 >>>>>>>>>>> ceph-mds >>>>>>>>>>> 19215 root 20 0 7926m 7.5g 5236 S 179.2 23.8 2:44.39 >>>>>>>>>>> ceph-mds >>>>>>>>>>> 19215 root 20 0 12.4g 12g 5236 S 157.2 38.8 3:43.47 >>>>>>>>>>> ceph-mds >>>>>>>>>>> 19215 root 20 0 16.6g 16g 5236 S 144.4 52.0 4:15.01 >>>>>>>>>>> ceph-mds >>>>>>>>>>> 19215 root 20 0 19.9g 19g 5236 S 137.2 62.5 4:35.83 >>>>>>>>>>> ceph-mds >>>>>>>>>>> 19215 root 20 0 24.5g 24g 5224 S 136.5 77.0 5:04.66 >>>>>>>>>>> ceph-mds >>>>>>>>>>> 19215 root 20 0 25.8g 25g 2944 S 33.7 81.2 5:13.74 >>>>>>>>>>> ceph-mds >>>>>>>>>>> 19215 root 20 0 26.0g 25g 2916 S 24.6 81.7 5:19.07 >>>>>>>>>>> ceph-mds >>>>>>>>>>> 19215 root 20 0 26.1g 25g 2916 S 13.0 82.1 5:22.16 >>>>>>>>>>> ceph-mds >>>>>>>>>>> 19215 root 20 0 27.7g 26g 1856 S 100.0 85.8 5:36.46 >>>>>>>>>>> ceph-mds >>>>>>>>>>> >>>>>>>>>>> Then it crashes. I changed the core dump location out of the root >>>>>>>>>>> fs, >>>>>>>>>>> the >>>>>>>>>>> core dump is indeed about 26G >>>>>>>>>>> >>>>>>>>>>> My disks: >>>>>>>>>>> >>>>>>>>>>> Filesystem Size Used Avail Use% Mounted on >>>>>>>>>>> /dev/sda2 9.9G 2.9G 6.5G 31% / >>>>>>>>>>> tmpfs 16G 0 16G 0% /dev/shm >>>>>>>>>>> /dev/sda1 248M 53M 183M 23% /boot >>>>>>>>>>> /dev/sda4 172G 61G 112G 35% /var/lib/ceph/log/sda4 >>>>>>>>>>> /dev/sdb 187G 61G 127G 33% /var/lib/ceph/log/sdb >>>>>>>>>>> /dev/sdc 3.7T 1.7T 2.0T 47% /var/lib/ceph/osd/sdc >>>>>>>>>>> /dev/sdd 3.7T 1.5T 2.2T 41% /var/lib/ceph/osd/sdd >>>>>>>>>>> /dev/sde 3.7T 1.4T 2.4T 37% /var/lib/ceph/osd/sde >>>>>>>>>>> /dev/sdf 3.7T 1.5T 2.3T 39% /var/lib/ceph/osd/sdf >>>>>>>>>>> /dev/sdg 3.7T 2.1T 1.7T 56% /var/lib/ceph/osd/sdg >>>>>>>>>>> /dev/sdh 3.7T 1.7T 2.0T 47% /var/lib/ceph/osd/sdh >>>>>>>>>>> /dev/sdi 3.7T 1.7T 2.0T 47% /var/lib/ceph/osd/sdi >>>>>>>>>>> /dev/sdj 3.7T 1.7T 2.0T 47% /var/lib/ceph/osd/sdj >>>>>>>>>>> /dev/sdk 3.7T 2.1T 1.6T 58% /var/lib/ceph/osd/sdk >>>>>>>>>>> /dev/sdl 3.7T 1.7T 2.0T 46% /var/lib/ceph/osd/sdl >>>>>>>>>>> /dev/sdm 3.7T 1.5T 2.2T 41% /var/lib/ceph/osd/sdm >>>>>>>>>>> /dev/sdn 3.7T 1.4T 2.3T 38% /var/lib/ceph/osd/sdn >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>>> -Greg >>>>>>>>>>>> Software Engineer #42 @ http://inktank.com | http://ceph.com >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> ----- End message from Gregory Farnum <[email protected]> ----- >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> >>>>>>>>>>> -- >>>>>>>>>>> >>>>>>>>>>> Met vriendelijke groeten, >>>>>>>>>>> Kenneth Waegeman >>>>>>>>>>> >>>>>>>>>> _______________________________________________ >>>>>>>>>> ceph-users mailing list >>>>>>>>>> [email protected] >>>>>>>>>> http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com >>>>>>>>>> >>>>>>>>>> >>>>>>>>> _______________________________________________ >>>>>>>>> ceph-users mailing list >>>>>>>>> [email protected] >>>>>>>>> http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com >>>>>>>>> >>>>>>>>> >>>>>>>> _______________________________________________ >>>>>>>> ceph-users mailing list >>>>>>>> [email protected] >>>>>>>> http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com >>>>>>> >>>>>>> >>>>>>> >>>>>>> >>>>>> >>>>>> _______________________________________________ >>>>>> ceph-users mailing list >>>>>> [email protected] >>>>>> http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com >>>>>> >>>>> >>>> >> _______________________________________________ >> ceph-users mailing list >> [email protected] >> http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com > > > > ----- End message from Stijn De Weirdt <[email protected]> ----- > > > -- > > Met vriendelijke groeten, > Kenneth Waegeman > > _______________________________________________ > ceph-users mailing list > [email protected] > http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com _______________________________________________ ceph-users mailing list [email protected] http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com
