Rework some debug messages
authorWerner Koch <wk@gnupg.org>
Wed, 24 Jun 2015 10:16:14 +0000 (12:16 +0200)
committerWerner Koch <wk@gnupg.org>
Wed, 24 Jun 2015 10:16:14 +0000 (12:16 +0200)
* src/protocol.c (_ntbtls_state2str): New.
* src/ntbtls-cli.c (simple_client): Send some headers.

doc/HACKING
src/ntbtls-cli.c
src/ntbtls-int.h
src/protocol-cli.c
src/protocol-srv.c
src/protocol.c

index 62574e2..e034df3 100644 (file)
 #+end_example
 
 ** How to start an OpenSSL test server
+
+
+* Specs
+** RFC Notes
+
+*** 5246 - The Transport Layer Security (TLS) Protocol Version 1.2.
+    T. Dierks, E. Rescorla. August 2008. (Format: TXT=222395 bytes)
+    (Obsoletes RFC3268, RFC4346, RFC4366) (Updates RFC4492) (Updated
+    by RFC5746, RFC5878, RFC6176) (Status: PROPOSED STANDARD)
+
+*** 5746 Transport Layer Security (TLS) Renegotiation Indication Extension.
+    E. Rescorla, M. Ray, S. Dispensa, N. Oskov. February 2010.
+    (Format: TXT=33790 bytes) (Updates RFC5246, RFC4366, RFC4347,
+    RFC4346, RFC2246) (Status: PROPOSED STANDARD)
+
+*** 5878 Transport Layer Security (TLS) Authorization Extensions.
+    M. Brown, R. Housley. May 2010. (Format: TXT=44594 bytes) (Updates
+    RFC5246) (Status: EXPERIMENTAL)
+
+*** 6176 Prohibiting Secure Sockets Layer (SSL) Version 2.0.
+    S. Turner, T. Polk. March 2011. (Format: TXT=7642 bytes) (Updates
+    RFC2246, RFC4346, RFC5246) (Status: PROPOSED STANDARD)
+
+*** 5077 Transport Layer Security (TLS) Session Resumption without
+    Server-Side State. J. Salowey, H. Zhou, P. Eronen, H. Tschofenig.
+    January 2008. (Format: TXT=41989 bytes) (Obsoletes RFC4507)
+    (Status: PROPOSED STANDARD)
index 2187cf1..46264cf 100644 (file)
@@ -239,9 +239,14 @@ simple_client (const char *server, int port)
 
   do
     {
-      es_fputs ("GET / HTTP/1.0\r\n\r\n", writefp);
+      es_fputs ("GET / HTTP/1.0\r\n", writefp);
+      if (opt_hostname)
+        es_fprintf (writefp, "Host: %s\r\n", opt_hostname);
+      es_fprintf (writefp, "X-ntbtls: %s\r\n",
+                  ntbtls_check_version (PACKAGE_VERSION));
+      es_fputs ("\r\n", writefp);
       es_fflush (writefp);
-      while (/* es_pending (readfp) && */(c = es_fgetc (readfp)) != EOF)
+      while (/*es_pending (readfp) &&*/ (c = es_fgetc (readfp)) != EOF)
         putchar (c);
     }
   while (c != EOF);
index 3fd1b91..d734de6 100644 (file)
@@ -282,6 +282,8 @@ tls_own_cert (ntbtls_t tls)
 const char *_ntbtls_check_version (const char *req_version);
 
 /*-- protocol.c --*/
+const char *_ntbtls_state2str (tls_state_t state);
+
 gpg_error_t _ntbtls_fetch_input (ntbtls_t tls, size_t nb_want);
 gpg_error_t _ntbtls_flush_output (ntbtls_t tls);
 
index c29f883..69a635a 100644 (file)
@@ -42,7 +42,7 @@ write_hostname_ext (ntbtls_t tls, unsigned char *buf, size_t * olen)
   if (!tls->hostname)
     return;
 
