summaryrefslogtreecommitdiff
path: root/libs/libcurl/src/cf-h2-proxy.c
diff options
context:
space:
mode:
Diffstat (limited to 'libs/libcurl/src/cf-h2-proxy.c')
-rw-r--r--libs/libcurl/src/cf-h2-proxy.c374
1 files changed, 252 insertions, 122 deletions
diff --git a/libs/libcurl/src/cf-h2-proxy.c b/libs/libcurl/src/cf-h2-proxy.c
index 5248660fc8..c18e1e0cf7 100644
--- a/libs/libcurl/src/cf-h2-proxy.c
+++ b/libs/libcurl/src/cf-h2-proxy.c
@@ -30,11 +30,12 @@
#include "urldata.h"
#include "cfilters.h"
#include "connect.h"
-#include "curl_log.h"
+#include "curl_trc.h"
#include "bufq.h"
#include "dynbuf.h"
#include "dynhds.h"
#include "http1.h"
+#include "http2.h"
#include "http_proxy.h"
#include "multiif.h"
#include "cf-h2-proxy.h"
@@ -44,16 +45,16 @@
#include "curl_memory.h"
#include "memdebug.h"
-#define H2_CHUNK_SIZE (16*1024)
+#define PROXY_H2_CHUNK_SIZE (16*1024)
#define PROXY_HTTP2_HUGE_WINDOW_SIZE (100 * 1024 * 1024)
#define H2_TUNNEL_WINDOW_SIZE (10 * 1024 * 1024)
-#define PROXY_H2_NW_RECV_CHUNKS (H2_TUNNEL_WINDOW_SIZE / H2_CHUNK_SIZE)
+#define PROXY_H2_NW_RECV_CHUNKS (H2_TUNNEL_WINDOW_SIZE / PROXY_H2_CHUNK_SIZE)
#define PROXY_H2_NW_SEND_CHUNKS 1
-#define H2_TUNNEL_RECV_CHUNKS (H2_TUNNEL_WINDOW_SIZE / H2_CHUNK_SIZE)
-#define H2_TUNNEL_SEND_CHUNKS ((128 * 1024) / H2_CHUNK_SIZE)
+#define H2_TUNNEL_RECV_CHUNKS (H2_TUNNEL_WINDOW_SIZE / PROXY_H2_CHUNK_SIZE)
+#define H2_TUNNEL_SEND_CHUNKS ((128 * 1024) / PROXY_H2_CHUNK_SIZE)
typedef enum {
@@ -87,9 +88,9 @@ static CURLcode tunnel_stream_init(struct Curl_cfilter *cf,
ts->state = H2_TUNNEL_INIT;
ts->stream_id = -1;
- Curl_bufq_init2(&ts->recvbuf, H2_CHUNK_SIZE, H2_TUNNEL_RECV_CHUNKS,
+ Curl_bufq_init2(&ts->recvbuf, PROXY_H2_CHUNK_SIZE, H2_TUNNEL_RECV_CHUNKS,
BUFQ_OPT_SOFT_LIMIT);
- Curl_bufq_init(&ts->sendbuf, H2_CHUNK_SIZE, H2_TUNNEL_SEND_CHUNKS);
+ Curl_bufq_init(&ts->sendbuf, PROXY_H2_CHUNK_SIZE, H2_TUNNEL_SEND_CHUNKS);
if(cf->conn->bits.conn_to_host)
hostname = cf->conn->conn_to_host.name;
@@ -146,29 +147,30 @@ static void h2_tunnel_go_state(struct Curl_cfilter *cf,
/* entering this one */
switch(new_state) {
case H2_TUNNEL_INIT:
- DEBUGF(LOG_CF(data, cf, "new tunnel state 'init'"));
+ CURL_TRC_CF(data, cf, "[%d] new tunnel state 'init'", ts->stream_id);
tunnel_stream_clear(ts);
break;
case H2_TUNNEL_CONNECT:
- DEBUGF(LOG_CF(data, cf, "new tunnel state 'connect'"));
+ CURL_TRC_CF(data, cf, "[%d] new tunnel state 'connect'", ts->stream_id);
ts->state = H2_TUNNEL_CONNECT;
break;
case H2_TUNNEL_RESPONSE:
- DEBUGF(LOG_CF(data, cf, "new tunnel state 'response'"));
+ CURL_TRC_CF(data, cf, "[%d] new tunnel state 'response'", ts->stream_id);
ts->state = H2_TUNNEL_RESPONSE;
break;
case H2_TUNNEL_ESTABLISHED:
- DEBUGF(LOG_CF(data, cf, "new tunnel state 'established'"));
+ CURL_TRC_CF(data, cf, "[%d] new tunnel state 'established'",
+ ts->stream_id);
infof(data, "CONNECT phase completed");
data->state.authproxy.done = TRUE;
data->state.authproxy.multipass = FALSE;
/* FALLTHROUGH */
case H2_TUNNEL_FAILED:
if(new_state == H2_TUNNEL_FAILED)
- DEBUGF(LOG_CF(data, cf, "new tunnel state 'failed'"));
+ CURL_TRC_CF(data, cf, "[%d] new tunnel state 'failed'", ts->stream_id);
ts->state = new_state;
/* If a proxy-authorization header was used for the proxy, then we should
make sure that it isn't accidentally used for the document request
@@ -231,9 +233,9 @@ static void drain_tunnel(struct Curl_cfilter *cf,
bits = CURL_CSELECT_IN;
if(!tunnel->closed && !tunnel->reset && tunnel->upload_blocked_len)
bits |= CURL_CSELECT_OUT;
- if(data->state.dselect_bits != bits) {
- DEBUGF(LOG_CF(data, cf, "[h2sid=%d] DRAIN dselect_bits=%x",
- tunnel->stream_id, bits));
+ if(data->state.dselect_bits != bits || 1) {
+ CURL_TRC_CF(data, cf, "[%d] DRAIN dselect_bits=%x",
+ tunnel->stream_id, bits);
data->state.dselect_bits = bits;
Curl_expire(data, 0, EXPIRE_RUN_NOW);
}
@@ -244,12 +246,17 @@ static ssize_t proxy_nw_in_reader(void *reader_ctx,
CURLcode *err)
{
struct Curl_cfilter *cf = reader_ctx;
- struct Curl_easy *data = CF_DATA_CURRENT(cf);
ssize_t nread;
- nread = Curl_conn_cf_recv(cf->next, data, (char *)buf, buflen, err);
- DEBUGF(LOG_CF(data, cf, "nw_in_reader(len=%zu) -> %zd, %d",
- buflen, nread, *err));
+ if(cf) {
+ struct Curl_easy *data = CF_DATA_CURRENT(cf);
+ nread = Curl_conn_cf_recv(cf->next, data, (char *)buf, buflen, err);
+ CURL_TRC_CF(data, cf, "[0] nw_in_reader(len=%zu) -> %zd, %d",
+ buflen, nread, *err);
+ }
+ else {
+ nread = 0;
+ }
return nread;
}
@@ -258,12 +265,18 @@ static ssize_t proxy_h2_nw_out_writer(void *writer_ctx,
CURLcode *err)
{
struct Curl_cfilter *cf = writer_ctx;
- struct Curl_easy *data = CF_DATA_CURRENT(cf);
ssize_t nwritten;
- nwritten = Curl_conn_cf_send(cf->next, data, (const char *)buf, buflen, err);
- DEBUGF(LOG_CF(data, cf, "nw_out_writer(len=%zu) -> %zd, %d",
- buflen, nwritten, *err));
+ if(cf) {
+ struct Curl_easy *data = CF_DATA_CURRENT(cf);
+ nwritten = Curl_conn_cf_send(cf->next, data, (const char *)buf, buflen,
+ err);
+ CURL_TRC_CF(data, cf, "[0] nw_out_writer(len=%zu) -> %zd, %d",
+ buflen, nwritten, *err);
+ }
+ else {
+ nwritten = 0;
+ }
return nwritten;
}
@@ -295,6 +308,10 @@ static ssize_t on_session_send(nghttp2_session *h2,
static int proxy_h2_on_frame_recv(nghttp2_session *session,
const nghttp2_frame *frame,
void *userp);
+#ifndef CURL_DISABLE_VERBOSE_STRINGS
+static int on_frame_send(nghttp2_session *session, const nghttp2_frame *frame,
+ void *userp);
+#endif
static int proxy_h2_on_stream_close(nghttp2_session *session,
int32_t stream_id,
uint32_t error_code, void *userp);
@@ -322,8 +339,8 @@ static CURLcode cf_h2_proxy_ctx_init(struct Curl_cfilter *cf,
DEBUGASSERT(!ctx->h2);
memset(&ctx->tunnel, 0, sizeof(ctx->tunnel));
- Curl_bufq_init(&ctx->inbufq, H2_CHUNK_SIZE, PROXY_H2_NW_RECV_CHUNKS);
- Curl_bufq_init(&ctx->outbufq, H2_CHUNK_SIZE, PROXY_H2_NW_SEND_CHUNKS);
+ Curl_bufq_init(&ctx->inbufq, PROXY_H2_CHUNK_SIZE, PROXY_H2_NW_RECV_CHUNKS);
+ Curl_bufq_init(&ctx->outbufq, PROXY_H2_CHUNK_SIZE, PROXY_H2_NW_SEND_CHUNKS);
if(tunnel_stream_init(cf, &ctx->tunnel))
goto out;
@@ -337,6 +354,9 @@ static CURLcode cf_h2_proxy_ctx_init(struct Curl_cfilter *cf,
nghttp2_session_callbacks_set_send_callback(cbs, on_session_send);
nghttp2_session_callbacks_set_on_frame_recv_callback(
cbs, proxy_h2_on_frame_recv);
+#ifndef CURL_DISABLE_VERBOSE_STRINGS
+ nghttp2_session_callbacks_set_on_frame_send_callback(cbs, on_frame_send);
+#endif
nghttp2_session_callbacks_set_on_data_chunk_recv_callback(
cbs, tunnel_recv_callback);
nghttp2_session_callbacks_set_on_stream_close_callback(
@@ -384,11 +404,11 @@ static CURLcode cf_h2_proxy_ctx_init(struct Curl_cfilter *cf,
out:
if(cbs)
nghttp2_session_callbacks_del(cbs);
- DEBUGF(LOG_CF(data, cf, "init proxy ctx -> %d", result));
+ CURL_TRC_CF(data, cf, "[0] init proxy ctx -> %d", result);
return result;
}
-static int should_close_session(struct cf_h2_proxy_ctx *ctx)
+static int proxy_h2_should_close_session(struct cf_h2_proxy_ctx *ctx)
{
return !nghttp2_session_want_read(ctx->h2) &&
!nghttp2_session_want_write(ctx->h2);
@@ -409,13 +429,13 @@ static CURLcode proxy_h2_nw_out_flush(struct Curl_cfilter *cf,
&result);
if(nwritten < 0) {
if(result == CURLE_AGAIN) {
- DEBUGF(LOG_CF(data, cf, "flush nw send buffer(%zu) -> EAGAIN",
- Curl_bufq_len(&ctx->outbufq)));
+ CURL_TRC_CF(data, cf, "[0] flush nw send buffer(%zu) -> EAGAIN",
+ Curl_bufq_len(&ctx->outbufq));
ctx->nw_out_blocked = 1;
}
return result;
}
- DEBUGF(LOG_CF(data, cf, "nw send buffer flushed"));
+ CURL_TRC_CF(data, cf, "[0] nw send buffer flushed");
return Curl_bufq_is_empty(&ctx->outbufq)? CURLE_OK: CURLE_AGAIN;
}
@@ -436,8 +456,7 @@ static int proxy_h2_process_pending_input(struct Curl_cfilter *cf,
while(Curl_bufq_peek(&ctx->inbufq, &buf, &blen)) {
rv = nghttp2_session_mem_recv(ctx->h2, (const uint8_t *)buf, blen);
- DEBUGF(LOG_CF(data, cf,
- "fed %zu bytes from nw to nghttp2 -> %zd", blen, rv));
+ CURL_TRC_CF(data, cf, "[0] %zu bytes to nghttp2 -> %zd", blen, rv);
if(rv < 0) {
failf(data,
"process_pending_input: nghttp2_session_mem_recv() returned "
@@ -447,12 +466,12 @@ static int proxy_h2_process_pending_input(struct Curl_cfilter *cf,
}
Curl_bufq_skip(&ctx->inbufq, (size_t)rv);
if(Curl_bufq_is_empty(&ctx->inbufq)) {
- DEBUGF(LOG_CF(data, cf, "all data in connection buffer processed"));
+ CURL_TRC_CF(data, cf, "[0] all data in connection buffer processed");
break;
}
else {
- DEBUGF(LOG_CF(data, cf, "process_pending_input: %zu bytes left "
- "in connection buffer", Curl_bufq_len(&ctx->inbufq)));
+ CURL_TRC_CF(data, cf, "[0] process_pending_input: %zu bytes left "
+ "in connection buffer", Curl_bufq_len(&ctx->inbufq));
}
}
@@ -468,8 +487,8 @@ static CURLcode proxy_h2_progress_ingress(struct Curl_cfilter *cf,
/* Process network input buffer fist */
if(!Curl_bufq_is_empty(&ctx->inbufq)) {
- DEBUGF(LOG_CF(data, cf, "Process %zu bytes in connection buffer",
- Curl_bufq_len(&ctx->inbufq)));
+ CURL_TRC_CF(data, cf, "[0] process %zu bytes in connection buffer",
+ Curl_bufq_len(&ctx->inbufq));
if(proxy_h2_process_pending_input(cf, data, &result) < 0)
return result;
}
@@ -482,8 +501,8 @@ static CURLcode proxy_h2_progress_ingress(struct Curl_cfilter *cf,
!Curl_bufq_is_full(&ctx->tunnel.recvbuf)) {
nread = Curl_bufq_slurp(&ctx->inbufq, proxy_nw_in_reader, cf, &result);
- DEBUGF(LOG_CF(data, cf, "read %zu bytes nw data -> %zd, %d",
- Curl_bufq_len(&ctx->inbufq), nread, result));
+ CURL_TRC_CF(data, cf, "[0] read %zu bytes nw data -> %zd, %d",
+ Curl_bufq_len(&ctx->inbufq), nread, result);
if(nread < 0) {
if(result != CURLE_AGAIN) {
failf(data, "Failed receiving HTTP2 data");
@@ -518,8 +537,8 @@ static CURLcode proxy_h2_progress_egress(struct Curl_cfilter *cf,
rv = nghttp2_session_send(ctx->h2);
if(nghttp2_is_fatal(rv)) {
- DEBUGF(LOG_CF(data, cf, "nghttp2_session_send error (%s)%d",
- nghttp2_strerror(rv), rv));
+ CURL_TRC_CF(data, cf, "[0] nghttp2_session_send error (%s)%d",
+ nghttp2_strerror(rv), rv);
return CURLE_SEND_ERROR;
}
return proxy_h2_nw_out_flush(cf, data);
@@ -555,6 +574,97 @@ static ssize_t on_session_send(nghttp2_session *h2,
return nwritten;
}
+#ifndef CURL_DISABLE_VERBOSE_STRINGS
+static int fr_print(const nghttp2_frame *frame, char *buffer, size_t blen)
+{
+ switch(frame->hd.type) {
+ case NGHTTP2_DATA: {
+ return msnprintf(buffer, blen,
+ "FRAME[DATA, len=%d, eos=%d, padlen=%d]",
+ (int)frame->hd.length,
+ !!(frame->hd.flags & NGHTTP2_FLAG_END_STREAM),
+ (int)frame->data.padlen);
+ }
+ case NGHTTP2_HEADERS: {
+ return msnprintf(buffer, blen,
+ "FRAME[HEADERS, len=%d, hend=%d, eos=%d]",
+ (int)frame->hd.length,
+ !!(frame->hd.flags & NGHTTP2_FLAG_END_HEADERS),
+ !!(frame->hd.flags & NGHTTP2_FLAG_END_STREAM));
+ }
+ case NGHTTP2_PRIORITY: {
+ return msnprintf(buffer, blen,
+ "FRAME[PRIORITY, len=%d, flags=%d]",
+ (int)frame->hd.length, frame->hd.flags);
+ }
+ case NGHTTP2_RST_STREAM: {
+ return msnprintf(buffer, blen,
+ "FRAME[RST_STREAM, len=%d, flags=%d, error=%u]",
+ (int)frame->hd.length, frame->hd.flags,
+ frame->rst_stream.error_code);
+ }
+ case NGHTTP2_SETTINGS: {
+ if(frame->hd.flags & NGHTTP2_FLAG_ACK) {
+ return msnprintf(buffer, blen, "FRAME[SETTINGS, ack=1]");
+ }
+ return msnprintf(buffer, blen,
+ "FRAME[SETTINGS, len=%d]", (int)frame->hd.length);
+ }
+ case NGHTTP2_PUSH_PROMISE: {
+ return msnprintf(buffer, blen,
+ "FRAME[PUSH_PROMISE, len=%d, hend=%d]",
+ (int)frame->hd.length,
+ !!(frame->hd.flags & NGHTTP2_FLAG_END_HEADERS));
+ }
+ case NGHTTP2_PING: {
+ return msnprintf(buffer, blen,
+ "FRAME[PING, len=%d, ack=%d]",
+ (int)frame->hd.length,
+ frame->hd.flags&NGHTTP2_FLAG_ACK);
+ }
+ case NGHTTP2_GOAWAY: {
+ char scratch[128];
+ size_t s_len = sizeof(scratch)/sizeof(scratch[0]);
+ size_t len = (frame->goaway.opaque_data_len < s_len)?
+ frame->goaway.opaque_data_len : s_len-1;
+ if(len)
+ memcpy(scratch, frame->goaway.opaque_data, len);
+ scratch[len] = '\0';
+ return msnprintf(buffer, blen, "FRAME[GOAWAY, error=%d, reason='%s', "
+ "last_stream=%d]", frame->goaway.error_code,
+ scratch, frame->goaway.last_stream_id);
+ }
+ case NGHTTP2_WINDOW_UPDATE: {
+ return msnprintf(buffer, blen,
+ "FRAME[WINDOW_UPDATE, incr=%d]",
+ frame->window_update.window_size_increment);
+ }
+ default:
+ return msnprintf(buffer, blen, "FRAME[%d, len=%d, flags=%d]",
+ frame->hd.type, (int)frame->hd.length,
+ frame->hd.flags);
+ }
+}
+
+static int on_frame_send(nghttp2_session *session, const nghttp2_frame *frame,
+ void *userp)
+{
+ struct Curl_cfilter *cf = userp;
+ struct Curl_easy *data = CF_DATA_CURRENT(cf);
+
+ (void)session;
+ DEBUGASSERT(data);
+ if(data && Curl_trc_cf_is_verbose(cf, data)) {
+ char buffer[256];
+ int len;
+ len = fr_print(frame, buffer, sizeof(buffer)-1);
+ buffer[len] = 0;
+ CURL_TRC_CF(data, cf, "[%d] -> %s", frame->hd.stream_id, buffer);
+ }
+ return 0;
+}
+#endif /* !CURL_DISABLE_VERBOSE_STRINGS */
+
static int proxy_h2_on_frame_recv(nghttp2_session *session,
const nghttp2_frame *frame,
void *userp)
@@ -566,75 +676,74 @@ static int proxy_h2_on_frame_recv(nghttp2_session *session,
(void)session;
DEBUGASSERT(data);
+#ifndef CURL_DISABLE_VERBOSE_STRINGS
+ if(Curl_trc_cf_is_verbose(cf, data)) {
+ char buffer[256];
+ int len;
+ len = fr_print(frame, buffer, sizeof(buffer)-1);
+ buffer[len] = 0;
+ CURL_TRC_CF(data, cf, "[%d] <- %s",frame->hd.stream_id, buffer);
+ }
+#endif /* !CURL_DISABLE_VERBOSE_STRINGS */
+
if(!stream_id) {
/* stream ID zero is for connection-oriented stuff */
DEBUGASSERT(data);
switch(frame->hd.type) {
case NGHTTP2_SETTINGS:
- /* we do not do anything with this for now */
+ /* Since the initial stream window is 64K, a request might be on HOLD,
+ * due to exhaustion. The (initial) SETTINGS may announce a much larger
+ * window and *assume* that we treat this like a WINDOW_UPDATE. Some
+ * servers send an explicit WINDOW_UPDATE, but not all seem to do that.
+ * To be safe, we UNHOLD a stream in order not to stall. */
+ if((data->req.keepon & KEEP_SEND_HOLD) &&
+ (data->req.keepon & KEEP_SEND)) {
+ data->req.keepon &= ~KEEP_SEND_HOLD;
+ drain_tunnel(cf, data, &ctx->tunnel);
+ CURL_TRC_CF(data, cf, "[%d] un-holding after SETTINGS",
+ stream_id);
+ }
break;
case NGHTTP2_GOAWAY:
- infof(data, "recveived GOAWAY, error=%d, last_stream=%u",
- frame->goaway.error_code, frame->goaway.last_stream_id);
ctx->goaway = TRUE;
break;
- case NGHTTP2_WINDOW_UPDATE:
- DEBUGF(LOG_CF(data, cf, "recv frame WINDOW_UPDATE"));
- break;
default:
- DEBUGF(LOG_CF(data, cf, "recv frame %x on 0", frame->hd.type));
+ break;
}
return 0;
}
if(stream_id != ctx->tunnel.stream_id) {
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] rcvd FRAME not for tunnel",
- stream_id));
+ CURL_TRC_CF(data, cf, "[%d] rcvd FRAME not for tunnel", stream_id);
return NGHTTP2_ERR_CALLBACK_FAILURE;
}
switch(frame->hd.type) {
- case NGHTTP2_DATA:
- /* If body started on this stream, then receiving DATA is illegal. */
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] recv frame DATA", stream_id));
- break;
case NGHTTP2_HEADERS:
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] recv frame HEADERS", stream_id));
-
/* nghttp2 guarantees that :status is received, and we store it to
stream->status_code. Fuzzing has proven this can still be reached
without status code having been set. */
if(!ctx->tunnel.resp)
return NGHTTP2_ERR_CALLBACK_FAILURE;
/* Only final status code signals the end of header */
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] got http status: %d",
- stream_id, ctx->tunnel.resp->status));
+ CURL_TRC_CF(data, cf, "[%d] got http status: %d",
+ stream_id, ctx->tunnel.resp->status);
if(!ctx->tunnel.has_final_response) {
if(ctx->tunnel.resp->status / 100 != 1) {
ctx->tunnel.has_final_response = TRUE;
}
}
break;
- case NGHTTP2_PUSH_PROMISE:
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] recv PUSH_PROMISE", stream_id));
- return NGHTTP2_ERR_CALLBACK_FAILURE;
- case NGHTTP2_RST_STREAM:
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] recv RST", stream_id));
- ctx->tunnel.reset = TRUE;
- break;
case NGHTTP2_WINDOW_UPDATE:
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] recv WINDOW_UPDATE", stream_id));
if((data->req.keepon & KEEP_SEND_HOLD) &&
(data->req.keepon & KEEP_SEND)) {
data->req.keepon &= ~KEEP_SEND_HOLD;
Curl_expire(data, 0, EXPIRE_RUN_NOW);
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] unpausing after win update",
- stream_id));
+ CURL_TRC_CF(data, cf, "[%d] unpausing after win update",
+ stream_id);
}
break;
default:
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] recv frame %x",
- stream_id, frame->hd.type));
break;
}
return 0;
@@ -658,10 +767,9 @@ static int proxy_h2_on_header(nghttp2_session *session,
(void)session;
DEBUGASSERT(stream_id); /* should never be a zero stream ID here */
if(stream_id != ctx->tunnel.stream_id) {
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] header for non-tunnel stream: "
- "%.*s: %.*s", stream_id,
- (int)namelen, name,
- (int)valuelen, value));
+ CURL_TRC_CF(data, cf, "[%d] header for non-tunnel stream: "
+ "%.*s: %.*s", stream_id,
+ (int)namelen, name, (int)valuelen, value);
return NGHTTP2_ERR_CALLBACK_FAILURE;
}
@@ -689,8 +797,8 @@ static int proxy_h2_on_header(nghttp2_session *session,
return NGHTTP2_ERR_CALLBACK_FAILURE;
resp->prev = ctx->tunnel.resp;
ctx->tunnel.resp = resp;
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] status: HTTP/2 %03d",
- stream_id, ctx->tunnel.resp->status));
+ CURL_TRC_CF(data, cf, "[%d] status: HTTP/2 %03d",
+ stream_id, ctx->tunnel.resp->status);
return 0;
}
@@ -703,10 +811,8 @@ static int proxy_h2_on_header(nghttp2_session *session,
if(result)
return NGHTTP2_ERR_CALLBACK_FAILURE;
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] header: %.*s: %.*s",
- stream_id,
- (int)namelen, name,
- (int)valuelen, value));
+ CURL_TRC_CF(data, cf, "[%d] header: %.*s: %.*s",
+ stream_id, (int)namelen, name, (int)valuelen, value);
return 0; /* 0 is successful */
}
@@ -746,8 +852,8 @@ static ssize_t tunnel_send_callback(nghttp2_session *session,
if(ts->closed && Curl_bufq_is_empty(&ts->sendbuf))
*data_flags = NGHTTP2_DATA_FLAG_EOF;
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] tunnel_send_callback -> %zd",
- ts->stream_id, nread));
+ CURL_TRC_CF(data, cf, "[%d] tunnel_send_callback -> %zd",
+ ts->stream_id, nread);
return nread;
}
@@ -791,8 +897,8 @@ static int proxy_h2_on_stream_close(nghttp2_session *session,
if(stream_id != ctx->tunnel.stream_id)
return 0;
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] proxy_h2_on_stream_close, %s (err %d)",
- stream_id, nghttp2_http2_strerror(error_code), error_code));
+ CURL_TRC_CF(data, cf, "[%d] proxy_h2_on_stream_close, %s (err %d)",
+ stream_id, nghttp2_http2_strerror(error_code), error_code);
ctx->tunnel.closed = TRUE;
ctx->tunnel.error = error_code;
@@ -910,8 +1016,8 @@ static CURLcode submit_CONNECT(struct Curl_cfilter *cf,
result = proxy_h2_submit(&ts->stream_id, cf, data, ctx->h2, req,
NULL, ts, tunnel_send_callback, cf);
if(result) {
- DEBUGF(LOG_CF(data, cf, "send: nghttp2_submit_request error (%s)%u",
- nghttp2_strerror(ts->stream_id), ts->stream_id));
+ CURL_TRC_CF(data, cf, "[%d] send, nghttp2_submit_request error: %s",
+ ts->stream_id, nghttp2_strerror(ts->stream_id));
}
out:
@@ -945,8 +1051,8 @@ static CURLcode inspect_response(struct Curl_cfilter *cf,
}
if(auth_reply) {
- DEBUGF(LOG_CF(data, cf, "CONNECT: fwd auth header '%s'",
- auth_reply->value));
+ CURL_TRC_CF(data, cf, "[0] CONNECT: fwd auth header '%s'",
+ auth_reply->value);
result = Curl_http_input_auth(data, ts->resp->status == 407,
auth_reply->value);
if(result)
@@ -976,7 +1082,7 @@ static CURLcode H2_CONNECT(struct Curl_cfilter *cf,
switch(ts->state) {
case H2_TUNNEL_INIT:
/* Prepare the CONNECT request and make a first attempt to send. */
- DEBUGF(LOG_CF(data, cf, "CONNECT start for %s", ts->authority));
+ CURL_TRC_CF(data, cf, "[0] CONNECT start for %s", ts->authority);
result = submit_CONNECT(cf, data, ts);
if(result)
goto out;
@@ -1143,8 +1249,8 @@ static ssize_t h2_handle_tunnel_close(struct Curl_cfilter *cf,
ssize_t rv = 0;
if(ctx->tunnel.error == NGHTTP2_REFUSED_STREAM) {
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] REFUSED_STREAM, try again on a new "
- "connection", ctx->tunnel.stream_id));
+ CURL_TRC_CF(data, cf, "[%d] REFUSED_STREAM, try again on a new "
+ "connection", ctx->tunnel.stream_id);
connclose(cf->conn, "REFUSED_STREAM"); /* don't use this anymore */
*err = CURLE_RECV_ERROR; /* trigger Curl_retry_request() later */
return -1;
@@ -1164,7 +1270,8 @@ static ssize_t h2_handle_tunnel_close(struct Curl_cfilter *cf,
*err = CURLE_OK;
rv = 0;
- DEBUGF(LOG_CF(data, cf, "handle_tunnel_close -> %zd, %d", rv, *err));
+ CURL_TRC_CF(data, cf, "[%d] handle_tunnel_close -> %zd, %d",
+ ctx->tunnel.stream_id, rv, *err);
return rv;
}
@@ -1200,8 +1307,8 @@ static ssize_t tunnel_recv(struct Curl_cfilter *cf, struct Curl_easy *data,
}
out:
- DEBUGF(LOG_CF(data, cf, "tunnel_recv(len=%zu) -> %zd, %d",
- len, nread, *err));
+ CURL_TRC_CF(data, cf, "[%d] tunnel_recv(len=%zu) -> %zd, %d",
+ ctx->tunnel.stream_id, len, nread, *err);
return nread;
}
@@ -1229,13 +1336,22 @@ static ssize_t cf_h2_proxy_recv(struct Curl_cfilter *cf,
nread = tunnel_recv(cf, data, buf, len, err);
if(nread > 0) {
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] increase window by %zd",
- ctx->tunnel.stream_id, nread));
+ CURL_TRC_CF(data, cf, "[%d] increase window by %zd",
+ ctx->tunnel.stream_id, nread);
nghttp2_session_consume(ctx->h2, ctx->tunnel.stream_id, (size_t)nread);
}
result = proxy_h2_progress_egress(cf, data);
- if(result && result != CURLE_AGAIN) {
+ if(result == CURLE_AGAIN) {
+ /* pending data to send, need to be called again. Ideally, we'd
+ * monitor the socket for POLLOUT, but we might not be in SENDING
+ * transfer state any longer and are unable to make this happen.
+ */
+ CURL_TRC_CF(data, cf, "[%d] egress blocked, DRAIN",
+ ctx->tunnel.stream_id);
+ drain_tunnel(cf, data, &ctx->tunnel);
+ }
+ else if(result) {
*err = result;
nread = -1;
}
@@ -1247,8 +1363,8 @@ out:
* draining to avoid stalling when no socket events happen. */
drain_tunnel(cf, data, &ctx->tunnel);
}
- DEBUGF(LOG_CF(data, cf, "[h2sid=%u] cf_recv(len=%zu) -> %zd %d",
- ctx->tunnel.stream_id, len, nread, *err));
+ CURL_TRC_CF(data, cf, "[%d] cf_recv(len=%zu) -> %zd %d",
+ ctx->tunnel.stream_id, len, nread, *err);
CF_DATA_RESTORE(cf, save);
return nread;
}
@@ -1276,12 +1392,12 @@ static ssize_t cf_h2_proxy_send(struct Curl_cfilter *cf,
goto out;
}
else if(ctx->tunnel.upload_blocked_len) {
- /* the data in `buf` has alread been submitted or added to the
+ /* the data in `buf` has already been submitted or added to the
* buffers, but have been EAGAINed on the last invocation. */
DEBUGASSERT(len >= ctx->tunnel.upload_blocked_len);
if(len < ctx->tunnel.upload_blocked_len) {
/* Did we get called again with a smaller `len`? This should not
- * happend. We are not prepared to handle that. */
+ * happen. We are not prepared to handle that. */
failf(data, "HTTP/2 proxy, send again with decreased length");
*err = CURLE_HTTP2;
nwritten = -1;
@@ -1289,6 +1405,7 @@ static ssize_t cf_h2_proxy_send(struct Curl_cfilter *cf,
}
nwritten = (ssize_t)ctx->tunnel.upload_blocked_len;
ctx->tunnel.upload_blocked_len = 0;
+ *err = CURLE_OK;
}
else {
nwritten = Curl_bufq_write(&ctx->tunnel.sendbuf, buf, len, err);
@@ -1309,6 +1426,13 @@ static ssize_t cf_h2_proxy_send(struct Curl_cfilter *cf,
}
}
+ result = proxy_h2_progress_ingress(cf, data);
+ if(result) {
+ *err = result;
+ nwritten = -1;
+ goto out;
+ }
+
/* Call the nghttp2 send loop and flush to write ALL buffered data,
* headers and/or request body completely out to the network */
result = proxy_h2_progress_egress(cf, data);
@@ -1339,24 +1463,25 @@ static ssize_t cf_h2_proxy_send(struct Curl_cfilter *cf,
* proxy connection AND to UNHOLD all of them again when the
* window increases.
* We *could* iterate over all data on this conn maybe? */
- DEBUGF(LOG_CF(data, cf, "[h2sid=%d] remote flow "
- "window is exhausted", ctx->tunnel.stream_id));
+ CURL_TRC_CF(data, cf, "[%d] remote flow "
+ "window is exhausted", ctx->tunnel.stream_id);
}
/* Whatever the cause, we need to return CURL_EAGAIN for this call.
* We have unwritten state that needs us being invoked again and EAGAIN
* is the only way to ensure that. */
ctx->tunnel.upload_blocked_len = nwritten;
- DEBUGF(LOG_CF(data, cf, "[h2sid=%d] cf_send(len=%zu) BLOCK: win %u/%zu "
- "blocked_len=%zu",
- ctx->tunnel.stream_id, len,
- nghttp2_session_get_remote_window_size(ctx->h2), rwin,
- nwritten));
+ CURL_TRC_CF(data, cf, "[%d] cf_send(len=%zu) BLOCK: win %u/%zu "
+ "blocked_len=%zu",
+ ctx->tunnel.stream_id, len,
+ nghttp2_session_get_remote_window_size(ctx->h2), rwin,
+ nwritten);
+ drain_tunnel(cf, data, &ctx->tunnel);
*err = CURLE_AGAIN;
nwritten = -1;
goto out;
}
- else if(should_close_session(ctx)) {
+ else if(proxy_h2_should_close_session(ctx)) {
/* nghttp2 thinks this session is done. If the stream has not been
* closed, this is an error state for out transfer */
if(ctx->tunnel.closed) {
@@ -1364,22 +1489,27 @@ static ssize_t cf_h2_proxy_send(struct Curl_cfilter *cf,
nwritten = -1;
}
else {
- DEBUGF(LOG_CF(data, cf, "send: nothing to do in this session"));
+ CURL_TRC_CF(data, cf, "[0] send: nothing to do in this session");
*err = CURLE_HTTP2;
nwritten = -1;
}
}
out:
- DEBUGF(LOG_CF(data, cf, "[h2sid=%d] cf_send(len=%zu) -> %zd, %d, "
- "h2 windows %d-%d (stream-conn), "
- "buffers %zu-%zu (stream-conn)",
- ctx->tunnel.stream_id, len, nwritten, *err,
- nghttp2_session_get_stream_remote_window_size(
+ if(!Curl_bufq_is_empty(&ctx->tunnel.recvbuf) &&
+ (nwritten >= 0 || *err == CURLE_AGAIN)) {
+ /* data pending and no fatal error to report. Need to trigger
+ * draining to avoid stalling when no socket events happen. */
+ drain_tunnel(cf, data, &ctx->tunnel);
+ }
+ CURL_TRC_CF(data, cf, "[%d] cf_send(len=%zu) -> %zd, %d, "
+ "h2 windows %d-%d (stream-conn), buffers %zu-%zu (stream-conn)",
+ ctx->tunnel.stream_id, len, nwritten, *err,
+ nghttp2_session_get_stream_remote_window_size(
ctx->h2, ctx->tunnel.stream_id),
- nghttp2_session_get_remote_window_size(ctx->h2),
- Curl_bufq_len(&ctx->tunnel.sendbuf),
- Curl_bufq_len(&ctx->outbufq)));
+ nghttp2_session_get_remote_window_size(ctx->h2),
+ Curl_bufq_len(&ctx->tunnel.sendbuf),
+ Curl_bufq_len(&ctx->outbufq));
CF_DATA_RESTORE(cf, save);
return nwritten;
}
@@ -1409,7 +1539,7 @@ static bool proxy_h2_connisalive(struct Curl_cfilter *cf,
/* immediate error, considered dead */
alive = FALSE;
else {
- alive = !should_close_session(ctx);
+ alive = !proxy_h2_should_close_session(ctx);
}
}
else if(result != CURLE_AGAIN) {
@@ -1431,8 +1561,8 @@ static bool cf_h2_proxy_is_alive(struct Curl_cfilter *cf,
CF_DATA_SAVE(save, cf, data);
result = (ctx && ctx->h2 && proxy_h2_connisalive(cf, data, input_pending));
- DEBUGF(LOG_CF(data, cf, "conn alive -> %d, input_pending=%d",
- result, *input_pending));
+ CURL_TRC_CF(data, cf, "[0] conn alive -> %d, input_pending=%d",
+ result, *input_pending);
CF_DATA_RESTORE(cf, save);
return result;
}
@@ -1440,7 +1570,7 @@ static bool cf_h2_proxy_is_alive(struct Curl_cfilter *cf,
struct Curl_cftype Curl_cft_h2_proxy = {
"H2-PROXY",
CF_TYPE_IP_CONNECT,
- CURL_LOG_DEFAULT,
+ CURL_LOG_LVL_NONE,
cf_h2_proxy_destroy,
cf_h2_proxy_connect,
cf_h2_proxy_close,
generated by cgit v1.2.3 (git 2.25.1) at 2024-11-19 14:25:12 +0000