luo980/curl
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

lib: add trace support for client reads and writes

Browse Source 
- add `CURL_TRC_READ()` and `CURL_TRC_WRITE()`
- use in generic client writers and readers, as well
  as http headers, chunking and websockets

Closes #13223
This commit is contained in:
Stefan Eissing 2024-03-28 14:12:54 +01:00 committed by Daniel Stenberg
parent f46385d36d
commit 0b28ece657
No known key found for this signature in database
GPG Key ID: 5CC908FDB71E12C2
9 changed files with 188 additions and 51 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

10
docs/libcurl/curl_global_trace.md
View File

@ -68,7 +68,7 @@ that.
## `tcp` ## `tcp`
Tracing of TCP socket handling: connect, reads, writes. Tracing of TCP socket handling: connect, sends, receives.
## `ssl` ## `ssl`
@ -96,6 +96,14 @@ trace.
Tracing of DNS-over-HTTP operations to resolve hostnames. Tracing of DNS-over-HTTP operations to resolve hostnames.
## `read`
Traces reading of upload data from the application in order to send it to the server.
## `write`
Traces writing of download data, received from the server, to the application.
# EXAMPLE # EXAMPLE
~~~c ~~~c

58
lib/curl_trc.c
View File

@ -111,21 +111,30 @@ void Curl_failf(struct Curl_easy *data, const char *fmt, ...)
/* Curl_infof() is for info message along the way */ /* Curl_infof() is for info message along the way */
#define MAXINFO 2048 #define MAXINFO 2048
static void trc_infof(struct Curl_easy *data, struct curl_trc_feat *feat,
const char * const fmt, va_list ap) CURL_PRINTF(3, 0);
static void trc_infof(struct Curl_easy *data, struct curl_trc_feat *feat,
const char * const fmt, va_list ap)
{
int len = 0;
char buffer[MAXINFO + 2];
if(feat)
len = msnprintf(buffer, MAXINFO, "[%s] ", feat->name);
len += mvsnprintf(buffer + len, MAXINFO - len, fmt, ap);
buffer[len++] = '\n';
buffer[len] = '\0';
Curl_debug(data, CURLINFO_TEXT, buffer, len);
}
void Curl_infof(struct Curl_easy *data, const char *fmt, ...) void Curl_infof(struct Curl_easy *data, const char *fmt, ...)
{ {
DEBUGASSERT(!strchr(fmt, '\n')); DEBUGASSERT(!strchr(fmt, '\n'));
if(Curl_trc_is_verbose(data)) { if(Curl_trc_is_verbose(data)) {
va_list ap; va_list ap;
int len = 0;
char buffer[MAXINFO + 2];
if(data->state.feat)
len = msnprintf(buffer, MAXINFO, "[%s] ", data->state.feat->name);
va_start(ap, fmt); va_start(ap, fmt);
len += mvsnprintf(buffer + len, MAXINFO - len, fmt, ap); trc_infof(data, data->state.feat, fmt, ap);
va_end(ap); va_end(ap);
buffer[len++] = '\n';
buffer[len] = '\0';
Curl_debug(data, CURLINFO_TEXT, buffer, len);
} }
} }
@ -154,7 +163,40 @@ void Curl_trc_cf_infof(struct Curl_easy *data, struct Curl_cfilter *cf,
} }
} }
struct curl_trc_feat Curl_trc_feat_read = {
"READ",
CURL_LOG_LVL_NONE,
};
struct curl_trc_feat Curl_trc_feat_write = {
"WRITE",
CURL_LOG_LVL_NONE,
};
void Curl_trc_read(struct Curl_easy *data, const char *fmt, ...)
{
DEBUGASSERT(!strchr(fmt, '\n'));
if(Curl_trc_ft_is_verbose(data, &Curl_trc_feat_read)) {
va_list ap;
va_start(ap, fmt);
trc_infof(data, &Curl_trc_feat_read, fmt, ap);
va_end(ap);
}
}
void Curl_trc_write(struct Curl_easy *data, const char *fmt, ...)
{
DEBUGASSERT(!strchr(fmt, '\n'));
if(Curl_trc_ft_is_verbose(data, &Curl_trc_feat_write)) {
va_list ap;
va_start(ap, fmt);
trc_infof(data, &Curl_trc_feat_write, fmt, ap);
va_end(ap);
}
}
static struct curl_trc_feat *trc_feats[] = { static struct curl_trc_feat *trc_feats[] = {
&Curl_trc_feat_read,
&Curl_trc_feat_write,
#ifndef CURL_DISABLE_DOH #ifndef CURL_DISABLE_DOH
&Curl_doh_trc, &Curl_doh_trc,
#endif #endif

43
lib/curl_trc.h
View File

@ -77,10 +77,18 @@ void Curl_failf(struct Curl_easy *data,
#define CURL_TRC_CF(data, cf, ...) \ #define CURL_TRC_CF(data, cf, ...) \
do { if(Curl_trc_cf_is_verbose(cf, data)) \ do { if(Curl_trc_cf_is_verbose(cf, data)) \
Curl_trc_cf_infof(data, cf, __VA_ARGS__); } while(0) Curl_trc_cf_infof(data, cf, __VA_ARGS__); } while(0)
#define CURL_TRC_WRITE(data, ...) \
do { if(Curl_trc_ft_is_verbose(data, &Curl_trc_feat_write)) \
Curl_trc_write(data, __VA_ARGS__); } while(0)
#define CURL_TRC_READ(data, ...) \
do { if(Curl_trc_ft_is_verbose(data, &Curl_trc_feat_read)) \
Curl_trc_read(data, __VA_ARGS__); } while(0)
#else #else
#define infof Curl_infof #define infof Curl_infof
#define CURL_TRC_CF Curl_trc_cf_infof #define CURL_TRC_CF Curl_trc_cf_infof
#define CURL_TRC_WRITE Curl_trc_write
#define CURL_TRC_READ Curl_trc_read
#endif #endif
#ifndef CURL_DISABLE_VERBOSE_STRINGS #ifndef CURL_DISABLE_VERBOSE_STRINGS
@ -90,6 +98,8 @@ struct curl_trc_feat {
const char *name; const char *name;
int log_level; int log_level;
}; };
extern struct curl_trc_feat Curl_trc_feat_read;
extern struct curl_trc_feat Curl_trc_feat_write;
#define Curl_trc_is_verbose(data) \ #define Curl_trc_is_verbose(data) \
((data) && (data)->set.verbose && \ ((data) && (data)->set.verbose && \
@ -97,10 +107,10 @@ struct curl_trc_feat {
((data)->state.feat->log_level >= CURL_LOG_LVL_INFO))) ((data)->state.feat->log_level >= CURL_LOG_LVL_INFO)))
#define Curl_trc_cf_is_verbose(cf, data) \ #define Curl_trc_cf_is_verbose(cf, data) \
(Curl_trc_is_verbose(data) && \ (Curl_trc_is_verbose(data) && \
(cf) && (cf)->cft->log_level >= CURL_LOG_LVL_INFO) (cf) && (cf)->cft->log_level >= CURL_LOG_LVL_INFO)
#define Curl_trc_ft_is_verbose(data, ft) \ #define Curl_trc_ft_is_verbose(data, ft) \
(Curl_trc_is_verbose(data) && \ (Curl_trc_is_verbose(data) && \
(ft)->log_level >= CURL_LOG_LVL_INFO) (ft)->log_level >= CURL_LOG_LVL_INFO)
/** /**
* Output an informational message when transfer's verbose logging is enabled. * Output an informational message when transfer's verbose logging is enabled.
@ -114,6 +124,16 @@ void Curl_infof(struct Curl_easy *data,
*/ */
void Curl_trc_cf_infof(struct Curl_easy *data, struct Curl_cfilter *cf, void Curl_trc_cf_infof(struct Curl_easy *data, struct Curl_cfilter *cf,
const char *fmt, ...) CURL_PRINTF(3, 4); const char *fmt, ...) CURL_PRINTF(3, 4);
void Curl_trc_ft_infof(struct Curl_easy *data, struct curl_trc_feat *ft,
const char *fmt, ...) CURL_PRINTF(3, 4);
void Curl_trc_write(struct Curl_easy *data,
const char *fmt, ...) CURL_PRINTF(2, 3);
void Curl_trc_read(struct Curl_easy *data,
const char *fmt, ...) CURL_PRINTF(2, 3);
#else /* defined(CURL_DISABLE_VERBOSE_STRINGS) */ #else /* defined(CURL_DISABLE_VERBOSE_STRINGS) */
/* All informational messages are not compiled in for size savings */ /* All informational messages are not compiled in for size savings */
@ -134,6 +154,23 @@ static void Curl_trc_cf_infof(struct Curl_easy *data,
(void)data; (void)cf; (void)fmt; (void)data; (void)cf; (void)fmt;
} }
static void Curl_trc_ft_infof(struct Curl_easy *data,
struct curl_trc_feat *ft,
const char *fmt, ...)
{
(void)data; (void)ft; (void)fmt;
}
static void Curl_trc_write(struct Curl_easy *data, const char *fmt, ...)
{
(void)data; (void)fmt;
}
static void Curl_trc_read(struct Curl_easy *data, const char *fmt, ...)
{
(void)data; (void)fmt;
}
#endif /* !defined(CURL_DISABLE_VERBOSE_STRINGS) */ #endif /* !defined(CURL_DISABLE_VERBOSE_STRINGS) */
#endif /* HEADER_CURL_TRC_H */ #endif /* HEADER_CURL_TRC_H */