-  debug_msg (3, "client hello, adding server name extension: '%s'",
+  debug_msg (3, "client_hello, adding server name extension: '%s'",
              tls->hostname);
 
   len = strlen (tls->hostname);
@@ -95,7 +95,7 @@ write_cli_renegotiation_ext (ntbtls_t ssl,
   if (ssl->renegotiation != TLS_RENEGOTIATION)
     return;
 
-  debug_msg (3, "client hello, adding renegotiation extension");
+  debug_msg (3, "client_hello, adding renegotiation extension");
 
   /*
    * Secure renegotiation
@@ -126,7 +126,7 @@ write_signature_algorithms_ext (ntbtls_t ssl,
   if (ssl->max_minor_ver != TLS_MINOR_VERSION_3)
     return;
 
-  debug_msg (3, "client hello, adding signature_algorithms extension");
+  debug_msg (3, "client_hello, adding signature_algorithms extension");
 
   /*
    * Prepare signature_algorithms extension (TLS 1.2)
@@ -258,7 +258,7 @@ write_cli_max_fragment_length_ext (ntbtls_t tls,
       return;
     }
 
-  debug_msg (3, "client hello, adding max_fragment_length extension");
+  debug_msg (3, "client_hello, adding max_fragment_length extension");
 
   *p++ = (unsigned char) ((TLS_EXT_MAX_FRAGMENT_LENGTH >> 8) & 0xFF);
   *p++ = (unsigned char) ((TLS_EXT_MAX_FRAGMENT_LENGTH) & 0xFF);
@@ -284,7 +284,7 @@ write_cli_truncated_hmac_ext (ntbtls_t tls,
       return;
     }
 
-  debug_msg (3, "client hello, adding truncated_hmac extension");
+  debug_msg (3, "client_hello, adding truncated_hmac extension");
 
   *p++ = (unsigned char) ((TLS_EXT_TRUNCATED_HMAC >> 8) & 0xFF);
   *p++ = (unsigned char) ((TLS_EXT_TRUNCATED_HMAC) & 0xFF);
@@ -309,7 +309,7 @@ write_cli_session_ticket_ext (ntbtls_t ssl,
       return;
     }
 
-  debug_msg (3, "client hello, adding session ticket extension");
+  debug_msg (3, "client_hello, adding session ticket extension");
 
   *p++ = (unsigned char) ((TLS_EXT_SESSION_TICKET >> 8) & 0xFF);
   *p++ = (unsigned char) ((TLS_EXT_SESSION_TICKET) & 0xFF);
@@ -325,7 +325,7 @@ write_cli_session_ticket_ext (ntbtls_t ssl,
       return;
     }
 
-  debug_msg (3, "sending session ticket of length %d", tlen);
+  debug_msg (3, "sending session_ticket of length %d", tlen);
 
   memcpy (p, ssl->session_negotiate->ticket, tlen);
 
@@ -392,7 +392,7 @@ write_client_hello (ntbtls_t tls)
   const int *ciphersuites;
   ciphersuite_t suite;
 
-  debug_msg (2, "=> write client hello");
+  debug_msg (2, "write client_hello");
 
   if (tls->renegotiation == TLS_INITIAL_HANDSHAKE)
     {
@@ -419,7 +419,7 @@ write_client_hello (ntbtls_t tls)
   *p++ = (unsigned char) tls->max_major_ver;
   *p++ = (unsigned char) tls->max_minor_ver;
 
-  debug_msg (3, "client hello, max version: [%d:%d]", buf[4], buf[5]);
+  debug_msg (3, "client_hello, max version: [%d:%d]", buf[4], buf[5]);
 
   t = time (NULL);
   *p++ = (unsigned char) (t >> 24);
@@ -427,7 +427,7 @@ write_client_hello (ntbtls_t tls)
   *p++ = (unsigned char) (t >> 8);
   *p++ = (unsigned char) (t);
 
-  debug_msg (3, "client hello, current time: %lu", t);
+  debug_msg (3, "client_hello, current time: %lu", t);
 
   //FIXME: Check RNG requirements.
   gcry_create_nonce (p, 28);
@@ -435,7 +435,7 @@ write_client_hello (ntbtls_t tls)
 
   memcpy (tls->handshake->randbytes, buf + 6, 32);
 
-  debug_buf (3, "client hello, random bytes", buf + 6, 32);
+  debug_buf (3, "client_hello, random bytes", buf + 6, 32);
 
   /*
    *    38  .  38   session id length
@@ -472,8 +472,8 @@ write_client_hello (ntbtls_t tls)
   for (i = 0; i < n; i++)
     *p++ = tls->session_negotiate->id[i];
 
-  debug_msg (3, "client hello, session id len.: %d", n);
-  debug_buf (3, "client hello, session id", buf + 39, n);
+  debug_msg (3, "client_hello, session id len.: %d", n);
+  debug_buf (3, "client_hello, session id", buf + 39, n);
 
   // Fixme: We do not have a way to set the ciphersuites.  Thus
   // consider to replace this with simpler code.
@@ -506,7 +506,7 @@ write_client_hello (ntbtls_t tls)
                                            tls->max_minor_ver))
         continue;
 
-      debug_msg (3, "client hello, add ciphersuite: %5d %s",
+      debug_msg (3, "client_hello, add ciphersuite: %5d %s",
                  ciphersuites[i],
                  _ntbtls_ciphersuite_get_name (ciphersuites[i]));
 
@@ -519,10 +519,10 @@ write_client_hello (ntbtls_t tls)
   *q++ = (unsigned char) (n >> 7);
   *q++ = (unsigned char) (n << 1);
 
-  debug_msg (3, "client hello, got %d ciphersuites", n);
+  debug_msg (3, "client_hello, got %d ciphersuites", n);
 
-  debug_msg (3, "client hello, compress len.: %d", 2);
-  debug_msg (3, "client hello, compress alg.: %d %d",
+  debug_msg (3, "client_hello, compress len.: %d", 2);
+  debug_msg (3, "client_hello, compress alg.: %d %d",
              TLS_COMPRESS_DEFLATE, TLS_COMPRESS_NULL);
 
   *p++ = 2;
@@ -557,7 +557,7 @@ write_client_hello (ntbtls_t tls)
   write_cli_alpn_ext (tls, p + 2 + ext_len, &olen);
   ext_len += olen;
 
-  debug_msg (3, "client hello, total extension length: %d", ext_len);
+  debug_msg (3, "client_hello, total extension length: %d", ext_len);
 
   if (ext_len > 0)
     {
@@ -579,9 +579,7 @@ write_client_hello (ntbtls_t tls)
       return err;
     }
 
-  debug_msg (2, "<= write client hello");
-
-  return (0);
+  return 0;
 }
 
 
@@ -772,7 +770,7 @@ parse_server_hello (ntbtls_t tls)
   const int *ciphersuites;
   uint32_t t;
 
-  debug_msg (2, "=> parse server hello");
+  debug_msg (2, "read server_hello");
 
   /*
    *     0  .   0   handshake type
@@ -792,23 +790,23 @@ parse_server_hello (ntbtls_t tls)
 
   if (tls->in_msgtype != TLS_MSG_HANDSHAKE)
     {
-      debug_msg (1, "bad server hello message");
+      debug_msg (1, "bad server_hello message");
       return gpg_error (GPG_ERR_UNEXPECTED_MSG);
     }
 
-  debug_msg (3, "server hello, chosen version: [%d:%d]",  buf[4], buf[5]);
+  debug_msg (3, "server_hello, chosen version: [%d:%d]",  buf[4], buf[5]);
 
   if (tls->in_hslen < 42
       || buf[0] != TLS_HS_SERVER_HELLO
       || buf[4] != TLS_MAJOR_VERSION_3)
     {
-      debug_msg (1, "bad server hello message");
+      debug_msg (1, "bad server_hello message");
       return gpg_error (GPG_ERR_BAD_HS_SERVER_HELLO);
     }
 
   if (buf[5] > tls->max_minor_ver)
     {
-      debug_msg (1, "bad server hello message");
+      debug_msg (1, "bad server_hello message");
       return gpg_error (GPG_ERR_BAD_HS_SERVER_HELLO);
     }
 
@@ -827,17 +825,17 @@ parse_server_hello (ntbtls_t tls)
     }
 
   t = buf32_to_u32 (buf+6);
-  debug_msg (3, "server hello, current time: %lu", t);
+  debug_msg (3, "server_hello, current time: %lu", t);
 
   memcpy (tls->handshake->randbytes + 32, buf + 6, 32);
 
   n = buf[38];
 
-  debug_buf (3, "server hello, random bytes", buf + 6, 32);
+  debug_buf (3, "server_hello, random bytes", buf + 6, 32);
 
   if (n > 32)
     {
-      debug_msg (1, "bad server hello message");
+      debug_msg (1, "bad server_hello message");
       return gpg_error (GPG_ERR_BAD_HS_SERVER_HELLO);
     }
 
@@ -854,7 +852,7 @@ parse_server_hello (ntbtls_t tls)
       ext_len = buf16_to_size_t (buf + 42 + n);
       if ((ext_len > 0 && ext_len < 4) || tls->in_hslen != 44 + n + ext_len)
         {
-          debug_msg (1, "bad server hello message");
+          debug_msg (1, "bad server_hello message");
           return gpg_error (GPG_ERR_BAD_HS_SERVER_HELLO);
         }
     }
@@ -875,8 +873,8 @@ parse_server_hello (ntbtls_t tls)
 
   _ntbtls_optimize_checksum (tls, tls->transform_negotiate->ciphersuite);
 
-  debug_msg (3, "server hello, session id len.: %d", n);
-  debug_buf (3, "server hello, session id", buf + 39, n);
+  debug_msg (3, "server_hello, session id len.: %d", n);
+  debug_buf (3, "server_hello, session id", buf + 39, n);
 
   /*
    * Check if the session can be resumed
@@ -912,8 +910,8 @@ parse_server_hello (ntbtls_t tls)
   debug_msg (3, "%s session has been resumed",
              tls->handshake->resume ? "a" : "no");
 
-  debug_msg (3, "server hello, chosen ciphersuite: %d", suite_id);
-  debug_msg (3, "server hello, compress alg.: %d", buf[41 + n]);
+  debug_msg (3, "server_hello, chosen ciphersuite: %d", suite_id);
+  debug_msg (3, "server_hello, compress alg.: %d", buf[41 + n]);
 
   /* Check that we support the cipher suite.  */
   ciphersuites = tls->ciphersuite_list[tls->minor_ver];
@@ -925,21 +923,21 @@ parse_server_hello (ntbtls_t tls)
     }
   if (!ciphersuites || !ciphersuites[i])
     {
-      debug_msg (1, "bad server hello message");
+      debug_msg (1, "bad server_hello message");
       return gpg_error (GPG_ERR_BAD_HS_SERVER_HELLO);
     }
 
 
   if (comp != TLS_COMPRESS_NULL && comp != TLS_COMPRESS_DEFLATE)
     {
-      debug_msg (1, "bad server hello message");
+      debug_msg (1, "bad server_hello message");
       return gpg_error (GPG_ERR_BAD_HS_SERVER_HELLO);
     }
   tls->session_negotiate->compression = comp;
 
   ext = buf + 44 + n;
 
-  debug_msg (2, "server hello, total extension length: %d", ext_len);
+  debug_msg (2, "server_hello, total extension length: %d", ext_len);
 
   while (ext_len)
     {
@@ -948,7 +946,7 @@ parse_server_hello (ntbtls_t tls)
 
       if (ext_size + 4 > ext_len)
         {
-          debug_msg (1, "bad server hello message");
+          debug_msg (1, "bad server_hello message");
           return gpg_error (GPG_ERR_BAD_HS_SERVER_HELLO);
         }
 
@@ -1007,7 +1005,7 @@ parse_server_hello (ntbtls_t tls)
 
       if (ext_len > 0 && ext_len < 4)
         {
-          debug_msg (1, "bad server hello message");
+          debug_msg (1, "bad server_hello message");
           return gpg_error (GPG_ERR_BAD_HS_SERVER_HELLO);
         }
     }
@@ -1051,8 +1049,6 @@ parse_server_hello (ntbtls_t tls)
       return err;
     }
 
