Project

General

Profile

Actions

Bug #48108

closed

unittest_seastar_messenger fails

Added by Xuehan Xu over 3 years ago. Updated over 3 years ago.

Status:
Resolved
Priority:
Normal
Assignee:
Target version:
% Done:

0%

Source:
Tags:
Backport:
Regression:
No
Severity:
3 - minor
Reviewed:
Affected Versions:
ceph-qa-suite:
Pull request ID:
Crash signature (v1):
Crash signature (v2):

Description

Encountered this issue in github make check

183/210 Test #198: unittest_seastar_messenger ................***Exception: Child aborted 24.85 sec
WARNING: debug mode. Not for benchmarking or production
WARN  2020-11-04 03:52:18,446 [shard 0] seastar - Unable to set SCHED_FIFO scheduling policy for timer thread; latency impact possible. Try adding CAP_SYS_NICE
INFO  2020-11-04 03:52:19,050 [shard 0] ms - test_echo(rounds=512, keepalive_ratio=0.1, v2=false):
INFO  2020-11-04 03:52:19,052 [shard 0] ms - [osd.1(server2) v1:127.0.0.1:9011/2] bind: done
INFO  2020-11-04 03:52:19,052 [shard 0] ms - [osd.0(server1) v1:127.0.0.1:9010/1] bind: done
INFO  2020-11-04 03:52:19,098 [shard 0] ms - [osd.3(client2) - >> osd.? v1:127.0.0.1:9010/1] write_event: delay ...
INFO  2020-11-04 03:52:19,098 [shard 0] ms - [osd.2(client1) - >> osd.? v1:127.0.0.1:9011/2] write_event: delay ...
INFO  2020-11-04 03:52:19,180 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@51862 >> osd.? v1:127.0.0.1:9011/2] learned myaddr=127.0.0.1:0/3 (unbound) from v1:127.0.0.1:51862/0
INFO  2020-11-04 03:52:19,180 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@58225 >> osd.? v1:127.0.0.1:9010/1] learned myaddr=127.0.0.1:0/4 (unbound) from v1:127.0.0.1:58225/0
INFO  2020-11-04 03:52:23,763 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@58225 >> osd.? v1:127.0.0.1:9010/1]: finished sending 512 pings with 61 keepalives
INFO  2020-11-04 03:52:23,839 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@51862 >> osd.? v1:127.0.0.1:9011/2]: finished sending 512 pings with 57 keepalives
INFO  2020-11-04 03:52:37,486 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@51862 >> osd.? v1:127.0.0.1:9011/2]: finished receiving 512 pongs
INFO  2020-11-04 03:52:37,487 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@51862 >> osd.? v1:127.0.0.1:9011/2]: handshake 0.177571686, pingpong 18.211226015
INFO  2020-11-04 03:52:37,492 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@58225 >> osd.? v1:127.0.0.1:9010/1]: finished receiving 512 pongs
INFO  2020-11-04 03:52:37,492 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@58225 >> osd.? v1:127.0.0.1:9010/1]: handshake 0.179250722, pingpong 18.2155872
INFO  2020-11-04 03:52:37,492 [shard 0] ms - client1 shutdown...
INFO  2020-11-04 03:52:37,492 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@51862 >> osd.? v1:127.0.0.1:9011/2] closing: reset no, replace no
WARN  2020-11-04 03:52:37,493 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@51862 >> osd.? v1:127.0.0.1:9011/2] open fault: std::system_error (error crimson::net:4, read eof)
WARN  2020-11-04 03:52:37,493 [shard 0] ms - [osd.1(server2) v1:127.0.0.1:9011/2 >> osd.? v1:127.0.0.1:0/3@51862] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-11-04 03:52:37,493 [shard 0] ms - [osd.1(server2) v1:127.0.0.1:9011/2 >> osd.? v1:127.0.0.1:0/3@51862] closing: reset yes, replace no
INFO  2020-11-04 03:52:37,495 [shard 0] ms - client2 shutdown...
INFO  2020-11-04 03:52:37,495 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@58225 >> osd.? v1:127.0.0.1:9010/1] closing: reset no, replace no
WARN  2020-11-04 03:52:37,495 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@58225 >> osd.? v1:127.0.0.1:9010/1] open fault: std::system_error (error crimson::net:4, read eof)
WARN  2020-11-04 03:52:37,496 [shard 0] ms - [osd.0(server1) v1:127.0.0.1:9010/1 >> osd.? v1:127.0.0.1:0/4@58225] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-11-04 03:52:37,496 [shard 0] ms - [osd.0(server1) v1:127.0.0.1:9010/1 >> osd.? v1:127.0.0.1:0/4@58225] closing: reset yes, replace no
INFO  2020-11-04 03:52:37,496 [shard 0] ms - server1 shutdown...
INFO  2020-11-04 03:52:37,498 [shard 0] ms - server2 shutdown...
INFO  2020-11-04 03:52:37,499 [shard 0] ms - test_echo() done!