4
lib/cw-out.c
View File

@ -217,6 +217,9 @@ static CURLcode cw_out_ptr_flush(struct cw_out_ctx *ctx,
Curl_set_in_callback(data, TRUE); Curl_set_in_callback(data, TRUE);
nwritten = wcb((char *)buf, 1, wlen, wcb_data); nwritten = wcb((char *)buf, 1, wlen, wcb_data);
Curl_set_in_callback(data, FALSE); Curl_set_in_callback(data, FALSE);
CURL_TRC_WRITE(data, "cw_out, wrote %zu %s bytes -> %zu",
wlen, (otype == CW_OUT_BODY)? "body" : "header",
nwritten);
if(CURL_WRITEFUNC_PAUSE == nwritten) { if(CURL_WRITEFUNC_PAUSE == nwritten) {
if(data->conn && data->conn->handler->flags & PROTOPT_NONETWORK) { if(data->conn && data->conn->handler->flags & PROTOPT_NONETWORK) {
/* Protocols that work without network cannot be paused. This is /* Protocols that work without network cannot be paused. This is
@ -227,6 +230,7 @@ static CURLcode cw_out_ptr_flush(struct cw_out_ctx *ctx,
} }
/* mark the connection as RECV paused */ /* mark the connection as RECV paused */
data->req.keepon |= KEEP_RECV_PAUSE; data->req.keepon |= KEEP_RECV_PAUSE;
CURL_TRC_WRITE(data, "cw_out, PAUSE requested by client");
break; break;
} }
if(nwritten != wlen) { if(nwritten != wlen) {

2
lib/headers.c
View File

@ -361,6 +361,8 @@ static CURLcode hds_cw_collect_write(struct Curl_easy *data,
(type & CLIENTWRITE_TRAILER ? CURLH_TRAILER : (type & CLIENTWRITE_TRAILER ? CURLH_TRAILER :
CURLH_HEADER))); CURLH_HEADER)));
CURLcode result = Curl_headers_push(data, buf, htype); CURLcode result = Curl_headers_push(data, buf, htype);
CURL_TRC_WRITE(data, "header_collect pushed(type=%x, len=%zu) -> %d",
htype, blen, result);
if(result) if(result)
return result; return result;
} }