-  debug_msg (2, "<= parse server hello");
-
   return 0;
 }
 
@@ -1333,11 +1329,9 @@ parse_server_key_exchange (ntbtls_t tls)
   pk_algo_t pk_alg = 0;
 
 
-  debug_msg (2, "=> parse server key exchange");
-
   if (kex == KEY_EXCHANGE_RSA)
     {
-      debug_msg (2, "<= skip parse server key exchange");
+      debug_msg (2, "skipping read server_key_exchange");
       tls->state++;
       return 0;
     }
@@ -1351,11 +1345,13 @@ parse_server_key_exchange (ntbtls_t tls)
           return err;
         }
 
-      debug_msg (2, "<= skip parse server key exchange");
+      debug_msg (2, "skipping read server_key_exchange");
       tls->state++;
       return 0;
     }
 
+  debug_msg (2, "read server_key_exchange");
+
   err = _ntbtls_read_record (tls);
   if (err)
     {
@@ -1365,7 +1361,7 @@ parse_server_key_exchange (ntbtls_t tls)
 
   if (tls->in_msgtype != TLS_MSG_HANDSHAKE)
     {
-      debug_msg (1, "bad server key exchange message (%d)", __LINE__);
+      debug_msg (1, "bad server_key_exchange message (%d)", __LINE__);
       return gpg_error (GPG_ERR_UNEXPECTED_MSG);
     }
 
@@ -1381,13 +1377,13 @@ parse_server_key_exchange (ntbtls_t tls)
           goto leave;
         }
 
-      debug_msg (1, "bad server key exchange message (%d)", __LINE__);
+      debug_msg (1, "bad server_key_exchange message (%d)", __LINE__);
       return gpg_error (GPG_ERR_UNEXPECTED_MSG);
     }
 
   p = tls->in_msg + 4;
   end = tls->in_msg + tls->in_hslen;
-  debug_buf (3, "server key exchange", p, tls->in_hslen - 4);
+  debug_buf (3, "server_key_exchange", p, tls->in_hslen - 4);
 
   if (kex == KEY_EXCHANGE_PSK
       || kex == KEY_EXCHANGE_RSA_PSK
@@ -1397,7 +1393,7 @@ parse_server_key_exchange (ntbtls_t tls)
       err = parse_server_psk_hint (tls, &p, end);
       if (err)
         {
-          debug_msg (1, "bad server key exchange message (%d)", __LINE__);
+          debug_msg (1, "bad server_key_exchange message (%d)", __LINE__);
           return err;
         }
     }
@@ -1411,7 +1407,7 @@ parse_server_key_exchange (ntbtls_t tls)
       err = parse_server_dh_params (tls, &p, end);
       if (err)
         {
-          debug_msg (1, "bad server key exchange message (%d)", __LINE__);
+          debug_msg (1, "bad server_key_exchange message (%d)", __LINE__);
           return err;
         }
     }
@@ -1422,7 +1418,7 @@ parse_server_key_exchange (ntbtls_t tls)
       err = parse_server_ecdh_params (tls, &p, end);
       if (err)
         {
-          debug_msg (1, "bad server key exchange message (%d)", __LINE__);
+          debug_msg (1, "bad server_key_exchange message (%d)", __LINE__);
           return err;
         }
     }
