Bug #10494
Updated by Loïc Dachary over 9 years ago
Steps to reproduce:
<pre>
$ 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
</pre>
it will eventually crash with:
<pre>
[ 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)
</pre>