Project

General

Profile

Subtask #2643

Feature #2611: mon: Single-Paxos

mon: Single-Paxos: mds: Strange message behavior on peon

Added by Joao Eduardo Luis almost 12 years ago. Updated about 11 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Joao Eduardo Luis
Category:
Monitor
Target version:
% Done:

0%

Source:
Development
Tags:
Backport:
Reviewed:
Affected Versions:
Pull request ID:

Description

Just for future reference.

When checking how things were going with the monitors, we noticed that the following snippet was being repeated over and over, non-stop.


2012-06-21 16:17:25.584119 7fffee7fc700  1 -- 127.0.0.1:6791/0 <== mds.? 127.0.0.1:6800/25236 322130 ==== auth(proto 2 2 bytes epoch 0) v1 ==== 32+0+0 (2260890001 0 0) 0x7fffc402bbb0 con 0x7fffdc0015b0
2012-06-21 16:17:25.584126 7fffee7fc700 20 mon.c@2(peon) e1 have connection
2012-06-21 16:17:25.584127 7fffee7fc700 20 mon.c@2(peon) e1 ms_dispatch existing session MonSession: mds.? 127.0.0.1:6800/25236 is open for mds.? 127.0.0.1:6800/25236
2012-06-21 16:17:25.584131 7fffee7fc700 20 mon.c@2(peon) e1  caps
2012-06-21 16:17:25.584132 7fffee7fc700 10 mon.c@2(peon).paxosservice(auth) dispatch auth(proto 2 2 bytes epoch 0) v1 from mds.? 127.0.0.1:6800/25236
2012-06-21 16:17:25.584154 7fffee7fc700 10 mon.c@2(peon).auth v15 update_from_paxos
2012-06-21 16:17:25.584169 7fffee7fc700 10 mon.c@2(peon).auth v15 preprocess_query auth(proto 2 2 bytes epoch 0) v1 from mds.? 127.0.0.1:6800/25236
2012-06-21 16:17:25.584180 7fffee7fc700 10 mon.c@2(peon).auth v15 prep_auth() blob_size=2
2012-06-21 16:17:25.584189 7fffee7fc700 10 cephx server mds.a: handle_request getting rotating secret for mds.a
2012-06-21 16:17:25.584208 7fffee7fc700  1 -- 127.0.0.1:6791/0 --> 127.0.0.1:6800/25236 -- auth_reply(proto 2 0 Success) v1 -- ?+0 0x7fffd53c5a80 con 0x7fffdc0015b0
2012-06-21 16:17:25.584222 7fffee7fc700  1 -- 127.0.0.1:6791/0 <== mds.? 127.0.0.1:6801/25414 298416 ==== auth(proto 2 2 bytes epoch 0) v1 ==== 32+0+0 (2260890001 0 0) 0x7fffcc00e8e0 con 0x7fffdc001090
2012-06-21 16:17:25.584229 7fffee7fc700 20 mon.c@2(peon) e1 have^C connection
2012-06-21 16:17:25.584230 7fffee7fc700 20 mon.c@2(peon) e1 ms_dispatch existing session MonSession: mds.? 127.0.0.1:6801/25414 is open for mds.? 127.0.0.1:6801/25414
2012-06-21 16:17:25.584234 7fffee7fc700 20 mon.c@2(peon) e1  caps
2012-06-21 16:17:25.584235 7fffee7fc700 10 mon.c@2(peon).paxosservice(auth) dispatch auth(proto 2 2 bytes epoch 0) v1 from mds.? 127.0.0.1:6801/25414
2012-06-21 16:17:25.584260 7fffee7fc700 10 mon.c@2(peon).auth v15 update_from_paxos
2012-06-21 16:17:25.584275 7fffee7fc700 10 mon.c@2(peon).auth v15 preprocess_query auth(proto 2 2 bytes epoch 0) v1 from mds.? 127.0.0.1:6801/25414
2012-06-21 16:17:25.584285 7fffee7fc700 10 mon.c@2(peon).auth v15 prep_auth() blob_size=2
2012-06-21 16:17:25.584294 7fffee7fc700 10 cephx server mds.b: handle_request getting rotating secret for mds.b
2012-06-21 16:17:25.584313 7fffee7fc700  1 -- 127.0.0.1:6791/0 --> 127.0.0.1:6801/25414 -- auth_reply(proto 2 0 Success) v1 -- ?+0 0x7fffd53c46c0 con 0x7fffdc001090
2012-06-21 16:17:25.584327 7fffee7fc700  1 -- 127.0.0.1:6791/0 <== mds.? 127.0.0.1:6802/25594 309137 ==== auth(proto 2 2 bytes epoch 0) v1 ==== 32+0+0 (2260890001 0 0) 0x7fffb8023dc0 con 0x7fffdc001ad0
2012-06-21 16:17:25.584334 7fffee7fc700 20 mon.c@2(peon) e1 have connection
2012-06-21 16:17:25.584335 7fffee7fc700 20 mon.c@2(peon) e1 ms_dispatch existing session MonSession: mds.? 127.0.0.1:6802/25594 is open for mds.? 127.0.0.1:6802/25594
2012-06-21 16:17:25.584339 7fffee7fc700 20 mon.c@2(peon) e1  caps
2012-06-21 16:17:25.584340 7fffee7fc700 10 mon.c@2(peon).paxosservice(auth) dispatch auth(proto 2 2 bytes epoch 0) v1 from mds.? 127.0.0.1:6802/25594
2012-06-21 16:17:25.584363 7fffee7fc700 10 mon.c@2(peon).auth v15 update_from_paxos
2012-06-21 16:17:25.584378 7fffee7fc700 10 mon.c@2(peon).auth v15 preprocess_query auth(proto 2 2 bytes epoch 0) v1 from mds.? 127.0.0.1:6802/25594
2012-06-21 16:17:25.584388 7fffee7fc700 10 mon.c@2(peon).auth v15 prep_auth() blob_size=2
2012-06-21 16:17:25.584397 7fffee7fc700 10 cephx server mds.c: handle_request getting rotating secret for mds.c
2012-06-21 16:17:25.584415 7fffee7fc700  1 -- 127.0.0.1:6791/0 --> 127.0.0.1:6802/25594 -- auth_reply(proto 2 0 Success) v1 -- ?+0 0x7fffd53c7010 con 0x7fffdc001ad0

