On Sun, 19 Jan 2014, Guang wrote:
> Thanks Sage.
>
> I just captured part of the log (it was fast growing), the process did
> not hang but I saw the same pattern repeatedly. Should I increase the
> log level and send over email (it constantly reproduced)?
Sure! A representative fragment of the repeating fragment shoudl be
enough.
s
>
> Thanks,
> Guang
>
> On Jan 18, 2014, at 12:05 AM, Sage Weil <sage@xxxxxxxxxxx> wrote:
>
> > On Fri, 17 Jan 2014, Guang wrote:
> >> Thanks Sage.
> >>
> >> I further narrow down the problem to #any command using paxos service would hang#, following are details:
> >>
> >> 1. I am able to run ceph status / osd dump, etc., however, the result are out of date (though I stopped all OSDs, it does not reflect in ceph status report).
> >>
> >> -bash-4.1$ sudo ceph -s
> >> cluster b9cb3ea9-e1de-48b4-9e86-6921e2c537d2
> >> health HEALTH_WARN 2797 pgs degraded; 107 pgs down; 7503 pgs peering; 917 pgs recovering; 6079 pgs recovery_wait; 2957 pgs stale; 7771 pgs stuck inactive; 2957 pgs stuck stale; 16567 pgs stuck unclean; recovery 54346804/779462977 degraded (6.972%); 9/259724199 unfound (0.000%); 2 near full osd(s); 57/751 in osds are down; noout,nobackfill,norecover,noscrub,nodeep-scrub flag(s) set
> >> monmap e1: 3 mons at {osd151=10.194.0.68:6789/0,osd152=10.193.207.130:6789/0,osd153=10.193.207.131:6789/0}, election epoch 123278, quorum 0,1,2 osd151,osd152,osd153
> >> osdmap e134893: 781 osds: 694 up, 751 in
> >> pgmap v2388518: 22203 pgs: 26 inactive, 14 active, 79 stale+active+recovering, 5020 active+clean, 242 stale, 4352 active+recovery_wait, 616 stale+active+clean, 177 active+recovering+degraded, 6714 peering, 925 stale+active+recovery_wait, 86 down+peering, 1547 active+degraded, 32 stale+active+recovering+degraded, 648 stale+peering, 21 stale+down+peering, 239 stale+active+degraded, 651 active+recovery_wait+degraded, 30 remapped+peering, 151 stale+active+recovery_wait+degraded, 4 stale+remapped+peering, 629 active+recovering; 79656 GB data, 363 TB used, 697 TB / 1061 TB avail; 54346804/779462977 degraded (6.972%); 9/259724199 unfound (0.000%)
> >> mdsmap e1: 0/0/1 up
> >>
> >> 2. If I run a command which uses paxos, the command will hang forever, this includes, ceph osd set noup (and also including those commands osd send to monitor when being started (create-or-add)).
> >>
> >> I attached the corresponding monitor log (it is like a bug).
> >
> > I see the osd set command coming through, but it arrives while paxos is
> > converging and the log seems to end before the mon would normally process
> > te delayed messages. Is there a reason why the log fragment you attached
> > ends there, or did the process hang or something?
> >
> > Thanks-
> > sage
> >
> >> I
> >>
> >> On Jan 17, 2014, at 1:35 AM, Sage Weil <sage@xxxxxxxxxxx> wrote:
> >>
> >>> Hi Guang,
> >>>
> >>> On Thu, 16 Jan 2014, Guang wrote:
> >>>> I still have bad the luck to figure out what is the problem making authentication failure, so in order to get the cluster back, I tried:
> >>>> 1. stop all daemons (mon & osd)
> >>>> 2. change the configuration to disable cephx
> >>>> 3. start mon daemons (3 in total)
> >>>> 4. start osd daemon one by one
> >>>>
> >>>> After finishing step 3, the cluster can be reachable ('ceph -s' give results):
> >>>> -bash-4.1$ sudo ceph -s
> >>>> cluster b9cb3ea9-e1de-48b4-9e86-6921e2c537d2
> >>>> health HEALTH_WARN 2797 pgs degraded; 107 pgs down; 7503 pgs peering; 917 pgs recovering; 6079 pgs recovery_wait; 2957 pgs stale; 7771 pgs stuck inactive; 2957 pgs stuck stale; 16567 pgs stuck unclean; recovery 54346804/779462977 degraded (6.972%); 9/259724199 unfound (0.000%); 2 near full osd(s); 57/751 in osds are down; noout,nobackfill,norecover,noscrub,nodeep-scrub flag(s) set
> >>>> monmap e1: 3 mons at {osd151=10.194.0.68:6789/0,osd152=10.193.207.130:6789/0,osd153=10.193.207.131:6789/0}, election epoch 106022, quorum 0,1,2 osd151,osd152,osd153
> >>>> osdmap e134893: 781 osds: 694 up, 751 in
> >>>> pgmap v2388518: 22203 pgs: 26 inactive, 14 active, 79 stale+active+recovering, 5020 active+clean, 242 stale, 4352 active+recovery_wait, 616 stale+active+clean, 177 active+recovering+degraded, 6714 peering, 925 stale+active+recovery_wait, 86 down+peering, 1547 active+degraded, 32 stale+active+recovering+degraded, 648 stale+peering, 21 stale+down+peering, 239 stale+active+degraded, 651 active+recovery_wait+degraded, 30 remapped+peering, 151 stale+active+recovery_wait+degraded, 4 stale+remapped+peering, 629 active+recovering; 79656 GB data, 363 TB used, 697 TB / 1061 TB avail; 54346804/779462977 degraded (6.972%); 9/259724199 unfound (0.000%)
> >>>> mdsmap e1: 0/0/1 up
> >>>> (at this point, all OSDs should be down).
> >>>>
> >>>> When I tried to start OSD daemon, the starting script got hang, and the process hang is:
> >>>> root 80497 80496 0 08:18 pts/0 00:00:00 python /usr/bin/ceph --name=osd.22 --keyring=/var/lib/ceph/osd/ceph-22/keyring osd crush create-or-move -- 22 0.40 root=default host=osd173
> >>>>
> >>>> When I strace the starting script, I got the following traces (process 75873 is the above process), it failed with futex and then do a infinite loop:
> >>>> select(0, NULL, NULL, NULL, {0, 16000}) = 0 (Timeout)
> >>>> Any idea what might trigger this?
> >>>
> >>> It is hard to tell from the strace what is going on from this. Do you see
> >>> that the OSDs are booting in ceph.log (or ceph -w output)? If not, I
> >>> would look at the osd daemon log for clues. You may need to turn up
> >>> debugging to see (ceph daemon osd.NNN config set debug_osd 20 to adjust
> >>> the level on the running daemon).
> >>>
> >>> If they are booting, it is mostly a matter of letting it recover and come
> >>> up. We have seen patterns where configuration or network issues have let
> >>> the system bury itself under a series of osdmap updates. If you see that
> >>> in the log when you turn up debugging, or see the osds going up and down
> >>> when you try to bring the cluster up, that could be what is going on. A
> >>> strategy that has worked there is to let all the osds catch up on their
> >>> maps before trying to peer and join the cluster. To do that, 'ceph osd
> >>> set noup' (which prevents the osds from joining), wait for the ceph-osd
> >>> processes to stop chewing on maps (watch the cpu utilization in top), and
> >>> once they are all ready 'ceph osd unset noup' and let them join and peer
> >>> all at once.
> >>>
> >>> sage
> >>>
> >>>>
> >>>> ======= STRACE (PARTIAL) ==========
> >>>> [pid 75873] futex(0xf707a0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
> >>>> [pid 75878] mmap(NULL, 134217728, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x7f5da6529000
> >>>> [pid 75878] munmap(0x7f5da6529000, 28143616) = 0
> >>>> [pid 75878] munmap(0x7f5dac000000, 38965248) = 0
> >>>> [pid 75878] mprotect(0x7f5da8000000, 135168, PROT_READ|PROT_WRITE) = 0
> >>>> [pid 75878] futex(0xf707a0, FUTEX_WAKE_PRIVATE, 1) = 1
> >>>> [pid 75873] <... futex resumed> ) = 0
> >>>> [pid 75873] futex(0xdd3cb0, FUTEX_WAIT_PRIVATE, 0, NULL <unfinished ...>
> >>>> [pid 75878] futex(0xdd3cb0, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
> >>>> [pid 75873] <... futex resumed> ) = -1 EAGAIN (Resource temporarily unavailable)
> >>>> [pid 75878] <... futex resumed> ) = 0
> >>>> [pid 75873] select(0, NULL, NULL, NULL, {0, 1000} <unfinished ...>
> >>>> [pid 75878] rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1], [], 8) = 0
> >>>> [pid 75878] mmap(NULL, 10489856, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f5dadb28000
> >>>> [pid 75878] mprotect(0x7f5dadb28000, 4096, PROT_NONE) = 0
> >>>> [ omit some entries?]
> >>>> [pid 75873] select(0, NULL, NULL, NULL, {0, 16000}) = 0 (Timeout)
> >>>> [pid 75873] select(0, NULL, NULL, NULL, {0, 32000}) = 0 (Timeout)
> >>>> [pid 75873] select(0, NULL, NULL, NULL, {0, 50000}) = 0 (Timeout)
> >>>> [pid 75873] select(0, NULL, NULL, NULL, {0, 50000}) = 0 (Timeout)
> >>>> [pid 75873] select(0, NULL, NULL, NULL, {0, 50000}) = 0 (Timeout)
> >>>> [pid 75873] select(0, NULL, NULL, NULL, {0, 50000}) = 0 (Timeout)
> >>>> [pid 75873] select(0, NULL, NULL, NULL, {0, 50000}) = 0 (Timeout)
> >>>>
> >>>>
> >>>> Thanks,
> >>>> Guang
> >>>>
> >>>> On Jan 15, 2014, at 5:54 AM, Guang <yguang11@xxxxxxxxxxx> wrote:
> >>>>
> >>>>> Thanks Sage.
> >>>>>
> >>>>> -bash-4.1$ sudo ceph --admin-daemon /var/run/ceph/ceph-mon.osd151.asok mon_status
> >>>>> { "name": "osd151",
> >>>>> "rank": 2,
> >>>>> "state": "electing",
> >>>>> "election_epoch": 85469,
> >>>>> "quorum": [],
> >>>>> "outside_quorum": [],
> >>>>> "extra_probe_peers": [],
> >>>>> "sync_provider": [],
> >>>>> "monmap": { "epoch": 1,
> >>>>> "fsid": "b9cb3ea9-e1de-48b4-9e86-6921e2c537d2",
> >>>>> "modified": "0.000000",
> >>>>> "created": "0.000000",
> >>>>> "mons": [
> >>>>> { "rank": 0,
> >>>>> "name": "osd152",
> >>>>> "addr": "10.193.207.130:6789\/0"},
> >>>>> { "rank": 1,
> >>>>> "name": "osd153",
> >>>>> "addr": "10.193.207.131:6789\/0"},
> >>>>> { "rank": 2,
> >>>>> "name": "osd151",
> >>>>> "addr": "10.194.0.68:6789\/0"}]}}
> >>>>>
> >>>>> And:
> >>>>>
> >>>>> -bash-4.1$ sudo ceph --admin-daemon /var/run/ceph/ceph-mon.osd151.asok quorum_status
> >>>>> { "election_epoch": 85480,
> >>>>> "quorum": [
> >>>>> 0,
> >>>>> 1,
> >>>>> 2],
> >>>>> "quorum_names": [
> >>>>> "osd151",
> >>>>> "osd152",
> >>>>> "osd153"],
> >>>>> "quorum_leader_name": "osd152",
> >>>>> "monmap": { "epoch": 1,
> >>>>> "fsid": "b9cb3ea9-e1de-48b4-9e86-6921e2c537d2",
> >>>>> "modified": "0.000000",
> >>>>> "created": "0.000000",
> >>>>> "mons": [
> >>>>> { "rank": 0,
> >>>>> "name": "osd152",
> >>>>> "addr": "10.193.207.130:6789\/0"},
> >>>>> { "rank": 1,
> >>>>> "name": "osd153",
> >>>>> "addr": "10.193.207.131:6789\/0"},
> >>>>> { "rank": 2,
> >>>>> "name": "osd151",
> >>>>> "addr": "10.194.0.68:6789\/0"}]}}
> >>>>>
> >>>>>
> >>>>> The election has been finished with leader selected from the above status.
> >>>>>
> >>>>> Thanks,
> >>>>> Guang
> >>>>>
> >>>>> On Jan 14, 2014, at 10:55 PM, Sage Weil <sage@xxxxxxxxxxx> wrote:
> >>>>>
> >>>>>> On Tue, 14 Jan 2014, GuangYang wrote:
> >>>>>>> Hi ceph-users and ceph-devel,
> >>>>>>> I came across an issue after restarting monitors of the cluster, that authentication fails which prevents running any ceph command.
> >>>>>>>
> >>>>>>> After we did some maintenance work, I restart OSD, however, I found that the OSD would not join the cluster automatically after being restarted, though TCP dump showed it had already sent messenger to monitor telling add me into the cluster.
> >>>>>>>
> >>>>>>> So that I suspected there might be some issues of monitor and I restarted monitor one by one (3 in total), however, after restarting monitors, all ceph command would fail saying authentication timeout?
> >>>>>>>
> >>>>>>> 2014-01-14 12:00:30.499397 7fc7f195e700 0 monclient(hunting): authenticate timed out after 300
> >>>>>>> 2014-01-14 12:00:30.499440 7fc7f195e700 0 librados: client.admin authentication error (110) Connection timed out
> >>>>>>> Error connecting to cluster: Error
> >>>>>>>
> >>>>>>> Any idea why such error happened (restarting OSD would result in the same error)?
> >>>>>>>
> >>>>>>> I am thinking the authentication information is persisted in mon local disk and is there a chance those data got corrupted?
> >>>>>>
> >>>>>> That sounds unlikely, but you're right that the core problem is with the
> >>>>>> mons. What does
> >>>>>>
> >>>>>> ceph daemon mon.`hostname` mon_status
> >>>>>>
> >>>>>> say? Perhaps they are not forming a quorum and that is what is preventing
> >>>>>> authentication.
> >>>>>>
> >>>>>> sage
> >>>>>> --
> >>>>>> To unsubscribe from this list: send the line "unsubscribe ceph-devel" in
> >>>>>> the body of a message to majordomo@xxxxxxxxxxxxxxx
> >>>>>> More majordomo info at http://vger.kernel.org/majordomo-info.html
> >>>>>
> >>>>
> >>>>
> >>>
> >>
> >>
> >
>
>
_______________________________________________
ceph-users mailing list
ceph-users@xxxxxxxxxxxxxx
http://lists.ceph.com/listinfo.cgi/ceph-users-ceph.com