INFO  2020-11-04 03:52:37,499 [shard 0] ms - test_echo(rounds=512, keepalive_ratio=0.1, v2=true):
INFO  2020-11-04 03:52:37,500 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9010/1] bind: done
INFO  2020-11-04 03:52:37,500 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9011/2] bind: done
INFO  2020-11-04 03:52:37,501 [shard 0] ms - [osd.3(client2) - >> osd.? v2:127.0.0.1:9010/1] ProtocolV2::start_connect(): peer_addr=v2:127.0.0.1:9010/1, peer_name=osd.?, cc=10759306136260902454 policy(lossy=true, server=false, standby=false, resetcheck=false)
INFO  2020-11-04 03:52:37,501 [shard 0] ms - [osd.3(client2) - >> osd.? v2:127.0.0.1:9010/1] write_event: delay ...
INFO  2020-11-04 03:52:37,501 [shard 0] ms - [osd.2(client1) - >> osd.? v2:127.0.0.1:9011/2] ProtocolV2::start_connect(): peer_addr=v2:127.0.0.1:9011/2, peer_name=osd.?, cc=5292632113824920183 policy(lossy=true, server=false, standby=false, resetcheck=false)
INFO  2020-11-04 03:52:37,502 [shard 0] ms - [osd.2(client1) - >> osd.? v2:127.0.0.1:9011/2] write_event: delay ...
INFO  2020-11-04 03:52:37,503 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9011/2 >> unknown.? -@54252] ProtocolV2::start_accept(): target_addr=127.0.0.1:54252/0
INFO  2020-11-04 03:52:37,504 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9010/1 >> unknown.? -@50082] ProtocolV2::start_accept(): target_addr=127.0.0.1:50082/0
INFO  2020-11-04 03:52:37,514 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9010/1 >> osd.? -@50082] UPDATE: peer_type=osd, policy(lossy=true server=true standby=false resetcheck=false)
INFO  2020-11-04 03:52:37,516 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@50082 >> osd.? v2:127.0.0.1:9010/1] learned myaddr=127.0.0.1:0/4 (unbound) from v2:127.0.0.1:50082/0
INFO  2020-11-04 03:52:37,517 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9011/2 >> osd.? -@54252] UPDATE: peer_type=osd, policy(lossy=true server=true standby=false resetcheck=false)
INFO  2020-11-04 03:52:37,518 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@54252 >> osd.? v2:127.0.0.1:9011/2] learned myaddr=127.0.0.1:0/3 (unbound) from v2:127.0.0.1:54252/0
INFO  2020-11-04 03:52:37,568 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9010/1 >> osd.3 127.0.0.1:0/4@50082] established: gs=0, pgs=1, cs=0, client_cookie=10759306136260902454, server_cookie=0, in_seq=0, out_seq=0, out_q=0
INFO  2020-11-04 03:52:37,570 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@50082 >> osd.0 v2:127.0.0.1:9010/1] connected: gs=1, pgs=1, cs=0, client_cookie=10759306136260902454, server_cookie=0, in_seq=0, out_seq=0, out_q=378
INFO  2020-11-04 03:52:37,600 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9011/2 >> osd.2 127.0.0.1:0/3@54252] established: gs=0, pgs=1, cs=0, client_cookie=5292632113824920183, server_cookie=0, in_seq=0, out_seq=0, out_q=0
INFO  2020-11-04 03:52:37,606 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@54252 >> osd.1 v2:127.0.0.1:9011/2] connected: gs=1, pgs=1, cs=0, client_cookie=5292632113824920183, server_cookie=0, in_seq=0, out_seq=0, out_q=375
INFO  2020-11-04 03:52:37,768 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@50082 >> osd.0 v2:127.0.0.1:9010/1]: finished sending 512 pings with 69 keepalives
INFO  2020-11-04 03:52:37,797 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@54252 >> osd.1 v2:127.0.0.1:9011/2]: finished sending 512 pings with 69 keepalives
INFO  2020-11-04 03:52:40,426 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@50082 >> osd.0 v2:127.0.0.1:9010/1]: finished receiving 512 pongs
INFO  2020-11-04 03:52:40,428 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@50082 >> osd.0 v2:127.0.0.1:9010/1]: handshake 0.070268423, pingpong 2.856178596
INFO  2020-11-04 03:52:40,432 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@54252 >> osd.1 v2:127.0.0.1:9011/2]: finished receiving 512 pongs
INFO  2020-11-04 03:52:40,433 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@54252 >> osd.1 v2:127.0.0.1:9011/2]: handshake 0.104952403, pingpong 2.826381452
INFO  2020-11-04 03:52:40,434 [shard 0] ms - client1 shutdown...
INFO  2020-11-04 03:52:40,435 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@54252 >> osd.1 v2:127.0.0.1:9011/2] closing: reset no, replace no
INFO  2020-11-04 03:52:40,437 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9011/2 >> osd.2 127.0.0.1:0/3@54252] execute_ready(): fault at READY on lossy channel, going to CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-11-04 03:52:40,437 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9011/2 >> osd.2 127.0.0.1:0/3@54252] closing: reset yes, replace no
INFO  2020-11-04 03:52:40,439 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@54252 >> osd.1 v2:127.0.0.1:9011/2] execute_ready(): protocol aborted at CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-11-04 03:52:40,443 [shard 0] ms - client2 shutdown...
INFO  2020-11-04 03:52:40,444 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@50082 >> osd.0 v2:127.0.0.1:9010/1] closing: reset no, replace no
INFO  2020-11-04 03:52:40,446 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@50082 >> osd.0 v2:127.0.0.1:9010/1] execute_ready(): protocol aborted at CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-11-04 03:52:40,448 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9010/1 >> osd.3 127.0.0.1:0/4@50082] execute_ready(): fault at READY on lossy channel, going to CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-11-04 03:52:40,448 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9010/1 >> osd.3 127.0.0.1:0/4@50082] closing: reset yes, replace no
INFO  2020-11-04 03:52:40,452 [shard 0] ms - server1 shutdown...
INFO  2020-11-04 03:52:40,455 [shard 0] ms - server2 shutdown...
INFO  2020-11-04 03:52:40,459 [shard 0] ms - test_echo() done!

INFO  2020-11-04 03:52:40,460 [shard 0] ms - test_concurrent_dispatch(v2=false):
INFO  2020-11-04 03:52:40,462 [shard 0] ms - [osd.4(server3) v1:127.0.0.1:9010/5] bind: done
INFO  2020-11-04 03:52:40,464 [shard 0] ms - [osd.5(client3) - >> osd.? v1:127.0.0.1:9010/5] write_event: delay ...
INFO  2020-11-04 03:52:40,472 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@64431 >> osd.? v1:127.0.0.1:9010/5] learned myaddr=127.0.0.1:0/6 (unbound) from v1:127.0.0.1:64431/0
INFO  2020-11-04 03:52:40,491 [shard 0] ms - client shutdown...
INFO  2020-11-04 03:52:40,493 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@64431 >> osd.? v1:127.0.0.1:9010/5] closing: reset no, replace no
WARN  2020-11-04 03:52:40,496 [shard 0] ms - [osd.4(server3) v1:127.0.0.1:9010/5 >> osd.? v1:127.0.0.1:0/6@64431] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-11-04 03:52:40,496 [shard 0] ms - [osd.4(server3) v1:127.0.0.1:9010/5 >> osd.? v1:127.0.0.1:0/6@64431] closing: reset yes, replace no
WARN  2020-11-04 03:52:40,497 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@64431 >> osd.? v1:127.0.0.1:9010/5] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-11-04 03:52:40,501 [shard 0] ms - server shutdown...
INFO  2020-11-04 03:52:40,505 [shard 0] ms - test_concurrent_dispatch() done!

INFO  2020-11-04 03:52:40,505 [shard 0] ms - test_concurrent_dispatch(v2=true):
INFO  2020-11-04 03:52:40,507 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9010/5] bind: done
INFO  2020-11-04 03:52:40,509 [shard 0] ms - [osd.5(client3) - >> osd.? v2:127.0.0.1:9010/5] ProtocolV2::start_connect(): peer_addr=v2:127.0.0.1:9010/5, peer_name=osd.?, cc=10031162860024635984 policy(lossy=true, server=false, standby=false, resetcheck=false)
INFO  2020-11-04 03:52:40,510 [shard 0] ms - [osd.5(client3) - >> osd.? v2:127.0.0.1:9010/5] write_event: delay ...
INFO  2020-11-04 03:52:40,513 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9010/5 >> unknown.? -@56731] ProtocolV2::start_accept(): target_addr=127.0.0.1:56731/0
INFO  2020-11-04 03:52:40,530 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@56731 >> osd.? v2:127.0.0.1:9010/5] learned myaddr=127.0.0.1:0/6 (unbound) from v2:127.0.0.1:56731/0
INFO  2020-11-04 03:52:40,531 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9010/5 >> osd.? -@56731] UPDATE: peer_type=osd, policy(lossy=true server=true standby=false resetcheck=false)
INFO  2020-11-04 03:52:40,558 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9010/5 >> osd.5 127.0.0.1:0/6@56731] established: gs=0, pgs=1, cs=0, client_cookie=10031162860024635984, server_cookie=0, in_seq=0, out_seq=0, out_q=0
INFO  2020-11-04 03:52:40,562 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@56731 >> osd.4 v2:127.0.0.1:9010/5] connected: gs=1, pgs=1, cs=0, client_cookie=10031162860024635984, server_cookie=0, in_seq=0, out_seq=0, out_q=2
INFO  2020-11-04 03:52:40,572 [shard 0] ms - client shutdown...
INFO  2020-11-04 03:52:40,573 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@56731 >> osd.4 v2:127.0.0.1:9010/5] closing: reset no, replace no
INFO  2020-11-04 03:52:40,577 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@56731 >> osd.4 v2:127.0.0.1:9010/5] execute_ready(): protocol aborted at CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-11-04 03:52:40,578 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9010/5 >> osd.5 127.0.0.1:0/6@56731] execute_ready(): fault at READY on lossy channel, going to CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-11-04 03:52:40,579 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9010/5 >> osd.5 127.0.0.1:0/6@56731] closing: reset yes, replace no
INFO  2020-11-04 03:52:40,584 [shard 0] ms - server shutdown...
INFO  2020-11-04 03:52:40,589 [shard 0] ms - test_concurrent_dispatch() done!

