Ticket #957:

 - Applied workaround solution for getting local address problem with getsockname on win IOCP by using parent local address instead.
 - Fixed SSL socket not to return PJ_FALSE in active socket accept callback, to keep accepting connections.
 - Applied workaround solution for OpenSSL error mapping, as OpenSSL error codes are big numbers that won't fit pj_status_t.
 - Minor updates, e.g: using pj_perror(), removing some logs, OpenSSL error print callback.
 - Minor updates on SSL unit test, e.g: start_read() before start sending, additional ioqueue poll to cleanup sockets, add timeout feature to https client test.



git-svn-id: http://svn.pjsip.org/repos/pjproject/trunk@2986 74dad513-b988-da41-8d7b-12977e46ad98

2 files changed, 154 insertions, 84 deletions

diff --git a/pjlib/src/pj/ssl_sock_ossl.c b/pjlib/src/pj/ssl_sock_ossl.c
index a7959ce3..899667c2 100644
--- a/pjlib/src/pj/ssl_sock_ossl.c
+++ b/pjlib/src/pj/ssl_sock_ossl.c
@@ -192,16 +192,14 @@ static pj_status_t flush_delayed_send(pj_ssl_sock_t *ssock);
 #define PJ_SSL_ERRNO_START		(PJ_ERRNO_START_USER + \
 					 PJ_ERRNO_SPACE_SIZE*6)
 
-#define PJ_SSL_ERRNO_SPACE_SIZE		5000
-
-#define PJ_STATUS_FROM_OSSL(ossl_err)	(ossl_err == SSL_ERROR_NONE? \
-					 PJ_SUCCESS : \
-					 (PJ_SSL_ERRNO_START + ossl_err))
-
-#define PJ_STATUS_TO_OSSL(status)	(status == PJ_SUCCESS? \
-					 SSL_ERROR_NONE : \
-					(status - PJ_SSL_ERRNO_START))
+#define PJ_SSL_ERRNO_SPACE_SIZE		PJ_ERRNO_SPACE_SIZE
 
+#define GET_SSL_STATUS(status) { \
+    unsigned long e = ERR_get_error();\
+    status = ERR_GET_LIB(e)*300 + ERR_GET_REASON(e);\
+    pj_assert(status < PJ_SSL_ERRNO_SPACE_SIZE);\
+    if (status) status += PJ_SSL_ERRNO_START;\
+}
 
 /*
  * Get error string of OpenSSL.
@@ -210,22 +208,36 @@ static pj_str_t ssl_strerror(pj_status_t status,
 			     char *buf, pj_size_t bufsize)
 {
     pj_str_t errstr;
-    unsigned long ssl_err = PJ_STATUS_TO_OSSL(status);
+    unsigned long ssl_err = status;
+
+    if (ssl_err) {
+	unsigned long l, r;
+	ssl_err -= PJ_SSL_ERRNO_START;
+	l = ssl_err/300;
+	r = ssl_err%300;
+	ssl_err = ERR_PACK(l, 0, r);
+    }
 
 #if defined(PJ_HAS_ERROR_STRING) && (PJ_HAS_ERROR_STRING != 0)
 
-    ERR_error_string_n(ssl_err, buf, bufsize);
-    errstr = pj_str(buf);
+    {
+	const char *tmp = NULL;
+	tmp = ERR_reason_error_string(ssl_err);
+
+	if (tmp) {
+	    pj_ansi_strncpy(buf, tmp, bufsize);
+	    errstr = pj_str(buf);
+	    return errstr;
+	}
+    }
 
-#else
+#endif	/* PJ_HAS_ERROR_STRING */
 
     errstr.ptr = buf;
     errstr.slen = pj_ansi_snprintf(buf, bufsize, 
 				   "Unknown OpenSSL error %d",
 				   ssl_err);
 
-#endif	/* PJ_HAS_ERROR_STRING */
-
     return errstr;
 }
 
@@ -336,6 +348,7 @@ static pj_status_t create_ssl_ctx(pj_ssl_sock_t *ssock, SSL_CTX **p_ctx)
     SSL_CTX *ctx;
     pj_ssl_cert_t *cert;
     int mode, rc;