@@ -1447,13 +1443,13 @@ parse_server_key_exchange (ntbtls_t tls)
           err = parse_signature_algorithm (tls, &p, end, &md_alg, &pk_alg);
           if (err)
             {
-              debug_msg (1, "bad server key exchange message (%d)", __LINE__);
+              debug_msg (1, "bad server_key_exchange message (%d)", __LINE__);
               return err;
             }
 
           if (pk_alg != _ntbtls_ciphersuite_get_sig_pk_alg (suite))
             {
-              debug_msg (1, "bad server key exchange message (%d)", __LINE__);
+              debug_msg (1, "bad server_key_exchange message (%d)", __LINE__);
               return gpg_error (GPG_ERR_BAD_HS_SERVER_KEX);
             }
           //FIXME: Check that the ECC subtype matches.  */
@@ -1472,7 +1468,7 @@ parse_server_key_exchange (ntbtls_t tls)
 
       if (end != p + sig_len)
         {
-          debug_msg (1, "bad server key exchange message (%d)", __LINE__);
+          debug_msg (1, "bad server_key_exchange message (%d)", __LINE__);
           return gpg_error (GPG_ERR_BAD_HS_SERVER_KEX);
         }
 
@@ -1530,8 +1526,6 @@ parse_server_key_exchange (ntbtls_t tls)
  leave:
   tls->state++;
 
-  debug_msg (2, "<= parse server key exchange");
-
   return 0;
 }
 
@@ -1547,18 +1541,18 @@ parse_certificate_request (ntbtls_t tls)
   const ciphersuite_t suite = tls->transform_negotiate->ciphersuite;
   key_exchange_type_t kex = _ntbtls_ciphersuite_get_kex (suite);
 
-  debug_msg (2, "=> parse certificate request");
-
   if (kex == KEY_EXCHANGE_PSK
       || kex == KEY_EXCHANGE_RSA_PSK
       || kex == KEY_EXCHANGE_DHE_PSK
       || kex == KEY_EXCHANGE_ECDHE_PSK)
     {
-      debug_msg (2, "<= skip parse certificate request");
+      debug_msg (2, "skipping read certificate_request");
       tls->state++;
       return 0;
     }
 
+  debug_msg (2, "read certificate_request");
+
   /*
    *     0  .   0   handshake type
    *     1  .   3   handshake length
@@ -1582,7 +1576,7 @@ parse_certificate_request (ntbtls_t tls)
 
       if (tls->in_msgtype != TLS_MSG_HANDSHAKE)
         {
-          debug_msg (1, "bad certificate request message");
+          debug_msg (1, "bad certificate_request message");
           return gpg_error (GPG_ERR_UNEXPECTED_MSG);
         }
 
@@ -1595,7 +1589,7 @@ parse_certificate_request (ntbtls_t tls)
   if (tls->in_msg[0] == TLS_HS_CERTIFICATE_REQUEST)
     tls->client_auth++;
 
-  debug_msg (3, "got %s certificate request", tls->client_auth ? "a" : "no");
+  debug_msg (3, "got %s certificate_request", tls->client_auth ? "a" : "no");
 
   if (!tls->client_auth)
     goto leave;
@@ -1614,7 +1608,7 @@ parse_certificate_request (ntbtls_t tls)
 
   if (tls->in_hslen < 6 + n)
     {
-      debug_msg (1, "bad certificate request message");
+      debug_msg (1, "bad certificate_request message");
       return gpg_error (GPG_ERR_BAD_HS_CERT_REQ);
     }
 
@@ -1654,7 +1648,7 @@ parse_certificate_request (ntbtls_t tls)
 
       if (tls->in_hslen < 6 + n)
         {
-          debug_msg (1, "bad certificate request message");
+          debug_msg (1, "bad certificate_request message");
           return gpg_error (GPG_ERR_BAD_HS_CERT_REQ);
         }
     }
@@ -1666,12 +1660,11 @@ parse_certificate_request (ntbtls_t tls)
   n += dn_len;
   if (tls->in_hslen != 7 + m + n)
     {
-      debug_msg (1, "bad certificate request message");
+      debug_msg (1, "bad certificate_request message");
       return gpg_error (GPG_ERR_BAD_HS_CERT_REQ);
     }
 
  leave:
-  debug_msg (2, "<= parse certificate request");
 
   return 0;
 }
@@ -1682,7 +1675,7 @@ parse_server_hello_done (ntbtls_t tls)
 {
   gpg_error_t err;
 
-  debug_msg (2, "=> parse server hello done");
+  debug_msg (2, "read server_hello_done");
 
   if (!tls->record_read)
     {
@@ -1695,7 +1688,7 @@ parse_server_hello_done (ntbtls_t tls)
 
       if (tls->in_msgtype != TLS_MSG_HANDSHAKE)
         {
-          debug_msg (1, "bad server hello done message");
+          debug_msg (1, "bad server_hello_done message");
           return gpg_error (GPG_ERR_UNEXPECTED_MSG);
         }
     }
@@ -1703,14 +1696,12 @@ parse_server_hello_done (ntbtls_t tls)
 
   if (tls->in_hslen != 4 || tls->in_msg[0] != TLS_HS_SERVER_HELLO_DONE)
     {
-      debug_msg (1, "bad server hello done message");
+      debug_msg (1, "bad server_hello_done message");
       return gpg_error (GPG_ERR_BAD_HS_SERVER_HELLO_DONE);
     }
 
   tls->state++;
 
-  debug_msg (2, "<= parse server hello done");
-
   return 0;
 }
 
@@ -1723,7 +1714,7 @@ write_client_key_exchange (ntbtls_t tls)
   const ciphersuite_t suite = tls->transform_negotiate->ciphersuite;
   key_exchange_type_t kex = _ntbtls_ciphersuite_get_kex (suite);
 
-  debug_msg (2, "=> write client key exchange");
+  debug_msg (2, "write client_key_exchange");
 
   if (kex == KEY_EXCHANGE_DHE_RSA)
     {
@@ -1895,8 +1886,6 @@ write_client_key_exchange (ntbtls_t tls)
       return err;
     }
 
-  debug_msg (2, "<= write client key exchange");
-
   return 0;
 }
 
@@ -1914,25 +1903,20 @@ write_certificate_verify (ntbtls_t tls)
   md_algo_t md_alg = 0;
   unsigned int hashlen;
 
-  debug_msg (2, "=> write certificate verify");
-
   if (kex == KEY_EXCHANGE_PSK
       || kex == KEY_EXCHANGE_RSA_PSK
       || kex == KEY_EXCHANGE_ECDHE_PSK
-      || kex == KEY_EXCHANGE_DHE_PSK)
-    {
-      debug_msg (2, "<= skip write certificate verify");
-      tls->state++;
-      return (0);
-    }
-
-  if (!tls->client_auth  || !tls_own_cert (tls))
+      || kex == KEY_EXCHANGE_DHE_PSK
+      || !tls->client_auth
+      || !tls_own_cert (tls))
     {
-      debug_msg (2, "<= skip write certificate verify");
+      debug_msg (2, "skipping write certificate_verify");
       tls->state++;
       return 0;
     }
 
+  debug_msg (2, "write certificate_verify");
+
   if (!tls_own_key (tls))
     {
       debug_msg (1, "got no private key");
@@ -2009,8 +1993,6 @@ write_certificate_verify (ntbtls_t tls)
       return err;
     }
 
-  debug_msg (2, "<= write certificate verify");
-
   return 0;
 }
 
@@ -2023,7 +2005,7 @@ parse_new_session_ticket (ntbtls_t tls)
   size_t ticket_len;
   unsigned char *ticket;
 
-  debug_msg (2, "=> parse new session ticket");
+  debug_msg (2, "read new_session_ticket");
 
   err = _ntbtls_read_record (tls);
   if (err)
@@ -2034,7 +2016,7 @@ parse_new_session_ticket (ntbtls_t tls)
 
   if (tls->in_msgtype != TLS_MSG_HANDSHAKE)
     {
-      debug_msg (1, "bad new session ticket message");
+      debug_msg (1, "bad new_session_ticket message");
       return gpg_error (GPG_ERR_UNEXPECTED_MSG);
     }
 
@@ -2052,7 +2034,7 @@ parse_new_session_ticket (ntbtls_t tls)
    */
   if (tls->in_msg[0] != TLS_HS_NEW_SESSION_TICKET || tls->in_hslen < 10)
     {
-      debug_msg (1, "bad new session ticket message");
+      debug_msg (1, "bad new_session_ticket message");
       return gpg_error (GPG_ERR_BAD_TICKET);
     }
 