INFO  2020-11-04 03:52:40,589 [shard 0] ms - test_preemptive_shutdown(v2=false):
INFO  2020-11-04 03:52:40,592 [shard 0] ms - [osd.6(server4) v1:127.0.0.1:9010/7] bind: done
INFO  2020-11-04 03:52:40,595 [shard 0] ms - [osd.7(client4) - >> osd.? v1:127.0.0.1:9010/7] write_event: delay ...
INFO  2020-11-04 03:52:40,607 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@59263 >> osd.? v1:127.0.0.1:9010/7] learned myaddr=127.0.0.1:0/8 (unbound) from v1:127.0.0.1:59263/0
INFO  2020-11-04 03:52:40,697 [shard 0] ms - client shutdown...
INFO  2020-11-04 03:52:40,697 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@59263 >> osd.? v1:127.0.0.1:9010/7] closing: reset no, replace no
INFO  2020-11-04 03:52:40,700 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@59263 >> osd.? v1:127.0.0.1:9010/7] write_event: dropped and set exit_open
WARN  2020-11-04 03:52:40,714 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@59263 >> osd.? v1:127.0.0.1:9010/7] open fault: seastar::gate_closed_exception (gate closed)
INFO  2020-11-04 03:52:40,728 [shard 0] ms - server shutdown...
INFO  2020-11-04 03:52:40,736 [shard 0] ms - [osd.6(server4) v1:127.0.0.1:9010/7 >> osd.? v1:127.0.0.1:0/8@59263] closing: reset no, replace no
WARN  2020-11-04 03:52:40,738 [shard 0] ms - [osd.6(server4) v1:127.0.0.1:9010/7 >> osd.? v1:127.0.0.1:0/8@59263] open fault: seastar::gate_closed_exception (gate closed)
INFO  2020-11-04 03:52:40,741 [shard 0] ms - test_preemptive_shutdown() done!

INFO  2020-11-04 03:52:40,742 [shard 0] ms - test_preemptive_shutdown(v2=true):
INFO  2020-11-04 03:52:40,744 [shard 0] ms - [osd.6(server4) v2:127.0.0.1:9010/7] bind: done
INFO  2020-11-04 03:52:40,746 [shard 0] ms - [osd.7(client4) - >> osd.? v2:127.0.0.1:9010/7] ProtocolV2::start_connect(): peer_addr=v2:127.0.0.1:9010/7, peer_name=osd.?, cc=18443549546525755972 policy(lossy=true, server=false, standby=false, resetcheck=false)
INFO  2020-11-04 03:52:40,747 [shard 0] ms - [osd.7(client4) - >> osd.? v2:127.0.0.1:9010/7] write_event: delay ...
INFO  2020-11-04 03:52:40,753 [shard 0] ms - [osd.6(server4) v2:127.0.0.1:9010/7 >> unknown.? -@56020] ProtocolV2::start_accept(): target_addr=127.0.0.1:56020/0
INFO  2020-11-04 03:52:40,776 [shard 0] ms - [osd.6(server4) v2:127.0.0.1:9010/7 >> osd.? -@56020] UPDATE: peer_type=osd, policy(lossy=true server=true standby=false resetcheck=false)
INFO  2020-11-04 03:52:40,780 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@56020 >> osd.? v2:127.0.0.1:9010/7] learned myaddr=127.0.0.1:0/8 (unbound) from v2:127.0.0.1:56020/0
INFO  2020-11-04 03:52:40,849 [shard 0] ms - client shutdown...
INFO  2020-11-04 03:52:40,849 [shard 0] ms - [osd.6(server4) v2:127.0.0.1:9010/7 >> osd.7 127.0.0.1:0/8@56020] established: gs=0, pgs=1, cs=0, client_cookie=18443549546525755972, server_cookie=0, in_seq=0, out_seq=0, out_q=0
INFO  2020-11-04 03:52:40,851 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@56020 >> osd.? v2:127.0.0.1:9010/7] closing: reset no, replace no
INFO  2020-11-04 03:52:40,853 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@56020 >> osd.? v2:127.0.0.1:9010/7] write_event: dropped
INFO  2020-11-04 03:52:40,857 [shard 0] ms - [osd.6(server4) v2:127.0.0.1:9010/7 >> osd.7 127.0.0.1:0/8@56020] execute_ready(): fault at READY on lossy channel, going to CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-11-04 03:52:40,858 [shard 0] ms - [osd.6(server4) v2:127.0.0.1:9010/7 >> osd.7 127.0.0.1:0/8@56020] closing: reset yes, replace no
INFO  2020-11-04 03:52:40,861 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@56020 >> osd.6 v2:127.0.0.1:9010/7] execute_connecting(): protocol aborted at CLOSING -- std::system_error (error crimson::net:6, protocol aborted)
INFO  2020-11-04 03:52:40,868 [shard 0] ms - server shutdown...
INFO  2020-11-04 03:52:40,871 [shard 0] ms - test_preemptive_shutdown() done!

INFO  2020-11-04 03:52:40,872 [shard 0] ms - test_v2_protocol: start local TestPeer at v2:127.0.0.1:9013/0...
ERROR 2020-11-04 03:52:40,876 [shard 0] ms - FailoverTestPeer::init(v2:127.0.0.1:9013/0) likely there is another instance of unittest_seastar_messenger running
Aborting on shard 0.
Backtrace:
  /usr/lib/x86_64-linux-gnu/libasan.so.5+0x000000000006bb2f
  0x000000000d6fb272
  0x000000000d6d3431
  0x000000000d58872a
  0x000000000d58889d
  0x000000000d5eaa5b
  0x000000000d6225ba
  0x000000000d622655
  /lib/x86_64-linux-gnu/libpthread.so.0+0x000000000001288f
  /lib/x86_64-linux-gnu/libc.so.6+0x000000000003ee96
  /lib/x86_64-linux-gnu/libc.so.6+0x0000000000040800
  0x000000000add2ace
  0x000000000aebaf6e
  0x000000000ae55e4f
  0x000000000afdd4a0
  0x000000000afa7c96
  0x000000000af3fdf7
  0x000000000afdd7cc
  0x000000000b166cd3
  0x000000000b145f0e
  0x000000000b166dca
  0x000000000b1459c3
  0x000000000b24c49a
  0x000000000d5cee0e
  0x000000000d5d3460
  0x000000000d5d898a
  0x000000000d44f7b4
  0x000000000d44d679
  0x000000000d44dc19
  0x000000000ae37505
  /lib/x86_64-linux-gnu/libc.so.6+0x0000000000021b96
  0x000000000ad910f9

Files

msgr.log (22.4 KB) msgr.log Kefu Chai, 11/10/2020 09:19 AM

Related issues 1 (0 open1 closed)

Related to crimson - Bug #47324: unittest_seastar_messenger fails in "make check" run randomlyWon't FixYingxin Cheng

Actions
Actions #1

Updated by Kefu Chai over 3 years ago

  • Assignee set to Yingxin Cheng

Yingxin, could you take a look at this issue?

Actions #2

Updated by Yingxin Cheng over 3 years ago

Ah, it is said "FailoverTestPeer::init(v2:127.0.0.1:9013/0) likely there is another instance of unittest_seastar_messenger running", which is already addressed in https://tracker.ceph.com/issues/47324.

Actions #3

Updated by Kefu Chai over 3 years ago

  • Related to Bug #47324: unittest_seastar_messenger fails in "make check" run randomly added
Actions #4

Updated by Kefu Chai over 3 years ago

Actions #5

Updated by Yingxin Cheng over 3 years ago

The current unittest-seastar-messenger doesn't handle bind failure correctly and results in undefined behaviors, including forever waiting for the unresolved future. I improved and fixed start/stop/bind interfaces in https://github.com/ceph/ceph/pull/38360. Please paste logs (except the bind failure logs) here if the issue is happened again.

Actions #6

Updated by Kefu Chai over 3 years ago

