[rabbitmq-discuss] SSL connection - ASN1 error

Skorepa, Michal Michal.Skorepa at Honeywell.com
Fri Nov 15 14:18:36 GMT 2013


Hi Tim,

So, I did what you suggested. I followed the procedure on www.rabbitmq.com/ssl.html and generated brand new certificates. Now I am getting a different error. It is not an exception as before, now it is an error result from amqp_connection:start(Args). 

The log on the client side says:

2013-11-15 13:02:56.384 [error] <0.412.0> SSL: certify: tls_handshake.erl:1331:Fatal error: handshake failure
2013-11-15 13:02:56.386 [error] <0.309.0>@swim_cm_connector:handle_info:73 Connection setup error: {tls_alert,"handshake failure"}
---------------

On the server side it is:

=INFO REPORT==== 15-Nov-2013::15:05:39 ===
accepting AMQP connection <0.4914.0> (10.10.10.52:37826 -> 192.168.0.21:5671)

=ERROR REPORT==== 15-Nov-2013::15:05:40 ===
SSL: certify: ssl_connection.erl:1678:Fatal error: handshake failure

=INFO REPORT==== 15-Nov-2013::15:05:46 ===
accepting AMQP connection <0.4923.0> (10.10.10.52:42106 -> 192.168.0.21:5671)

=ERROR REPORT==== 15-Nov-2013::15:05:46 ===
SSL: certify: ssl_connection.erl:1678:Fatal error: handshake failure

=ERROR REPORT==== 15-Nov-2013::15:05:50 ===
error on AMQP connection <0.4914.0>: {ssl_upgrade_error,esslaccept} (unknown POSIX error)

=ERROR REPORT==== 15-Nov-2013::15:05:56 ===
error on AMQP connection <0.4923.0>: {ssl_upgrade_error,esslaccept} (unknown POSIX error)
---------------------

I really do not understand why this is happening.

Also, I follow the troubleshooting procedure on http://www.rabbitmq.com/troubleshooting-ssl.html and everything worked fine except for the last exercise - the stunnel test. When performing this test, I got an exception on the client side saying:

