Bug #10494: unittest_msgr : segmentation fault - Ceph - Ceph

Bug #10494

unittest_msgr : segmentation fault

Added by Loïc Dachary over 8 years ago. Updated over 8 years ago.

Status:

Resolved

Priority:

Normal

Assignee:

Haomai Wang

Category:

Target version:

% Done:

Source:

other

Tags:

Backport:

Regression:

Severity:

3 - minor

Reviewed:

Affected Versions:

ceph-qa-suite:

Pull request ID:

Crash signature (v1):

Crash signature (v2):

Description

Steps to reproduce:

$ git describe
v0.90-805-gcf432fa
$ ./autogen.sh
$ ./configure --with-radosgw --disable-static --with-debug CC='ccache gcc' CXX='ccache g++'
while ./unittest_msgr ; do : ; done

it will eventually crash with:

[ RUN      ] Messenger/MessengerTest.StatefulTest/1
SetUp start set up simple
ms_handle_fast_connect0x3f0e7b0
ms_handle_fast_connect con: 0x3f0e7b0 count: 0
ms_handle_fast_connect0x3f0e7b0
ms_handle_fast_connect0x3f13540
ms_handle_fast_connect con: 0x3f13540 count: 0
ms_fast_dispatch conn: 0x7fea1c007810 session 0x7fea2400e3b0 count: 1
ms_fast_dispatch conn: 0x3f13540 session 0x7fea20002700 count: 1
2015-01-09 15:28:47.717959 7fea4542e700  0 -- 127.0.0.1:7150/6690 >> 127.0.0.1:0/6690 pipe(0x7fea1c0195e0 sd=15 :7150 s=2 pgs=1 cs=1 l=0 c=0x7fea1c007810).fault, server, going to standby
2015-01-09 15:28:47.718076 7fea40476700  0 -- 127.0.0.1:7150/6690 >> 127.0.0.1:0/6690 pipe(0x7fea1c01e890 sd=16 :7150 s=0 pgs=0 cs=0 l=0 c=0x7fea1c007980).accept connect_seq 0 vs existing 1 state standby
2015-01-09 15:28:47.718082 7fea40476700  0 -- 127.0.0.1:7150/6690 >> 127.0.0.1:0/6690 pipe(0x7fea1c01e890 sd=16 :7150 s=0 pgs=0 cs=0 l=0 c=0x7fea1c007980).accept peer reset, then tried to connect to us, replacing
ms_handle_fast_connect0x3f136b0
ms_handle_fast_connect con: 0x3f136b0 count: 0
ms_fast_dispatch conn: 0x7fea1c007810 session 0x7fea2400e3b0 count: 2
ms_fast_dispatch conn: ms_handle_remote_reset0x7fea1c007810
2015-01-09 15:28:47.718239 7fea4542e700  0 -- 127.0.0.1:0/6690 >> 127.0.0.1:7150/6690 pipe(0x3f0f2a0 sd=14 :57393 s=2 pgs=2 cs=1 l=0 c=0x3f136b0).reader missed message?  skipped from seq 0 to 187807877
0x3f136b0 session 0x7fea14001280 count: 1
ms_handle_reset0x7fea1c007980
*** Caught signal (Segmentation fault) **
 in thread 7fea454947c0
 ceph version 0.90-783-g6fd348f (6fd348fe43399a882906646004bf3f5a4cf9dabb)
 1: ./unittest_msgr() [0x85e41a]
 2: (()+0x10340) [0x7fea44e81340]
 3: (MessengerTest_StatefulTest_Test::TestBody()+0xbff) [0x82d06f]
 4: (testing::Test::Run()+0x96) [0x83ce56]
 5: (testing::internal::TestInfoImpl::Run()+0xd8) [0x83d3c0]
 6: (testing::TestCase::Run()+0xcb) [0x83d8c9]
 7: (testing::internal::UnitTestImpl::RunAllTests()+0x26e) [0x841dca]
 8: (testing::UnitTest::Run()+0x1c) [0x840d80]
 9: (main()+0x103) [0x829683]
 10: (__libc_start_main()+0xf5) [0x7fea4359fec5]
 11: ./unittest_msgr() [0x82ad87]