@@ -2061,7 +2043,7 @@ parse_new_session_ticket (ntbtls_t tls)
 
   if (ticket_len + 10 != tls->in_hslen)
     {
-      debug_msg (1, "bad new session ticket message");
+      debug_msg (1, "bad new_session_ticket message");
       return gpg_error (GPG_ERR_BAD_TICKET);
     }
 
@@ -2105,8 +2087,6 @@ parse_new_session_ticket (ntbtls_t tls)
   debug_msg (3, "ticket in use, discarding session id");
   tls->session_negotiate->length = 0;
 
-  debug_msg (2, "<= parse new session ticket");
-
   return 0;
 }
 
@@ -2122,7 +2102,8 @@ _ntbtls_handshake_client_step (ntbtls_t tls)
   if (tls->state == TLS_HANDSHAKE_OVER)
     return gpg_error (GPG_ERR_INV_STATE);
 
-  debug_msg (2, "client state: %d", tls->state);
+  debug_msg (2, "client state: %d (%s)",
+             tls->state, _ntbtls_state2str (tls->state));
 
   err = _ntbtls_flush_output (tls);
   if (err)
index 5d9b5fb..c6b6b43 100644 (file)
@@ -2605,7 +2605,8 @@ _ntbtls_handshake_server_step (ntbtls_t tls)
   if (tls->state == TLS_HANDSHAKE_OVER)
     return gpg_error (GPG_ERR_INV_STATE)
 
-  debug_msg (2, "server state: %d", tls->state);
+  debug_msg (2, "server state: %d (%s)",
+             tls->state, _ntbtls_state2str (tls->state));
 
   err = _ntbtls_flush_output (tls);
   if (err)
index b863d05..432b772 100644 (file)
@@ -79,6 +79,37 @@ is_aead_mode (cipher_mode_t mode)
 }
 
 
+const char *
+_ntbtls_state2str (tls_state_t state)
+{
+  const char *s = "?";
+
+  switch (state)
+    {
+    case TLS_HELLO_REQUEST:             s = "hello_request"; break;
+    case TLS_CLIENT_HELLO:              s = "client_hello"; break;
+    case TLS_SERVER_HELLO:              s = "server_hello"; break;
+    case TLS_SERVER_CERTIFICATE:        s = "server_certificate"; break;
+    case TLS_SERVER_KEY_EXCHANGE:       s = "server_key_exchange"; break;
+    case TLS_CERTIFICATE_REQUEST:       s = "certificate_request"; break;
+    case TLS_SERVER_HELLO_DONE:         s = "server_hello_done"; break;
+    case TLS_CLIENT_CERTIFICATE:        s = "client_certificate"; break;
+    case TLS_CLIENT_KEY_EXCHANGE:       s = "client_key_exchange"; break;
+    case TLS_CERTIFICATE_VERIFY:        s = "certificate_verify"; break;
+    case TLS_CLIENT_CHANGE_CIPHER_SPEC: s = "client_change_cipher_spec"; break;
+    case TLS_CLIENT_FINISHED:           s = "client_finished"; break;
+    case TLS_SERVER_CHANGE_CIPHER_SPEC: s = "server_change_cipher_spec"; break;
+    case TLS_SERVER_FINISHED:           s = "server_finished"; break;
+    case TLS_FLUSH_BUFFERS:             s = "flush_buffers"; break;
+    case TLS_HANDSHAKE_WRAPUP:          s = "handshake_wrapup"; break;
+    case TLS_HANDSHAKE_OVER:            s = "handshake_over"; break;
+    case TLS_SERVER_NEW_SESSION_TICKET: s = "server_new_session_tickets"; break;
+    }
+  return s;
+}
+
+
+
 static gpg_error_t
 session_copy (session_t dst, const session_t src)
 {
@@ -252,7 +283,7 @@ _ntbtls_derive_keys (ntbtls_t tls)
   transform_t transform = tls->transform_negotiate;
   handshake_params_t handshake = tls->handshake;
 
-  debug_msg (2, "=> derive keys");
+  debug_msg (2, "derive keys");
 
   if (tls->minor_ver != TLS_MINOR_VERSION_3)
     {
@@ -516,8 +547,6 @@ _ntbtls_derive_keys (ntbtls_t tls)
         }
     }
 
-  debug_msg (2, "<= derive keys");
-
   return 0;
 }
 
