Actions
Bug #4999
closedmonitor sync failure
% Done:
0%
Source:
Tags:
Backport:
Regression:
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):
Description
I've been testing v0.61 and v0.61.1 with 262,144 PGs in
a single pool, 576 OSDs, 3 mon, 3 MDS (1 active + 2 standby).
After starting a new filesystem and writing data to it
for a while from various numbers of CephFS clients, one
of my monitors dies like this:
-19> 2013-05-09 16:02:28.707657 7ffff2a8c700 5 mon.cs30@2(peon).paxos(paxos recovering c 4713..4749) handle_collect leader's lowest version is too high for our last committed (theirs: 4775; ours: 4749) -- bootstrap!
then
0> 2013-05-09 16:03:29.389081 7ffff328d700 -1 mon/Monitor.cc: In function 'void Monitor::sync_start_reply_timeout()' thread 7ffff328d700 time 2013-05-09 16:03:29.384508
If it matters, here's the mon leveldb config I'm using to make 256K PGs work:
[mon]
mon leveldb block size = 524288
mon leveldb write buffer size = 4194304
mon leveldb cache size = 134217728
mon leveldb compression = false
mon compact on trim = true
mon sync max payload size = 4194304
This issue is reproducible for me, so let me know what I can
do to help sort it out.
Restarting the monitor after it fails like this never works;
reinitializing it and then restarting it sometimes works,
sometimes runs into a sync issue again.
Here's what log I have leading up to the assert:
-758> 2013-05-09 16:00:20.218489 7ffff2a8c700 7 mon.cs30@2(peon).log v1412 update_from_paxos applying incremental log 1412 2013-05-09 16:00:15.025852 mon.0 172.17.131.28:6789/0 3354 : [INF] pgmap v1744: 262144 pgs: 262144 active+clean; 133 GB data, 277 GB used, 502 TB / 503 TB avail; 118MB/s rd, 101KB/s wr, 7579op/s -757> 2013-05-09 16:00:20.288434 7ffff2a8c700 1 mon.cs30@2(peon).log v1412 check_sub sending message to client.? 172.17.131.31:0/19500 with 1 entries (version 1412) -756> 2013-05-09 16:00:21.554919 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos active c 4713..4739) is_readable now=2013-05-09 16:00:21.554928 lease_expire=2013-05-09 16:00:25.508722 has v0 lc 4739 -755> 2013-05-09 16:00:21.555737 7ffff2a8c700 7 mon.cs30@2(peon).pg v1745 update_from_paxos applying incremental 1746 -754> 2013-05-09 16:00:21.926047 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos active c 4713..4740) is_readable now=2013-05-09 16:00:21.926052 lease_expire=2013-05-09 16:00:26.913232 has v0 lc 4740 -753> 2013-05-09 16:00:21.926319 7ffff2a8c700 7 mon.cs30@2(peon).log v1413 update_from_paxos applying incremental log 1413 2013-05-09 16:00:18.306005 mon.0 172.17.131.28:6789/0 3355 : [INF] pgmap v1745: 262144 pgs: 262144 active+clean; 136 GB data, 279 GB used, 502 TB / 503 TB avail; 299KB/s rd, 405MB/s wr, 521op/s -752> 2013-05-09 16:00:21.926401 7ffff2a8c700 7 mon.cs30@2(peon).log v1413 update_from_paxos applying incremental log 1413 2013-05-09 16:00:20.544090 mon.0 172.17.131.28:6789/0 3356 : [INF] pgmap v1746: 262144 pgs: 262144 active+clean; 136 GB data, 283 GB used, 502 TB / 503 TB avail; 114MB/s rd, 360MB/s wr, 7807op/s -751> 2013-05-09 16:00:21.992427 7ffff2a8c700 1 mon.cs30@2(peon).log v1413 check_sub sending message to client.? 172.17.131.31:0/19500 with 2 entries (version 1413) -750> 2013-05-09 16:00:22.409225 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos active c 4713..4741) is_readable now=2013-05-09 16:00:22.409232 lease_expire=2013-05-09 16:00:27.410054 has v0 lc 4741 -749> 2013-05-09 16:00:22.409627 7ffff2a8c700 7 mon.cs30@2(peon).pg v1746 update_from_paxos applying incremental 1747 -748> 2013-05-09 16:00:23.889938 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos active c 4713..4742) is_readable now=2013-05-09 16:00:23.889946 lease_expire=2013-05-09 16:00:28.890657 has v0 lc 4742 -747> 2013-05-09 16:00:23.890471 7ffff2a8c700 7 mon.cs30@2(peon).pg v1747 update_from_paxos applying incremental 1748 -746> 2013-05-09 16:00:23.978122 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4743) is_readable now=2013-05-09 16:00:23.978130 lease_expire=0.000000 has v0 lc 4743 -745> 2013-05-09 16:00:24.010636 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos active c 4713..4743) is_readable now=2013-05-09 16:00:24.010639 lease_expire=2013-05-09 16:00:29.011452 has v0 lc 4743 -744> 2013-05-09 16:00:24.011108 7ffff2a8c700 7 mon.cs30@2(peon).log v1414 update_from_paxos applying incremental log 1414 2013-05-09 16:00:22.452001 mon.0 172.17.131.28:6789/0 3357 : [INF] pgmap v1747: 262144 pgs: 262144 active+clean; 136 GB data, 283 GB used, 502 TB / 503 TB avail; 347MB/s rd, 49210KB/s wr, 22438op/s -743> 2013-05-09 16:00:24.082920 7ffff2a8c700 1 mon.cs30@2(peon).log v1414 check_sub sending message to client.? 172.17.131.31:0/19500 with 1 entries (version 1414) -742> 2013-05-09 16:00:25.163082 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos active c 4713..4744) is_readable now=2013-05-09 16:00:25.163086 lease_expire=2013-05-09 16:00:30.141842 has v0 lc 4744 -741> 2013-05-09 16:00:25.163219 7ffff2a8c700 7 mon.cs30@2(peon).pg v1748 update_from_paxos applying incremental 1749 -740> 2013-05-09 16:00:26.767771 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos active c 4713..4745) is_readable now=2013-05-09 16:00:26.767776 lease_expire=2013-05-09 16:00:31.733366 has v0 lc 4745 -739> 2013-05-09 16:00:26.768050 7ffff2a8c700 7 mon.cs30@2(peon).pg v1749 update_from_paxos applying incremental 1750 -738> 2013-05-09 16:00:26.797412 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos active c 4713..4746) is_readable now=2013-05-09 16:00:26.797415 lease_expire=2013-05-09 16:00:31.793233 has v0 lc 4746 -737> 2013-05-09 16:00:26.797646 7ffff2a8c700 7 mon.cs30@2(peon).log v1415 update_from_paxos applying incremental log 1415 2013-05-09 16:00:23.908847 mon.0 172.17.131.28:6789/0 3358 : [INF] pgmap v1748: 262144 pgs: 262144 active+clean; 137 GB data, 283 GB used, 502 TB / 503 TB avail; 463MB/s rd, 231MB/s wr, 30026op/s -736> 2013-05-09 16:00:26.797723 7ffff2a8c700 7 mon.cs30@2(peon).log v1415 update_from_paxos applying incremental log 1415 2013-05-09 16:00:25.144683 mon.0 172.17.131.28:6789/0 3359 : [INF] pgmap v1749: 262144 pgs: 262144 active+clean; 137 GB data, 283 GB used, 502 TB / 503 TB avail; 213MB/s rd, 364MB/s wr, 14033op/s -735> 2013-05-09 16:00:26.873853 7ffff2a8c700 1 mon.cs30@2(peon).log v1415 check_sub sending message to client.? 172.17.131.31:0/19500 with 2 entries (version 1415) -734> 2013-05-09 16:00:28.373677 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos active c 4713..4747) is_readable now=2013-05-09 16:00:28.373683 lease_expire=2013-05-09 16:00:33.324894 has v0 lc 4747 -733> 2013-05-09 16:00:28.374061 7ffff2a8c700 7 mon.cs30@2(peon).pg v1750 update_from_paxos applying incremental 1751 -732> 2013-05-09 16:00:29.832912 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos active c 4713..4748) is_readable now=2013-05-09 16:00:29.832915 lease_expire=2013-05-09 16:00:34.826224 has v0 lc 4748 -731> 2013-05-09 16:00:29.833081 7ffff2a8c700 7 mon.cs30@2(peon).log v1416 update_from_paxos applying incremental log 1416 2013-05-09 16:00:26.748039 mon.0 172.17.131.28:6789/0 3360 : [INF] pgmap v1750: 262144 pgs: 262144 active+clean; 138 GB data, 285 GB used, 502 TB / 503 TB avail; 134MB/s rd, 411MB/s wr, 9137op/s -730> 2013-05-09 16:00:29.833135 7ffff2a8c700 7 mon.cs30@2(peon).log v1416 update_from_paxos applying incremental log 1416 2013-05-09 16:00:28.350306 mon.0 172.17.131.28:6789/0 3361 : [INF] pgmap v1751: 262144 pgs: 262144 active+clean; 139 GB data, 288 GB used, 502 TB / 503 TB avail; 589MB/s rd, 606MB/s wr, 38694op/s -729> 2013-05-09 16:00:30.018122 7ffff2a8c700 1 mon.cs30@2(peon).log v1416 check_sub sending message to client.? 172.17.131.31:0/19500 with 2 entries (version 1416) -728> 2013-05-09 16:00:30.650742 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:30.650748 lease_expire=0.000000 has v0 lc 4748 -727> 2013-05-09 16:00:30.881629 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:30.881634 lease_expire=0.000000 has v0 lc 4748 -726> 2013-05-09 16:00:31.245967 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:31.245973 lease_expire=0.000000 has v0 lc 4748 -725> 2013-05-09 16:00:31.821365 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:31.821369 lease_expire=0.000000 has v0 lc 4748 -724> 2013-05-09 16:00:31.874846 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:31.874849 lease_expire=0.000000 has v0 lc 4748 -723> 2013-05-09 16:00:31.946519 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:31.946522 lease_expire=0.000000 has v0 lc 4748 -722> 2013-05-09 16:00:31.996611 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:31.996615 lease_expire=0.000000 has v0 lc 4748 -721> 2013-05-09 16:00:33.980641 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:33.980647 lease_expire=0.000000 has v0 lc 4748 -720> 2013-05-09 16:00:35.652313 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:35.652318 lease_expire=0.000000 has v0 lc 4748 -719> 2013-05-09 16:00:35.882745 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:35.882750 lease_expire=0.000000 has v0 lc 4748 -718> 2013-05-09 16:00:36.247011 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:36.247015 lease_expire=0.000000 has v0 lc 4748 -717> 2013-05-09 16:00:36.822630 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:36.822636 lease_expire=0.000000 has v0 lc 4748 -716> 2013-05-09 16:00:36.875907 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:36.875911 lease_expire=0.000000 has v0 lc 4748 -715> 2013-05-09 16:00:36.947733 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:36.947736 lease_expire=0.000000 has v0 lc 4748 -714> 2013-05-09 16:00:36.997834 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:36.997837 lease_expire=0.000000 has v0 lc 4748 -713> 2013-05-09 16:00:38.981939 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:38.981945 lease_expire=0.000000 has v0 lc 4748 -712> 2013-05-09 16:00:39.833039 7ffff328d700 5 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) lease_timeout -- calling new election -711> 2013-05-09 16:00:39.834053 7ffff2a8c700 0 log [INF] : mon.cs30 calling new monitor election -710> 2013-05-09 16:00:39.834065 7ffff2a8c700 10 send_log to self -709> 2013-05-09 16:00:39.834067 7ffff2a8c700 10 log_queue is 2 last_log 16 sent 14 num 2 unsent 2 sending 2 -708> 2013-05-09 16:00:39.834071 7ffff2a8c700 10 will send 2013-05-09 15:43:50.856021 mon.2 172.17.131.30:6789/0 15 : [INF] mon.cs30 calling new monitor election -707> 2013-05-09 16:00:39.834088 7ffff2a8c700 10 will send 2013-05-09 16:00:39.834064 mon.2 172.17.131.30:6789/0 16 : [INF] mon.cs30 calling new monitor election -706> 2013-05-09 16:00:39.834101 7ffff2a8c700 5 mon.cs30@2(electing).elector(74) start -- can i be leader? -705> 2013-05-09 16:00:39.834242 7ffff2a8c700 1 mon.cs30@2(electing).elector(74) init, last seen epoch 74 -704> 2013-05-09 16:00:39.842804 7ffff2a8c700 1 mon.cs30@2(electing).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:00:39.842807 lease_expire=0.000000 has v0 lc 4748 -703> 2013-05-09 16:00:39.850432 7ffff2a8c700 5 mon.cs30@2(electing).elector(75) handle_propose from mon.1 -702> 2013-05-09 16:00:39.850449 7ffff2a8c700 5 mon.cs30@2(electing).elector(75) defer to 1 -701> 2013-05-09 16:00:40.653354 7ffff2a8c700 1 mon.cs30@2(electing).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:00:40.653360 lease_expire=0.000000 has v0 lc 4748 -700> 2013-05-09 16:00:40.884331 7ffff2a8c700 1 mon.cs30@2(electing).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:00:40.884336 lease_expire=0.000000 has v0 lc 4748 -699> 2013-05-09 16:00:41.248140 7ffff2a8c700 1 mon.cs30@2(electing).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:00:41.248143 lease_expire=0.000000 has v0 lc 4748 -698> 2013-05-09 16:00:41.824077 7ffff2a8c700 1 mon.cs30@2(electing).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:00:41.824083 lease_expire=0.000000 has v0 lc 4748 -697> 2013-05-09 16:00:41.877141 7ffff2a8c700 1 mon.cs30@2(electing).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:00:41.877144 lease_expire=0.000000 has v0 lc 4748 -696> 2013-05-09 16:00:41.949003 7ffff2a8c700 1 mon.cs30@2(electing).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:00:41.949007 lease_expire=0.000000 has v0 lc 4748 -695> 2013-05-09 16:00:41.999048 7ffff2a8c700 1 mon.cs30@2(electing).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:00:41.999051 lease_expire=0.000000 has v0 lc 4748 -694> 2013-05-09 16:00:43.983226 7ffff2a8c700 1 mon.cs30@2(electing).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:00:43.983233 lease_expire=0.000000 has v0 lc 4748 -693> 2013-05-09 16:00:44.861844 7ffff2a8c700 5 mon.cs30@2(electing).elector(75) handle_victory from mon.1 quorum_features 4294967295 -692> 2013-05-09 16:00:45.654641 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:45.654647 lease_expire=0.000000 has v0 lc 4748 -691> 2013-05-09 16:00:45.885517 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:45.885521 lease_expire=0.000000 has v0 lc 4748 -690> 2013-05-09 16:00:46.249584 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:46.249588 lease_expire=0.000000 has v0 lc 4748 -689> 2013-05-09 16:00:46.825535 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:46.825539 lease_expire=0.000000 has v0 lc 4748 -688> 2013-05-09 16:00:46.878323 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:46.878327 lease_expire=0.000000 has v0 lc 4748 -687> 2013-05-09 16:00:46.950454 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:46.950459 lease_expire=0.000000 has v0 lc 4748 -686> 2013-05-09 16:00:47.000176 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:47.000182 lease_expire=0.000000 has v0 lc 4748 -685> 2013-05-09 16:00:48.984636 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:48.984644 lease_expire=0.000000 has v0 lc 4748 -684> 2013-05-09 16:00:50.656177 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:50.656182 lease_expire=0.000000 has v0 lc 4748 -683> 2013-05-09 16:00:50.886886 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:50.886890 lease_expire=0.000000 has v0 lc 4748 -682> 2013-05-09 16:00:50.898396 7ffff328d700 0 mon.cs30@2(peon).data_health(76) update_stats avail 90% total 134219776 used 6056888 avail 121856968 -681> 2013-05-09 16:00:51.250843 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:51.250846 lease_expire=0.000000 has v0 lc 4748 -680> 2013-05-09 16:00:51.826790 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:51.826793 lease_expire=0.000000 has v0 lc 4748 -679> 2013-05-09 16:00:51.879377 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:51.879381 lease_expire=0.000000 has v0 lc 4748 -678> 2013-05-09 16:00:51.951876 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:51.951880 lease_expire=0.000000 has v0 lc 4748 -677> 2013-05-09 16:00:52.001374 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:52.001378 lease_expire=0.000000 has v0 lc 4748 -676> 2013-05-09 16:00:53.986059 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:53.986066 lease_expire=0.000000 has v0 lc 4748 -675> 2013-05-09 16:00:55.657449 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:55.657455 lease_expire=0.000000 has v0 lc 4748 -674> 2013-05-09 16:00:55.664852 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:55.664855 lease_expire=0.000000 has v0 lc 4748 -673> 2013-05-09 16:00:55.828756 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:55.828761 lease_expire=0.000000 has v0 lc 4748 -672> 2013-05-09 16:00:55.887962 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:55.887964 lease_expire=0.000000 has v0 lc 4748 -671> 2013-05-09 16:00:56.138393 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.138397 lease_expire=0.000000 has v0 lc 4748 -670> 2013-05-09 16:00:56.252211 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.252214 lease_expire=0.000000 has v0 lc 4748 -669> 2013-05-09 16:00:56.336613 7fffe599e700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2c3dc380 sd=35 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -668> 2013-05-09 16:00:56.343350 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.343353 lease_expire=0.000000 has v0 lc 4748 -667> 2013-05-09 16:00:56.363084 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.363087 lease_expire=0.000000 has v0 lc 4748 -666> 2013-05-09 16:00:56.389686 7fffe599e700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1dc7b200 sd=35 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -665> 2013-05-09 16:00:56.397941 7fffe599e700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e1d0000 sd=35 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -664> 2013-05-09 16:00:56.407029 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.407032 lease_expire=0.000000 has v0 lc 4748 -663> 2013-05-09 16:00:56.749560 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.749564 lease_expire=0.000000 has v0 lc 4748 -662> 2013-05-09 16:00:56.769930 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.769934 lease_expire=0.000000 has v0 lc 4748 -661> 2013-05-09 16:00:56.789890 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.789893 lease_expire=0.000000 has v0 lc 4748 -660> 2013-05-09 16:00:56.811713 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.811716 lease_expire=0.000000 has v0 lc 4748 -659> 2013-05-09 16:00:56.828068 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.828072 lease_expire=0.000000 has v0 lc 4748 -658> 2013-05-09 16:00:56.854565 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.854568 lease_expire=0.000000 has v0 lc 4748 -657> 2013-05-09 16:00:56.862594 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.862597 lease_expire=0.000000 has v0 lc 4748 -656> 2013-05-09 16:00:56.880736 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.880740 lease_expire=0.000000 has v0 lc 4748 -655> 2013-05-09 16:00:56.881426 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.881429 lease_expire=0.000000 has v0 lc 4748 -654> 2013-05-09 16:00:56.913497 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.913500 lease_expire=0.000000 has v0 lc 4748 -653> 2013-05-09 16:00:56.953228 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.953231 lease_expire=0.000000 has v0 lc 4748 -652> 2013-05-09 16:00:56.953969 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.953972 lease_expire=0.000000 has v0 lc 4748 -651> 2013-05-09 16:00:56.972440 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.972443 lease_expire=0.000000 has v0 lc 4748 -650> 2013-05-09 16:00:56.977989 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.977993 lease_expire=0.000000 has v0 lc 4748 -649> 2013-05-09 16:00:56.978232 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.978235 lease_expire=0.000000 has v0 lc 4748 -648> 2013-05-09 16:00:56.982305 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:56.982309 lease_expire=0.000000 has v0 lc 4748 -647> 2013-05-09 16:00:57.002581 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.002585 lease_expire=0.000000 has v0 lc 4748 -646> 2013-05-09 16:00:57.021532 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.021535 lease_expire=0.000000 has v0 lc 4748 -645> 2013-05-09 16:00:57.048447 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.048450 lease_expire=0.000000 has v0 lc 4748 -644> 2013-05-09 16:00:57.081478 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.081481 lease_expire=0.000000 has v0 lc 4748 -643> 2013-05-09 16:00:57.085974 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.085977 lease_expire=0.000000 has v0 lc 4748 -642> 2013-05-09 16:00:57.328897 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.328900 lease_expire=0.000000 has v0 lc 4748 -641> 2013-05-09 16:00:57.329399 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.329402 lease_expire=0.000000 has v0 lc 4748 -640> 2013-05-09 16:00:57.457705 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.457708 lease_expire=0.000000 has v0 lc 4748 -639> 2013-05-09 16:00:57.495871 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.495875 lease_expire=0.000000 has v0 lc 4748 -638> 2013-05-09 16:00:57.526175 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.526179 lease_expire=0.000000 has v0 lc 4748 -637> 2013-05-09 16:00:57.543841 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.543845 lease_expire=0.000000 has v0 lc 4748 -636> 2013-05-09 16:00:57.573740 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.573743 lease_expire=0.000000 has v0 lc 4748 -635> 2013-05-09 16:00:57.578190 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.578193 lease_expire=0.000000 has v0 lc 4748 -634> 2013-05-09 16:00:57.590892 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.590896 lease_expire=0.000000 has v0 lc 4748 -633> 2013-05-09 16:00:57.626610 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.626614 lease_expire=0.000000 has v0 lc 4748 -632> 2013-05-09 16:00:57.630873 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.630875 lease_expire=0.000000 has v0 lc 4748 -631> 2013-05-09 16:00:57.663602 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.663606 lease_expire=0.000000 has v0 lc 4748 -630> 2013-05-09 16:00:57.722794 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.722798 lease_expire=0.000000 has v0 lc 4748 -629> 2013-05-09 16:00:57.735836 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.735840 lease_expire=0.000000 has v0 lc 4748 -628> 2013-05-09 16:00:57.751602 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.751606 lease_expire=0.000000 has v0 lc 4748 -627> 2013-05-09 16:00:57.765883 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:57.765886 lease_expire=0.000000 has v0 lc 4748 -626> 2013-05-09 16:00:57.775332 7fffd854f700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x17caf80 sd=65 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -625> 2013-05-09 16:00:57.887592 7fffd854f700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2e55f080 sd=65 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -624> 2013-05-09 16:00:58.365623 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.365626 lease_expire=0.000000 has v0 lc 4748 -623> 2013-05-09 16:00:58.385940 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.385943 lease_expire=0.000000 has v0 lc 4748 -622> 2013-05-09 16:00:58.696600 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.696603 lease_expire=0.000000 has v0 lc 4748 -621> 2013-05-09 16:00:58.716013 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.716017 lease_expire=0.000000 has v0 lc 4748 -620> 2013-05-09 16:00:58.719212 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.719215 lease_expire=0.000000 has v0 lc 4748 -619> 2013-05-09 16:00:58.735507 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.735511 lease_expire=0.000000 has v0 lc 4748 -618> 2013-05-09 16:00:58.760920 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.760923 lease_expire=0.000000 has v0 lc 4748 -617> 2013-05-09 16:00:58.801826 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.801829 lease_expire=0.000000 has v0 lc 4748 -616> 2013-05-09 16:00:58.810915 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.810919 lease_expire=0.000000 has v0 lc 4748 -615> 2013-05-09 16:00:58.814235 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.814239 lease_expire=0.000000 has v0 lc 4748 -614> 2013-05-09 16:00:58.827913 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.827916 lease_expire=0.000000 has v0 lc 4748 -613> 2013-05-09 16:00:58.830793 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.830797 lease_expire=0.000000 has v0 lc 4748 -612> 2013-05-09 16:00:58.839604 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.839607 lease_expire=0.000000 has v0 lc 4748 -611> 2013-05-09 16:00:58.841718 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.841722 lease_expire=0.000000 has v0 lc 4748 -610> 2013-05-09 16:00:58.844592 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.844595 lease_expire=0.000000 has v0 lc 4748 -609> 2013-05-09 16:00:58.887915 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.887918 lease_expire=0.000000 has v0 lc 4748 -608> 2013-05-09 16:00:58.894158 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.894162 lease_expire=0.000000 has v0 lc 4748 -607> 2013-05-09 16:00:58.901221 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.901225 lease_expire=0.000000 has v0 lc 4748 -606> 2013-05-09 16:00:58.904751 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.904754 lease_expire=0.000000 has v0 lc 4748 -605> 2013-05-09 16:00:58.908906 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.908909 lease_expire=0.000000 has v0 lc 4748 -604> 2013-05-09 16:00:58.971693 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.971696 lease_expire=0.000000 has v0 lc 4748 -603> 2013-05-09 16:00:58.976650 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.976653 lease_expire=0.000000 has v0 lc 4748 -602> 2013-05-09 16:00:58.980244 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.980320 lease_expire=0.000000 has v0 lc 4748 -601> 2013-05-09 16:00:58.983739 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:58.983742 lease_expire=0.000000 has v0 lc 4748 -600> 2013-05-09 16:00:59.007008 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.007011 lease_expire=0.000000 has v0 lc 4748 -599> 2013-05-09 16:00:59.014895 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.014898 lease_expire=0.000000 has v0 lc 4748 -598> 2013-05-09 16:00:59.018003 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.018007 lease_expire=0.000000 has v0 lc 4748 -597> 2013-05-09 16:00:59.032983 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.032986 lease_expire=0.000000 has v0 lc 4748 -596> 2013-05-09 16:00:59.033569 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.033572 lease_expire=0.000000 has v0 lc 4748 -595> 2013-05-09 16:00:59.037753 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.037756 lease_expire=0.000000 has v0 lc 4748 -594> 2013-05-09 16:00:59.041010 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.041013 lease_expire=0.000000 has v0 lc 4748 -593> 2013-05-09 16:00:59.044868 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.044872 lease_expire=0.000000 has v0 lc 4748 -592> 2013-05-09 16:00:59.057053 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.057056 lease_expire=0.000000 has v0 lc 4748 -591> 2013-05-09 16:00:59.060844 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.060847 lease_expire=0.000000 has v0 lc 4748 -590> 2013-05-09 16:00:59.068189 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.068192 lease_expire=0.000000 has v0 lc 4748 -589> 2013-05-09 16:00:59.092781 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.092784 lease_expire=0.000000 has v0 lc 4748 -588> 2013-05-09 16:00:59.108753 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.108756 lease_expire=0.000000 has v0 lc 4748 -587> 2013-05-09 16:00:59.120583 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.120587 lease_expire=0.000000 has v0 lc 4748 -586> 2013-05-09 16:00:59.120744 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.120746 lease_expire=0.000000 has v0 lc 4748 -585> 2013-05-09 16:00:59.153375 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.153379 lease_expire=0.000000 has v0 lc 4748 -584> 2013-05-09 16:00:59.170391 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.170395 lease_expire=0.000000 has v0 lc 4748 -583> 2013-05-09 16:00:59.203869 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.203872 lease_expire=0.000000 has v0 lc 4748 -582> 2013-05-09 16:00:59.204469 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.204472 lease_expire=0.000000 has v0 lc 4748 -581> 2013-05-09 16:00:59.222996 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.222998 lease_expire=0.000000 has v0 lc 4748 -580> 2013-05-09 16:00:59.262496 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:00:59.262500 lease_expire=0.000000 has v0 lc 4748 -579> 2013-05-09 16:01:00.304472 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:00.304476 lease_expire=0.000000 has v0 lc 4748 -578> 2013-05-09 16:01:00.505113 7fffce2fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x19e2a80 sd=106 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -577> 2013-05-09 16:01:00.551049 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:00.551052 lease_expire=0.000000 has v0 lc 4748 -576> 2013-05-09 16:01:00.574986 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:00.574989 lease_expire=0.000000 has v0 lc 4748 -575> 2013-05-09 16:01:00.840825 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:00.840829 lease_expire=0.000000 has v0 lc 4748 -574> 2013-05-09 16:01:00.982624 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:00.982630 lease_expire=0.000000 has v0 lc 4748 -573> 2013-05-09 16:01:01.246841 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:01.246846 lease_expire=0.000000 has v0 lc 4748 -572> 2013-05-09 16:01:01.265371 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:01.265375 lease_expire=0.000000 has v0 lc 4748 -571> 2013-05-09 16:01:01.376445 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:01.376448 lease_expire=0.000000 has v0 lc 4748 -570> 2013-05-09 16:01:01.485106 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:01.485110 lease_expire=0.000000 has v0 lc 4748 -569> 2013-05-09 16:01:01.900726 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:01.900730 lease_expire=0.000000 has v0 lc 4748 -568> 2013-05-09 16:01:01.923581 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:01.923584 lease_expire=0.000000 has v0 lc 4748 -567> 2013-05-09 16:01:01.957579 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:01.957583 lease_expire=0.000000 has v0 lc 4748 -566> 2013-05-09 16:01:01.968737 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:01.968741 lease_expire=0.000000 has v0 lc 4748 -565> 2013-05-09 16:01:02.036873 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.036877 lease_expire=0.000000 has v0 lc 4748 -564> 2013-05-09 16:01:02.191458 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.191461 lease_expire=0.000000 has v0 lc 4748 -563> 2013-05-09 16:01:02.203621 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.203624 lease_expire=0.000000 has v0 lc 4748 -562> 2013-05-09 16:01:02.217761 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.217765 lease_expire=0.000000 has v0 lc 4748 -561> 2013-05-09 16:01:02.253631 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.253634 lease_expire=0.000000 has v0 lc 4748 -560> 2013-05-09 16:01:02.278668 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.278671 lease_expire=0.000000 has v0 lc 4748 -559> 2013-05-09 16:01:02.330197 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.330200 lease_expire=0.000000 has v0 lc 4748 -558> 2013-05-09 16:01:02.367334 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.367337 lease_expire=0.000000 has v0 lc 4748 -557> 2013-05-09 16:01:02.392663 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.392667 lease_expire=0.000000 has v0 lc 4748 -556> 2013-05-09 16:01:02.403220 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.403223 lease_expire=0.000000 has v0 lc 4748 -555> 2013-05-09 16:01:02.414029 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.414032 lease_expire=0.000000 has v0 lc 4748 -554> 2013-05-09 16:01:02.419120 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.419123 lease_expire=0.000000 has v0 lc 4748 -553> 2013-05-09 16:01:02.516863 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.516867 lease_expire=0.000000 has v0 lc 4748 -552> 2013-05-09 16:01:02.529030 7fffc2a78700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x19e5f00 sd=128 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -551> 2013-05-09 16:01:02.550505 7fffc2a78700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x19e0c80 sd=128 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -550> 2013-05-09 16:01:02.605428 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.605431 lease_expire=0.000000 has v0 lc 4748 -549> 2013-05-09 16:01:02.611718 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.611722 lease_expire=0.000000 has v0 lc 4748 -548> 2013-05-09 16:01:02.621636 7fffc2674700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x377eee00 sd=130 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -547> 2013-05-09 16:01:02.721658 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.721663 lease_expire=0.000000 has v0 lc 4748 -546> 2013-05-09 16:01:02.763380 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.763384 lease_expire=0.000000 has v0 lc 4748 -545> 2013-05-09 16:01:02.770441 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.770444 lease_expire=0.000000 has v0 lc 4748 -544> 2013-05-09 16:01:02.783948 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.783951 lease_expire=0.000000 has v0 lc 4748 -543> 2013-05-09 16:01:02.801166 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.801169 lease_expire=0.000000 has v0 lc 4748 -542> 2013-05-09 16:01:02.831132 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.831135 lease_expire=0.000000 has v0 lc 4748 -541> 2013-05-09 16:01:02.848451 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.848455 lease_expire=0.000000 has v0 lc 4748 -540> 2013-05-09 16:01:02.878101 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.878105 lease_expire=0.000000 has v0 lc 4748 -539> 2013-05-09 16:01:02.898922 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.898925 lease_expire=0.000000 has v0 lc 4748 -538> 2013-05-09 16:01:02.921561 7fffb8279700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x19e6900 sd=136 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -537> 2013-05-09 16:01:02.952908 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.952911 lease_expire=0.000000 has v0 lc 4748 -536> 2013-05-09 16:01:02.955987 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.955991 lease_expire=0.000000 has v0 lc 4748 -535> 2013-05-09 16:01:02.956387 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:02.956390 lease_expire=0.000000 has v0 lc 4748 -534> 2013-05-09 16:01:03.066893 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:03.066896 lease_expire=0.000000 has v0 lc 4748 -533> 2013-05-09 16:01:03.123566 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:03.123570 lease_expire=0.000000 has v0 lc 4748 -532> 2013-05-09 16:01:03.154610 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:03.154613 lease_expire=0.000000 has v0 lc 4748 -531> 2013-05-09 16:01:03.215423 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:03.215427 lease_expire=0.000000 has v0 lc 4748 -530> 2013-05-09 16:01:03.221199 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1cbddf00 sd=141 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -529> 2013-05-09 16:01:04.080156 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:04.080159 lease_expire=0.000000 has v0 lc 4748 -528> 2013-05-09 16:01:05.370957 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:05.370964 lease_expire=0.000000 has v0 lc 4748 -527> 2013-05-09 16:01:05.484004 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x377ec600 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -526> 2013-05-09 16:01:05.704446 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:05.704450 lease_expire=0.000000 has v0 lc 4748 -525> 2013-05-09 16:01:05.816471 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:05.816474 lease_expire=0.000000 has v0 lc 4748 -524> 2013-05-09 16:01:05.856470 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:05.856473 lease_expire=0.000000 has v0 lc 4748 -523> 2013-05-09 16:01:05.894483 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1ab08f00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -522> 2013-05-09 16:01:05.897439 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c231180 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -521> 2013-05-09 16:01:05.917116 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:05.917119 lease_expire=0.000000 has v0 lc 4748 -520> 2013-05-09 16:01:05.974063 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2e55e400 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -519> 2013-05-09 16:01:06.003271 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e05f00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -518> 2013-05-09 16:01:06.005386 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x377e8780 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -517> 2013-05-09 16:01:06.018264 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2e55fa80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -516> 2013-05-09 16:01:06.022523 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2e55dc80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -515> 2013-05-09 16:01:06.029093 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.029096 lease_expire=0.000000 has v0 lc 4748 -514> 2013-05-09 16:01:06.050732 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c235500 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -513> 2013-05-09 16:01:06.081430 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e1d2800 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -512> 2013-05-09 16:01:06.088402 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.088406 lease_expire=0.000000 has v0 lc 4748 -511> 2013-05-09 16:01:06.107584 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.107588 lease_expire=0.000000 has v0 lc 4748 -510> 2013-05-09 16:01:06.115206 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.115209 lease_expire=0.000000 has v0 lc 4748 -509> 2013-05-09 16:01:06.199428 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c232d00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -508> 2013-05-09 16:01:06.207277 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.207281 lease_expire=0.000000 has v0 lc 4748 -507> 2013-05-09 16:01:06.208318 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.208321 lease_expire=0.000000 has v0 lc 4748 -506> 2013-05-09 16:01:06.263484 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.263488 lease_expire=0.000000 has v0 lc 4748 -505> 2013-05-09 16:01:06.290038 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.290042 lease_expire=0.000000 has v0 lc 4748 -504> 2013-05-09 16:01:06.294526 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.294530 lease_expire=0.000000 has v0 lc 4748 -503> 2013-05-09 16:01:06.302407 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.302412 lease_expire=0.000000 has v0 lc 4748 -502> 2013-05-09 16:01:06.343344 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.343348 lease_expire=0.000000 has v0 lc 4748 -501> 2013-05-09 16:01:06.370106 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.370110 lease_expire=0.000000 has v0 lc 4748 -500> 2013-05-09 16:01:06.390469 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1ade3200 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -499> 2013-05-09 16:01:06.398858 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1ade6400 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -498> 2013-05-09 16:01:06.402293 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x7e70000 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -497> 2013-05-09 16:01:06.406004 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1dc7f800 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -496> 2013-05-09 16:01:06.425831 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e1d3200 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -495> 2013-05-09 16:01:06.436929 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.436932 lease_expire=0.000000 has v0 lc 4748 -494> 2013-05-09 16:01:06.448475 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.448478 lease_expire=0.000000 has v0 lc 4748 -493> 2013-05-09 16:01:06.570189 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:06.570193 lease_expire=0.000000 has v0 lc 4748 -492> 2013-05-09 16:01:06.721951 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e02580 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -491> 2013-05-09 16:01:07.102733 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:07.102737 lease_expire=0.000000 has v0 lc 4748 -490> 2013-05-09 16:01:07.175365 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:07.175368 lease_expire=0.000000 has v0 lc 4748 -489> 2013-05-09 16:01:07.246116 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e7a3700 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -488> 2013-05-09 16:01:07.252240 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e06180 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -487> 2013-05-09 16:01:07.255736 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e02800 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -486> 2013-05-09 16:01:07.259957 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1ab0b700 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -485> 2013-05-09 16:01:07.266757 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:07.266761 lease_expire=0.000000 has v0 lc 4748 -484> 2013-05-09 16:01:07.275409 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:07.275413 lease_expire=0.000000 has v0 lc 4748 -483> 2013-05-09 16:01:07.304209 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c237d00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -482> 2013-05-09 16:01:07.312541 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:07.312544 lease_expire=0.000000 has v0 lc 4748 -481> 2013-05-09 16:01:07.337785 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:07.337789 lease_expire=0.000000 has v0 lc 4748 -480> 2013-05-09 16:01:07.340662 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:07.340665 lease_expire=0.000000 has v0 lc 4748 -479> 2013-05-09 16:01:07.370190 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:07.370193 lease_expire=0.000000 has v0 lc 4748 -478> 2013-05-09 16:01:07.385369 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2e559900 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -477> 2013-05-09 16:01:07.386620 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:07.386623 lease_expire=0.000000 has v0 lc 4748 -476> 2013-05-09 16:01:07.452446 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c233480 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -475> 2013-05-09 16:01:07.455007 7fffb13fb700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2e55f580 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -474> 2013-05-09 16:01:07.464515 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:07.464519 lease_expire=0.000000 has v0 lc 4748 -473> 2013-05-09 16:01:07.489085 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:07.489089 lease_expire=0.000000 has v0 lc 4748 -472> 2013-05-09 16:01:07.776155 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:07.776158 lease_expire=0.000000 has v0 lc 4748 -471> 2013-05-09 16:01:07.778675 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:07.778679 lease_expire=0.000000 has v0 lc 4748 -470> 2013-05-09 16:01:10.402797 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:10.402801 lease_expire=0.000000 has v0 lc 4748 -469> 2013-05-09 16:01:10.405768 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:10.405772 lease_expire=0.000000 has v0 lc 4748 -468> 2013-05-09 16:01:10.488517 7fffb7c73700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c231400 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -467> 2013-05-09 16:01:10.490495 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:10.490499 lease_expire=0.000000 has v0 lc 4748 -466> 2013-05-09 16:01:10.586468 7fffb7c73700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c236180 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -465> 2013-05-09 16:01:10.593408 7fffb7c73700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c230c80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -464> 2013-05-09 16:01:10.665761 7fffb7c73700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e05000 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -463> 2013-05-09 16:01:10.712149 7fffb7c73700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2e55bc00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -462> 2013-05-09 16:01:10.785341 7fffb7c73700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c237a80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -461> 2013-05-09 16:01:10.863938 7fffb7c73700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1dc79180 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -460> 2013-05-09 16:01:10.903660 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:10.903664 lease_expire=0.000000 has v0 lc 4748 -459> 2013-05-09 16:01:10.944374 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:10.944377 lease_expire=0.000000 has v0 lc 4748 -458> 2013-05-09 16:01:10.975160 7fffb7c73700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e03700 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -457> 2013-05-09 16:01:10.982010 7fffb7c73700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e03480 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -456> 2013-05-09 16:01:10.985538 7fffb7c73700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e03c00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -455> 2013-05-09 16:01:10.985781 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c232300 sd=139 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -454> 2013-05-09 16:01:11.022195 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.022198 lease_expire=0.000000 has v0 lc 4748 -453> 2013-05-09 16:01:11.037022 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.037025 lease_expire=0.000000 has v0 lc 4748 -452> 2013-05-09 16:01:11.046771 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.046775 lease_expire=0.000000 has v0 lc 4748 -451> 2013-05-09 16:01:11.058649 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c235000 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -450> 2013-05-09 16:01:11.060227 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.060231 lease_expire=0.000000 has v0 lc 4748 -449> 2013-05-09 16:01:11.091236 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1ab0f800 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -448> 2013-05-09 16:01:11.095497 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1dc78780 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -447> 2013-05-09 16:01:11.095976 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1ab0c600 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -446> 2013-05-09 16:01:11.110770 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1ab0ee00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -445> 2013-05-09 16:01:11.111235 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e02d00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -444> 2013-05-09 16:01:11.115334 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.115337 lease_expire=0.000000 has v0 lc 4748 -443> 2013-05-09 16:01:11.118311 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.118315 lease_expire=0.000000 has v0 lc 4748 -442> 2013-05-09 16:01:11.123070 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.123074 lease_expire=0.000000 has v0 lc 4748 -441> 2013-05-09 16:01:11.129133 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.129137 lease_expire=0.000000 has v0 lc 4748 -440> 2013-05-09 16:01:11.144328 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c231e00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -439> 2013-05-09 16:01:11.145707 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.145711 lease_expire=0.000000 has v0 lc 4748 -438> 2013-05-09 16:01:11.147493 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c235780 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -437> 2013-05-09 16:01:11.152330 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1ab0d780 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -436> 2013-05-09 16:01:11.185101 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2e559680 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -435> 2013-05-09 16:01:11.207800 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e04100 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -434> 2013-05-09 16:01:11.209224 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.209227 lease_expire=0.000000 has v0 lc 4748 -433> 2013-05-09 16:01:11.217965 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c233200 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -432> 2013-05-09 16:01:11.221132 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e7a6900 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -431> 2013-05-09 16:01:11.266301 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2c3d9b80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -430> 2013-05-09 16:01:11.270371 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1dc7b480 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -429> 2013-05-09 16:01:11.301240 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e1d0500 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -428> 2013-05-09 16:01:11.302880 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.302884 lease_expire=0.000000 has v0 lc 4748 -427> 2013-05-09 16:01:11.305194 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1b1baf80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -426> 2013-05-09 16:01:11.306489 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.306492 lease_expire=0.000000 has v0 lc 4748 -425> 2013-05-09 16:01:11.318907 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.318911 lease_expire=0.000000 has v0 lc 4748 -424> 2013-05-09 16:01:11.329907 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c232800 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -423> 2013-05-09 16:01:11.330368 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c237300 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -422> 2013-05-09 16:01:11.350082 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e07a80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected -421> 2013-05-09 16:01:11.352177 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.352181 lease_expire=0.000000 has v0 lc 4748 -420> 2013-05-09 16:01:11.355009 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.355012 lease_expire=0.000000 has v0 lc 4748 -419> 2013-05-09 16:01:11.356144 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.356148 lease_expire=0.000000 has v0 lc 4748 -418> 2013-05-09 16:01:11.363298 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.363301 lease_expire=0.000000 has v0 lc 4748 -417> 2013-05-09 16:01:11.365622 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.365626 lease_expire=0.000000 has v0 l
Files
Updated by Sage Weil almost 11 years ago
- Priority changed from Normal to Urgent
Hi Jim!
Can you generate a 'debug ms = 1' 'debug mon = 20' 'debug paxos = 20' log for the restart after the crash?
Also, can you post a bit more of the log at the time of the crash (the stack trace, any assert message)?
thanks!
Updated by Jim Schutt almost 11 years ago
Oops, sorry; too-small cut-n-paste buffer clipped off the trace.
I'll try the restart here in a bit -- I had to shut down a couple of my OSD hosts
for maintenance issues, so I think I'll restart them first, let all the recovery
happen, then restart the mon as you asked. Does that sound OK?
If it doesn't give a clean log, I can reproduce -- that'll take a few hours to
hit the first assert.
Here's the rest of the existing log.
-416> 2013-05-09 16:01:11.376986 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1ab09b80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-415> 2013-05-09 16:01:11.378282 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c237580 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-414> 2013-05-09 16:01:11.379403 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.379406 lease_expire=0.000000 has v0 lc 4748
-413> 2013-05-09 16:01:11.390390 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1ab0c880 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-412> 2013-05-09 16:01:11.394282 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e06900 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-411> 2013-05-09 16:01:11.395207 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1c230a00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-410> 2013-05-09 16:01:11.415715 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e03200 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-409> 2013-05-09 16:01:11.418458 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e04600 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-408> 2013-05-09 16:01:11.420163 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.420166 lease_expire=0.000000 has v0 lc 4748
-407> 2013-05-09 16:01:11.447078 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e7a5000 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-406> 2013-05-09 16:01:11.448569 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1dc78280 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-405> 2013-05-09 16:01:11.458465 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.458468 lease_expire=0.000000 has v0 lc 4748
-404> 2013-05-09 16:01:11.498367 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1a88cb00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-403> 2013-05-09 16:01:11.519483 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e01b80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-402> 2013-05-09 16:01:11.521683 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e7a5f00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-401> 2013-05-09 16:01:11.524211 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e01680 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-400> 2013-05-09 16:01:11.538946 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.538949 lease_expire=0.000000 has v0 lc 4748
-399> 2013-05-09 16:01:11.578218 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.578222 lease_expire=0.000000 has v0 lc 4748
-398> 2013-05-09 16:01:11.605637 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1a88f300 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-397> 2013-05-09 16:01:11.633936 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.633940 lease_expire=0.000000 has v0 lc 4748
-396> 2013-05-09 16:01:11.678218 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.678222 lease_expire=0.000000 has v0 lc 4748
-395> 2013-05-09 16:01:11.707012 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.707015 lease_expire=0.000000 has v0 lc 4748
-394> 2013-05-09 16:01:11.736315 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1dc79b80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-393> 2013-05-09 16:01:11.755987 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x7e72f80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-392> 2013-05-09 16:01:11.757888 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:11.757891 lease_expire=0.000000 has v0 lc 4748
-391> 2013-05-09 16:01:12.031605 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:12.031608 lease_expire=0.000000 has v0 lc 4748
-390> 2013-05-09 16:01:12.140510 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x10b84b00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-389> 2013-05-09 16:01:12.149037 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x10b83e80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-388> 2013-05-09 16:01:12.186148 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x10b81400 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-387> 2013-05-09 16:01:12.239463 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x10b82d00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-386> 2013-05-09 16:01:12.249184 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x10b87a80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-385> 2013-05-09 16:01:12.258909 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x10b84880 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-384> 2013-05-09 16:01:12.312178 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1cfc7800 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-383> 2013-05-09 16:01:12.347658 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:12.347662 lease_expire=0.000000 has v0 lc 4748
-382> 2013-05-09 16:01:12.382345 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:12.382348 lease_expire=0.000000 has v0 lc 4748
-381> 2013-05-09 16:01:12.400516 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x10b80500 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-380> 2013-05-09 16:01:12.516775 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:12.516778 lease_expire=0.000000 has v0 lc 4748
-379> 2013-05-09 16:01:12.545950 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:12.545954 lease_expire=0.000000 has v0 lc 4748
-378> 2013-05-09 16:01:12.767353 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1cfc2080 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-377> 2013-05-09 16:01:13.106350 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1cfc5a00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-376> 2013-05-09 16:01:13.137529 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x10b81e00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-375> 2013-05-09 16:01:15.216320 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x10b85000 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-374> 2013-05-09 16:01:15.279826 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:15.279830 lease_expire=0.000000 has v0 lc 4748
-373> 2013-05-09 16:01:15.304858 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:15.304861 lease_expire=0.000000 has v0 lc 4748
-372> 2013-05-09 16:01:15.394943 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:15.394946 lease_expire=0.000000 has v0 lc 4748
-371> 2013-05-09 16:01:15.464724 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2d1dee00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-370> 2013-05-09 16:01:15.523196 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:15.523200 lease_expire=0.000000 has v0 lc 4748
-369> 2013-05-09 16:01:15.534624 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:15.534627 lease_expire=0.000000 has v0 lc 4748
-368> 2013-05-09 16:01:15.543500 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:15.543503 lease_expire=0.000000 has v0 lc 4748
-367> 2013-05-09 16:01:15.563635 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:15.563639 lease_expire=0.000000 has v0 lc 4748
-366> 2013-05-09 16:01:15.761942 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2ce44d80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-365> 2013-05-09 16:01:15.793487 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1da14380 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-364> 2013-05-09 16:01:15.833005 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:15.833009 lease_expire=0.000000 has v0 lc 4748
-363> 2013-05-09 16:01:16.020417 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:16.020421 lease_expire=0.000000 has v0 lc 4748
-362> 2013-05-09 16:01:16.043921 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e02a80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-361> 2013-05-09 16:01:16.122480 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e00a00 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-360> 2013-05-09 16:01:16.130334 7fffb7b72700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x27e04d80 sd=105 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-359> 2013-05-09 16:01:16.194221 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:16.194224 lease_expire=0.000000 has v0 lc 4748
-358> 2013-05-09 16:01:16.329390 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:16.329394 lease_expire=0.000000 has v0 lc 4748
-357> 2013-05-09 16:01:16.337509 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:16.337513 lease_expire=0.000000 has v0 lc 4748
-356> 2013-05-09 16:01:16.399139 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:16.399143 lease_expire=0.000000 has v0 lc 4748
-355> 2013-05-09 16:01:18.067615 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:18.067623 lease_expire=0.000000 has v0 lc 4748
-354> 2013-05-09 16:01:20.475553 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:20.475561 lease_expire=0.000000 has v0 lc 4748
-353> 2013-05-09 16:01:20.551043 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos updating c 4713..4748) is_readable now=2013-05-09 16:01:20.551047 lease_expire=0.000000 has v0 lc 4748
-352> 2013-05-09 16:01:20.786625 7ffff2a8c700 5 mon.cs30@2(peon).elector(76) handle_propose from mon.0
-351> 2013-05-09 16:01:20.786640 7ffff2a8c700 5 mon.cs30@2(peon).elector(76) got propose from old epoch, quorum is 1,2, mon.0 must have just started
-350> 2013-05-09 16:01:20.786661 7ffff2a8c700 0 log [INF] : mon.cs30 calling new monitor election
-349> 2013-05-09 16:01:20.786663 7ffff2a8c700 10 send_log to self
-348> 2013-05-09 16:01:20.786664 7ffff2a8c700 10 log_queue is 3 last_log 17 sent 16 num 3 unsent 1 sending 1
-347> 2013-05-09 16:01:20.786667 7ffff2a8c700 10 will send 2013-05-09 16:00:39.834064 mon.2 172.17.131.30:6789/0 16 : [INF] mon.cs30 calling new monitor election
-346> 2013-05-09 16:01:20.786686 7ffff2a8c700 5 mon.cs30@2(electing).elector(76) start -- can i be leader?
-345> 2013-05-09 16:01:20.786763 7ffff2a8c700 1 mon.cs30@2(electing).elector(76) init, last seen epoch 76
-344> 2013-05-09 16:01:20.795689 7ffff2a8c700 5 mon.cs30@2(electing).elector(77) defer to 0
-343> 2013-05-09 16:01:20.796071 7ffff2a8c700 1 mon.cs30@2(electing).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:20.796074 lease_expire=0.000000 has v0 lc 4748
-342> 2013-05-09 16:01:20.796101 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-341> 2013-05-09 16:01:20.796108 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-340> 2013-05-09 16:01:20.796113 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-339> 2013-05-09 16:01:20.796118 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-338> 2013-05-09 16:01:20.796122 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-337> 2013-05-09 16:01:20.796126 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-336> 2013-05-09 16:01:20.796131 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-335> 2013-05-09 16:01:20.796135 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-334> 2013-05-09 16:01:20.796140 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-333> 2013-05-09 16:01:20.796144 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-332> 2013-05-09 16:01:20.796151 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-331> 2013-05-09 16:01:20.796155 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-330> 2013-05-09 16:01:20.796160 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-329> 2013-05-09 16:01:20.796164 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-328> 2013-05-09 16:01:20.796169 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-327> 2013-05-09 16:01:20.796174 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-326> 2013-05-09 16:01:20.796179 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-325> 2013-05-09 16:01:20.796183 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 26 bytes epoch 1) v1
-324> 2013-05-09 16:01:20.796189 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-323> 2013-05-09 16:01:20.796193 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-322> 2013-05-09 16:01:20.796197 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-321> 2013-05-09 16:01:20.796201 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-320> 2013-05-09 16:01:20.796206 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-319> 2013-05-09 16:01:20.796210 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-318> 2013-05-09 16:01:20.796215 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-317> 2013-05-09 16:01:20.796220 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-316> 2013-05-09 16:01:20.796395 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-315> 2013-05-09 16:01:20.796408 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-314> 2013-05-09 16:01:20.797337 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-313> 2013-05-09 16:01:20.797767 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-312> 2013-05-09 16:01:20.797784 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-311> 2013-05-09 16:01:20.798168 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-310> 2013-05-09 16:01:20.806667 7ffff2a8c700 5 mon.cs30@2(electing).elector(77) handle_propose from mon.0
-309> 2013-05-09 16:01:20.806684 7ffff2a8c700 5 mon.cs30@2(electing).elector(77) defer to 0
-308> 2013-05-09 16:01:20.808547 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-307> 2013-05-09 16:01:20.808568 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-306> 2013-05-09 16:01:20.809623 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 26 bytes epoch 1) v1
-305> 2013-05-09 16:01:20.810379 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-304> 2013-05-09 16:01:20.810839 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-303> 2013-05-09 16:01:20.811015 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-302> 2013-05-09 16:01:20.811904 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-301> 2013-05-09 16:01:20.812069 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-300> 2013-05-09 16:01:20.812206 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-299> 2013-05-09 16:01:20.812358 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-298> 2013-05-09 16:01:20.812384 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-297> 2013-05-09 16:01:20.813198 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-296> 2013-05-09 16:01:20.813433 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-295> 2013-05-09 16:01:20.813767 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-294> 2013-05-09 16:01:20.818876 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-293> 2013-05-09 16:01:20.819274 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-292> 2013-05-09 16:01:20.819462 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-291> 2013-05-09 16:01:20.819674 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-290> 2013-05-09 16:01:20.819693 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-289> 2013-05-09 16:01:20.819701 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-288> 2013-05-09 16:01:20.819707 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-287> 2013-05-09 16:01:20.819905 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-286> 2013-05-09 16:01:20.820478 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-285> 2013-05-09 16:01:20.820497 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-284> 2013-05-09 16:01:20.820571 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-283> 2013-05-09 16:01:20.821011 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-282> 2013-05-09 16:01:20.821148 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-281> 2013-05-09 16:01:20.821199 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-280> 2013-05-09 16:01:20.823437 7fff25b19700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2c3d9180 sd=200 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-279> 2013-05-09 16:01:20.833016 7fff25b19700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1b1b9b80 sd=200 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-278> 2013-05-09 16:01:20.845394 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-277> 2013-05-09 16:01:20.855406 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-276> 2013-05-09 16:01:20.877486 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-275> 2013-05-09 16:01:20.902518 7fff25b19700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1b1bcb00 sd=200 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-274> 2013-05-09 16:01:20.943442 7fff884e6700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1b1bb200 sd=172 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-273> 2013-05-09 16:01:21.014228 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-272> 2013-05-09 16:01:21.202189 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-271> 2013-05-09 16:01:21.211390 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-270> 2013-05-09 16:01:21.298095 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-269> 2013-05-09 16:01:21.316994 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-268> 2013-05-09 16:01:21.326385 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-267> 2013-05-09 16:01:21.329556 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-266> 2013-05-09 16:01:21.379415 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-265> 2013-05-09 16:01:21.407685 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-264> 2013-05-09 16:01:21.419528 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-263> 2013-05-09 16:01:21.515584 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-262> 2013-05-09 16:01:21.824792 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-261> 2013-05-09 16:01:22.245164 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-260> 2013-05-09 16:01:22.267677 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-259> 2013-05-09 16:01:22.268451 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-258> 2013-05-09 16:01:22.271707 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-257> 2013-05-09 16:01:22.304311 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-256> 2013-05-09 16:01:22.327010 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-255> 2013-05-09 16:01:22.329319 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-254> 2013-05-09 16:01:22.332103 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-253> 2013-05-09 16:01:22.362614 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-252> 2013-05-09 16:01:22.424592 7fff880e2700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1dc7a080 sd=150 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-251> 2013-05-09 16:01:22.445200 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-250> 2013-05-09 16:01:22.499201 7fff880e2700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e1d3e80 sd=150 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-249> 2013-05-09 16:01:22.515655 7fff880e2700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1b1bb480 sd=150 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-248> 2013-05-09 16:01:22.522017 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-247> 2013-05-09 16:01:22.532534 7fff880e2700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1ade4380 sd=160 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-246> 2013-05-09 16:01:22.554004 7fff880e2700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1b1b9400 sd=160 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-245> 2013-05-09 16:01:22.554493 7fff880e2700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1b1bcd80 sd=160 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-244> 2013-05-09 16:01:22.576227 7fff880e2700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x7e70280 sd=160 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-243> 2013-05-09 16:01:22.583043 7fff880e2700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1b1bf300 sd=160 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-242> 2013-05-09 16:01:22.625158 7fff876d8700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x2c3dc600 sd=160 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-241> 2013-05-09 16:01:22.627457 7fff876d8700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1b1bf580 sd=160 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-240> 2013-05-09 16:01:22.658736 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-239> 2013-05-09 16:01:22.725297 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-238> 2013-05-09 16:01:22.735813 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-237> 2013-05-09 16:01:22.742084 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-236> 2013-05-09 16:01:22.773655 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-235> 2013-05-09 16:01:22.787401 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-234> 2013-05-09 16:01:22.899124 7fff875d7700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x10b85f00 sd=157 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-233> 2013-05-09 16:01:22.912032 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-232> 2013-05-09 16:01:22.925003 7fff26220700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e1d7080 sd=167 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-231> 2013-05-09 16:01:22.926212 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-230> 2013-05-09 16:01:23.046842 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-229> 2013-05-09 16:01:23.072850 7fff87cde700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1b1b8f00 sd=141 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-228> 2013-05-09 16:01:23.088558 7fff98999700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e1d1400 sd=141 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-227> 2013-05-09 16:01:23.089856 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-226> 2013-05-09 16:01:23.126391 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-225> 2013-05-09 16:01:23.169056 7fff98999700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e1d4d80 sd=141 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-224> 2013-05-09 16:01:23.344198 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-223> 2013-05-09 16:01:23.518189 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-222> 2013-05-09 16:01:23.935230 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-221> 2013-05-09 16:01:24.004824 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-220> 2013-05-09 16:01:24.174712 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-219> 2013-05-09 16:01:24.307171 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-218> 2013-05-09 16:01:24.372150 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-217> 2013-05-09 16:01:24.483501 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 27 bytes epoch 1) v1 and sending client elsewhere
-216> 2013-05-09 16:01:24.483549 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-215> 2013-05-09 16:01:24.483553 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 27 bytes epoch 1) v1 and sending client elsewhere
-214> 2013-05-09 16:01:24.483595 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 27 bytes epoch 1) v1 and sending client elsewhere
-213> 2013-05-09 16:01:24.483603 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 27 bytes epoch 1) v1 and sending client elsewhere
-212> 2013-05-09 16:01:24.483610 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-211> 2013-05-09 16:01:24.483616 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-210> 2013-05-09 16:01:24.483621 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-209> 2013-05-09 16:01:24.483641 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-208> 2013-05-09 16:01:24.483646 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-207> 2013-05-09 16:01:24.483651 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-206> 2013-05-09 16:01:24.483656 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-205> 2013-05-09 16:01:24.483660 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-204> 2013-05-09 16:01:24.483665 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-203> 2013-05-09 16:01:24.483673 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-202> 2013-05-09 16:01:24.483677 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-201> 2013-05-09 16:01:24.483680 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-200> 2013-05-09 16:01:24.483684 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 26 bytes epoch 1) v1 and sending client elsewhere
-199> 2013-05-09 16:01:24.483689 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-198> 2013-05-09 16:01:24.483694 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-197> 2013-05-09 16:01:24.483701 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-196> 2013-05-09 16:01:24.483710 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-195> 2013-05-09 16:01:24.483714 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-194> 2013-05-09 16:01:24.483718 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-193> 2013-05-09 16:01:24.483723 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-192> 2013-05-09 16:01:24.483727 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-191> 2013-05-09 16:01:24.483731 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-190> 2013-05-09 16:01:24.483736 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-189> 2013-05-09 16:01:24.483739 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-188> 2013-05-09 16:01:24.483742 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-187> 2013-05-09 16:01:24.483748 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 27 bytes epoch 1) v1 and sending client elsewhere
-186> 2013-05-09 16:01:24.483753 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-185> 2013-05-09 16:01:24.483756 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-184> 2013-05-09 16:01:24.483761 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-183> 2013-05-09 16:01:24.483767 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 26 bytes epoch 1) v1 and sending client elsewhere
-182> 2013-05-09 16:01:24.483773 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-181> 2013-05-09 16:01:24.483778 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-180> 2013-05-09 16:01:24.483783 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-179> 2013-05-09 16:01:24.483788 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-178> 2013-05-09 16:01:24.483794 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-177> 2013-05-09 16:01:24.483797 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-176> 2013-05-09 16:01:24.483803 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-175> 2013-05-09 16:01:24.483806 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-174> 2013-05-09 16:01:24.483812 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-173> 2013-05-09 16:01:24.483815 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-172> 2013-05-09 16:01:24.483818 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-171> 2013-05-09 16:01:24.483822 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-170> 2013-05-09 16:01:24.483826 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-169> 2013-05-09 16:01:24.483831 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-168> 2013-05-09 16:01:24.483835 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-167> 2013-05-09 16:01:24.483838 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-166> 2013-05-09 16:01:24.483843 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-165> 2013-05-09 16:01:24.483846 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-164> 2013-05-09 16:01:24.483853 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-163> 2013-05-09 16:01:24.483857 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-162> 2013-05-09 16:01:24.483863 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-161> 2013-05-09 16:01:24.483867 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-160> 2013-05-09 16:01:24.483871 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-159> 2013-05-09 16:01:24.483876 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-158> 2013-05-09 16:01:24.483879 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-157> 2013-05-09 16:01:24.483884 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-156> 2013-05-09 16:01:24.483890 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 27 bytes epoch 1) v1 and sending client elsewhere
-155> 2013-05-09 16:01:24.483895 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-154> 2013-05-09 16:01:24.483900 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-153> 2013-05-09 16:01:24.483905 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-152> 2013-05-09 16:01:24.483910 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 27 bytes epoch 1) v1 and sending client elsewhere
-151> 2013-05-09 16:01:24.483915 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-150> 2013-05-09 16:01:24.483920 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-149> 2013-05-09 16:01:24.483924 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-148> 2013-05-09 16:01:24.483929 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-147> 2013-05-09 16:01:24.483934 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-146> 2013-05-09 16:01:24.483940 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-145> 2013-05-09 16:01:24.483945 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-144> 2013-05-09 16:01:24.483949 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-143> 2013-05-09 16:01:24.483953 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-142> 2013-05-09 16:01:24.483956 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-141> 2013-05-09 16:01:24.483961 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-140> 2013-05-09 16:01:24.483966 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-139> 2013-05-09 16:01:24.483969 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-138> 2013-05-09 16:01:24.483974 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-137> 2013-05-09 16:01:24.483979 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-136> 2013-05-09 16:01:24.483983 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-135> 2013-05-09 16:01:24.483987 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-134> 2013-05-09 16:01:24.483992 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-133> 2013-05-09 16:01:24.483995 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-132> 2013-05-09 16:01:24.484001 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-131> 2013-05-09 16:01:24.484004 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-130> 2013-05-09 16:01:24.484008 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-129> 2013-05-09 16:01:24.484013 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-128> 2013-05-09 16:01:24.484019 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-127> 2013-05-09 16:01:24.484023 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-126> 2013-05-09 16:01:24.484028 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-125> 2013-05-09 16:01:24.484033 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-124> 2013-05-09 16:01:24.484037 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-123> 2013-05-09 16:01:24.484044 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-122> 2013-05-09 16:01:24.484048 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-121> 2013-05-09 16:01:24.484053 7ffff328d700 1 mon.cs30@2(electing) e1 discarding message auth(proto 0 29 bytes epoch 1) v1 and sending client elsewhere
-120> 2013-05-09 16:01:24.484058 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-119> 2013-05-09 16:01:24.484062 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-118> 2013-05-09 16:01:24.484065 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-117> 2013-05-09 16:01:24.484068 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-116> 2013-05-09 16:01:24.484071 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-115> 2013-05-09 16:01:24.484075 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-114> 2013-05-09 16:01:24.484078 7ffff328d700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-113> 2013-05-09 16:01:24.936899 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-112> 2013-05-09 16:01:25.001800 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-111> 2013-05-09 16:01:25.440023 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-110> 2013-05-09 16:01:25.447040 7fffb01e9700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x7e75a00 sd=148 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-109> 2013-05-09 16:01:25.464161 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-108> 2013-05-09 16:01:25.487118 7fff871d3700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e1d2300 sd=149 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-107> 2013-05-09 16:01:25.538340 7fff883e5700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e1d5280 sd=149 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-106> 2013-05-09 16:01:25.541498 7fff883e5700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x1e1d0a00 sd=149 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-105> 2013-05-09 16:01:25.585200 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 29 bytes epoch 1) v1
-104> 2013-05-09 16:01:25.594306 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-103> 2013-05-09 16:01:25.617538 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-102> 2013-05-09 16:01:25.644303 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-101> 2013-05-09 16:01:25.679194 7ffff2a8c700 5 mon.cs30@2(electing) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-100> 2013-05-09 16:01:25.706336 7fff874d6700 0 -- 172.17.131.30:6789/0 >> :/0 pipe(0x7e77580 sd=163 :6789 s=0 pgs=0 cs=0 l=0).accept failed to getpeername 107 Transport endpoint is not connected
-99> 2013-05-09 16:01:25.815752 7ffff2a8c700 5 mon.cs30@2(electing).elector(77) handle_victory from mon.0 quorum_features 4294967295
-98> 2013-05-09 16:01:25.825741 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.825745 lease_expire=0.000000 has v0 lc 4748
-97> 2013-05-09 16:01:25.825870 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.825872 lease_expire=0.000000 has v0 lc 4748
-96> 2013-05-09 16:01:25.825985 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.825987 lease_expire=0.000000 has v0 lc 4748
-95> 2013-05-09 16:01:25.826099 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.826101 lease_expire=0.000000 has v0 lc 4748
-94> 2013-05-09 16:01:25.826228 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.826231 lease_expire=0.000000 has v0 lc 4748
-93> 2013-05-09 16:01:25.826536 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.826539 lease_expire=0.000000 has v0 lc 4748
-92> 2013-05-09 16:01:25.826720 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.826723 lease_expire=0.000000 has v0 lc 4748
-91> 2013-05-09 16:01:25.826896 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.826899 lease_expire=0.000000 has v0 lc 4748
-90> 2013-05-09 16:01:25.827075 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.827078 lease_expire=0.000000 has v0 lc 4748
-89> 2013-05-09 16:01:25.827321 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.827324 lease_expire=0.000000 has v0 lc 4748
-88> 2013-05-09 16:01:25.827527 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.827530 lease_expire=0.000000 has v0 lc 4748
-87> 2013-05-09 16:01:25.827650 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.827652 lease_expire=0.000000 has v0 lc 4748
-86> 2013-05-09 16:01:25.827767 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.827768 lease_expire=0.000000 has v0 lc 4748
-85> 2013-05-09 16:01:25.827887 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.827888 lease_expire=0.000000 has v0 lc 4748
-84> 2013-05-09 16:01:25.828001 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.828002 lease_expire=0.000000 has v0 lc 4748
-83> 2013-05-09 16:01:25.828114 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.828116 lease_expire=0.000000 has v0 lc 4748
-82> 2013-05-09 16:01:25.828235 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.828237 lease_expire=0.000000 has v0 lc 4748
-81> 2013-05-09 16:01:25.828466 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.828469 lease_expire=0.000000 has v0 lc 4748
-80> 2013-05-09 16:01:25.828584 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.828586 lease_expire=0.000000 has v0 lc 4748
-79> 2013-05-09 16:01:25.832387 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.832391 lease_expire=0.000000 has v0 lc 4748
-78> 2013-05-09 16:01:25.832520 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.832522 lease_expire=0.000000 has v0 lc 4748
-77> 2013-05-09 16:01:25.832636 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.832638 lease_expire=0.000000 has v0 lc 4748
-76> 2013-05-09 16:01:25.832752 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.832754 lease_expire=0.000000 has v0 lc 4748
-75> 2013-05-09 16:01:25.832868 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.832870 lease_expire=0.000000 has v0 lc 4748
-74> 2013-05-09 16:01:25.832983 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.832985 lease_expire=0.000000 has v0 lc 4748
-73> 2013-05-09 16:01:25.833098 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.833100 lease_expire=0.000000 has v0 lc 4748
-72> 2013-05-09 16:01:25.833214 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.833216 lease_expire=0.000000 has v0 lc 4748
-71> 2013-05-09 16:01:25.833386 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.833388 lease_expire=0.000000 has v0 lc 4748
-70> 2013-05-09 16:01:25.833503 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.833505 lease_expire=0.000000 has v0 lc 4748
-69> 2013-05-09 16:01:25.833617 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.833619 lease_expire=0.000000 has v0 lc 4748
-68> 2013-05-09 16:01:25.833732 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.833733 lease_expire=0.000000 has v0 lc 4748
-67> 2013-05-09 16:01:25.833846 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.833848 lease_expire=0.000000 has v0 lc 4748
-66> 2013-05-09 16:01:25.833960 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.833962 lease_expire=0.000000 has v0 lc 4748
-65> 2013-05-09 16:01:25.834074 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.834076 lease_expire=0.000000 has v0 lc 4748
-64> 2013-05-09 16:01:25.834190 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.834191 lease_expire=0.000000 has v0 lc 4748
-63> 2013-05-09 16:01:25.834357 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.834359 lease_expire=0.000000 has v0 lc 4748
-62> 2013-05-09 16:01:25.834474 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.834476 lease_expire=0.000000 has v0 lc 4748
-61> 2013-05-09 16:01:25.834589 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.834591 lease_expire=0.000000 has v0 lc 4748
-60> 2013-05-09 16:01:25.834704 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.834706 lease_expire=0.000000 has v0 lc 4748
-59> 2013-05-09 16:01:25.834818 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.834820 lease_expire=0.000000 has v0 lc 4748
-58> 2013-05-09 16:01:25.834932 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.834933 lease_expire=0.000000 has v0 lc 4748
-57> 2013-05-09 16:01:25.835046 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.835048 lease_expire=0.000000 has v0 lc 4748
-56> 2013-05-09 16:01:25.835159 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.835161 lease_expire=0.000000 has v0 lc 4748
-55> 2013-05-09 16:01:25.835334 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.835336 lease_expire=0.000000 has v0 lc 4748
-54> 2013-05-09 16:01:25.835451 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.835453 lease_expire=0.000000 has v0 lc 4748
-53> 2013-05-09 16:01:25.835564 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.835566 lease_expire=0.000000 has v0 lc 4748
-52> 2013-05-09 16:01:25.835678 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.835679 lease_expire=0.000000 has v0 lc 4748
-51> 2013-05-09 16:01:25.835792 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.835794 lease_expire=0.000000 has v0 lc 4748
-50> 2013-05-09 16:01:25.835905 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.835907 lease_expire=0.000000 has v0 lc 4748
-49> 2013-05-09 16:01:25.836019 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.836021 lease_expire=0.000000 has v0 lc 4748
-48> 2013-05-09 16:01:25.836304 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4748) is_readable now=2013-05-09 16:01:25.836306 lease_expire=0.000000 has v0 lc 4748
-47> 2013-05-09 16:02:17.164388 7ffff328d700 0 mon.cs30@2(peon).data_health(78) update_stats avail 92% total 134219776 used 4122984 avail 123787480
-46> 2013-05-09 16:02:17.165195 7ffff2a8c700 -1 mon.cs30@2(peon).paxos(paxos recovering c 4713..4749) lease_expire from mon.0 172.17.131.28:6789/0 is 46.306927 seconds in the past; mons are probably laggy (or possibly clocks are too skewed)
-45> 2013-05-09 16:02:17.165603 7ffff2a8c700 7 mon.cs30@2(peon).pg v1751 update_from_paxos applying incremental 1752
-44> 2013-05-09 16:02:17.170817 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos active c 4713..4749) is_readable now=2013-05-09 16:02:17.170826 lease_expire=2013-05-09 16:01:30.858268 has v0 lc 4749
-43> 2013-05-09 16:02:17.183055 7ffff2a8c700 5 mon.cs30@2(peon).elector(78) handle_propose from mon.0
-42> 2013-05-09 16:02:17.193142 7ffff2a8c700 5 mon.cs30@2(peon).elector(79) defer to 0
-41> 2013-05-09 16:02:17.193216 7ffff2a8c700 5 mon.cs30@2(peon).elector(79) handle_propose from mon.1
-40> 2013-05-09 16:02:17.193220 7ffff2a8c700 5 mon.cs30@2(peon).elector(79) ignoring old propose
-39> 2013-05-09 16:02:23.193318 7ffff328d700 5 mon.cs30@2(peon).elector(79) election timer expired
-38> 2013-05-09 16:02:23.193350 7ffff328d700 5 mon.cs30@2(peon).elector(79) start -- can i be leader?
-37> 2013-05-09 16:02:23.193475 7ffff328d700 1 mon.cs30@2(peon).elector(79) init, last seen epoch 79
-36> 2013-05-09 16:02:23.305303 7ffff2a8c700 5 mon.cs30@2(peon).elector(79) handle_propose from mon.1
-35> 2013-05-09 16:02:23.318034 7ffff2a8c700 5 mon.cs30@2(peon).elector(81) defer to 1
-34> 2013-05-09 16:02:28.316491 7ffff2a8c700 5 mon.cs30@2(peon).elector(81) handle_victory from mon.1 quorum_features 4294967295
-33> 2013-05-09 16:02:28.395993 7ffff2a8c700 5 mon.cs30@2(peon).elector(82) handle_propose from mon.0
-32> 2013-05-09 16:02:28.396008 7ffff2a8c700 5 mon.cs30@2(peon).elector(82) got propose from old epoch, quorum is 1,2, mon.0 must have just started
-31> 2013-05-09 16:02:28.396065 7ffff2a8c700 0 log [INF] : mon.cs30 calling new monitor election
-30> 2013-05-09 16:02:28.396074 7ffff2a8c700 10 send_log to self
-29> 2013-05-09 16:02:28.396075 7ffff2a8c700 10 log_queue is 4 last_log 18 sent 16 num 4 unsent 2 sending 2
-28> 2013-05-09 16:02:28.396081 7ffff2a8c700 10 will send 2013-05-09 16:00:39.834064 mon.2 172.17.131.30:6789/0 16 : [INF] mon.cs30 calling new monitor election
-27> 2013-05-09 16:02:28.396103 7ffff2a8c700 10 will send 2013-05-09 16:01:20.786662 mon.2 172.17.131.30:6789/0 17 : [INF] mon.cs30 calling new monitor election
-26> 2013-05-09 16:02:28.396118 7ffff2a8c700 5 mon.cs30@2(electing).elector(82) start -- can i be leader?
-25> 2013-05-09 16:02:28.396181 7ffff2a8c700 1 mon.cs30@2(electing).elector(82) init, last seen epoch 82
-24> 2013-05-09 16:02:28.407972 7ffff2a8c700 5 mon.cs30@2(electing).elector(83) defer to 0
-23> 2013-05-09 16:02:28.408338 7ffff2a8c700 1 mon.cs30@2(electing).paxos(paxos recovering c 4713..4749) is_readable now=2013-05-09 16:02:28.408342 lease_expire=0.000000 has v0 lc 4749
-22> 2013-05-09 16:02:28.439287 7ffff2a8c700 5 mon.cs30@2(electing).elector(83) handle_propose from mon.0
-21> 2013-05-09 16:02:28.439302 7ffff2a8c700 5 mon.cs30@2(electing).elector(83) defer to 0
-20> 2013-05-09 16:02:28.698241 7ffff2a8c700 5 mon.cs30@2(electing).elector(83) handle_victory from mon.0 quorum_features 4294967295
-19> 2013-05-09 16:02:28.707657 7ffff2a8c700 5 mon.cs30@2(peon).paxos(paxos recovering c 4713..4749) handle_collect leader's lowest version is too high for our last committed (theirs: 4775; ours: 4749) -- bootstrap!
-18> 2013-05-09 16:02:28.707813 7ffff2a8c700 1 mon.cs30@2(probing) e1 handle_timecheck drop unexpected msg
-17> 2013-05-09 16:02:28.707847 7ffff2a8c700 1 mon.cs30@2(probing) e1 handle_timecheck drop unexpected msg
-16> 2013-05-09 16:02:28.707871 7ffff2a8c700 5 mon.cs30@2(probing).paxos(paxos recovering c 4713..4749) election in progress, dropping paxos(collect lc 4787 fc 4775 pn 4200 opn 0) v3
-15> 2013-05-09 16:02:28.760206 7ffff2a8c700 1 mon.cs30@2(synchronizing sync( requester state start )) e1 sync_requester_abort no longer a sync requester
-14> 2013-05-09 16:02:44.816753 7ffff2a8c700 5 mon.cs30@2(synchronizing sync( requester state chunks )) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-13> 2013-05-09 16:02:44.816979 7ffff328d700 5 mon.cs30@2(synchronizing sync( requester state chunks )) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-12> 2013-05-09 16:02:44.817038 7ffff2a8c700 5 mon.cs30@2(synchronizing sync( requester state chunks )) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-11> 2013-05-09 16:02:44.817049 7ffff2a8c700 5 mon.cs30@2(synchronizing sync( requester state chunks )) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-10> 2013-05-09 16:02:44.817055 7ffff2a8c700 5 mon.cs30@2(synchronizing sync( requester state chunks )) e1 waitlisting message auth(proto 0 27 bytes epoch 1) v1
-9> 2013-05-09 16:02:44.817066 7ffff2a8c700 5 mon.cs30@2(synchronizing sync( requester state chunks )) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-8> 2013-05-09 16:02:44.817074 7ffff2a8c700 5 mon.cs30@2(synchronizing sync( requester state chunks )) e1 waitlisting message auth(proto 0 28 bytes epoch 1) v1
-7> 2013-05-09 16:02:50.205584 7ffff328d700 1 mon.cs30@2(synchronizing sync( requester state chunks )) e1 discarding message auth(proto 0 27 bytes epoch 1) v1 and sending client elsewhere
-6> 2013-05-09 16:02:50.205657 7ffff328d700 1 mon.cs30@2(synchronizing sync( requester state chunks )) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-5> 2013-05-09 16:02:50.205709 7ffff328d700 1 mon.cs30@2(synchronizing sync( requester state chunks )) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-4> 2013-05-09 16:02:50.205730 7ffff328d700 1 mon.cs30@2(synchronizing sync( requester state chunks )) e1 discarding message auth(proto 0 27 bytes epoch 1) v1 and sending client elsewhere
-3> 2013-05-09 16:02:50.205782 7ffff328d700 1 mon.cs30@2(synchronizing sync( requester state chunks )) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-2> 2013-05-09 16:02:50.205840 7ffff328d700 1 mon.cs30@2(synchronizing sync( requester state chunks )) e1 discarding message auth(proto 0 28 bytes epoch 1) v1 and sending client elsewhere
-1> 2013-05-09 16:03:17.706012 7ffff328d700 0 mon.cs30@2(synchronizing sync( requester state chunks )).data_health(84) update_stats avail 91% total 134219776 used 5499472 avail 122413488
0> 2013-05-09 16:03:29.389081 7ffff328d700 -1 mon/Monitor.cc:Updated by Jim Schutt almost 11 years ago
Evidently it's Redmine's issue. Here's the rest, really!
0> 2013-05-09 16:03:29.389081 7ffff328d700 -1 mon/Monitor.cc: In function 'void Monitor::sync_start_reply_timeout()' thread 7ffff328d700 time 2013-05-09 16:03:29.384508
mon/Monitor.cc: 1482: FAILED assert(sync_state == SYNC_STATE_START)
ceph version 0.61.1-2-gc33273a (c33273ab4c8602f1e1e9b1b14ac84bf5ccffbd32)
1: (Monitor::sync_start_reply_timeout()+0x122) [0x4aa042]
2: (Context::complete(int)+0xa) [0x4af5ea]
3: (SafeTimer::timer_thread()+0x453) [0x5a8db3]
4: (SafeTimerThread::entry()+0xd) [0x5aaf6d]
5: (()+0x77f1) [0x7ffff76507f1]
6: (clone()+0x6d) [0x7ffff6a50ccd]
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/ 0 ms
9/ 9 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/ceph/log/mon.cs30.log
--- end dump of recent events ---
2013-05-09 16:03:29.752794 7ffff328d700 -1 *** Caught signal (Aborted) **
in thread 7ffff328d700
ceph version 0.61.1-2-gc33273a (c33273ab4c8602f1e1e9b1b14ac84bf5ccffbd32)
1: /usr/bin/ceph-mon() [0x5892d9]
2: (()+0xf4a0) [0x7ffff76584a0]
3: (gsignal()+0x35) [0x7ffff699d885]
4: (abort()+0x175) [0x7ffff699f065]
5: (__gnu_cxx::__verbose_terminate_handler()+0x12d) [0x3be84bea7d]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
--- begin dump of recent events ---
0> 2013-05-09 16:03:29.752794 7ffff328d700 -1 *** Caught signal (Aborted) **
in thread 7ffff328d700
ceph version 0.61.1-2-gc33273a (c33273ab4c8602f1e1e9b1b14ac84bf5ccffbd32)
1: /usr/bin/ceph-mon() [0x5892d9]
2: (()+0xf4a0) [0x7ffff76584a0]
3: (gsignal()+0x35) [0x7ffff699d885]
4: (abort()+0x175) [0x7ffff699f065]
5: (__gnu_cxx::__verbose_terminate_handler()+0x12d) [0x3be84bea7d]
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/ 0 ms
9/ 9 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/ceph/log/mon.cs30.log
--- end dump of recent events ---
Updated by Jim Schutt almost 11 years ago
Or, I guess, maybe my browser was getting in the way of a big cut-n-paste?
Anyway, it all seems to be there now.
Updated by Jim Schutt almost 11 years ago
OK, here's what happens when I try to restart:
# /etc/init.d/init-ceph start mon === mon.cs30 === Starting Ceph mon.cs30 on cs30... [222926]: (33) Numerical argument out of domain failed: 'ulimit -n 8192; /usr/bin/ceph-mon -i cs30 --pid-file /var/run/ceph/mon.cs30.pid -c /etc/ceph/ceph.conf '
It looks like some leveldb trouble; here's the mon log file from the restart:
2013-05-10 11:04:02.077643 7ffff7fbe780 0 ceph version 0.61.1-2-gc33273a (c33273ab4c8602f1e1e9b1b14ac84bf5ccffbd32), process ceph-mon, pid 222926
2013-05-10 11:04:02.084842 7ffff7fbe780 10 needs_conversion
2013-05-10 11:04:02.465975 7ffff428f700 -1 *** Caught signal (Segmentation fault) **
in thread 7ffff428f700
ceph version 0.61.1-2-gc33273a (c33273ab4c8602f1e1e9b1b14ac84bf5ccffbd32)
1: /usr/bin/ceph-mon() [0x5892d9]
2: (()+0xf4a0) [0x7ffff76584a0]
3: (leveldb::Table::Open(leveldb::Options const&, leveldb::RandomAccessFile*, unsigned long, leveldb::Table**)+0x35d) [0x7ffff6fb79ad]
4: (leveldb::TableCache::FindTable(unsigned long, unsigned long, leveldb::Cache::Handle**)+0x1db) [0x7ffff6fa7d8b]
5: (leveldb::TableCache::NewIterator(leveldb::ReadOptions const&, unsigned long, unsigned long, leveldb::Table**)+0x46) [0x7ffff6fa7ee6]
6: (leveldb::DBImpl::FinishCompactionOutputFile(leveldb::DBImpl::CompactionState*, leveldb::Iterator*)+0x1d9) [0x7ffff6f98c09]
7: (leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*)+0x79b) [0x7ffff6f9cf2b]
8: (leveldb::DBImpl::BackgroundCompaction()+0x251) [0x7ffff6f9d531]
9: (leveldb::DBImpl::BackgroundCall()+0x90) [0x7ffff6f9dc50]
10: (()+0x3dc6f) [0x7ffff6fbcc6f]
11: (()+0x77f1) [0x7ffff76507f1]
12: (clone()+0x6d) [0x7ffff6a50ccd]
NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
--- begin dump of recent events ---
-21> 2013-05-10 11:04:02.070118 7ffff7fbe780 5 asok(0x1240000) register_command perfcounters_dump hook 0x1200010
-20> 2013-05-10 11:04:02.070202 7ffff7fbe780 5 asok(0x1240000) register_command 1 hook 0x1200010
-19> 2013-05-10 11:04:02.070206 7ffff7fbe780 5 asok(0x1240000) register_command perf dump hook 0x1200010
-18> 2013-05-10 11:04:02.070216 7ffff7fbe780 5 asok(0x1240000) register_command perfcounters_schema hook 0x1200010
-17> 2013-05-10 11:04:02.070226 7ffff7fbe780 5 asok(0x1240000) register_command 2 hook 0x1200010
-16> 2013-05-10 11:04:02.070228 7ffff7fbe780 5 asok(0x1240000) register_command perf schema hook 0x1200010
-15> 2013-05-10 11:04:02.070238 7ffff7fbe780 5 asok(0x1240000) register_command config show hook 0x1200010
-14> 2013-05-10 11:04:02.070242 7ffff7fbe780 5 asok(0x1240000) register_command config set hook 0x1200010
-13> 2013-05-10 11:04:02.070296 7ffff7fbe780 5 asok(0x1240000) register_command log flush hook 0x1200010
-12> 2013-05-10 11:04:02.070299 7ffff7fbe780 5 asok(0x1240000) register_command log dump hook 0x1200010
-11> 2013-05-10 11:04:02.070312 7ffff7fbe780 5 asok(0x1240000) register_command log reopen hook 0x1200010
-10> 2013-05-10 11:04:02.077643 7ffff7fbe780 0 ceph version 0.61.1-2-gc33273a (c33273ab4c8602f1e1e9b1b14ac84bf5ccffbd32), process ceph-mon, pid 222926
-9> 2013-05-10 11:04:02.078759 7ffff7fbe780 1 finished global_init_daemonize
-8> 2013-05-10 11:04:02.084675 7ffff7fbe780 5 asok(0x1240000) init /var/run/ceph/ceph-mon.cs30.asok
-7> 2013-05-10 11:04:02.084703 7ffff7fbe780 5 asok(0x1240000) bind_and_listen /var/run/ceph/ceph-mon.cs30.asok
-6> 2013-05-10 11:04:02.084766 7ffff7fbe780 5 asok(0x1240000) register_command 0 hook 0x11f80b8
-5> 2013-05-10 11:04:02.084775 7ffff7fbe780 5 asok(0x1240000) register_command version hook 0x11f80b8
-4> 2013-05-10 11:04:02.084780 7ffff7fbe780 5 asok(0x1240000) register_command git_version hook 0x11f80b8
-3> 2013-05-10 11:04:02.084783 7ffff7fbe780 5 asok(0x1240000) register_command help hook 0x12000b0
-2> 2013-05-10 11:04:02.084815 7ffff4a90700 5 asok(0x1240000) entry start
-1> 2013-05-10 11:04:02.084842 7ffff7fbe780 10 needs_conversion
0> 2013-05-10 11:04:02.465975 7ffff428f700 -1 *** Caught signal (Segmentation fault) **
in thread 7ffff428f700
ceph version 0.61.1-2-gc33273a (c33273ab4c8602f1e1e9b1b14ac84bf5ccffbd32)
1: /usr/bin/ceph-mon() [0x5892d9]
2: (()+0xf4a0) [0x7ffff76584a0]
3: (leveldb::Table::Open(leveldb::Options const&, leveldb::RandomAccessFile*, unsigned long, leveldb::Table**)+0x35d) [0x7ffff6fb79ad]
4: (leveldb::TableCache::FindTable(unsigned long, unsigned long, leveldb::Cache::Handle**)+0x1db) [0x7ffff6fa7d8b]
5: (leveldb::TableCache::NewIterator(leveldb::ReadOptions const&, unsigned long, unsigned long, leveldb::Table**)+0x46) [0x7ffff6fa7ee6]
6: (leveldb::DBImpl::FinishCompactionOutputFile(leveldb::DBImpl::CompactionState*, leveldb::Iterator*)+0x1d9) [0x7ffff6f98c09]
7: (leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*)+0x79b) [0x7ffff6f9cf2b]
8: (leveldb::DBImpl::BackgroundCompaction()+0x251) [0x7ffff6f9d531]
9: (leveldb::DBImpl::BackgroundCall()+0x90) [0x7ffff6f9dc50]
10: (()+0x3dc6f) [0x7ffff6fbcc6f]
11: (()+0x77f1) [0x7ffff76507f1]
12: (clone()+0x6d) [0x7ffff6a50ccd]
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
1/ 1 ms
20/20 mon
0/10 monc
20/20 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/ceph/log/mon.cs30.log
--- end dump of recent events ---
Updated by Joao Eduardo Luis almost 11 years ago
- Status changed from New to In Progress
Jim, still unable to restart the monitor? If so, could you by any chance run the monitor with gdb and check out what is causing it to segfault?
Updated by Sage Weil almost 11 years ago
- Status changed from In Progress to Need More Info
Updated by Joao Eduardo Luis almost 11 years ago
After talking with Sage, this bug is being postponed until we get a log with higher debug levels to catch intermediate states to assess what the heck is happening.
If anyone is able to trigger this again with 'debug mon = 10' (or 20!) and 'debug ms = 1' it would be awesome.
Updated by Jim Schutt almost 11 years ago
I've got a monitor that has just failed, so I'll see what gdb has to say
about that one.
Am I correct in assuming you want the first assert reproduced with higher
debugging?
I'll be able to start that in a bit - I'm testing OSD rebalancing for a bit :)
So far I'm completely able to reproduce this issue starting from a new filesystem,
but it takes a while of writing to the file system to trigger it.
Updated by Jim Schutt almost 11 years ago
This failure is the first type, in sync_start_reply_timeout().
It looks just like the previous one, and I don't have the higher debugging on this one either,
so here's just a bit of the log for completeness:
-23> 2013-05-14 10:39:20.884687 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4062..4090) is_readable now=2013-05-14 10:39:20.884689 lease_expire=0.000000 has v0 lc 4090
-22> 2013-05-14 10:39:20.934094 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos recovering c 4062..4090) is_readable now=2013-05-14 10:39:20.934097 lease_expire=0.000000 has v0 lc 4090
-21> 2013-05-14 10:40:12.933631 7ffff2a8c700 -1 mon.cs30@2(peon).paxos(paxos recovering c 4062..4091) lease_expire from mon.0 172.17.131.28:6789/0 is 47.006060 seconds in the past; mons are probably laggy (or possibly clocks are too skewed)
-20> 2013-05-14 10:40:12.936129 7ffff2a8c700 7 mon.cs30@2(peon).pg v1501 update_from_paxos applying incremental 1502
-19> 2013-05-14 10:40:12.958478 7ffff2a8c700 1 mon.cs30@2(peon).paxos(paxos active c 4062..4091) is_readable now=2013-05-14 10:40:12.958486 lease_expire=2013-05-14 10:39:25.927570 has v0 lc 4091
-18> 2013-05-14 10:40:12.968099 7ffff2a8c700 10 handle_log_ack log(last 6) v1
-17> 2013-05-14 10:40:12.968128 7ffff2a8c700 5 mon.cs30@2(peon).elector(42) handle_propose from mon.0
-16> 2013-05-14 10:40:12.978247 7ffff2a8c700 5 mon.cs30@2(peon).elector(43) defer to 0
-15> 2013-05-14 10:40:12.978347 7ffff2a8c700 5 mon.cs30@2(peon).elector(43) handle_propose from mon.1
-14> 2013-05-14 10:40:12.978352 7ffff2a8c700 5 mon.cs30@2(peon).elector(43) ignoring old propose
-13> 2013-05-14 10:40:14.634233 7ffff328d700 0 mon.cs30@2(peon).data_health(42) update_stats avail 91% total 134219776 used 5229680 avail 122683792
-12> 2013-05-14 10:40:18.978487 7ffff328d700 5 mon.cs30@2(peon).elector(43) election timer expired
-11> 2013-05-14 10:40:18.978512 7ffff328d700 5 mon.cs30@2(peon).elector(43) start -- can i be leader?
-10> 2013-05-14 10:40:18.978675 7ffff328d700 1 mon.cs30@2(peon).elector(43) init, last seen epoch 43
-9> 2013-05-14 10:40:18.991377 7ffff2a8c700 5 mon.cs30@2(peon).elector(43) handle_propose from mon.1
-8> 2013-05-14 10:40:18.995661 7ffff2a8c700 5 mon.cs30@2(peon).elector(45) defer to 1
-7> 2013-05-14 10:40:18.995704 7ffff2a8c700 5 mon.cs30@2(peon).elector(45) handle_propose from mon.0
-6> 2013-05-14 10:40:18.995709 7ffff2a8c700 5 mon.cs30@2(peon).elector(45) defer to 0
-5> 2013-05-14 10:40:19.002242 7ffff2a8c700 5 mon.cs30@2(peon).elector(45) handle_victory from mon.0 quorum_features 4294967295
-4> 2013-05-14 10:40:19.012362 7ffff2a8c700 5 mon.cs30@2(peon).paxos(paxos recovering c 4062..4091) handle_collect leader's lowest version is too high for our last committed (theirs: 4093; ours: 4091) -- bootstrap!
-3> 2013-05-14 10:40:19.012421 7ffff2a8c700 1 mon.cs30@2(probing) e1 handle_timecheck drop unexpected msg
-2> 2013-05-14 10:40:19.068627 7ffff2a8c700 1 mon.cs30@2(synchronizing sync( requester state start )) e1 sync_requester_abort no longer a sync requester
-1> 2013-05-14 10:41:17.224550 7ffff328d700 0 mon.cs30@2(synchronizing sync( requester state chunks )).data_health(46) update_stats avail 90% total 134219776 used 5912056 avail 122004456
0> 2013-05-14 10:41:23.077740 7ffff328d700 -1 mon/Monitor.cc: In function 'void Monitor::sync_start_reply_timeout()' thread 7ffff328d700 time 2013-05-14 10:41:23.076615
mon/Monitor.cc: 1482: FAILED assert(sync_state == SYNC_STATE_START)
ceph version 0.61.1-6-g04bb75c (04bb75cb1b81684329404a5938e88484df16bc4f)
1: (Monitor::sync_start_reply_timeout()+0x122) [0x4aa172]
2: (Context::complete(int)+0xa) [0x4b07ea]
3: (SafeTimer::timer_thread()+0x453) [0x5aa553]
4: (SafeTimerThread::entry()+0xd) [0x5ac70d]
5: (()+0x77f1) [0x7ffff76507f1]
6: (clone()+0x6d) [0x7ffff6a50ccd]
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/ 0 ms
9/ 9 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/ceph/log/mon.cs30.log
--- end dump of recent events ---
After a restart attempt, the monitor crashes the same way, in leveldb.
gdb doesn't tell me much more than the log from a few days ago....
Core was generated by `/usr/bin/ceph-mon -i cs30 --pid-file /var/run/ceph/mon.cs30.pid -c /etc/ceph/ce'. Program terminated with signal 11, Segmentation fault. #0 0x00007ffff765836b in raise (sig=11) at ../nptl/sysdeps/unix/sysv/linux/pt-raise.c:42 warning: Source file is more recent than executable. 42 sig); Missing separate debuginfos, use: debuginfo-install gperftools-libs-2.0-3.el6.2.x86_64 leveldb-1.7.0-2.el6.x86_64 libgcc-4.4.6-3.el6.x86_64 libstdc++-4.4.6-3.el6.x86_64 libuuid-2.17.2-12.4.el6.x86_64 nspr-4.9-1.el6.x86_64 nss-3.13.3-8.el6.x86_64 nss-softokn-3.12.9-11.el6.x86_64 nss-softokn-freebl-3.12.9-11.el6.x86_64 nss-util-3.13.3-2.el6.x86_64 snappy-1.0.4-3.el6.x86_64 sqlite-3.6.20-1.el6.x86_64 (gdb) bt #0 0x00007ffff765836b in raise (sig=11) at ../nptl/sysdeps/unix/sysv/linux/pt-raise.c:42 #1 0x000000000058aea7 in reraise_fatal (signum=11) at global/signal_handler.cc:58 #2 handle_fatal_signal (signum=11) at global/signal_handler.cc:104 #3 <signal handler called> #4 0x00007ffff6fb79ad in leveldb::Table::Open(leveldb::Options const&, leveldb::RandomAccessFile*, unsigned long, leveldb::Table**) () from /usr/lib64/libleveldb.so.1 #5 0x00007ffff6fa7d8b in leveldb::TableCache::FindTable(unsigned long, unsigned long, leveldb::Cache::Handle**) () from /usr/lib64/libleveldb.so.1 #6 0x00007ffff6fa7ee6 in leveldb::TableCache::NewIterator(leveldb::ReadOptions const&, unsigned long, unsigned long, leveldb::Table**) () from /usr/lib64/libleveldb.so.1 #7 0x00007ffff6f98c09 in leveldb::DBImpl::FinishCompactionOutputFile(leveldb::DBImpl::CompactionState*, leveldb::Iterator*) () from /usr/lib64/libleveldb.so.1 #8 0x00007ffff6f9cf2b in leveldb::DBImpl::DoCompactionWork(leveldb::DBImpl::CompactionState*) () from /usr/lib64/libleveldb.so.1 #9 0x00007ffff6f9d531 in leveldb::DBImpl::BackgroundCompaction() () from /usr/lib64/libleveldb.so.1 #10 0x00007ffff6f9dc50 in leveldb::DBImpl::BackgroundCall() () from /usr/lib64/libleveldb.so.1 #11 0x00007ffff6fbcc6f in ?? () from /usr/lib64/libleveldb.so.1 #12 0x00007ffff76507f1 in start_thread (arg=0x7ffff3ce1700) at pthread_create.c:301 #13 0x00007ffff6a50ccd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115 (gdb) f 4 #4 0x00007ffff6fb79ad in leveldb::Table::Open(leveldb::Options const&, leveldb::RandomAccessFile*, unsigned long, leveldb::Table**) () from /usr/lib64/libleveldb.so.1 (gdb) l 37 pid = -pid; 38 #endif 39 40 #if __ASSUME_TGKILL 41 return INLINE_SYSCALL (tgkill, 3, pid, THREAD_GETMEM (THREAD_SELF, tid), 42 sig); 43 #else 44 # ifdef __NR_tgkill 45 int res = INLINE_SYSCALL (tgkill, 3, pid, THREAD_GETMEM (THREAD_SELF, tid), 46 sig); (gdb) f 5 #5 0x00007ffff6fa7d8b in leveldb::TableCache::FindTable(unsigned long, unsigned long, leveldb::Cache::Handle**) () from /usr/lib64/libleveldb.so.1 (gdb) l 47 if (res != -1 || errno != ENOSYS) 48 return res; 49 # endif 50 return INLINE_SYSCALL (tkill, 2, THREAD_GETMEM (THREAD_SELF, tid), sig); 51 #endif 52 } (gdb) f 6 #6 0x00007ffff6fa7ee6 in leveldb::TableCache::NewIterator(leveldb::ReadOptions const&, unsigned long, unsigned long, leveldb::Table**) () from /usr/lib64/libleveldb.so.1 (gdb) l Line number 53 out of range; ../nptl/sysdeps/unix/sysv/linux/pt-raise.c has 52 lines. (gdb) f 7 #7 0x00007ffff6f98c09 in leveldb::DBImpl::FinishCompactionOutputFile(leveldb::DBImpl::CompactionState*, leveldb::Iterator*) () from /usr/lib64/libleveldb.so.1 (gdb) l Line number 53 out of range; ../nptl/sysdeps/unix/sysv/linux/pt-raise.c has 52 lines. (gdb) quit
Maybe I need to install the leveldb-debuginfo RPM?
Updated by Joao Eduardo Luis almost 11 years ago
Yeah, I'd say so.
Anyway, this ticket has two (independent, I hope) bugs: the sync bug and the leveldb bug. I've opened #5072 to track the leveldb issue.
Jim, if you are in some way able to reproduce it, can you please set debug mon at 10? It will generate a whole bunch of logs, but they'd be really helpful in tracking this without sending me on a wild goose chase.
Updated by Jim Schutt almost 11 years ago
I'll be attempting to reproduce this morning with the debug mon = 10, debug ms = 1.
Updated by Jim Schutt almost 11 years ago
Hmmm, I've been running all day, but I haven't reproduced yet.
I'm seeing a mon repeatedly drop out of and then rejoin quorum, which I recall as a precursor to the assert reported above, but I'm not triggering it now. Possibly the debugging is changing timing enough to avoid it?
I'll keep a load on the filesystem overnight, but I'm afraid we're going to need a plan B,
involving more targetted debugging, to sort this out.
Updated by Jim Schutt almost 11 years ago
Well, unfortunately it didn't reproduce overnight, either.
I was reproducing this every day at lower debug levels, so I think my plan B is to run with debug ms = 0, debug mon = 9, and then start adding in more targetted debugging to try to figure out what is going on. I'll start by trying to selectively instrument the sync process with some debugging thats low-impact enough to not impair my ability to reproduce, but with enough information to help unravel what's going on.
Unless there's some other approach I'm not seeing?
Updated by Joao Eduardo Luis almost 11 years ago
That's pretty much what I was going to suggest if you were unable to trigger this.
Trying to output only the relevant debug messages, which would basically be just those outputting the function name on the beginning of each function, for anything related with the monitor's sync, election, bootstrap and reset.
If you'd like, I can push a branch with the appropriate functions with log level 9 and avoid all the other noise from level 10.
Updated by Joao Eduardo Luis almost 11 years ago
huh, although debug ms = 1 would still be useful to see what's triggering what. That could also be surgically debugged if need be.
Updated by Jim Schutt almost 11 years ago
I'm afraid the debug ms = 1 is responsible for whatever is keeping me from reproducing, so I was
leaning towards the sugical option here - my first attempt will be to try to find the places where
I can print out only the messages involved in sync, and see if I can reproduce, and whether there's enough info from that to debug.
If not, I'll keep trying to add useful information until either I can't reproduce and we need to regroup, or we figure it out.
Updated by Jim Schutt almost 11 years ago
Joao, maybe it would be best if you pushed a branch with the debugging you'd like to see, since you know the code much better than I. That way we're not slowed down by me needing to learn what you already know?
If so, I'd like to start under the assumption that debug ms = 0, and that we add debugging at level 0 to print the pertinent messages. Would that work for you?
Updated by Joao Eduardo Luis almost 11 years ago
Yeah. Will push something shortly and let you know.
Updated by Joao Eduardo Luis almost 11 years ago
Jim, pushed wip-4999 with a patch to output what I believe to be the relevant information on 'debug mon = 9' (some messages included). It's on top of next; I hope that's not an issue for you. Otherwise I can push it on top of 0.62.2, or whatever you're comfortable with.
Updated by Jim Schutt almost 11 years ago
OK, I'll take it for a spin. next branch is fine, except we might run into other issues that confound debugging this one ... hopefully if we run into such it will be obvious.
Thanks!
Updated by Jim Schutt almost 11 years ago
- File mon.cs28.log.bz2 mon.cs28.log.bz2 added
Hmm, got the following during mon startup:
0> 2013-05-16 12:01:57.081475 7ffff328d700 -1 mon/PaxosService.cc: In function 'void PaxosService::propose_pending()' thread 7ffff328d700 time 2013-05-16 12:01:57.08047 5 mon/PaxosService.cc: 139: FAILED assert(is_active())
This seems new to me, and different from what we're tracking here?
See uploaded log file.
Updated by Jim Schutt almost 11 years ago
Hmmm, this bit seems odd:
void PaxosService::propose_pending()
{
dout(10) << "propose_pending" << dendl;
assert(have_pending);
assert(mon->is_leader());
assert(is_active());
if (!is_active())
return;
That 'assert(is_active())' looks like leftover debugging given the following return statement.
Any harm in just deleting the assert?
Updated by Joao Eduardo Luis almost 11 years ago
Yeah, the assert guarantees an invariable is always met (we must be active to propose a new value through Paxos).
The issue here is that at some point we back off a proposal on one of the PaxosServices and the proposal_timer is scheduled. However, it appears that something was updated leading to a 'Paxos::prepare_bootstrap()' [1], which by setting Paxos as 'going_to_bootstrap' makes 'PaxosService::is_active()' to return false and that assert to fail.
If this is indeed the cause, the easiest solution is fairly simple: just return on propose_pending() if we're going to bootstrap -- then again, this might make us lose the pending state; I guess this warrants another approach.
[1] - For clarity's sake, we use the prepare_bootstrap() approach so that we know that we must not schedule new proposals, but at the same time taking care of any currently queued proposals so that we don't end up losing them.
Updated by Jim Schutt almost 11 years ago
I've been unable to reproduce this while using the debugging info patch.
Finally, yesterday I tried the cuttlefish branch (at commit 0e127dc4ef16) without cherry-picking the debug patch, and got another occurrence.
I'm not sure what to do next to track this down.....
Maybe I'll try 0.63 or the next branch for a while....
Updated by Sage Weil almost 11 years ago
Jim, you mean you hit the leveldb error again? can you post a complete log for that? The one in the original report looks truncated.
Thanks!
The second crash (is_active() assert in propose_pending()) should be fixed now in master/next and cuttlefish branches.
Updated by Jim Schutt almost 11 years ago
No, I meant I had hit the original issue again, where a sync failed
due to timeout (see updates 2,3)
I haven't been able to reproduce that since I started testing your
trim+compaction work, so maybe this bug needs to be "can't reproduce"
for now. Also, I've been running with "mon sync timeout = 60",
which may be migitigating the issue
I haven't reproduced the leveldb issue recently. That one only
happens after a restart of a monitor after it crashes, so if I don't
get the original crash, I don't hit the restart issue either.
Updated by Sage Weil almost 11 years ago
- Status changed from Need More Info to Can't reproduce
Actions