185/212 Test #199: unittest-seastar-messenger ................***Exception: Child aborted 31.05 sec
WARNING: debug mode. Not for benchmarking or production
WARN  2020-12-02 09:37:35,337 [shard 0] seastar - Unable to set SCHED_FIFO scheduling policy for timer thread; latency impact possible. Try adding CAP_SYS_NICE
INFO  2020-12-02 09:37:36,025 [shard 0] ms - test_echo(rounds=512, keepalive_ratio=0.1, v2=false):
INFO  2020-12-02 09:37:36,027 [shard 0] ms - [osd.1(server2) v1:127.0.0.1:9011/2] bind: done
INFO  2020-12-02 09:37:36,027 [shard 0] ms - [osd.0(server1) v1:127.0.0.1:9010/1] bind: done
INFO  2020-12-02 09:37:36,084 [shard 0] ms - [osd.3(client2) - >> osd.? v1:127.0.0.1:9010/1] write_event: delay ...
INFO  2020-12-02 09:37:36,084 [shard 0] ms - [osd.2(client1) - >> osd.? v1:127.0.0.1:9011/2] write_event: delay ...
INFO  2020-12-02 09:37:36,133 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@62546 >> osd.? v1:127.0.0.1:9011/2] learned myaddr=127.0.0.1:0/3 (unbound) from v1:127.0.0.1:62546/0
INFO  2020-12-02 09:37:36,133 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@49985 >> osd.? v1:127.0.0.1:9010/1] learned myaddr=127.0.0.1:0/4 (unbound) from v1:127.0.0.1:49985/0
INFO  2020-12-02 09:37:40,853 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@49985 >> osd.? v1:127.0.0.1:9010/1]: finished sending 512 pings with 69 keepalives
INFO  2020-12-02 09:37:40,992 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@62546 >> osd.? v1:127.0.0.1:9011/2]: finished sending 512 pings with 51 keepalives
INFO  2020-12-02 09:37:56,675 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@62546 >> osd.? v1:127.0.0.1:9011/2]: finished receiving 512 pongs
INFO  2020-12-02 09:37:56,676 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@62546 >> osd.? v1:127.0.0.1:9011/2]: handshake 0.142323669, pingpong 20.449314391
INFO  2020-12-02 09:37:56,715 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@49985 >> osd.? v1:127.0.0.1:9010/1]: finished receiving 512 pongs
INFO  2020-12-02 09:37:56,715 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@49985 >> osd.? v1:127.0.0.1:9010/1]: handshake 0.143442384, pingpong 20.488801521
INFO  2020-12-02 09:37:56,716 [shard 0] ms - client1 shutdown...
INFO  2020-12-02 09:37:56,716 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@62546 >> osd.? v1:127.0.0.1:9011/2] closing: reset no, replace no
WARN  2020-12-02 09:37:56,717 [shard 0] ms - [osd.1(server2) v1:127.0.0.1:9011/2 >> osd.? v1:127.0.0.1:0/3@62546] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-12-02 09:37:56,717 [shard 0] ms - [osd.1(server2) v1:127.0.0.1:9011/2 >> osd.? v1:127.0.0.1:0/3@62546] closing: reset yes, replace no
WARN  2020-12-02 09:37:56,718 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@62546 >> osd.? v1:127.0.0.1:9011/2] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-12-02 09:37:56,719 [shard 0] ms - client2 shutdown...
INFO  2020-12-02 09:37:56,720 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@49985 >> osd.? v1:127.0.0.1:9010/1] closing: reset no, replace no
WARN  2020-12-02 09:37:56,721 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@49985 >> osd.? v1:127.0.0.1:9010/1] open fault: std::system_error (error crimson::net:4, read eof)
WARN  2020-12-02 09:37:56,721 [shard 0] ms - [osd.0(server1) v1:127.0.0.1:9010/1 >> osd.? v1:127.0.0.1:0/4@49985] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-12-02 09:37:56,722 [shard 0] ms - [osd.0(server1) v1:127.0.0.1:9010/1 >> osd.? v1:127.0.0.1:0/4@49985] closing: reset yes, replace no
INFO  2020-12-02 09:37:56,723 [shard 0] ms - server1 shutdown...
INFO  2020-12-02 09:37:56,725 [shard 0] ms - server2 shutdown...
INFO  2020-12-02 09:37:56,726 [shard 0] ms - test_echo() done!

INFO  2020-12-02 09:37:56,726 [shard 0] ms - test_echo(rounds=512, keepalive_ratio=0.1, v2=true):
INFO  2020-12-02 09:37:56,727 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9010/1] bind: done
INFO  2020-12-02 09:37:56,728 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9011/2] bind: done
INFO  2020-12-02 09:37:56,729 [shard 0] ms - [osd.3(client2) - >> osd.? v2:127.0.0.1:9010/1] ProtocolV2::start_connect(): peer_addr=v2:127.0.0.1:9010/1, peer_name=osd.?, cc=7040800483238218448 policy(lossy=true, server=false, standby=false, resetcheck=false)
INFO  2020-12-02 09:37:56,729 [shard 0] ms - [osd.3(client2) - >> osd.? v2:127.0.0.1:9010/1] write_event: delay ...
INFO  2020-12-02 09:37:56,729 [shard 0] ms - [osd.2(client1) - >> osd.? v2:127.0.0.1:9011/2] ProtocolV2::start_connect(): peer_addr=v2:127.0.0.1:9011/2, peer_name=osd.?, cc=5932627855944194358 policy(lossy=true, server=false, standby=false, resetcheck=false)
INFO  2020-12-02 09:37:56,730 [shard 0] ms - [osd.2(client1) - >> osd.? v2:127.0.0.1:9011/2] write_event: delay ...
INFO  2020-12-02 09:37:56,731 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9011/2 >> unknown.? -@53005] ProtocolV2::start_accept(): target_addr=127.0.0.1:53005/0
INFO  2020-12-02 09:37:56,733 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9010/1 >> unknown.? -@61556] ProtocolV2::start_accept(): target_addr=127.0.0.1:61556/0
INFO  2020-12-02 09:37:56,744 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@53005 >> osd.? v2:127.0.0.1:9011/2] learned myaddr=127.0.0.1:0/3 (unbound) from v2:127.0.0.1:53005/0
INFO  2020-12-02 09:37:56,746 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9010/1 >> osd.? -@61556] UPDATE: peer_type=osd, policy(lossy=true server=true standby=false resetcheck=false)
INFO  2020-12-02 09:37:56,746 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9011/2 >> osd.? -@53005] UPDATE: peer_type=osd, policy(lossy=true server=true standby=false resetcheck=false)
INFO  2020-12-02 09:37:56,747 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@61556 >> osd.? v2:127.0.0.1:9010/1] learned myaddr=127.0.0.1:0/4 (unbound) from v2:127.0.0.1:61556/0
INFO  2020-12-02 09:37:56,760 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9011/2 >> osd.2 127.0.0.1:0/3@53005] established: gs=0, pgs=1, cs=0, client_cookie=5932627855944194358, server_cookie=0, in_seq=0, out_seq=0, out_q=0
INFO  2020-12-02 09:37:56,762 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@53005 >> osd.1 v2:127.0.0.1:9011/2] connected: gs=1, pgs=1, cs=0, client_cookie=5932627855944194358, server_cookie=0, in_seq=0, out_seq=0, out_q=60
INFO  2020-12-02 09:37:56,805 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9010/1 >> osd.3 127.0.0.1:0/4@61556] established: gs=0, pgs=1, cs=0, client_cookie=7040800483238218448, server_cookie=0, in_seq=0, out_seq=0, out_q=0
INFO  2020-12-02 09:37:56,812 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@61556 >> osd.0 v2:127.0.0.1:9010/1] connected: gs=1, pgs=1, cs=0, client_cookie=7040800483238218448, server_cookie=0, in_seq=0, out_seq=0, out_q=136
INFO  2020-12-02 09:37:58,170 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@53005 >> osd.1 v2:127.0.0.1:9011/2]: finished sending 512 pings with 68 keepalives
INFO  2020-12-02 09:37:58,180 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@61556 >> osd.0 v2:127.0.0.1:9010/1]: finished sending 512 pings with 40 keepalives
INFO  2020-12-02 09:38:03,526 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@61556 >> osd.0 v2:127.0.0.1:9010/1]: finished receiving 512 pongs
INFO  2020-12-02 09:38:03,527 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@53005 >> osd.1 v2:127.0.0.1:9011/2]: finished receiving 512 pongs
INFO  2020-12-02 09:38:03,527 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@61556 >> osd.0 v2:127.0.0.1:9010/1]: handshake 0.083707841, pingpong 6.714484047
INFO  2020-12-02 09:38:03,528 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@53005 >> osd.1 v2:127.0.0.1:9011/2]: handshake 0.032873084, pingpong 6.765007198
INFO  2020-12-02 09:38:03,528 [shard 0] ms - client1 shutdown...
INFO  2020-12-02 09:38:03,528 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@53005 >> osd.1 v2:127.0.0.1:9011/2] closing: reset no, replace no
INFO  2020-12-02 09:38:03,529 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9011/2 >> osd.2 127.0.0.1:0/3@53005] execute_ready(): fault at READY on lossy channel, going to CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-02 09:38:03,529 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9011/2 >> osd.2 127.0.0.1:0/3@53005] closing: reset yes, replace no
INFO  2020-12-02 09:38:03,530 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@53005 >> osd.1 v2:127.0.0.1:9011/2] execute_ready(): protocol aborted at CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-02 09:38:03,532 [shard 0] ms - client2 shutdown...
INFO  2020-12-02 09:38:03,532 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@61556 >> osd.0 v2:127.0.0.1:9010/1] closing: reset no, replace no
INFO  2020-12-02 09:38:03,548 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@61556 >> osd.0 v2:127.0.0.1:9010/1] execute_ready(): protocol aborted at CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-02 09:38:03,548 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9010/1 >> osd.3 127.0.0.1:0/4@61556] execute_ready(): fault at READY on lossy channel, going to CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-02 09:38:03,549 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9010/1 >> osd.3 127.0.0.1:0/4@61556] closing: reset yes, replace no
INFO  2020-12-02 09:38:03,552 [shard 0] ms - server1 shutdown...
INFO  2020-12-02 09:38:03,555 [shard 0] ms - server2 shutdown...
INFO  2020-12-02 09:38:03,559 [shard 0] ms - test_echo() done!

