Channel die inmediatly after deposit

Hello People!

We have this unexpected problem, maybe you can give us a hint about why this is happening.

We just reconnect a channel (YES! :smiley: ) and we issue a deposit in it. And channel gets instantly disconnected!

We include node logs here: https://drive.google.com/drive/folders/1cBo9zildcUpOOvQhnOHQ5EAU0HYBeCIV?usp=sharing just in case… the related part looks like this:

Whatever needed to inspect this more in detail please let me know!
Thanks,
david

2019-09-03 23:53:09.535 [debug] <0.26855.467>@aesc_session_noise:cast:397 to noise session <0.26239.467>: {msg,deposit_signed,#{block_hash => <<0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0>>,channel_id => <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>,data => #{tx => <<249,1,6,11,1,248,132,184,64,10,110,158,153,160,46,161,62,24,133,82,78,129,208,118,74,59,71,235,67,63,118,63,150,186,246,131,97,141,37,68,44,5,154,107,178,135,123,169,201,237,225,55,50,64,187,251,81,167,104,32,129,56,108,147,155,248,60,172,250,197,249,156,9,184,64,13,46,245,168,127,60,54,184,4,91,168,17,231,93,139,92,108,191,238,108,106,253,188,97,6,62,212,99,11,6,190,186,124,38,168,143,39,4,192,35,77,101,125,251,64,102,111,211,139,28,248,5,150,230,143,10,154,153,125,241,184,19,10,13,184,124,248,122,51,1,161,6,23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14,161,1,74,74,151,173,233,118,18,63,117,143,180,140,150,136,2,211,152,160,24,221,158,244,154,156,218,27,43,24,21,182,80,229,136,83,68,72,53,236,88,0,0,0,134,15,229,225,48,208,0,160,206,197,222,242,213,24,113,220,24,111,114,147,201,54,95,249,39,20,232,227,216,81,13,242,216,155,128,62,225,122,151,68,2,67>>}}}
2019-09-03 23:53:09.536 [debug] <0.26855.467>@aesc_fsm:report_info:2642 report_info(true, Client = <0.26852.467>, Msg = #{channel_id => <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>,info => #{info => deposit_created,tx => {signed_tx,{aetx,channel_deposit_tx,aesc_deposit_tx,124,{channel_deposit_tx,{id,channel,<<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>},{id,account,<<74,74,151,173,233,118,18,63,117,143,180,140,150,136,2,211,152,160,24,221,158,244,154,156,218,27,43,24,21,182,80,229>>},6000000000000000000,0,17480000000000,<<206,197,222,242,213,24,113,220,24,111,114,147,201,54,95,249,39,20,232,227,216,81,13,242,216,155,128,62,225,122,151,68>>,2,67}},[<<13,46,245,168,127,60,54,184,4,91,168,17,231,93,139,92,108,191,238,108,106,253,188,97,6,62,212,99,11,6,190,186,124,38,168,143,39,4,192,35,77,101,125,251,64,102,111,211,139,28,248,5,150,230,143,10,154,153,125,241,184,19,10,13>>,<<10,110,158,153,160,46,161,62,24,133,82,78,129,208,118,74,59,71,235,67,63,118,63,150,186,246,131,97,141,37,68,44,5,154,107,178,135,123,169,201,237,225,55,50,64,187,251,81,167,104,32,129,56,108,147,155,248,60,172,250,197,249,156,9>>]},type => channel_deposit_tx},tag => on_chain_tx,type => report})
2019-09-03 23:53:09.536 [debug] <0.26852.467>@sc_ws_handler:set_channel_id:157 Msg=#{channel_id => <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>,info => #{info => deposit_created,tx => {signed_tx,{aetx,channel_deposit_tx,aesc_deposit_tx,124,{channel_deposit_tx,{id,channel,<<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>},{id,account,<<74,74,151,173,233,118,18,63,117,143,180,140,150,136,2,211,152,160,24,221,158,244,154,156,218,27,43,24,21,182,80,229>>},6000000000000000000,0,17480000000000,<<206,197,222,242,213,24,113,220,24,111,114,147,201,54,95,249,39,20,232,227,216,81,13,242,216,155,128,62,225,122,151,68>>,2,67}},[<<13,46,245,168,127,60,54,184,4,91,168,17,231,93,139,92,108,191,238,108,106,253,188,97,6,62,212,99,11,6,190,186,124,38,168,143,39,4,192,35,77,101,125,251,64,102,111,211,139,28,248,5,150,230,143,10,154,153,125,241,184,19,10,13>>,<<10,110,158,153,160,46,161,62,24,133,82,78,129,208,118,74,59,71,235,67,63,118,63,150,186,246,131,97,141,37,68,44,5,154,107,178,135,123,169,201,237,225,55,50,64,187,251,81,167,104,32,129,56,108,147,155,248,60,172,250,197,249,156,9>>]},type => channel_deposit_tx},tag => on_chain_tx,type => report} (Id0=<<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>) -> <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>
2019-09-03 23:53:09.536 [debug] <0.26997.467>@aesc_fsm:message:335 message(<0.26990.467>, {deposit_signed,#{block_hash => <<0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0>>,channel_id => <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>,data => #{tx => <<249,1,6,11,1,248,132,184,64,10,110,158,153,160,46,161,62,24,133,82,78,129,208,118,74,59,71,235,67,63,118,63,150,186,246,131,97,141,37,68,44,5,154,107,178,135,123,169,201,237,225,55,50,64,187,251,81,167,104,32,129,56,108,147,155,248,60,172,250,197,249,156,9,184,64,13,46,245,168,127,60,54,184,4,91,168,17,231,93,139,92,108,191,238,108,106,253,188,97,6,62,212,99,11,6,190,186,124,38,168,143,39,4,192,35,77,101,125,251,64,102,111,211,139,28,248,5,150,230,143,10,154,153,125,241,184,19,10,13,184,124,248,122,51,1,161,6,23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14,161,1,74,74,151,173,233,118,18,63,117,143,180,140,150,136,2,211,152,160,24,221,158,244,154,156,218,27,43,24,21,182,80,229,136,83,68,72,53,236,88,0,0,0,134,15,229,225,48,208,0,160,206,197,222,242,213,24,113,220,24,111,114,147,201,54,95,249,39,20,232,227,216,81,13,242,216,155,128,62,225,122,151,68,2,67>>}}})
2019-09-03 23:53:09.536 [debug] <0.26855.467>@aesc_fsm:terminate:3015 terminate({case_clause,{{min_depth,deposit},undefined}}, awaiting_signature, _)
2019-09-03 23:53:09.537 [debug] <0.26855.467>@aesc_fsm:report_info:2642 report_info(true, Client = <0.26852.467>, Msg = #{channel_id => <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>,info => {died,{case_clause,{{min_depth,deposit},undefined}}},tag => info,type => report})
2019-09-03 23:53:09.537 [debug] <0.26852.467>@sc_ws_handler:set_channel_id:157 Msg=#{channel_id => <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>,info => {died,{case_clause,{{min_depth,deposit},undefined}}},tag => info,type => report} (Id0=<<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>) -> <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>
2019-09-03 23:53:09.538 [debug] <0.26855.467>@aesc_fsm:report_info:2645 report_info(false, #{info => {log,[{req,sign,{1567,554789,485723},#{channel_id => <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>,info => #{signed_tx => {signed_tx,{aetx,channel_deposit_tx,aesc_deposit_tx,124,{channel_deposit_tx,{id,channel,<<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>},{id,account,<<74,74,151,173,233,118,18,63,117,143,180,140,150,136,2,211,152,160,24,221,158,244,154,156,218,27,43,24,21,182,80,229>>},6000000000000000000,0,17480000000000,<<206,197,222,242,213,24,113,220,24,111,114,147,201,54,95,249,39,20,232,227,216,81,13,242,216,155,128,62,225,122,151,68>>,2,67}},[<<13,46,245,168,127,60,54,184,4,91,168,17,231,93,139,92,108,191,238,108,106,253,188,97,6,62,212,99,11,6,190,186,124,38,168,143,39,4,192,35,77,101,125,251,64,102,111,211,139,28,248,5,150,230,143,10,154,153,125,241,184,19,10,13>>]},updates => [{deposit,{id,account,<<74,74,151,173,233,118,18,63,117,143,180,140,150,136,2,211,152,160,24,221,158,244,154,156,218,27,43,24,21,182,80,229>>},6000000000000000000}]},tag => deposit_created,type => sign}},{rcv,deposit_created,{1567,554789,485541},#{block_hash => <<0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0>>,channel_id => <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>,data => #{tx => <<248,196,11,1,248,66,184,64,13,46,245,168,127,60,54,184,4,91,168,17,231,93,139,92,108,191,238,108,106,253,188,97,6,62,212,99,11,6,190,186,124,38,168,143,39,4,192,35,77,101,125,251,64,102,111,211,139,28,248,5,150,230,143,10,154,153,125,241,184,19,10,13,184,124,248,122,51,1,161,6,23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14,161,1,74,74,151,173,233,118,18,63,117,143,180,140,150,136,2,211,152,160,24,221,158,244,154,156,218,27,43,24,21,182,80,229,136,83,68,72,53,236,88,0,0,0,134,15,229,225,48,208,0,160,206,197,222,242,213,24,113,220,24,111,114,147,201,54,95,249,39,20,232,227,216,81,13,242,216,155,128,62,225,122,151,68,2,67>>,updates => [<<239,130,2,59,1,161,1,74,74,151,173,233,118,18,63,117,143,180,140,150,136,2,211,152,160,24,221,158,244,154,156,218,27,43,24,21,182,80,229,136,83,68,72,53,236,88,0,0>>]}}},{snd,inband_msg,{1567,554789,457909},#{channel_id => <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>,from => <<226,184,104,230,58,207,139,9,115,120,213,62,238,97,34,253,124,96,113,208,144,17,6,215,46,3,201,239,240,38,216,183>>,info => <<"{“type”:“heartbeat”}">>,to => <<74,74,151,173,233,118,18,63,117,143,180,140,150,136,2,211,152,160,24,221,158,244,154,156,218,27,43,24,21,182,80,229>>}},{rcv,inband_msg,{1567,554788,702816},#{channel_id => <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>,from => <<74,74,151,173,233,118,18,63,117,143,180,140,150,136,2,211,152,160,24,221,158,244,154,156,218,27,43,24,21,182,80,229>>,info => <<“heartbeat_ack”>>,to => <<226,184,104,230,58,207,139,9,115,120,213,62,238,97,34,253,124,96,113,208,144,17,6,215,46,3,201,239,240,38,216,183>>}},{snd,inband_msg,{1567,554788,458011},#{channel_id => <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>,from => <<226,184,104,230,58,207,139,9,115,120,213,62,238,97,34,253,124,96,113,208,144,17,6,215,46,3,201,239,240,38,216,183>>,info => <<"{“type”:“heartbeat”}">>,to => <<74,74,151,173,233,118,18,63,117,143,180,140,150,136,2,211,152,160,24,221,158,244,154,156,218,27,43,24,21,182,80,229>>}},{rcv,inband_msg,{1567,554787,711563},#{channel_id => <<23,235,199,223,33,17,65,97,181,51,191,180,86,124,13,109,237,117,24,67,209,87,22,31,57,161,177,222,199,39,91,14>>,from => <<74,74,151,173,233,118,18,63,117,143,180,140,150,136,2,211,152,160,24,221,158,244,154,156,218,27,43,24,21,182,80,229>>,info => <<“heartbeat_ack”>>,to => <<226,184,104,230,58,207,139,9,115,120,213,62,238,97,…>>}},…]},…})
2019-09-03 23:53:09.538 [debug] <0.26855.467>@aesc_session_noise:call:401 Call to noise session <0.26239.467>: close
2019-09-03 23:53:09.538 [debug] <0.26239.467>@aesc_session_noise:handle_call:265 got close request
2019-09-03 23:53:09.538 [debug] <0.26997.467>@aesc_fsm:connection_died:158 connection to participant died(<0.26990.467>)
2019-09-03 23:53:09.538 [error] <0.26855.467>@aesc_fsm:start_min_depth_watcher:2533 gen_statem <0.26855.467> in state awaiting_signature terminated with reason: no case clause matching {{min_depth,deposit},undefined} in aesc_fsm:start_min_depth_watcher/4 line 2533
2019-09-03 23:53:09.538 [error] <0.26855.467>@aesc_fsm:start_min_depth_watcher:2533 CRASH REPORT Process <0.26855.467> with 0 neighbours crashed with reason: no case clause matching {{min_depth,deposit},undefined} in aesc_fsm:start_min_depth_watcher/4 line 2533
2019-09-03 23:53:09.539 [error] <0.1375.0>@aesc_fsm:start_min_depth_watcher:2533 Supervisor aesc_fsm_sup had child aesc_fsm started with {aesc_fsm,start_link,undefined} at <0.26855.467> exit with reason no case clause matching {{min_depth,deposit},undefined} in aesc_fsm:start_min_depth_watcher/4 line 2533 in context child_terminated
2019-09-03 23:53:09.539 [debug] <0.26852.467>@sc_ws_handler:terminate:176 WebSocket dying because of stop/[{lager_trunc_io,alist,3,[{file,"/app/_build/default/lib/lager/src/lager_trunc_io.erl"},{line,448}]},{lager_trunc_io,print,3,[{file,"/app/_build/default/lib/lager/src/lager_trunc_io.erl"},{line,168}]},{lager_trunc_io,fprint,3,[{file,"/app/_build/default/lib/lager/src/lager_trunc_io.erl"},{line,80}]},{lager_format,control2,8,[{file,"/app/_build/default/lib/lager/src/lager_format.erl"},{line,238}]},{lager_format,build2,3,[{file,"/app/_build/default/lib/lager/src/lager_format.erl"},{line,160}]},{lager_format,build2,3,[{file,"/app/_build/default/lib/lager/src/lager_format.erl"},{line,163}]},{lager_format,build2,3,[{file,"/app/_build/default/lib/lager/src/lager_format.erl"},{line,161}]},{lager_format,build2,3,[{file,"/app/_build/default/lib/lager/src/lager_format.erl"},{line,163}]}]

Hi @dave

Yes, we are aware of it, it had been tracked as deposit/withdrawal after re-establish fails. Although the Pivotal Tracker Ticket (PT) is not started, this is being currently worked upon (as part of SC: Harmonize client reconnect and reestablish) and will probably be fixed in RC2 next week.

5 Likes

Thank you!! I’ll be waiting!

1 Like

This is probably related and hopefully fixed in related PR, but also, even when the deposit returns an Onchain TX to track, the channel balance does not get updated. cc @dimitar.ivanov

Hi @hernandp
In the documentation there is a section on how to deposit. At the end of it, there is a subsection for the finalization of the deposit that describes events after the channels.on_chain_tx one: there are infos for the maturity of the transaction on-chain own_deposit_locked and then deposit_locked. It is only after both had received deposit_locked that we consider the deposit to be finished. It is then when we update balances as well.

1 Like