From a424623dc6f85b931e631572157454bf1bdc8aca Mon Sep 17 00:00:00 2001 From: Andy Green Date: Thu, 30 Jul 2020 16:23:59 +0100 Subject: [PATCH] docs: add README-debugging.md and provide example points for decrypted traffic handling Some general debugging advice but also really clarify the official way of how to dump what is going out and coming in directly from the tls tunnel, so you can see the actual data unencrypted. --- READMEs/README.debugging.md | 63 +++++++++++++++++++++++++++++++++++ lib/core-net/output.c | 14 ++++---- lib/tls/mbedtls/mbedtls-ssl.c | 19 +++++++++++ lib/tls/openssl/openssl-ssl.c | 22 +++++++++--- 4 files changed, 107 insertions(+), 11 deletions(-) create mode 100644 READMEs/README.debugging.md diff --git a/READMEs/README.debugging.md b/READMEs/README.debugging.md new file mode 100644 index 000000000..aca24b2b5 --- /dev/null +++ b/READMEs/README.debugging.md @@ -0,0 +1,63 @@ +# Tips on debugging with lws + +## Problem with the library, or your code? + +Because lws is only really used when already combined with user code, +it can be a headache figuring out if the actual problem is inside lws +or in the user code. + +If it's in lws, I would really like to solve it, but if it's in your +code, that's your problem. Finding out which side it's on when it +involves your code is also something you need to try to resolve. + +The minimal examples are useful because if they demonstrate the same +problem, it's something about your platform or lws itself, I have the +minimal examples so I can test it and find out if it's your platform. +If I can reproduce it, it's my problem. + +## Debug builds + +With cmake, build with `-DCMAKE_BUILD_TYPE=DEBUG` to build in extra +logging, and use a log level bitmap of eg, 1039 or 1151 to enable +the extra logs for print. + +The minimal examples take a -d xxx commandline parameter so you can +select the logging level when you run it. + +The extra logging can be very useful to understand the sequencing of +problematic actions. + +## Valgrind + +If your problems involve heap corruption or use-after-free, Valgrind +is indespensible. It's simple to use, if you normally run `xxx`, just +run `valgrind xxx`. Your code will run slower, usually something +like 2 - 4x slower but it depends on the exact code. However you will +get a backtrace as soon as there is some kind of misbehaviour of either +lws or your code. + +lws is developed using valgrind routinely and strives to be completely +valgrind-clean. So typically any problems reported are telling you +about problems in user code (or my bugs). + +## Traffic dumping + +The best place for dumping traffic, assuming you are linking against a +tls library, is `lws_ssl_capable_read()` and `lws_ssl_capable_write()` +in either `./lib/tls/openssl/openssl-ssl.c` or +`./lib/tls/mbedtls/mbedtls-ssl.c` according to which tls library you +are using. There are default-`#if 0` sections in each function like + +``` +#if 0 + /* + * If using mbedtls type tls library, this is the earliest point for all + * paths to dump what was received as decrypted data from the tls tunnel + */ + lwsl_notice("%s: len %d\n", __func__, len); + lwsl_hexdump_notice(buf, len); +#endif +``` + +Enable these to get hexdumps for all unencrypted data in both directions. + diff --git a/lib/core-net/output.c b/lib/core-net/output.c index a9f9082e6..264f88e55 100644 --- a/lib/core-net/output.c +++ b/lib/core-net/output.c @@ -35,16 +35,16 @@ lws_issue_raw(struct lws *wsi, unsigned char *buf, size_t len) size_t real_len = len; unsigned int n, m; -#if 0 /* - * This is the last place data going out over tls tunnels can be dumped - * before encryption, in order to understand what's being sent "raw" + * If you're looking to dump data being sent down the tls tunnel, see + * lws_ssl_capable_write() in lib/tls/mbedtls/mbedtls-ssl.c or + * lib/tls/openssl/openssl-ssl.c. + * + * There's also a corresponding lws_ssl_capable_read() in those files + * where you can enable a dump of decrypted data as soon as it was + * read. */ - lwsl_notice("%s: wsi: %p, len: %d\n", __func__, wsi, (int)len); - lwsl_hexdump_notice(buf, len); -#endif - /* * Detect if we got called twice without going through the * event loop to handle pending. Since that guarantees extending any diff --git a/lib/tls/mbedtls/mbedtls-ssl.c b/lib/tls/mbedtls/mbedtls-ssl.c index db5489e6f..d5f06d53a 100644 --- a/lib/tls/mbedtls/mbedtls-ssl.c +++ b/lib/tls/mbedtls/mbedtls-ssl.c @@ -106,6 +106,15 @@ lws_ssl_capable_read(struct lws *wsi, unsigned char *buf, int len) return LWS_SSL_CAPABLE_ERROR; } +#if 0 + /* + * If using mbedtls type tls library, this is the earliest point for all + * paths to dump what was received as decrypted data from the tls tunnel + */ + lwsl_notice("%s: len %d\n", __func__, n); + lwsl_hexdump_notice(buf, n); +#endif + lws_stats_bump(pt, LWSSTATS_B_READ, n); #if defined(LWS_WITH_SERVER_STATUS) @@ -163,6 +172,16 @@ lws_ssl_capable_write(struct lws *wsi, unsigned char *buf, int len) { int n, m; +#if 0 + /* + * If using mbedtls type tls library, this is the last point for all + * paths before sending data into the tls tunnel, where you can dump it + * and see what is being sent. + */ + lwsl_notice("%s: len %d\n", __func__, len); + lwsl_hexdump_notice(buf, len); +#endif + if (!wsi->tls.ssl) return lws_ssl_capable_write_no_ssl(wsi, buf, len); diff --git a/lib/tls/openssl/openssl-ssl.c b/lib/tls/openssl/openssl-ssl.c index 00e5e62f1..0943d2436 100644 --- a/lib/tls/openssl/openssl-ssl.c +++ b/lib/tls/openssl/openssl-ssl.c @@ -290,6 +290,15 @@ lws_ssl_capable_read(struct lws *wsi, unsigned char *buf, int len) /* keep on trucking it seems */ } +#if 0 + /* + * If using openssl type tls library, this is the earliest point for all + * paths to dump what was received as decrypted data from the tls tunnel + */ + lwsl_notice("%s: len %d\n", __func__, n); + lwsl_hexdump_notice(buf, n); +#endif + lws_stats_bump(pt, LWSSTATS_B_READ, n); #if defined(LWS_WITH_SERVER_STATUS) @@ -297,8 +306,6 @@ lws_ssl_capable_read(struct lws *wsi, unsigned char *buf, int len) wsi->a.vhost->conn_stats.rx += n; #endif - // lwsl_hexdump_err(buf, n); - #if defined(LWS_WITH_DETAILED_LATENCY) if (context->detailed_latency_cb) { wsi->detlat.req_size = len; @@ -351,8 +358,15 @@ lws_ssl_capable_write(struct lws *wsi, unsigned char *buf, int len) { int n, m; - // lwsl_notice("%s: len %d\n", __func__, len); - // lwsl_hexdump_notice(buf, len); +#if 0 + /* + * If using OpenSSL type tls library, this is the last point for all + * paths before sending data into the tls tunnel, where you can dump it + * and see what is being sent. + */ + lwsl_notice("%s: len %d\n", __func__, len); + lwsl_hexdump_notice(buf, len); +#endif if (!wsi->tls.ssl) return lws_ssl_capable_write_no_ssl(wsi, buf, len);