INFO  2020-12-02 09:38:03,559 [shard 0] ms - test_concurrent_dispatch(v2=false):
INFO  2020-12-02 09:38:03,562 [shard 0] ms - [osd.4(server3) v1:127.0.0.1:9010/5] bind: done
INFO  2020-12-02 09:38:03,564 [shard 0] ms - [osd.5(client3) - >> osd.? v1:127.0.0.1:9010/5] write_event: delay ...
INFO  2020-12-02 09:38:03,571 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@57516 >> osd.? v1:127.0.0.1:9010/5] learned myaddr=127.0.0.1:0/6 (unbound) from v1:127.0.0.1:57516/0
INFO  2020-12-02 09:38:03,590 [shard 0] ms - client shutdown...
INFO  2020-12-02 09:38:03,591 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@57516 >> osd.? v1:127.0.0.1:9010/5] closing: reset no, replace no
WARN  2020-12-02 09:38:03,593 [shard 0] ms - [osd.4(server3) v1:127.0.0.1:9010/5 >> osd.? v1:127.0.0.1:0/6@57516] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-12-02 09:38:03,593 [shard 0] ms - [osd.4(server3) v1:127.0.0.1:9010/5 >> osd.? v1:127.0.0.1:0/6@57516] closing: reset yes, replace no
WARN  2020-12-02 09:38:03,594 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@57516 >> osd.? v1:127.0.0.1:9010/5] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-12-02 09:38:03,598 [shard 0] ms - server shutdown...
INFO  2020-12-02 09:38:03,602 [shard 0] ms - test_concurrent_dispatch() done!

INFO  2020-12-02 09:38:03,602 [shard 0] ms - test_concurrent_dispatch(v2=true):
INFO  2020-12-02 09:38:03,604 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9010/5] bind: done
INFO  2020-12-02 09:38:03,606 [shard 0] ms - [osd.5(client3) - >> osd.? v2:127.0.0.1:9010/5] ProtocolV2::start_connect(): peer_addr=v2:127.0.0.1:9010/5, peer_name=osd.?, cc=9064938719887311083 policy(lossy=true, server=false, standby=false, resetcheck=false)
INFO  2020-12-02 09:38:03,607 [shard 0] ms - [osd.5(client3) - >> osd.? v2:127.0.0.1:9010/5] write_event: delay ...
INFO  2020-12-02 09:38:03,609 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9010/5 >> unknown.? -@58611] ProtocolV2::start_accept(): target_addr=127.0.0.1:58611/0
INFO  2020-12-02 09:38:03,623 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@58611 >> osd.? v2:127.0.0.1:9010/5] learned myaddr=127.0.0.1:0/6 (unbound) from v2:127.0.0.1:58611/0
INFO  2020-12-02 09:38:03,627 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9010/5 >> osd.? -@58611] UPDATE: peer_type=osd, policy(lossy=true server=true standby=false resetcheck=false)
INFO  2020-12-02 09:38:03,644 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9010/5 >> osd.5 127.0.0.1:0/6@58611] established: gs=0, pgs=1, cs=0, client_cookie=9064938719887311083, server_cookie=0, in_seq=0, out_seq=0, out_q=0
INFO  2020-12-02 09:38:03,648 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@58611 >> osd.4 v2:127.0.0.1:9010/5] connected: gs=1, pgs=1, cs=0, client_cookie=9064938719887311083, server_cookie=0, in_seq=0, out_seq=0, out_q=2
INFO  2020-12-02 09:38:03,656 [shard 0] ms - client shutdown...
INFO  2020-12-02 09:38:03,657 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@58611 >> osd.4 v2:127.0.0.1:9010/5] closing: reset no, replace no
INFO  2020-12-02 09:38:03,660 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@58611 >> osd.4 v2:127.0.0.1:9010/5] execute_ready(): protocol aborted at CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-02 09:38:03,661 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9010/5 >> osd.5 127.0.0.1:0/6@58611] execute_ready(): fault at READY on lossy channel, going to CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-02 09:38:03,662 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9010/5 >> osd.5 127.0.0.1:0/6@58611] closing: reset yes, replace no
INFO  2020-12-02 09:38:03,665 [shard 0] ms - server shutdown...
INFO  2020-12-02 09:38:03,668 [shard 0] ms - test_concurrent_dispatch() done!

INFO  2020-12-02 09:38:03,668 [shard 0] ms - test_preemptive_shutdown(v2=false):
INFO  2020-12-02 09:38:03,670 [shard 0] ms - [osd.6(server4) v1:127.0.0.1:9010/7] bind: done
INFO  2020-12-02 09:38:03,672 [shard 0] ms - [osd.7(client4) - >> osd.? v1:127.0.0.1:9010/7] write_event: delay ...
INFO  2020-12-02 09:38:03,679 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@62820 >> osd.? v1:127.0.0.1:9010/7] learned myaddr=127.0.0.1:0/8 (unbound) from v1:127.0.0.1:62820/0
INFO  2020-12-02 09:38:03,773 [shard 0] ms - client shutdown...
INFO  2020-12-02 09:38:03,774 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@62820 >> osd.? v1:127.0.0.1:9010/7] closing: reset no, replace no
INFO  2020-12-02 09:38:03,775 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@62820 >> osd.? v1:127.0.0.1:9010/7] write_event: nothing queued at drop, set exit_open
WARN  2020-12-02 09:38:03,780 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@62820 >> osd.? v1:127.0.0.1:9010/7] open fault: seastar::gate_closed_exception (gate closed)
INFO  2020-12-02 09:38:03,788 [shard 0] ms - server shutdown...
INFO  2020-12-02 09:38:03,794 [shard 0] ms - [osd.6(server4) v1:127.0.0.1:9010/7 >> osd.? v1:127.0.0.1:0/8@62820] closing: reset no, replace no
WARN  2020-12-02 09:38:03,796 [shard 0] ms - [osd.6(server4) v1:127.0.0.1:9010/7 >> osd.? v1:127.0.0.1:0/8@62820] open fault: seastar::gate_closed_exception (gate closed)
INFO  2020-12-02 09:38:03,799 [shard 0] ms - test_preemptive_shutdown() done!

