SSL handshake crash

Ulf Wiger <[email protected]> Wed, 23 Dec 2015 18:38:10 +0100
Newsgroups gmane.comp.lang.erlang.bugs
Message-ID <CADPRLo_vd1dcgYD1RGNtCdQJVdgRHfSe1EuJO0B1h+tbMv3HAg@mail.gmail.com>
--===============4149407437093019831==
Content-Type: multipart/alternative; boundary=001a113f8ec294509c0527942ffa

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

Hmm=E2=80=A6 I send this to erlang-bugs, but it didn=E2=80=99t seem to get =
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 hello
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,2=
47,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"},{line,=
458}]},{tls_connection,next_state,4,[{file,"tls_connection.erl"},{line,467}=
]},{gen_fsm,handle_msg,7,[{file,"gen_fsm.erl"},{line,518}]},{proc_lib,init_=
p_do_apply,3,[{file,"proc_lib.erl"},{line,240}]}]},{gen_fsm,sync_send_all_s=
tate_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,2=
47,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,2=
47,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/d=
link_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/d=
link_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

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

<div dir=3D"ltr"><span style=3D"color:rgb(0,0,0);font-family:Helvetica;font=
-size:12px">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:Helve=
tica;font-size:12px"><br></div><div style=3D"color:rgb(0,0,0);font-family:H=
elvetica;font-size:12px">When connecting some Android software to an Erlang=
 node using TLS, we sometimes (about 1 in 3 or 4 times) get the following e=
rrors:<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 matchi=
ng 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<br><br>15:31:00.783&lt;dlink_tls_conn/327&gt=
;dlink_tls_conn:terminate(): Reason: {{function_clause,[{ssl_handshake,upda=
te_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,2=
04,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,1=
5,192,7,192,9,192,10,192,17,192,19,192,20,0,51,0,57,0,50,0,56,0,10,192,3,19=
2,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&gt=
;&gt;],[{file,&quot;ssl_handshake.erl&quot;},{line,450}]},{tls_connection,&=
#39;-next_state/4-fun-0-&#39;,3,[{file,&quot;tls_connection.erl&quot;},{lin=
e,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,2=
40}]}]},{gen_fsm,sync_send_all_state_event,[&lt;0.210.0&gt;,{start,infinity=
},infinity]}}=C2=A0<br><br>2015-12-22 15:31:00.784 [error] &lt;0.210.0&gt; =
CRASH REPORT Process &lt;0.210.0&gt; with 0 neighbours exited with reason: =
no function clause matching ssl_handshake:update_handshake_history(undefine=
d,=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:terminat=
e/7 line 626<br><br>2015-12-22 15:31:00.785 [error] &lt;0.209.0&gt; gen_ser=
ver &lt;0.209.0&gt; terminated with reason: {{function_clause,[{ssl_handsha=
ke,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,17=
0,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,1=
4,192,15,192,7,192,9,192,10,192,17,192,19,192,20,0,51,0,57,0,50,0,56,0,10,1=
92,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_fsm:sync_send_all_st=
ate_event/3 line 257<br><br>2015-12-22 15:31:00.786 [error] &lt;0.209.0&gt;=
 CRASH REPORT Process &lt;0.209.0&gt; with 0 neighbours exited with reason:=
 {{function_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,5=
3,192,2,192,4,192,5,192,12,192,14,192,15,192,7,192,9,192,10,192,17,192,19,1=
92,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 [err=
or] &lt;0.109.0&gt; Supervisor tls_connection_sup had child undefined start=
ed with {tls_connection,start_link,undefined} at &lt;0.210.0&gt; exit with =
reason no function clause matching=C2=A0ssl_handshake:update_handshake_hist=
ory(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,...&gt;&gt;) line 450 in context c=
hild_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_pee=
r},<br>{certfile,&quot;/home/.../device_cert.crt=E2=80=9D},<br>{keyfile,&qu=
ot;/home/.../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_con=
n.64.24728257&gt;}]<br><br>Basically, the verify_fun validates a self-signe=
d cert<br><a href=3D"https://github.com/PDXostc/rvi_core/blob/develop/compo=
nents/dlink_tls/src/dlink_tls_conn.erl#L393">https://github.com/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/components/dlin=
k_tls/src/dlink_tls_conn.erl#L421">https://github.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>

--001a113f8ec294509c0527942ffa--

--===============4149407437093019831==
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

--===============4149407437093019831==--