?assert(?strict_causality(#{ ?snk_kind := debug
, function := "connection_controlling_process"
, tag := "exit"
, resource_id := CRid
},
#{ ?snk_kind := debug
, function := "resource_conn_down_callback"
, tag := "start"
, resource_id := CRid
},
Trace)),
%% check that it triggers an immediate connection shutdown
?assert(?strict_causality(#{ ?snk_kind := debug
, function := "resource_conn_down_callback"
, tag := "end"
, resource_id := CRid
},
#{ ?snk_kind := debug
, context := "callback"
, function := "ClientConnectionCallback"
, tag := "event"
, mark := ?QUIC_CONNECTION_EVENT_SHUTDOWN_COMPLETE
, resource_id := CRid
},
Trace)),
%% check that client side immediate shutdown triggers a stream shutdown
?assert(?causality(#{ ?snk_kind := debug
, function := "resource_conn_down_callback"
, tag := "end"
, resource_id := CRid
},
#{ ?snk_kind := debug
, context := "callback"
, function := "ClientStreamCallback"
, mark := ?QUIC_STREAM_EVENT_SEND_SHUTDOWN_COMPLETE
, tag := "event"
, resource_id := SRid
},
Trace)),
%% check that client side conn shutdown happens after stream shutdown
?assert(?strict_causality(#{ ?snk_kind := debug
, context := "callback"
, function := "ClientStreamCallback"
, mark := ?QUIC_STREAM_EVENT_SEND_SHUTDOWN_COMPLETE
, tag := "event"
, resource_id := SRid
},
#{ ?snk_kind := debug
, context := "callback"
, function := "ClientConnectionCallback"
, tag := "event"
, mark := ?QUIC_CONNECTION_EVENT_SHUTDOWN_COMPLETE
, resource_id := CRid
},
Trace)),
%% check that client side immediate shutdown triggers a close at server side
?assert(?strict_causality( #{ ?snk_kind := quic_shutdown
, module := quicer_conn_acceptor
, '~meta' := #{pid := _PID}},
#{ ?snk_kind := quic_closed
, module := quicer_conn_acceptor
,'~meta' := #{pid := _PID}},
Trace))
Trace is [#{'$kind' => '$trace_begin','~meta' => #{time => -576460699595632}},
#{'$kind' => debug,context => "callback",
function => "ServerListenerCallback",mark => 0,
resource_id => 140242026360512,tag => "fast_conn",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ServerConnectionCallback",mark => 9,
resource_id => 140242026360512,tag => "event",'~meta' => #{}},
#{'$kind' => quic_new_conn,
conn => #Ref<0.1073225519.3176529920.194733>,
module => quicer_conn_acceptor,
'~meta' =>
#{gl => <0.572.0>,node => nonode@nohost,pid => <0.1523.0>,
time => -576460699593970}},
#{'$kind' => debug,context => "nif",function => "async_handshake_1",
mark => 0,resource_id => 140242026360512,tag => "start",
'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ClientConnectionCallback",mark => 7,
resource_id => 140242026369136,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ClientConnectionCallback",mark => 10,
resource_id => 140242026369136,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ClientConnectionCallback",mark => 0,
resource_id => 140242026369136,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ClientConnectionCallback",mark => 9,
resource_id => 140242026369136,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ClientStreamCallback",mark => 0,
resource_id => 140242158217008,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ServerConnectionCallback",mark => 0,
resource_id => 140242026360512,tag => "event",'~meta' => #{}},
#{'$kind' => quic_connected_slow,
conn => #Ref<0.1073225519.3176529920.194733>,
module => quicer_conn_acceptor,
'~meta' =>
#{gl => <0.572.0>,node => nonode@nohost,pid => <0.1523.0>,
time => -576460699586243}},
#{'$kind' => debug,context => "callback",
function => "ClientStreamCallback",mark => 2,
resource_id => 140242158217008,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ServerConnectionCallback",mark => 9,
resource_id => 140242026360512,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ServerConnectionCallback",mark => 6,
resource_id => 140242026360512,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ServerStreamCallback",mark => 1,
resource_id => 140241889423504,tag => "event",'~meta' => #{}},
#{'$kind' => new_stream,module => quicer_stream,
stream => #Ref<0.1073225519.3176529920.194736>,
'~meta' =>
#{gl => <0.572.0>,node => nonode@nohost,pid => <0.1556.0>,
time => -576460699585966}},
#{'$kind' => stream_data,module => quicer_stream,
stream => #Ref<0.1073225519.3176529920.194736>,
'~meta' =>
#{gl => <0.572.0>,node => nonode@nohost,pid => <0.1556.0>,
time => -576460699585959}},
#{'$kind' => debug,context => "callback",
function => "ServerStreamCallback",mark => 2,
resource_id => 140241889423504,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ClientConnectionCallback",mark => 14,
resource_id => 140242026369136,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ClientStreamCallback",mark => 1,
resource_id => 140242158217008,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "nif",
function => "connection_controlling_process",
mark => 140242395753536,resource_id => 140242026369136,
tag => "enter",'~meta' => #{}},
#{'$kind' => debug,context => "nif",
function => "connection_controlling_process",
mark => 140242395753536,resource_id => 140242026369136,
tag => "exit",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "resource_conn_down_callback",mark => 94726386207240,
resource_id => 140242026369136,tag => "start",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "resource_conn_down_callback",mark => 94726386207240,
resource_id => 140242026369136,tag => "end",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ClientStreamCallback",mark => 6,
resource_id => 140242158217008,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ClientStreamCallback",mark => 7,
resource_id => 140242158217008,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ServerConnectionCallback",mark => 2,
resource_id => 140242026360512,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ServerStreamCallback",mark => 6,
resource_id => 140241889423504,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ServerStreamCallback",mark => 7,
resource_id => 140241889423504,tag => "event",'~meta' => #{}},
#{'$kind' => quic_shutdown,module => quicer_conn_acceptor,
'~meta' =>
#{gl => <0.572.0>,node => nonode@nohost,pid => <0.1523.0>,
time => -576460699585187}},
#{'$kind' => debug,context => "callback",
function => "ServerConnectionCallback",mark => 3,
resource_id => 140242026360512,tag => "event",'~meta' => #{}},
#{'$kind' => debug,context => "callback",
function => "ServerConnectionCallback",mark => 0,
resource_id => 140242026360512,tag => "shutdown_complete",
'~meta' => #{}},
#{'$kind' => quic_closed,module => quicer_conn_acceptor,
'~meta' =>
#{gl => <0.572.0>,node => nonode@nohost,pid => <0.1523.0>,
time => -576460699585119}},
#{'$kind' => '$trace_end','~meta' => #{time => -576460699585102}}],
*** System report during quicer_snb_SUITE:tc_conn_owner_down/1 2022-01-12 09:40:24.688 ***
=CRITICAL REPORT==== 12-Jan-2022::09:40:24.687945 ===
"check stage" failed: error
{panic,#{'$kind' => "Causality violation",
causes_without_effect =>
[#{'$kind' => debug,context => "callback",
function => "resource_conn_down_callback",
mark => 94726386207240,resource_id => 140242026369136,
tag => "end",'~meta' => #{}}],
effects_without_cause => []}}
Stacktrace: [{snabbkaffe,causality,5,
[{file,"/home/runner/work/quic/quic/_build/default/lib/snabbkaffe/src/snabbkaffe.erl"},
{line,469}]},
{quicer_snb_SUITE,'-tc_conn_owner_down/1-fun-20-',2,
[{file,"/home/runner/work/quic/quic/test/quicer_snb_SUITE.erl"},
{line,367}]},
{snabbkaffe,run_trace_spec,3,
[{file,"/home/runner/work/quic/quic/_build/default/lib/snabbkaffe/src/snabbkaffe.erl"},
{line,640}]},
{snabbkaffe,'-check_stage/3-lc$^0/1-0-',3,
[{file,"/home/runner/work/quic/quic/_build/default/lib/snabbkaffe/src/snabbkaffe.erl"},
{line,621}]},
{snabbkaffe,check_stage,3,
[{file,"/home/runner/work/quic/quic/_build/default/lib/snabbkaffe/src/snabbkaffe.erl"},
{line,621}]},
{quicer_snb_SUITE,tc_conn_owner_down,1,
[{file,"/home/runner/work/quic/quic/test/quicer_snb_SUITE.erl"},
{line,329}]},
{test_server,ts_tc,3,[{file,"test_server.erl"},{line,1783}]},
{test_server,run_test_case_eval1,6,
[{file,"test_server.erl"},{line,1292}]}]