@@ -530,7 +559,7 @@ calc_verify_tls (gcry_md_hd_t md_input, md_algo_t md_alg,
   gcry_md_hd_t md;
   char *p;
 
-  debug_msg (2, "=> calc verify tls sha%d", hashlen*8);
+  debug_msg (2, "calc_verify_tls sha%d", hashlen*8);
 
   err = gcry_md_copy (&md, md_input);
   if (err)
@@ -551,7 +580,7 @@ calc_verify_tls (gcry_md_hd_t md_input, md_algo_t md_alg,
   gcry_md_close (md);
 
   debug_buf (3, "calculated verify result", hash, hashlen);
-  debug_msg (2, "<= calc verify tls sha%d", hashlen*8);
+  debug_msg (3, "calc_verify_tls sha%d", hashlen*8);
 }
 
 
@@ -669,7 +698,7 @@ encrypt_buf (ntbtls_t tls)
   size_t tmplen, i;
   cipher_mode_t mode = tls->transform_out->cipher_mode_enc;
 
-  debug_msg (2, "=> encrypt buf");
+  debug_msg (2, "encrypt buf");
 
   if (tls->minor_ver < TLS_MINOR_VERSION_3)
     {
@@ -867,8 +896,6 @@ encrypt_buf (ntbtls_t tls)
       return gpg_error (GPG_ERR_WOULD_WRAP);
     }
 
-  debug_msg (2, "<= encrypt buf");
-
   return 0;
 }
 
@@ -882,7 +909,7 @@ decrypt_buf (ntbtls_t tls)
   size_t correct = 1;
   size_t tmplen, i;
 
-  debug_msg (2, "=> decrypt buf");
+  debug_msg (2, "decrypt buf");
 
   if (tls->minor_ver < TLS_MINOR_VERSION_3)
     {
@@ -1207,8 +1234,6 @@ decrypt_buf (ntbtls_t tls)
       return gpg_error (GPG_ERR_WOULD_WRAP);
     }
 
-  debug_msg (2, "<= decrypt buf");
-
   return 0;
 }
 
@@ -1224,7 +1249,7 @@ ssl_compress_buf (ntbtls_t ssl)
   size_t len_pre = ssl->out_msglen;
   unsigned char *msg_pre = ssl->compress_buf;
 
-  debug_msg (2, "=> compress buf");
+  debug_msg (2, "compress buf");
 
   if (len_pre == 0)
     return (0);
@@ -1257,8 +1282,6 @@ ssl_compress_buf (ntbtls_t ssl)
   debug_buf (4, "after compression: output payload",
              ssl->out_msg, ssl->out_msglen);
 
-  debug_msg (2, "<= compress buf");
-
   return (0);
 }
 
@@ -1270,7 +1293,7 @@ ssl_decompress_buf (ntbtls_t ssl)
   size_t len_pre = ssl->in_msglen;
   unsigned char *msg_pre = ssl->compress_buf;
 
-  debug_msg (2, "=> decompress buf");
+  debug_msg (2, "decompress buf");
 
   if (len_pre == 0)
     return (0);
@@ -1303,8 +1326,6 @@ ssl_decompress_buf (ntbtls_t ssl)
   debug_buf (4, "after decompression: input payload",
              ssl->in_msg, ssl->in_msglen);
 
-  debug_msg (2, "<= decompress buf");
-
   return (0);
 }
 
@@ -1318,7 +1339,7 @@ _ntbtls_fetch_input (ntbtls_t tls, size_t nb_want)
   gpg_error_t err;
   size_t len, nread;
 
-  debug_msg (2, "=> fetch input");
+  debug_msg (3, "fetch input");
 
   if (!tls->inbound)
     return gpg_error (GPG_ERR_NOT_INITIALIZED);
@@ -1336,8 +1357,8 @@ _ntbtls_fetch_input (ntbtls_t tls, size_t nb_want)
       if (es_read (tls->inbound, tls->in_hdr + tls->in_left, len, &nread))
         err = gpg_error_from_syserror ();
 
-      debug_msg (2, "in_left: %d, nb_want: %d", tls->in_left, nb_want);
-      debug_ret (2, "es_read", err);
+      debug_msg (3, "in_left: %d, nb_want: %d", tls->in_left, nb_want);
+      debug_ret (3, "es_read", err);
 
       if (err || !nread /*ie. EOF*/)
         break;
@@ -1345,8 +1366,6 @@ _ntbtls_fetch_input (ntbtls_t tls, size_t nb_want)
       tls->in_left += nread;
     }
 
-  debug_msg (2, "<= fetch input");
-
   return err;
 }
 
@@ -1361,7 +1380,7 @@ _ntbtls_flush_output (ntbtls_t tls)
   unsigned char *buf;
   size_t nwritten;
 
-  debug_msg (2, "=> flush output");
+  debug_msg (3, "flush output");
 
   if (!tls->outbound)
     return gpg_error (GPG_ERR_NOT_INITIALIZED);
@@ -1369,14 +1388,14 @@ _ntbtls_flush_output (ntbtls_t tls)
   err = 0;
   while (tls->out_left > 0)
     {
-      debug_msg (2, "message length: %d, out_left: %d",
+      debug_msg (3, "message length: %d, out_left: %d",
                  5 + tls->out_msglen, tls->out_left);
 
       buf = tls->out_hdr + 5 + tls->out_msglen - tls->out_left;
       if (es_write (tls->outbound, buf, tls->out_left, &nwritten))
         err = gpg_error_from_syserror ();
 
-      debug_ret (2, "es_write", err);
+      debug_ret (3, "es_write", err);
 
       if (err)
         break;
@@ -1384,8 +1403,6 @@ _ntbtls_flush_output (ntbtls_t tls)
       tls->out_left -= nwritten;
     }
 
-  debug_msg (2, "<= flush output");
-
   return err;
 }
 
@@ -1400,7 +1417,7 @@ _ntbtls_write_record (ntbtls_t tls)
   int done = 0;
   size_t len = tls->out_msglen;
 
-  debug_msg (2, "=> write record");
+  debug_msg (3, "write record");
 
   if (tls->out_msgtype == TLS_MSG_HANDSHAKE)
     {
@@ -1460,12 +1477,7 @@ _ntbtls_write_record (ntbtls_t tls)
 
   err = _ntbtls_flush_output (tls);
   if (err)
-    {
-      debug_ret (1, "_ntbtls_flush_output", err);
-      return err;
-    }
-
-  debug_msg (2, "<= write record");
+    debug_ret (1, "_ntbtls_flush_output", err);
 
   return err;
 }