INFO  2020-12-02 09:38:03,799 [shard 0] ms - test_preemptive_shutdown(v2=true):
INFO  2020-12-02 09:38:03,801 [shard 0] ms - [osd.6(server4) v2:127.0.0.1:9010/7] bind: done
INFO  2020-12-02 09:38:03,803 [shard 0] ms - [osd.7(client4) - >> osd.? v2:127.0.0.1:9010/7] ProtocolV2::start_connect(): peer_addr=v2:127.0.0.1:9010/7, peer_name=osd.?, cc=9547952022115139158 policy(lossy=true, server=false, standby=false, resetcheck=false)
INFO  2020-12-02 09:38:03,804 [shard 0] ms - [osd.7(client4) - >> osd.? v2:127.0.0.1:9010/7] write_event: delay ...
INFO  2020-12-02 09:38:03,807 [shard 0] ms - [osd.6(server4) v2:127.0.0.1:9010/7 >> unknown.? -@56000] ProtocolV2::start_accept(): target_addr=127.0.0.1:56000/0
INFO  2020-12-02 09:38:03,830 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@56000 >> osd.? v2:127.0.0.1:9010/7] learned myaddr=127.0.0.1:0/8 (unbound) from v2:127.0.0.1:56000/0
INFO  2020-12-02 09:38:03,833 [shard 0] ms - [osd.6(server4) v2:127.0.0.1:9010/7 >> osd.? -@56000] UPDATE: peer_type=osd, policy(lossy=true server=true standby=false resetcheck=false)
INFO  2020-12-02 09:38:03,892 [shard 0] ms - [osd.6(server4) v2:127.0.0.1:9010/7 >> osd.7 127.0.0.1:0/8@56000] established: gs=0, pgs=1, cs=0, client_cookie=9547952022115139158, server_cookie=0, in_seq=0, out_seq=0, out_q=0
INFO  2020-12-02 09:38:03,898 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@56000 >> osd.6 v2:127.0.0.1:9010/7] connected: gs=1, pgs=1, cs=0, client_cookie=9547952022115139158, server_cookie=0, in_seq=0, out_seq=0, out_q=161
INFO  2020-12-02 09:38:03,915 [shard 0] ms - client shutdown...
INFO  2020-12-02 09:38:03,916 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@56000 >> osd.6 v2:127.0.0.1:9010/7] closing: reset no, replace no
INFO  2020-12-02 09:38:03,917 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@56000 >> osd.6 v2:127.0.0.1:9010/7] write_event: nothing queued at drop, set exit_open
INFO  2020-12-02 09:38:03,918 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@56000 >> osd.6 v2:127.0.0.1:9010/7] execute_ready(): protocol aborted at CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-02 09:38:03,921 [shard 0] ms - server shutdown...
INFO  2020-12-02 09:38:03,922 [shard 0] ms - [osd.6(server4) v2:127.0.0.1:9010/7 >> osd.7 127.0.0.1:0/8@56000] closing: reset no, replace no
INFO  2020-12-02 09:38:04,033 [shard 0] ms - [osd.6(server4) v2:127.0.0.1:9010/7 >> osd.7 127.0.0.1:0/8@56000] execute_ready(): protocol aborted at CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-02 09:38:04,034 [shard 0] ms - test_preemptive_shutdown() done!

INFO  2020-12-02 09:38:04,035 [shard 0] ms - test_v2_protocol: start local TestPeer at v2:127.0.0.1:9013/0...
ERROR 2020-12-02 09:38:04,036 [shard 0] ms - FailoverTestPeer::init(v2:127.0.0.1:9013/0) likely there is another instance of unittest_seastar_messenger running
Aborting on shard 0.
Backtrace:
  /usr/lib/x86_64-linux-gnu/libasan.so.5+0x000000000006bb2f
  0x000000000da09dd2
  0x000000000d9e1f91
  0x000000000d89728a
  0x000000000d8973fd
  0x000000000d8f95bb
  0x000000000d93111a
  0x000000000d9311b5
  /lib/x86_64-linux-gnu/libpthread.so.0+0x000000000001288f
  /lib/x86_64-linux-gnu/libc.so.6+0x000000000003ee96
  /lib/x86_64-linux-gnu/libc.so.6+0x0000000000040800
  0x000000000b0c3f2e
  0x000000000b1ac3ce
  0x000000000b1472af
  0x000000000b2ce900
  0x000000000b2990f6
  0x000000000b231257
  0x000000000b2cec2c
  0x000000000b4594cd
  0x000000000b438708
  0x000000000b4595c4
  0x000000000b4381bd
  0x000000000b53eda2
  0x000000000d8dd96e
  0x000000000d8e1fc0
  0x000000000d8e74ea
  0x000000000d75e314
  0x000000000d75c1d9
  0x000000000d75c779
  0x000000000b128965
  /lib/x86_64-linux-gnu/libc.so.6+0x0000000000021b96
  0x000000000b082559
Actions #7

Updated by Kefu Chai over 3 years ago

191/213 Test #199: unittest-seastar-messenger ................***Exception: Child aborted 51.17 sec
WARNING: debug mode. Not for benchmarking or production
WARN  2020-12-12 03:02:00,928 [shard 0] seastar - Unable to set SCHED_FIFO scheduling policy for timer thread; latency impact possible. Try adding CAP_SYS_NICE
INFO  2020-12-12 03:02:01,260 [shard 0] ms - test_echo(rounds=512, keepalive_ratio=0.1, v2=false):
INFO  2020-12-12 03:02:01,273 [shard 0] ms - [osd.1(server2) v1:127.0.0.1:9032/2] bind: done
INFO  2020-12-12 03:02:01,283 [shard 0] ms - [osd.0(server1) v1:127.0.0.1:9031/1] bind: done
INFO  2020-12-12 03:02:01,291 [shard 0] ms - [osd.3(client2) - >> osd.? v1:127.0.0.1:9031/1] write_event: delay ...
INFO  2020-12-12 03:02:01,295 [shard 0] ms - [osd.2(client1) - >> osd.? v1:127.0.0.1:9032/2] write_event: delay ...
INFO  2020-12-12 03:02:01,313 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@57295 >> osd.? v1:127.0.0.1:9032/2] learned myaddr=127.0.0.1:0/3 (unbound) from v1:127.0.0.1:57295/0
INFO  2020-12-12 03:02:01,314 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@62942 >> osd.? v1:127.0.0.1:9031/1] learned myaddr=127.0.0.1:0/4 (unbound) from v1:127.0.0.1:62942/0
INFO  2020-12-12 03:02:02,166 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@57295 >> osd.? v1:127.0.0.1:9032/2]: finished sending 512 pings with 57 keepalives
INFO  2020-12-12 03:02:02,199 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@62942 >> osd.? v1:127.0.0.1:9031/1]: finished sending 512 pings with 55 keepalives
INFO  2020-12-12 03:02:09,560 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@62942 >> osd.? v1:127.0.0.1:9031/1]: finished receiving 512 pongs
INFO  2020-12-12 03:02:09,563 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@62942 >> osd.? v1:127.0.0.1:9031/1]: handshake 0.048827103, pingpong 8.229097381
INFO  2020-12-12 03:02:09,571 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@57295 >> osd.? v1:127.0.0.1:9032/2]: finished receiving 512 pongs
INFO  2020-12-12 03:02:09,574 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@57295 >> osd.? v1:127.0.0.1:9032/2]: handshake 0.033484037, pingpong 8.243418154
INFO  2020-12-12 03:02:09,577 [shard 0] ms - client1 shutdown...
INFO  2020-12-12 03:02:09,578 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@57295 >> osd.? v1:127.0.0.1:9032/2] closing: reset no, replace no
WARN  2020-12-12 03:02:09,588 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@57295 >> osd.? v1:127.0.0.1:9032/2] open fault: std::system_error (error crimson::net:4, read eof)
WARN  2020-12-12 03:02:09,589 [shard 0] ms - [osd.1(server2) v1:127.0.0.1:9032/2 >> osd.? v1:127.0.0.1:0/3@57295] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-12-12 03:02:09,590 [shard 0] ms - [osd.1(server2) v1:127.0.0.1:9032/2 >> osd.? v1:127.0.0.1:0/3@57295] closing: reset yes, replace no
INFO  2020-12-12 03:02:09,601 [shard 0] ms - client2 shutdown...
INFO  2020-12-12 03:02:09,602 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@62942 >> osd.? v1:127.0.0.1:9031/1] closing: reset no, replace no
WARN  2020-12-12 03:02:09,608 [shard 0] ms - [osd.0(server1) v1:127.0.0.1:9031/1 >> osd.? v1:127.0.0.1:0/4@62942] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-12-12 03:02:09,609 [shard 0] ms - [osd.0(server1) v1:127.0.0.1:9031/1 >> osd.? v1:127.0.0.1:0/4@62942] closing: reset yes, replace no
WARN  2020-12-12 03:02:09,612 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@62942 >> osd.? v1:127.0.0.1:9031/1] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-12-12 03:02:09,621 [shard 0] ms - server1 shutdown...
INFO  2020-12-12 03:02:09,632 [shard 0] ms - server2 shutdown...
INFO  2020-12-12 03:02:09,642 [shard 0] ms - test_echo() done!

