Re: SSL handshake crash

Danil Zagoskin <[email protected]> Thu, 24 Dec 2015 12:22:24 +0300
Newsgroups gmane.comp.lang.erlang.bugs
Message-ID <CAJ6dJEj6rZFiF4=dq34ugASneKVTuo_ssQHOU-Us2hmcAZCAnw@mail.gmail.com>
--===============1970731020751769847==
Content-Type: multipart/alternative; boundary=001a11487f3c99a7140527a161b2

--001a11487f3c99a7140527a161b2
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: quoted-printable

Hi!

I have the same issue, but not so often.
It seems to appear only when upgrading plain socket to TLS (XMPP starttls
in my case).

Possibly it's some kind of race condition when client sends TLS hello
before server does ssl_accept(). Maybe some active/passive socket mode
issue.

If you control the client code, could you add some sleep before starttls
and check if that fixes the issue?

On Wed, Dec 23, 2015 at 8:38 PM, Ulf Wiger <[email protected]> wrote:

> Hmm=E2=80=A6 I send this to erlang-bugs, but it didn=E2=80=99t seem to ge=
t through.
>
> When connecting some Android software to an Erlang node using TLS, we
> sometimes (about 1 in 3 or 4 times) get the following errors:
>
> 2015-12-22 15:31:00.772 [error] <0.210.0> gen_fsm <0.210.0> in state hell=
o
> terminated with reason: no function clause matching
> ssl_handshake:update_handshake_history(undefined, <<1,0,0,175,3,1,86,121,=
221,42,209,19,198,53,3,42,92,9,16,158,197,5,169,29,247,96,14,32,123,176,...=
>>)
> line 450
>
> 15:31:00.783<dlink_tls_conn/327>dlink_tls_conn:terminate(): Reason:
> {{function_clause,[{ssl_handshake,update_handshake_history,[undefined,<<1=
,0,0,175,3,1,86,121,221,42,209,19,198,53,3,42,92,9,16,158,197,5,169,29,247,=
96,14,32,123,176,109,210,170,150,204,23,32,228,0,0,70,0,4,0,5,0,47,0,53,192=
,2,192,4,192,5,192,12,192,14,192,15,192,7,192,9,192,10,192,17,192,19,192,20=
,0,51,0,57,0,50,0,56,0,10,192,3,192,13,192,8,192,18,0,22,0,19,0,9,0,21,0,18=
,0,3,0,8,0,20,0,17,0,255,1,0,0,64,0,11,0,4,3,0,1,2,0,10,0,52,0,50,0,14,0,13=
,0,25,0,11,0,12,0,24,0,9,0,10,0,22,0,23,0,8,0,6,0,7,0,20,0,21,0,4,0,5,0,18,=
0,19,0,1,0,2,0,3,0,15,0,16,0,17>>],[{file,"ssl_handshake.erl"},{line,450}]}=
,{tls_connection,'-next_state/4-fun-0-',3,[{file,"tls_connection.erl"},{lin=
e,458}]},{tls_connection,next_state,4,[{file,"tls_connection.erl"},{line,46=
7}]},{gen_fsm,handle_msg,7,[{file,"gen_fsm.erl"},{line,518}]},{proc_lib,ini=
t_p_do_apply,3,[{file,"proc_lib.erl"},{line,240}]}]},{gen_fsm,sync_send_all=
_state_event,[<0.210.0>,{start,infinity},infinity]}}
>
> 2015-12-22 15:31:00.784 [error] <0.210.0> CRASH REPORT Process <0.210.0>
> with 0 neighbours exited with reason: no function clause matching
> ssl_handshake:update_handshake_history(undefined, <<1,0,0,175,3,1,86,121,=
221,42,209,19,198,53,3,42,92,9,16,158,197,5,169,29,247,96,14,32,123,176,...=
>>)
> line 450 in gen_fsm:terminate/7 line 626
>
> 2015-12-22 15:31:00.785 [error] <0.209.0> gen_server <0.209.0> terminated
> with reason:
> {{function_clause,[{ssl_handshake,update_handshake_history,[undefined,<<1=
,0,0,175,3,1,86,121,221,42,209,19,198,53,3,42,92,9,16,158,197,5,169,29,247,=
96,14,32,123,176,109,210,170,150,204,23,32,228,0,0,70,0,4,0,5,0,47,0,53,192=
,2,192,4,192,5,192,12,192,14,192,15,192,7,192,9,192,10,192,17,192,19,192,20=
,0,51,0,57,0,50,0,56,0,10,192,3,192,13,192,8,192,18,0,22,0,19,0,9,0,21,0,18=
,0,3,0,8,0,20,0,17,0,255,1,0,0,64,0,11,0,4,3,0,1,2,0,10,0,52,0,50,0,14,0,13=
,0,25,0,11,0,12,0,24,0,9,0,10,0,22,0,23,0,8,0,...>>],...},...]},...}
> in gen_fsm:sync_send_all_state_event/3 line 257
>
> 2015-12-22 15:31:00.786 [error] <0.209.0> CRASH REPORT Process <0.209.0>
> with 0 neighbours exited with reason:
> {{function_clause,[{ssl_handshake,update_handshake_history,[undefined,<<1=
,0,0,175,3,1,86,121,221,42,209,19,198,53,3,42,92,9,16,158,197,5,169,29,247,=
96,14,32,123,176,109,210,170,150,204,23,32,228,0,0,70,0,4,0,5,0,47,0,53,192=
,2,192,4,192,5,192,12,192,14,192,15,192,7,192,9,192,10,192,17,192,19,192,20=
,0,51,0,57,0,50,0,56,0,10,192,3,192,13,192,8,192,18,0,22,0,19,0,9,0,21,0,18=
,0,3,0,8,0,20,0,17,0,255,1,0,0,64,0,11,0,4,3,0,1,2,0,10,0,52,0,50,0,14,0,13=
,0,25,0,11,0,12,0,24,0,9,0,10,0,22,0,23,0,8,0,...>>],...},...]},...}
> in gen_server:terminate/7 line 826
>
> 2015-12-22 15:31:00.787 [error] <0.109.0> Supervisor tls_connection_sup
> had child undefined started with {tls_connection,start_link,undefined} at
> <0.210.0> exit with reason no function clause
> matching ssl_handshake:update_handshake_history(undefined,
> <<1,0,0,175,3,1,86,121,221,42,209,19,198,53,3,42,92,9,16,158,197,5,169,29=
,247,96,14,32,123,176,...>>)
> line 450 in context child_terminated
>
>
> We run OTP Erlang/OTP 18 [erts-7.2] with ssl-7.2, and the erlang side has
> the following options:
>
> [{verify,verify_peer},
> {certfile,"/home/.../device_cert.crt=E2=80=9D},
> {keyfile,"/home/.../device_key.pem=E2=80=9D},
> {cacertfile,"/home/.../root_cert.crt=E2=80=9D},
> {verify_fun,{#Fun<dlink_tls_conn.65.24728257>,{'RSAPublicKey=E2=80=99,...=
}}},
> {partial_chain,#Fun<dlink_tls_conn.64.24728257>}]
>
> Basically, the verify_fun validates a self-signed cert
>
> https://github.com/PDXostc/rvi_core/blob/develop/components/dlink_tls/src=
/dlink_tls_conn.erl#L393
>
> and the partial_chain fun most likely does much less than it should
>
> https://github.com/PDXostc/rvi_core/blob/develop/components/dlink_tls/src=
/dlink_tls_conn.erl#L421
>
> On the Android side, we=E2=80=99re using Android 4.4.2 (API 19).
>
> It feels like a timing-related problem on the erlang side.
>
> Let me know if you need more information.
>
> BR,
> Ulf W
>
> _______________________________________________
> erlang-bugs mailing list
> [email protected]
> http://erlang.org/mailman/listinfo/erlang-bugs
>
>


--=20
Danil Zagoskin | [email protected]

--001a11487f3c99a7140527a161b2
Content-Type: text/html; charset=UTF-8
Content-Transfer-Encoding: quoted-printable

<div dir=3D"ltr">Hi!<div><br></div><div>I have the same issue, but not so o=
ften.</div><div>It seems to appear only when upgrading plain socket to TLS =
(XMPP starttls in my case).</div><div><br></div><div>Possibly it&#39;s some=
 kind of race condition when client sends TLS hello before server does ssl_=
accept(). Maybe some active/passive socket mode issue.</div><div><br></div>=
<div>If you control the client code, could you add some sleep before startt=
ls and check if that fixes the issue?</div></div><div class=3D"gmail_extra"=
><br><div class=3D"gmail_quote">On Wed, Dec 23, 2015 at 8:38 PM, Ulf Wiger =
<span dir=3D"ltr">&lt;<a href=3D"mailto:[email protected]" target=3D"_blank">ul=
[email protected]</a>&gt;</span> wrote:<br><blockquote class=3D"gmail_quote" styl=
e=3D"margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div di=
r=3D"ltr"><span style=3D"color:rgb(0,0,0);font-family:Helvetica;font-size:1=
2px">Hmm=E2=80=A6 I send this to erlang-bugs, but it didn=E2=80=99t seem to=
 get through.</span><div style=3D"color:rgb(0,0,0);font-family:Helvetica;fo=
nt-size:12px"><br></div><div style=3D"color:rgb(0,0,0);font-family:Helvetic=
a;font-size:12px">When connecting some Android software to an Erlang node u=
sing TLS, we sometimes (about 1 in 3 or 4 times) get the following errors:<=
br><br>2015-12-22 15:31:00.772 [error] &lt;0.210.0&gt; gen_fsm &lt;0.210.0&=
gt; in state hello terminated with reason: no function clause matching ssl_=
handshake:update_handshake_history(undefined,=C2=A0&lt;&lt;1,0,0,175,3,1,86=
,121,221,42,209,19,198,53,3,42,92,9,16,158,197,5,169,29,247,96,14,32,123,17=
6,...&gt;&gt;) line 450<br><br>15:31:00.783&lt;dlink_tls_conn/327&gt;dlink_=
tls_conn:terminate(): Reason: {{function_clause,[{ssl_handshake,update_hand=
shake_history,[undefined,&lt;&lt;1,0,0,175,3,1,86,121,221,42,209,19,198,53,=
3,42,92,9,16,158,197,5,169,29,247,96,14,32,123,176,109,210,170,150,204,23,3=
2,228,0,0,70,0,4,0,5,0,47,0,53,192,2,192,4,192,5,192,12,192,14,192,15,192,7=
,192,9,192,10,192,17,192,19,192,20,0,51,0,57,0,50,0,56,0,10,192,3,192,13,19=
2,8,192,18,0,22,0,19,0,9,0,21,0,18,0,3,0,8,0,20,0,17,0,255,1,0,0,64,0,11,0,=
4,3,0,1,2,0,10,0,52,0,50,0,14,0,13,0,25,0,11,0,12,0,24,0,9,0,10,0,22,0,23,0=
,8,0,6,0,7,0,20,0,21,0,4,0,5,0,18,0,19,0,1,0,2,0,3,0,15,0,16,0,17&gt;&gt;],=
[{file,&quot;ssl_handshake.erl&quot;},{line,450}]},{tls_connection,&#39;-ne=
xt_state/4-fun-0-&#39;,3,[{file,&quot;tls_connection.erl&quot;},{line,458}]=
},{tls_connection,next_state,4,[{file,&quot;tls_connection.erl&quot;},{line=
,467}]},{gen_fsm,handle_msg,7,[{file,&quot;gen_fsm.erl&quot;},{line,518}]},=
{proc_lib,init_p_do_apply,3,[{file,&quot;proc_lib.erl&quot;},{line,240}]}]}=
,{gen_fsm,sync_send_all_state_event,[&lt;0.210.0&gt;,{start,infinity},infin=
ity]}}=C2=A0<br><br>2015-12-22 15:31:00.784 [error] &lt;0.210.0&gt; CRASH R=
EPORT Process &lt;0.210.0&gt; with 0 neighbours exited with reason: no func=
tion clause matching ssl_handshake:update_handshake_history(undefined,=C2=
=A0&lt;&lt;1,0,0,175,3,1,86,121,221,42,209,19,198,53,3,42,92,9,16,158,197,5=
,169,29,247,96,14,32,123,176,...&gt;&gt;) line 450 in gen_fsm:terminate/7 l=
ine 626<br><br>2015-12-22 15:31:00.785 [error] &lt;0.209.0&gt; gen_server &=
lt;0.209.0&gt; terminated with reason: {{function_clause,[{ssl_handshake,up=
date_handshake_history,[undefined,&lt;&lt;1,0,0,175,3,1,86,121,221,42,209,1=
9,198,53,3,42,92,9,16,158,197,5,169,29,247,96,14,32,123,176,109,210,170,150=
,204,23,32,228,0,0,70,0,4,0,5,0,47,0,53,192,2,192,4,192,5,192,12,192,14,192=
,15,192,7,192,9,192,10,192,17,192,19,192,20,0,51,0,57,0,50,0,56,0,10,192,3,=
192,13,192,8,192,18,0,22,0,19,0,9,0,21,0,18,0,3,0,8,0,20,0,17,0,255,1,0,0,6=
4,0,11,0,4,3,0,1,2,0,10,0,52,0,50,0,14,0,13,0,25,0,11,0,12,0,24,0,9,0,10,0,=
22,0,23,0,8,0,...&gt;&gt;],...},...]},...} in gen_fsm:sync_send_all_state_e=
vent/3 line 257<br><br>2015-12-22 15:31:00.786 [error] &lt;0.209.0&gt; CRAS=
H REPORT Process &lt;0.209.0&gt; with 0 neighbours exited with reason: {{fu=
nction_clause,[{ssl_handshake,update_handshake_history,[undefined,&lt;&lt;1=
,0,0,175,3,1,86,121,221,42,209,19,198,53,3,42,92,9,16,158,197,5,169,29,247,=
96,14,32,123,176,109,210,170,150,204,23,32,228,0,0,70,0,4,0,5,0,47,0,53,192=
,2,192,4,192,5,192,12,192,14,192,15,192,7,192,9,192,10,192,17,192,19,192,20=
,0,51,0,57,0,50,0,56,0,10,192,3,192,13,192,8,192,18,0,22,0,19,0,9,0,21,0,18=
,0,3,0,8,0,20,0,17,0,255,1,0,0,64,0,11,0,4,3,0,1,2,0,10,0,52,0,50,0,14,0,13=
,0,25,0,11,0,12,0,24,0,9,0,10,0,22,0,23,0,8,0,...&gt;&gt;],...},...]},...} =
in gen_server:terminate/7 line 826<br><br>2015-12-22 15:31:00.787 [error] &=
lt;0.109.0&gt; Supervisor tls_connection_sup had child undefined started wi=
th {tls_connection,start_link,undefined} at &lt;0.210.0&gt; exit with reaso=
n no function clause matching=C2=A0ssl_handshake:update_handshake_history(u=
ndefined, &lt;&lt;1,0,0,175,3,1,86,121,221,42,209,19,198,53,3,42,92,9,16,15=
8,197,5,169,29,247,96,14,32,123,176,...&gt;&gt;) line 450 in context child_=
terminated<br><br><br>We run OTP Erlang/OTP 18 [erts-7.2] with ssl-7.2, and=
 the erlang side has the following options:<br><br>[{verify,verify_peer},<b=
r>{certfile,&quot;/home/.../device_cert.crt=E2=80=9D},<br>{keyfile,&quot;/h=
ome/.../device_key.pem=E2=80=9D},<br>{cacertfile,&quot;/home/.../root_cert.=
crt=E2=80=9D},<br>{verify_fun,{#Fun&lt;dlink_tls_conn.65.24728257&gt;,{&#39=
;RSAPublicKey=E2=80=99,...}}},<br>{partial_chain,#Fun&lt;dlink_tls_conn.64.=
24728257&gt;}]<br><br>Basically, the verify_fun validates a self-signed cer=
t<br><a href=3D"https://github.com/PDXostc/rvi_core/blob/develop/components=
/dlink_tls/src/dlink_tls_conn.erl#L393" target=3D"_blank">https://github.co=
m/PDXostc/rvi_core/blob/develop/components/dlink_tls/src/dlink_tls_conn.erl=
#L393</a><br><br>and the partial_chain fun most likely does much less than =
it should<br><a href=3D"https://github.com/PDXostc/rvi_core/blob/develop/co=
mponents/dlink_tls/src/dlink_tls_conn.erl#L421" target=3D"_blank">https://g=
ithub.com/PDXostc/rvi_core/blob/develop/components/dlink_tls/src/dlink_tls_=
conn.erl#L421</a><br><br>On the Android side, we=E2=80=99re using Android 4=
.4.2 (API 19).<br><br>It feels like a timing-related problem on the erlang =
side.<br><br>Let me know if you need more information.<br><br>BR,<br>Ulf W<=
/div></div>
<br>_______________________________________________<br>
erlang-bugs mailing list<br>
<a href=3D"mailto:[email protected]">[email protected]</a><br>
<a href=3D"http://erlang.org/mailman/listinfo/erlang-bugs" rel=3D"noreferre=
r" target=3D"_blank">http://erlang.org/mailman/listinfo/erlang-bugs</a><br>
<br></blockquote></div><br><br clear=3D"all"><div><br></div>-- <br><div cla=
ss=3D"gmail_signature"><div dir=3D"ltr"><div><font face=3D"&#39;courier new=
&#39;, monospace">Danil Zagoskin | <a href=3D"mailto:[email protected]" target=3D"_=
blank">[email protected]</a></font></div></div></div>
</div>

--001a11487f3c99a7140527a161b2--

--===============1970731020751769847==
Content-Type: text/plain; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Content-Disposition: inline

_______________________________________________
erlang-bugs mailing list
[email protected]
http://erlang.org/mailman/listinfo/erlang-bugs

--===============1970731020751769847==--