We have no idea what is causing it.

History

#1 Updated by Joao Eduardo Luis almost 12 years ago

This is what can be seen on the Leader:


2012-06-21 16:25:16.770718 7fffeeffd700  1 -- 127.0.0.1:6789/0 <== mds.? 127.0.0.1:6802/25594 5 ==== mdsbeacon(4409/c up:boot seq 2241 v0) v2 ==== 240+0+0 (1013814919 0 0) 0x7fffc40049d0 con 0x7fffe8001da0
2012-06-21 16:25:16.770742 7fffeeffd700 10 mon.a@0(leader).paxosservice(mdsmap) dispatch mdsbeacon(4409/c up:boot seq 2241 v0) v2 from mds.? 127.0.0.1:6802/25594
2012-06-21 16:25:16.770815 7fffeeffd700 10 mon.a@0(leader).mds e1 preprocess_query mdsbeacon(4409/c up:boot seq 2241 v0) v2 from mds.? 127.0.0.1:6802/25594
2012-06-21 16:25:16.770834 7fffeeffd700  0 mon.a@0(leader).mds e1 preprocess_beason got MMDSBeacon from entity with insufficient privileges
2012-06-21 16:25:16.770841 7fffeeffd700 10 -- 127.0.0.1:6789/0 dispatch_throttle_release 240 to dispatch throttler 240/104857600
2012-06-21 16:25:18.154593 7fffee7fc700 10 mon.a@0(leader).pg v3 check_down_pgs
2012-06-21 16:25:18.154608 7fffee7fc700 10 mon.a@0(leader).pg v3 v3: 24 pgs: 24 creating; 0 bytes data, 0 KB used, 0 KB / 0 KB avail
2012-06-21 16:25:18.154645 7fffee7fc700 10 mon.a@0(leader).mds e1 e1: 0/0/1 up
2012-06-21 16:25:18.154671 7fffee7fc700 10 mon.a@0(leader).osd e2 e2: 1 osds: 0 up, 0 in
2012-06-21 16:25:18.154676 7fffee7fc700  5 mon.a@0(leader).osd e2 can_mark_down current in_ratio 0 < min 0.3, will not mark osds out
2012-06-21 16:25:18.154688 7fffee7fc700 10 mon.a@0(leader).osd e2 tick NOOUT flag set, not checking down osds
2012-06-21 16:25:18.154767 7fffee7fc700 10 mon.a@0(leader).log v29 log
2012-06-21 16:25:18.154807 7fffee7fc700 10 mon.a@0(leader).auth v15 update_from_paxos
2012-06-21 16:25:18.154859 7fffee7fc700 10 mon.a@0(leader).auth v15 auth
2012-06-21 16:25:18.154897 7fffee7fc700 10 cephx keyserver: _check_rotating_secrets
2012-06-21 16:25:18.512384 7fffedefa700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).reader wants 42 from dispatch throttler 0/104857600
2012-06-21 16:25:18.512427 7fffedefa700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).aborted = 0
2012-06-21 16:25:18.512450 7fffedefa700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).reader got message 6 0x7fffc4004f80 mon_subscribe({mdsmap=0+,monmap=2+}) v2
2012-06-21 16:25:18.512540 7ffff43f2700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:18.512569 7ffff43f2700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).write_ack 6
2012-06-21 16:25:18.512598 7ffff43f2700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:18.512615 7fffeeffd700  1 -- 127.0.0.1:6789/0 <== mds.? 127.0.0.1:6802/25594 6 ==== mon_subscribe({mdsmap=0+,monmap=2+}) v2 ==== 42+0+0 (1735446458 0 0) 0x7fffc4004f80 con 0x7fffe8001da0
2012-06-21 16:25:18.512647 7fffeeffd700 10 mon.a@0(leader) e1 handle_subscribe mon_subscribe({mdsmap=0+,monmap=2+}) v2
2012-06-21 16:25:18.512656 7fffeeffd700 10 mon.a@0(leader) e1 check_sub monmap next 2 have 1
2012-06-21 16:25:18.512661 7fffeeffd700  1 -- 127.0.0.1:6789/0 --> mds.? 127.0.0.1:6802/25594 -- mon_subscribe_ack(300s) v1 -- ?+0 0x7fffd40dd4a0
2012-06-21 16:25:18.512681 7fffeeffd700 10 -- 127.0.0.1:6789/0 dispatch_throttle_release 42 to dispatch throttler 42/104857600
2012-06-21 16:25:18.512718 7ffff43f2700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:18.512814 7ffff43f2700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:18.561005 7ffff42f1700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).reader wants 42 from dispatch throttler 0/104857600
2012-06-21 16:25:18.561053 7ffff42f1700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).aborted = 0
2012-06-21 16:25:18.561083 7ffff42f1700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).reader got message 6 0x7fffd0002ce0 mon_subscribe({mdsmap=0+,monmap=2+}) v2
2012-06-21 16:25:18.561206 7fffedcf9700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:18.561247 7fffedcf9700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).write_ack 6
2012-06-21 16:25:18.561201 7fffeeffd700  1 -- 127.0.0.1:6789/0 <== mds.? 127.0.0.1:6800/25236 6 ==== mon_subscribe({mdsmap=0+,monmap=2+}) v2 ==== 42+0+0 (1735446458 0 0) 0x7fffd0002ce0 con 0x7fffe8002050
2012-06-21 16:25:18.561264 7fffeeffd700 10 mon.a@0(leader) e1 handle_subscribe mon_subscribe({mdsmap=0+,monmap=2+}) v2
2012-06-21 16:25:18.561270 7fffedcf9700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:18.561276 7fffeeffd700 10 mon.a@0(leader) e1 check_sub monmap next 2 have 1
2012-06-21 16:25:18.561282 7fffeeffd700  1 -- 127.0.0.1:6789/0 --> mds.? 127.0.0.1:6800/25236 -- mon_subscribe_ack(300s) v1 -- ?+0 0x7fffd40dda80
2012-06-21 16:25:18.561307 7fffeeffd700 10 -- 127.0.0.1:6789/0 dispatch_throttle_release 42 to dispatch throttler 42/104857600
2012-06-21 16:25:18.561321 7fffedcf9700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:18.561384 7fffedcf9700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:18.826526 7ffff42f1700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).reader wants 240 from dispatch throttler 0/104857600
2012-06-21 16:25:18.826564 7ffff42f1700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).aborted = 0
2012-06-21 16:25:18.826584 7ffff42f1700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).reader got message 7 0x7fffd0003b80 mdsbeacon(4403/a up:boot seq 2243 v0) v2
2012-06-21 16:25:18.826618 7fffeeffd700  1 -- 127.0.0.1:6789/0 <== mds.? 127.0.0.1:6800/25236 7 ==== mdsbeacon(4403/a up:boot seq 2243 v0) v2 ==== 240+0+0 (1932240504 0 0) 0x7fffd0003b80 con 0x7fffe8002050
2012-06-21 16:25:18.826629 7fffedcf9700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:18.826657 7fffedcf9700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).write_ack 7
2012-06-21 16:25:18.826656 7fffeeffd700 10 mon.a@0(leader).paxosservice(mdsmap) dispatch mdsbeacon(4403/a up:boot seq 2243 v0) v2 from mds.? 127.0.0.1:6800/25236
2012-06-21 16:25:18.826683 7fffedcf9700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:18.826754 7fffeeffd700 10 mon.a@0(leader).mds e1 preprocess_query mdsbeacon(4403/a up:boot seq 2243 v0) v2 from mds.? 127.0.0.1:6800/25236
2012-06-21 16:25:18.826776 7fffeeffd700  0 mon.a@0(leader).mds e1 preprocess_beason got MMDSBeacon from entity with insufficient privileges
2012-06-21 16:25:18.826785 7fffeeffd700 10 -- 127.0.0.1:6789/0 dispatch_throttle_release 240 to dispatch throttler 240/104857600
2012-06-21 16:25:19.184488 7fffee7fc700  7 mon.a@0(leader).paxos(paxos active c 1..51) extend_lease now+5 (2012-06-21 16:25:24.184486)
2012-06-21 16:25:19.184518 7fffee7fc700  1 -- 127.0.0.1:6789/0 --> mon.2 127.0.0.1:6791/0 -- paxos(lease lc 51 fc 1 pn 0 opn 0) v2 -- ?+0 0x7fffc0030110
2012-06-21 16:25:19.184637 7ffff44f3700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).writer: state = 2 policy.server=0
2012-06-21 16:25:19.184725 7ffff44f3700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).writer: state = 2 policy.server=0
2012-06-21 16:25:19.185186 7ffff41f0700 10 reader got ack seq 1622 >= 1622 on 0x7fffc0030110 paxos(lease lc 51 fc 1 pn 0 opn 0) v2
2012-06-21 16:25:19.185219 7ffff41f0700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).reader wants 80 from dispatch throttler 0/104857600
2012-06-21 16:25:19.185247 7ffff41f0700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).aborted = 0
2012-06-21 16:25:19.185264 7ffff41f0700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).reader got message 1589 0x7fffcc009610 paxos(lease_ack lc 51 fc 1 pn 0 opn 0) v2
2012-06-21 16:25:19.185294 7fffeeffd700  1 -- 127.0.0.1:6789/0 <== mon.2 127.0.0.1:6791/0 1589 ==== paxos(lease_ack lc 51 fc 1 pn 0 opn 0) v2 ==== 80+0+0 (1097150785 0 0) 0x7fffcc009610 con 0x934a20
2012-06-21 16:25:19.185318 7fffeeffd700 10 mon.a@0(leader).paxos(paxos active c 1..51) handle_lease_ack from mon.2 -- got everyone
2012-06-21 16:25:19.185303 7ffff44f3700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).writer: state = 2 policy.server=0
2012-06-21 16:25:19.185326 7ffff44f3700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).write_ack 1589
2012-06-21 16:25:19.185348 7ffff44f3700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).writer: state = 2 policy.server=0
2012-06-21 16:25:19.185409 7fffeeffd700 10 mon.a@0(leader).auth v15 update_from_paxos
2012-06-21 16:25:19.185440 7fffeeffd700 10 -- 127.0.0.1:6789/0 dispatch_throttle_release 80 to dispatch throttler 80/104857600
2012-06-21 16:25:20.291757 7fffedffb700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6801/25414 pipe(0x7fffe8001750 sd=29 pgs=209 cs=1 l=1).reader wants 240 from dispatch throttler 0/104857600
2012-06-21 16:25:20.291800 7fffedffb700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6801/25414 pipe(0x7fffe8001750 sd=29 pgs=209 cs=1 l=1).aborted = 0
2012-06-21 16:25:20.291825 7fffedffb700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6801/25414 pipe(0x7fffe8001750 sd=29 pgs=209 cs=1 l=1).reader got message 8 0x7fffdc001e80 mdsbeacon(4311/b up:boot seq 2243 v0) v2
2012-06-21 16:25:20.291857 7fffeeffd700  1 -- 127.0.0.1:6789/0 <== mds.? 127.0.0.1:6801/25414 8 ==== mdsbeacon(4311/b up:boot seq 2243 v0) v2 ==== 240+0+0 (3039885157 0 0) 0x7fffdc001e80 con 0x7fffe80019c0
2012-06-21 16:25:20.291882 7fffeeffd700 10 mon.a@0(leader).paxosservice(mdsmap) dispatch mdsbeacon(4311/b up:boot seq 2243 v0) v2 from mds.? 127.0.0.1:6801/25414
2012-06-21 16:25:20.291901 7fffedbf8700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6801/25414 pipe(0x7fffe8001750 sd=29 pgs=209 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:20.291922 7fffedbf8700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6801/25414 pipe(0x7fffe8001750 sd=29 pgs=209 cs=1 l=1).write_ack 8
2012-06-21 16:25:20.291945 7fffedbf8700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6801/25414 pipe(0x7fffe8001750 sd=29 pgs=209 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:20.291976 7fffeeffd700 10 mon.a@0(leader).mds e1 preprocess_query mdsbeacon(4311/b up:boot seq 2243 v0) v2 from mds.? 127.0.0.1:6801/25414
2012-06-21 16:25:20.292000 7fffeeffd700  0 mon.a@0(leader).mds e1 preprocess_beason got MMDSBeacon from entity with insufficient privileges
2012-06-21 16:25:20.292008 7fffeeffd700 10 -- 127.0.0.1:6789/0 dispatch_throttle_release 240 to dispatch throttler 240/104857600
2012-06-21 16:25:20.770733 7fffedefa700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).reader wants 240 from dispatch throttler 0/104857600
2012-06-21 16:25:20.770777 7fffedefa700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).aborted = 0
2012-06-21 16:25:20.770802 7fffedefa700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).reader got message 7 0x7fffc4005410 mdsbeacon(4409/c up:boot seq 2242 v0) v2
2012-06-21 16:25:20.770876 7ffff43f2700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:20.770914 7ffff43f2700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).write_ack 7
2012-06-21 16:25:20.770930 7fffeeffd700  1 -- 127.0.0.1:6789/0 <== mds.? 127.0.0.1:6802/25594 7 ==== mdsbeacon(4409/c up:boot seq 2242 v0) v2 ==== 240+0+0 (1591574214 0 0) 0x7fffc4005410 con 0x7fffe8001da0
2012-06-21 16:25:20.770946 7ffff43f2700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6802/25594 pipe(0x7fffe8001b30 sd=28 pgs=201 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:20.770952 7fffeeffd700 10 mon.a@0(leader).paxosservice(mdsmap) dispatch mdsbeacon(4409/c up:boot seq 2242 v0) v2 from mds.? 127.0.0.1:6802/25594
2012-06-21 16:25:20.771021 7fffeeffd700 10 mon.a@0(leader).mds e1 preprocess_query mdsbeacon(4409/c up:boot seq 2242 v0) v2 from mds.? 127.0.0.1:6802/25594
2012-06-21 16:25:20.771038 7fffeeffd700  0 mon.a@0(leader).mds e1 preprocess_beason got MMDSBeacon from entity with insufficient privileges

2012-06-21 16:25:20.771044 7fffeeffd700 10 -- 127.0.0.1:6789/0 dispatch_throttle_release 240 to dispatch throttler 240/104857600
2012-06-21 16:25:22.184639 7fffee7fc700  7 mon.a@0(leader).paxos(paxos active c 1..51) extend_lease now+5 (2012-06-21 16:25:27.184638)
2012-06-21 16:25:22.184669 7fffee7fc700  1 -- 127.0.0.1:6789/0 --> mon.2 127.0.0.1:6791/0 -- paxos(lease lc 51 fc 1 pn 0 opn 0) v2 -- ?+0 0x7fffc0161460
2012-06-21 16:25:22.184787 7ffff44f3700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).writer: state = 2 policy.server=0
2012-06-21 16:25:22.184871 7ffff44f3700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).writer: state = 2 policy.server=0
2012-06-21 16:25:22.185208 7ffff41f0700 10 reader got ack seq 1623 >= 1623 on 0x7fffc0161460 paxos(lease lc 51 fc 1 pn 0 opn 0) v2
2012-06-21 16:25:22.185241 7ffff41f0700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).reader wants 80 from dispatch throttler 0/104857600
2012-06-21 16:25:22.185269 7ffff41f0700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).aborted = 0
2012-06-21 16:25:22.185286 7ffff41f0700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).reader got message 1590 0x7fffcc0533a0 paxos(lease_ack lc 51 fc 1 pn 0 opn 0) v2
2012-06-21 16:25:22.185378 7ffff44f3700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).writer: state = 2 policy.server=0
2012-06-21 16:25:22.185419 7ffff44f3700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).write_ack 1590
2012-06-21 16:25:22.185435 7fffeeffd700  1 -- 127.0.0.1:6789/0 <== mon.2 127.0.0.1:6791/0 1590 ==== paxos(lease_ack lc 51 fc 1 pn 0 opn 0) v2 ==== 80+0+0 (2824985556 0 0) 0x7fffcc0533a0 con 0x934a20
2012-06-21 16:25:22.185448 7ffff44f3700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6791/0 pipe(0x9347b0 sd=26 pgs=6 cs=1 l=0).writer: state = 2 policy.server=0
2012-06-21 16:25:22.185458 7fffeeffd700 10 mon.a@0(leader).paxos(paxos active c 1..51) handle_lease_ack from mon.2 -- got everyone
2012-06-21 16:25:22.185557 7fffeeffd700 10 mon.a@0(leader).auth v15 update_from_paxos
2012-06-21 16:25:22.185598 7fffeeffd700 10 -- 127.0.0.1:6789/0 dispatch_throttle_release 80 to dispatch throttler 80/104857600
2012-06-21 16:25:22.826816 7ffff42f1700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).reader wants 240 from dispatch throttler 0/104857600
2012-06-21 16:25:22.826860 7ffff42f1700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).aborted = 0
2012-06-21 16:25:22.826884 7ffff42f1700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).reader got message 8 0x7fffd0004030 mdsbeacon(4403/a up:boot seq 2244 v0) v2
2012-06-21 16:25:22.826919 7fffedcf9700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).writer: state = 2 policy.server=1
2012-06-21 16:25:22.826941 7fffedcf9700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).write_ack 8
2012-06-21 16:25:22.826960 7fffedcf9700 10 -- 127.0.0.1:6789/0 >> 127.0.0.1:6800/25236 pipe(0x7fffe8001090 sd=27 pgs=216 cs=1 l=1).writer: state = 2 policy.server=1

This appears to be the same bug as #2620

#2 Updated by Joao Eduardo Luis almost 12 years ago

  • Status changed from New to Closed

Had to do with the AuthMonitor losing some infos when reading versions from the store.

This is fixed.

Also available in: Atom PDF