+    pj_status_t status;
         
     pj_assert(ssock && p_ctx);
 
@@ -369,8 +382,8 @@ static pj_status_t create_ssl_ctx(pj_ssl_sock_t *ssock, SSL_CTX **p_ctx)
     /* Create SSL context for the listener */
     ctx = SSL_CTX_new(ssl_method);
     if (ctx == NULL) {
-	PJ_LOG(1,(ssock->pool->obj_name, "Error creating OpenSSL context"));
-	return PJ_STATUS_FROM_OSSL(ERR_get_error());
+	GET_SSL_STATUS(status);
+	return status;
     }
 
     /* Apply credentials */
@@ -381,10 +394,11 @@ static pj_status_t create_ssl_ctx(pj_ssl_sock_t *ssock, SSL_CTX **p_ctx)
 	    rc = SSL_CTX_load_verify_locations(ctx, cert->CA_file.ptr, NULL);
 
 	    if (rc != 1) {
+		GET_SSL_STATUS(status);
 		PJ_LOG(1,(ssock->pool->obj_name, "Error loading CA list file "
 			  "'%s'", cert->CA_file.ptr));
 		SSL_CTX_free(ctx);
-		return PJ_STATUS_FROM_OSSL(ERR_get_error());
+		return status;
 	    }
 	}
     
@@ -402,10 +416,11 @@ static pj_status_t create_ssl_ctx(pj_ssl_sock_t *ssock, SSL_CTX **p_ctx)
 	    rc = SSL_CTX_use_certificate_chain_file(ctx, cert->cert_file.ptr);
 
 	    if(rc != 1) {
+		GET_SSL_STATUS(status);
 		PJ_LOG(1,(ssock->pool->obj_name, "Error loading certificate "
 			  "chain file '%s'", cert->cert_file.ptr));
 		SSL_CTX_free(ctx);
-		return PJ_STATUS_FROM_OSSL(ERR_get_error());
+		return status;
 	    }
 	}
 
@@ -417,10 +432,11 @@ static pj_status_t create_ssl_ctx(pj_ssl_sock_t *ssock, SSL_CTX **p_ctx)
 					     SSL_FILETYPE_PEM);
 
 	    if(rc != 1) {
+		GET_SSL_STATUS(status);
 		PJ_LOG(1,(ssock->pool->obj_name, "Error adding private key "
 			  "from '%s'", cert->privkey_file.ptr));
 		SSL_CTX_free(ctx);
-		return PJ_STATUS_FROM_OSSL(ERR_get_error());
+		return status;
 	    }
 	}
     }
@@ -542,8 +558,11 @@ static pj_status_t set_cipher_list(pj_ssl_sock_t *ssock)
 
     /* Finally, set chosen cipher list */
     ret = SSL_set_cipher_list(ssock->ossl_ssl, buf);
-    if (ret < 1)
-	return PJ_STATUS_FROM_OSSL(SSL_get_error(ssock->ossl_ssl, ret));
+    if (ret < 1) {
+	pj_status_t status;
+	GET_SSL_STATUS(status);
+	return status;
+    }
 
     return PJ_SUCCESS;
 }
