Thanks Victor. I don't have a handshake recording for these stacks.
The problem occurs intermittently. I've dumped the SSL state and method
objects for the server and client. Anything else you want to see while
the processes are still alive?
Norm
Here's the SSL state and method from the server:
(gdb) p *s
$1 = {version = 770, type = 8192, method = 0x7f666a831040
<TLSv1_1_server_method_data.15190>, rbio = 0x1082990, wbio = 0x1090e80,
bbio = 0x1090e80, rwstate = 3, in_handshake = 1,
handshake_func = 0x7f666a53b962 <ssl3_accept>, server = 1,
new_session = 0, quiet_shutdown = 0, shutdown = 0, state = 8609, rstate
= 240, init_buf = 0x1082ef0, init_msg = 0x1082f14, init_num = 24,
init_off = 0, packet = 0x1088473 "\026\003\002", packet_length = 0,
s2 = 0x0, s3 = 0x10824b0, d1 = 0x0, read_ahead = 0, msg_callback = 0x0,
msg_callback_arg = 0x0, hit = 0, param = 0x1081f30,
cipher_list = 0x0, cipher_list_by_id = 0x0, mac_flags = 0,
enc_read_ctx = 0x1093830, read_hash = 0x1093980, expand = 0x0,
enc_write_ctx = 0x0, write_hash = 0x0, compress = 0x0, cert = 0x1081e00,
sid_ctx_length = 0, sid_ctx = '\000' <repeats 31 times>, session =
0x1093020, generate_session_id = 0x0, verify_mode = 0, verify_callback =
0x0, info_callback = 0x0, error = 0, error_code = 0,
psk_client_callback = 0x0, psk_server_callback = 0x0, ctx =
0x10813e0, debug = 0, verify_result = 0, ex_data = {sk = 0x0, dummy =
0}, client_CA = 0x0, references = 1, options = 4, mode = 4,
max_cert_list = 102400, first_packet = 0, client_version = 770,
max_send_fragment = 16384, tlsext_debug_cb = 0x0, tlsext_debug_arg =
0x0, tlsext_hostname = 0x0, servername_done = 0, tlsext_status_type = -1,
tlsext_status_expected = 0, tlsext_ocsp_ids = 0x0, tlsext_ocsp_exts =
0x0, tlsext_ocsp_resp = 0x0, tlsext_ocsp_resplen = -1,
tlsext_ticket_expected = 1, tlsext_ecpointformatlist_length = 0,
tlsext_ecpointformatlist = 0x0, tlsext_ellipticcurvelist_length = 0,
tlsext_ellipticcurvelist = 0x0, tlsext_opaque_prf_input = 0x0,
tlsext_opaque_prf_input_len = 0, tlsext_session_ticket = 0x0,
tls_session_ticket_ext_cb = 0x0, tls_session_ticket_ext_cb_arg = 0x0,
tls_session_secret_cb = 0x0, tls_session_secret_cb_arg = 0x0,
initial_ctx = 0x10813e0, next_proto_negotiated = 0x0,
next_proto_negotiated_len = 0 '\000', srtp_profiles = 0x0,
srtp_profile = 0x0, tlsext_heartbeat = 1, tlsext_hb_pending = 0,
tlsext_hb_seq = 0, renegotiate = 2, srp_ctx = {
SRP_cb_arg = 0x7f669800bd00 <srpInfo>,
TLS_ext_srp_username_callback = 0x7f6697319112 <srp_server_cb(SSL*,
int*, void*)>, SRP_verify_param_callback = 0x0,
SRP_give_srp_client_pwd_callback = 0x0,
login = 0x10932d0 "qauser3", N = 0x1082eb0, g = 0x1093520, s =
0x1093560, B = 0x10937b0, A = 0x1093a40, a = 0x0, b = 0x10936c0, v =
0x10935a0, info = 0x0, strength = 1024, srp_Mask = 1024}}
(gdb)
(gdb) p s->method
$1 = (const SSL_METHOD *) 0x7f666a831040 <TLSv1_1_server_method_data.15190>
(gdb) p *s->method
$2 = {version = 770, ssl_new = 0x7f666a56e8ff <tls1_new>, ssl_clear =
0x7f666a56e97b <tls1_clear>, ssl_free = 0x7f666a56e93e <tls1_free>,
ssl_accept = 0x7f666a53b962 <ssl3_accept>,
ssl_connect = 0x7f666a5634c1 <ssl_undefined_function>, ssl_read =
0x7f666a538735 <ssl3_read>, ssl_peek = 0x7f666a538762 <ssl3_peek>,
ssl_write = 0x7f666a5384a4 <ssl3_write>,
ssl_shutdown = 0x7f666a53835b <ssl3_shutdown>, ssl_renegotiate =
0x7f666a53878f <ssl3_renegotiate>, ssl_renegotiate_check =
0x7f666a5387e3 <ssl3_renegotiate_check>,
ssl_get_message = 0x7f666a529cfb <ssl3_get_message>, ssl_read_bytes =
0x7f666a53a184 <ssl3_read_bytes>, ssl_write_bytes = 0x7f666a539754
<ssl3_write_bytes>,
ssl_dispatch_alert = 0x7f666a53b6f3 <ssl3_dispatch_alert>, ssl_ctrl =
0x7f666a536564 <ssl3_ctrl>, ssl_ctx_ctrl = 0x7f666a536e55
<ssl3_ctx_ctrl>, get_cipher_by_char = 0x7f666a5376cf
<ssl3_get_cipher_by_char>,
put_cipher_by_char = 0x7f666a53774c <ssl3_put_cipher_by_char>,
ssl_pending = 0x7f666a535e3b <ssl3_pending>, num_ciphers =
0x7f666a535dff <ssl3_num_ciphers>, get_cipher = 0x7f666a535e0a
<ssl3_get_cipher>,
get_ssl_method = 0x7f666a574040 <tls1_get_server_method>, get_timeout
= 0x7f666a56e8f4 <tls1_default_timeout>, ssl3_enc = 0x7f666a847f20
<TLSv1_enc_data>,
ssl_version = 0x7f666a5634f5 <ssl_undefined_void_function>,
ssl_callback_ctrl = 0x7f666a536d79 <ssl3_callback_ctrl>,
ssl_ctx_callback_ctrl = 0x7f666a53757b <ssl3_ctx_callback_ctrl>}
(gdb)
And from the client:
$1 = {version = 770, type = 4096, method = 0x7f91b3b04a40
<TLSv1_1_client_method_data.15190>, rbio = 0x2585720, wbio = 0x260c210,
bbio = 0x260c210, rwstate = 3, in_handshake = 1,
handshake_func = 0x7f91b38002df <ssl3_connect>, server = 0,
new_session = 0, quiet_shutdown = 0, shutdown = 2, state = 4576, rstate
= 240, init_buf = 0x260c290, init_msg = 0x2614364, init_num = 0,
init_off = 0, packet = 0x2580093 "\025\003\002", packet_length = 0,
s2 = 0x0, s3 = 0x253d720, d1 = 0x0, read_ahead = 0, msg_callback = 0x0,
msg_callback_arg = 0x0, hit = 0, param = 0x260c3c0,
cipher_list = 0x0, cipher_list_by_id = 0x0, mac_flags = 0,
enc_read_ctx = 0x0, read_hash = 0x0, expand = 0x0, enc_write_ctx =
0x253e590, write_hash = 0x2612420, compress = 0x0, cert = 0x25855e0,
sid_ctx_length = 0, sid_ctx = '\000' <repeats 31 times>, session =
0x2619900, generate_session_id = 0x0, verify_mode = 0, verify_callback =
0x0, info_callback = 0x0, error = 0, error_code = 0,
psk_client_callback = 0x0, psk_server_callback = 0x0, ctx =
0x26127a0, debug = 0, verify_result = 0, ex_data = {sk = 0x0, dummy =
0}, client_CA = 0x0, references = 1, options = 4, mode = 4,
max_cert_list = 102400, first_packet = 0, client_version = 770,
max_send_fragment = 16384, tlsext_debug_cb = 0x0, tlsext_debug_arg =
0x0, tlsext_hostname = 0x0, servername_done = 0, tlsext_status_type = -1,
tlsext_status_expected = 0, tlsext_ocsp_ids = 0x0, tlsext_ocsp_exts =
0x0, tlsext_ocsp_resp = 0x0, tlsext_ocsp_resplen = -1,
tlsext_ticket_expected = 1, tlsext_ecpointformatlist_length = 0,
tlsext_ecpointformatlist = 0x0, tlsext_ellipticcurvelist_length = 0,
tlsext_ellipticcurvelist = 0x0, tlsext_opaque_prf_input = 0x0,
tlsext_opaque_prf_input_len = 0, tlsext_session_ticket = 0x0,
tls_session_ticket_ext_cb = 0x0, tls_session_ticket_ext_cb_arg = 0x0,
tls_session_secret_cb = 0x0, tls_session_secret_cb_arg = 0x0,
initial_ctx = 0x26127a0, next_proto_negotiated = 0x0,
next_proto_negotiated_len = 0 '\000', srtp_profiles = 0x0,
srtp_profile = 0x0, tlsext_heartbeat = 1, tlsext_hb_pending = 0,
tlsext_hb_seq = 0, renegotiate = 0, srp_ctx = {SRP_cb_arg = 0x0,
TLS_ext_srp_username_callback = 0x0, SRP_verify_param_callback =
0x0, SRP_give_srp_client_pwd_callback = 0x7f91b380a53f
<srp_password_from_info_cb>, login = 0x2509ef0 "qauser3", N = 0x26198d0,
g = 0x257f4e0, s = 0x257f510, B = 0x257f570, A = 0x257f6b0, a =
0x257f630, b = 0x0, v = 0x0, info = 0x253d188 "junkfish", strength =
1024, srp_Mask = 1024}}
(gdb) p s->method
$2 = (const SSL_METHOD *) 0x7f91b3b04a40 <TLSv1_1_client_method_data.15190>
(gdb) p *s->method
$3 = {version = 770, ssl_new = 0x7f91b38428ff <tls1_new>, ssl_clear =
0x7f91b384297b <tls1_clear>, ssl_free = 0x7f91b384293e <tls1_free>,
ssl_accept = 0x7f91b38374c1 <ssl_undefined_function>,
ssl_connect = 0x7f91b38002df <ssl3_connect>, ssl_read =
0x7f91b380c735 <ssl3_read>, ssl_peek = 0x7f91b380c762 <ssl3_peek>,
ssl_write = 0x7f91b380c4a4 <ssl3_write>,
ssl_shutdown = 0x7f91b380c35b <ssl3_shutdown>, ssl_renegotiate =
0x7f91b380c78f <ssl3_renegotiate>, ssl_renegotiate_check =
0x7f91b380c7e3 <ssl3_renegotiate_check>,
ssl_get_message = 0x7f91b37fdcfb <ssl3_get_message>, ssl_read_bytes =
0x7f91b380e184 <ssl3_read_bytes>, ssl_write_bytes = 0x7f91b380d754
<ssl3_write_bytes>,
ssl_dispatch_alert = 0x7f91b380f6f3 <ssl3_dispatch_alert>, ssl_ctrl =
0x7f91b380a564 <ssl3_ctrl>, ssl_ctx_ctrl = 0x7f91b380ae55
<ssl3_ctx_ctrl>, get_cipher_by_char = 0x7f91b380b6cf
<ssl3_get_cipher_by_char>,
put_cipher_by_char = 0x7f91b380b74c <ssl3_put_cipher_by_char>,
ssl_pending = 0x7f91b3809e3b <ssl3_pending>, num_ciphers =
0x7f91b3809dff <ssl3_num_ciphers>, get_cipher = 0x7f91b3809e0a
<ssl3_get_cipher>,
get_ssl_method = 0x7f91b383fabc <tls1_get_client_method>, get_timeout
= 0x7f91b38428f4 <tls1_default_timeout>, ssl3_enc = 0x7f91b3b1bf20
<TLSv1_enc_data>,
ssl_version = 0x7f91b38374f5 <ssl_undefined_void_function>,
ssl_callback_ctrl = 0x7f91b380ad79 <ssl3_callback_ctrl>,
ssl_ctx_callback_ctrl = 0x7f91b380b57b <ssl3_ctx_callback_ctrl>}
(gdb)
On 9/8/14 14:21, Viktor Dukhovni wrote:
On Mon, Sep 08, 2014 at 11:45:59AM -0700, Norm Green wrote:
Were are occasionally seeing hangs when establishing an SSL connection with
OpenSSL 1.0.1i. This connection uses SRP and both the server and the client
sockets are in blocking mode (thus the hang).
Is there anything I can do to debug this problem?
A recording (PCAP network capture) of the handshake in question up
to the point at which the server and client deadlock, each waiting
for the other to say something, would be useful.
Client side:
gdb) where
#0 0x00007f91e412dd2d in read () from /lib/x86_64-linux-gnu/libpthread.so.0
#1 0x00007f91b3749423 in sock_read (b=0x2585720, out=0x2580093
"\025\003\002", outl=5)
at bss_sock.c:142
#2 0x00007f91b3716c5c in BIO_read (b=0x2585720, out=0x2580093, outl=5) at
bio_lib.c:212
#3 0x00007f91b380cc77 in ssl3_read_n (s=0x260bed0, n=5, max=5, extend=0) at
s3_pkt.c:240
#4 0x00007f91b380cec3 in ssl3_get_record (s=0x260bed0) at s3_pkt.c:317
#5 0x00007f91b380e43d in ssl3_read_bytes (s=0x260bed0, type=22,
buf=0x2614360 "\024",
len=4, peek=0) at s3_pkt.c:1024
#6 0x00007f91b37fde3d in ssl3_get_message (s=0x260bed0, st1=4576, stn=4577,
mt=-1,
max=16384, ok=0x7fff4461ed00) at s3_both.c:457
#7 0x00007f91b3804979 in ssl3_get_new_session_ticket (s=0x260bed0) at
s3_clnt.c:2060
#8 0x00007f91b3800e12 in ssl3_connect (s=0x260bed0) at s3_clnt.c:545
Printing the SSL state could also be useful here in frame #8:
print *s
#9 0x00007f91b383407e in SSL_connect (s=0x260bed0) at ssl_lib.c:949
#10 0x00007f91b240230d in GsSslState::SSL_connect (this=0x7f91b2e6b740
<SslState>,
ssl=0x260bed0) at /export/ghana1/users/bretlb/trunk/src/sslsocket.c:518
Server Side
(gdb) where
#0 0x00007f669ae5ad2d in read () from /lib/x86_64-linux-gnu/libpthread.so.0
#1 0x00007f666a475423 in sock_read (b=0x1082990, out=0x1088473
"\026\003\002", outl=5)
at bss_sock.c:142
#2 0x00007f666a442c5c in BIO_read (b=0x1082990, out=0x1088473, outl=5) at
bio_lib.c:212
#3 0x00007f666a538c77 in ssl3_read_n (s=0x1082180, n=5, max=5, extend=0) at
s3_pkt.c:240
#4 0x00007f666a538ec3 in ssl3_get_record (s=0x1082180) at s3_pkt.c:317
#5 0x00007f666a53a43d in ssl3_read_bytes (s=0x1082180, type=22,
buf=0x1082f2c
"\243Lk\327u\f\352\372\037\301\315\353\325\322\377\304\034\343\275?b-\030\f\314\371l\320Z\237\315!\223\336\v\266\355\027\271\063c\033\331R\255C\237",
<incomplete sequence \330>..., len=12735, peek=0) at s3_pkt.c:1024
#6 0x00007f666a52a18d in ssl3_get_message (s=0x1082180, st1=8608, stn=8609,
mt=-1,
max=16384, ok=0x7fff4d35eb50) at s3_both.c:538
#7 0x00007f666a5416ae in ssl3_get_cert_verify (s=0x1082180) at
s3_srvr.c:2926
Also print the server SSL structure.
The server seems to be expecting a client certificate perhaps? I
would not expect a client certificate with SRP. What is the agreed
cipher suite? A PCAP with all previous messages would be most
useful.
#8 0x00007f666a53c7e9 in ssl3_accept (s=0x1082180) at s3_srvr.c:680
#9 0x00007f666a560042 in SSL_accept (s=0x1082180) at ssl_lib.c:940
#10 0x00007f669731b0fb in GsSslState::SSL_accept (this=0x7f669800fd20
<SslState>,
ssl=0x1082180) at /export/ghana1/users/bretlb/trunk/src/sslsocket.c:528
______________________________________________________________________
OpenSSL Project http://www.openssl.org
User Support Mailing List openssl-users@openssl.org
Automated List Manager majord...@openssl.org