@@ -1477,7 +1489,7 @@ _ntbtls_read_record (ntbtls_t tls)
   gpg_error_t err;
   int done = 0;
 
-  debug_msg (2, "=> read record");
+  debug_msg (3, "read record");
 
   if (tls->in_hslen != 0 && tls->in_hslen < tls->in_msglen)
     {
@@ -1708,8 +1720,6 @@ _ntbtls_read_record (ntbtls_t tls)
 
   tls->in_left = 0;
 
-  debug_msg (2, "<= read record");
-
   return (0);
 }
 
@@ -1728,7 +1738,7 @@ _ntbtls_send_alert_message (ntbtls_t tls,
 {
   gpg_error_t err;
 
-  debug_msg (2, "=> send alert message");
+  debug_msg (2, "send alert message");
 
   tls->out_msgtype = TLS_MSG_ALERT;
   tls->out_msglen = 2;
@@ -1742,8 +1752,6 @@ _ntbtls_send_alert_message (ntbtls_t tls,
       return err;
     }
 
-  debug_msg (2, "<= send alert message");
-
   return 0;
 }
 
@@ -1765,34 +1773,22 @@ _ntbtls_write_certificate (ntbtls_t tls)
   size_t derlen;
   size_t i;
 
-  debug_msg (2, "=> write certificate");
-
   if (kex == KEY_EXCHANGE_PSK
       || kex == KEY_EXCHANGE_DHE_PSK
-      || kex == KEY_EXCHANGE_ECDHE_PSK)
+      || kex == KEY_EXCHANGE_ECDHE_PSK
+      || (tls->is_client && !tls->client_auth))
     {
-      debug_msg (2, "<= skip write certificate");
+      debug_msg (2, "skipping write certificate");
       tls->state++;
       return 0;
     }
 
-  if (tls->is_client)
-    {
-      if (!tls->client_auth)
-        {
-          debug_msg (2, "<= skip write certificate");
-          tls->state++;
-          return 0;
-        }
+  debug_msg (2, "write certificate");
 
-    }
-  else /* is_server */
+  if (!tls->is_client && !tls_own_cert (tls))
     {
-      if (!tls_own_cert (tls))
-        {
-          debug_msg (1, "got no certificate to send");
-          return gpg_error (GPG_ERR_MISSING_CERT);
-        }
+      debug_msg (1, "got no certificate to send");
+      return gpg_error (GPG_ERR_MISSING_CERT);
     }
 
   /* SSL_DEBUG_CRT (3, "own certificate", tls_own_cert (tls)); */
@@ -1842,8 +1838,6 @@ _ntbtls_write_certificate (ntbtls_t tls)
       return err;
     }
 
-  debug_msg (2, "<= write certificate");
-
   return err;
 }
 
@@ -1856,13 +1850,11 @@ _ntbtls_parse_certificate (ntbtls_t tls)
   const ciphersuite_t suite = tls->transform_negotiate->ciphersuite;
   key_exchange_type_t kex = _ntbtls_ciphersuite_get_kex (suite);
 
-  debug_msg (2, "=> parse certificate");
-
   if (kex == KEY_EXCHANGE_PSK
       || kex == KEY_EXCHANGE_DHE_PSK
       || kex == KEY_EXCHANGE_ECDHE_PSK)
     {
-      debug_msg (2, "<= skip parse certificate");
+      debug_msg (2, "skipping read certificate");
       tls->state++;
       return 0;
     }
@@ -1871,11 +1863,13 @@ _ntbtls_parse_certificate (ntbtls_t tls)
       && (tls->authmode == TLS_VERIFY_NONE || kex == KEY_EXCHANGE_RSA_PSK))
     {
       tls->session_negotiate->verify_result = BADCERT_SKIP_VERIFY;
-      debug_msg (2, "<= skip parse certificate");
+      debug_msg (2, "skipping read certificate");
       tls->state++;
       return 0;
     }
 
+  debug_msg (2, "read certificate");
+
   err = _ntbtls_read_record (tls);
   if (err)
     {
@@ -2041,8 +2035,6 @@ _ntbtls_parse_certificate (ntbtls_t tls)
         err = 0;
     }
 
-  debug_msg (2, "<= parse certificate");
-
   return err;
 }
 
@@ -2052,7 +2044,7 @@ _ntbtls_write_change_cipher_spec (ntbtls_t tls)
 {
   gpg_error_t err;
 
-  debug_msg (2, "=> write change cipher spec");
+  debug_msg (2, "write change cipher spec");
 
   tls->out_msgtype = TLS_MSG_CHANGE_CIPHER_SPEC;
   tls->out_msglen = 1;
@@ -2067,8 +2059,6 @@ _ntbtls_write_change_cipher_spec (ntbtls_t tls)
       return err;
     }
 
-  debug_msg (2, "<= write change cipher spec");
-
   return 0;
 }
 
@@ -2078,7 +2068,7 @@ _ntbtls_parse_change_cipher_spec (ntbtls_t tls)
 {
   gpg_error_t err;
 
-  debug_msg (2, "=> parse change cipher spec");
+  debug_msg (2, "read change_cipher_spec");
 
   err = _ntbtls_read_record (tls);
   if (err)
@@ -2089,20 +2079,18 @@ _ntbtls_parse_change_cipher_spec (ntbtls_t tls)
 
   if (tls->in_msgtype != TLS_MSG_CHANGE_CIPHER_SPEC)
     {
-      debug_msg (1, "bad change cipher spec message");
+      debug_msg (1, "bad change_cipher_spec message");
       return gpg_error (GPG_ERR_UNEXPECTED_MSG);
     }
 
   if (tls->in_msglen != 1 || tls->in_msg[0] != 1)
     {
-      debug_msg (1, "bad change cipher spec message");
+      debug_msg (1, "bad change_cipher_spec message");
       return gpg_error (GPG_ERR_BAD_HS_CHANGE_CIPHER);
     }
 
   tls->state++;
 
-  debug_msg (2, "<= parse change cipher spec");
-
   return 0;
 }
 