@@ -687,6 +706,16 @@ static pj_bool_t on_handshake_complete(pj_ssl_sock_t *ssock,
     if (ssock->is_server) {
 	if (status != PJ_SUCCESS) {
 	    /* Handshake failed in accepting, destroy our self silently. */
+
+	    char errmsg[PJ_ERR_MSG_SIZE];
+	    char buf[PJ_INET6_ADDRSTRLEN+10];
+
+	    pj_strerror(status, errmsg, sizeof(errmsg));
+	    PJ_LOG(3,(ssock->pool->obj_name, "Handshake failed in accepting "
+		      "%s: %s",
+		      pj_sockaddr_print(&ssock->rem_addr, buf, sizeof(buf), 3),
+		      errmsg));
+
 	    pj_ssl_sock_close(ssock);
 	    return PJ_FALSE;
 	}
@@ -874,8 +903,9 @@ static pj_status_t do_handshake(pj_ssl_sock_t *ssock)
 	if (err != SSL_ERROR_NONE && err != SSL_ERROR_WANT_READ) 
 	{
 	    /* Handshake fails */
+	    GET_SSL_STATUS(status);
 	    pj_lock_release(ssock->write_mutex);
-	    return PJ_STATUS_FROM_OSSL(err);
+	    return status;
 	}
     }
 
@@ -921,7 +951,7 @@ static pj_bool_t asock_on_data_read (pj_activesock_t *asock,
 	/* Consume the whole data */
 	nwritten = BIO_write(ssock->ossl_rbio, data, size);
 	if (nwritten < size) {
-	    status = PJ_STATUS_FROM_OSSL(ERR_get_error());
+	    GET_SSL_STATUS(status);
 	    goto on_error;
 	}
     }
@@ -994,13 +1024,8 @@ static pj_bool_t asock_on_data_read (pj_activesock_t *asock,
 		 */
 		if (err != SSL_ERROR_NONE && err != SSL_ERROR_WANT_READ)
 		{
-		    char errmsg[PJ_ERR_MSG_SIZE];
-
-		    pj_strerror(status, errmsg, sizeof(errmsg));
-		    PJ_LOG(1,(ssock->pool->obj_name, "SSL_read() failed: %s",
-			      errmsg));
-
 		    /* Reset SSL socket state, then return PJ_FALSE */
+		    GET_SSL_STATUS(status);
 		    reset_ssl_sock_state(ssock);
 		    goto on_error;
 		}
@@ -1017,19 +1042,13 @@ static pj_bool_t asock_on_data_read (pj_activesock_t *asock,
 		    pj_lock_release(ssock->write_mutex);
 
 		    if (status != PJ_SUCCESS && status != PJ_EPENDING) {
-			char errmsg[PJ_ERR_MSG_SIZE];
-
-			pj_strerror(status, errmsg, sizeof(errmsg));
-			PJ_LOG(1,(ssock->pool->obj_name, "Failed to flush "
-				  "delayed send: %s", errmsg));
+			pj_perror(1, ssock->pool->obj_name, status, 
+				  "Failed to flush delayed send", 0);
 			goto on_error;
 		    }
 		} else if (status != PJ_EPENDING) {
-		    char errmsg[PJ_ERR_MSG_SIZE];
-
-		    pj_strerror(status, errmsg, sizeof(errmsg));
-		    PJ_LOG(1,(ssock->pool->obj_name, "Renegotiation failed: "
-			      "%s", errmsg));
+		    pj_perror(1, ssock->pool->obj_name, status, 
+			      "Renegotiation failed", 0);
 		    goto on_error;
 		}
 
@@ -1121,13 +1140,9 @@ static pj_bool_t asock_on_accept_complete (pj_activesock_t *asock,
     pj_activesock_cfg asock_cfg;
     unsigned i;
     pj_status_t status;
-    char buf[64];
 
     PJ_UNUSED_ARG(src_addr_len);
 
-    PJ_LOG(4,(ssock_parent->pool->obj_name, "Incoming connection from %s",
-	      pj_sockaddr_print(src_addr, buf, sizeof(buf), 3)));
-
     /* Create new SSL socket instance */
     status = pj_ssl_sock_create(ssock_parent->pool, &ssock_parent->param,
 				&ssock);
@@ -1149,8 +1164,12 @@ static pj_bool_t asock_on_accept_complete (pj_activesock_t *asock,
     ssock->addr_len = src_addr_len;
     status = pj_sock_getsockname(ssock->sock, &ssock->local_addr, 
 				 &ssock->addr_len);
-    if (status != PJ_SUCCESS)
-	goto on_return;
+    if (status != PJ_SUCCESS) {
+	/* This fails on few envs, e.g: win IOCP, just tolerate this and
+	 * use parent local address instead.
+	 */
+	pj_sockaddr_cp(&ssock->local_addr, &ssock_parent->local_addr);
+    }
 
     /* Set remote address */
     pj_sockaddr_cp(&ssock->rem_addr, src_addr);
@@ -1163,8 +1182,7 @@ static pj_bool_t asock_on_accept_complete (pj_activesock_t *asock,
     /* Create SSL instance */
     ssock->ossl_ssl = SSL_new(ssock->ossl_ctx);
     if (ssock->ossl_ssl == NULL) {
-	PJ_LOG(1,(ssock->pool->obj_name, "Error creating SSL instance"));
-	status = PJ_STATUS_FROM_OSSL(ERR_get_error());
+	GET_SSL_STATUS(status);
 	goto on_return;
     }
 
@@ -1244,13 +1262,15 @@ static pj_bool_t asock_on_accept_complete (pj_activesock_t *asock,
     ssock->ssl_state = SSL_STATE_HANDSHAKING;
     SSL_set_accept_state(ssock->ossl_ssl);
     status = do_handshake(ssock);
-    if (status != PJ_EPENDING)
-	goto on_return;
-
-    return PJ_TRUE;
 
 on_return:
-    return on_handshake_complete(ssock, status);
+    if (ssock && status != PJ_EPENDING)
+	on_handshake_complete(ssock, status);
+
+    /* Must return PJ_TRUE whatever happened, as active socket must 
+     * continue listening.
+     */
+    return PJ_TRUE;
 }
 
 
@@ -1279,8 +1299,7 @@ static pj_bool_t asock_on_connect_complete (pj_activesock_t *asock,
     /* Create SSL instance */
     ssock->ossl_ssl = SSL_new(ssock->ossl_ctx);
     if (ssock->ossl_ssl == NULL) {
-	PJ_LOG(1,(ssock->pool->obj_name, "Error creating SSL instance"));
-	status = PJ_STATUS_FROM_OSSL(ERR_get_error());
+	GET_SSL_STATUS(status);
 	goto on_return;
     }
 
@@ -1722,7 +1741,7 @@ static pj_status_t ssl_write(pj_ssl_sock_t *ssock,
 		status = PJ_EBUSY;
 	} else {
 	    /* Some problem occured */
-	    status = PJ_STATUS_FROM_OSSL(err);
+	    GET_SSL_STATUS(status);
 	}
     } else {
 	/* nwritten < *size, shouldn't happen, unless write BIO cannot hold 
@@ -2017,7 +2036,7 @@ PJ_DEF(pj_status_t) pj_ssl_sock_renegotiate(pj_ssl_sock_t *ssock)
 
     ret = SSL_renegotiate(ssock->ossl_ssl);
     if (ret <= 0) {
-	status = PJ_STATUS_FROM_OSSL(SSL_get_error(ssock->ossl_ssl, ret));
+	GET_SSL_STATUS(status);
     } else {
 	status = do_handshake(ssock);
     }
diff --git a/pjlib/src/pjlib-test/ssl_sock.c b/pjlib/src/pjlib-test/ssl_sock.c
index a37c827b..a1f9dca2 100644
--- a/pjlib/src/pjlib-test/ssl_sock.c
+++ b/pjlib/src/pjlib-test/ssl_sock.c
@@ -150,6 +150,14 @@ static pj_bool_t ssl_on_connect_complete(pj_ssl_sock_t *ssock,
 	}
     }
 
+    /* Start reading data */
+    read_buf[0] = st->read_buf;
+    status = pj_ssl_sock_start_read2(ssock, st->pool, sizeof(st->read_buf), (void**)read_buf, 0);
+    if (status != PJ_SUCCESS) {
+	app_perror("...ERROR pj_ssl_sock_start_read2()", status);
+	goto on_return;
+    }
+
     /* Start sending data */
     while (st->sent < st->send_str_len) {
 	pj_ssize_t size;
@@ -168,14 +176,6 @@ static pj_bool_t ssl_on_connect_complete(pj_ssl_sock_t *ssock,
 	    break;
     }
 
-    /* Start reading data */
-    read_buf[0] = st->read_buf;
-    status = pj_ssl_sock_start_read2(ssock, st->pool, sizeof(st->read_buf), (void**)read_buf, 0);
-    if (status != PJ_SUCCESS  && status != PJ_EPENDING) {
-	app_perror("...ERROR pj_ssl_sock_start_read2()", status);
-	goto on_return;
-    }
-
 on_return:
     st->err = status;
 
@@ -195,7 +195,7 @@ static pj_bool_t ssl_on_accept_complete(pj_ssl_sock_t *ssock,
 					int src_addr_len)
 {
     struct test_state *parent_st = (struct test_state*) 
-			    pj_ssl_sock_get_user_data(ssock);
+				   pj_ssl_sock_get_user_data(ssock);
     struct test_state *st;
     void *read_buf[1];
     pj_status_t status;
@@ -238,6 +238,14 @@ static pj_bool_t ssl_on_accept_complete(pj_ssl_sock_t *ssock,
 	}
     }
 
+    /* Start reading data */
+    read_buf[0] = st->read_buf;
+    status = pj_ssl_sock_start_read2(newsock, st->pool, sizeof(st->read_buf), (void**)read_buf, 0);
+    if (status != PJ_SUCCESS) {
+	app_perror("...ERROR pj_ssl_sock_start_read2()", status);
+	goto on_return;
+    }
+
     /* Start sending data */
     while (st->sent < st->send_str_len) {
 	pj_ssize_t size;
@@ -256,14 +264,6 @@ static pj_bool_t ssl_on_accept_complete(pj_ssl_sock_t *ssock,
 	    break;
     }
 
-    /* Start reading data */
-    read_buf[0] = st->read_buf;
-    status = pj_ssl_sock_start_read2(newsock, st->pool, sizeof(st->read_buf), (void**)read_buf, 0);
-    if (status != PJ_SUCCESS  && status != PJ_EPENDING) {
-	app_perror("...ERROR pj_ssl_sock_start_read2()", status);
-	goto on_return;
-    }
-
 on_return:
     st->err = status;
 
@@ -421,10 +421,11 @@ static pj_bool_t ssl_on_data_sent(pj_ssl_sock_t *ssock,
 #define HTTP_SERVER_ADDR	"trac.pjsip.org"
 #define HTTP_SERVER_PORT	443
 
-static int https_client_test(void)
+static int https_client_test(unsigned ms_timeout)
 {
     pj_pool_t *pool = NULL;
     pj_ioqueue_t *ioqueue = NULL;
+    pj_timer_heap_t *timer = NULL;
     pj_ssl_sock_t *ssock = NULL;
     pj_ssl_sock_param param;
     pj_status_t status;
@@ -439,6 +440,11 @@ static int https_client_test(void)
 	goto on_return;
     }
 
+    status = pj_timer_heap_create(pool, 4, &timer);
+    if (status != PJ_SUCCESS) {
+	goto on_return;
+    }
+
     state.pool = pool;
     state.send_str = HTTP_REQ;
     state.send_str_len = pj_ansi_strlen(state.send_str);
@@ -451,6 +457,10 @@ static int https_client_test(void)
     param.ioqueue = ioqueue;
     param.user_data = &state;
     param.server_name = pj_str((char*)HTTP_SERVER_ADDR);
+    param.timer_heap = timer;
+    param.timeout.sec = 0;
+    param.timeout.msec = ms_timeout;
+    pj_time_val_normalize(&param.timeout);
 
     status = pj_ssl_sock_create(pool, &param, &ssock);
     if (status != PJ_SUCCESS) {
@@ -475,6 +485,7 @@ static int https_client_test(void)
 #else
 	pj_time_val delay = {0, 100};
 	pj_ioqueue_poll(ioqueue, &delay);
+	pj_timer_heap_poll(timer, &delay);
 #endif
     }
 
@@ -491,6 +502,8 @@ on_return:
 	pj_ssl_sock_close(ssock);
     if (ioqueue)
 	pj_ioqueue_destroy(ioqueue);
+    if (timer)
+	pj_timer_heap_destroy(timer);
     if (pool)
 	pj_pool_release(pool);
 
@@ -632,6 +645,12 @@ static int echo_test(pj_ssl_sock_proto srv_proto, pj_ssl_sock_proto cli_proto,
 #endif
     }
 
+    /* Clean up sockets */
+    {
+	pj_time_val delay = {0, 100};
+	while (pj_ioqueue_poll(ioqueue, &delay) > 0);
+    }
+
     if (state_serv.err || state_cli.err) {
 	if (state_serv.err != PJ_SUCCESS)
 	    status = state_serv.err;
@@ -682,6 +701,13 @@ static pj_bool_t asock_on_data_read(pj_activesock_t *asock,
 
     st->err = status;
 
+    if (st->err != PJ_SUCCESS || st->done) {
+	pj_activesock_close(asock);
+	if (!st->is_server)
+	    clients_num--;
+	return PJ_FALSE;
+    }
+
     return PJ_TRUE;
 }
 
@@ -693,11 +719,25 @@ static pj_bool_t asock_on_connect_complete(pj_activesock_t *asock,
 			     pj_activesock_get_user_data(asock);
 
     if (status == PJ_SUCCESS) {
-	status = pj_activesock_start_read(asock, st->pool, 1, 0);
+	void *read_buf[1];
+
+	/* Start reading data */
+	read_buf[0] = st->read_buf;
+	status = pj_activesock_start_read2(asock, st->pool, sizeof(st->read_buf), (void**)read_buf, 0);
+	if (status != PJ_SUCCESS) {
+	    app_perror("...ERROR pj_ssl_sock_start_read2()", status);
+	}
     }
 
     st->err = status;
 
+    if (st->err != PJ_SUCCESS) {
+	pj_activesock_close(asock);
+	if (!st->is_server)
+	    clients_num--;
+	return PJ_FALSE;
+    }
+
     return PJ_TRUE;
 }
 
@@ -845,7 +885,7 @@ static int client_non_ssl(unsigned ms_timeout)
 on_return:
     if (ssock_serv)
 	pj_ssl_sock_close(ssock_serv);
-    if (asock_cli)
+    if (asock_cli && !state_cli.err && !state_cli.done)
 	pj_activesock_close(asock_cli);
     if (timer)
 	pj_timer_heap_destroy(timer);
@@ -858,6 +898,9 @@ on_return:
 }
 
 
+/* Test will perform multiple clients trying to connect to single server.
+ * Once SSL connection established, echo test will be performed.
+ */
 static int perf_test(unsigned clients, unsigned ms_handshake_timeout)
 {
     pj_pool_t *pool = NULL;
@@ -1022,6 +1065,12 @@ static int perf_test(unsigned clients, unsigned ms_handshake_timeout)
 #endif
     }
 
+    /* Clean up sockets */
+    {
+	pj_time_val delay = {0, 500};
+	while (pj_ioqueue_poll(ioqueue, &delay) > 0);
+    }
+
     if (state_serv.err != PJ_SUCCESS) {
 	status = state_serv.err;
 	goto on_return;
@@ -1077,13 +1126,13 @@ int ssl_sock_test(void)
     if (ret != 0)
 	return ret;
 
-    // Disable this test as requiring internet connection.
-#if 0
     PJ_LOG(3,("", "..https client test"));
-    ret = https_client_test();
-    if (ret != 0)
-	return ret;
-#endif
+    ret = https_client_test(30000);
+    // Ignore test result as internet connection may not be available.
+    //if (ret != 0)
+	//return ret;
+
+#ifndef PJ_SYMBIAN
 
     PJ_LOG(3,("", "..echo test w/ TLSv1 and TLS_RSA_WITH_DES_CBC_SHA cipher"));
     ret = echo_test(PJ_SSL_SOCK_PROTO_TLS1, PJ_SSL_SOCK_PROTO_TLS1, 
@@ -1109,7 +1158,7 @@ int ssl_sock_test(void)
     if (ret == 0)
 	return PJ_EBUG;
 
-    PJ_LOG(3,("", "..client non-SSL timeout in 5 secs"));
+    PJ_LOG(3,("", "..client non-SSL (handshake timeout 5 secs)"));
     ret = client_non_ssl(5000);
     if (ret != 0)
 	return ret;
@@ -1119,6 +1168,8 @@ int ssl_sock_test(void)
     if (ret != 0)
 	return ret;
 
+#endif
+
     return 0;
 }