2015-01-09 15:28:47.763637 7fea454947c0 -1 *** Caught signal (Segmentation fault) **
 in thread 7fea454947c0

 ceph version 0.90-783-g6fd348f (6fd348fe43399a882906646004bf3f5a4cf9dabb)
 1: ./unittest_msgr() [0x85e41a]
 2: (()+0x10340) [0x7fea44e81340]
 3: (MessengerTest_StatefulTest_Test::TestBody()+0xbff) [0x82d06f]
 4: (testing::Test::Run()+0x96) [0x83ce56]
 5: (testing::internal::TestInfoImpl::Run()+0xd8) [0x83d3c0]
 6: (testing::TestCase::Run()+0xcb) [0x83d8c9]
 7: (testing::internal::UnitTestImpl::RunAllTests()+0x26e) [0x841dca]
 8: (testing::UnitTest::Run()+0x1c) [0x840d80]
 9: (main()+0x103) [0x829683]
 10: (__libc_start_main()+0xf5) [0x7fea4359fec5]
 11: ./unittest_msgr() [0x82ad87]
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
  -396> 2015-01-09 15:28:47.705764 7fea454947c0  5 asok(0x3e81e90) register_command perfcounters_dump hook 0x3e83f90
  -395> 2015-01-09 15:28:47.705797 7fea454947c0  5 asok(0x3e81e90) register_command 1 hook 0x3e83f90
  -394> 2015-01-09 15:28:47.705802 7fea454947c0  5 asok(0x3e81e90) register_command perf dump hook 0x3e83f90
  -393> 2015-01-09 15:28:47.705807 7fea454947c0  5 asok(0x3e81e90) register_command perfcounters_schema hook 0x3e83f90
  -392> 2015-01-09 15:28:47.705816 7fea454947c0  5 asok(0x3e81e90) register_command 2 hook 0x3e83f90
  -391> 2015-01-09 15:28:47.705824 7fea454947c0  5 asok(0x3e81e90) register_command perf schema hook 0x3e83f90
  -390> 2015-01-09 15:28:47.705830 7fea454947c0  5 asok(0x3e81e90) register_command perf reset hook 0x3e83f90
  -389> 2015-01-09 15:28:47.705836 7fea454947c0  5 asok(0x3e81e90) register_command config show hook 0x3e83f90
  -388> 2015-01-09 15:28:47.705839 7fea454947c0  5 asok(0x3e81e90) register_command config set hook 0x3e83f90
  -387> 2015-01-09 15:28:47.705844 7fea454947c0  5 asok(0x3e81e90) register_command config get hook 0x3e83f90
  -386> 2015-01-09 15:28:47.705847 7fea454947c0  5 asok(0x3e81e90) register_command config diff hook 0x3e83f90
  -385> 2015-01-09 15:28:47.705852 7fea454947c0  5 asok(0x3e81e90) register_command log flush hook 0x3e83f90
  -384> 2015-01-09 15:28:47.705854 7fea454947c0  5 asok(0x3e81e90) register_command log dump hook 0x3e83f90
  -383> 2015-01-09 15:28:47.705859 7fea454947c0  5 asok(0x3e81e90) register_command log reopen hook 0x3e83f90
  -382> 2015-01-09 15:28:47.708157 7fea454947c0 -1 WARNING: the following dangerous and experimental features are enabled: ms-type-async
  -381> 2015-01-09 15:28:47.708173 7fea454947c0  5 asok(0x3e81e90) init /home/loic/software/ceph/ceph/src/out/client.admin.6690.asok
  -380> 2015-01-09 15:28:47.708180 7fea454947c0  5 asok(0x3e81e90) bind_and_listen /home/loic/software/ceph/ceph/src/out/client.admin.6690.asok
  -379> 2015-01-09 15:28:47.708355 7fea454947c0  5 asok(0x3e81e90) register_command 0 hook 0x3e877b0
  -378> 2015-01-09 15:28:47.708360 7fea454947c0  5 asok(0x3e81e90) register_command version hook 0x3e877b0
  -377> 2015-01-09 15:28:47.708363 7fea454947c0  5 asok(0x3e81e90) register_command git_version hook 0x3e877b0
  -376> 2015-01-09 15:28:47.708366 7fea454947c0  5 asok(0x3e81e90) register_command help hook 0x3e891f0
  -375> 2015-01-09 15:28:47.708368 7fea454947c0  5 asok(0x3e81e90) register_command get_command_descriptions hook 0x3e87900
  -374> 2015-01-09 15:28:47.708407 7fea4257b700  5 asok(0x3e81e90) entry start
  -373> 2015-01-09 15:28:47.708582 7fea454947c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -372> 2015-01-09 15:28:47.708585 7fea454947c0 -1 Please be aware that this feature is experimental, untested,
  -371> 2015-01-09 15:28:47.708586 7fea454947c0 -1 unsupported, and may result in data corruption, data loss,
  -370> 2015-01-09 15:28:47.708586 7fea454947c0 -1 and/or irreparable damage to your cluster.  Do not use
  -369> 2015-01-09 15:28:47.708587 7fea454947c0 -1 feature with important data.
  -368> 2015-01-09 15:28:47.708769 7fea454947c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -367> 2015-01-09 15:28:47.708771 7fea454947c0 -1 Please be aware that this feature is experimental, untested,
  -366> 2015-01-09 15:28:47.708771 7fea454947c0 -1 unsupported, and may result in data corruption, data loss,
  -365> 2015-01-09 15:28:47.708772 7fea454947c0 -1 and/or irreparable damage to your cluster.  Do not use
  -364> 2015-01-09 15:28:47.708772 7fea454947c0 -1 feature with important data.
  -363> 2015-01-09 15:28:47.708951 7fea454947c0  1 -- 127.0.0.1:0/0 learned_addr learned my addr 127.0.0.1:0/0
  -362> 2015-01-09 15:28:47.708962 7fea454947c0  1  Processor -- bind bind my_inst.addr is 127.0.0.1:7146/6690
  -361> 2015-01-09 15:28:47.708966 7fea454947c0  1  Processor -- start start
  -360> 2015-01-09 15:28:47.708978 7fea454947c0  1 -- 127.0.0.1:7146/6690 start start
  -359> 2015-01-09 15:28:47.708998 7fea454947c0  1  Processor -- start start
  -358> 2015-01-09 15:28:47.709000 7fea454947c0  1 -- :/0 start start
  -357> 2015-01-09 15:28:47.709040 7fea454947c0  1 Event wakeup
  -356> 2015-01-09 15:28:47.709168 7fea41d7a700  1 Event wakeup
  -355> 2015-01-09 15:28:47.709224 7fea40d78700  1 -- 127.0.0.1:7146/6690 >> :/0 conn(0x7fea2c0008c0 sd=15 :7146 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:48965/0
  -354> 2015-01-09 15:28:47.709303 7fea41579700  1 -- 127.0.0.1:0/6690 learned_addr learned my addr 127.0.0.1:0/6690
  -353> 2015-01-09 15:28:47.709350 7fea40d78700  1 Event wakeup
  -352> 2015-01-09 15:28:47.709375 7fea40d78700  2 -- 127.0.0.1:7146/6690 >> 127.0.0.1:0/6690 conn(0x7fea2c0008c0 sd=15 :7146 s=STATE_ACCEPTING_READY pgs=1 cs=1 l=1).handle_connect_msg accept write reply msg done
  -351> 2015-01-09 15:28:47.709397 7fea41579700  1 Event wakeup
  -350> 2015-01-09 15:28:47.709429 7fea41579700  1 Event wakeup
  -349> 2015-01-09 15:28:47.709607 7fea454947c0  1 -- 127.0.0.1:7146/6690 rebind rebind avoid 7146,7147,7148,7149,7150,7151,7152,7153,7154,7155
  -348> 2015-01-09 15:28:47.709668 7fea454947c0  1 -- 127.0.0.1:7146/6690 mark_down_all 
  -347> 2015-01-09 15:28:47.709674 7fea454947c0  5 -- 127.0.0.1:7146/6690 mark_down_all mark down 127.0.0.1:0/6690 0x7fea2c0008c0
  -346> 2015-01-09 15:28:47.709677 7fea454947c0  1 Event wakeup
  -345> 2015-01-09 15:28:47.709730 7fea40d78700  1 Event wakeup
  -344> 2015-01-09 15:28:47.709741 7fea41579700  1 -- 127.0.0.1:0/6690 >> 127.0.0.1:7146/6690 conn(0x3eb9260 sd=14 :-1 s=STATE_OPEN pgs=1 cs=1 l=1).read_bulk Peer close file descriptor 14
  -343> 2015-01-09 15:28:47.709751 7fea41579700  1 -- 127.0.0.1:0/6690 >> 127.0.0.1:7146/6690 conn(0x3eb9260 sd=14 :-1 s=STATE_OPEN pgs=1 cs=1 l=1).process read tag failed, state is STATE_OPEN
  -342> 2015-01-09 15:28:47.709758 7fea454947c0  5 -- 127.0.0.1:7146/6690 mark_down_all delete 0x7fea2c0008c0
  -341> 2015-01-09 15:28:47.709764 7fea41579700  1 Event wakeup
  -340> 2015-01-09 15:28:47.709766 7fea454947c0  1  Processor -- rebind rebind avoid 7146,7147,7148,7149,7150,7151,7152,7153,7154,7155
  -339> 2015-01-09 15:28:47.709791 7fea41579700  1 Event wakeup
  -338> 2015-01-09 15:28:47.709944 7fea454947c0  1  Processor -- bind bind my_inst.addr is 127.0.0.1:7156/1006690
  -337> 2015-01-09 15:28:47.709951 7fea454947c0  1  Processor -- start start
  -336> 2015-01-09 15:28:47.709984 7fea454947c0  1 Event wakeup
  -335> 2015-01-09 15:28:47.710043 7fea41d7a700  1 Event wakeup
  -334> 2015-01-09 15:28:47.710079 7fea40d78700  1 -- 127.0.0.1:7156/1006690 >> :/0 conn(0x7fea2c0064d0 sd=15 :7156 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:57214/0
  -333> 2015-01-09 15:28:47.710167 7fea40d78700  1 Event wakeup
  -332> 2015-01-09 15:28:47.710192 7fea40d78700  2 -- 127.0.0.1:7156/1006690 >> 127.0.0.1:0/6690 conn(0x7fea2c0064d0 sd=15 :7156 s=STATE_ACCEPTING_READY pgs=2 cs=1 l=1).handle_connect_msg accept write reply msg done
  -331> 2015-01-09 15:28:47.710212 7fea41579700  1 Event wakeup
  -330> 2015-01-09 15:28:47.710249 7fea41579700  1 Event wakeup
  -329> 2015-01-09 15:28:47.710377 7fea454947c0  1 Event wakeup
  -328> 2015-01-09 15:28:47.710411 7fea41579700  1 Event wakeup
  -327> 2015-01-09 15:28:47.710422 7fea40d78700  1 -- 127.0.0.1:7156/1006690 >> 127.0.0.1:0/6690 conn(0x7fea2c0064d0 sd=15 :7156 s=STATE_OPEN pgs=2 cs=1 l=1).read_bulk Peer close file descriptor 15
  -326> 2015-01-09 15:28:47.710431 7fea454947c0  1 -- 127.0.0.1:7156/1006690 mark_down_all 
  -325> 2015-01-09 15:28:47.710435 7fea454947c0  5 -- 127.0.0.1:7156/1006690 mark_down_all mark down 127.0.0.1:0/6690 0x7fea2c0064d0
  -324> 2015-01-09 15:28:47.710435 7fea40d78700  1 -- 127.0.0.1:7156/1006690 >> 127.0.0.1:0/6690 conn(0x7fea2c0064d0 sd=15 :7156 s=STATE_OPEN pgs=2 cs=1 l=1).process read tag failed, state is STATE_OPEN
  -323> 2015-01-09 15:28:47.710441 7fea454947c0  1 Event wakeup
  -322> 2015-01-09 15:28:47.710441 7fea40d78700  1 Event wakeup
  -321> 2015-01-09 15:28:47.710468 7fea40d78700  1 Event wakeup
  -320> 2015-01-09 15:28:47.710473 7fea40d78700  1 Event wakeup
  -319> 2015-01-09 15:28:47.710512 7fea454947c0  5 -- 127.0.0.1:7156/1006690 mark_down_all delete 0x7fea2c0064d0
  -318> 2015-01-09 15:28:47.710541 7fea454947c0  1 -- 127.0.0.1:7156/1006690 mark_down_all 
  -317> 2015-01-09 15:28:47.710547 7fea454947c0  1 -- 127.0.0.1:7156/1006690 wait complete.
  -316> 2015-01-09 15:28:47.710550 7fea454947c0  1 Event wakeup
  -315> 2015-01-09 15:28:47.710556 7fea454947c0  1 Event wakeup
  -314> 2015-01-09 15:28:47.710591 7fea454947c0  1 -- 127.0.0.1:0/6690 mark_down_all 
  -313> 2015-01-09 15:28:47.710592 7fea41579700 -1 net_handler: generic_connect connect: %s Connection refused
  -312> 2015-01-09 15:28:47.710597 7fea454947c0  5 -- 127.0.0.1:0/6690 mark_down_all mark down 127.0.0.1:7146/6690 0x3eb9260
  -311> 2015-01-09 15:28:47.710609 7fea454947c0  1 Event wakeup
  -310> 2015-01-09 15:28:47.710617 7fea41579700  1 Event wakeup
  -309> 2015-01-09 15:28:47.710638 7fea41579700 -1 net_handler: generic_connect connect: %s Connection refused
  -308> 2015-01-09 15:28:47.710656 7fea41579700 -1 net_handler: generic_connect connect: %s Connection refused
  -307> 2015-01-09 15:28:47.710655 7fea454947c0  5 -- 127.0.0.1:0/6690 mark_down_all mark down 127.0.0.1:7156/1006690 0x3ebf8f0
  -306> 2015-01-09 15:28:47.710660 7fea454947c0  1 Event wakeup
  -305> 2015-01-09 15:28:47.710670 7fea41579700 -1 net_handler: generic_connect connect: %s Connection refused
  -304> 2015-01-09 15:28:47.710684 7fea41579700 -1 net_handler: generic_connect connect: %s Connection refused
  -303> 2015-01-09 15:28:47.710697 7fea41579700 -1 net_handler: generic_connect connect: %s Connection refused
  -302> 2015-01-09 15:28:47.710704 7fea41579700  1 Event wakeup
  -301> 2015-01-09 15:28:47.710731 7fea454947c0  5 -- 127.0.0.1:0/6690 mark_down_all delete 0x3eb9260
  -300> 2015-01-09 15:28:47.710737 7fea454947c0  5 -- 127.0.0.1:0/6690 mark_down_all delete 0x3ebf8f0
  -299> 2015-01-09 15:28:47.710742 7fea454947c0  1 -- 127.0.0.1:0/6690 mark_down_all 
  -298> 2015-01-09 15:28:47.710746 7fea454947c0  1 -- 127.0.0.1:0/6690 wait complete.
  -297> 2015-01-09 15:28:47.710934 7fea454947c0  1 -- 127.0.0.1:0/0 learned my addr 127.0.0.1:0/0
  -296> 2015-01-09 15:28:47.710941 7fea454947c0  1 accepter.accepter.bind my_inst.addr is 127.0.0.1:7147/6690 need_addr=0
  -295> 2015-01-09 15:28:47.711088 7fea454947c0  1 accepter.accepter.start
  -294> 2015-01-09 15:28:47.711101 7fea454947c0  1 -- 127.0.0.1:7147/6690 messenger.start
  -293> 2015-01-09 15:28:47.711130 7fea454947c0  1 -- :/0 messenger.start
  -292> 2015-01-09 15:28:47.711211 7fea454947c0  1 -- :/6690 --> 127.0.0.1:7147/6690 -- ping magic: 0 v1 -- ?+0 0x3ec7eb0 con 0x3ecc300
  -291> 2015-01-09 15:28:47.711356 7fea40577700  1 -- 127.0.0.1:7147/6690 >> :/0 pipe(0x7fea2c00c090 sd=15 :7147 s=0 pgs=0 cs=0 l=0 c=0x7fea2c010330).accept sd=15 127.0.0.1:52720/0
  -290> 2015-01-09 15:28:47.711365 7fea4542e700  1 -- 127.0.0.1:0/6690 learned my addr 127.0.0.1:0/6690
  -289> 2015-01-09 15:28:47.711558 7fea40577700  1 -- 127.0.0.1:7147/6690 <== client.? 127.0.0.1:0/6690 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x7fea24000f30 con 0x7fea2c010330
  -288> 2015-01-09 15:28:47.711590 7fea40577700  1 -- 127.0.0.1:7147/6690 --> 127.0.0.1:0/6690 -- ping magic: 0 v1 -- ?+0 0x7fea240011b0 con 0x7fea2c010330
  -287> 2015-01-09 15:28:47.711641 7fea40375700  1 -- 127.0.0.1:0/6690 <== osd.0 127.0.0.1:7147/6690 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x7fea200008c0 con 0x3ecc300
  -286> 2015-01-09 15:28:47.711686 7fea454947c0  1 -- 127.0.0.1:7147/6690 rebind avoid 7147,7148,7149,7150,7151,7152,7153,7154,7155,7156
  -285> 2015-01-09 15:28:47.711727 7fea454947c0  1 -- 127.0.0.1:7147/6690 mark_down_all
  -284> 2015-01-09 15:28:47.711731 7fea454947c0  5 -- 127.0.0.1:7147/6690 mark_down_all 127.0.0.1:0/6690 0x7fea2c00c090
  -283> 2015-01-09 15:28:47.711761 7fea454947c0  1 accepter.accepter.rebind avoid 7147,7148,7149,7150,7151,7152,7153,7154,7155,7156
  -282> 2015-01-09 15:28:47.711764 7fea40375700  2 -- 127.0.0.1:0/6690 >> 127.0.0.1:7147/6690 pipe(0x3ec8060 sd=14 :52720 s=2 pgs=1 cs=1 l=1 c=0x3ecc300).reader couldn't read tag, (0) Success
  -281> 2015-01-09 15:28:47.711767 7fea40577700  2 -- 127.0.0.1:7147/1006690 >> 127.0.0.1:0/6690 pipe(0x7fea2c00c090 sd=15 :7147 s=4 pgs=1 cs=1 l=1 c=0x7fea2c010330).reader couldn't read tag, (0) Success
  -280> 2015-01-09 15:28:47.711790 7fea40375700  2 -- 127.0.0.1:0/6690 >> 127.0.0.1:7147/6690 pipe(0x3ec8060 sd=14 :52720 s=2 pgs=1 cs=1 l=1 c=0x3ecc300).fault (0) Success
  -279> 2015-01-09 15:28:47.711794 7fea40577700  2 -- 127.0.0.1:7147/1006690 >> 127.0.0.1:0/6690 pipe(0x7fea2c00c090 sd=15 :7147 s=4 pgs=1 cs=1 l=1 c=0x7fea2c010330).fault (0) Success
  -278> 2015-01-09 15:28:47.711924 7fea454947c0  1 accepter.accepter.bind my_inst.addr is 127.0.0.1:7157/1006690 need_addr=0
  -277> 2015-01-09 15:28:47.711929 7fea454947c0  1 accepter.accepter.start
  -276> 2015-01-09 15:28:47.711951 7fea454947c0  1 -- 127.0.0.1:0/6690 --> 127.0.0.1:7157/1006690 -- ping magic: 0 v1 -- ?+0 0x3ecc5e0 con 0x3ecc470
  -275> 2015-01-09 15:28:47.712038 7fea4542e700  1 -- 127.0.0.1:7157/1006690 >> :/0 pipe(0x7fea1c000f50 sd=15 :7157 s=0 pgs=0 cs=0 l=0 c=0x7fea1c000b90).accept sd=15 127.0.0.1:44207/0
  -274> 2015-01-09 15:28:47.712143 7fea4542e700  1 -- 127.0.0.1:7157/1006690 <== client.? 127.0.0.1:0/6690 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x7fea20001520 con 0x7fea1c000b90
  -273> 2015-01-09 15:28:47.712172 7fea4542e700  1 -- 127.0.0.1:7157/1006690 --> 127.0.0.1:0/6690 -- ping magic: 0 v1 -- ?+0 0x7fea200016d0 con 0x7fea1c000b90
  -272> 2015-01-09 15:28:47.712211 7fea40476700  1 -- 127.0.0.1:0/6690 <== osd.0 127.0.0.1:7157/1006690 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x7fea2c0104a0 con 0x3ecc470
  -271> 2015-01-09 15:28:47.712246 7fea454947c0  1 -- 127.0.0.1:0/6690 mark_down 0x3ecc470 -- 0x3ecdbf0
  -270> 2015-01-09 15:28:47.712266 7fea454947c0  1 -- 127.0.0.1:7157/1006690 mark_down_all
  -269> 2015-01-09 15:28:47.712265 7fea4542e700  2 -- 127.0.0.1:7157/1006690 >> 127.0.0.1:0/6690 pipe(0x7fea1c000f50 sd=15 :7157 s=2 pgs=2 cs=1 l=1 c=0x7fea1c000b90).reader couldn't read tag, (0) Success
  -268> 2015-01-09 15:28:47.712269 7fea454947c0  5 -- 127.0.0.1:7157/1006690 mark_down_all 127.0.0.1:0/6690 0x7fea1c000f50
  -267> 2015-01-09 15:28:47.712275 7fea4542e700  2 -- 127.0.0.1:7157/1006690 >> 127.0.0.1:0/6690 pipe(0x7fea1c000f50 sd=15 :7157 s=2 pgs=2 cs=1 l=1 c=0x7fea1c000b90).fault (0) Success
  -266> 2015-01-09 15:28:47.712274 7fea40476700  2 -- 127.0.0.1:0/6690 >> 127.0.0.1:7157/1006690 pipe(0x3ecdbf0 sd=14 :44207 s=4 pgs=2 cs=1 l=1 c=0x3ecc470).reader couldn't read tag, (0) Success
  -265> 2015-01-09 15:28:47.712290 7fea40476700  2 -- 127.0.0.1:0/6690 >> 127.0.0.1:7157/1006690 pipe(0x3ecdbf0 sd=14 :44207 s=4 pgs=2 cs=1 l=1 c=0x3ecc470).fault (0) Success
  -264> 2015-01-09 15:28:47.712496 7fea454947c0  1 -- 127.0.0.1:7157/1006690 shutdown complete.
  -263> 2015-01-09 15:28:47.712502 7fea454947c0  1 -- 127.0.0.1:0/6690 --> 127.0.0.1:7157/1006690 -- ping magic: 0 v1 -- ?+0 0x3ecc930 con 0x3ecc470
  -262> 2015-01-09 15:28:47.712509 7fea454947c0  0 -- 127.0.0.1:0/6690 submit_message ping magic: 0 v1 remote, 127.0.0.1:7157/1006690, failed lossy con, dropping message 0x3ecc930
  -261> 2015-01-09 15:28:47.712517 7fea454947c0  1 -- 127.0.0.1:0/6690 --> 127.0.0.1:0/6690 -- ping magic: 0 v1 -- ?+0 0x3ecc930 con 0x3ec71f0
  -260> 2015-01-09 15:28:47.712536 7fea29ffb700  1 -- 127.0.0.1:0/6690 <== client.? 127.0.0.1:0/6690 0 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x3ecc930 con 0x3ec71f0
  -259> 2015-01-09 15:28:47.712581 7fea454947c0  1 -- 127.0.0.1:0/6690 mark_down_all
  -258> 2015-01-09 15:28:47.712641 7fea454947c0  1 -- 127.0.0.1:0/6690 shutdown complete.
  -257> 2015-01-09 15:28:47.712686 7fea454947c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -256> 2015-01-09 15:28:47.712688 7fea454947c0 -1 Please be aware that this feature is experimental, untested,
  -255> 2015-01-09 15:28:47.712689 7fea454947c0 -1 unsupported, and may result in data corruption, data loss,
  -254> 2015-01-09 15:28:47.712690 7fea454947c0 -1 and/or irreparable damage to your cluster.  Do not use
  -253> 2015-01-09 15:28:47.712691 7fea454947c0 -1 feature with important data.
  -252> 2015-01-09 15:28:47.712707 7fea454947c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -251> 2015-01-09 15:28:47.712708 7fea454947c0 -1 Please be aware that this feature is experimental, untested,
  -250> 2015-01-09 15:28:47.712709 7fea454947c0 -1 unsupported, and may result in data corruption, data loss,
  -249> 2015-01-09 15:28:47.712710 7fea454947c0 -1 and/or irreparable damage to your cluster.  Do not use
  -248> 2015-01-09 15:28:47.712710 7fea454947c0 -1 feature with important data.
  -247> 2015-01-09 15:28:47.712892 7fea454947c0  1 -- 127.0.0.1:0/0 learned_addr learned my addr 127.0.0.1:0/0
  -246> 2015-01-09 15:28:47.712898 7fea454947c0  1  Processor -- bind bind my_inst.addr is 127.0.0.1:7147/6690
  -245> 2015-01-09 15:28:47.712903 7fea454947c0  1  Processor -- start start
  -244> 2015-01-09 15:28:47.712915 7fea454947c0  1 -- 127.0.0.1:7147/6690 start start
  -243> 2015-01-09 15:28:47.712918 7fea454947c0  1  Processor -- start start
  -242> 2015-01-09 15:28:47.712919 7fea454947c0  1 -- :/0 start start
  -241> 2015-01-09 15:28:47.712955 7fea454947c0  1 Event wakeup
  -240> 2015-01-09 15:28:47.713024 7fea297fa700  1 Event wakeup
  -239> 2015-01-09 15:28:47.713041 7fea40d78700  1 -- 127.0.0.1:7147/6690 >> :/0 conn(0x7fea1c000e10 sd=15 :7147 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:52722/0
  -238> 2015-01-09 15:28:47.713097 7fea41579700  1 -- 127.0.0.1:0/6690 learned_addr learned my addr 127.0.0.1:0/6690
  -237> 2015-01-09 15:28:47.713137 7fea40d78700  1 Event wakeup
  -236> 2015-01-09 15:28:47.713153 7fea40d78700  2 -- 127.0.0.1:7147/6690 >> 127.0.0.1:0/6690 conn(0x7fea1c000e10 sd=15 :7147 s=STATE_ACCEPTING_READY pgs=1 cs=1 l=1).handle_connect_msg accept write reply msg done
  -235> 2015-01-09 15:28:47.713170 7fea41579700  1 Event wakeup
  -234> 2015-01-09 15:28:47.713197 7fea41579700  1 Event wakeup
  -233> 2015-01-09 15:28:47.713273 7fea454947c0  1 -- 127.0.0.1:7147/6690 mark_down_all 
  -232> 2015-01-09 15:28:47.713278 7fea454947c0  5 -- 127.0.0.1:7147/6690 mark_down_all mark down 127.0.0.1:0/6690 0x7fea1c000e10
  -231> 2015-01-09 15:28:47.713283 7fea454947c0  1 Event wakeup
  -230> 2015-01-09 15:28:47.713301 7fea40d78700  1 Event wakeup
  -229> 2015-01-09 15:28:47.713300 7fea41579700  1 -- 127.0.0.1:0/6690 >> 127.0.0.1:7147/6690 conn(0x3ed6ab0 sd=14 :-1 s=STATE_OPEN pgs=1 cs=1 l=1).read_bulk Peer close file descriptor 14
  -228> 2015-01-09 15:28:47.713306 7fea41579700  1 -- 127.0.0.1:0/6690 >> 127.0.0.1:7147/6690 conn(0x3ed6ab0 sd=14 :-1 s=STATE_OPEN pgs=1 cs=1 l=1).process read tag failed, state is STATE_OPEN
  -227> 2015-01-09 15:28:47.713311 7fea41579700  1 Event wakeup
  -226> 2015-01-09 15:28:47.713321 7fea454947c0  5 -- 127.0.0.1:7147/6690 mark_down_all delete 0x7fea1c000e10
  -225> 2015-01-09 15:28:47.713330 7fea41579700  1 Event wakeup
  -224> 2015-01-09 15:28:47.713344 7fea454947c0  1 -- 127.0.0.1:0/6690 mark_down_all 
  -223> 2015-01-09 15:28:47.713348 7fea454947c0  5 -- 127.0.0.1:0/6690 mark_down_all mark down 127.0.0.1:7147/6690 0x3ed6ab0
  -222> 2015-01-09 15:28:47.713353 7fea454947c0  1 Event wakeup
  -221> 2015-01-09 15:28:47.713361 7fea41579700  1 Event wakeup
  -220> 2015-01-09 15:28:47.713376 7fea454947c0  5 -- 127.0.0.1:0/6690 mark_down_all delete 0x3ed6ab0
  -219> 2015-01-09 15:28:47.713380 7fea454947c0  1 -- 127.0.0.1:7147/6690 mark_down_all 
  -218> 2015-01-09 15:28:47.713384 7fea454947c0  1 -- 127.0.0.1:7147/6690 wait complete.
  -217> 2015-01-09 15:28:47.713388 7fea454947c0  1 -- 127.0.0.1:0/6690 mark_down_all 
  -216> 2015-01-09 15:28:47.713391 7fea454947c0  1 -- 127.0.0.1:0/6690 wait complete.
  -215> 2015-01-09 15:28:47.713544 7fea454947c0  1 -- 127.0.0.1:0/0 learned my addr 127.0.0.1:0/0
  -214> 2015-01-09 15:28:47.713550 7fea454947c0  1 accepter.accepter.bind my_inst.addr is 127.0.0.1:7148/6690 need_addr=0
  -213> 2015-01-09 15:28:47.713566 7fea454947c0  1 accepter.accepter.start
  -212> 2015-01-09 15:28:47.713574 7fea454947c0  1 -- 127.0.0.1:7148/6690 messenger.start
  -211> 2015-01-09 15:28:47.713721 7fea454947c0  1 -- :/0 messenger.start
  -210> 2015-01-09 15:28:47.713775 7fea454947c0  1 -- :/6690 --> 127.0.0.1:7148/6690 -- ping magic: 0 v1 -- ?+0 0x3edc3e0 con 0x3ee0830
  -209> 2015-01-09 15:28:47.713859 7fea4542e700  1 -- 127.0.0.1:0/6690 learned my addr 127.0.0.1:0/6690
  -208> 2015-01-09 15:28:47.713860 7fea40577700  1 -- 127.0.0.1:7148/6690 >> :/0 pipe(0x7fea1c006900 sd=15 :7148 s=0 pgs=0 cs=0 l=0 c=0x7fea1c00aba0).accept sd=15 127.0.0.1:34696/0
  -207> 2015-01-09 15:28:47.713978 7fea40577700  1 -- 127.0.0.1:7148/6690 <== client.? 127.0.0.1:0/6690 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x7fea20001f40 con 0x7fea1c00aba0
  -206> 2015-01-09 15:28:47.714008 7fea40577700  1 -- 127.0.0.1:7148/6690 --> 127.0.0.1:0/6690 -- ping magic: 0 v1 -- ?+0 0x7fea200020f0 con 0x7fea1c00aba0
  -205> 2015-01-09 15:28:47.714048 7fea40375700  1 -- 127.0.0.1:0/6690 <== osd.0 127.0.0.1:7148/6690 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x7fea240014b0 con 0x3ee0830
  -204> 2015-01-09 15:28:47.714083 7fea454947c0  1 -- 127.0.0.1:7148/6690 mark_down_all
  -203> 2015-01-09 15:28:47.714087 7fea454947c0  5 -- 127.0.0.1:7148/6690 mark_down_all 127.0.0.1:0/6690 0x7fea1c006900
  -202> 2015-01-09 15:28:47.714122 7fea454947c0  1 -- 127.0.0.1:0/6690 mark_down_all
  -201> 2015-01-09 15:28:47.714116 7fea40375700  2 -- 127.0.0.1:0/6690 >> 127.0.0.1:7148/6690 pipe(0x3edc590 sd=14 :34696 s=2 pgs=1 cs=1 l=1 c=0x3ee0830).reader couldn't read tag, (0) Success
  -200> 2015-01-09 15:28:47.714129 7fea454947c0  5 -- 127.0.0.1:0/6690 mark_down_all 127.0.0.1:7148/6690 0x3edc590
  -199> 2015-01-09 15:28:47.714126 7fea40577700  2 -- 127.0.0.1:7148/6690 >> 127.0.0.1:0/6690 pipe(0x7fea1c006900 sd=15 :7148 s=4 pgs=1 cs=1 l=1 c=0x7fea1c00aba0).reader couldn't read tag, (0) Success
  -198> 2015-01-09 15:28:47.714137 7fea40375700  2 -- 127.0.0.1:0/6690 >> 127.0.0.1:7148/6690 pipe(0x3edc590 sd=14 :34696 s=2 pgs=1 cs=1 l=1 c=0x3ee0830).fault (0) Success
  -197> 2015-01-09 15:28:47.714139 7fea40577700  2 -- 127.0.0.1:7148/6690 >> 127.0.0.1:0/6690 pipe(0x7fea1c006900 sd=15 :7148 s=4 pgs=1 cs=1 l=1 c=0x7fea1c00aba0).fault (0) Success
  -196> 2015-01-09 15:28:47.714186 7fea454947c0  1 -- 127.0.0.1:7148/6690 shutdown complete.
  -195> 2015-01-09 15:28:47.714358 7fea454947c0  1 -- 127.0.0.1:0/6690 shutdown complete.
  -194> 2015-01-09 15:28:47.714397 7fea454947c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -193> 2015-01-09 15:28:47.714400 7fea454947c0 -1 Please be aware that this feature is experimental, untested,
  -192> 2015-01-09 15:28:47.714401 7fea454947c0 -1 unsupported, and may result in data corruption, data loss,
  -191> 2015-01-09 15:28:47.714401 7fea454947c0 -1 and/or irreparable damage to your cluster.  Do not use
  -190> 2015-01-09 15:28:47.714402 7fea454947c0 -1 feature with important data.
  -189> 2015-01-09 15:28:47.714419 7fea454947c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -188> 2015-01-09 15:28:47.714421 7fea454947c0 -1 Please be aware that this feature is experimental, untested,
  -187> 2015-01-09 15:28:47.714421 7fea454947c0 -1 unsupported, and may result in data corruption, data loss,
  -186> 2015-01-09 15:28:47.714422 7fea454947c0 -1 and/or irreparable damage to your cluster.  Do not use
  -185> 2015-01-09 15:28:47.714423 7fea454947c0 -1 feature with important data.
  -184> 2015-01-09 15:28:47.714604 7fea454947c0  1 -- 127.0.0.1:0/0 learned_addr learned my addr 127.0.0.1:0/0
  -183> 2015-01-09 15:28:47.714610 7fea454947c0  1  Processor -- bind bind my_inst.addr is 127.0.0.1:7148/6690
  -182> 2015-01-09 15:28:47.714615 7fea454947c0  1  Processor -- start start
  -181> 2015-01-09 15:28:47.714626 7fea454947c0  1 -- 127.0.0.1:7148/6690 start start
  -180> 2015-01-09 15:28:47.714630 7fea454947c0  1  Processor -- start start
  -179> 2015-01-09 15:28:47.714631 7fea454947c0  1 -- :/0 start start
  -178> 2015-01-09 15:28:47.714670 7fea454947c0  1 Event wakeup
  -177> 2015-01-09 15:28:47.714677 7fea454947c0  1 -- :/6690 mark_down_all 
  -176> 2015-01-09 15:28:47.714679 7fea454947c0  5 -- :/6690 mark_down_all mark down 127.0.0.1:7148/6690 0x3eeae90
  -175> 2015-01-09 15:28:47.714685 7fea454947c0  1 Event wakeup
  -174> 2015-01-09 15:28:47.714723 7fea41579700  1 Event wakeup
  -173> 2015-01-09 15:28:47.714722 7fea2b7fe700  1 Event wakeup
  -172> 2015-01-09 15:28:47.714744 7fea454947c0  5 -- :/6690 mark_down_all delete 0x3eeae90
  -171> 2015-01-09 15:28:47.714748 7fea454947c0  1 -- :/6690 mark_down_all 
  -170> 2015-01-09 15:28:47.714751 7fea454947c0  1 -- :/6690 wait complete.
  -169> 2015-01-09 15:28:47.714755 7fea454947c0  1 -- :/6690 start start
  -168> 2015-01-09 15:28:47.714755 7fea40d78700  1 -- 127.0.0.1:7148/6690 >> :/0 conn(0x7fea24001880 sd=15 :7148 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:34697/0
  -167> 2015-01-09 15:28:47.714783 7fea40d78700  1 -- 127.0.0.1:7148/6690 >> :/0 conn(0x7fea24001880 sd=15 :7148 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).read_bulk Peer close file descriptor 15
  -166> 2015-01-09 15:28:47.714788 7fea454947c0  1 Event wakeup
  -165> 2015-01-09 15:28:47.714789 7fea40d78700  1 -- 127.0.0.1:7148/6690 >> :/0 conn(0x7fea24001880 sd=15 :7148 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).read_until read failed, state is STATE_ACCEPTING_WAIT_BANNER_ADDR
  -164> 2015-01-09 15:28:47.714795 7fea40d78700  1 -- 127.0.0.1:7148/6690 >> :/0 conn(0x7fea24001880 sd=15 :7148 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0)._process_connection read peer banner and addr failed
  -163> 2015-01-09 15:28:47.714801 7fea40d78700  0 -- 127.0.0.1:7148/6690 >> :/0 conn(0x7fea24001880 sd=15 :7148 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).fault server, going to standby
  -162> 2015-01-09 15:28:47.714833 7fea2b7fe700  1 Event wakeup
  -161> 2015-01-09 15:28:47.714857 7fea40d78700  1 -- 127.0.0.1:7148/6690 >> :/0 conn(0x7fea24007390 sd=16 :7148 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=16 127.0.0.1:34698/0
  -160> 2015-01-09 15:28:47.714891 7fea41579700  1 -- 127.0.0.1:0/6690 learned_addr learned my addr 127.0.0.1:0/6690
  -159> 2015-01-09 15:28:47.714934 7fea40d78700  1 Event wakeup
  -158> 2015-01-09 15:28:47.714951 7fea41579700  1 Event wakeup
  -157> 2015-01-09 15:28:47.714948 7fea40d78700  2 -- 127.0.0.1:7148/6690 >> 127.0.0.1:0/6690 conn(0x7fea24007390 sd=16 :7148 s=STATE_ACCEPTING_READY pgs=2 cs=1 l=1).handle_connect_msg accept write reply msg done
  -156> 2015-01-09 15:28:47.714979 7fea41579700  1 Event wakeup
  -155> 2015-01-09 15:28:47.715056 7fea454947c0  1 -- 127.0.0.1:7148/6690 mark_down_all 
  -154> 2015-01-09 15:28:47.715062 7fea454947c0  5 -- 127.0.0.1:7148/6690 mark_down_all accepting_conn 0x7fea24001880
  -153> 2015-01-09 15:28:47.715066 7fea454947c0  1 Event wakeup
  -152> 2015-01-09 15:28:47.715077 7fea40d78700  1 Event wakeup
  -151> 2015-01-09 15:28:47.715096 7fea454947c0  5 -- 127.0.0.1:7148/6690 mark_down_all mark down 127.0.0.1:0/6690 0x7fea24007390
  -150> 2015-01-09 15:28:47.715100 7fea454947c0  1 Event wakeup
  -149> 2015-01-09 15:28:47.715116 7fea40d78700  1 Event wakeup
  -148> 2015-01-09 15:28:47.715115 7fea41579700  1 -- 127.0.0.1:0/6690 >> 127.0.0.1:7148/6690 conn(0x3eef5f0 sd=14 :-1 s=STATE_OPEN pgs=1 cs=1 l=1).read_bulk Peer close file descriptor 14
  -147> 2015-01-09 15:28:47.715123 7fea41579700  1 -- 127.0.0.1:0/6690 >> 127.0.0.1:7148/6690 conn(0x3eef5f0 sd=14 :-1 s=STATE_OPEN pgs=1 cs=1 l=1).process read tag failed, state is STATE_OPEN
  -146> 2015-01-09 15:28:47.715128 7fea41579700  1 Event wakeup
  -145> 2015-01-09 15:28:47.715134 7fea454947c0  5 -- 127.0.0.1:7148/6690 mark_down_all delete 0x7fea24001880
  -144> 2015-01-09 15:28:47.715138 7fea454947c0  5 -- 127.0.0.1:7148/6690 mark_down_all delete 0x7fea24007390
  -143> 2015-01-09 15:28:47.715144 7fea41579700  1 Event wakeup
  -142> 2015-01-09 15:28:47.715163 7fea454947c0  1 -- 127.0.0.1:0/6690 mark_down_all 
  -141> 2015-01-09 15:28:47.715166 7fea454947c0  5 -- 127.0.0.1:0/6690 mark_down_all mark down 127.0.0.1:7148/6690 0x3eef5f0
  -140> 2015-01-09 15:28:47.715173 7fea454947c0  1 Event wakeup
  -139> 2015-01-09 15:28:47.715180 7fea41579700  1 Event wakeup
  -138> 2015-01-09 15:28:47.715195 7fea454947c0  5 -- 127.0.0.1:0/6690 mark_down_all delete 0x3eef5f0
  -137> 2015-01-09 15:28:47.715199 7fea454947c0  1 -- 127.0.0.1:7148/6690 mark_down_all 
  -136> 2015-01-09 15:28:47.715202 7fea454947c0  1 -- 127.0.0.1:7148/6690 wait complete.
  -135> 2015-01-09 15:28:47.715206 7fea454947c0  1 -- 127.0.0.1:0/6690 mark_down_all 
  -134> 2015-01-09 15:28:47.715209 7fea454947c0  1 -- 127.0.0.1:0/6690 wait complete.
  -133> 2015-01-09 15:28:47.715367 7fea454947c0  1 -- 127.0.0.1:0/0 learned my addr 127.0.0.1:0/0
  -132> 2015-01-09 15:28:47.715372 7fea454947c0  1 accepter.accepter.bind my_inst.addr is 127.0.0.1:7149/6690 need_addr=0
  -131> 2015-01-09 15:28:47.715388 7fea454947c0  1 accepter.accepter.start
  -130> 2015-01-09 15:28:47.715396 7fea454947c0  1 -- 127.0.0.1:7149/6690 messenger.start
  -129> 2015-01-09 15:28:47.715425 7fea454947c0  1 -- :/0 messenger.start
  -128> 2015-01-09 15:28:47.715494 7fea454947c0  1 -- :/6690 --> 127.0.0.1:7149/6690 -- ping magic: 0 v1 -- ?+0 0x3ef5c00 con 0x3efa050
  -127> 2015-01-09 15:28:47.715502 7fea454947c0  1 -- :/6690 mark_down_all
  -126> 2015-01-09 15:28:47.715506 7fea454947c0  5 -- :/6690 mark_down_all 127.0.0.1:7149/6690 0x3ef5db0
  -125> 2015-01-09 15:28:47.715532 7fea40375700  2 -- :/6690 >> 127.0.0.1:7149/6690 pipe(0x3ef5db0 sd=14 :0 s=4 pgs=0 cs=0 l=1 c=0x3efa050).connect couldn't read banner, (0) Success
  -124> 2015-01-09 15:28:47.715549 7fea40375700  3 -- :/6690 >> 127.0.0.1:7149/6690 pipe(0x3ef5db0 sd=14 :0 s=4 pgs=0 cs=0 l=1 c=0x3efa050).connect fault, but state = closed != connecting, stopping
  -123> 2015-01-09 15:28:47.715573 7fea454947c0  1 -- :/6690 shutdown complete.
  -122> 2015-01-09 15:28:47.715579 7fea454947c0  1 -- :/6690 messenger.start
  -121> 2015-01-09 15:28:47.715571 7fea4542e700  0 -- 127.0.0.1:7149/6690 >> :/0 pipe(0x7fea2400cf50 sd=15 :7149 s=0 pgs=0 cs=0 l=0 c=0x7fea240111f0).accept failed to getpeername (107) Transport endpoint is not connected
  -120> 2015-01-09 15:28:47.715590 7fea4542e700  2 -- 127.0.0.1:7149/6690 >> :/0 pipe(0x7fea2400cf50 sd=15 :7149 s=4 pgs=0 cs=0 l=0 c=0x7fea240111f0).fault (107) Transport endpoint is not connected
  -119> 2015-01-09 15:28:47.715642 7fea454947c0  1 -- :/6690 --> 127.0.0.1:7149/6690 -- ping magic: 0 v1 -- ?+0 0x3efa010 con 0x3ef9ea0
  -118> 2015-01-09 15:28:47.715706 7fea4542e700  1 -- 127.0.0.1:0/6690 learned my addr 127.0.0.1:0/6690
  -117> 2015-01-09 15:28:47.715704 7fea40375700  1 -- 127.0.0.1:7149/6690 >> :/0 pipe(0x7fea2400cf50 sd=15 :7149 s=0 pgs=0 cs=0 l=0 c=0x7fea240111f0).accept sd=15 127.0.0.1:45383/0
  -116> 2015-01-09 15:28:47.715825 7fea40375700  1 -- 127.0.0.1:7149/6690 <== client.? 127.0.0.1:0/6690 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x7fea1c006d50 con 0x7fea240111f0
  -115> 2015-01-09 15:28:47.715855 7fea40375700  1 -- 127.0.0.1:7149/6690 --> 127.0.0.1:0/6690 -- ping magic: 0 v1 -- ?+0 0x7fea1c0070b0 con 0x7fea240111f0
  -114> 2015-01-09 15:28:47.715887 7fea40476700  1 -- 127.0.0.1:0/6690 <== osd.0 127.0.0.1:7149/6690 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x7fea2c010a40 con 0x3ef9ea0
  -113> 2015-01-09 15:28:47.715922 7fea454947c0  1 -- 127.0.0.1:7149/6690 mark_down_all
  -112> 2015-01-09 15:28:47.715927 7fea454947c0  5 -- 127.0.0.1:7149/6690 mark_down_all 127.0.0.1:0/6690 0x7fea2400cf50
  -111> 2015-01-09 15:28:47.715943 7fea40476700  2 -- 127.0.0.1:0/6690 >> 127.0.0.1:7149/6690 pipe(0x3ef5c00 sd=14 :45383 s=2 pgs=1 cs=1 l=1 c=0x3ef9ea0).reader couldn't read tag, (0) Success
  -110> 2015-01-09 15:28:47.715954 7fea40476700  2 -- 127.0.0.1:0/6690 >> 127.0.0.1:7149/6690 pipe(0x3ef5c00 sd=14 :45383 s=2 pgs=1 cs=1 l=1 c=0x3ef9ea0).fault (0) Success
  -109> 2015-01-09 15:28:47.715966 7fea454947c0  1 -- 127.0.0.1:0/6690 mark_down_all
  -108> 2015-01-09 15:28:47.715989 7fea40375700  2 -- 127.0.0.1:7149/6690 >> 127.0.0.1:0/6690 pipe(0x7fea2400cf50 sd=15 :7149 s=4 pgs=2 cs=1 l=1 c=0x7fea240111f0).reader couldn't read tag, (0) Success
  -107> 2015-01-09 15:28:47.716000 7fea40375700  2 -- 127.0.0.1:7149/6690 >> 127.0.0.1:0/6690 pipe(0x7fea2400cf50 sd=15 :7149 s=4 pgs=2 cs=1 l=1 c=0x7fea240111f0).fault (0) Success
  -106> 2015-01-09 15:28:47.716030 7fea454947c0  1 -- 127.0.0.1:7149/6690 shutdown complete.
  -105> 2015-01-09 15:28:47.716044 7fea454947c0  1 -- 127.0.0.1:0/6690 shutdown complete.
  -104> 2015-01-09 15:28:47.716081 7fea454947c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -103> 2015-01-09 15:28:47.716083 7fea454947c0 -1 Please be aware that this feature is experimental, untested,
  -102> 2015-01-09 15:28:47.716084 7fea454947c0 -1 unsupported, and may result in data corruption, data loss,
  -101> 2015-01-09 15:28:47.716085 7fea454947c0 -1 and/or irreparable damage to your cluster.  Do not use
  -100> 2015-01-09 15:28:47.716085 7fea454947c0 -1 feature with important data.
   -99> 2015-01-09 15:28:47.716097 7fea454947c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
   -98> 2015-01-09 15:28:47.716097 7fea454947c0 -1 Please be aware that this feature is experimental, untested,
   -97> 2015-01-09 15:28:47.716098 7fea454947c0 -1 unsupported, and may result in data corruption, data loss,
   -96> 2015-01-09 15:28:47.716098 7fea454947c0 -1 and/or irreparable damage to your cluster.  Do not use
   -95> 2015-01-09 15:28:47.716099 7fea454947c0 -1 feature with important data.
   -94> 2015-01-09 15:28:47.716224 7fea454947c0  1 -- 127.0.0.1:0/0 learned_addr learned my addr 127.0.0.1:0/0
   -93> 2015-01-09 15:28:47.716229 7fea454947c0  1  Processor -- bind bind my_inst.addr is 127.0.0.1:7149/6690
   -92> 2015-01-09 15:28:47.716231 7fea454947c0  1  Processor -- start start
   -91> 2015-01-09 15:28:47.716241 7fea454947c0  1 -- 127.0.0.1:7149/6690 start start
   -90> 2015-01-09 15:28:47.716245 7fea454947c0  1  Processor -- start start
   -89> 2015-01-09 15:28:47.716245 7fea454947c0  1 -- :/0 start start
   -88> 2015-01-09 15:28:47.716277 7fea454947c0  1 Event wakeup
   -87> 2015-01-09 15:28:47.716328 7fea297fa700  1 Event wakeup
   -86> 2015-01-09 15:28:47.716345 7fea40d78700  1 -- 127.0.0.1:7149/6690 >> :/0 conn(0x7fea1c00afb0 sd=15 :7149 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:45384/0
   -85> 2015-01-09 15:28:47.716389 7fea41579700  1 -- 127.0.0.1:0/6690 learned_addr learned my addr 127.0.0.1:0/6690
   -84> 2015-01-09 15:28:47.716427 7fea40d78700  1 Event wakeup
   -83> 2015-01-09 15:28:47.716443 7fea41579700  1 Event wakeup
   -82> 2015-01-09 15:28:47.716440 7fea40d78700  2 -- 127.0.0.1:7149/6690 >> 127.0.0.1:0/6690 conn(0x7fea1c00afb0 sd=15 :7149 s=STATE_ACCEPTING_READY pgs=1 cs=1 l=0).handle_connect_msg accept write reply msg done
   -81> 2015-01-09 15:28:47.716470 7fea41579700  1 Event wakeup
   -80> 2015-01-09 15:28:47.716541 7fea454947c0  1 Event wakeup
   -79> 2015-01-09 15:28:47.716559 7fea41579700  1 Event wakeup
   -78> 2015-01-09 15:28:47.716557 7fea40d78700  1 -- 127.0.0.1:7149/6690 >> 127.0.0.1:0/6690 conn(0x7fea1c00afb0 sd=15 :7149 s=STATE_OPEN pgs=1 cs=1 l=0).read_bulk Peer close file descriptor 15
   -77> 2015-01-09 15:28:47.716562 7fea40d78700  1 -- 127.0.0.1:7149/6690 >> 127.0.0.1:0/6690 conn(0x7fea1c00afb0 sd=15 :7149 s=STATE_OPEN pgs=1 cs=1 l=0).process read tag failed, state is STATE_OPEN
   -76> 2015-01-09 15:28:47.716576 7fea454947c0  1 Event wakeup
   -75> 2015-01-09 15:28:47.716579 7fea40d78700  0 -- 127.0.0.1:7149/6690 >> 127.0.0.1:0/6690 conn(0x7fea1c00afb0 sd=15 :7149 s=STATE_OPEN pgs=1 cs=1 l=0).fault server, going to standby
   -74> 2015-01-09 15:28:47.716621 7fea297fa700  1 Event wakeup
   -73> 2015-01-09 15:28:47.716635 7fea40d78700  1 -- 127.0.0.1:7149/6690 >> :/0 conn(0x7fea1c00f710 sd=16 :7149 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=16 127.0.0.1:45385/0
   -72> 2015-01-09 15:28:47.716681 7fea40d78700  0 -- 127.0.0.1:7149/6690 >> 127.0.0.1:0/6690 conn(0x7fea1c00f710 sd=16 :7149 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msgaccept connect_seq 0 vs existing 1 state 30
   -71> 2015-01-09 15:28:47.716688 7fea40d78700  0 -- 127.0.0.1:7149/6690 >> 127.0.0.1:0/6690 conn(0x7fea1c00f710 sd=16 :7149 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept peer reset, then tried to connect to us, replacing
   -70> 2015-01-09 15:28:47.716691 7fea40d78700  1 Event wakeup
   -69> 2015-01-09 15:28:47.716708 7fea40d78700  1 Event wakeup
   -68> 2015-01-09 15:28:47.716710 7fea40d78700  1 Event wakeup
   -67> 2015-01-09 15:28:47.716723 7fea40d78700  1 Event wakeup
   -66> 2015-01-09 15:28:47.716747 7fea40d78700  1 Event wakeup
   -65> 2015-01-09 15:28:47.716761 7fea41579700  1 Event wakeup
   -64> 2015-01-09 15:28:47.716759 7fea40d78700  2 -- 127.0.0.1:7149/6690 >> 127.0.0.1:0/6690 conn(0x7fea1c00afb0 sd=16 :7149 s=STATE_ACCEPTING_READY pgs=2 cs=2 l=0).handle_connect_msg accept write reply msg done
   -63> 2015-01-09 15:28:47.716794 7fea41579700  1 Event wakeup
   -62> 2015-01-09 15:28:47.716844 7fea41579700  1 Event wakeup
   -61> 2015-01-09 15:28:47.716871 7fea454947c0  1 Event wakeup
   -60> 2015-01-09 15:28:47.716890 7fea40d78700  1 Event wakeup
   -59> 2015-01-09 15:28:47.716888 7fea41579700  1 -- 127.0.0.1:0/6690 >> 127.0.0.1:7149/6690 conn(0x3f08b80 sd=14 :-1 s=STATE_OPEN pgs=2 cs=2 l=0).read_bulk Peer close file descriptor 14
   -58> 2015-01-09 15:28:47.716895 7fea41579700  1 -- 127.0.0.1:0/6690 >> 127.0.0.1:7149/6690 conn(0x3f08b80 sd=14 :-1 s=STATE_OPEN pgs=2 cs=2 l=0).process read tag failed, state is STATE_OPEN
   -57> 2015-01-09 15:28:47.716911 7fea41579700  0 -- 127.0.0.1:0/6690 >> 127.0.0.1:7149/6690 conn(0x3f08b80 sd=14 :-1 s=STATE_OPEN pgs=2 cs=2 l=0).fault initiating reconnect
   -56> 2015-01-09 15:28:47.716961 7fea297fa700  1 Event wakeup
   -55> 2015-01-09 15:28:47.716978 7fea41579700  1 -- 127.0.0.1:7149/6690 >> :/0 conn(0x7fea1c013e70 sd=15 :7149 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:45386/0
   -54> 2015-01-09 15:28:47.717024 7fea41579700  0 -- 127.0.0.1:7149/6690 >> 127.0.0.1:0/6690 conn(0x7fea1c013e70 sd=15 :7149 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msgaccept we reset (peer sent cseq 3), sending RESETSESSION
   -53> 2015-01-09 15:28:47.717039 7fea41579700  0 -- 127.0.0.1:0/6690 >> 127.0.0.1:7149/6690 conn(0x3f08b80 sd=14 :-1 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=2 cs=3 l=0).handle_connect_replyconnect got RESETSESSION
   -52> 2015-01-09 15:28:47.717043 7fea41579700  1 Event wakeup
   -51> 2015-01-09 15:28:47.717079 7fea41579700  1 Event wakeup
   -50> 2015-01-09 15:28:47.717089 7fea41579700  2 -- 127.0.0.1:7149/6690 >> 127.0.0.1:0/6690 conn(0x7fea1c013e70 sd=15 :7149 s=STATE_ACCEPTING_READY pgs=3 cs=1 l=0).handle_connect_msg accept write reply msg done
   -49> 2015-01-09 15:28:47.717099 7fea41579700  1 Event wakeup
   -48> 2015-01-09 15:28:47.717147 7fea41579700  1 Event wakeup
   -47> 2015-01-09 15:28:47.717209 7fea454947c0  1 -- 127.0.0.1:7149/6690 mark_down_all 
   -46> 2015-01-09 15:28:47.717214 7fea454947c0  5 -- 127.0.0.1:7149/6690 mark_down_all accepting_conn 0x7fea1c00f710
   -45> 2015-01-09 15:28:47.717216 7fea454947c0  1 Event wakeup
   -44> 2015-01-09 15:28:47.717222 7fea40d78700  1 Event wakeup
   -43> 2015-01-09 15:28:47.717238 7fea454947c0  5 -- 127.0.0.1:7149/6690 mark_down_all mark down 127.0.0.1:0/6690 0x7fea1c013e70
   -42> 2015-01-09 15:28:47.717243 7fea454947c0  1 Event wakeup
   -41> 2015-01-09 15:28:47.717256 7fea41579700  1 Event wakeup
   -40> 2015-01-09 15:28:47.717263 7fea41579700  1 -- 127.0.0.1:0/6690 >> 127.0.0.1:7149/6690 conn(0x3f08b80 sd=14 :-1 s=STATE_OPEN pgs=3 cs=1 l=0).read_bulk Peer close file descriptor 14
   -39> 2015-01-09 15:28:47.717270 7fea454947c0  5 -- 127.0.0.1:7149/6690 mark_down_all delete 0x7fea1c00f710
   -38> 2015-01-09 15:28:47.717276 7fea454947c0  5 -- 127.0.0.1:7149/6690 mark_down_all delete 0x7fea1c013e70
   -37> 2015-01-09 15:28:47.717269 7fea41579700  1 -- 127.0.0.1:0/6690 >> 127.0.0.1:7149/6690 conn(0x3f08b80 sd=14 :-1 s=STATE_OPEN pgs=3 cs=1 l=0).process read tag failed, state is STATE_OPEN
   -36> 2015-01-09 15:28:47.717301 7fea454947c0  1 -- 127.0.0.1:0/6690 mark_down_all 
   -35> 2015-01-09 15:28:47.717297 7fea41579700  0 -- 127.0.0.1:0/6690 >> 127.0.0.1:7149/6690 conn(0x3f08b80 sd=14 :-1 s=STATE_OPEN pgs=3 cs=1 l=0).fault initiating reconnect
   -34> 2015-01-09 15:28:47.717304 7fea454947c0  5 -- 127.0.0.1:0/6690 mark_down_all mark down 127.0.0.1:7149/6690 0x3f08b80
   -33> 2015-01-09 15:28:47.717307 7fea454947c0  1 Event wakeup
   -32> 2015-01-09 15:28:47.717329 7fea41579700 -1 net_handler: generic_connect connect: %s Connection refused
   -31> 2015-01-09 15:28:47.717341 7fea41579700  1 Event wakeup
   -30> 2015-01-09 15:28:47.717369 7fea454947c0  5 -- 127.0.0.1:0/6690 mark_down_all delete 0x3f08b80
   -29> 2015-01-09 15:28:47.717373 7fea454947c0  1 -- 127.0.0.1:7149/6690 mark_down_all 
   -28> 2015-01-09 15:28:47.717374 7fea454947c0  1 -- 127.0.0.1:7149/6690 wait complete.
   -27> 2015-01-09 15:28:47.717378 7fea454947c0  1 -- 127.0.0.1:0/6690 mark_down_all 
   -26> 2015-01-09 15:28:47.717379 7fea454947c0  1 -- 127.0.0.1:0/6690 wait complete.
   -25> 2015-01-09 15:28:47.717529 7fea454947c0  1 -- 127.0.0.1:0/0 learned my addr 127.0.0.1:0/0
   -24> 2015-01-09 15:28:47.717534 7fea454947c0  1 accepter.accepter.bind my_inst.addr is 127.0.0.1:7150/6690 need_addr=0
   -23> 2015-01-09 15:28:47.717548 7fea454947c0  1 accepter.accepter.start
   -22> 2015-01-09 15:28:47.717555 7fea454947c0  1 -- 127.0.0.1:7150/6690 messenger.start
   -21> 2015-01-09 15:28:47.717583 7fea454947c0  1 -- :/0 messenger.start
   -20> 2015-01-09 15:28:47.717630 7fea454947c0  1 -- :/6690 --> 127.0.0.1:7150/6690 -- ping magic: 0 v1 -- ?+0 0x3f14760 con 0x3f13540
   -19> 2015-01-09 15:28:47.717714 7fea40476700  1 -- 127.0.0.1:0/6690 learned my addr 127.0.0.1:0/6690
   -18> 2015-01-09 15:28:47.717711 7fea4542e700  1 -- 127.0.0.1:7150/6690 >> :/0 pipe(0x7fea1c0195e0 sd=15 :7150 s=0 pgs=0 cs=0 l=0 c=0x7fea1c007810).accept sd=15 127.0.0.1:57392/0
   -17> 2015-01-09 15:28:47.717818 7fea4542e700  1 -- 127.0.0.1:7150/6690 <== client.? 127.0.0.1:0/6690 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x7fea2400cf50 con 0x7fea1c007810
   -16> 2015-01-09 15:28:47.717842 7fea4542e700  1 -- 127.0.0.1:7150/6690 --> 127.0.0.1:0/6690 -- ping magic: 0 v1 -- ?+0 0x7fea2400d1d0 con 0x7fea1c007810
   -15> 2015-01-09 15:28:47.717884 7fea40577700  1 -- 127.0.0.1:0/6690 <== osd.0 127.0.0.1:7150/6690 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x7fea140008c0 con 0x3f13540
   -14> 2015-01-09 15:28:47.717912 7fea454947c0  1 -- 127.0.0.1:0/6690 mark_down 0x3f13540 -- 0x3f0f2a0
   -13> 2015-01-09 15:28:47.717930 7fea4542e700  2 -- 127.0.0.1:7150/6690 >> 127.0.0.1:0/6690 pipe(0x7fea1c0195e0 sd=15 :7150 s=2 pgs=1 cs=1 l=0 c=0x7fea1c007810).reader couldn't read tag, (0) Success
   -12> 2015-01-09 15:28:47.717933 7fea40577700  2 -- 127.0.0.1:0/6690 >> 127.0.0.1:7150/6690 pipe(0x3f0f2a0 sd=14 :57392 s=4 pgs=1 cs=1 l=0 c=0x3f13540).reader couldn't read tag, (0) Success
   -11> 2015-01-09 15:28:47.717943 7fea4542e700  2 -- 127.0.0.1:7150/6690 >> 127.0.0.1:0/6690 pipe(0x7fea1c0195e0 sd=15 :7150 s=2 pgs=1 cs=1 l=0 c=0x7fea1c007810).fault (0) Success
   -10> 2015-01-09 15:28:47.717942 7fea40577700  2 -- 127.0.0.1:0/6690 >> 127.0.0.1:7150/6690 pipe(0x3f0f2a0 sd=14 :57392 s=4 pgs=1 cs=1 l=0 c=0x3f13540).fault (0) Success
    -9> 2015-01-09 15:28:47.717959 7fea4542e700  0 -- 127.0.0.1:7150/6690 >> 127.0.0.1:0/6690 pipe(0x7fea1c0195e0 sd=15 :7150 s=2 pgs=1 cs=1 l=0 c=0x7fea1c007810).fault, server, going to standby
    -8> 2015-01-09 15:28:47.717985 7fea454947c0  1 -- 127.0.0.1:0/6690 --> 127.0.0.1:7150/6690 -- ping magic: 0 v1 -- ?+0 0x3f13820 con 0x3f136b0
    -7> 2015-01-09 15:28:47.718054 7fea40476700  1 -- 127.0.0.1:7150/6690 >> :/0 pipe(0x7fea1c01e890 sd=16 :7150 s=0 pgs=0 cs=0 l=0 c=0x7fea1c007980).accept sd=16 127.0.0.1:57393/0
    -6> 2015-01-09 15:28:47.718076 7fea40476700  0 -- 127.0.0.1:7150/6690 >> 127.0.0.1:0/6690 pipe(0x7fea1c01e890 sd=16 :7150 s=0 pgs=0 cs=0 l=0 c=0x7fea1c007980).accept connect_seq 0 vs existing 1 state standby
    -5> 2015-01-09 15:28:47.718082 7fea40476700  0 -- 127.0.0.1:7150/6690 >> 127.0.0.1:0/6690 pipe(0x7fea1c01e890 sd=16 :7150 s=0 pgs=0 cs=0 l=0 c=0x7fea1c007980).accept peer reset, then tried to connect to us, replacing
    -4> 2015-01-09 15:28:47.718190 7fea40476700  1 -- 127.0.0.1:7150/6690 <== client.? 127.0.0.1:0/6690 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x7fea20002ed0 con 0x7fea1c007810
    -3> 2015-01-09 15:28:47.718215 7fea40476700  1 -- 127.0.0.1:7150/6690 --> 127.0.0.1:0/6690 -- ping magic: 0 v1 -- ?+0 0x7fea20003080 con 0x7fea1c007810
    -2> 2015-01-09 15:28:47.718239 7fea4542e700  0 -- 127.0.0.1:0/6690 >> 127.0.0.1:7150/6690 pipe(0x3f0f2a0 sd=14 :57393 s=2 pgs=2 cs=1 l=0 c=0x3f136b0).reader missed message?  skipped from seq 0 to 187807877
    -1> 2015-01-09 15:28:47.718249 7fea4542e700  1 -- 127.0.0.1:0/6690 <== osd.0 127.0.0.1:7150/6690 187807877 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x7fea2c011380 con 0x3f136b0
     0> 2015-01-09 15:28:47.763637 7fea454947c0 -1 *** Caught signal (Segmentation fault) **
 in thread 7fea454947c0

 ceph version 0.90-783-g6fd348f (6fd348fe43399a882906646004bf3f5a4cf9dabb)
 1: ./unittest_msgr() [0x85e41a]
 2: (()+0x10340) [0x7fea44e81340]
 3: (MessengerTest_StatefulTest_Test::TestBody()+0xbff) [0x82d06f]
 4: (testing::Test::Run()+0x96) [0x83ce56]
 5: (testing::internal::TestInfoImpl::Run()+0xd8) [0x83d3c0]
 6: (testing::TestCase::Run()+0xcb) [0x83d8c9]
 7: (testing::internal::UnitTestImpl::RunAllTests()+0x26e) [0x841dca]
 8: (testing::UnitTest::Run()+0x1c) [0x840d80]
 9: (main()+0x103) [0x829683]
 10: (__libc_start_main()+0xf5) [0x7fea4359fec5]
 11: ./unittest_msgr() [0x82ad87]
 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 rbd_replay
   0/ 5 journaler
   0/ 5 objectcacher
   0/ 5 client
   0/ 5 osd
   0/ 5 optracker
   0/ 5 objclass
   1/ 3 filestore
   1/ 3 keyvaluestore
   1/ 3 journal
   0/ 5 ms
   1/ 5 mon
   0/10 monc
   1/ 5 paxos
   0/ 5 tp
   1/ 5 auth
   1/ 5 crypto
   1/ 1 finisher
   1/ 5 heartbeatmap
   1/ 5 perfcounter
   1/ 5 rgw
   1/10 civetweb
   1/ 5 javaclient
   1/ 5 asok
   1/ 1 throttle
   0/ 0 refs
  -2/-2 (syslog threshold)
  99/99 (stderr threshold)
  max_recent       500
  max_new         1000
  log_file /home/loic/software/ceph/ceph/src/out/client.admin.6690.log
--- end dump of recent events ---
Segmentation fault (core dumped)

Associated revisions

Revision 55a5c5f2 (diff)
Added by Loic Dachary over 8 years ago

tests: temporarily disable unittest_msgr

http://tracker.ceph.com/issues/10494 Refs: #10494

Signed-off-by: Loic Dachary <ldachary@redhat.com>

History

#1 Updated by Loïc Dachary over 8 years ago

Run with

while valgrind --tool=memcheck ./unittest_msgr ; do : ; done

it provides more information

[ RUN      ] Messenger/MessengerTest.StatefulTest/1
SetUp start set up simple
2015-01-09 15:32:26.877457 9762700 -1 net_handler: generic_connect connect: %s Connection refused
ms_handle_fast_connect0x6e79bc0
ms_handle_fast_connect con: 0x6e79bc0 count: 0
2015-01-09 15:32:26.877622 9762700 -1 net_handler: generic_connect connect: %s Connection refused
2015-01-09 15:32:26.877889 9762700 -1 net_handler: generic_connect connect: %s Connection refused
2015-01-09 15:32:26.878086 9762700 -1 net_handler: generic_connect connect: %s Connection refused
ms_handle_fast_connect0x6e79bc0
2015-01-09 15:32:26.878663 9762700 -1 net_handler: generic_connect connect: %s Connection refused
2015-01-09 15:32:26.878788 9762700 -1 net_handler: generic_connect connect: %s Connection refused
2015-01-09 15:32:26.879379 9762700 -1 net_handler: generic_connect connect: %s Connection refused
ms_handle_fast_connect2015-01-09 15:32:26.879515 9762700 -1 0x6e90270net_handler: generic_connect connect: %s Connection refused
2015-01-09 15:32:26.879841 9762700 -1 net_handler: generic_connect connect: %s Connection refused

ms_handle_fast_connect con: 0x6e90270 count: 0
ms_fast_dispatch conn: 0x6e95d90 session 0x6e99490 count: 0x1
ms_fast_dispatch conn: 0x6e90270 session 0x6e99990 count: 0x1
2015-01-09 15:32:26.891242 4159700  0 -- 127.0.0.1:6832/10669 >> 127.0.0.1:0/10669 pipe(0x6e91ab0 sd=15 :6832 s=2 pgs=1 cs=1 l=0 c=0x6e95d90).fault, server, going to standby
ms_handle_fast_connect0x6ea17d0
2015-01-09 15:32:26.895871 d16b700  0 -- 127.0.0.1:6832/10669 >> 127.0.0.1:0/10669 pipe(0x6ea3180 sd=16 :6832 s=0 pgs=0 cs=0 l=0 c=0x6ea7460).accept connect_seq 0 vs existing 1 state standbyms_handle_fast_connect con: 0x6ea17d0 count: 0
ms_handle_remote_reset
0x6e95d90
ms_fast_dispatch2015-01-09 15:32:26.897578 d16b700  0 ms_handle_reset0x6ea7460
 conn: 0x6e95d90 session 0x6e99490 count: 0x2
-- 127.0.0.1:6832/10669 >> 127.0.0.1:0/10669 pipe(0x6ea3180 sd=16 :6832 s=0 pgs=0 cs=0 l=0 c=0x6ea7460).accept peer reset, then tried to connect to us, replacing
ms_fast_dispatch conn: 0x6ea17d0 session 0x6ead080 count: 0x1
2015-01-09 15:32:26.912691 4159700  0 -- 127.0.0.1:0/10669 >> 127.0.0.1:6832/10669 pipe(0x6e9d4f0 sd=14 :36852 s=2 pgs=2 cs=1 l=0 c=0x6ea17d0).reader missed message?  skipped from seq 0 to 484519424
==10669== Invalid read of size 8
==10669==    at 0x82D06F: MessengerTest_StatefulTest_Test::TestBody() (test_msgr.cc:395)
==10669==    by 0x83CE55: testing::Test::Run() (gtest.cc:2095)
==10669==    by 0x83D3BF: testing::internal::TestInfoImpl::Run() (gtest.cc:2314)
==10669==    by 0x83D8C8: testing::TestCase::Run() (gtest.cc:2420)
==10669==    by 0x841DC9: testing::internal::UnitTestImpl::RunAllTests() (gtest.cc:4024)
==10669==    by 0x840D7F: testing::UnitTest::Run() (gtest.cc:3687)
==10669==    by 0x829682: main (test_msgr.cc:591)
==10669==  Address 0x70 is not stack'd, malloc'd or (recently) free'd
==10669== 
*** Caught signal (Segmentation fault) **
 in thread 40544c0
 ceph version 0.90-783-g6fd348f (6fd348fe43399a882906646004bf3f5a4cf9dabb)
 1: ./unittest_msgr() [0x85e41a]
 2: (()+0x10340) [0x505d340]
 3: (MessengerTest_StatefulTest_Test::TestBody()+0xbff) [0x82d06f]
 4: (testing::Test::Run()+0x96) [0x83ce56]
 5: (testing::internal::TestInfoImpl::Run()+0xd8) [0x83d3c0]
 6: (testing::TestCase::Run()+0xcb) [0x83d8c9]
 7: (testing::internal::UnitTestImpl::RunAllTests()+0x26e) [0x841dca]
 8: (testing::UnitTest::Run()+0x1c) [0x840d80]
 9: (main()+0x103) [0x829683]
 10: (__libc_start_main()+0xf5) [0x67b9ec5]
 11: ./unittest_msgr() [0x82ad87]
2015-01-09 15:32:26.979086 40544c0 -1 *** Caught signal (Segmentation fault) **
 in thread 40544c0

#2 Updated by Loïc Dachary over 8 years ago

Another run fails in a different way:

[ RUN      ] Messenger/MessengerTest.StatelessTest/1
SetUp start set up simple
ms_handle_fast_connect0x6f28ef0
ms_handle_fast_connect con: 0x6f28ef0 count: 0
ms_handle_fast_connect0x6f28ef0
ms_handle_fast_connect0x6f2e070
ms_handle_fast_connect con: 0x6f2e070 count: 0
ms_fast_dispatch conn: 0x6f33b90 session 0x6f37c20 count: 1
ms_fast_dispatch conn: 0x6f2e070 session 0x6f39780 count: 1
2015-01-09 15:40:13.127884 d46e700  0 -- 127.0.0.1:6851/11478 >> 127.0.0.1:0/11478 pipe(0x6f40ce0 sd=17 :6851 s=0 pgs=0 cs=0 l=1 c=0x6f44fc0).accept replacing existing (lossy) channel (new one lossy=1)
ms_handle_remote_reset0x6f33b90
common/Mutex.cc: In function 'Mutex::~Mutex()' thread c768700 time 2015-01-09 15:40:13.137660
common/Mutex.cc: 71: FAILED assert(nlock == 0)
ms_handle_fast_connect0x6f3eea0
ms_handle_fast_connect con: 0x6f3eea0 count: 0
 ceph version 0.90-805-gcf432fa (cf432fa670bf20b66b24255768fe9dffbfe85416)
 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x8b) [0x90f26b]
 2: ./unittest_msgr() [0x8db036]
 3: (FakeDispatcher::Session::~Session()+0x27) [0x831ca7]
 4: (RefCountedObject::put()+0x32) [0x832b72]
 5: (FakeDispatcher::ms_handle_remote_reset(Connection*)+0xef) [0x832f7f]
 6: (DispatchQueue::entry()+0x5ad) [0xa4edfd]
 7: (DispatchQueue::DispatchThread::entry()+0xd) [0x909add]
 8: (()+0x8182) [0x5055182]
 9: (clone()+0x6d) [0x6892fbd]
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
2015-01-09 15:40:13.218562 c768700 -1 common/Mutex.cc: In function 'Mutex::~Mutex()' thread c768700 time 2015-01-09 15:40:13.137660
common/Mutex.cc: 71: FAILED assert(nlock == 0)

#3 Updated by Loïc Dachary over 8 years ago

Another assert

2015-01-09 15:58:10.019278 d46e700  0 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6ecbc20 sd=16 :6976 s=2 pgs=4 cs=1 l=0 c=0x6ecff00).fault with nothing to send, going to standby
msg/simple/SimpleMessenger.cc: In function 'void SimpleMessenger::reaper()' thread 40544c0 time 2015-01-09 15:58:10.022867
msg/simple/SimpleMessenger.cc: 237: FAILED assert(!cleared)
 ceph version 0.90-805-gcf432fa (cf432fa670bf20b66b24255768fe9dffbfe85416)
 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x8b) [0x90f26b]
 2: (SimpleMessenger::reaper()+0xcbd) [0x901bdd]
 3: (SimpleMessenger::wait()+0x527) [0x902607]
 4: (MessengerTest_StatefulTest_Test::TestBody()+0x1a1d) [0x82ca1d]
 5: (testing::Test::Run()+0x96) [0x83bbc6]
 6: (testing::internal::TestInfoImpl::Run()+0xd8) [0x83c130]
 7: (testing::TestCase::Run()+0xcb) [0x83c639]
 8: (testing::internal::UnitTestImpl::RunAllTests()+0x26e) [0x840b3a]
 9: (testing::UnitTest::Run()+0x1c) [0x83faf0]
 10: (main()+0x103) [0x8281c3]
 11: (__libc_start_main()+0xf5) [0x67b9ec5]
 12: ./unittest_msgr() [0x829917]
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
2015-01-09 15:58:10.094276 40544c0 -1 msg/simple/SimpleMessenger.cc: In function 'void SimpleMessenger::reaper()' thread 40544c0 time 2015-01-09 15:58:10.022867
msg/simple/SimpleMessenger.cc: 237: FAILED assert(!cleared)

 ceph version 0.90-805-gcf432fa (cf432fa670bf20b66b24255768fe9dffbfe85416)
 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x8b) [0x90f26b]
 2: (SimpleMessenger::reaper()+0xcbd) [0x901bdd]
 3: (SimpleMessenger::wait()+0x527) [0x902607]
 4: (MessengerTest_StatefulTest_Test::TestBody()+0x1a1d) [0x82ca1d]
 5: (testing::Test::Run()+0x96) [0x83bbc6]
 6: (testing::internal::TestInfoImpl::Run()+0xd8) [0x83c130]
 7: (testing::TestCase::Run()+0xcb) [0x83c639]
 8: (testing::internal::UnitTestImpl::RunAllTests()+0x26e) [0x840b3a]
 9: (testing::UnitTest::Run()+0x1c) [0x83faf0]
 10: (main()+0x103) [0x8281c3]
 11: (__libc_start_main()+0xf5) [0x67b9ec5]
 12: ./unittest_msgr() [0x829917]
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
  -443> 2015-01-09 15:58:08.761618 40544c0  5 asok(0x6b6eae0) register_command perfcounters_dump hook 0x6b740c0
  -442> 2015-01-09 15:58:08.774538 40544c0  5 asok(0x6b6eae0) register_command 1 hook 0x6b740c0
  -441> 2015-01-09 15:58:08.777638 40544c0  5 asok(0x6b6eae0) register_command perf dump hook 0x6b740c0
  -440> 2015-01-09 15:58:08.780435 40544c0  5 asok(0x6b6eae0) register_command perfcounters_schema hook 0x6b740c0
  -439> 2015-01-09 15:58:08.781711 40544c0  5 asok(0x6b6eae0) register_command 2 hook 0x6b740c0
  -438> 2015-01-09 15:58:08.782524 40544c0  5 asok(0x6b6eae0) register_command perf schema hook 0x6b740c0
  -437> 2015-01-09 15:58:08.783530 40544c0  5 asok(0x6b6eae0) register_command perf reset hook 0x6b740c0
  -436> 2015-01-09 15:58:08.784559 40544c0  5 asok(0x6b6eae0) register_command config show hook 0x6b740c0
  -435> 2015-01-09 15:58:08.785565 40544c0  5 asok(0x6b6eae0) register_command config set hook 0x6b740c0
  -434> 2015-01-09 15:58:08.786545 40544c0  5 asok(0x6b6eae0) register_command config get hook 0x6b740c0
  -433> 2015-01-09 15:58:08.787460 40544c0  5 asok(0x6b6eae0) register_command config diff hook 0x6b740c0
  -432> 2015-01-09 15:58:08.788426 40544c0  5 asok(0x6b6eae0) register_command log flush hook 0x6b740c0
  -431> 2015-01-09 15:58:08.789333 40544c0  5 asok(0x6b6eae0) register_command log dump hook 0x6b740c0
  -430> 2015-01-09 15:58:08.790367 40544c0  5 asok(0x6b6eae0) register_command log reopen hook 0x6b740c0
  -429> 2015-01-09 15:58:08.977103 40544c0 -1 WARNING: the following dangerous and experimental features are enabled: ms-type-async
  -428> 2015-01-09 15:58:08.981362 40544c0  5 asok(0x6b6eae0) init /home/loic/software/ceph/ceph/src/out/client.admin.24551.asok
  -427> 2015-01-09 15:58:08.983261 40544c0  5 asok(0x6b6eae0) bind_and_listen /home/loic/software/ceph/ceph/src/out/client.admin.24551.asok
  -426> 2015-01-09 15:58:08.996322 40544c0  5 asok(0x6b6eae0) register_command 0 hook 0x6c8fc10
  -425> 2015-01-09 15:58:08.997300 40544c0  5 asok(0x6b6eae0) register_command version hook 0x6c8fc10
  -424> 2015-01-09 15:58:08.998157 40544c0  5 asok(0x6b6eae0) register_command git_version hook 0x6c8fc10
  -423> 2015-01-09 15:58:08.999161 40544c0  5 asok(0x6b6eae0) register_command help hook 0x6c906c0
  -422> 2015-01-09 15:58:09.000168 40544c0  5 asok(0x6b6eae0) register_command get_command_descriptions hook 0x6c90aa0
  -421> 2015-01-09 15:58:09.100295 8760700  5 asok(0x6b6eae0) entry start
  -420> 2015-01-09 15:58:09.156993 40544c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -419> 2015-01-09 15:58:09.157908 40544c0 -1 Please be aware that this feature is experimental, untested,
  -418> 2015-01-09 15:58:09.158636 40544c0 -1 unsupported, and may result in data corruption, data loss,
  -417> 2015-01-09 15:58:09.159455 40544c0 -1 and/or irreparable damage to your cluster.  Do not use
  -416> 2015-01-09 15:58:09.160216 40544c0 -1 feature with important data.
  -415> 2015-01-09 15:58:09.185576 40544c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -414> 2015-01-09 15:58:09.185627 40544c0 -1 Please be aware that this feature is experimental, untested,
  -413> 2015-01-09 15:58:09.185655 40544c0 -1 unsupported, and may result in data corruption, data loss,
  -412> 2015-01-09 15:58:09.185672 40544c0 -1 and/or irreparable damage to your cluster.  Do not use
  -411> 2015-01-09 15:58:09.185689 40544c0 -1 feature with important data.
  -410> 2015-01-09 15:58:09.196630 40544c0  1 -- 127.0.0.1:0/0 learned_addr learned my addr 127.0.0.1:0/0
  -409> 2015-01-09 15:58:09.205564 40544c0  1  Processor -- bind bind my_inst.addr is 127.0.0.1:6972/24551
  -408> 2015-01-09 15:58:09.208498 40544c0  1  Processor -- start start
  -407> 2015-01-09 15:58:09.210380 40544c0  1 -- 127.0.0.1:6972/24551 start start
  -406> 2015-01-09 15:58:09.212963 40544c0  1  Processor -- start start
  -405> 2015-01-09 15:58:09.213053 40544c0  1 -- :/0 start start
  -404> 2015-01-09 15:58:09.230153 40544c0  1 Event wakeup
  -403> 2015-01-09 15:58:09.250615 8f61700  1 Event wakeup
  -402> 2015-01-09 15:58:09.270477 9f63700  1 -- 127.0.0.1:6972/24551 >> :/0 conn(0x6d37c80 sd=15 :6972 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:37766/0
  -401> 2015-01-09 15:58:09.292377 9762700  1 -- 127.0.0.1:0/24551 learned_addr learned my addr 127.0.0.1:0/24551
  -400> 2015-01-09 15:58:09.312171 9f63700  1 Event wakeup
  -399> 2015-01-09 15:58:09.319972 9762700  1 Event wakeup
  -398> 2015-01-09 15:58:09.321008 9f63700  2 -- 127.0.0.1:6972/24551 >> 127.0.0.1:0/24551 conn(0x6d37c80 sd=15 :6972 s=STATE_ACCEPTING_READY pgs=1 cs=1 l=1).handle_connect_msg accept write reply msg done
  -397> 2015-01-09 15:58:09.324557 9762700  1 Event wakeup
  -396> 2015-01-09 15:58:09.367214 40544c0  1 -- 127.0.0.1:6972/24551 rebind rebind avoid 6972,6973,6974,6975,6976,6977,6978,6979,6980,6981
  -395> 2015-01-09 15:58:09.376982 40544c0  1 -- 127.0.0.1:6972/24551 mark_down_all 
  -394> 2015-01-09 15:58:09.380143 40544c0  5 -- 127.0.0.1:6972/24551 mark_down_all mark down 127.0.0.1:0/24551 0x6d37c80
  -393> 2015-01-09 15:58:09.384687 40544c0  1 Event wakeup
  -392> 2015-01-09 15:58:09.391042 9f63700  1 Event wakeup
  -391> 2015-01-09 15:58:09.393224 9762700  1 -- 127.0.0.1:0/24551 >> 127.0.0.1:6972/24551 conn(0x6d31a30 sd=14 :0 s=STATE_OPEN pgs=1 cs=1 l=1).read_bulk Peer close file descriptor 14
  -390> 2015-01-09 15:58:09.397130 9762700  1 -- 127.0.0.1:0/24551 >> 127.0.0.1:6972/24551 conn(0x6d31a30 sd=14 :0 s=STATE_OPEN pgs=1 cs=1 l=1).process read tag failed, state is STATE_OPEN
  -389> 2015-01-09 15:58:09.400882 9762700  1 Event wakeup
  -388> 2015-01-09 15:58:09.404072 9762700  1 Event wakeup
  -387> 2015-01-09 15:58:09.411781 40544c0  5 -- 127.0.0.1:6972/24551 mark_down_all delete 0x6d37c80
  -386> 2015-01-09 15:58:09.417587 40544c0  1  Processor -- rebind rebind avoid 6972,6973,6974,6975,6976,6977,6978,6979,6980,6981
  -385> 2015-01-09 15:58:09.426070 40544c0  1  Processor -- bind bind my_inst.addr is 127.0.0.1:6982/1024551
  -384> 2015-01-09 15:58:09.426549 40544c0  1  Processor -- start start
  -383> 2015-01-09 15:58:09.431358 40544c0  1 Event wakeup
  -382> 2015-01-09 15:58:09.434278 8f61700  1 Event wakeup
  -381> 2015-01-09 15:58:09.434409 9f63700  1 -- 127.0.0.1:6982/1024551 >> :/0 conn(0x6d51b20 sd=15 :6982 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:34961/0
  -380> 2015-01-09 15:58:09.435145 9f63700  1 Event wakeup
  -379> 2015-01-09 15:58:09.435292 9f63700  2 -- 127.0.0.1:6982/1024551 >> 127.0.0.1:0/24551 conn(0x6d51b20 sd=15 :6982 s=STATE_ACCEPTING_READY pgs=2 cs=1 l=1).handle_connect_msg accept write reply msg done
  -378> 2015-01-09 15:58:09.435498 9762700  1 Event wakeup
  -377> 2015-01-09 15:58:09.435888 9762700  1 Event wakeup
  -376> 2015-01-09 15:58:09.438130 40544c0  1 Event wakeup
  -375> 2015-01-09 15:58:09.438627 9762700  1 Event wakeup
  -374> 2015-01-09 15:58:09.438977 9f63700  1 -- 127.0.0.1:6982/1024551 >> 127.0.0.1:0/24551 conn(0x6d51b20 sd=15 :6982 s=STATE_OPEN pgs=2 cs=1 l=1).read_bulk Peer close file descriptor 15
  -373> 2015-01-09 15:58:09.439153 9f63700  1 -- 127.0.0.1:6982/1024551 >> 127.0.0.1:0/24551 conn(0x6d51b20 sd=15 :6982 s=STATE_OPEN pgs=2 cs=1 l=1).process read tag failed, state is STATE_OPEN
  -372> 2015-01-09 15:58:09.439285 9f63700  1 Event wakeup
  -371> 2015-01-09 15:58:09.439381 9f63700  1 Event wakeup
  -370> 2015-01-09 15:58:09.440266 40544c0  1 -- 127.0.0.1:6982/1024551 mark_down_all 
  -369> 2015-01-09 15:58:09.440357 40544c0  5 -- 127.0.0.1:6982/1024551 mark_down_all mark down 127.0.0.1:0/24551 0x6d51b20
  -368> 2015-01-09 15:58:09.440463 40544c0  1 Event wakeup
  -367> 2015-01-09 15:58:09.440780 9f63700  1 Event wakeup
  -366> 2015-01-09 15:58:09.441299 40544c0  5 -- 127.0.0.1:6982/1024551 mark_down_all delete 0x6d51b20
  -365> 2015-01-09 15:58:09.444189 40544c0  1 -- 127.0.0.1:6982/1024551 mark_down_all 
  -364> 2015-01-09 15:58:09.444587 40544c0  1 -- 127.0.0.1:6982/1024551 wait complete.
  -363> 2015-01-09 15:58:09.446105 40544c0  1 Event wakeup
  -362> 2015-01-09 15:58:09.448741 40544c0  1 Event wakeup
  -361> 2015-01-09 15:58:09.453107 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -360> 2015-01-09 15:58:09.470303 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -359> 2015-01-09 15:58:09.471498 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -358> 2015-01-09 15:58:09.471729 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -357> 2015-01-09 15:58:09.474156 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -356> 2015-01-09 15:58:09.474332 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -355> 2015-01-09 15:58:09.475327 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -354> 2015-01-09 15:58:09.475613 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -353> 2015-01-09 15:58:09.476147 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -352> 2015-01-09 15:58:09.477121 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -351> 2015-01-09 15:58:09.477335 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -350> 2015-01-09 15:58:09.477556 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -349> 2015-01-09 15:58:09.477786 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -348> 2015-01-09 15:58:09.478925 40544c0  1 -- 127.0.0.1:0/24551 mark_down_all 
  -347> 2015-01-09 15:58:09.479010 40544c0  5 -- 127.0.0.1:0/24551 mark_down_all mark down 127.0.0.1:6982/1024551 0x6d4c350
  -346> 2015-01-09 15:58:09.479114 40544c0  1 Event wakeup
  -345> 2015-01-09 15:58:09.479153 9762700 -1 net_handler: generic_connect connect: %s Connection refused
  -344> 2015-01-09 15:58:09.481425 9762700  1 Event wakeup
  -343> 2015-01-09 15:58:09.481942 40544c0  5 -- 127.0.0.1:0/24551 mark_down_all mark down 127.0.0.1:6972/24551 0x6d31a30
  -342> 2015-01-09 15:58:09.482022 40544c0  1 Event wakeup
  -341> 2015-01-09 15:58:09.482372 9762700  1 Event wakeup
  -340> 2015-01-09 15:58:09.482981 40544c0  5 -- 127.0.0.1:0/24551 mark_down_all delete 0x6d31a30
  -339> 2015-01-09 15:58:09.483159 40544c0  5 -- 127.0.0.1:0/24551 mark_down_all delete 0x6d4c350
  -338> 2015-01-09 15:58:09.483339 40544c0  1 -- 127.0.0.1:0/24551 mark_down_all 
  -337> 2015-01-09 15:58:09.483408 40544c0  1 -- 127.0.0.1:0/24551 wait complete.
  -336> 2015-01-09 15:58:09.517719 40544c0  1 -- 127.0.0.1:0/0 learned my addr 127.0.0.1:0/0
  -335> 2015-01-09 15:58:09.521032 40544c0  1 accepter.accepter.bind my_inst.addr is 127.0.0.1:6973/24551 need_addr=0
  -334> 2015-01-09 15:58:09.524137 40544c0  1 accepter.accepter.start
  -333> 2015-01-09 15:58:09.525749 40544c0  1 -- 127.0.0.1:6973/24551 messenger.start
  -332> 2015-01-09 15:58:09.531685 40544c0  1 -- :/0 messenger.start
  -331> 2015-01-09 15:58:09.550283 40544c0  1 -- :/24551 --> 127.0.0.1:6973/24551 -- ping magic: 0 v1 -- ?+0 0x6d6a6e0 con 0x6d6ebb0
  -330> 2015-01-09 15:58:09.573710 4159700  1 -- 127.0.0.1:0/24551 learned my addr 127.0.0.1:0/24551
  -329> 2015-01-09 15:58:09.574229 d06a700  1 -- 127.0.0.1:6973/24551 >> :/0 pipe(0x6d70370 sd=15 :6973 s=0 pgs=0 cs=0 l=0 c=0x6d74650).accept sd=15 127.0.0.1:39322/0
  -328> 2015-01-09 15:58:09.648290 d06a700  1 -- 127.0.0.1:6973/24551 <== client.? 127.0.0.1:0/24551 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6d7a660 con 0x6d74650
  -327> 2015-01-09 15:58:09.655302 d06a700  1 -- 127.0.0.1:6973/24551 --> 127.0.0.1:0/24551 -- ping magic: 0 v1 -- ?+0 0x6d7aab0 con 0x6d74650
  -326> 2015-01-09 15:58:09.659102 d26c700  1 -- 127.0.0.1:0/24551 <== osd.0 127.0.0.1:6973/24551 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6d7afe0 con 0x6d6ebb0
  -325> 2015-01-09 15:58:09.662163 40544c0  1 -- 127.0.0.1:6973/24551 rebind avoid 6973,6974,6975,6976,6977,6978,6979,6980,6981,6982
  -324> 2015-01-09 15:58:09.666134 40544c0  1 -- 127.0.0.1:6973/24551 mark_down_all
  -323> 2015-01-09 15:58:09.668537 40544c0  5 -- 127.0.0.1:6973/24551 mark_down_all 127.0.0.1:0/24551 0x6d70370
  -322> 2015-01-09 15:58:09.682387 40544c0  1 accepter.accepter.rebind avoid 6973,6974,6975,6976,6977,6978,6979,6980,6981,6982
  -321> 2015-01-09 15:58:09.685976 d26c700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6973/24551 pipe(0x6d6a8d0 sd=14 :39322 s=2 pgs=1 cs=1 l=1 c=0x6d6ebb0).reader couldn't read tag, (0) Success
  -320> 2015-01-09 15:58:09.689867 d06a700  2 -- 127.0.0.1:6983/1024551 >> 127.0.0.1:0/24551 pipe(0x6d70370 sd=15 :6973 s=4 pgs=1 cs=1 l=1 c=0x6d74650).reader couldn't read tag, (0) Success
  -319> 2015-01-09 15:58:09.690402 d06a700  2 -- 127.0.0.1:6983/1024551 >> 127.0.0.1:0/24551 pipe(0x6d70370 sd=15 :6973 s=4 pgs=1 cs=1 l=1 c=0x6d74650).fault (0) Success
  -318> 2015-01-09 15:58:09.693312 d26c700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6973/24551 pipe(0x6d6a8d0 sd=14 :39322 s=2 pgs=1 cs=1 l=1 c=0x6d6ebb0).fault (0) Success
  -317> 2015-01-09 15:58:09.715686 40544c0  1 accepter.accepter.bind my_inst.addr is 127.0.0.1:6983/1024551 need_addr=0
  -316> 2015-01-09 15:58:09.716121 40544c0  1 accepter.accepter.start
  -315> 2015-01-09 15:58:09.717222 40544c0  1 -- 127.0.0.1:0/24551 --> 127.0.0.1:6983/1024551 -- ping magic: 0 v1 -- ?+0 0x6d830f0 con 0x6d81d40
  -314> 2015-01-09 15:58:09.717745 4159700  1 -- 127.0.0.1:6983/1024551 >> :/0 pipe(0x6d83580 sd=15 :6983 s=0 pgs=0 cs=0 l=0 c=0x6d87860).accept sd=15 127.0.0.1:53190/0
  -313> 2015-01-09 15:58:09.718919 4159700  1 -- 127.0.0.1:6983/1024551 <== client.? 127.0.0.1:0/24551 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6d8d990 con 0x6d87860
  -312> 2015-01-09 15:58:09.719269 4159700  1 -- 127.0.0.1:6983/1024551 --> 127.0.0.1:0/24551 -- ping magic: 0 v1 -- ?+0 0x6d8dd40 con 0x6d87860
  -311> 2015-01-09 15:58:09.719635 d16b700  1 -- 127.0.0.1:0/24551 <== osd.0 127.0.0.1:6983/1024551 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6d8e1d0 con 0x6d81d40
  -310> 2015-01-09 15:58:09.721074 40544c0  1 -- 127.0.0.1:0/24551 mark_down 0x6d81d40 -- 0x6d7da60
  -309> 2015-01-09 15:58:09.723080 4159700  2 -- 127.0.0.1:6983/1024551 >> 127.0.0.1:0/24551 pipe(0x6d83580 sd=15 :6983 s=2 pgs=2 cs=1 l=1 c=0x6d87860).reader couldn't read tag, (0) Success
  -308> 2015-01-09 15:58:09.723727 4159700  2 -- 127.0.0.1:6983/1024551 >> 127.0.0.1:0/24551 pipe(0x6d83580 sd=15 :6983 s=2 pgs=2 cs=1 l=1 c=0x6d87860).fault (0) Success
  -307> 2015-01-09 15:58:09.725494 40544c0  1 -- 127.0.0.1:6983/1024551 mark_down_all
  -306> 2015-01-09 15:58:09.725576 40544c0  5 -- 127.0.0.1:6983/1024551 mark_down_all 127.0.0.1:0/24551 0x6d83580
  -305> 2015-01-09 15:58:09.725881 d16b700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6983/1024551 pipe(0x6d7da60 sd=14 :53190 s=4 pgs=2 cs=1 l=1 c=0x6d81d40).reader couldn't read tag, (0) Success
  -304> 2015-01-09 15:58:09.730273 d16b700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6983/1024551 pipe(0x6d7da60 sd=14 :53190 s=4 pgs=2 cs=1 l=1 c=0x6d81d40).fault (0) Success
  -303> 2015-01-09 15:58:09.739392 40544c0  1 -- 127.0.0.1:6983/1024551 shutdown complete.
  -302> 2015-01-09 15:58:09.740745 40544c0  1 -- 127.0.0.1:0/24551 --> 127.0.0.1:6983/1024551 -- ping magic: 0 v1 -- ?+0 0x6d8fe60 con 0x6d81d40
  -301> 2015-01-09 15:58:09.741576 40544c0  0 -- 127.0.0.1:0/24551 submit_message ping magic: 0 v1 remote, 127.0.0.1:6983/1024551, failed lossy con, dropping message 0x6d8fe60
  -300> 2015-01-09 15:58:09.744626 40544c0  1 -- 127.0.0.1:0/24551 --> 127.0.0.1:0/24551 -- ping magic: 0 v1 -- ?+0 0x6d903d0 con 0x6d69510
  -299> 2015-01-09 15:58:09.748767 c768700  1 -- 127.0.0.1:0/24551 <== client.? 127.0.0.1:0/24551 0 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6d903d0 con 0x6d69510
  -298> 2015-01-09 15:58:09.750500 40544c0  1 -- 127.0.0.1:0/24551 mark_down_all
  -297> 2015-01-09 15:58:09.753294 40544c0  1 -- 127.0.0.1:0/24551 shutdown complete.
  -296> 2015-01-09 15:58:09.765890 40544c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -295> 2015-01-09 15:58:09.765940 40544c0 -1 Please be aware that this feature is experimental, untested,
  -294> 2015-01-09 15:58:09.765970 40544c0 -1 unsupported, and may result in data corruption, data loss,
  -293> 2015-01-09 15:58:09.765998 40544c0 -1 and/or irreparable damage to your cluster.  Do not use
  -292> 2015-01-09 15:58:09.766025 40544c0 -1 feature with important data.
  -291> 2015-01-09 15:58:09.766259 40544c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -290> 2015-01-09 15:58:09.766295 40544c0 -1 Please be aware that this feature is experimental, untested,
  -289> 2015-01-09 15:58:09.766322 40544c0 -1 unsupported, and may result in data corruption, data loss,
  -288> 2015-01-09 15:58:09.766348 40544c0 -1 and/or irreparable damage to your cluster.  Do not use
  -287> 2015-01-09 15:58:09.766373 40544c0 -1 feature with important data.
  -286> 2015-01-09 15:58:09.768383 40544c0  1 -- 127.0.0.1:0/0 learned_addr learned my addr 127.0.0.1:0/0
  -285> 2015-01-09 15:58:09.768499 40544c0  1  Processor -- bind bind my_inst.addr is 127.0.0.1:6973/24551
  -284> 2015-01-09 15:58:09.768700 40544c0  1  Processor -- start start
  -283> 2015-01-09 15:58:09.768860 40544c0  1 -- 127.0.0.1:6973/24551 start start
  -282> 2015-01-09 15:58:09.769059 40544c0  1  Processor -- start start
  -281> 2015-01-09 15:58:09.769145 40544c0  1 -- :/0 start start
  -280> 2015-01-09 15:58:09.769978 40544c0  1 Event wakeup
  -279> 2015-01-09 15:58:09.771198 cf69700  1 Event wakeup
  -278> 2015-01-09 15:58:09.771588 9f63700  1 -- 127.0.0.1:6973/24551 >> :/0 conn(0x6da5b20 sd=15 :6973 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:39324/0
  -277> 2015-01-09 15:58:09.772263 9762700  1 -- 127.0.0.1:0/24551 learned_addr learned my addr 127.0.0.1:0/24551
  -276> 2015-01-09 15:58:09.773314 9f63700  1 Event wakeup
  -275> 2015-01-09 15:58:09.773591 9f63700  2 -- 127.0.0.1:6973/24551 >> 127.0.0.1:0/24551 conn(0x6da5b20 sd=15 :6973 s=STATE_ACCEPTING_READY pgs=1 cs=1 l=1).handle_connect_msg accept write reply msg done
  -274> 2015-01-09 15:58:09.773917 9762700  1 Event wakeup
  -273> 2015-01-09 15:58:09.774576 9762700  1 Event wakeup
  -272> 2015-01-09 15:58:09.778344 40544c0  1 -- 127.0.0.1:6973/24551 mark_down_all 
  -271> 2015-01-09 15:58:09.778410 40544c0  5 -- 127.0.0.1:6973/24551 mark_down_all mark down 127.0.0.1:0/24551 0x6da5b20
  -270> 2015-01-09 15:58:09.778493 40544c0  1 Event wakeup
  -269> 2015-01-09 15:58:09.778605 9f63700  1 Event wakeup
  -268> 2015-01-09 15:58:09.778684 9762700  1 -- 127.0.0.1:0/24551 >> 127.0.0.1:6973/24551 conn(0x6d9f830 sd=14 :0 s=STATE_OPEN pgs=1 cs=1 l=1).read_bulk Peer close file descriptor 14
  -267> 2015-01-09 15:58:09.778810 9762700  1 -- 127.0.0.1:0/24551 >> 127.0.0.1:6973/24551 conn(0x6d9f830 sd=14 :0 s=STATE_OPEN pgs=1 cs=1 l=1).process read tag failed, state is STATE_OPEN
  -266> 2015-01-09 15:58:09.778918 9762700  1 Event wakeup
  -265> 2015-01-09 15:58:09.778996 9762700  1 Event wakeup
  -264> 2015-01-09 15:58:09.779592 40544c0  5 -- 127.0.0.1:6973/24551 mark_down_all delete 0x6da5b20
  -263> 2015-01-09 15:58:09.780027 40544c0  1 -- 127.0.0.1:0/24551 mark_down_all 
  -262> 2015-01-09 15:58:09.780157 40544c0  5 -- 127.0.0.1:0/24551 mark_down_all mark down 127.0.0.1:6973/24551 0x6d9f830
  -261> 2015-01-09 15:58:09.780324 40544c0  1 Event wakeup
  -260> 2015-01-09 15:58:09.780461 9762700  1 Event wakeup
  -259> 2015-01-09 15:58:09.781049 40544c0  5 -- 127.0.0.1:0/24551 mark_down_all delete 0x6d9f830
  -258> 2015-01-09 15:58:09.781370 40544c0  1 -- 127.0.0.1:6973/24551 mark_down_all 
  -257> 2015-01-09 15:58:09.781482 40544c0  1 -- 127.0.0.1:6973/24551 wait complete.
  -256> 2015-01-09 15:58:09.781729 40544c0  1 -- 127.0.0.1:0/24551 mark_down_all 
  -255> 2015-01-09 15:58:09.781838 40544c0  1 -- 127.0.0.1:0/24551 wait complete.
  -254> 2015-01-09 15:58:09.785455 40544c0  1 -- 127.0.0.1:0/0 learned my addr 127.0.0.1:0/0
  -253> 2015-01-09 15:58:09.785637 40544c0  1 accepter.accepter.bind my_inst.addr is 127.0.0.1:6974/24551 need_addr=0
  -252> 2015-01-09 15:58:09.785892 40544c0  1 accepter.accepter.start
  -251> 2015-01-09 15:58:09.786003 40544c0  1 -- 127.0.0.1:6974/24551 messenger.start
  -250> 2015-01-09 15:58:09.786556 40544c0  1 -- :/0 messenger.start
  -249> 2015-01-09 15:58:09.787379 40544c0  1 -- :/24551 --> 127.0.0.1:6974/24551 -- ping magic: 0 v1 -- ?+0 0x6dbc700 con 0x6dc0bd0
  -248> 2015-01-09 15:58:09.788051 4159700  1 -- 127.0.0.1:0/24551 learned my addr 127.0.0.1:0/24551
  -247> 2015-01-09 15:58:09.788191 d06a700  1 -- 127.0.0.1:6974/24551 >> :/0 pipe(0x6dc2390 sd=15 :6974 s=0 pgs=0 cs=0 l=0 c=0x6dc6670).accept sd=15 127.0.0.1:56185/0
  -246> 2015-01-09 15:58:09.789452 d06a700  1 -- 127.0.0.1:6974/24551 <== client.? 127.0.0.1:0/24551 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6dcaca0 con 0x6dc6670
  -245> 2015-01-09 15:58:09.789810 d06a700  1 -- 127.0.0.1:6974/24551 --> 127.0.0.1:0/24551 -- ping magic: 0 v1 -- ?+0 0x6dcc2f0 con 0x6dc6670
  -244> 2015-01-09 15:58:09.790197 d26c700  1 -- 127.0.0.1:0/24551 <== osd.0 127.0.0.1:6974/24551 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6dcc720 con 0x6dc0bd0
  -243> 2015-01-09 15:58:09.791520 40544c0  1 -- 127.0.0.1:6974/24551 mark_down_all
  -242> 2015-01-09 15:58:09.791650 40544c0  5 -- 127.0.0.1:6974/24551 mark_down_all 127.0.0.1:0/24551 0x6dc2390
  -241> 2015-01-09 15:58:09.791874 d26c700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6974/24551 pipe(0x6dbc8f0 sd=14 :56185 s=2 pgs=1 cs=1 l=1 c=0x6dc0bd0).reader couldn't read tag, (0) Success
  -240> 2015-01-09 15:58:09.792301 d26c700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6974/24551 pipe(0x6dbc8f0 sd=14 :56185 s=2 pgs=1 cs=1 l=1 c=0x6dc0bd0).fault (0) Success
  -239> 2015-01-09 15:58:09.792718 d06a700  2 -- 127.0.0.1:6974/24551 >> 127.0.0.1:0/24551 pipe(0x6dc2390 sd=15 :6974 s=4 pgs=1 cs=1 l=1 c=0x6dc6670).reader couldn't read tag, (0) Success
  -238> 2015-01-09 15:58:09.792966 d06a700  2 -- 127.0.0.1:6974/24551 >> 127.0.0.1:0/24551 pipe(0x6dc2390 sd=15 :6974 s=4 pgs=1 cs=1 l=1 c=0x6dc6670).fault (0) Success
  -237> 2015-01-09 15:58:09.793522 40544c0  1 -- 127.0.0.1:0/24551 mark_down_all
  -236> 2015-01-09 15:58:09.794438 40544c0  1 -- 127.0.0.1:6974/24551 shutdown complete.
  -235> 2015-01-09 15:58:09.794766 40544c0  1 -- 127.0.0.1:0/24551 shutdown complete.
  -234> 2015-01-09 15:58:09.795856 40544c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -233> 2015-01-09 15:58:09.795898 40544c0 -1 Please be aware that this feature is experimental, untested,
  -232> 2015-01-09 15:58:09.795925 40544c0 -1 unsupported, and may result in data corruption, data loss,
  -231> 2015-01-09 15:58:09.795950 40544c0 -1 and/or irreparable damage to your cluster.  Do not use
  -230> 2015-01-09 15:58:09.795974 40544c0 -1 feature with important data.
  -229> 2015-01-09 15:58:09.796161 40544c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -228> 2015-01-09 15:58:09.796192 40544c0 -1 Please be aware that this feature is experimental, untested,
  -227> 2015-01-09 15:58:09.796216 40544c0 -1 unsupported, and may result in data corruption, data loss,
  -226> 2015-01-09 15:58:09.796238 40544c0 -1 and/or irreparable damage to your cluster.  Do not use
  -225> 2015-01-09 15:58:09.796260 40544c0 -1 feature with important data.
  -224> 2015-01-09 15:58:09.800617 40544c0  1 -- 127.0.0.1:0/0 learned_addr learned my addr 127.0.0.1:0/0
  -223> 2015-01-09 15:58:09.800708 40544c0  1  Processor -- bind bind my_inst.addr is 127.0.0.1:6974/24551
  -222> 2015-01-09 15:58:09.800930 40544c0  1  Processor -- start start
  -221> 2015-01-09 15:58:09.801098 40544c0  1 -- 127.0.0.1:6974/24551 start start
  -220> 2015-01-09 15:58:09.801513 40544c0  1  Processor -- start start
  -219> 2015-01-09 15:58:09.801604 40544c0  1 -- :/0 start start
  -218> 2015-01-09 15:58:09.802675 40544c0  1 Event wakeup
  -217> 2015-01-09 15:58:09.803285 40544c0  1 -- :/24551 mark_down_all 
  -216> 2015-01-09 15:58:09.803325 40544c0  5 -- :/24551 mark_down_all mark down 127.0.0.1:6974/24551 0x6ddd290
  -215> 2015-01-09 15:58:09.803394 40544c0  1 Event wakeup
  -214> 2015-01-09 15:58:09.803696 af65700  1 Event wakeup
  -213> 2015-01-09 15:58:09.803784 9762700  1 Event wakeup
  -212> 2015-01-09 15:58:09.803944 9f63700  1 -- 127.0.0.1:6974/24551 >> :/0 conn(0x6de3920 sd=15 :6974 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:56186/0
  -211> 2015-01-09 15:58:09.804324 40544c0  5 -- :/24551 mark_down_all delete 0x6ddd290
  -210> 2015-01-09 15:58:09.804478 40544c0  1 -- :/24551 mark_down_all 
  -209> 2015-01-09 15:58:09.804521 40544c0  1 -- :/24551 wait complete.
  -208> 2015-01-09 15:58:09.805075 40544c0  1 -- :/24551 start start
  -207> 2015-01-09 15:58:09.805126 9f63700  1 -- 127.0.0.1:6974/24551 >> :/0 conn(0x6de3920 sd=15 :6974 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).read_bulk Peer close file descriptor 15
  -206> 2015-01-09 15:58:09.805509 9f63700  1 -- 127.0.0.1:6974/24551 >> :/0 conn(0x6de3920 sd=15 :6974 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).read_until read failed, state is STATE_ACCEPTING_WAIT_BANNER_ADDR
  -205> 2015-01-09 15:58:09.807260 9f63700  1 -- 127.0.0.1:6974/24551 >> :/0 conn(0x6de3920 sd=15 :6974 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0)._process_connection read peer banner and addr failed
  -204> 2015-01-09 15:58:09.808785 9f63700  0 -- 127.0.0.1:6974/24551 >> :/0 conn(0x6de3920 sd=15 :6974 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).fault server, going to standby
  -203> 2015-01-09 15:58:09.810514 40544c0  1 Event wakeup
  -202> 2015-01-09 15:58:09.814721 af65700  1 Event wakeup
  -201> 2015-01-09 15:58:09.814980 9f63700  1 -- 127.0.0.1:6974/24551 >> :/0 conn(0x6df3330 sd=16 :6974 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=16 127.0.0.1:56187/0
  -200> 2015-01-09 15:58:09.816020 9762700  1 -- 127.0.0.1:0/24551 learned_addr learned my addr 127.0.0.1:0/24551
  -199> 2015-01-09 15:58:09.818485 9f63700  1 Event wakeup
  -198> 2015-01-09 15:58:09.820205 9f63700  2 -- 127.0.0.1:6974/24551 >> 127.0.0.1:0/24551 conn(0x6df3330 sd=16 :6974 s=STATE_ACCEPTING_READY pgs=2 cs=1 l=1).handle_connect_msg accept write reply msg done
  -197> 2015-01-09 15:58:09.820523 9762700  1 Event wakeup
  -196> 2015-01-09 15:58:09.821886 9762700  1 Event wakeup
  -195> 2015-01-09 15:58:09.827138 40544c0  1 -- 127.0.0.1:6974/24551 mark_down_all 
  -194> 2015-01-09 15:58:09.828558 40544c0  5 -- 127.0.0.1:6974/24551 mark_down_all accepting_conn 0x6de3920
  -193> 2015-01-09 15:58:09.830332 40544c0  1 Event wakeup
  -192> 2015-01-09 15:58:09.830865 9f63700  1 Event wakeup
  -191> 2015-01-09 15:58:09.832424 40544c0  5 -- 127.0.0.1:6974/24551 mark_down_all mark down 127.0.0.1:0/24551 0x6df3330
  -190> 2015-01-09 15:58:09.832630 40544c0  1 Event wakeup
  -189> 2015-01-09 15:58:09.832806 9f63700  1 Event wakeup
  -188> 2015-01-09 15:58:09.833381 9762700  1 -- 127.0.0.1:0/24551 >> 127.0.0.1:6974/24551 conn(0x6dece60 sd=14 :0 s=STATE_OPEN pgs=1 cs=1 l=1).read_bulk Peer close file descriptor 14
  -187> 2015-01-09 15:58:09.833667 9762700  1 -- 127.0.0.1:0/24551 >> 127.0.0.1:6974/24551 conn(0x6dece60 sd=14 :0 s=STATE_OPEN pgs=1 cs=1 l=1).process read tag failed, state is STATE_OPEN
  -186> 2015-01-09 15:58:09.833896 9762700  1 Event wakeup
  -185> 2015-01-09 15:58:09.834044 9762700  1 Event wakeup
  -184> 2015-01-09 15:58:09.834761 40544c0  5 -- 127.0.0.1:6974/24551 mark_down_all delete 0x6de3920
  -183> 2015-01-09 15:58:09.834909 40544c0  5 -- 127.0.0.1:6974/24551 mark_down_all delete 0x6df3330
  -182> 2015-01-09 15:58:09.835330 40544c0  1 -- 127.0.0.1:0/24551 mark_down_all 
  -181> 2015-01-09 15:58:09.835499 40544c0  5 -- 127.0.0.1:0/24551 mark_down_all mark down 127.0.0.1:6974/24551 0x6dece60
  -180> 2015-01-09 15:58:09.835649 40544c0  1 Event wakeup
  -179> 2015-01-09 15:58:09.837103 9762700  1 Event wakeup
  -178> 2015-01-09 15:58:09.838185 40544c0  5 -- 127.0.0.1:0/24551 mark_down_all delete 0x6dece60
  -177> 2015-01-09 15:58:09.838489 40544c0  1 -- 127.0.0.1:6974/24551 mark_down_all 
  -176> 2015-01-09 15:58:09.838595 40544c0  1 -- 127.0.0.1:6974/24551 wait complete.
  -175> 2015-01-09 15:58:09.838821 40544c0  1 -- 127.0.0.1:0/24551 mark_down_all 
  -174> 2015-01-09 15:58:09.838925 40544c0  1 -- 127.0.0.1:0/24551 wait complete.
  -173> 2015-01-09 15:58:09.842397 40544c0  1 -- 127.0.0.1:0/0 learned my addr 127.0.0.1:0/0
  -172> 2015-01-09 15:58:09.842556 40544c0  1 accepter.accepter.bind my_inst.addr is 127.0.0.1:6975/24551 need_addr=0
  -171> 2015-01-09 15:58:09.842856 40544c0  1 accepter.accepter.start
  -170> 2015-01-09 15:58:09.842994 40544c0  1 -- 127.0.0.1:6975/24551 messenger.start
  -169> 2015-01-09 15:58:09.843404 40544c0  1 -- :/0 messenger.start
  -168> 2015-01-09 15:58:09.844023 40544c0  1 -- :/24551 --> 127.0.0.1:6975/24551 -- ping magic: 0 v1 -- ?+0 0x6e0bb80 con 0x6e10050
  -167> 2015-01-09 15:58:09.844287 40544c0  1 -- :/24551 mark_down_all
  -166> 2015-01-09 15:58:09.844357 40544c0  5 -- :/24551 mark_down_all 127.0.0.1:6975/24551 0x6e0bd70
  -165> 2015-01-09 15:58:09.845404 d26c700  2 -- :/24551 >> 127.0.0.1:6975/24551 pipe(0x6e0bd70 sd=14 :0 s=4 pgs=0 cs=0 l=1 c=0x6e10050).connect couldn't read banner, (0) Success
  -164> 2015-01-09 15:58:09.849412 4159700  0 -- 127.0.0.1:6975/24551 >> :/0 pipe(0x6e118c0 sd=15 :6975 s=0 pgs=0 cs=0 l=0 c=0x6e15ba0).accept failed to getpeername (107) Transport endpoint is not connected
  -163> 2015-01-09 15:58:09.852378 d26c700  3 -- :/24551 >> 127.0.0.1:6975/24551 pipe(0x6e0bd70 sd=14 :0 s=4 pgs=0 cs=0 l=1 c=0x6e10050).connect fault, but state = closed != connecting, stopping
  -162> 2015-01-09 15:58:09.856082 4159700  2 -- 127.0.0.1:6975/24551 >> :/0 pipe(0x6e118c0 sd=15 :6975 s=4 pgs=0 cs=0 l=0 c=0x6e15ba0).fault (107) Transport endpoint is not connected
  -161> 2015-01-09 15:58:09.867892 40544c0  1 -- :/24551 shutdown complete.
  -160> 2015-01-09 15:58:09.867961 40544c0  1 -- :/24551 messenger.start
  -159> 2015-01-09 15:58:09.868796 40544c0  1 -- :/24551 --> 127.0.0.1:6975/24551 -- ping magic: 0 v1 -- ?+0 0x6e1f880 con 0x6e1e4d0
  -158> 2015-01-09 15:58:09.869342 4159700  1 -- 127.0.0.1:6975/24551 >> :/0 pipe(0x6e1fd10 sd=15 :6975 s=0 pgs=0 cs=0 l=0 c=0x6e23ff0).accept sd=15 127.0.0.1:34087/0
  -157> 2015-01-09 15:58:09.869645 d26c700  1 -- 127.0.0.1:0/24551 learned my addr 127.0.0.1:0/24551
  -156> 2015-01-09 15:58:09.872359 4159700  1 -- 127.0.0.1:6975/24551 <== client.? 127.0.0.1:0/24551 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6e27ae0 con 0x6e23ff0
  -155> 2015-01-09 15:58:09.872903 4159700  1 -- 127.0.0.1:6975/24551 --> 127.0.0.1:0/24551 -- ping magic: 0 v1 -- ?+0 0x6e29520 con 0x6e23ff0
  -154> 2015-01-09 15:58:09.873449 d16b700  1 -- 127.0.0.1:0/24551 <== osd.0 127.0.0.1:6975/24551 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6e29840 con 0x6e1e4d0
  -153> 2015-01-09 15:58:09.874037 40544c0  1 -- 127.0.0.1:6975/24551 mark_down_all
  -152> 2015-01-09 15:58:09.874161 40544c0  5 -- 127.0.0.1:6975/24551 mark_down_all 127.0.0.1:0/24551 0x6e1fd10
  -151> 2015-01-09 15:58:09.874389 d16b700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6975/24551 pipe(0x6e1a1f0 sd=14 :34087 s=2 pgs=1 cs=1 l=1 c=0x6e1e4d0).reader couldn't read tag, (0) Success
  -150> 2015-01-09 15:58:09.874989 4159700  2 -- 127.0.0.1:6975/24551 >> 127.0.0.1:0/24551 pipe(0x6e1fd10 sd=15 :6975 s=4 pgs=2 cs=1 l=1 c=0x6e23ff0).reader couldn't read tag, (0) Success
  -149> 2015-01-09 15:58:09.875307 d16b700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6975/24551 pipe(0x6e1a1f0 sd=14 :34087 s=2 pgs=1 cs=1 l=1 c=0x6e1e4d0).fault (0) Success
  -148> 2015-01-09 15:58:09.876453 40544c0  1 -- 127.0.0.1:0/24551 mark_down_all
  -147> 2015-01-09 15:58:09.876803 4159700  2 -- 127.0.0.1:6975/24551 >> 127.0.0.1:0/24551 pipe(0x6e1fd10 sd=15 :6975 s=4 pgs=2 cs=1 l=1 c=0x6e23ff0).fault (0) Success
  -146> 2015-01-09 15:58:09.877667 40544c0  1 -- 127.0.0.1:6975/24551 shutdown complete.
  -145> 2015-01-09 15:58:09.877924 40544c0  1 -- 127.0.0.1:0/24551 shutdown complete.
  -144> 2015-01-09 15:58:09.879594 40544c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -143> 2015-01-09 15:58:09.879660 40544c0 -1 Please be aware that this feature is experimental, untested,
  -142> 2015-01-09 15:58:09.879703 40544c0 -1 unsupported, and may result in data corruption, data loss,
  -141> 2015-01-09 15:58:09.879738 40544c0 -1 and/or irreparable damage to your cluster.  Do not use
  -140> 2015-01-09 15:58:09.879773 40544c0 -1 feature with important data.
  -139> 2015-01-09 15:58:09.880047 40544c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
  -138> 2015-01-09 15:58:09.880092 40544c0 -1 Please be aware that this feature is experimental, untested,
  -137> 2015-01-09 15:58:09.880127 40544c0 -1 unsupported, and may result in data corruption, data loss,
  -136> 2015-01-09 15:58:09.880159 40544c0 -1 and/or irreparable damage to your cluster.  Do not use
  -135> 2015-01-09 15:58:09.880196 40544c0 -1 feature with important data.
  -134> 2015-01-09 15:58:09.884343 40544c0  1 -- 127.0.0.1:0/0 learned_addr learned my addr 127.0.0.1:0/0
  -133> 2015-01-09 15:58:09.884560 40544c0  1  Processor -- bind bind my_inst.addr is 127.0.0.1:6975/24551
  -132> 2015-01-09 15:58:09.885016 40544c0  1  Processor -- start start
  -131> 2015-01-09 15:58:09.885304 40544c0  1 -- 127.0.0.1:6975/24551 start start
  -130> 2015-01-09 15:58:09.885783 40544c0  1  Processor -- start start
  -129> 2015-01-09 15:58:09.885992 40544c0  1 -- :/0 start start
  -128> 2015-01-09 15:58:09.886988 40544c0  1 Event wakeup
  -127> 2015-01-09 15:58:09.890507 cf69700  1 Event wakeup
  -126> 2015-01-09 15:58:09.890761 9f63700  1 -- 127.0.0.1:6975/24551 >> :/0 conn(0x6e40500 sd=15 :6975 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:34088/0
  -125> 2015-01-09 15:58:09.891409 9762700  1 -- 127.0.0.1:0/24551 learned_addr learned my addr 127.0.0.1:0/24551
  -124> 2015-01-09 15:58:09.896528 9f63700  1 Event wakeup
  -123> 2015-01-09 15:58:09.896857 9762700  1 Event wakeup
  -122> 2015-01-09 15:58:09.897107 9f63700  2 -- 127.0.0.1:6975/24551 >> 127.0.0.1:0/24551 conn(0x6e40500 sd=15 :6975 s=STATE_ACCEPTING_READY pgs=1 cs=1 l=0).handle_connect_msg accept write reply msg done
  -121> 2015-01-09 15:58:09.898473 9762700  1 Event wakeup
  -120> 2015-01-09 15:58:09.903843 40544c0  1 Event wakeup
  -119> 2015-01-09 15:58:09.905511 9762700  1 Event wakeup
  -118> 2015-01-09 15:58:09.905617 9f63700  1 -- 127.0.0.1:6975/24551 >> 127.0.0.1:0/24551 conn(0x6e40500 sd=15 :6975 s=STATE_OPEN pgs=1 cs=1 l=0).read_bulk Peer close file descriptor 15
  -117> 2015-01-09 15:58:09.905894 9f63700  1 -- 127.0.0.1:6975/24551 >> 127.0.0.1:0/24551 conn(0x6e40500 sd=15 :6975 s=STATE_OPEN pgs=1 cs=1 l=0).process read tag failed, state is STATE_OPEN
  -116> 2015-01-09 15:58:09.908241 9f63700  0 -- 127.0.0.1:6975/24551 >> 127.0.0.1:0/24551 conn(0x6e40500 sd=15 :6975 s=STATE_OPEN pgs=1 cs=1 l=0).fault server, going to standby
  -115> 2015-01-09 15:58:09.916296 40544c0  1 Event wakeup
  -114> 2015-01-09 15:58:09.920480 cf69700  1 Event wakeup
  -113> 2015-01-09 15:58:09.920613 9f63700  1 -- 127.0.0.1:6975/24551 >> :/0 conn(0x6e5b260 sd=16 :6975 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=16 127.0.0.1:34089/0
  -112> 2015-01-09 15:58:09.923249 9f63700  0 -- 127.0.0.1:6975/24551 >> 127.0.0.1:0/24551 conn(0x6e5b260 sd=16 :6975 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msgaccept connect_seq 0 vs existing 1 state 30
  -111> 2015-01-09 15:58:09.924756 9f63700  0 -- 127.0.0.1:6975/24551 >> 127.0.0.1:0/24551 conn(0x6e5b260 sd=16 :6975 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msg accept peer reset, then tried to connect to us, replacing
  -110> 2015-01-09 15:58:09.926182 9f63700  1 Event wakeup
  -109> 2015-01-09 15:58:09.928517 9f63700  1 Event wakeup
  -108> 2015-01-09 15:58:09.929409 9f63700  1 Event wakeup
  -107> 2015-01-09 15:58:09.936242 9f63700  1 Event wakeup
  -106> 2015-01-09 15:58:09.942334 9f63700  1 Event wakeup
  -105> 2015-01-09 15:58:09.942659 9762700  1 Event wakeup
  -104> 2015-01-09 15:58:09.942731 9f63700  2 -- 127.0.0.1:6975/24551 >> 127.0.0.1:0/24551 conn(0x6e40500 sd=16 :6975 s=STATE_ACCEPTING_READY pgs=2 cs=2 l=0).handle_connect_msg accept write reply msg done
  -103> 2015-01-09 15:58:09.943322 9762700  1 Event wakeup
  -102> 2015-01-09 15:58:09.944310 9762700  1 Event wakeup
  -101> 2015-01-09 15:58:09.946546 40544c0  1 Event wakeup
  -100> 2015-01-09 15:58:09.949040 9f63700  1 Event wakeup
   -99> 2015-01-09 15:58:09.949084 9762700  1 -- 127.0.0.1:0/24551 >> 127.0.0.1:6975/24551 conn(0x6e54c70 sd=14 :0 s=STATE_OPEN pgs=2 cs=2 l=0).read_bulk Peer close file descriptor 14
   -98> 2015-01-09 15:58:09.949266 9762700  1 -- 127.0.0.1:0/24551 >> 127.0.0.1:6975/24551 conn(0x6e54c70 sd=14 :0 s=STATE_OPEN pgs=2 cs=2 l=0).process read tag failed, state is STATE_OPEN
   -97> 2015-01-09 15:58:09.949690 9762700  0 -- 127.0.0.1:0/24551 >> 127.0.0.1:6975/24551 conn(0x6e54c70 sd=14 :0 s=STATE_OPEN pgs=2 cs=2 l=0).fault initiating reconnect
   -96> 2015-01-09 15:58:09.952436 cf69700  1 Event wakeup
   -95> 2015-01-09 15:58:09.952570 9762700  1 -- 127.0.0.1:6975/24551 >> :/0 conn(0x6e75a10 sd=15 :6975 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:34090/0
   -94> 2015-01-09 15:58:09.954278 9762700  0 -- 127.0.0.1:6975/24551 >> 127.0.0.1:0/24551 conn(0x6e75a10 sd=15 :6975 s=STATE_ACCEPTING_WAIT_CONNECT_MSG_AUTH pgs=0 cs=0 l=0).handle_connect_msgaccept we reset (peer sent cseq 3), sending RESETSESSION
   -93> 2015-01-09 15:58:09.956378 9762700  0 -- 127.0.0.1:0/24551 >> 127.0.0.1:6975/24551 conn(0x6e54c70 sd=14 :0 s=STATE_CONNECTING_WAIT_CONNECT_REPLY_AUTH pgs=2 cs=3 l=0).handle_connect_replyconnect got RESETSESSION
   -92> 2015-01-09 15:58:09.957406 9762700  1 Event wakeup
   -91> 2015-01-09 15:58:09.958025 9762700  1 Event wakeup
   -90> 2015-01-09 15:58:09.958128 9762700  2 -- 127.0.0.1:6975/24551 >> 127.0.0.1:0/24551 conn(0x6e75a10 sd=15 :6975 s=STATE_ACCEPTING_READY pgs=3 cs=1 l=0).handle_connect_msg accept write reply msg done
   -89> 2015-01-09 15:58:09.958364 9762700  1 Event wakeup
   -88> 2015-01-09 15:58:09.960724 9762700  1 Event wakeup
   -87> 2015-01-09 15:58:09.964468 40544c0  1 -- 127.0.0.1:6975/24551 mark_down_all 
   -86> 2015-01-09 15:58:09.964549 40544c0  5 -- 127.0.0.1:6975/24551 mark_down_all accepting_conn 0x6e5b260
   -85> 2015-01-09 15:58:09.964616 40544c0  1 Event wakeup
   -84> 2015-01-09 15:58:09.964695 9f63700  1 Event wakeup
   -83> 2015-01-09 15:58:09.965069 40544c0  5 -- 127.0.0.1:6975/24551 mark_down_all mark down 127.0.0.1:0/24551 0x6e75a10
   -82> 2015-01-09 15:58:09.965171 40544c0  1 Event wakeup
   -81> 2015-01-09 15:58:09.965294 9762700  1 Event wakeup
   -80> 2015-01-09 15:58:09.965449 9762700  1 -- 127.0.0.1:0/24551 >> 127.0.0.1:6975/24551 conn(0x6e54c70 sd=14 :0 s=STATE_OPEN pgs=3 cs=1 l=0).read_bulk Peer close file descriptor 14
   -79> 2015-01-09 15:58:09.965590 9762700  1 -- 127.0.0.1:0/24551 >> 127.0.0.1:6975/24551 conn(0x6e54c70 sd=14 :0 s=STATE_OPEN pgs=3 cs=1 l=0).process read tag failed, state is STATE_OPEN
   -78> 2015-01-09 15:58:09.965792 9762700  0 -- 127.0.0.1:0/24551 >> 127.0.0.1:6975/24551 conn(0x6e54c70 sd=14 :0 s=STATE_OPEN pgs=3 cs=1 l=0).fault initiating reconnect
   -77> 2015-01-09 15:58:09.966128 40544c0  5 -- 127.0.0.1:6975/24551 mark_down_all delete 0x6e5b260
   -76> 2015-01-09 15:58:09.966207 40544c0  5 -- 127.0.0.1:6975/24551 mark_down_all delete 0x6e75a10
   -75> 2015-01-09 15:58:09.966395 cf69700  1 Event wakeup
   -74> 2015-01-09 15:58:09.966669 9f63700  1 -- 127.0.0.1:6975/24551 >> :/0 conn(0x6e8f6e0 sd=15 :6975 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:34091/0
   -73> 2015-01-09 15:58:09.967404 40544c0  1 -- 127.0.0.1:0/24551 mark_down_all 
   -72> 2015-01-09 15:58:09.967494 40544c0  5 -- 127.0.0.1:0/24551 mark_down_all mark down 127.0.0.1:6975/24551 0x6e54c70
   -71> 2015-01-09 15:58:09.967599 40544c0  1 Event wakeup
   -70> 2015-01-09 15:58:09.968083 9762700  1 Event wakeup
   -69> 2015-01-09 15:58:09.968148 9f63700  1 -- 127.0.0.1:6975/24551 >> :/0 conn(0x6e8f6e0 sd=15 :6975 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).read_bulk Peer close file descriptor 15
   -68> 2015-01-09 15:58:09.968267 9f63700  1 -- 127.0.0.1:6975/24551 >> :/0 conn(0x6e8f6e0 sd=15 :6975 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).read_until read failed, state is STATE_ACCEPTING_WAIT_BANNER_ADDR
   -67> 2015-01-09 15:58:09.968388 9f63700  1 -- 127.0.0.1:6975/24551 >> :/0 conn(0x6e8f6e0 sd=15 :6975 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0)._process_connection read peer banner and addr failed
   -66> 2015-01-09 15:58:09.968543 9f63700  0 -- 127.0.0.1:6975/24551 >> :/0 conn(0x6e8f6e0 sd=15 :6975 s=STATE_ACCEPTING_WAIT_BANNER_ADDR pgs=0 cs=0 l=0).fault server, going to standby
   -65> 2015-01-09 15:58:09.969210 40544c0  5 -- 127.0.0.1:0/24551 mark_down_all delete 0x6e54c70
   -64> 2015-01-09 15:58:09.969354 40544c0  1 -- 127.0.0.1:6975/24551 mark_down_all 
   -63> 2015-01-09 15:58:09.969406 40544c0  5 -- 127.0.0.1:6975/24551 mark_down_all accepting_conn 0x6e8f6e0
   -62> 2015-01-09 15:58:09.969458 40544c0  1 Event wakeup
   -61> 2015-01-09 15:58:09.969537 9f63700  1 Event wakeup
   -60> 2015-01-09 15:58:09.969945 40544c0  5 -- 127.0.0.1:6975/24551 mark_down_all delete 0x6e8f6e0
   -59> 2015-01-09 15:58:09.970023 40544c0  1 -- 127.0.0.1:6975/24551 wait complete.
   -58> 2015-01-09 15:58:09.970181 40544c0  1 -- 127.0.0.1:0/24551 mark_down_all 
   -57> 2015-01-09 15:58:09.970247 40544c0  1 -- 127.0.0.1:0/24551 wait complete.
   -56> 2015-01-09 15:58:09.972188 40544c0  1 -- 127.0.0.1:0/0 learned my addr 127.0.0.1:0/0
   -55> 2015-01-09 15:58:09.972281 40544c0  1 accepter.accepter.bind my_inst.addr is 127.0.0.1:6976/24551 need_addr=0
   -54> 2015-01-09 15:58:09.972462 40544c0  1 accepter.accepter.start
   -53> 2015-01-09 15:58:09.972572 40544c0  1 -- 127.0.0.1:6976/24551 messenger.start
   -52> 2015-01-09 15:58:09.972828 40544c0  1 -- :/0 messenger.start
   -51> 2015-01-09 15:58:09.973162 40544c0  1 -- :/24551 --> 127.0.0.1:6976/24551 -- ping magic: 0 v1 -- ?+0 0x6ea1360 con 0x6e9ffb0
   -50> 2015-01-09 15:58:09.973549 d26c700  1 -- 127.0.0.1:6976/24551 >> :/0 pipe(0x6ea17f0 sd=15 :6976 s=0 pgs=0 cs=0 l=0 c=0x6ea5ad0).accept sd=15 127.0.0.1:57833/0
   -49> 2015-01-09 15:58:09.973691 d16b700  1 -- 127.0.0.1:0/24551 learned my addr 127.0.0.1:0/24551
   -48> 2015-01-09 15:58:09.975060 d26c700  1 -- 127.0.0.1:6976/24551 <== client.? 127.0.0.1:0/24551 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6eab820 con 0x6ea5ad0
   -47> 2015-01-09 15:58:09.975333 d26c700  1 -- 127.0.0.1:6976/24551 --> 127.0.0.1:0/24551 -- ping magic: 0 v1 -- ?+0 0x6eabbd0 con 0x6ea5ad0
   -46> 2015-01-09 15:58:09.976355 d06a700  1 -- 127.0.0.1:0/24551 <== osd.0 127.0.0.1:6976/24551 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6eac0c0 con 0x6e9ffb0
   -45> 2015-01-09 15:58:09.976753 40544c0  1 -- 127.0.0.1:0/24551 mark_down 0x6e9ffb0 -- 0x6e9bcd0
   -44> 2015-01-09 15:58:09.976906 d06a700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6976/24551 pipe(0x6e9bcd0 sd=14 :57833 s=4 pgs=1 cs=1 l=0 c=0x6e9ffb0).reader couldn't read tag, (0) Success
   -43> 2015-01-09 15:58:09.977669 d26c700  2 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6ea17f0 sd=15 :6976 s=2 pgs=1 cs=1 l=0 c=0x6ea5ad0).reader couldn't read tag, (0) Success
   -42> 2015-01-09 15:58:09.977904 d26c700  2 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6ea17f0 sd=15 :6976 s=2 pgs=1 cs=1 l=0 c=0x6ea5ad0).fault (0) Success
   -41> 2015-01-09 15:58:09.978516 40544c0  1 -- 127.0.0.1:0/24551 --> 127.0.0.1:6976/24551 -- ping magic: 0 v1 -- ?+0 0x6eb2b30 con 0x6eb0cf0
   -40> 2015-01-09 15:58:09.978662 d06a700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6976/24551 pipe(0x6e9bcd0 sd=14 :57833 s=4 pgs=1 cs=1 l=0 c=0x6e9ffb0).fault (0) Success
   -39> 2015-01-09 15:58:09.980784 d26c700  0 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6ea17f0 sd=15 :6976 s=2 pgs=1 cs=1 l=0 c=0x6ea5ad0).fault, server, going to standby
   -38> 2015-01-09 15:58:09.983829 d46e700  1 -- 127.0.0.1:6976/24551 >> :/0 pipe(0x6eb36f0 sd=17 :6976 s=0 pgs=0 cs=0 l=0 c=0x6eb79d0).accept sd=17 127.0.0.1:57834/0
   -37> 2015-01-09 15:58:09.986000 d46e700  0 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6eb36f0 sd=17 :6976 s=0 pgs=0 cs=0 l=0 c=0x6eb79d0).accept connect_seq 0 vs existing 1 state standby
   -36> 2015-01-09 15:58:09.987665 d46e700  0 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6eb36f0 sd=17 :6976 s=0 pgs=0 cs=0 l=0 c=0x6eb79d0).accept peer reset, then tried to connect to us, replacing
   -35> 2015-01-09 15:58:09.999391 d46e700  1 -- 127.0.0.1:6976/24551 <== client.? 127.0.0.1:0/24551 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6ebd280 con 0x6ea5ad0
   -34> 2015-01-09 15:58:09.999654 d46e700  1 -- 127.0.0.1:6976/24551 --> 127.0.0.1:0/24551 -- ping magic: 0 v1 -- ?+0 0x6ebd630 con 0x6ea5ad0
   -33> 2015-01-09 15:58:10.000269 d26c700  0 -- 127.0.0.1:0/24551 >> 127.0.0.1:6976/24551 pipe(0x6eaca10 sd=16 :57834 s=2 pgs=2 cs=1 l=0 c=0x6eb0cf0).reader missed message?  skipped from seq 0 to 458020547
   -32> 2015-01-09 15:58:10.001465 d26c700  1 -- 127.0.0.1:0/24551 <== osd.0 127.0.0.1:6976/24551 458020547 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6ebdaa0 con 0x6eb0cf0
   -31> 2015-01-09 15:58:10.001798 40544c0  1 -- 127.0.0.1:6976/24551 mark_down 0x6ea5ad0 -- 0x6eb36f0
   -30> 2015-01-09 15:58:10.001899 d26c700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6976/24551 pipe(0x6eaca10 sd=16 :57834 s=2 pgs=2 cs=1 l=0 c=0x6eb0cf0).reader couldn't read tag, (0) Success
   -29> 2015-01-09 15:58:10.002088 d46e700  2 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6eb36f0 sd=17 :6976 s=4 pgs=2 cs=1 l=0 c=0x6ea5ad0).reader couldn't read tag, (107) Transport endpoint is not connected
   -28> 2015-01-09 15:58:10.002284 d26c700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6976/24551 pipe(0x6eaca10 sd=16 :57834 s=2 pgs=2 cs=1 l=0 c=0x6eb0cf0).fault (0) Success
   -27> 2015-01-09 15:58:10.002975 d26c700  0 -- 127.0.0.1:0/24551 >> 127.0.0.1:6976/24551 pipe(0x6eaca10 sd=16 :57834 s=2 pgs=2 cs=1 l=0 c=0x6eb0cf0).fault, initiating reconnect
   -26> 2015-01-09 15:58:10.002472 d46e700  2 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6eb36f0 sd=17 :6976 s=4 pgs=2 cs=1 l=0 c=0x6ea5ad0).fault (107) Transport endpoint is not connected
   -25> 2015-01-09 15:58:10.005831 4159700  1 -- 127.0.0.1:6976/24551 >> :/0 pipe(0x6ebf9c0 sd=15 :6976 s=0 pgs=0 cs=0 l=0 c=0x6ec3ca0).accept sd=15 127.0.0.1:57835/0
   -24> 2015-01-09 15:58:10.006496 4159700  0 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6ebf9c0 sd=15 :6976 s=0 pgs=0 cs=0 l=0 c=0x6ec3ca0).accept we reset (peer sent cseq 2), sending RESETSESSION
   -23> 2015-01-09 15:58:10.008930 d36d700  0 -- 127.0.0.1:0/24551 >> 127.0.0.1:6976/24551 pipe(0x6eaca10 sd=14 :57835 s=1 pgs=2 cs=2 l=0 c=0x6eb0cf0).connect got RESETSESSION
   -22> 2015-01-09 15:58:10.011669 40544c0  1 -- 127.0.0.1:0/24551 --> 127.0.0.1:6976/24551 -- ping magic: 0 v1 -- ?+0 0x6ec7b60 con 0x6eb0cf0
   -21> 2015-01-09 15:58:10.011933 4159700  0 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6ebf9c0 sd=15 :6976 s=2 pgs=3 cs=1 l=0 c=0x6ec3ca0).reader missed message?  skipped from seq 0 to 1345771825
   -20> 2015-01-09 15:58:10.012186 4159700  1 -- 127.0.0.1:6976/24551 <== client.? 127.0.0.1:0/24551 1345771825 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6ec9290 con 0x6ec3ca0
   -19> 2015-01-09 15:58:10.012437 4159700  1 -- 127.0.0.1:6976/24551 --> 127.0.0.1:0/24551 -- ping magic: 0 v1 -- ?+0 0x6ec99b0 con 0x6ec3ca0
   -18> 2015-01-09 15:58:10.012743 d26c700  1 -- 127.0.0.1:0/24551 <== osd.0 127.0.0.1:6976/24551 1 ==== ping magic: 0 v1 ==== 0+0+0 (0 0 0) 0x6ec9ea0 con 0x6eb0cf0
   -17> 2015-01-09 15:58:10.013097 40544c0  1 -- 127.0.0.1:6976/24551 mark_down_all
   -16> 2015-01-09 15:58:10.013167 40544c0  5 -- 127.0.0.1:6976/24551 mark_down_all 127.0.0.1:0/24551 0x6ebf9c0
   -15> 2015-01-09 15:58:10.013353 d26c700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6976/24551 pipe(0x6eaca10 sd=14 :57835 s=2 pgs=3 cs=1 l=0 c=0x6eb0cf0).reader couldn't read tag, (0) Success
   -14> 2015-01-09 15:58:10.013596 4159700  2 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6ebf9c0 sd=15 :6976 s=4 pgs=3 cs=1 l=0 c=0x6ec3ca0).reader couldn't read tag, (0) Success
   -13> 2015-01-09 15:58:10.013782 4159700  2 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6ebf9c0 sd=15 :6976 s=4 pgs=3 cs=1 l=0 c=0x6ec3ca0).fault (0) Success
   -12> 2015-01-09 15:58:10.014051 d26c700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6976/24551 pipe(0x6eaca10 sd=14 :57835 s=2 pgs=3 cs=1 l=0 c=0x6eb0cf0).fault (0) Success
   -11> 2015-01-09 15:58:10.014280 d26c700  0 -- 127.0.0.1:0/24551 >> 127.0.0.1:6976/24551 pipe(0x6eaca10 sd=14 :57835 s=2 pgs=3 cs=1 l=0 c=0x6eb0cf0).fault, initiating reconnect
   -10> 2015-01-09 15:58:10.015258 d46e700  1 -- 127.0.0.1:6976/24551 >> :/0 pipe(0x6ecbc20 sd=16 :6976 s=0 pgs=0 cs=0 l=0 c=0x6ecff00).accept sd=16 127.0.0.1:57836/0
    -9> 2015-01-09 15:58:10.015587 d46e700  0 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6ecbc20 sd=16 :6976 s=0 pgs=0 cs=0 l=0 c=0x6ecff00).accept we reset (peer sent cseq 2), sending RESETSESSION
    -8> 2015-01-09 15:58:10.015847 d36d700  0 -- 127.0.0.1:0/24551 >> 127.0.0.1:6976/24551 pipe(0x6eaca10 sd=14 :57836 s=1 pgs=3 cs=2 l=0 c=0x6eb0cf0).connect got RESETSESSION
    -7> 2015-01-09 15:58:10.017018 40544c0  1 -- 127.0.0.1:0/24551 mark_down_all
    -6> 2015-01-09 15:58:10.017647 40544c0  5 -- 127.0.0.1:0/24551 mark_down_all 127.0.0.1:6976/24551 0x6eaca10
    -5> 2015-01-09 15:58:10.017914 d46e700  2 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6ecbc20 sd=16 :6976 s=2 pgs=4 cs=1 l=0 c=0x6ecff00).reader couldn't read tag, (0) Success
    -4> 2015-01-09 15:58:10.018187 d26c700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6976/24551 pipe(0x6eaca10 sd=14 :57836 s=4 pgs=4 cs=1 l=0 c=0x6eb0cf0).reader couldn't read tag, (0) Success
    -3> 2015-01-09 15:58:10.018381 d26c700  2 -- 127.0.0.1:0/24551 >> 127.0.0.1:6976/24551 pipe(0x6eaca10 sd=14 :57836 s=4 pgs=4 cs=1 l=0 c=0x6eb0cf0).fault (0) Success
    -2> 2015-01-09 15:58:10.018604 d46e700  2 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6ecbc20 sd=16 :6976 s=2 pgs=4 cs=1 l=0 c=0x6ecff00).fault (0) Success
    -1> 2015-01-09 15:58:10.019278 d46e700  0 -- 127.0.0.1:6976/24551 >> 127.0.0.1:0/24551 pipe(0x6ecbc20 sd=16 :6976 s=2 pgs=4 cs=1 l=0 c=0x6ecff00).fault with nothing to send, going to standby
     0> 2015-01-09 15:58:10.094276 40544c0 -1 msg/simple/SimpleMessenger.cc: In function 'void SimpleMessenger::reaper()' thread 40544c0 time 2015-01-09 15:58:10.022867
msg/simple/SimpleMessenger.cc: 237: FAILED assert(!cleared)

#4 Updated by Loïc Dachary over 8 years ago

Description updated (diff)

#5 Updated by Haomai Wang over 8 years ago

Due date set to 01/13/2015
Category set to msgr

#6 Updated by Loïc Dachary over 8 years ago

Due date deleted (~~01/13/2015~~)
Category deleted (~~msgr~~)

The following happened with a run done with a different set of flags.

./configure --with-radosgw --disable-static --with-debug CC='ccache gcc' CXX='ccache g++' CFLAGS="-Wall -g" CXXFLAGS="-Wall -g"

[ RUN      ] Messenger/MessengerTest.SimpleTest/0
SetUp start set up async
2015-01-09 16:28:31.660956 7f1fb50ca7c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
2015-01-09 16:28:31.660960 7f1fb50ca7c0 -1 Please be aware that this feature is experimental, untested,
2015-01-09 16:28:31.660962 7f1fb50ca7c0 -1 unsupported, and may result in data corruption, data loss,
2015-01-09 16:28:31.660963 7f1fb50ca7c0 -1 and/or irreparable damage to your cluster.  Do not use
2015-01-09 16:28:31.660964 7f1fb50ca7c0 -1 feature with important data.
2015-01-09 16:28:31.661170 7f1fb50ca7c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
2015-01-09 16:28:31.661173 7f1fb50ca7c0 -1 Please be aware that this feature is experimental, untested,
2015-01-09 16:28:31.661174 7f1fb50ca7c0 -1 unsupported, and may result in data corruption, data loss,
2015-01-09 16:28:31.661174 7f1fb50ca7c0 -1 and/or irreparable damage to your cluster.  Do not use
2015-01-09 16:28:31.661175 7f1fb50ca7c0 -1 feature with important data.
ms_handle_fast_connect0x52a0c30
ms_handle_fast_connect con: 0x52a0c30 count: 0
ms_handle_fast_connect0x52a0c30
ms_handle_fast_connect0x52a7260
ms_handle_fast_connect con: 0x52a7260 count: 0
ms_fast_dispatch conn: 0x7f1f9c0008c0 session 0x7f1fa0000bf0 count: 1
ms_fast_dispatch conn: 0x52a7260 session 0x7f1fa80008e0 count: 1
ms_handle_reset0x7f1f9c0008c0
ms_handle_reset0x52a7260
2015-01-09 16:28:31.662502 7f1fb50ca7c0 -1  Processor -- bind unable to bind to 127.0.0.1:7292 on any port in range 6800-7300: (98) Address already in use
test/msgr/test_msgr.cc:221: Failure
Value of: avoid_ports.count(server_msgr->get_myaddr().get_port()) == 0
  Actual: false
Expected: true
msg/async/AsyncMessenger.cc: In function 'virtual AsyncMessenger::~AsyncMessenger()' thread 7f1fb50ca7c0 time 2015-01-09 16:28:31.662576
msg/async/AsyncMessenger.cc: 370: FAILED assert(!did_bind)
 ceph version 0.90-806-g55a5c5f (55a5c5f2923090ae4440cbea36a201c5345e4fbc)
 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x95) [0xe61511]
 2: (AsyncMessenger::~AsyncMessenger()+0x4d) [0xfacdb9]
 3: (AsyncMessenger::~AsyncMessenger()+0x18) [0xfacf60]
 4: (MessengerTest::TearDown()+0x38) [0xcd7ab0]
 5: (testing::Test::Run()+0xc8) [0xce471e]
 6: (testing::internal::TestInfoImpl::Run()+0xd8) [0xce4c56]
 7: (testing::TestCase::Run()+0xcb) [0xce515f]
 8: (testing::internal::UnitTestImpl::RunAllTests()+0x26e) [0xce9660]
 9: (testing::UnitTest::Run()+0x1c) [0xce8616]
 10: (main()+0x126) [0xcd55af]
 11: (__libc_start_main()+0xf5) [0x7f1fb31d5ec5]
 12: ./unittest_msgr() [0xccdba9]
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.
2015-01-09 16:28:31.667056 7f1fb50ca7c0 -1 msg/async/AsyncMessenger.cc: In function 'virtual AsyncMessenger::~AsyncMessenger()' thread 7f1fb50ca7c0 time 2015-01-09 16:28:31.662576
msg/async/AsyncMessenger.cc: 370: FAILED assert(!did_bind)

 ceph version 0.90-806-g55a5c5f (55a5c5f2923090ae4440cbea36a201c5345e4fbc)
 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x95) [0xe61511]
 2: (AsyncMessenger::~AsyncMessenger()+0x4d) [0xfacdb9]
 3: (AsyncMessenger::~AsyncMessenger()+0x18) [0xfacf60]
 4: (MessengerTest::TearDown()+0x38) [0xcd7ab0]
 5: (testing::Test::Run()+0xc8) [0xce471e]
 6: (testing::internal::TestInfoImpl::Run()+0xd8) [0xce4c56]
 7: (testing::TestCase::Run()+0xcb) [0xce515f]
 8: (testing::internal::UnitTestImpl::RunAllTests()+0x26e) [0xce9660]
 9: (testing::UnitTest::Run()+0x1c) [0xce8616]
 10: (main()+0x126) [0xcd55af]
 11: (__libc_start_main()+0xf5) [0x7f1fb31d5ec5]
 12: ./unittest_msgr() [0xccdba9]
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

--- begin dump of recent events ---
   -59> 2015-01-09 16:28:31.657727 7f1fb50ca7c0  5 asok(0x526fe90) register_command perfcounters_dump hook 0x5271f90
   -58> 2015-01-09 16:28:31.657772 7f1fb50ca7c0  5 asok(0x526fe90) register_command 1 hook 0x5271f90
   -57> 2015-01-09 16:28:31.657775 7f1fb50ca7c0  5 asok(0x526fe90) register_command perf dump hook 0x5271f90
   -56> 2015-01-09 16:28:31.657781 7f1fb50ca7c0  5 asok(0x526fe90) register_command perfcounters_schema hook 0x5271f90
   -55> 2015-01-09 16:28:31.657784 7f1fb50ca7c0  5 asok(0x526fe90) register_command 2 hook 0x5271f90
   -54> 2015-01-09 16:28:31.657789 7f1fb50ca7c0  5 asok(0x526fe90) register_command perf schema hook 0x5271f90
   -53> 2015-01-09 16:28:31.657794 7f1fb50ca7c0  5 asok(0x526fe90) register_command perf reset hook 0x5271f90
   -52> 2015-01-09 16:28:31.657799 7f1fb50ca7c0  5 asok(0x526fe90) register_command config show hook 0x5271f90
   -51> 2015-01-09 16:28:31.657803 7f1fb50ca7c0  5 asok(0x526fe90) register_command config set hook 0x5271f90
   -50> 2015-01-09 16:28:31.657806 7f1fb50ca7c0  5 asok(0x526fe90) register_command config get hook 0x5271f90
   -49> 2015-01-09 16:28:31.657809 7f1fb50ca7c0  5 asok(0x526fe90) register_command config diff hook 0x5271f90
   -48> 2015-01-09 16:28:31.657812 7f1fb50ca7c0  5 asok(0x526fe90) register_command log flush hook 0x5271f90
   -47> 2015-01-09 16:28:31.657815 7f1fb50ca7c0  5 asok(0x526fe90) register_command log dump hook 0x5271f90
   -46> 2015-01-09 16:28:31.657820 7f1fb50ca7c0  5 asok(0x526fe90) register_command log reopen hook 0x5271f90
   -45> 2015-01-09 16:28:31.660605 7f1fb50ca7c0 -1 WARNING: the following dangerous and experimental features are enabled: ms-type-async
   -44> 2015-01-09 16:28:31.660619 7f1fb50ca7c0  5 asok(0x526fe90) init /home/loic/software/ceph/ceph/src/out/client.admin.20000.asok
   -43> 2015-01-09 16:28:31.660641 7f1fb50ca7c0  5 asok(0x526fe90) bind_and_listen /home/loic/software/ceph/ceph/src/out/client.admin.20000.asok
   -42> 2015-01-09 16:28:31.660678 7f1fb50ca7c0  5 asok(0x526fe90) register_command 0 hook 0x52757b0
   -41> 2015-01-09 16:28:31.660684 7f1fb50ca7c0  5 asok(0x526fe90) register_command version hook 0x52757b0
   -40> 2015-01-09 16:28:31.660687 7f1fb50ca7c0  5 asok(0x526fe90) register_command git_version hook 0x52757b0
   -39> 2015-01-09 16:28:31.660690 7f1fb50ca7c0  5 asok(0x526fe90) register_command help hook 0x52771f0
   -38> 2015-01-09 16:28:31.660694 7f1fb50ca7c0  5 asok(0x526fe90) register_command get_command_descriptions hook 0x5275900
   -37> 2015-01-09 16:28:31.660735 7f1fb21b1700  5 asok(0x526fe90) entry start
   -36> 2015-01-09 16:28:31.660956 7f1fb50ca7c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
   -35> 2015-01-09 16:28:31.660960 7f1fb50ca7c0 -1 Please be aware that this feature is experimental, untested,
   -34> 2015-01-09 16:28:31.660962 7f1fb50ca7c0 -1 unsupported, and may result in data corruption, data loss,
   -33> 2015-01-09 16:28:31.660963 7f1fb50ca7c0 -1 and/or irreparable damage to your cluster.  Do not use
   -32> 2015-01-09 16:28:31.660964 7f1fb50ca7c0 -1 feature with important data.
   -31> 2015-01-09 16:28:31.661170 7f1fb50ca7c0 -1 WARNING: experimental feature 'ms-type-async' is enabled
   -30> 2015-01-09 16:28:31.661173 7f1fb50ca7c0 -1 Please be aware that this feature is experimental, untested,
   -29> 2015-01-09 16:28:31.661174 7f1fb50ca7c0 -1 unsupported, and may result in data corruption, data loss,
   -28> 2015-01-09 16:28:31.661174 7f1fb50ca7c0 -1 and/or irreparable damage to your cluster.  Do not use
   -27> 2015-01-09 16:28:31.661175 7f1fb50ca7c0 -1 feature with important data.
   -26> 2015-01-09 16:28:31.661443 7f1fb50ca7c0  1 -- 127.0.0.1:0/0 learned_addr learned my addr 127.0.0.1:0/0
   -25> 2015-01-09 16:28:31.661454 7f1fb50ca7c0  1  Processor -- bind bind my_inst.addr is 127.0.0.1:7293/20000
   -24> 2015-01-09 16:28:31.661457 7f1fb50ca7c0  1  Processor -- start start
   -23> 2015-01-09 16:28:31.661470 7f1fb50ca7c0  1 -- 127.0.0.1:7293/20000 start start
   -22> 2015-01-09 16:28:31.661489 7f1fb50ca7c0  1  Processor -- start start
   -21> 2015-01-09 16:28:31.661491 7f1fb50ca7c0  1 -- :/0 start start
   -20> 2015-01-09 16:28:31.661541 7f1fb50ca7c0  1 Event wakeup
   -19> 2015-01-09 16:28:31.661671 7f1fb19b0700  1 Event wakeup
   -18> 2015-01-09 16:28:31.661743 7f1fb09ae700  1 -- 127.0.0.1:7293/20000 >> :/0 conn(0x7f1f9c0008c0 sd=15 :7293 s=STATE_ACCEPTING pgs=0 cs=0 l=0)._process_connection sd=15 127.0.0.1:56526/0
   -17> 2015-01-09 16:28:31.661816 7f1fb11af700  1 -- 127.0.0.1:0/20000 learned_addr learned my addr 127.0.0.1:0/20000
   -16> 2015-01-09 16:28:31.661877 7f1fb09ae700  1 Event wakeup
   -15> 2015-01-09 16:28:31.661900 7f1fb09ae700  2 -- 127.0.0.1:7293/20000 >> 127.0.0.1:0/20000 conn(0x7f1f9c0008c0 sd=15 :7293 s=STATE_ACCEPTING_READY pgs=1 cs=1 l=1).handle_connect_msg accept write reply msg done
   -14> 2015-01-09 16:28:31.661920 7f1fb11af700  1 Event wakeup
   -13> 2015-01-09 16:28:31.661948 7f1fb11af700  1 Event wakeup
   -12> 2015-01-09 16:28:31.662095 7f1fb50ca7c0  1 -- 127.0.0.1:7293/20000 rebind rebind avoid 7293,7294,7295,7296,7297,7298,7299,7300,7301,7302
   -11> 2015-01-09 16:28:31.662165 7f1fb50ca7c0  1 -- 127.0.0.1:7293/20000 mark_down_all 
   -10> 2015-01-09 16:28:31.662175 7f1fb50ca7c0  5 -- 127.0.0.1:7293/20000 mark_down_all mark down 127.0.0.1:0/20000 0x7f1f9c0008c0
    -9> 2015-01-09 16:28:31.662181 7f1fb50ca7c0  1 Event wakeup
    -8> 2015-01-09 16:28:31.662221 7f1fb09ae700  1 Event wakeup
    -7> 2015-01-09 16:28:31.662226 7f1fb11af700  1 -- 127.0.0.1:0/20000 >> 127.0.0.1:7293/20000 conn(0x52a7260 sd=14 :0 s=STATE_OPEN pgs=1 cs=1 l=1).read_bulk Peer close file descriptor 14
    -6> 2015-01-09 16:28:31.662237 7f1fb11af700  1 -- 127.0.0.1:0/20000 >> 127.0.0.1:7293/20000 conn(0x52a7260 sd=14 :0 s=STATE_OPEN pgs=1 cs=1 l=1).process read tag failed, state is STATE_OPEN
    -5> 2015-01-09 16:28:31.662243 7f1fb11af700  1 Event wakeup
    -4> 2015-01-09 16:28:31.662266 7f1fb11af700  1 Event wakeup
    -3> 2015-01-09 16:28:31.662268 7f1fb50ca7c0  5 -- 127.0.0.1:7293/20000 mark_down_all delete 0x7f1f9c0008c0
    -2> 2015-01-09 16:28:31.662285 7f1fb50ca7c0  1  Processor -- rebind rebind avoid 7293,7294,7295,7296,7297,7298,7299,7300,7301,7302
    -1> 2015-01-09 16:28:31.662502 7f1fb50ca7c0 -1  Processor -- bind unable to bind to 127.0.0.1:7292 on any port in range 6800-7300: (98) Address already in use
     0> 2015-01-09 16:28:31.667056 7f1fb50ca7c0 -1 msg/async/AsyncMessenger.cc: In function 'virtual AsyncMessenger::~AsyncMessenger()' thread 7f1fb50ca7c0 time 2015-01-09 16:28:31.662576
msg/async/AsyncMessenger.cc: 370: FAILED assert(!did_bind)

 ceph version 0.90-806-g55a5c5f (55a5c5f2923090ae4440cbea36a201c5345e4fbc)
 1: (ceph::__ceph_assert_fail(char const*, char const*, int, char const*)+0x95) [0xe61511]
 2: (AsyncMessenger::~AsyncMessenger()+0x4d) [0xfacdb9]
 3: (AsyncMessenger::~AsyncMessenger()+0x18) [0xfacf60]
 4: (MessengerTest::TearDown()+0x38) [0xcd7ab0]
 5: (testing::Test::Run()+0xc8) [0xce471e]
 6: (testing::internal::TestInfoImpl::Run()+0xd8) [0xce4c56]
 7: (testing::TestCase::Run()+0xcb) [0xce515f]
 8: (testing::internal::UnitTestImpl::RunAllTests()+0x26e) [0xce9660]
 9: (testing::UnitTest::Run()+0x1c) [0xce8616]
 10: (main()+0x126) [0xcd55af]
 11: (__libc_start_main()+0xf5) [0x7f1fb31d5ec5]
 12: ./unittest_msgr() [0xccdba9]
 NOTE: a copy of the executable, or `objdump -rdS <executable>` is needed to interpret this.

#7 Updated by Haomai Wang over 8 years ago

Status changed from 12 to Resolved

https://github.com/ceph/ceph/pull/3211#event-221219768

Also available in: Atom PDF

Project

General

Profile

Ceph

Issues

Tags

Custom queries