Project

General

Profile

Bug #5069 » mdsmonitor_assert_mon.1.log

Florian Wiessner, 05/16/2013 03:25 AM

 
-133> 2013-05-16 05:07:18.644202 7fc8666a8700 1 -- 188.65.144.5:6789/0 --> mon.3 188.65.144.7:6789/0 -- election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 propose 12125) v4 -- ?+0 0x14c8b900
-132> 2013-05-16 05:07:18.644212 7fc8666a8700 1 -- 188.65.144.5:6789/0 --> mon.4 188.65.144.8:6789/0 -- election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 propose 12125) v4 -- ?+0 0x145c5000
-131> 2013-05-16 05:07:18.644240 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.2 188.65.144.6:6789/0 489911092 ==== mon_probe(reply 2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 name 2 quorum 0,2,3,4 paxos( fc 31852646 lc 31865060 )) v4 ==== 853+0+0 (4272104714 0 0) 0x17991600 con 0x21372c0
-130> 2013-05-16 05:07:18.644259 7fc8666a8700 10 mon.1@1(electing) e8 handle_probe mon_probe(reply 2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 name 2 quorum 0,2,3,4 paxos( fc 31852646 lc 31865060 )) v4
-129> 2013-05-16 05:07:18.644263 7fc8666a8700 10 mon.1@1(electing) e8 handle_probe_reply mon.2 188.65.144.6:6789/0mon_probe(reply 2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 name 2 quorum 0,2,3,4 paxos( fc 31852646 lc 31865060 )) v4
-128> 2013-05-16 05:07:18.644268 7fc8666a8700 10 mon.1@1(electing) e8 monmap is e8: 5 mons at {0=188.65.144.4:6789/0,1=188.65.144.5:6789/0,2=188.65.144.6:6789/0,3=188.65.144.7:6789/0,4=188.65.144.8:6789/0}
-127> 2013-05-16 05:07:18.644275 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.4 188.65.144.8:6789/0 3051 ==== mon_probe(reply 2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 name 4 quorum 0,2,3,4 paxos( fc 31852646 lc 31865060 )) v4 ==== 853+0+0 (2474847232 0 0) 0x17991000 con 0x2137000
-126> 2013-05-16 05:07:18.644282 7fc8666a8700 10 mon.1@1(electing) e8 handle_probe mon_probe(reply 2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 name 4 quorum 0,2,3,4 paxos( fc 31852646 lc 31865060 )) v4
-125> 2013-05-16 05:07:18.644293 7fc8666a8700 10 mon.1@1(electing) e8 handle_probe_reply mon.4 188.65.144.8:6789/0mon_probe(reply 2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 name 4 quorum 0,2,3,4 paxos( fc 31852646 lc 31865060 )) v4
-124> 2013-05-16 05:07:18.644299 7fc8666a8700 10 mon.1@1(electing) e8 monmap is e8: 5 mons at {0=188.65.144.4:6789/0,1=188.65.144.5:6789/0,2=188.65.144.6:6789/0,3=188.65.144.7:6789/0,4=188.65.144.8:6789/0}
-123> 2013-05-16 05:07:18.644307 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.1 188.65.144.5:6789/0 0 ==== log(2 entries) v1 ==== 0+0+0 (0 0 0) 0x18d976c0 con 0x1bcf160
-122> 2013-05-16 05:07:18.667038 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.0 188.65.144.4:6789/0 1801767831 ==== mon_probe(reply 2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 name 0 quorum 0,2,3,4 paxos( fc 31852646 lc 31865061 )) v4 ==== 853+0+0 (1876652676 0 0) 0x19236c00 con 0x2137420
-121> 2013-05-16 05:07:18.667058 7fc8666a8700 10 mon.1@1(electing) e8 handle_probe mon_probe(reply 2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 name 0 quorum 0,2,3,4 paxos( fc 31852646 lc 31865061 )) v4
-120> 2013-05-16 05:07:18.667063 7fc8666a8700 10 mon.1@1(electing) e8 handle_probe_reply mon.0 188.65.144.4:6789/0mon_probe(reply 2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 name 0 quorum 0,2,3,4 paxos( fc 31852646 lc 31865061 )) v4
-119> 2013-05-16 05:07:18.667076 7fc8666a8700 10 mon.1@1(electing) e8 monmap is e8: 5 mons at {0=188.65.144.4:6789/0,1=188.65.144.5:6789/0,2=188.65.144.6:6789/0,3=188.65.144.7:6789/0,4=188.65.144.8:6789/0}
-118> 2013-05-16 05:07:18.667085 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.3 188.65.144.7:6789/0 3211 ==== election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 propose 12143) v4 ==== 807+0+0 (1969300828 0 0) 0x14c8b900 con 0x2137160
-117> 2013-05-16 05:07:18.667101 7fc8666a8700 5 mon.1@1(electing).elector(12125) handle_propose from mon.3
-116> 2013-05-16 05:07:18.667104 7fc8666a8700 10 mon.1@1(electing).elector(12125) bump_epoch 12125 to 12143
-115> 2013-05-16 05:07:18.860834 7fc8666a8700 10 mon.1@1(electing) e8 reset
-114> 2013-05-16 05:07:18.860852 7fc8666a8700 10 mon.1@1(electing) e8 timecheck_finish
-113> 2013-05-16 05:07:18.883273 7fc8666a8700 10 mon.1@1(electing) e8 reset
-112> 2013-05-16 05:07:18.883289 7fc8666a8700 10 mon.1@1(electing) e8 timecheck_finish
-111> 2013-05-16 05:07:18.904372 7fc8666a8700 10 mon.1@1(electing) e8 start_election
-110> 2013-05-16 05:07:18.904382 7fc8666a8700 10 mon.1@1(electing) e8 cancel_probe_timeout (none scheduled)
-109> 2013-05-16 05:07:18.904389 7fc8666a8700 0 log [INF] : mon.1 calling new monitor election
-108> 2013-05-16 05:07:18.904391 7fc8666a8700 10 send_log to self
-107> 2013-05-16 05:07:18.904392 7fc8666a8700 10 log_queue is 4 last_log 868 sent 866 num 4 unsent 2 sending 2
-106> 2013-05-16 05:07:18.904399 7fc8666a8700 10 will send 2013-05-16 04:52:35.548256 mon.1 188.65.144.5:6789/0 866 : [INF] mon.1@1 won leader election with quorum 1,2,3,4
-105> 2013-05-16 05:07:18.904408 7fc8666a8700 10 will send 2013-05-16 05:07:18.513870 mon.1 188.65.144.5:6789/0 867 : [INF] mon.1 calling new monitor election
-104> 2013-05-16 05:07:18.904412 7fc8666a8700 1 -- 188.65.144.5:6789/0 --> mon.1 188.65.144.5:6789/0 -- log(2 entries) v1 -- ?+0 0x177d9480
-103> 2013-05-16 05:07:18.904423 7fc8666a8700 5 mon.1@1(electing).elector(12143) start -- can i be leader?
-102> 2013-05-16 05:07:18.904545 7fc8666a8700 1 mon.1@1(electing).elector(12143) init, last seen epoch 12143
-101> 2013-05-16 05:07:18.904555 7fc8666a8700 1 -- 188.65.144.5:6789/0 --> mon.0 188.65.144.4:6789/0 -- election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 propose 12143) v4 -- ?+0 0x177d96c0
-100> 2013-05-16 05:07:18.904568 7fc8666a8700 1 -- 188.65.144.5:6789/0 --> mon.2 188.65.144.6:6789/0 -- election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 propose 12143) v4 -- ?+0 0x177d9900
-99> 2013-05-16 05:07:18.904580 7fc8666a8700 1 -- 188.65.144.5:6789/0 --> mon.3 188.65.144.7:6789/0 -- election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 propose 12143) v4 -- ?+0 0x177d9000
-98> 2013-05-16 05:07:18.904593 7fc8666a8700 1 -- 188.65.144.5:6789/0 --> mon.4 188.65.144.8:6789/0 -- election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 propose 12143) v4 -- ?+0 0x177d9240
-97> 2013-05-16 05:07:18.904614 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.4 188.65.144.8:6789/0 3052 ==== election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 propose 12143) v4 ==== 807+0+0 (1969300828 0 0) 0x145c5000 con 0x2137000
-96> 2013-05-16 05:07:18.904640 7fc8666a8700 5 mon.1@1(electing).elector(12143) handle_propose from mon.4
-95> 2013-05-16 05:07:18.904648 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.1 188.65.144.5:6789/0 0 ==== log(2 entries) v1 ==== 0+0+0 (0 0 0) 0x177d9480 con 0x1bcf160
-94> 2013-05-16 05:07:18.925292 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.0 188.65.144.4:6789/0 1801767832 ==== election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 propose 12143) v4 ==== 807+0+0 (1969300828 0 0) 0x17918000 con 0x2137420
-93> 2013-05-16 05:07:18.925317 7fc8666a8700 5 mon.1@1(electing).elector(12143) handle_propose from mon.0
-92> 2013-05-16 05:07:18.925321 7fc8666a8700 5 mon.1@1(electing).elector(12143) defer to 0
-91> 2013-05-16 05:07:18.925326 7fc8666a8700 1 -- 188.65.144.5:6789/0 --> mon.0 188.65.144.4:6789/0 -- election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 ack 12143) v4 -- ?+0 0x145c5000
-90> 2013-05-16 05:07:18.925340 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.2 188.65.144.6:6789/0 489911093 ==== election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 propose 12143) v4 ==== 807+0+0 (1969300828 0 0) 0x18d97480 con 0x21372c0
-89> 2013-05-16 05:07:18.925362 7fc8666a8700 5 mon.1@1(electing).elector(12143) handle_propose from mon.2
-88> 2013-05-16 05:07:18.925367 7fc8666a8700 5 mon.1@1(electing).elector(12143) no, we already acked 0
-87> 2013-05-16 05:07:18.925372 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.3 188.65.144.7:6789/0 3212 ==== election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 ack 12143) v4 ==== 807+0+0 (3542124623 0 0) 0x18d97000 con 0x2137160
-86> 2013-05-16 05:07:18.925390 7fc8666a8700 5 mon.1@1(electing).elector(12143) handle_ack from mon.3
-85> 2013-05-16 05:07:18.925398 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.4 188.65.144.8:6789/0 3053 ==== election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 ack 12143) v4 ==== 807+0+0 (3542124623 0 0) 0x18d326c0 con 0x2137000
-84> 2013-05-16 05:07:18.925410 7fc8666a8700 5 mon.1@1(electing).elector(12143) handle_ack from mon.4
-83> 2013-05-16 05:07:18.925415 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.2 188.65.144.6:6789/0 489911094 ==== election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 ack 12143) v4 ==== 807+0+0 (3542124623 0 0) 0x134e46c0 con 0x21372c0
-82> 2013-05-16 05:07:18.925424 7fc8666a8700 5 mon.1@1(electing).elector(12143) handle_ack from mon.2
-81> 2013-05-16 05:07:18.994254 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.0 188.65.144.4:6789/0 1801767833 ==== election(2ff06d61-7b8e-4b10-b39d-138cfcc1ee43 victory 12144) v4 ==== 827+0+0 (960909070 0 0) 0x17918240 con 0x2137420
-80> 2013-05-16 05:07:18.994316 7fc8666a8700 5 mon.1@1(electing).elector(12143) handle_victory from mon.0 quorum_features 4294967295
-79> 2013-05-16 05:07:18.994322 7fc8666a8700 10 mon.1@1(electing).elector(12143) bump_epoch 12143 to 12144
-78> 2013-05-16 05:07:19.124084 7fc8666a8700 10 mon.1@1(electing) e8 reset
-77> 2013-05-16 05:07:19.124110 7fc8666a8700 10 mon.1@1(electing) e8 timecheck_finish
-76> 2013-05-16 05:07:19.166581 7fc8666a8700 10 mon.1@1(peon) e8 lose_election, epoch 12144 leader is mon0 quorum is 0,1,2,3,4 features are 4294967295
-75> 2013-05-16 05:07:19.207815 7fc8666a8700 10 mon.1@1(peon).data_health(12144) start_epoch epoch 12144
-74> 2013-05-16 05:07:19.207826 7fc8666a8700 10 mon.1@1(peon) e8 timecheck_finish
-73> 2013-05-16 05:07:19.207828 7fc8666a8700 10 mon.1@1(peon) e8 resend_routed_requests
-72> 2013-05-16 05:07:19.207831 7fc8666a8700 10 mon.1@1(peon) e8 register_cluster_logger
-71> 2013-05-16 05:07:19.207842 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.0 188.65.144.4:6789/0 1801767834 ==== paxos(collect lc 31865061 fc 31852646 pn 612800 opn 0) v3 ==== 80+0+0 (1122117718 0 0) 0x191f9280 con 0x2137420
-70> 2013-05-16 05:07:19.509581 7fc8666a8700 1 -- 188.65.144.5:6789/0 --> mon.0 188.65.144.4:6789/0 -- paxos(last lc 31864344 fc 31846715 pn 612800 opn 0) v3 -- ?+0 0x1701f500
-69> 2013-05-16 05:07:19.509615 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.0 188.65.144.4:6789/0 1801767835 ==== time_check( ping e 12144 r 1 ) v1 ==== 36+0+0 (675962479 0 0) 0x17918480 con 0x2137420
-68> 2013-05-16 05:07:19.509632 7fc8666a8700 10 mon.1@1(peon) e8 handle_timecheck time_check( ping e 12144 r 1 ) v1
-67> 2013-05-16 05:07:19.509636 7fc8666a8700 10 mon.1@1(peon) e8 handle_timecheck_peon time_check( ping e 12144 r 1 ) v1
-66> 2013-05-16 05:07:19.509639 7fc8666a8700 10 mon.1@1(peon) e8 handle_timecheck_peon send time_check( ping e 12144 r 1 ) v1 to mon.0 188.65.144.4:6789/0
-65> 2013-05-16 05:07:19.509642 7fc8666a8700 1 -- 188.65.144.5:6789/0 --> 188.65.144.4:6789/0 -- time_check( pong e 12144 r 1 ts 2013-05-16 05:07:19.509639 ) v1 -- ?+0 0x17918240 con 0x2137420
-64> 2013-05-16 05:07:19.696764 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.0 188.65.144.4:6789/0 1801767836 ==== paxos(commit lc 31865061 fc 0 pn 0 opn 0) v3 ==== 17327472+0+0 (379669761 0 0) 0x191f9000 con 0x2137420
-63> 2013-05-16 05:11:18.804568 7fc86457d700 1 -- 188.65.144.5:6789/0 >> :/0 pipe(0x15549a00 sd=22 :6789 s=0 pgs=0 cs=0 l=0).accept sd=22 188.65.144.5:35318/0
-62> 2013-05-16 05:11:18.804602 7fc86457d700 10 mon.1@1(peon) e8 ms_verify_authorizer 188.65.144.5:6801/29051 osd protocol 0
-61> 2013-05-16 05:11:20.765247 7fc86a4a0700 1 -- 188.65.144.5:6789/0 >> :/0 pipe(0x15549c80 sd=27 :6789 s=0 pgs=0 cs=0 l=0).accept sd=27 188.65.144.10:48694/0
-60> 2013-05-16 05:11:20.765435 7fc86a4a0700 10 mon.1@1(peon) e8 ms_verify_authorizer 188.65.144.10:6800/23197 osd protocol 0
-59> 2013-05-16 05:11:48.808133 7fc86457d700 2 -- 188.65.144.5:6789/0 >> 188.65.144.5:6801/29051 pipe(0x15549a00 sd=22 :6789 s=2 pgs=4280 cs=1 l=1).reader couldn't read tag, Success
-58> 2013-05-16 05:11:48.808175 7fc86457d700 2 -- 188.65.144.5:6789/0 >> 188.65.144.5:6801/29051 pipe(0x15549a00 sd=22 :6789 s=2 pgs=4280 cs=1 l=1).fault 0: Success
-57> 2013-05-16 05:11:49.168960 7fc86457d700 1 -- 188.65.144.5:6789/0 >> :/0 pipe(0x1489a280 sd=22 :6789 s=0 pgs=0 cs=0 l=0).accept sd=22 188.65.144.6:53777/0
-56> 2013-05-16 05:11:49.169239 7fc86457d700 10 mon.1@1(peon) e8 ms_verify_authorizer 188.65.144.6:6803/29392 osd protocol 0
-55> 2013-05-16 05:11:50.768653 7fc86a4a0700 2 -- 188.65.144.5:6789/0 >> 188.65.144.10:6800/23197 pipe(0x15549c80 sd=27 :6789 s=2 pgs=4214 cs=1 l=1).reader couldn't read tag, Success
-54> 2013-05-16 05:11:50.768686 7fc86a4a0700 2 -- 188.65.144.5:6789/0 >> 188.65.144.10:6800/23197 pipe(0x15549c80 sd=27 :6789 s=2 pgs=4214 cs=1 l=1).fault 0: Success
-53> 2013-05-16 05:11:50.912373 7fc86a4a0700 1 -- 188.65.144.5:6789/0 >> :/0 pipe(0x18a6c280 sd=27 :6789 s=0 pgs=0 cs=0 l=0).accept sd=27 188.65.144.9:49419/0
-52> 2013-05-16 05:11:50.912754 7fc86a4a0700 10 mon.1@1(peon) e8 ms_verify_authorizer 188.65.144.9:6801/5830 osd protocol 0
-51> 2013-05-16 05:12:19.172052 7fc86457d700 2 -- 188.65.144.5:6789/0 >> 188.65.144.6:6803/29392 pipe(0x1489a280 sd=22 :6789 s=2 pgs=4099 cs=1 l=1).reader couldn't read tag, Success
-50> 2013-05-16 05:12:19.172094 7fc86457d700 2 -- 188.65.144.5:6789/0 >> 188.65.144.6:6803/29392 pipe(0x1489a280 sd=22 :6789 s=2 pgs=4099 cs=1 l=1).fault 0: Success
-49> 2013-05-16 05:12:20.919089 7fc86a4a0700 2 -- 188.65.144.5:6789/0 >> 188.65.144.9:6801/5830 pipe(0x18a6c280 sd=27 :6789 s=2 pgs=3358 cs=1 l=1).reader couldn't read tag, Success
-48> 2013-05-16 05:12:20.919133 7fc86a4a0700 2 -- 188.65.144.5:6789/0 >> 188.65.144.9:6801/5830 pipe(0x18a6c280 sd=27 :6789 s=2 pgs=3358 cs=1 l=1).fault 0: Success
-47> 2013-05-16 05:15:05.893590 7fc8666a8700 10 mon.1@1(peon) e8 ms_handle_reset 0xd4b3420 188.65.144.5:6801/29051
-46> 2013-05-16 05:15:05.893610 7fc8666a8700 10 mon.1@1(peon) e8 ms_handle_reset 0xd4b3b00 188.65.144.10:6800/23197
-45> 2013-05-16 05:15:05.893613 7fc8666a8700 10 mon.1@1(peon) e8 ms_handle_reset 0x13f0e9a0 188.65.144.6:6803/29392
-44> 2013-05-16 05:15:05.893616 7fc8666a8700 10 mon.1@1(peon) e8 ms_handle_reset 0x13f0e840 188.65.144.9:6801/5830
-43> 2013-05-16 05:15:05.893637 7fc8666a8700 1 -- 188.65.144.5:6789/0 <== mon.0 188.65.144.4:6789/0 1801767837 ==== paxos(lease lc 31865061 fc 31852646 pn 0 opn 0) v3 ==== 80+0+0 (1652509130 0 0) 0x15549500 con 0x2137420
-42> 2013-05-16 05:15:05.898655 7fc866ea9700 10 mon.1@1(peon).data_health(12144) service_tick
-41> 2013-05-16 05:15:05.898666 7fc866ea9700 0 mon.1@1(peon).data_health(12144) update_stats avail 71% total 701854104 used 164029844 avail 502172064
-40> 2013-05-16 05:15:05.898669 7fc866ea9700 10 mon.1@1(peon).data_health(12144) share_stats
-39> 2013-05-16 05:15:05.898672 7fc866ea9700 1 -- 188.65.144.5:6789/0 --> mon.0 188.65.144.4:6789/0 -- mon_health( service 1 op tell e 0 r 0 flags ) v1 -- ?+0 0x19195200
-38> 2013-05-16 05:15:05.898682 7fc866ea9700 1 -- 188.65.144.5:6789/0 --> mon.2 188.65.144.6:6789/0 -- mon_health( service 1 op tell e 0 r 0 flags none ) v1 -- ?+0 0x19195000
-37> 2013-05-16 05:15:05.898690 7fc866ea9700 1 -- 188.65.144.5:6789/0 --> mon.3 188.65.144.7:6789/0 -- mon_health( service 1 op tell e 0 r 0 flags ) v1 -- ?+0 0x880aa00
-36> 2013-05-16 05:15:05.898695 7fc866ea9700 1 -- 188.65.144.5:6789/0 --> mon.4 188.65.144.8:6789/0 -- mon_health( service 1 op tell e 0 r 0 flags ) v1 -- ?+0 0x880ac00
-35> 2013-05-16 05:15:05.898725 7fc8666a8700 -1 mon.1@1(peon).paxos(paxos recovering c 31846715..31865061) lease_expire from mon.0 188.65.144.4:6789/0 is 461.369059 seconds in the past; mons are probably laggy (or possibly clocks are too skewed)
-34> 2013-05-16 05:15:05.898750 7fc8666a8700 1 -- 188.65.144.5:6789/0 --> mon.0 188.65.144.4:6789/0 -- paxos(lease_ack lc 31865061 fc 31846715 pn 0 opn 0) v3 -- ?+0 0x191f9000
-33> 2013-05-16 05:15:05.899686 7fc8666a8700 7 mon.1@1(peon).pg v16088653 update_from_paxos loading latest full pgmap v16089048
-32> 2013-05-16 05:15:05.901363 7fc8666a8700 7 mon.1@1(peon).pg v16089048 update_from_paxos applying incremental 16089049
-31> 2013-05-16 05:15:05.901446 7fc8666a8700 10 mon.1@1(peon).pg v16089049 v16089049: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 16042KB/s rd, 6887KB/s wr, 499op/s
-30> 2013-05-16 05:15:05.901471 7fc8666a8700 7 mon.1@1(peon).pg v16089049 update_from_paxos applying incremental 16089050
-29> 2013-05-16 05:15:05.901498 7fc8666a8700 10 mon.1@1(peon).pg v16089050 v16089050: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 7029KB/s rd, 5736KB/s wr, 298op/s
-28> 2013-05-16 05:15:05.901524 7fc8666a8700 7 mon.1@1(peon).pg v16089050 update_from_paxos applying incremental 16089051
-27> 2013-05-16 05:15:05.901656 7fc8666a8700 10 mon.1@1(peon).pg v16089051 v16089051: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 3050KB/s rd, 19242KB/s wr, 228op/s
-26> 2013-05-16 05:15:05.901681 7fc8666a8700 7 mon.1@1(peon).pg v16089051 update_from_paxos applying incremental 16089052
-25> 2013-05-16 05:15:05.901754 7fc8666a8700 10 mon.1@1(peon).pg v16089052 v16089052: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 4535KB/s rd, 25051KB/s wr, 273op/s
-24> 2013-05-16 05:15:05.901785 7fc8666a8700 7 mon.1@1(peon).pg v16089052 update_from_paxos applying incremental 16089053
-23> 2013-05-16 05:15:05.902130 7fc8666a8700 10 mon.1@1(peon).pg v16089053 v16089053: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 4294KB/s rd, 6114KB/s wr, 174op/s
-22> 2013-05-16 05:15:05.902168 7fc8666a8700 7 mon.1@1(peon).pg v16089053 update_from_paxos applying incremental 16089054
-21> 2013-05-16 05:15:05.902361 7fc8666a8700 10 mon.1@1(peon).pg v16089054 v16089054: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 5746KB/s rd, 6644KB/s wr, 332op/s
-20> 2013-05-16 05:15:05.902395 7fc8666a8700 7 mon.1@1(peon).pg v16089054 update_from_paxos applying incremental 16089055
-19> 2013-05-16 05:15:05.902426 7fc8666a8700 10 mon.1@1(peon).pg v16089055 v16089055: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 6147KB/s rd, 6530KB/s wr, 275op/s
-18> 2013-05-16 05:15:05.902472 7fc8666a8700 7 mon.1@1(peon).pg v16089055 update_from_paxos applying incremental 16089056
-17> 2013-05-16 05:15:05.902663 7fc8666a8700 10 mon.1@1(peon).pg v16089056 v16089056: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 12650KB/s rd, 7490KB/s wr, 288op/s
-16> 2013-05-16 05:15:05.902696 7fc8666a8700 7 mon.1@1(peon).pg v16089056 update_from_paxos applying incremental 16089057
-15> 2013-05-16 05:15:05.902729 7fc8666a8700 10 mon.1@1(peon).pg v16089057 v16089057: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 13571KB/s rd, 9114KB/s wr, 395op/s
-14> 2013-05-16 05:15:05.902852 7fc8666a8700 7 mon.1@1(peon).pg v16089057 update_from_paxos applying incremental 16089058
-13> 2013-05-16 05:15:05.902895 7fc8666a8700 10 mon.1@1(peon).pg v16089058 v16089058: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 2669KB/s rd, 3035KB/s wr, 128op/s
-12> 2013-05-16 05:15:05.902926 7fc8666a8700 7 mon.1@1(peon).pg v16089058 update_from_paxos applying incremental 16089059
-11> 2013-05-16 05:15:05.903063 7fc8666a8700 10 mon.1@1(peon).pg v16089059 v16089059: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 15454KB/s rd, 5864KB/s wr, 483op/s
-10> 2013-05-16 05:15:05.903089 7fc8666a8700 7 mon.1@1(peon).pg v16089059 update_from_paxos applying incremental 16089060
-9> 2013-05-16 05:15:05.903169 7fc8666a8700 10 mon.1@1(peon).pg v16089060 v16089060: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 14420KB/s rd, 3386KB/s wr, 512op/s
-8> 2013-05-16 05:15:05.903188 7fc8666a8700 7 mon.1@1(peon).pg v16089060 update_from_paxos applying incremental 16089061
-7> 2013-05-16 05:15:05.903210 7fc8666a8700 10 mon.1@1(peon).pg v16089061 v16089061: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 5460KB/s rd, 3489KB/s wr, 175op/s
-6> 2013-05-16 05:15:05.903234 7fc8666a8700 7 mon.1@1(peon).pg v16089061 update_from_paxos applying incremental 16089062
-5> 2013-05-16 05:15:05.903356 7fc8666a8700 10 mon.1@1(peon).pg v16089062 v16089062: 768 pgs: 768 active+clean; 1533 GB data, 3065 GB used, 3107 GB / 6359 GB avail; 23364KB/s rd, 33421KB/s wr, 351op/s
-4> 2013-05-16 05:15:05.903375 7fc8666a8700 10 mon.1@1(peon).pg v16089062 map_pg_creates to 0 pgs
-3> 2013-05-16 05:15:05.903377 7fc8666a8700 10 mon.1@1(peon).pg v16089062 send_pg_creates to 0 pgs
-2> 2013-05-16 05:15:05.903378 7fc8666a8700 10 mon.1@1(peon).pg v16089062 update_logger
-1> 2013-05-16 05:15:05.903516 7fc8666a8700 10 mon.1@1(peon).pg v16089062 update_logger
0> 2013-05-16 05:15:05.904191 7fc8666a8700 -1 mon/MDSMonitor.cc: In function 'virtual void MDSMonitor::update_from_paxos()' thread 7fc8666a8700 time 2013-05-16 05:15:05.903535
mon/MDSMonitor.cc: 88: FAILED assert(version >= mdsmap.epoch)