INFO  2020-12-12 03:02:09,645 [shard 0] ms - test_echo(rounds=512, keepalive_ratio=0.1, v2=true):
INFO  2020-12-12 03:02:09,657 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9033/1] bind: done
INFO  2020-12-12 03:02:09,660 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9034/2] bind: done
INFO  2020-12-12 03:02:09,668 [shard 0] ms - [osd.3(client2) - >> osd.? v2:127.0.0.1:9033/1] ProtocolV2::start_connect(): peer_addr=v2:127.0.0.1:9033/1, peer_name=osd.?, cc=16923177755833480441 policy(lossy=true, server=false, standby=false, resetcheck=false)
INFO  2020-12-12 03:02:09,686 [shard 0] ms - [osd.3(client2) - >> osd.? v2:127.0.0.1:9033/1] write_event: delay ...
INFO  2020-12-12 03:02:09,687 [shard 0] ms - [osd.2(client1) - >> osd.? v2:127.0.0.1:9034/2] ProtocolV2::start_connect(): peer_addr=v2:127.0.0.1:9034/2, peer_name=osd.?, cc=8919006338067468654 policy(lossy=true, server=false, standby=false, resetcheck=false)
INFO  2020-12-12 03:02:09,687 [shard 0] ms - [osd.2(client1) - >> osd.? v2:127.0.0.1:9034/2] write_event: delay ...
INFO  2020-12-12 03:02:09,694 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9034/2 >> unknown.? -@65146] ProtocolV2::start_accept(): target_addr=127.0.0.1:65146/0
INFO  2020-12-12 03:02:09,697 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9033/1 >> unknown.? -@62474] ProtocolV2::start_accept(): target_addr=127.0.0.1:62474/0
INFO  2020-12-12 03:02:09,806 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9033/1 >> osd.? -@62474] UPDATE: peer_type=osd, policy(lossy=true server=true standby=false resetcheck=false)
INFO  2020-12-12 03:02:09,816 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@62474 >> osd.? v2:127.0.0.1:9033/1] learned myaddr=127.0.0.1:0/4 (unbound) from v2:127.0.0.1:62474/0
INFO  2020-12-12 03:02:09,828 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9034/2 >> osd.? -@65146] UPDATE: peer_type=osd, policy(lossy=true server=true standby=false resetcheck=false)
INFO  2020-12-12 03:02:09,833 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@65146 >> osd.? v2:127.0.0.1:9034/2] learned myaddr=127.0.0.1:0/3 (unbound) from v2:127.0.0.1:65146/0
INFO  2020-12-12 03:02:10,003 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9034/2 >> osd.2 127.0.0.1:0/3@65146] established: gs=0, pgs=1, cs=0, client_cookie=8919006338067468654, server_cookie=0, in_seq=0, out_seq=0, out_q=0
INFO  2020-12-12 03:02:10,029 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9033/1 >> osd.3 127.0.0.1:0/4@62474] established: gs=0, pgs=1, cs=0, client_cookie=16923177755833480441, server_cookie=0, in_seq=0, out_seq=0, out_q=0
INFO  2020-12-12 03:02:10,057 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@62474 >> osd.0 v2:127.0.0.1:9033/1] connected: gs=1, pgs=1, cs=0, client_cookie=16923177755833480441, server_cookie=0, in_seq=0, out_seq=0, out_q=63
INFO  2020-12-12 03:02:10,064 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@65146 >> osd.1 v2:127.0.0.1:9034/2] connected: gs=1, pgs=1, cs=0, client_cookie=8919006338067468654, server_cookie=0, in_seq=0, out_seq=0, out_q=74
INFO  2020-12-12 03:02:14,931 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@65146 >> osd.1 v2:127.0.0.1:9034/2]: finished sending 512 pings with 48 keepalives
INFO  2020-12-12 03:02:15,230 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@62474 >> osd.0 v2:127.0.0.1:9033/1]: finished sending 512 pings with 61 keepalives
INFO  2020-12-12 03:02:43,470 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@65146 >> osd.1 v2:127.0.0.1:9034/2]: finished receiving 512 pongs
INFO  2020-12-12 03:02:43,474 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@65146 >> osd.1 v2:127.0.0.1:9034/2]: handshake 0.378300419, pingpong 33.406037179
INFO  2020-12-12 03:02:43,683 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@62474 >> osd.0 v2:127.0.0.1:9033/1]: finished receiving 512 pongs
INFO  2020-12-12 03:02:43,685 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@62474 >> osd.0 v2:127.0.0.1:9033/1]: handshake 0.394137908, pingpong 33.625263309
INFO  2020-12-12 03:02:43,687 [shard 0] ms - client1 shutdown...
INFO  2020-12-12 03:02:43,690 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@65146 >> osd.1 v2:127.0.0.1:9034/2] closing: reset no, replace no
INFO  2020-12-12 03:02:43,700 [shard 0] ms - [osd.2(client1) 127.0.0.1:0/3@65146 >> osd.1 v2:127.0.0.1:9034/2] execute_ready(): protocol aborted at CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-12 03:02:43,704 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9034/2 >> osd.2 127.0.0.1:0/3@65146] execute_ready(): fault at READY on lossy channel, going to CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-12 03:02:43,705 [shard 0] ms - [osd.1(server2) v2:127.0.0.1:9034/2 >> osd.2 127.0.0.1:0/3@65146] closing: reset yes, replace no
INFO  2020-12-12 03:02:43,717 [shard 0] ms - client2 shutdown...
INFO  2020-12-12 03:02:43,719 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@62474 >> osd.0 v2:127.0.0.1:9033/1] closing: reset no, replace no
INFO  2020-12-12 03:02:43,728 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9033/1 >> osd.3 127.0.0.1:0/4@62474] execute_ready(): fault at READY on lossy channel, going to CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-12 03:02:43,730 [shard 0] ms - [osd.0(server1) v2:127.0.0.1:9033/1 >> osd.3 127.0.0.1:0/4@62474] closing: reset yes, replace no
INFO  2020-12-12 03:02:43,732 [shard 0] ms - [osd.3(client2) 127.0.0.1:0/4@62474 >> osd.0 v2:127.0.0.1:9033/1] execute_ready(): protocol aborted at CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-12 03:02:43,743 [shard 0] ms - server1 shutdown...
INFO  2020-12-12 03:02:43,755 [shard 0] ms - server2 shutdown...
INFO  2020-12-12 03:02:43,767 [shard 0] ms - test_echo() done!