@@ -2162,7 +2150,7 @@ calc_finished_tls (ntbtls_t tls, int is_sha384,
   if (!session)
     session = tls->session;
 
-  debug_msg (2, "=> calc finished tls sha%d", is_sha384? 384 : 256);
+  debug_msg (2, "calc finished tls sha%d", is_sha384? 384 : 256);
 
   err = gcry_md_copy (&md, (is_sha384 ? tls->handshake->fin_sha512
                             /*     */ : tls->handshake->fin_sha256));
@@ -2197,8 +2185,6 @@ calc_finished_tls (ntbtls_t tls, int is_sha384,
   debug_buf (3, "calc finished result", buf, len);
 
   wipememory (padbuf, hashlen);
-
-  debug_msg (2, "<= calc finished tls sha%d", is_sha384? 384 : 256);
 }
 
 
@@ -2220,7 +2206,7 @@ _ntbtls_handshake_wrapup (ntbtls_t tls)
 {
   int resume = tls->handshake->resume;
 
-  debug_msg (3, "=> handshake wrapup");
+  debug_msg (3, "handshake wrapup");
 
   /*
    * Free our handshake params
@@ -2265,7 +2251,7 @@ _ntbtls_handshake_wrapup (ntbtls_t tls)
 
   tls->state++;
 
-  debug_msg (3, "<= handshake wrapup");
+  debug_msg (3, "handshake wrapup ready ");
 }
 
 
@@ -2275,7 +2261,7 @@ _ntbtls_write_finished (ntbtls_t tls)
   gpg_error_t err;
   int hashlen;
 
-  debug_msg (2, "=> write finished");
+  debug_msg (2, "write finished");
 
   /*
    * Set the out_msg pointer to the correct location based on IV length
@@ -2332,8 +2318,6 @@ _ntbtls_write_finished (ntbtls_t tls)
       return err;
     }
 
-  debug_msg (2, "<= write finished");
-
   return 0;
 }
 
@@ -2345,7 +2329,7 @@ _ntbtls_parse_finished (ntbtls_t tls)
   unsigned int hashlen;
   unsigned char buf[36];
 
-  debug_msg (2, "=> parse finished");
+  debug_msg (2, "read finished");
 
   tls->handshake->calc_finished (tls, buf, !tls->is_client);
 
@@ -2413,8 +2397,6 @@ _ntbtls_parse_finished (ntbtls_t tls)
   else
     tls->state++;
 
-  debug_msg (2, "<= parse finished");
-
   return 0;
 }
 
@@ -2738,7 +2720,7 @@ _ntbtls_release (ntbtls_t tls)
   if (!tls)
     return;
 
-  debug_msg (2, "=> release");
+  debug_msg (2, "release");
 
   if (tls->out_ctr)
     {
@@ -2807,8 +2789,6 @@ _ntbtls_release (ntbtls_t tls)
   //FIXME:
   /* ssl_key_cert_free (tls->key_cert); */
 
-  debug_msg (2, "<= release");
-
   /* Actually clear after last debug message */
   wipememory (tls, sizeof *tls);
   free (tls);
@@ -3476,7 +3456,7 @@ _ntbtls_handshake (ntbtls_t tls)
 {
   gpg_error_t err = 0;
 
-  debug_msg (2, "=> handshake");
+  debug_msg (2, "handshake");
 
   while (tls->state != TLS_HANDSHAKE_OVER)
     {
@@ -3485,7 +3465,7 @@ _ntbtls_handshake (ntbtls_t tls)
         break;
     }
 
-  debug_msg (2, "<= handshake");
+  debug_msg (2, "handshake ready");
 
   return err;
 }
@@ -3499,7 +3479,7 @@ ssl_write_hello_request (ntbtls_t ssl)
 {
   int ret;
 
-  debug_msg (2, "=> write hello request");
+  debug_msg (2, "write hello_request");
 
   ssl->out_msglen = 4;
   ssl->out_msgtype = TLS_MSG_HANDSHAKE;
@@ -3514,8 +3494,6 @@ ssl_write_hello_request (ntbtls_t ssl)
 
   ssl->renegotiation = TLS_RENEGOTIATION_PENDING;
 
-  debug_msg (2, "<= write hello request");
-
   return (0);
 }
 
@@ -3534,7 +3512,7 @@ start_renegotiation (ntbtls_t tls)
 {
   gpg_error_t err;
 
-  debug_msg (2, "=> renegotiate");
+  debug_msg (2, "renegotiate");
 
   err = handshake_init (tls);
   if (err)
@@ -3550,8 +3528,6 @@ start_renegotiation (ntbtls_t tls)
       return err;
     }
 
-  debug_msg (2, "<= renegotiate");
-
   return 0;
 }
 
@@ -3610,7 +3586,7 @@ _ntbtls_close_notify (ntbtls_t tls)
 {
   gpg_error_t err;
 
-  debug_msg (2, "=> write close notify");
+  debug_msg (2, "write close_notify");
 
   err = _ntbtls_flush_output (tls);
   if (err)
@@ -3627,8 +3603,6 @@ _ntbtls_close_notify (ntbtls_t tls)
         return err;
     }
 
-  debug_msg (2, "<= write close notify");
-
   return err;
 }
 
@@ -3801,7 +3775,7 @@ tls_read (ntbtls_t tls, unsigned char *buf, size_t len, size_t *nread)
 
   *nread = 0;
 
-  debug_msg (2, "=> tls read");
+  debug_msg (2, "tls read");
 
   if (tls->state != TLS_HANDSHAKE_OVER)
     {
@@ -3923,7 +3897,7 @@ tls_read (ntbtls_t tls, unsigned char *buf, size_t len, size_t *nread)
   else /* More data available.  */
     tls->in_offt += n;
 
-  debug_msg (2, "<= tls read");
+  debug_msg (2, "tls read ready");
 
   *nread = n;
   return 0;
@@ -3942,7 +3916,7 @@ tls_write (ntbtls_t tls, const unsigned char *buf, size_t len, size_t *nwritten)
 
   *nwritten = 0;
 
-  debug_msg (2, "=> tls write");
+  debug_msg (2, "tls write");
 
   if (tls->state != TLS_HANDSHAKE_OVER)
     {
@@ -3993,7 +3967,7 @@ tls_write (ntbtls_t tls, const unsigned char *buf, size_t len, size_t *nwritten)
         }
     }
 
-  debug_msg (2, "<= tls write");
+  debug_msg (2, "tls write ready");
 
   *nwritten = n;
   return 0;
@@ -4072,8 +4046,8 @@ static es_cookie_io_functions_t cookie_functions =
   };
 
 
-/* Return the two streams used to read and write the plaintext.  the
-   streams are valid as along as TLS is valid and may thus not be used
+/* Return the two streams used to read and write the plaintext.  The
+   streams are valid as long as TLS is valid and may thus not be used
    after TLS has been destroyed.  Note: After adding a "fullduplex"
    feature to estream we will allow to pass NULL for r_writefp to
    make use of that feature.  */