17
lib/http_chunks.c
View File

@ -28,6 +28,7 @@
#include "urldata.h" /* it includes http_chunks.h */ #include "urldata.h" /* it includes http_chunks.h */
#include "curl_printf.h" #include "curl_printf.h"
#include "curl_trc.h"
#include "sendf.h" /* for the client write stuff */ #include "sendf.h" /* for the client write stuff */
#include "dynbuf.h" #include "dynbuf.h"
#include "content_encoding.h" #include "content_encoding.h"
@ -185,8 +186,11 @@ static CURLcode httpchunk_readwrite(struct Curl_easy *data,
if(0 == ch->datasize) { if(0 == ch->datasize) {
ch->state = CHUNK_TRAILER; /* now check for trailers */ ch->state = CHUNK_TRAILER; /* now check for trailers */
} }
else else {
ch->state = CHUNK_DATA; ch->state = CHUNK_DATA;
CURL_TRC_WRITE(data, "http_chunked, chunk start of %"
CURL_FORMAT_CURL_OFF_T " bytes", ch->datasize);
}
} }
buf++; buf++;
@ -221,6 +225,9 @@ static CURLcode httpchunk_readwrite(struct Curl_easy *data,
ch->datasize -= piece; /* decrease amount left to expect */ ch->datasize -= piece; /* decrease amount left to expect */
buf += piece; /* move read pointer forward */ buf += piece; /* move read pointer forward */
blen -= piece; /* decrease space left in this round */ blen -= piece; /* decrease space left in this round */
CURL_TRC_WRITE(data, "http_chunked, write %zu body bytes, %"
CURL_FORMAT_CURL_OFF_T " bytes in chunk remain",
piece, ch->datasize);
if(0 == ch->datasize) if(0 == ch->datasize)
/* end of data this round, we now expect a trailing CRLF */ /* end of data this round, we now expect a trailing CRLF */
@ -340,11 +347,14 @@ static CURLcode httpchunk_readwrite(struct Curl_easy *data,
even if there's no more chunks to read */ even if there's no more chunks to read */
ch->datasize = blen; ch->datasize = blen;
ch->state = CHUNK_DONE; ch->state = CHUNK_DONE;
CURL_TRC_WRITE(data, "http_chunk, response complete");
return CURLE_OK; return CURLE_OK;
} }
else { else {
ch->state = CHUNK_FAILED; ch->state = CHUNK_FAILED;
ch->last_code = CHUNKE_BAD_CHUNK; ch->last_code = CHUNKE_BAD_CHUNK;
CURL_TRC_WRITE(data, "http_chunk error, expected 0x0a, seeing 0x%ux",
(unsigned int)*buf);
return CURLE_RECV_ERROR; return CURLE_RECV_ERROR;
} }
case CHUNK_DONE: case CHUNK_DONE:
@ -498,6 +508,7 @@ static CURLcode add_last_chunk(struct Curl_easy *data,
int rc; int rc;
if(!data->set.trailer_callback) { if(!data->set.trailer_callback) {
CURL_TRC_READ(data, "http_chunk, added last, empty chunk");
return Curl_bufq_cwrite(&ctx->chunkbuf, STRCONST("0\r\n\r\n"), &n); return Curl_bufq_cwrite(&ctx->chunkbuf, STRCONST("0\r\n\r\n"), &n);
} }
@ -535,6 +546,8 @@ static CURLcode add_last_chunk(struct Curl_easy *data,
out: out:
curl_slist_free_all(trailers); curl_slist_free_all(trailers);
CURL_TRC_READ(data, "http_chunk, added last chunk with trailers "
"from client -> %d", result);
return result; return result;
} }
@ -581,6 +594,8 @@ static CURLcode add_chunk(struct Curl_easy *data,
result = Curl_bufq_cwrite(&ctx->chunkbuf, buf, nread, &n); result = Curl_bufq_cwrite(&ctx->chunkbuf, buf, nread, &n);
if(!result) if(!result)
result = Curl_bufq_cwrite(&ctx->chunkbuf, "\r\n", 2, &n); result = Curl_bufq_cwrite(&ctx->chunkbuf, "\r\n", 2, &n);
CURL_TRC_READ(data, "http_chunk, made chunk of %zu bytes -> %d",
nread, result);
if(result) if(result)
return result; return result;
} }