INFO  2020-12-12 03:02:43,770 [shard 0] ms - test_concurrent_dispatch(v2=false):
INFO  2020-12-12 03:02:43,778 [shard 0] ms - [osd.4(server3) v1:127.0.0.1:9035/5] bind: done
INFO  2020-12-12 03:02:43,786 [shard 0] ms - [osd.5(client3) - >> osd.? v1:127.0.0.1:9035/5] write_event: delay ...
INFO  2020-12-12 03:02:43,808 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@60336 >> osd.? v1:127.0.0.1:9035/5] learned myaddr=127.0.0.1:0/6 (unbound) from v1:127.0.0.1:60336/0
INFO  2020-12-12 03:02:43,874 [shard 0] ms - client shutdown...
INFO  2020-12-12 03:02:43,876 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@60336 >> osd.? v1:127.0.0.1:9035/5] closing: reset no, replace no
WARN  2020-12-12 03:02:43,881 [shard 0] ms - [osd.4(server3) v1:127.0.0.1:9035/5 >> osd.? v1:127.0.0.1:0/6@60336] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-12-12 03:02:43,882 [shard 0] ms - [osd.4(server3) v1:127.0.0.1:9035/5 >> osd.? v1:127.0.0.1:0/6@60336] closing: reset yes, replace no
WARN  2020-12-12 03:02:43,884 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@60336 >> osd.? v1:127.0.0.1:9035/5] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-12-12 03:02:43,913 [shard 0] ms - server shutdown...
INFO  2020-12-12 03:02:43,924 [shard 0] ms - test_concurrent_dispatch() done!

INFO  2020-12-12 03:02:43,925 [shard 0] ms - test_concurrent_dispatch(v2=true):
INFO  2020-12-12 03:02:43,935 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9036/5] bind: done
INFO  2020-12-12 03:02:43,940 [shard 0] ms - [osd.5(client3) - >> osd.? v2:127.0.0.1:9036/5] ProtocolV2::start_connect(): peer_addr=v2:127.0.0.1:9036/5, peer_name=osd.?, cc=1423599486730428181 policy(lossy=true, server=false, standby=false, resetcheck=false)
INFO  2020-12-12 03:02:43,944 [shard 0] ms - [osd.5(client3) - >> osd.? v2:127.0.0.1:9036/5] write_event: delay ...
INFO  2020-12-12 03:02:43,954 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9036/5 >> unknown.? -@62605] ProtocolV2::start_accept(): target_addr=127.0.0.1:62605/0
INFO  2020-12-12 03:02:44,011 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9036/5 >> osd.? -@62605] UPDATE: peer_type=osd, policy(lossy=true server=true standby=false resetcheck=false)
INFO  2020-12-12 03:02:44,016 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@62605 >> osd.? v2:127.0.0.1:9036/5] learned myaddr=127.0.0.1:0/6 (unbound) from v2:127.0.0.1:62605/0
INFO  2020-12-12 03:02:44,103 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9036/5 >> osd.5 127.0.0.1:0/6@62605] established: gs=0, pgs=1, cs=0, client_cookie=1423599486730428181, server_cookie=0, in_seq=0, out_seq=0, out_q=0
INFO  2020-12-12 03:02:44,120 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@62605 >> osd.4 v2:127.0.0.1:9036/5] connected: gs=1, pgs=1, cs=0, client_cookie=1423599486730428181, server_cookie=0, in_seq=0, out_seq=0, out_q=2
INFO  2020-12-12 03:02:44,158 [shard 0] ms - client shutdown...
INFO  2020-12-12 03:02:44,161 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@62605 >> osd.4 v2:127.0.0.1:9036/5] closing: reset no, replace no
INFO  2020-12-12 03:02:44,169 [shard 0] ms - [osd.5(client3) 127.0.0.1:0/6@62605 >> osd.4 v2:127.0.0.1:9036/5] execute_ready(): protocol aborted at CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-12 03:02:44,179 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9036/5 >> osd.5 127.0.0.1:0/6@62605] execute_ready(): fault at READY on lossy channel, going to CLOSING -- std::system_error (error crimson::net:4, read eof)
INFO  2020-12-12 03:02:44,182 [shard 0] ms - [osd.4(server3) v2:127.0.0.1:9036/5 >> osd.5 127.0.0.1:0/6@62605] closing: reset yes, replace no
INFO  2020-12-12 03:02:44,196 [shard 0] ms - server shutdown...
INFO  2020-12-12 03:02:44,213 [shard 0] ms - test_concurrent_dispatch() done!

INFO  2020-12-12 03:02:44,216 [shard 0] ms - test_preemptive_shutdown(v2=false):
INFO  2020-12-12 03:02:44,227 [shard 0] ms - [osd.6(server4) v1:127.0.0.1:9037/7] bind: done
INFO  2020-12-12 03:02:44,238 [shard 0] ms - [osd.7(client4) - >> osd.? v1:127.0.0.1:9037/7] write_event: delay ...
INFO  2020-12-12 03:02:44,281 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@61295 >> osd.? v1:127.0.0.1:9037/7] learned myaddr=127.0.0.1:0/8 (unbound) from v1:127.0.0.1:61295/0
INFO  2020-12-12 03:02:44,344 [shard 0] ms - client shutdown...
INFO  2020-12-12 03:02:44,347 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@61295 >> osd.? v1:127.0.0.1:9037/7] closing: reset no, replace no
INFO  2020-12-12 03:02:44,354 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@61295 >> osd.? v1:127.0.0.1:9037/7] write_event: dropped
WARN  2020-12-12 03:02:44,362 [shard 0] ms - [osd.6(server4) v1:127.0.0.1:9037/7 >> osd.? v1:127.0.0.1:0/8@61295] open fault: std::system_error (error crimson::net:4, read eof)
INFO  2020-12-12 03:02:44,364 [shard 0] ms - [osd.6(server4) v1:127.0.0.1:9037/7 >> osd.? v1:127.0.0.1:0/8@61295] closing: reset yes, replace no
WARN  2020-12-12 03:02:44,384 [shard 0] ms - [osd.7(client4) 127.0.0.1:0/8@61295 >> osd.? v1:127.0.0.1:9037/7] connecting fault: seastar::gate_closed_exception (gate closed)
ERROR 2020-12-12 03:02:44,395 [shard 0] none - /home/jenkins-build/build/workspace/ceph-pull-requests/src/crimson/net/SocketMessenger.h:57 : In function 'virtual crimson::net::SocketMessenger::~SocketMessenger()', ceph_assert(%s)
!listener
Aborting on shard 0.
Backtrace:
  /usr/lib/x86_64-linux-gnu/libasan.so.5+0x000000000006bb2f
  0x000000000da0e5f2
  0x000000000d9e6935
  0x000000000d89701c
  0x000000000d89718f
  0x000000000d8faf2f
  0x000000000d933afa
  0x000000000d933b95
  /lib/x86_64-linux-gnu/libpthread.so.0+0x000000000001289f
  /lib/x86_64-linux-gnu/libc.so.6+0x000000000003ef46
  /lib/x86_64-linux-gnu/libc.so.6+0x00000000000408b0
  0x000000000d0d1408
  0x000000000b550579
  0x000000000b556f71
  0x000000000b557009
  0x000000000b35ec03
  0x000000000b20c98c
  0x000000000b2d9208
  0x000000000b2d92a1
  0x000000000b11ed6b
  0x000000000b07b0ed
  0x000000000b120aff
  0x000000000b20eba1
  0x000000000b3842bd
  0x000000000b50dde2
  0x000000000b50e0ac
  0x000000000d8deab9
  0x000000000d8e3403
  0x000000000d8e8c99
  0x000000000d75c302
  0x000000000d75a1c7
  0x000000000d75a767
  0x000000000b10e6c9
  /lib/x86_64-linux-gnu/libc.so.6+0x0000000000021b96
  0x000000000b05e3c9
Actions #8

Updated by Yingxin Cheng over 3 years ago

Thanks Kefu, this is a new issue. Seems the connection gate is closed prior to connection close, looking...

Actions #9

Updated by Kefu Chai over 3 years ago

  • Status changed from New to Resolved
  • Pull request ID set to 38581
Actions

Also available in: Atom PDF