ceph version 0.61.2 (fea782543a844bb277ae94d3391788b76c5bee60)
1: (MDSMonitor::update_from_paxos()+0x785) [0x525a45]
2: (PaxosService::_active()+0x21a) [0x4e333a]
3: (Context::complete(int)+0xa) [0x4b748a]
4: (finish_contexts(CephContext*, std::list<Context*, std::allocator<Context*> >&, int)+0x8d) [0x4ba32d]
5: (Paxos::handle_lease(MMonPaxos*)+0x410) [0x4d2550]
6: (Paxos::dispatch(PaxosServiceMessage*)+0x22b) [0x4dc8bb]
7: (Monitor::_ms_dispatch(Message*)+0x115b) [0x4b5ddb]
8: (Monitor::ms_dispatch(Message*)+0x32) [0x4cf342]
9: (DispatchQueue::entry()+0x3f1) [0x6a6f81]
10: (DispatchQueue::DispatchThread::entry()+0xd) [0x6a277d]
11: (()+0x68ca) [0x7fc86f00d8ca]
12: (clone()+0x6d) [0x7fc86dd04b6d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- logging levels ---
0/ 5 none
0/ 1 lockdep
0/ 1 context
1/ 1 crush
1/ 5 mds
1/ 5 mds_balancer
1/ 5 mds_locker
1/ 5 mds_log
1/ 5 mds_log_expire
1/ 5 mds_migrator
0/ 1 buffer
0/ 1 timer
0/ 1 filer
0/ 1 striper
0/ 1 objecter
0/ 5 rados
0/ 5 rbd
0/ 5 journaler
0/ 5 objectcacher
0/ 5 client
0/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
0/ 5 ms
10/10 mon
0/10 monc
0/ 5 paxos
0/ 5 tp
1/ 5 auth
1/ 5 crypto
1/ 1 finisher
1/ 5 heartbeatmap
1/ 5 perfcounter
1/ 5 rgw
1/ 5 hadoop
1/ 5 javaclient
1/ 5 asok
1/ 1 throttle
-2/-2 (syslog threshold)
-1/-1 (stderr threshold)
max_recent 10000
max_new 1000
log_file /var/log/ceph/ceph-mon.1.log
--- end dump of recent events ---
2013-05-16 05:15:05.963954 7fc8666a8700 -1 *** Caught signal (Aborted) **
in thread 7fc8666a8700

ceph version 0.61.2 (fea782543a844bb277ae94d3391788b76c5bee60)
1: /usr/bin/ceph-mon() [0x5957c9]
2: (()+0xeff0) [0x7fc86f015ff0]
3: (gsignal()+0x35) [0x7fc86dc671b5]
4: (abort()+0x180) [0x7fc86dc69fc0]
5: (__gnu_cxx::__verbose_terminate_handler()+0x115) [0x7fc86e4fbdc5]
6: (()+0xcb166) [0x7fc86e4fa166]
7: (()+0xcb193) [0x7fc86e4fa193]
8: (()+0xcb28e) [0x7fc86e4fa28e]
9: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x7c9) [0x5bb2c9]
10: (MDSMonitor::update_from_paxos()+0x785) [0x525a45]
11: (PaxosService::_active()+0x21a) [0x4e333a]
12: (Context::complete(int)+0xa) [0x4b748a]
13: (finish_contexts(CephContext*, std::list<Context*, std::allocator<Context*> >&, int)+0x8d) [0x4ba32d]
14: (Paxos::handle_lease(MMonPaxos*)+0x410) [0x4d2550]
15: (Paxos::dispatch(PaxosServiceMessage*)+0x22b) [0x4dc8bb]
16: (Monitor::_ms_dispatch(Message*)+0x115b) [0x4b5ddb]
17: (Monitor::ms_dispatch(Message*)+0x32) [0x4cf342]
18: (DispatchQueue::entry()+0x3f1) [0x6a6f81]
19: (DispatchQueue::DispatchThread::entry()+0xd) [0x6a277d]
20: (()+0x68ca) [0x7fc86f00d8ca]
21: (clone()+0x6d) [0x7fc86dd04b6d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
0> 2013-05-16 05:15:05.963954 7fc8666a8700 -1 *** Caught signal (Aborted) **
in thread 7fc8666a8700

ceph version 0.61.2 (fea782543a844bb277ae94d3391788b76c5bee60)
1: /usr/bin/ceph-mon() [0x5957c9]
2: (()+0xeff0) [0x7fc86f015ff0]
3: (gsignal()+0x35) [0x7fc86dc671b5]
4: (abort()+0x180) [0x7fc86dc69fc0]
5: (__gnu_cxx::__verbose_terminate_handler()+0x115) [0x7fc86e4fbdc5]
6: (()+0xcb166) [0x7fc86e4fa166]
7: (()+0xcb193) [0x7fc86e4fa193]
8: (()+0xcb28e) [0x7fc86e4fa28e]
9: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x7c9) [0x5bb2c9]
10: (MDSMonitor::update_from_paxos()+0x785) [0x525a45]
11: (PaxosService::_active()+0x21a) [0x4e333a]
12: (Context::complete(int)+0xa) [0x4b748a]
13: (finish_contexts(CephContext*, std::list<Context*, std::allocator<Context*> >&, int)+0x8d) [0x4ba32d]
14: (Paxos::handle_lease(MMonPaxos*)+0x410) [0x4d2550]
15: (Paxos::dispatch(PaxosServiceMessage*)+0x22b) [0x4dc8bb]
16: (Monitor::_ms_dispatch(Message*)+0x115b) [0x4b5ddb]
17: (Monitor::ms_dispatch(Message*)+0x32) [0x4cf342]
18: (DispatchQueue::entry()+0x3f1) [0x6a6f81]
19: (DispatchQueue::DispatchThread::entry()+0xd) [0x6a277d]
20: (()+0x68ca) [0x7fc86f00d8ca]
21: (clone()+0x6d) [0x7fc86dd04b6d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- logging levels ---
0/ 5 none
0/ 1 lockdep
0/ 1 context
1/ 1 crush
1/ 5 mds
1/ 5 mds_balancer
1/ 5 mds_locker
1/ 5 mds_log
1/ 5 mds_log_expire
1/ 5 mds_migrator
0/ 1 buffer
0/ 1 timer
0/ 1 filer
0/ 1 striper
0/ 1 objecter
0/ 5 rados
0/ 5 rbd
0/ 5 journaler
0/ 5 objectcacher
0/ 5 client
0/ 5 osd
0/ 5 optracker
0/ 5 objclass
1/ 3 filestore
1/ 3 journal
0/ 5 ms
10/10 mon
0/10 monc
0/ 5 paxos
0/ 5 tp
1/ 5 auth
1/ 5 crypto
1/ 1 finisher
1/ 5 heartbeatmap
1/ 5 perfcounter
1/ 5 rgw
1/ 5 hadoop
1/ 5 javaclient
1/ 5 asok
1/ 1 throttle
-2/-2 (syslog threshold)
-1/-1 (stderr threshold)
max_recent 10000
max_new 1000
log_file /var/log/ceph/ceph-mon.1.log
--- end dump of recent events ---



2013-05-16 11:43:57.844533 7f50d93e2780 0 ceph version 0.61.2 (fea782543a844bb277ae94d3391788b76c5bee60), process ceph-mon, pid 6139
2013-05-16 11:43:58.007800 7f50d93e2780 10 needs_conversion
2013-05-16 11:43:58.668333 7f50d93e2780 10 obtain_monmap
2013-05-16 11:43:58.875603 7f50d93e2780 -1 obtain_monmap unable to find a monmap
2013-05-16 11:43:58.875655 7f50d93e2780 0 mon.1 does not exist in monmap, will attempt to join an existing cluster
2013-05-16 11:43:58.888155 7f50d93e2780 1 mon.1@-1(probing) e0 preinit fsid 00000000-0000-0000-0000-000000000000
2013-05-16 11:43:58.888437 7f50d93e2780 10 mon.1@-1(probing) e0 check_fsid cluster_uuid contains '2ff06d61-7b8e-4b10-b39d-138cfcc1ee43'
2013-05-16 11:43:58.888443 7f50d93e2780 -1 mon.1@-1(probing) e0 error: cluster_uuid file exists with value '2ff06d61-7b8e-4b10-b39d-138cfcc1ee43', != our uuid 00000000-0000-0000-0000-000000000000
2013-05-16 11:44:57.948608 7f1325ccf780 0 ceph version 0.61.2 (fea782543a844bb277ae94d3391788b76c5bee60), process ceph-mon, pid 7026
2013-05-16 11:44:57.950598 7f1325ccf780 10 needs_conversion
2013-05-16 11:44:58.153887 7f1325ccf780 10 obtain_monmap
2013-05-16 11:44:58.177198 7f1325ccf780 -1 obtain_monmap unable to find a monmap
2013-05-16 11:44:58.177251 7f1325ccf780 0 mon.1 does not exist in monmap, will attempt to join an existing cluster
2013-05-16 11:44:58.177956 7f1325ccf780 1 mon.1@-1(probing) e0 preinit fsid 00000000-0000-0000-0000-000000000000
2013-05-16 11:44:58.177993 7f1325ccf780 10 mon.1@-1(probing) e0 check_fsid cluster_uuid contains '2ff06d61-7b8e-4b10-b39d-138cfcc1ee43'
2013-05-16 11:44:58.177996 7f1325ccf780 -1 mon.1@-1(probing) e0 error: cluster_uuid file exists with value '2ff06d61-7b8e-4b10-b39d-138cfcc1ee43', != our uuid 00000000-0000-0000-0000-000000000000
2013-05-16 11:51:33.927738 7feea53ba780 0 ceph version 0.61.2 (fea782543a844bb277ae94d3391788b76c5bee60), process ceph-mon, pid 11984
2013-05-16 11:51:33.930160 7feea53ba780 10 needs_conversion
2013-05-16 11:51:34.120060 7feea53ba780 10 obtain_monmap
2013-05-16 11:51:34.145498 7feea53ba780 -1 obtain_monmap unable to find a monmap
2013-05-16 11:51:34.145547 7feea53ba780 0 mon.1 does not exist in monmap, will attempt to join an existing cluster
2013-05-16 11:51:34.146394 7feea53ba780 1 mon.1@-1(probing) e0 preinit fsid 00000000-0000-0000-0000-000000000000
2013-05-16 11:51:34.146899 7feea53ba780 10 mon.1@-1(probing) e0 check_fsid cluster_uuid contains '2ff06d61-7b8e-4b10-b39d-138cfcc1ee43'
2013-05-16 11:51:34.146905 7feea53ba780 -1 mon.1@-1(probing) e0 error: cluster_uuid file exists with value '2ff06d61-7b8e-4b10-b39d-138cfcc1ee43', != our uuid 00000000-0000-0000-0000-000000000000
2013-05-16 12:00:56.058011 7fa7a07b4780 0 ceph version 0.61.2 (fea782543a844bb277ae94d3391788b76c5bee60), process ceph-mon, pid 27656
2013-05-16 12:00:56.060109 7fa7a07b4780 10 needs_conversion
2013-05-16 12:00:56.471970 7fa7a07b4780 10 obtain_monmap
2013-05-16 12:00:56.495896 7fa7a07b4780 -1 obtain_monmap unable to find a monmap
2013-05-16 12:00:56.495957 7fa7a07b4780 0 mon.1 does not exist in monmap, will attempt to join an existing cluster
2013-05-16 12:00:56.496606 7fa7a07b4780 1 mon.1@-1(probing) e0 preinit fsid 00000000-0000-0000-0000-000000000000
2013-05-16 12:00:56.496644 7fa7a07b4780 10 mon.1@-1(probing) e0 check_fsid cluster_uuid contains '2ff06d61-7b8e-4b10-b39d-138cfcc1ee43'
2013-05-16 12:00:56.496646 7fa7a07b4780 -1 mon.1@-1(probing) e0 error: cluster_uuid file exists with value '2ff06d61-7b8e-4b10-b39d-138cfcc1ee43', != our uuid 00000000-0000-0000-0000-000000000000
(1-1/2)