12:51:02.154 [error] swim_cm_connector: Exception caught in connection setup.
 Exception: exit
 Reason: {{function_clause,[{amqp_gen_connection,terminate,[{{badarg,[{crypto,ec_key_generate,[secp256r1],[]},{crypto,generate_key,3,[{file,"crypto.erl"},{line,560}]},{public_key,ec_generate_key,1,[{file,"public_key.erl"},{line,869}]},{tls_connection,server_master_secret,2,[{file,"tls_connection.erl"},{line,2053}]},{tls_connection,certify,2,[{file,"tls_connection.erl"},{line,544}]},{tls_connection,next_state,4,[{file,"tls_connection.erl"},{line,2537}]},{gen_fsm,handle_msg,7,[{file,"gen_fsm.erl"},{line,505}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,239}]}]},{gen_fsm,sync_send_all_state_event,[<0.425.0>,{start,infinity},infinity]}},{<0.421.0>,{amqp_params_network,<<"xxx">>,<<"xxx">>,<<"demo">>,{192,168,0,21},5677,0,0,60,infinity,[{cacertfile,"/home/root/new_certificates/testca/cacert.pem"},{certfile,"/home/root/new_certificates/client/cert.pem"},{keyfile,"/home/root/new_certificates/client/key.pem"},{verify,verify_peer},{fail_if_no_peer_cert,false}],[#Fun<amqp_auth_mechanisms.plain.3>,#Fun<amqp_auth_mechanisms.amqplain.3>],[],[{tos,64}]}}],[{file,"src/amqp_gen_connection.erl"},{line,229}]},{gen_server,terminate,6,[{file,"gen_server.erl"},{line,719}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,239}]}]},{gen_server,call,[<0.422.0>,connect,infinity]}}
-----------------------

The stunnel log says:

2013.11.15 13:48:50 LOG7[23085:139972456994560]: Service [stunnel3] accepted (FD=4) from 10.10.10.52:33027
2013.11.15 13:48:50 LOG7[23085:139972456986368]: Service [stunnel3] started
2013.11.15 13:48:50 LOG7[23085:139972456986368]: Waiting for a libwrap process
2013.11.15 13:48:50 LOG7[23085:139972456986368]: Acquired libwrap process #0
2013.11.15 13:48:50 LOG7[23085:139972456986368]: Releasing libwrap process #0
2013.11.15 13:48:50 LOG7[23085:139972456986368]: Released libwrap process #0
2013.11.15 13:48:50 LOG7[23085:139972456986368]: Service [stunnel3] permitted by libwrap from 10.10.10.52:33027
2013.11.15 13:48:50 LOG5[23085:139972456986368]: Service [stunnel3] accepted connection from 10.10.10.52:33027
2013.11.15 13:48:50 LOG3[23085:139972456986368]: SSL_accept: Peer suddenly disconnected
2013.11.15 13:48:50 LOG5[23085:139972456986368]: Connection reset: 0 byte(s) sent to SSL, 0 byte(s) sent to socket
2013.11.15 13:48:50 LOG7[23085:139972456986368]: Local socket (FD=4) closed
2013.11.15 13:48:50 LOG7[23085:139972456986368]: Service [stunnel3] finished (0 left)
----------------------

Does this make any sense to you?

Thank you!
Michal




-----Original Message-----
From: rabbitmq-discuss-bounces at lists.rabbitmq.com [mailto:rabbitmq-discuss-bounces at lists.rabbitmq.com] On Behalf Of Tim Watson
Sent: 13. listopadu 2013 12:22
To: Discussions about RabbitMQ
Subject: Re: [rabbitmq-discuss] SSL connection - ASN1 error

Hi Michal,

> So the new release did not fix the issue. I am still getting the same error.

The fix Simon and I spoke with you about previously was related to the startup error, which was fixed in 3.2.0 - see http://www.rabbitmq.com/release-notes/README-3.2.0.txt:

"25794 prevent startup error when using SSL on versions of Erlang from R16B01"

These other issues appear to be to do with your SSL setup, and that's hard/impossible to diagnose without more information. If I follow the instructions in www.rabbitmq.com/ssl.html for setting up testing certificates for the client and server, then I can successfully establish and close an SSL connection to the broker using the Erlang client, based on the latest RabbitMQ release and using Erlang R16B02 for both client and server. Can you please test that you can do the same, at which point we'll at least have a baseline to work to whilst trying to identify what the real issue you're running into is.

Cheers,
Tim 

On 13 Nov 2013, at 10:07, Skorepa, Michal wrote:

> Hi Tim,
> 
> So the new release did not fix the issue. I am still getting the same error.
> 
> What I am trying to do is a broker-to-broker communication. One broker (a "server") is a standard RabbitMQ. The other broker (a "client") is a RabbitMQ running a plugin application, which based on some events connects to the "server" broker using erlang AMQP client. We have been using this concept without SSL for a long time without any problems (several erlang and RabbitMQ versions). We have also tested it with SSL having RabbitMQ 3.1.3 and Erlang R15B01 on the "server" side and RabbitMQ 3.0.4 and Erlang R15B01 on the "client" side. This also worked.
> But having the same "server" broker (RabbitMQ 3.1.3 and Erlang 15B01) and using the "client" broker with RabbitMQ 3.2.1 and Erlang 16B01 throws the exception mentioned below when calling amqp_connection:start(Params).
> It seems the error came with the Erlang upgrade.
> 
> The log files follow..
> 
> The relevant lines form the plugin application log:
> 
> 2013-11-12 14:35:00.168 [debug] <0.309.0>@swim_cm_connector:handle_info:65 Connection parameters: {amqp_params_network,<<"aaa">>,<<"aaa">>,<<"demo">>,{192,168,0,21},5677,0,0,60,infinity,[{cacertfile,"/etc/ssl/swim/swim-ca_cert.pem"},{certfile,"/etc/ssl/swim/cert.pem"},{keyfile,"/etc/ssl/swim/key.pem"},{verify,verify_peer},{fail_if_no_peer_cert,true}],[#Fun<amqp_auth_mechanisms.plain.3>,#Fun<amqp_auth_mechanisms.amqplain.3>],[],[{tos,64}]}.
> 2013-11-12 14:35:00.171 [debug] <0.316.0> Supervisor 
> {<0.316.0>,amqp_connection_sup} started 
> amqp_gen_connection:start_link(<0.318.0>, 
> {amqp_params_direct,<<"swim">>,none,<<"/">>,rabbit at overoB7,none,[]}) 
> at pid <0.319.0>
> 2013-11-12 14:35:00.178 [debug] <0.318.0> Supervisor 
> {<0.318.0>,amqp_connection_type_sup} started 
> amqp_channel_sup_sup:start_link(direct, <0.319.0>) at pid <0.321.0>
> 2013-11-12 14:35:00.185 [debug] <0.320.0> Supervisor 
> {<0.320.0>,amqp_connection_sup} started 
> amqp_connection_type_sup:start_link() at pid <0.322.0>
> 2013-11-12 14:35:00.187 [debug] <0.318.0> Supervisor 
> {<0.318.0>,amqp_connection_type_sup} started 
> amqp_channels_manager:start_link(<0.319.0>, <0.321.0>) at pid 
> <0.323.0>
> 2013-11-12 14:35:00.193 [debug] <0.320.0> Supervisor 
> {<0.320.0>,amqp_connection_sup} started 
> amqp_gen_connection:start_link(<0.322.0>, 
> {amqp_params_network,<<"aaa">>,<<"aaa">>,<<"demo">>,{192,168,0,21},567
> 7,0,0,60,infinity,[{cacertfile,...},...],...}) at pid <0.324.0>
> 2013-11-12 14:35:00.194 [debug] <0.318.0> Supervisor 
> {<0.318.0>,amqp_connection_type_sup} started 
> rabbit_queue_collector:start_link() at pid <0.325.0>
> 2013-11-12 14:35:00.577 [info] <0.7.0> Application asn1 started on 
> node rabbit at overoB7
> 2013-11-12 14:35:00.882 [info] <0.7.0> Application webmachine started 
> on node rabbit at overoB7
> 2013-11-12 14:35:00.926 [debug] <0.358.0> Supervisor crypto_sup 
> started crypto_server:start_link() at pid <0.368.0>
> 2013-11-12 14:35:00.928 [info] <0.7.0> Application crypto started on 
> node rabbit at overoB7
> 2013-11-12 14:35:01.037 [info] <0.7.0> Application public_key started 
> on node rabbit at overoB7
> 2013-11-12 14:35:01.672 [debug] <0.375.0> Supervisor ssl_sup started 
> ssl_manager:start_link([]) at pid <0.376.0>
> 2013-11-12 14:35:01.722 [debug] <0.375.0> Supervisor ssl_sup started 
> ssl_connection_sup:start_link() at pid <0.377.0>
> 2013-11-12 14:35:01.724 [info] <0.7.0> Application ssl started on node 
> rabbit at overoB7
> 2013-11-12 14:35:02.389 [debug] <0.396.0> Supervisor rabbit_mgmt_sup 
> started supervisor2:start_link(mirrored_supervisor, 
> {delegate,{one_for_one,10,10}}) at pid <0.397.0>
> 2013-11-12 14:35:02.392 [debug] <0.396.0> Supervisor rabbit_mgmt_sup 
> started mirrored_supervisor:start_internal(rabbit_mgmt_sup, 
> [{rabbit_mgmt_db,{rabbit_mgmt_db,start_link,[]},permanent,4294967295,w
> orker,[rabbit_mgmt_db]}]) at pid <0.398.0>
> 2013-11-12 14:35:02.394 [debug] <0.32.0> Supervisor kernel_safe_sup 
> started pg2_fixed:start_link() at pid <0.399.0>
> 2013-11-12 14:35:02.421 [info] <0.177.0> Statistics database started.
> 2013-11-12 14:35:02.472 [error] <0.309.0>@swim_cm_connector:handle_info:84 Exception caught in connection setup for CoS 1.
> Exception: exit
> Reason: 
> {{function_clause,[{amqp_gen_connection,terminate,[{{{badmatch,error},
> [{tls_connection,dh_master_secret,5,[{file,"tls_connection.erl"},{line
> ,2093}]},{tls_connection,certify,2,[{file,"tls_connection.erl"},{line,
> 544}]},{tls_connection,next_state,4,[{file,"tls_connection.erl"},{line
> ,2537}]},{gen_fsm,handle_msg,7,[{file,"gen_fsm.erl"},{line,505}]},{pro
> c_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{line,239}]}]},{gen_fsm
> ,sync_send_all_state_event,[<0.378.0>,{start,infinity},infinity]}},{<0
> .322.0>,{amqp_params_network,<<"aaa">>,<<"aaa">>,<<"demo">>,{192,168,0
> ,21},5677,0,0,60,infinity,[{cacertfile,"/etc/ssl/swim/swim-ca_cert.pem
> "},{certfile,"/etc/ssl/swim/cert.pem"},{keyfile,"/etc/ssl/swim/key.pem
> "},{verify,verify_peer},{fail_if_no_peer_cert,true}],[#Fun<amqp_auth_m
> echanisms.plain.3>,#Fun<amqp_auth_mechanisms.amqplain.3>],[],[{tos,64}
> ]}}],[{file,"src/amqp_gen_connection.erl"},{line,229}]},{gen_server,te
> rminate,6,[{file,"gen_server.erl"},{line,719}]},{proc_lib,init_p_do_ap
> ply,3,[{file,"proc_lib.erl"},{line,239}]}]},{gen_server,call,[<0.324.0
> >,connect,infinity]}}
> 
> ------------------------------
> 
> And the "server" broker log:
> 
> =INFO REPORT==== 12-Nov-2013::14:34:29 === accepting AMQP connection 
> <0.26684.61> (10.10.10.52:41980 -> 192.168.0.21:5677)
> 
> =INFO REPORT==== 12-Nov-2013::14:34:30 === accepting AMQP connection 
> <0.26688.61> (10.10.10.52:33288 -> 192.168.0.21:5677)
> 
> =INFO REPORT==== 12-Nov-2013::14:34:30 === accepting AMQP connection 
> <0.26692.61> (10.10.10.52:36058 -> 192.168.0.21:5677)
> 
> =INFO REPORT==== 12-Nov-2013::14:34:31 === accepting AMQP connection 
> <0.26696.61> (10.10.10.52:33409 -> 192.168.0.21:5677)
> 
> =INFO REPORT==== 12-Nov-2013::14:34:31 === accepting AMQP connection 
> <0.26700.61> (10.10.10.52:34012 -> 192.168.0.21:5677)
> 
> =INFO REPORT==== 12-Nov-2013::14:34:31 === accepting AMQP connection 
> <0.26704.61> (10.10.10.52:33157 -> 192.168.0.21:5677)
> 
> =ERROR REPORT==== 12-Nov-2013::14:34:39 === error on AMQP connection 
> <0.26684.61>: {ssl_upgrade_error,closed} (unknown POSIX error)
> 
> =ERROR REPORT==== 12-Nov-2013::14:34:40 === error on AMQP connection 
> <0.26688.61>: {ssl_upgrade_error,closed} (unknown POSIX error)
> 
> =ERROR REPORT==== 12-Nov-2013::14:34:40 === error on AMQP connection 
> <0.26692.61>: {ssl_upgrade_error,closed} (unknown POSIX error)
> 
> =ERROR REPORT==== 12-Nov-2013::14:34:41 === error on AMQP connection 
> <0.26696.61>: {ssl_upgrade_error,closed} (unknown POSIX error)
> 
> =ERROR REPORT==== 12-Nov-2013::14:34:41 === error on AMQP connection 
> <0.26700.61>: {ssl_upgrade_error,closed} (unknown POSIX error)
> 
> =ERROR REPORT==== 12-Nov-2013::14:34:41 === error on AMQP connection 
> <0.26704.61>: {ssl_upgrade_error,closed} (unknown POSIX error)
> 
> --------------------------------
> 
> 
> Thank you for any ideas!
> 
> Cheers,
> Michal
> 
> 
> 
> 
> 
> -----Original Message-----
> From: rabbitmq-discuss-bounces at lists.rabbitmq.com 
> [mailto:rabbitmq-discuss-bounces at lists.rabbitmq.com] On Behalf Of Tim 
> Watson
> Sent: 16. října 2013 13:38
> To: Discussions about RabbitMQ
> Subject: Re: [rabbitmq-discuss] SSL connection - ASN1 error
> 
> Hi Michal,
> 
> On 1 Oct 2013, at 13:06, Skorepa, Michal wrote:
>> Thank you, Simon. But unfortunately neither of the proposed workarounds worked for me. Both produced the same error:
>> 
>> {{{{badmatch,error},[{tls_connection,dh_master_secret,5,[{file,"tls_c
>> o 
>> nnection.erl"},{line,2093}]},{tls_connection,certify,2,[{file,"tls_co
>> n 
>> nection.erl"},{line,544}]},{tls_connection,next_state,4,[{file,"tls_c
>> o 
>> nnection.erl"},{line,2537}]},{gen_fsm,handle_msg,7,[{file,"gen_fsm.er
>> l 
>> "},{line,505}]},{proc_lib,init_p_do_apply,3,[{file,"proc_lib.erl"},{l
>> i 
>> ne,239}]}]},{gen_fsm,sync_send_all_state_event,[<0.324.0>,{start,infi
>> n ity},infinity]}},{gen_server,call,[<0.292.0>,connect,infinity]}}
>> 
> 
> That looks like a very different error from the one you'd see due to the asn1 application not being started.
> 
>> Do you have any other suggestions?
> [snip]
>>> I am getting an exception in SSL connection establishment by AMQP 
>>> Erlang client (used by an application which is running as a RMQ plugin):
>> 
> 
> Can you explain a bit more about what you're doing here? The stack trace above indicates a failure during cryptographic key generation, which seems odd under the circumstances. Is there any more information available in the logs? In particular, it would be useful to have some more context for the error, e.g., an INFO report from the process in which this crash occured.
> 
>> 
>> Also, when do you plan to release a new version of AMQP Erlang client?
>> 
> 
> AFAIK a new release should be imminent. Although we cannot make any guarantees about release timescales, I'd expect to see one either this week or early next.
> 
> Cheers,
> Tim
> _______________________________________________
> rabbitmq-discuss mailing list
> rabbitmq-discuss at lists.rabbitmq.com
> https://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
> _______________________________________________
> rabbitmq-discuss mailing list
> rabbitmq-discuss at lists.rabbitmq.com
> https://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss

_______________________________________________
rabbitmq-discuss mailing list
rabbitmq-discuss at lists.rabbitmq.com
https://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss


More information about the rabbitmq-discuss mailing list