70
lib/sendf.c
View File

@ -88,7 +88,10 @@ CURLcode Curl_client_write(struct Curl_easy *data,
DEBUGASSERT(data->req.writer_stack); DEBUGASSERT(data->req.writer_stack);
} }
return Curl_cwriter_write(data, data->req.writer_stack, type, buf, blen); result = Curl_cwriter_write(data, data->req.writer_stack, type, buf, blen);
CURL_TRC_WRITE(data, "client_write(type=%x, len=%zu) -> %d",
type, blen, result);
return result;
} }
static void cl_reset_writer(struct Curl_easy *data) static void cl_reset_writer(struct Curl_easy *data)
@ -115,7 +118,6 @@ static void cl_reset_reader(struct Curl_easy *data)
void Curl_client_cleanup(struct Curl_easy *data) void Curl_client_cleanup(struct Curl_easy *data)
{ {
DEBUGF(infof(data, "Curl_client_cleanup()"));
cl_reset_reader(data); cl_reset_reader(data);
cl_reset_writer(data); cl_reset_writer(data);
@ -127,10 +129,10 @@ void Curl_client_reset(struct Curl_easy *data)
{ {
if(data->req.rewind_read) { if(data->req.rewind_read) {
/* already requested */ /* already requested */
DEBUGF(infof(data, "Curl_client_reset(), will rewind_read")); CURL_TRC_READ(data, "client_reset, will rewind reader");
} }
else { else {
DEBUGF(infof(data, "Curl_client_reset(), clear readers")); CURL_TRC_READ(data, "client_reset, clear readers");
cl_reset_reader(data); cl_reset_reader(data);
} }
cl_reset_writer(data); cl_reset_writer(data);
@ -145,7 +147,7 @@ CURLcode Curl_client_start(struct Curl_easy *data)
struct Curl_creader *r = data->req.reader_stack; struct Curl_creader *r = data->req.reader_stack;
CURLcode result = CURLE_OK; CURLcode result = CURLE_OK;
DEBUGF(infof(data, "client start, rewind readers")); CURL_TRC_READ(data, "client start, rewind readers");
while(r) { while(r) {
result = r->crt->rewind(data, r); result = r->crt->rewind(data, r);
if(result) { if(result) {
@ -249,7 +251,10 @@ static CURLcode cw_download_write(struct Curl_easy *data,
if(!(type & CLIENTWRITE_BODY)) { if(!(type & CLIENTWRITE_BODY)) {
if(is_connect && data->set.suppress_connect_headers) if(is_connect && data->set.suppress_connect_headers)
return CURLE_OK; return CURLE_OK;
return Curl_cwriter_write(data, writer->next, type, buf, nbytes); result = Curl_cwriter_write(data, writer->next, type, buf, nbytes);
CURL_TRC_WRITE(data, "download_write header(type=%x, blen=%zu) -> %d",
type, nbytes, result);
return result;
} }
/* Here, we deal with REAL BODY bytes. All filtering and transfer /* Here, we deal with REAL BODY bytes. All filtering and transfer
@ -261,8 +266,8 @@ static CURLcode cw_download_write(struct Curl_easy *data,
if(data->req.no_body && nbytes > 0) { if(data->req.no_body && nbytes > 0) {
/* BODY arrives although we want none, bail out */ /* BODY arrives although we want none, bail out */
streamclose(data->conn, "ignoring body"); streamclose(data->conn, "ignoring body");
DEBUGF(infof(data, "did not want a BODY, but seeing %zu bytes", CURL_TRC_WRITE(data, "download_write body(type=%x, blen=%zu), "
nbytes)); "did not want a BODY", type, nbytes);
data->req.download_done = TRUE; data->req.download_done = TRUE;
if(data->info.header_size) if(data->info.header_size)
/* if headers have been received, this is fine */ /* if headers have been received, this is fine */
@ -298,6 +303,8 @@ static CURLcode cw_download_write(struct Curl_easy *data,
if(!data->req.ignorebody && (nwrite || (type & CLIENTWRITE_EOS))) { if(!data->req.ignorebody && (nwrite || (type & CLIENTWRITE_EOS))) {
result = Curl_cwriter_write(data, writer->next, type, buf, nwrite); result = Curl_cwriter_write(data, writer->next, type, buf, nwrite);
CURL_TRC_WRITE(data, "download_write body(type=%x, blen=%zu) -> %d",
type, nbytes, result);
if(result) if(result)
return result; return result;
} }
@ -333,7 +340,7 @@ static CURLcode cw_download_write(struct Curl_easy *data,
} }
static const struct Curl_cwtype cw_download = { static const struct Curl_cwtype cw_download = {
"download", "protocol",
NULL, NULL,
Curl_cwriter_def_init, Curl_cwriter_def_init,
cw_download_write, cw_download_write,
@ -698,9 +705,10 @@ static CURLcode cr_in_read(struct Curl_easy *data,
*peos = ctx->seen_eos; *peos = ctx->seen_eos;
break; break;
} }
DEBUGF(infof(data, "cr_in_read(len=%zu, total=%"CURL_FORMAT_CURL_OFF_T CURL_TRC_READ(data, "cr_in_read(len=%zu, total=%"CURL_FORMAT_CURL_OFF_T
", read=%"CURL_FORMAT_CURL_OFF_T") -> %d, %zu, %d", ", read=%"CURL_FORMAT_CURL_OFF_T") -> %d, nread=%zu, eos=%d",
blen, ctx->total_len, ctx->read_len, CURLE_OK, *pnread, *peos)); blen, ctx->total_len, ctx->read_len, CURLE_OK,
*pnread, *peos);
return CURLE_OK; return CURLE_OK;
} }
@ -798,7 +806,7 @@ static CURLcode cr_in_rewind(struct Curl_easy *data,
Curl_set_in_callback(data, true); Curl_set_in_callback(data, true);
err = (data->set.seek_func)(data->set.seek_client, 0, SEEK_SET); err = (data->set.seek_func)(data->set.seek_client, 0, SEEK_SET);
Curl_set_in_callback(data, false); Curl_set_in_callback(data, false);
DEBUGF(infof(data, "cr_in, rewind via set.seek_func -> %d", err)); CURL_TRC_READ(data, "cr_in, rewind via set.seek_func -> %d", err);
if(err) { if(err) {
failf(data, "seek callback returned error %d", (int)err); failf(data, "seek callback returned error %d", (int)err);
return CURLE_SEND_FAIL_REWIND; return CURLE_SEND_FAIL_REWIND;
@ -811,7 +819,7 @@ static CURLcode cr_in_rewind(struct Curl_easy *data,
err = (data->set.ioctl_func)(data, CURLIOCMD_RESTARTREAD, err = (data->set.ioctl_func)(data, CURLIOCMD_RESTARTREAD,
data->set.ioctl_client); data->set.ioctl_client);
Curl_set_in_callback(data, false); Curl_set_in_callback(data, false);
DEBUGF(infof(data, "cr_in, rewind via set.ioctl_func -> %d", (int)err)); CURL_TRC_READ(data, "cr_in, rewind via set.ioctl_func -> %d", (int)err);
if(err) { if(err) {
failf(data, "ioctl callback returned error %d", (int)err); failf(data, "ioctl callback returned error %d", (int)err);
return CURLE_SEND_FAIL_REWIND; return CURLE_SEND_FAIL_REWIND;
@ -823,8 +831,8 @@ static CURLcode cr_in_rewind(struct Curl_easy *data,
ourselves with fseek() */ ourselves with fseek() */
if(data->state.fread_func == (curl_read_callback)fread) { if(data->state.fread_func == (curl_read_callback)fread) {
int err = fseek(data->state.in, 0, SEEK_SET); int err = fseek(data->state.in, 0, SEEK_SET);
DEBUGF(infof(data, "cr_in, rewind via fseek -> %d(%d)", CURL_TRC_READ(data, "cr_in, rewind via fseek -> %d(%d)",
(int)err, (int)errno)); (int)err, (int)errno);
if(-1 != err) if(-1 != err)
/* successful rewind */ /* successful rewind */
return CURLE_OK; return CURLE_OK;
@ -945,7 +953,8 @@ static CURLcode cr_lc_read(struct Curl_easy *data,
ctx->eos = TRUE; ctx->eos = TRUE;
*pnread = nread; *pnread = nread;
*peos = ctx->eos; *peos = ctx->eos;
return CURLE_OK; result = CURLE_OK;
goto out;
} }
/* at least one \n needs conversion to '\r\n', place into ctx->buf */ /* at least one \n needs conversion to '\r\n', place into ctx->buf */
@ -977,6 +986,10 @@ static CURLcode cr_lc_read(struct Curl_easy *data,
ctx->eos = TRUE; ctx->eos = TRUE;
*peos = TRUE; *peos = TRUE;
} }
out:
CURL_TRC_READ(data, "cr_lc_read(len=%zu) -> %d, nread=%zu, eos=%d",
blen, result, *pnread, *peos);
return result; return result;
} }
@ -1054,12 +1067,16 @@ CURLcode Curl_creader_set_fread(struct Curl_easy *data, curl_off_t len)
result = Curl_creader_create(&r, data, &cr_in, CURL_CR_CLIENT); result = Curl_creader_create(&r, data, &cr_in, CURL_CR_CLIENT);
if(result) if(result)
return result; goto out;
ctx = r->ctx; ctx = r->ctx;
ctx->total_len = len; ctx->total_len = len;
cl_reset_reader(data); cl_reset_reader(data);
return do_init_reader_stack(data, r); result = do_init_reader_stack(data, r);
out:
CURL_TRC_READ(data, "add fread reader, len=%"CURL_FORMAT_CURL_OFF_T
" -> %d", len, result);
return result;
} }
CURLcode Curl_creader_add(struct Curl_easy *data, CURLcode Curl_creader_add(struct Curl_easy *data,
@ -1117,6 +1134,8 @@ CURLcode Curl_client_read(struct Curl_easy *data, char *buf, size_t blen,
result = Curl_creader_read(data, data->req.reader_stack, buf, blen, result = Curl_creader_read(data, data->req.reader_stack, buf, blen,
nread, eos); nread, eos);
CURL_TRC_READ(data, "client_read(len=%zu) -> %d, nread=%zu, eos=%d",
blen, result, *nread, *eos);
return result; return result;
} }
@ -1124,8 +1143,10 @@ bool Curl_creader_needs_rewind(struct Curl_easy *data)
{ {
struct Curl_creader *reader = data->req.reader_stack; struct Curl_creader *reader = data->req.reader_stack;
while(reader) { while(reader) {
if(reader->crt->needs_rewind(data, reader)) if(reader->crt->needs_rewind(data, reader)) {
CURL_TRC_READ(data, "client reader needs rewind before next request");
return TRUE; return TRUE;
}
reader = reader->next; reader = reader->next;
} }
return FALSE; return FALSE;
@ -1209,6 +1230,8 @@ static CURLcode cr_buf_read(struct Curl_easy *data,
ctx->index += nread; ctx->index += nread;
*peos = (ctx->index == ctx->blen); *peos = (ctx->index == ctx->blen);
} }
CURL_TRC_READ(data, "cr_buf_read(len=%zu) -> 0, nread=%zu, eos=%d",
blen, *pnread, *peos);
return CURLE_OK; return CURLE_OK;
} }
@ -1274,14 +1297,17 @@ CURLcode Curl_creader_set_buf(struct Curl_easy *data,
result = Curl_creader_create(&r, data, &cr_buf, CURL_CR_CLIENT); result = Curl_creader_create(&r, data, &cr_buf, CURL_CR_CLIENT);
if(result) if(result)
return result; goto out;
ctx = r->ctx; ctx = r->ctx;
ctx->buf = buf; ctx->buf = buf;
ctx->blen = blen; ctx->blen = blen;
ctx->index = 0; ctx->index = 0;
cl_reset_reader(data); cl_reset_reader(data);
return do_init_reader_stack(data, r); result = do_init_reader_stack(data, r);
out:
CURL_TRC_READ(data, "add buf reader, len=%zu -> %d", blen, result);
return result;
} }
curl_off_t Curl_creader_total_length(struct Curl_easy *data) curl_off_t Curl_creader_total_length(struct Curl_easy *data)

2
lib/transfer.c
View File

@ -1190,6 +1190,8 @@ CURLcode Curl_xfer_write_resp(struct Curl_easy *data,
data->req.eos_written = TRUE; data->req.eos_written = TRUE;
data->req.download_done = TRUE; data->req.download_done = TRUE;
} }
CURL_TRC_WRITE(data, "xfer_write_resp(len=%zu, eos=%d) -> %d",
blen, is_eos, result);
return result; return result;
} }

33
lib/ws.c
View File

@ -114,23 +114,23 @@ static void ws_dec_info(struct ws_decoder *dec, struct Curl_easy *data,
case 0: case 0:
break; break;
case 1: case 1:
infof(data, "WS-DEC: %s [%s%s]", msg, CURL_TRC_WRITE(data, "websocket, decoded %s [%s%s]", msg,
ws_frame_name_of_op(dec->head[0]), ws_frame_name_of_op(dec->head[0]),
(dec->head[0] & WSBIT_FIN)? "" : " NON-FINAL"); (dec->head[0] & WSBIT_FIN)? "" : " NON-FINAL");
break; break;
default: default:
if(dec->head_len < dec->head_total) { if(dec->head_len < dec->head_total) {
infof(data, "WS-DEC: %s [%s%s](%d/%d)", msg, CURL_TRC_WRITE(data, "websocket, decoded %s [%s%s](%d/%d)", msg,
ws_frame_name_of_op(dec->head[0]), ws_frame_name_of_op(dec->head[0]),
(dec->head[0] & WSBIT_FIN)? "" : " NON-FINAL", (dec->head[0] & WSBIT_FIN)? "" : " NON-FINAL",
dec->head_len, dec->head_total); dec->head_len, dec->head_total);
} }
else { else {
infof(data, "WS-DEC: %s [%s%s payload=%" CURL_FORMAT_CURL_OFF_T CURL_TRC_WRITE(data, "websocket, decoded %s [%s%s payload=%"
"/%" CURL_FORMAT_CURL_OFF_T "]", CURL_FORMAT_CURL_OFF_T "/%" CURL_FORMAT_CURL_OFF_T "]",
msg, ws_frame_name_of_op(dec->head[0]), msg, ws_frame_name_of_op(dec->head[0]),
(dec->head[0] & WSBIT_FIN)? "" : " NON-FINAL", (dec->head[0] & WSBIT_FIN)? "" : " NON-FINAL",
dec->payload_offset, dec->payload_len); dec->payload_offset, dec->payload_len);
} }
break; break;
} }
@ -277,9 +277,8 @@ static CURLcode ws_dec_pass_payload(struct ws_decoder *dec,
Curl_bufq_skip(inraw, (size_t)nwritten); Curl_bufq_skip(inraw, (size_t)nwritten);
dec->payload_offset += (curl_off_t)nwritten; dec->payload_offset += (curl_off_t)nwritten;
remain = dec->payload_len - dec->payload_offset; remain = dec->payload_len - dec->payload_offset;
/* infof(data, "WS-DEC: passed %zd bytes payload, %" CURL_TRC_WRITE(data, "websocket, passed %zd bytes payload, %"
CURL_FORMAT_CURL_OFF_T " remain", CURL_FORMAT_CURL_OFF_T " remain", nwritten, remain);
nwritten, remain); */
} }
return remain? CURLE_AGAIN : CURLE_OK; return remain? CURLE_AGAIN : CURLE_OK;
@ -454,10 +453,12 @@ static CURLcode ws_cw_write(struct Curl_easy *data,
pass_ctx.cw_type = type; pass_ctx.cw_type = type;
result = ws_dec_pass(&ws->dec, data, &ctx->buf, result = ws_dec_pass(&ws->dec, data, &ctx->buf,
ws_cw_dec_next, &pass_ctx); ws_cw_dec_next, &pass_ctx);
if(result == CURLE_AGAIN) if(result == CURLE_AGAIN) {
/* insufficient amount of data, keep it for later. /* insufficient amount of data, keep it for later.
* we pretend to have written all since we have a copy */ * we pretend to have written all since we have a copy */
CURL_TRC_WRITE(data, "websocket, buffered incomplete frame head");
return CURLE_OK; return CURLE_OK;
}
else if(result) { else if(result) {
infof(data, "WS: decode error %d", (int)result); infof(data, "WS: decode error %d", (int)result);
return result; return result;