Improve debug logging, log proto name on connect/disconnect

Rename vars and functions
Improve and clean up
pull/13/head
Soner Tari 6 years ago
parent 1374d37722
commit c91d569723

@ -90,7 +90,7 @@ protoautossl_peek_and_upgrade(pxy_conn_ctx_t *ctx)
}
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_peek_and_upgrade: Enabling srv_dst, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protoautossl_peek_and_upgrade: Enabling srv_dst, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
bufferevent_setcb(ctx->srv_dst.bev, pxy_bev_readcb, pxy_bev_writecb, pxy_bev_eventcb, ctx);
@ -119,7 +119,7 @@ protoautossl_bufferevent_free_and_close_fd(struct bufferevent *bev, pxy_conn_ctx
evutil_socket_t fd = bufferevent_getfd(bev);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protoautossl_bufferevent_free_and_close_fd: ENTER i:%zu o:%zu, fd=%d\n",
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protoautossl_bufferevent_free_and_close_fd: in=%zu, out=%zu, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), evbuffer_get_length(bufferevent_get_output(bev)), fd);
#endif /* DEBUG_PROXY */
@ -168,7 +168,7 @@ protoautossl_conn_connect(pxy_conn_ctx_t *ctx)
if (bufferevent_socket_connect(ctx->srv_dst.bev, (struct sockaddr *)&ctx->addr, ctx->addrlen) == -1) {
log_err_level_printf(LOG_CRIT, "protoautossl_conn_connect: bufferevent_socket_connect for srv_dst failed\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protoautossl_conn_connect: bufferevent_socket_connect for srv_dst failed, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "protoautossl_conn_connect: bufferevent_socket_connect for srv_dst failed, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
}
}
@ -179,15 +179,15 @@ protoautossl_connect_child(pxy_conn_child_ctx_t *ctx)
protoautossl_ctx_t *autossl_ctx = ctx->conn->protoctx->arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_connect_child: ENTER, conn fd=%d, child_fd=%d\n", ctx->conn->fd, ctx->conn->child_fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_connect_child: ENTER, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
/* create server-side socket and eventbuffer */
// Children rely on the findings of parent
if (autossl_ctx->clienthello_found) {
protossl_setup_dst_child(ctx);
} else {
if (!autossl_ctx->clienthello_found) {
prototcp_setup_dst_child(ctx);
} else {
protossl_setup_dst_child(ctx);
}
}
@ -198,8 +198,8 @@ protoautossl_bev_readcb_src(struct bufferevent *bev, void *arg)
protoautossl_ctx_t *autossl_ctx = ctx->protoctx->arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_src: ENTER, fd=%d, size=%zu\n",
ctx->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_src: ENTER, size=%zu, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd);
#endif /* DEBUG_PROXY */
if (autossl_ctx->clienthello_search) {
@ -218,7 +218,7 @@ protoautossl_bev_readcb_src(struct bufferevent *bev, void *arg)
size_t packet_size = evbuffer_get_length(inbuf);
// +2 is for \r\n
unsigned char *packet = pxy_malloc_packet(packet_size + ctx->header_len + 2, ctx);
unsigned char *packet = pxy_malloc_packet(packet_size + ctx->sslproxy_header_len + 2, ctx);
if (!packet) {
return;
}
@ -226,13 +226,13 @@ protoautossl_bev_readcb_src(struct bufferevent *bev, void *arg)
evbuffer_remove(inbuf, packet, packet_size);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_src: ORIG packet (size=%zu), fd=%d:\n%.*s\n",
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_src: ORIG packet, size=%zu, fd=%d:\n%.*s\n",
packet_size, ctx->fd, (int)packet_size, packet);
#endif /* DEBUG_PROXY */
if (autossl_ctx->clienthello_search) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_src: clienthello_search Duping packet to srv_dst (size=%zu), fd=%d:\n%.*s\n",
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protoautossl_bev_readcb_src: clienthello_search Duping packet to srv_dst, size=%zu, fd=%d:\n%.*s\n",
packet_size, ctx->fd, (int)packet_size, packet);
#endif /* DEBUG_PROXY */
@ -240,13 +240,13 @@ protoautossl_bev_readcb_src(struct bufferevent *bev, void *arg)
evbuffer_add(bufferevent_get_output(ctx->srv_dst.bev), packet, packet_size);
}
if (!ctx->sent_header) {
if (!ctx->sent_sslproxy_header) {
pxy_insert_sslproxy_header(ctx, packet, &packet_size);
}
evbuffer_add(outbuf, packet, packet_size);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_src: NEW packet (size=%zu), fd=%d:\n%.*s\n",
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_src: NEW packet, size=%zu, fd=%d:\n%.*s\n",
packet_size, ctx->fd, (int)packet_size, packet);
#endif /* DEBUG_PROXY */
@ -261,8 +261,8 @@ protoautossl_bev_readcb_dst(struct bufferevent *bev, void *arg)
protoautossl_ctx_t *autossl_ctx = ctx->protoctx->arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_dst: ENTER, fd=%d, size=%zu\n",
ctx->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_dst: ENTER, size=%zu, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd);
#endif /* DEBUG_PROXY */
if (autossl_ctx->clienthello_search) {
@ -289,8 +289,8 @@ protoautossl_bev_readcb_srv_dst(struct bufferevent *bev, void *arg)
protoautossl_ctx_t *autossl_ctx = ctx->protoctx->arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_srv_dst: ENTER, fd=%d, size=%zu\n",
ctx->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_srv_dst: ENTER, size=%zu, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd);
#endif /* DEBUG_PROXY */
if (autossl_ctx->clienthello_search) {
@ -303,7 +303,7 @@ protoautossl_bev_readcb_srv_dst(struct bufferevent *bev, void *arg)
size_t inbuf_size = evbuffer_get_length(inbuf);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_srv_dst: clienthello_search Discarding packet, size=%zu, fd=%d\n",
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protoautossl_bev_readcb_srv_dst: clienthello_search Discarding packet, size=%zu, fd=%d\n",
inbuf_size, ctx->fd);
#endif /* DEBUG_PROXY */
@ -324,7 +324,7 @@ static void NONNULL(1)
protoautossl_close_srv_dst(pxy_conn_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protoautossl_close_srv_dst: Closing srv_dst, fd=%d, srv_dst fd=%d\n", ctx->fd, bufferevent_getfd(ctx->srv_dst.bev));
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protoautossl_close_srv_dst: Closing srv_dst, srv_dst fd=%d, fd=%d\n", bufferevent_getfd(ctx->srv_dst.bev), ctx->fd);
#endif /* DEBUG_PROXY */
// @attention Free the srv_dst of the conn asap, we don't need it anymore, but we need its fd
@ -387,7 +387,7 @@ protoautossl_enable_src(pxy_conn_ctx_t *ctx)
}
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_autossl_enable_src: Enabling src, %s, fd=%d, child_fd=%d\n", ctx->header_str, ctx->fd, ctx->child_fd);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_autossl_enable_src: Enabling src, %s, child_fd=%d, fd=%d\n", ctx->sslproxy_header, ctx->child_fd, ctx->fd);
#endif /* DEBUG_PROXY */
// Now open the gates, perhaps for a second time in autossl mode
@ -465,7 +465,7 @@ protoautossl_bev_readcb_complete_child(pxy_conn_child_ctx_t *ctx)
bufferevent_setcb(ctx->dst.bev, pxy_bev_readcb_child, pxy_bev_writecb_child, pxy_bev_eventcb_child, ctx);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_complete_child: Enabling dst, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protoautossl_bev_readcb_complete_child: Enabling dst, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
bufferevent_enable(ctx->dst.bev, EV_READ|EV_WRITE);
@ -478,8 +478,8 @@ protoautossl_bev_readcb_src_child(struct bufferevent *bev, void *arg)
protoautossl_ctx_t *autossl_ctx = ctx->conn->protoctx->arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_src_child: ENTER, fd=%d, conn fd=%d, size=%zu\n",
ctx->fd, ctx->conn->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_src_child: ENTER, size=%zu, child fd=%d, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
// Autossl upgrade on child connections follows the findings of parent
@ -496,7 +496,7 @@ protoautossl_bev_readcb_src_child(struct bufferevent *bev, void *arg)
struct evbuffer *inbuf = bufferevent_get_input(bev);
struct evbuffer *outbuf = bufferevent_get_output(ctx->dst.bev);
if (!ctx->removed_header) {
if (!ctx->removed_sslproxy_header) {
size_t packet_size = evbuffer_get_length(inbuf);
unsigned char *packet = pxy_malloc_packet(packet_size, ctx->conn);
if (!packet) {
@ -508,7 +508,7 @@ protoautossl_bev_readcb_src_child(struct bufferevent *bev, void *arg)
evbuffer_add(outbuf, packet, packet_size);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_src_child: src packet (size=%zu), fd=%d, conn fd=%d:\n%.*s\n",
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_src_child: NEW packet, size=%zu, child fd=%d, fd=%d:\n%.*s\n",
packet_size, ctx->fd, ctx->conn->fd, (int)packet_size, packet);
#endif /* DEBUG_PROXY */
@ -526,8 +526,8 @@ protoautossl_bev_readcb_dst_child(struct bufferevent *bev, void *arg)
protoautossl_ctx_t *autossl_ctx = ctx->conn->protoctx->arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_dst_child: ENTER, fd=%d, conn fd=%d, size=%zu\n",
ctx->fd, ctx->conn->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_dst_child: ENTER, size=%zu, child fd=%d, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
// Autossl upgrade on child connections follows the findings of parent
@ -543,11 +543,6 @@ protoautossl_bev_readcb_dst_child(struct bufferevent *bev, void *arg)
struct evbuffer *inbuf = bufferevent_get_input(bev);
struct evbuffer *outbuf = bufferevent_get_output(ctx->src.bev);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_readcb_dst_child: dst packet size=%zu, fd=%d\n", evbuffer_get_length(inbuf), ctx->fd);
#endif /* DEBUG_PROXY */
evbuffer_add_buffer(outbuf, inbuf);
pxy_try_set_watermark(bev, ctx->conn, ctx->src.bev);
}
@ -558,7 +553,7 @@ protoautossl_bev_eventcb_connected_dst_child(UNUSED struct bufferevent *bev, pxy
protoautossl_ctx_t *autossl_ctx = ctx->conn->protoctx->arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_eventcb_connected_dst_child: ENTER, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_eventcb_connected_dst_child: ENTER, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
ctx->connected = 1;
@ -571,7 +566,7 @@ protoautossl_bev_eventcb_connected_dst_child(UNUSED struct bufferevent *bev, pxy
// So, if we don't call readcb here, the connection would stall
if (autossl_ctx->clienthello_found && evbuffer_get_length(bufferevent_get_input(ctx->src.bev))) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protoautossl_bev_eventcb_connected_dst_child: clienthello_found src inbuf len > 0, Calling pxy_bev_readcb_child for src, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protoautossl_bev_eventcb_connected_dst_child: clienthello_found src inbuf len > 0, calling pxy_bev_readcb_child for src, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
pxy_bev_readcb_child(ctx->src.bev, ctx);

@ -259,7 +259,7 @@ deny:
}
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protohttp_ocsp_deny: Closing dst, fd=%d, dst fd=%d\n", ctx->fd, bufferevent_getfd(ctx->dst.bev));
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protohttp_ocsp_deny: Closing dst, dst fd=%d, fd=%d\n", bufferevent_getfd(ctx->dst.bev), ctx->fd);
#endif /* DEBUG_PROXY */
ctx->protoctx->bufferevent_free_and_close_fd(ctx->dst.bev, ctx);
@ -379,31 +379,35 @@ protohttp_filter_request_header(struct evbuffer *inbuf, struct evbuffer *outbuf,
char *line;
while (!http_ctx->seen_req_header && (line = evbuffer_readln(inbuf, NULL, EVBUFFER_EOL_CRLF))) {
char *replace = protohttp_filter_request_header_line(line, ctx, http_ctx);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_filter_request_header: line, fd=%d: %s\n", ctx->fd, line);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_filter_request_header: %s, fd=%d\n", line, ctx->fd);
#endif /* DEBUG_PROXY */
char *replace = protohttp_filter_request_header_line(line, ctx, http_ctx);
if (replace == line) {
evbuffer_add_printf(outbuf, "%s\r\n", line);
} else if (replace) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protohttp_filter_request_header: REPLACED line, fd=%d: %s\n", ctx->fd, replace);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protohttp_filter_request_header: REPLACE= %s, fd=%d\n", replace, ctx->fd);
#endif /* DEBUG_PROXY */
evbuffer_add_printf(outbuf, "%s\r\n", replace);
free(replace);
} else {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protohttp_filter_request_header: REMOVED line, fd=%d: %s\n", ctx->fd, line);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protohttp_filter_request_header: REMOVE= %s, fd=%d\n", line, ctx->fd);
#endif /* DEBUG_PROXY */
}
free(line);
if ((ctx->type == CONN_TYPE_PARENT) && !ctx->sent_header) {
ctx->sent_header = 1;
if ((ctx->type == CONN_TYPE_PARENT) && !ctx->sent_sslproxy_header) {
ctx->sent_sslproxy_header = 1;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protohttp_filter_request_header: INSERT header_str line, fd=%d: %s\n", ctx->fd, ctx->conn->header_str);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protohttp_filter_request_header: INSERT= %s, fd=%d\n", ctx->conn->sslproxy_header, ctx->fd);
#endif /* DEBUG_PROXY */
evbuffer_add_printf(outbuf, "%s\r\n", ctx->header_str);
evbuffer_add_printf(outbuf, "%s\r\n", ctx->sslproxy_header);
}
}
@ -434,8 +438,8 @@ protohttp_bev_readcb_src(struct bufferevent *bev, void *arg)
pxy_conn_ctx_t *ctx = arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_src_exec: ENTER, fd=%d, size=%zu\n",
ctx->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_src: ENTER, size=%zu, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd);
#endif /* DEBUG_PROXY */
if (ctx->dst.closed) {
@ -458,13 +462,13 @@ protohttp_bev_readcb_src(struct bufferevent *bev, void *arg)
/* request header munging */
if (!http_ctx->seen_req_header) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_src_exec: HTTP Request Header size=%zu, fd=%d\n", evbuffer_get_length(inbuf), ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_src: HTTP Request Header, size=%zu, fd=%d\n", evbuffer_get_length(inbuf), ctx->fd);
#endif /* DEBUG_PROXY */
protohttp_filter_request_header(inbuf, outbuf, ctx, http_ctx);
} else {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_src_exec: HTTP Request Body size=%zu, fd=%d\n", evbuffer_get_length(inbuf), ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_src: HTTP Request Body, size=%zu, fd=%d\n", evbuffer_get_length(inbuf), ctx->fd);
#endif /* DEBUG_PROXY */
evbuffer_add_buffer(outbuf, inbuf);
@ -561,21 +565,23 @@ protohttp_filter_response_header(struct evbuffer *inbuf, struct evbuffer *outbuf
char *line;
while (!http_ctx->seen_resp_header && (line = evbuffer_readln(inbuf, NULL, EVBUFFER_EOL_CRLF))) {
char *replace = protohttp_filter_response_header_line(line, ctx, http_ctx);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_filter_response_header: line, fd=%d: %s\n", ctx->fd, line);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_filter_response_header: %s, fd=%d\n", line, ctx->fd);
#endif /* DEBUG_PROXY */
char *replace = protohttp_filter_response_header_line(line, ctx, http_ctx);
if (replace == line) {
evbuffer_add_printf(outbuf, "%s\r\n", line);
} else if (replace) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protohttp_filter_response_header: REPLACED line, fd=%d: %s\n", ctx->fd, replace);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protohttp_filter_response_header: REPLACE= %s, fd=%d\n", replace, ctx->fd);
#endif /* DEBUG_PROXY */
evbuffer_add_printf(outbuf, "%s\r\n", replace);
free(replace);
} else {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protohttp_filter_response_header: REMOVED line, fd=%d: %s\n", ctx->fd, line);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protohttp_filter_response_header: REMOVE= %s, fd=%d\n", line, ctx->fd);
#endif /* DEBUG_PROXY */
}
free(line);
@ -603,8 +609,8 @@ protohttp_bev_readcb_dst(struct bufferevent *bev, void *arg)
pxy_conn_ctx_t *ctx = arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_dst_exec: ENTER, fd=%d, size=%zu\n",
ctx->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_dst: ENTER, size=%zu, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd);
#endif /* DEBUG_PROXY */
if (ctx->src.closed) {
@ -618,13 +624,13 @@ protohttp_bev_readcb_dst(struct bufferevent *bev, void *arg)
if (!http_ctx->seen_resp_header) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_dst_exec: HTTP Response Header size=%zu, fd=%d\n", evbuffer_get_length(inbuf), ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_dst: HTTP Response Header, size=%zu, fd=%d\n", evbuffer_get_length(inbuf), ctx->fd);
#endif /* DEBUG_PROXY */
protohttp_filter_response_header(inbuf, outbuf, ctx, http_ctx);
} else {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_dst_exec: HTTP Response Body size=%zu, fd=%d\n", evbuffer_get_length(inbuf), ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_dst: HTTP Response Body, size=%zu, fd=%d\n", evbuffer_get_length(inbuf), ctx->fd);
#endif /* DEBUG_PROXY */
evbuffer_add_buffer(outbuf, inbuf);
@ -636,6 +642,10 @@ static void NONNULL(1)
protohttp_bev_readcb_srv_dst(UNUSED struct bufferevent *bev, UNUSED void *arg)
{
log_err_printf("protohttp_bev_readcb_srv_dst: readcb called on srv_dst\n");
#ifdef DEBUG_PROXY
pxy_conn_ctx_t *ctx = arg;
log_dbg_level_printf(LOG_DBG_MODE_FINE, "protohttp_bev_readcb_srv_dst: readcb called on srv_dst, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
}
static void NONNULL(1)
@ -645,8 +655,8 @@ protohttp_bev_readcb_src_child(struct bufferevent *bev, void *arg)
protohttp_ctx_t *http_ctx = ctx->protoctx->arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_src_child: ENTER, fd=%d, conn fd=%d, size=%zu\n",
ctx->fd, ctx->conn->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_src_child: ENTER, size=%zu, child fd=%d, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
if (ctx->dst.closed) {
@ -659,14 +669,16 @@ protohttp_bev_readcb_src_child(struct bufferevent *bev, void *arg)
if (!http_ctx->seen_req_header) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_src_child: HTTP Request Header size=%zu, fd=%d\n", evbuffer_get_length(inbuf), ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_src_child: HTTP Request Header, size=%zu, child fd=%d, fd=%d\n",
evbuffer_get_length(inbuf), ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
// @todo Just remove SSLproxy line, do not filter response on the server side?
protohttp_filter_request_header(inbuf, outbuf, (pxy_conn_ctx_t *)ctx, http_ctx);
} else {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_src_child: HTTP Request Body size=%zu, fd=%d\n", evbuffer_get_length(inbuf), ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_src_child: HTTP Request Body, size=%zu, child fd=%d, fd=%d\n",
evbuffer_get_length(inbuf), ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
evbuffer_add_buffer(outbuf, inbuf);
@ -681,8 +693,8 @@ protohttp_bev_readcb_dst_child(struct bufferevent *bev, void *arg)
protohttp_ctx_t *http_ctx = ctx->protoctx->arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_dst_child: ENTER, fd=%d, conn fd=%d, size=%zu\n",
ctx->fd, ctx->conn->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_dst_child: ENTER, size=%zu, child fd=%d, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
if (ctx->src.closed) {
@ -695,14 +707,16 @@ protohttp_bev_readcb_dst_child(struct bufferevent *bev, void *arg)
if (!http_ctx->seen_resp_header) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_dst_child: HTTP Response Header size=%zu, fd=%d\n", evbuffer_get_length(inbuf), ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_dst_child: HTTP Response Header, size=%zu, child fd=%d, fd=%d\n",
evbuffer_get_length(inbuf), ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
// @todo Do not filter response on the server side?
protohttp_filter_response_header(inbuf, outbuf, (pxy_conn_ctx_t *)ctx, http_ctx);
} else {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_dst_child: HTTP Response Body size=%zu, fd=%d\n", evbuffer_get_length(inbuf), ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protohttp_bev_readcb_dst_child: HTTP Response Body, size=%zu, child fd=%d, fd=%d\n",
evbuffer_get_length(inbuf), ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
evbuffer_add_buffer(outbuf, inbuf);

@ -42,7 +42,7 @@ protopassthrough_prepare_logging(pxy_conn_ctx_t *ctx)
}
static void NONNULL(1)
protopassthrough_log_connect_type(pxy_conn_ctx_t *ctx)
protopassthrough_log_dbg_connect_type(pxy_conn_ctx_t *ctx)
{
if (OPTS_DEBUG(ctx->opts)) {
/* for TCP, we get only a dst connect event,
@ -50,9 +50,9 @@ protopassthrough_log_connect_type(pxy_conn_ctx_t *ctx)
* beginning; mirror SSL debug output anyway
* in order not to confuse anyone who might be
* looking closely at the output */
log_dbg_printf("protopassthrough_log_connect_type: TCP connected to [%s]:%s\n",
log_dbg_printf("PASSTHROUGH connected to [%s]:%s\n",
STRORDASH(ctx->dsthost_str), STRORDASH(ctx->dstport_str));
log_dbg_printf("protopassthrough_log_connect_type: TCP connected from [%s]:%s\n",
log_dbg_printf("PASSTHROUGH connected from [%s]:%s\n",
STRORDASH(ctx->srchost_str), STRORDASH(ctx->srcport_str));
}
}
@ -63,14 +63,14 @@ protopassthrough_log_connect_src(pxy_conn_ctx_t *ctx)
if (WANT_CONNECT_LOG(ctx) || ctx->opts->statslog) {
pxy_log_connect_nonhttp(ctx);
}
protopassthrough_log_connect_type(ctx);
protopassthrough_log_dbg_connect_type(ctx);
}
void
protopassthrough_engage(pxy_conn_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protopassthrough_engage: ENTER, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "protopassthrough_engage: fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
// @attention Do not call bufferevent_free_and_close_fd(), otherwise connection stalls due to ssl shutdown
@ -114,7 +114,7 @@ protopassthrough_conn_connect(pxy_conn_ctx_t *ctx)
if (bufferevent_socket_connect(ctx->srv_dst.bev, (struct sockaddr *)&ctx->addr, ctx->addrlen) == -1) {
log_err_level_printf(LOG_CRIT, "protopassthrough_conn_connect: bufferevent_socket_connect for srv_dst failed\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protopassthrough_conn_connect: bufferevent_socket_connect for srv_dst failed, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "protopassthrough_conn_connect: bufferevent_socket_connect for srv_dst failed, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
}
}
@ -123,9 +123,10 @@ static void NONNULL(1)
protopassthrough_bev_readcb_src(struct bufferevent *bev, void *arg)
{
pxy_conn_ctx_t *ctx = arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protopassthrough_bev_readcb_src: ENTER, fd=%d, size=%zu\n",
ctx->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protopassthrough_bev_readcb_src: ENTER, size=%zu, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd);
#endif /* DEBUG_PROXY */
// Passthrough packets are transfered between src and srv_dst
@ -142,9 +143,10 @@ static void NONNULL(1)
protopassthrough_bev_readcb_srv_dst(struct bufferevent *bev, void *arg)
{
pxy_conn_ctx_t *ctx = arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protopassthrough_bev_readcb_srv_dst: ENTER, fd=%d, size=%zu\n",
ctx->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protopassthrough_bev_readcb_srv_dst: ENTER, size=%zu, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd);
#endif /* DEBUG_PROXY */
// Passthrough packets are transfered between src and srv_dst
@ -225,7 +227,7 @@ protopassthrough_enable_src(pxy_conn_ctx_t *ctx)
bufferevent_setcb(ctx->src.bev, pxy_bev_readcb, pxy_bev_writecb, pxy_bev_eventcb, ctx);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protopassthrough_enable_src: Enabling src, %s, fd=%d, child_fd=%d\n", ctx->header_str, ctx->fd, ctx->child_fd);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protopassthrough_enable_src: Enabling src, %s, child_fd=%d, fd=%d\n", ctx->sslproxy_header, ctx->child_fd, ctx->fd);
#endif /* DEBUG_PROXY */
// Now open the gates
@ -257,12 +259,16 @@ static void NONNULL(1,2)
protopassthrough_bev_eventcb_eof_src(struct bufferevent *bev, pxy_conn_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protopassthrough_bev_eventcb_eof_src: EOF, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protopassthrough_bev_eventcb_eof_src: ENTER, fd=%d\n", ctx->fd);
pxy_log_dbg_evbuf_info(ctx, &ctx->src, &ctx->srv_dst);
#endif /* DEBUG_PROXY */
if (!ctx->connected) {
log_err_level_printf(LOG_WARNING, "EOF on outbound connection before connection establishment\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINE, "protopassthrough_bev_eventcb_eof_src: EOF on outbound connection before connection establishment, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
ctx->srv_dst.closed = 1;
} else if (!ctx->srv_dst.closed) {
#ifdef DEBUG_PROXY
@ -286,6 +292,10 @@ protopassthrough_bev_eventcb_eof_srv_dst(struct bufferevent *bev, pxy_conn_ctx_t
if (!ctx->connected) {
log_err_level_printf(LOG_WARNING, "EOF on outbound connection before connection establishment\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINE, "protopassthrough_bev_eventcb_eof_srv_dst: EOF on outbound connection before connection establishment, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
ctx->src.closed = 1;
} else if (!ctx->src.closed) {
#ifdef DEBUG_PROXY
@ -303,7 +313,7 @@ static void NONNULL(1,2)
protopassthrough_bev_eventcb_error_src(UNUSED struct bufferevent *bev, pxy_conn_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protopassthrough_bev_eventcb_error_src: BEV_EVENT_ERROR, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "protopassthrough_bev_eventcb_error_src: BEV_EVENT_ERROR, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
// Passthrough packets are transfered between src and srv_dst
@ -320,7 +330,7 @@ static void NONNULL(1,2)
protopassthrough_bev_eventcb_error_srv_dst(UNUSED struct bufferevent *bev, pxy_conn_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protopassthrough_bev_eventcb_error_srv_dst: BEV_EVENT_ERROR, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "protopassthrough_bev_eventcb_error_srv_dst: BEV_EVENT_ERROR, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
// Passthrough packets are transfered between src and srv_dst
@ -414,7 +424,7 @@ protopassthrough_bev_eventcb(struct bufferevent *bev, short events, void *arg)
if (protopassthrough_prepare_logging(ctx) == -1) {
return;
}
protopassthrough_log_connect_type(ctx);
protopassthrough_log_dbg_connect_type(ctx);
}
}
}

@ -863,7 +863,7 @@ protossl_bufferevent_free_and_close_fd(struct bufferevent *bev, pxy_conn_ctx_t *
evutil_socket_t fd = bufferevent_getfd(bev);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protossl_bufferevent_free_and_close_fd: ENTER i:%zu o:%zu, fd=%d\n",
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protossl_bufferevent_free_and_close_fd: in=%zu, out=%zu, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), evbuffer_get_length(bufferevent_get_output(bev)), fd);
#endif /* DEBUG_PROXY */
@ -956,7 +956,7 @@ protossl_fd_readcb(MAYBE_UNUSED evutil_socket_t fd, UNUSED short what, void *arg
if (n == -1) {
log_err_printf("Error peeking on fd, aborting connection\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "ERROR: Error peeking on fd, aborting connection, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "ERROR: Error peeking on fd, aborting connection, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
evutil_closesocket(fd);
pxy_conn_ctx_free(ctx, 1);
@ -966,7 +966,7 @@ protossl_fd_readcb(MAYBE_UNUSED evutil_socket_t fd, UNUSED short what, void *arg
/* socket got closed while we were waiting */
log_err_printf("Socket got closed while waiting\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "ERROR: Socket got closed while waiting, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "ERROR: Socket got closed while waiting, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
evutil_closesocket(fd);
pxy_conn_ctx_free(ctx, 1);
@ -977,7 +977,7 @@ protossl_fd_readcb(MAYBE_UNUSED evutil_socket_t fd, UNUSED short what, void *arg
if ((rv == 1) && !chello) {
log_err_printf("Peeking did not yield a (truncated) ClientHello message, aborting connection\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "ERROR: Peeking did not yield a (truncated) ClientHello message, aborting connection, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "ERROR: Peeking did not yield a (truncated) ClientHello message, aborting connection, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
evutil_closesocket(fd);
pxy_conn_ctx_free(ctx, 1);
@ -1003,7 +1003,7 @@ protossl_fd_readcb(MAYBE_UNUSED evutil_socket_t fd, UNUSED short what, void *arg
if (!ctx->ev) {
log_err_level_printf(LOG_CRIT, "Error creating retry event, aborting connection\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "Error creating retry event, aborting connection, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "ERROR: Error creating retry event, aborting connection, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
evutil_closesocket(fd);
pxy_conn_ctx_free(ctx, 1);
@ -1110,7 +1110,7 @@ protossl_conn_connect(pxy_conn_ctx_t *ctx)
if (bufferevent_socket_connect(ctx->srv_dst.bev, (struct sockaddr *)&ctx->addr, ctx->addrlen) == -1) {
log_err_level_printf(LOG_CRIT, "protossl_conn_connect: bufferevent_socket_connect for srv_dst failed\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protossl_conn_connect: bufferevent_socket_connect for srv_dst failed, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "protossl_conn_connect: bufferevent_socket_connect for srv_dst failed, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
// @attention Do not try to close the conn here, otherwise both pxy_conn_connect() and eventcb try to free the conn using pxy_conn_free(),
@ -1155,7 +1155,7 @@ void
protossl_connect_child(pxy_conn_child_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protossl_connect_child: ENTER, conn fd=%d, child_fd=%d\n", ctx->conn->fd, ctx->conn->child_fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protossl_connect_child: ENTER, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
/* create server-side socket and eventbuffer */
@ -1265,7 +1265,7 @@ protossl_enable_src(pxy_conn_ctx_t *ctx)
}
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "protossl_enable_src: Enabling src, %s, fd=%d, child_fd=%d\n", ctx->header_str, ctx->fd, ctx->child_fd);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protossl_enable_src: Enabling src, %s, fd=%d, child_fd=%d\n", ctx->sslproxy_header, ctx->fd, ctx->child_fd);
#endif /* DEBUG_PROXY */
// Now open the gates
@ -1323,7 +1323,7 @@ static void NONNULL(1,2)
protossl_bev_eventcb_error_srv_dst(struct bufferevent *bev, pxy_conn_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "protossl_bev_eventcb_error_srv_dst: BEV_EVENT_ERROR, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "protossl_bev_eventcb_error_srv_dst: BEV_EVENT_ERROR, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
if (!ctx->connected) {

@ -34,7 +34,7 @@
int protossl_log_masterkey(pxy_conn_ctx_t *, pxy_conn_desc_t *) NONNULL(1,2);
void protossl_log_ssl_error(struct bufferevent *, pxy_conn_ctx_t *) NONNULL(1,2);
// @todo Used externally by pxy_log_connect_src(), create tcp and ssl versions of that function instead
// @todo Used externally by pxy_log_connect_src(), create tcp and ssl versions of that function instead?
void protossl_srccert_write(pxy_conn_ctx_t *) NONNULL(1);
SSL *protossl_dstssl_create(pxy_conn_ctx_t *) NONNULL(1);

@ -53,6 +53,10 @@ prototcp_bufferevent_setup(pxy_conn_ctx_t *ctx, evutil_socket_t fd)
struct bufferevent *bev = bufferevent_socket_new(ctx->evbase, fd, BEV_OPT_DEFER_CALLBACKS);
if (!bev) {
log_err_level_printf(LOG_CRIT, "Error creating bufferevent socket\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_bufferevent_setup: bufferevent_socket_connect failed, fd=%d\n", fd);
#endif /* DEBUG_PROXY */
return NULL;
}
@ -73,6 +77,10 @@ prototcp_bufferevent_setup_child(pxy_conn_child_ctx_t *ctx, evutil_socket_t fd)
struct bufferevent *bev = bufferevent_socket_new(ctx->conn->evbase, fd, BEV_OPT_DEFER_CALLBACKS);
if (!bev) {
log_err_level_printf(LOG_CRIT, "Error creating bufferevent socket\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_bufferevent_setup_child: bufferevent_socket_connect failed, fd=%d\n", fd);
#endif /* DEBUG_PROXY */
return NULL;
}
@ -92,7 +100,7 @@ prototcp_bufferevent_free_and_close_fd(struct bufferevent *bev, UNUSED pxy_conn_
evutil_socket_t fd = bufferevent_getfd(bev);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "prototcp_bufferevent_free_and_close_fd: ENTER i:%zu o:%zu, fd=%d\n",
log_dbg_level_printf(LOG_DBG_MODE_FINER, "prototcp_bufferevent_free_and_close_fd: in=%zu, out=%zu, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), evbuffer_get_length(bufferevent_get_output(bev)), fd);
#endif /* DEBUG_PROXY */
@ -170,7 +178,7 @@ prototcp_conn_connect(pxy_conn_ctx_t *ctx)
if (bufferevent_socket_connect(ctx->srv_dst.bev, (struct sockaddr *)&ctx->addr, ctx->addrlen) == -1) {
log_err_level_printf(LOG_CRIT, "prototcp_conn_connect: bufferevent_socket_connect for srv_dst failed\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "prototcp_conn_connect: bufferevent_socket_connect for srv_dst failed, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_conn_connect: bufferevent_socket_connect for srv_dst failed, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
// @attention Do not try to close the conn here, otherwise both pxy_conn_connect() and eventcb try to free the conn using pxy_conn_free(),
@ -210,7 +218,7 @@ static void NONNULL(1)
prototcp_connect_child(pxy_conn_child_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_connect_child: ENTER, conn fd=%d, child_fd=%d\n", ctx->conn->fd, ctx->conn->child_fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_connect_child: ENTER, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
/* create server-side socket and eventbuffer */
@ -235,8 +243,8 @@ prototcp_bev_readcb_src(struct bufferevent *bev, void *arg)
pxy_conn_ctx_t *ctx = arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_src: ENTER, fd=%d, size=%zu\n",
ctx->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_src: ENTER, size=%zu, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd);
#endif /* DEBUG_PROXY */
if (ctx->dst.closed) {
@ -247,10 +255,10 @@ prototcp_bev_readcb_src(struct bufferevent *bev, void *arg)
struct evbuffer *inbuf = bufferevent_get_input(bev);
struct evbuffer *outbuf = bufferevent_get_output(ctx->dst.bev);
if (!ctx->sent_header) {
if (!ctx->sent_sslproxy_header) {
size_t packet_size = evbuffer_get_length(inbuf);
// +2 is for \r\n
unsigned char *packet = pxy_malloc_packet(packet_size + ctx->header_len + 2, ctx);
unsigned char *packet = pxy_malloc_packet(packet_size + ctx->sslproxy_header_len + 2, ctx);
if (!packet) {
return;
}
@ -258,7 +266,7 @@ prototcp_bev_readcb_src(struct bufferevent *bev, void *arg)
evbuffer_remove(inbuf, packet, packet_size);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_src: ORIG packet (size=%zu), fd=%d:\n%.*s\n",
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_src: ORIG packet, size=%zu, fd=%d:\n%.*s\n",
packet_size, ctx->fd, (int)packet_size, packet);
#endif /* DEBUG_PROXY */
@ -266,7 +274,7 @@ prototcp_bev_readcb_src(struct bufferevent *bev, void *arg)
evbuffer_add(outbuf, packet, packet_size);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_src: NEW packet (size=%zu), fd=%d:\n%.*s\n",
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_src: NEW packet, size=%zu, fd=%d:\n%.*s\n",
packet_size, ctx->fd, (int)packet_size, packet);
#endif /* DEBUG_PROXY */
@ -284,8 +292,8 @@ prototcp_bev_readcb_dst(struct bufferevent *bev, void *arg)
pxy_conn_ctx_t *ctx = arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_dst: ENTER, fd=%d, size=%zu\n",
ctx->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_dst: ENTER, size=%zu, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd);
#endif /* DEBUG_PROXY */
if (ctx->src.closed) {
@ -303,6 +311,10 @@ static void NONNULL(1)
prototcp_bev_readcb_srv_dst(UNUSED struct bufferevent *bev, UNUSED void *arg)
{
log_err_printf("prototcp_bev_readcb_srv_dst: readcb called on srv_dst\n");
#ifdef DEBUG_PROXY
pxy_conn_ctx_t *ctx = arg;
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_bev_readcb_srv_dst: readcb called on srv_dst, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
}
static void NONNULL(1)
@ -311,8 +323,8 @@ prototcp_bev_readcb_src_child(struct bufferevent *bev, void *arg)
pxy_conn_child_ctx_t *ctx = arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_src_child: ENTER, fd=%d, conn fd=%d, size=%zu\n",
ctx->fd, ctx->conn->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_src_child: ENTER, size=%zu, child fd=%d, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
if (ctx->dst.closed) {
@ -323,7 +335,7 @@ prototcp_bev_readcb_src_child(struct bufferevent *bev, void *arg)
struct evbuffer *inbuf = bufferevent_get_input(bev);
struct evbuffer *outbuf = bufferevent_get_output(ctx->dst.bev);
if (!ctx->removed_header) {
if (!ctx->removed_sslproxy_header) {
size_t packet_size = evbuffer_get_length(inbuf);
unsigned char *packet = pxy_malloc_packet(packet_size, ctx->conn);
if (!packet) {
@ -335,7 +347,7 @@ prototcp_bev_readcb_src_child(struct bufferevent *bev, void *arg)
evbuffer_add(outbuf, packet, packet_size);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_src_child: src packet (size=%zu), fd=%d, conn fd=%d:\n%.*s\n",
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_src_child: NEW packet, size=%zu, child fd=%d, fd=%d:\n%.*s\n",
packet_size, ctx->fd, ctx->conn->fd, (int)packet_size, packet);
#endif /* DEBUG_PROXY */
@ -352,8 +364,8 @@ prototcp_bev_readcb_dst_child(struct bufferevent *bev, void *arg)
pxy_conn_child_ctx_t *ctx = arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_dst_child: ENTER, fd=%d, conn fd=%d, size=%zu\n",
ctx->fd, ctx->conn->fd, evbuffer_get_length(bufferevent_get_input(bev)));
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_readcb_dst_child: ENTER, size=%zu, child fd=%d, fd=%d\n",
evbuffer_get_length(bufferevent_get_input(bev)), ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
if (ctx->src.closed) {
@ -447,13 +459,13 @@ prototcp_bev_writecb_src_child(struct bufferevent *bev, void *arg)
pxy_conn_child_ctx_t *ctx = arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_writecb_src_child: ENTER, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_writecb_src_child: ENTER, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
if (ctx->dst.closed) {
if (pxy_try_close_conn_end(&ctx->src, ctx->conn, &prototcp_bufferevent_free_and_close_fd) == 1) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_writecb_src_child: other->closed, terminate conn, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_writecb_src_child: other->closed, terminate conn, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
pxy_conn_free_child(ctx);
@ -468,7 +480,7 @@ prototcp_try_connect_dst_child(struct bufferevent *bev, pxy_conn_child_ctx_t *ct
{
if (!ctx->connected) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_try_connect_dst_child: writecb before connected, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_try_connect_dst_child: writecb before connected, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
// @attention Sometimes dst write cb fires but not event cb, especially if the listener cb is not finished yet, so the conn stalls.
@ -485,7 +497,7 @@ prototcp_bev_writecb_dst_child(struct bufferevent *bev, void *arg)
pxy_conn_child_ctx_t *ctx = arg;
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_writecb_dst_child: ENTER, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_writecb_dst_child: ENTER, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
prototcp_try_connect_dst_child(bev, ctx);
@ -493,7 +505,7 @@ prototcp_bev_writecb_dst_child(struct bufferevent *bev, void *arg)
if (ctx->src.closed) {
if (pxy_try_close_conn_end(&ctx->dst, ctx->conn, ctx->protoctx->bufferevent_free_and_close_fd) == 1) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_writecb_dst_child: other->closed, terminate conn, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_writecb_dst_child: other->closed, terminate conn, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
pxy_conn_free_child(ctx);
@ -507,7 +519,7 @@ static void NONNULL(1)
prototcp_close_srv_dst(pxy_conn_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "prototcp_close_srv_dst: Closing srv_dst, fd=%d, srv_dst fd=%d\n", ctx->fd, bufferevent_getfd(ctx->srv_dst.bev));
log_dbg_level_printf(LOG_DBG_MODE_FINER, "prototcp_close_srv_dst: Closing srv_dst, srv_dst fd=%d, fd=%d\n", bufferevent_getfd(ctx->srv_dst.bev), ctx->fd);
#endif /* DEBUG_PROXY */
// @attention Free the srv_dst of the conn asap, we don't need it anymore, but we need its fd
@ -533,7 +545,7 @@ prototcp_enable_src(pxy_conn_ctx_t *ctx)
}
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_enable_src: Enabling src, %s, fd=%d, child_fd=%d\n", ctx->header_str, ctx->fd, ctx->child_fd);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "prototcp_enable_src: Enabling src, %s, child_fd=%d, fd=%d\n", ctx->sslproxy_header, ctx->child_fd, ctx->fd);
#endif /* DEBUG_PROXY */
// Now open the gates
@ -599,12 +611,16 @@ void
prototcp_bev_eventcb_eof_src(struct bufferevent *bev, pxy_conn_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_eof_src: EOF, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_eof_src: ENTER, fd=%d\n", ctx->fd);
pxy_log_dbg_evbuf_info(ctx, &ctx->src, &ctx->dst);
#endif /* DEBUG_PROXY */
if (!ctx->connected) {
log_err_level_printf(LOG_WARNING, "EOF on outbound connection before connection establishment\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_bev_eventcb_eof_src: EOF on outbound connection before connection establishment, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
ctx->dst.closed = 1;
} else if (!ctx->dst.closed) {
#ifdef DEBUG_PROXY
@ -622,12 +638,16 @@ void
prototcp_bev_eventcb_eof_dst(struct bufferevent *bev, pxy_conn_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_eof_dst: EOF, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_eof_dst: ENTER, fd=%d\n", ctx->fd);
pxy_log_dbg_evbuf_info(ctx, &ctx->dst, &ctx->src);
#endif /* DEBUG_PROXY */
if (!ctx->connected) {
log_err_level_printf(LOG_WARNING, "EOF on outbound connection before connection establishment\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_bev_eventcb_eof_dst: EOF on outbound connection before connection establishment, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
ctx->src.closed = 1;
} else if (!ctx->src.closed) {
#ifdef DEBUG_PROXY
@ -644,11 +664,11 @@ prototcp_bev_eventcb_eof_dst(struct bufferevent *bev, pxy_conn_ctx_t *ctx)
void
prototcp_bev_eventcb_eof_srv_dst(UNUSED struct bufferevent *bev, pxy_conn_ctx_t *ctx)
{
log_err_level_printf(LOG_WARNING, "EOF on outbound connection before connection establishment on srv_dst\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_eof_srv_dst: EOF, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_bev_eventcb_eof_srv_dst: EOF on outbound connection before connection establishment, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
log_err_level_printf(LOG_WARNING, "EOF on outbound connection before connection establishment on srv_dst\n");
pxy_conn_free(ctx, 0);
}
@ -656,7 +676,7 @@ void
prototcp_bev_eventcb_error_src(UNUSED struct bufferevent *bev, pxy_conn_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "prototcp_bev_eventcb_error_src: BEV_EVENT_ERROR, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_bev_eventcb_error_src: BEV_EVENT_ERROR, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
if (!ctx->connected) {
@ -672,7 +692,7 @@ void
prototcp_bev_eventcb_error_dst(UNUSED struct bufferevent *bev, pxy_conn_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "prototcp_bev_eventcb_error_dst: BEV_EVENT_ERROR, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_bev_eventcb_error_dst: BEV_EVENT_ERROR, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
if (!ctx->connected) {
@ -688,7 +708,7 @@ void
prototcp_bev_eventcb_error_srv_dst(UNUSED struct bufferevent *bev, pxy_conn_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "prototcp_bev_eventcb_error_srv_dst: BEV_EVENT_ERROR, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_bev_eventcb_error_srv_dst: BEV_EVENT_ERROR, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
if (!ctx->connected) {
@ -704,7 +724,7 @@ static void NONNULL(1,2)
prototcp_bev_eventcb_connected_src_child(UNUSED struct bufferevent *bev, UNUSED pxy_conn_child_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_connected_src_child: ENTER, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_connected_src_child: ENTER, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
}
@ -712,7 +732,7 @@ static void NONNULL(1,2)
prototcp_bev_eventcb_connected_dst_child(UNUSED struct bufferevent *bev, pxy_conn_child_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_connected_dst_child: ENTER, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_connected_dst_child: ENTER, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
ctx->connected = 1;
@ -725,17 +745,21 @@ static void NONNULL(1,2)
prototcp_bev_eventcb_eof_src_child(struct bufferevent *bev, pxy_conn_child_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_eof_src_child: ENTER, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_eof_src_child: ENTER, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
pxy_log_dbg_evbuf_info(ctx->conn, &ctx->src, &ctx->dst);
#endif /* DEBUG_PROXY */
// @todo How to handle the following case?
if (!ctx->connected) {
log_err_level_printf(LOG_WARNING, "EOF on outbound connection before connection establishment\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_bev_eventcb_eof_src_child: EOF on outbound connection before connection establishment, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
ctx->dst.closed = 1;
} else if (!ctx->dst.closed) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_eof_src_child: !other->closed, terminate conn, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_eof_src_child: !other->closed, terminate conn, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
pxy_try_consume_last_input_child(bev, ctx);
@ -749,17 +773,21 @@ void
prototcp_bev_eventcb_eof_dst_child(struct bufferevent *bev, pxy_conn_child_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_eof_dst_child: ENTER, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_eof_dst_child: ENTER, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
pxy_log_dbg_evbuf_info(ctx->conn, &ctx->dst, &ctx->src);
#endif /* DEBUG_PROXY */
// @todo How to handle the following case?
if (!ctx->connected) {
log_err_level_printf(LOG_WARNING, "EOF on outbound connection before connection establishment\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_bev_eventcb_eof_dst_child: EOF on outbound connection before connection establishment, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
ctx->src.closed = 1;
} else if (!ctx->src.closed) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_eof_dst_child: !other->closed, terminate conn, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "prototcp_bev_eventcb_eof_dst_child: !other->closed, terminate conn, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
pxy_try_consume_last_input_child(bev, ctx);
@ -773,7 +801,7 @@ static void NONNULL(1,2)
prototcp_bev_eventcb_error_src_child(UNUSED struct bufferevent *bev, pxy_conn_child_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "prototcp_bev_eventcb_error_src_child: BEV_EVENT_ERROR, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_bev_eventcb_error_src_child: BEV_EVENT_ERROR, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
if (!ctx->connected) {
@ -795,7 +823,7 @@ void
prototcp_bev_eventcb_error_dst_child(UNUSED struct bufferevent *bev, pxy_conn_child_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "prototcp_bev_eventcb_error_dst_child: BEV_EVENT_ERROR, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "prototcp_bev_eventcb_error_dst_child: BEV_EVENT_ERROR, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
if (!ctx->connected) {

@ -83,6 +83,21 @@ typedef struct pxy_conn_lproc_desc {
int descriptor_table_size = 0;
// @attention The order of names should match the order in protocol enum
char *protocol_names[] = {
// ERROR = -1
"PASSTHROUGH", // = 0
"HTTP",
"HTTPS",
"POP3",
"POP3S",
"SMTP",
"SMTPS",
"AUTOSSL",
"TCP",
"SSL",
};
static protocol_t NONNULL(1)
pxy_setup_proto(pxy_conn_ctx_t *ctx)
{
@ -271,7 +286,7 @@ static void NONNULL(1)
pxy_conn_ctx_free_child(pxy_conn_child_ctx_t *ctx)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_conn_ctx_free_child: ENTER, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_conn_ctx_free_child: ENTER, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
pxy_thrmgr_detach_child(ctx->conn);
@ -373,8 +388,8 @@ pxy_conn_ctx_free(pxy_conn_ctx_t *ctx, int by_requestor)
if (ctx->ev) {
event_free(ctx->ev);
}
if (ctx->header_str) {
free(ctx->header_str);
if (ctx->sslproxy_header) {
free(ctx->sslproxy_header);
}
// If the proto doesn't have special args, proto_free() callback is NULL
if (ctx->protoctx->proto_free) {
@ -387,11 +402,9 @@ pxy_conn_ctx_free(pxy_conn_ctx_t *ctx, int by_requestor)
void
pxy_conn_free(pxy_conn_ctx_t *ctx, int by_requestor)
{
evutil_socket_t fd = ctx->fd;
#ifdef DEBUG_PROXY
evutil_socket_t child_fd = ctx->child_fd;
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_conn_free: ENTER, fd=%d, child_fd=%d\n", fd, child_fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_conn_free: ENTER, fd=%d, child_fd=%d\n", ctx->fd, child_fd);
#endif /* DEBUG_PROXY */
pxy_conn_desc_t *src = &ctx->src;
@ -401,11 +414,11 @@ pxy_conn_free(pxy_conn_ctx_t *ctx, int by_requestor)
src->bev = NULL;
} else {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINE, "pxy_conn_free: evutil_closesocket on NULL src->bev, fd=%d\n", fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "pxy_conn_free: evutil_closesocket on NULL src->bev, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
// @todo src fd may be open, although src.bev is NULL, where do we close the src fd?
evutil_closesocket(fd);
evutil_closesocket(ctx->fd);
}
}
@ -429,8 +442,8 @@ pxy_conn_free(pxy_conn_ctx_t *ctx, int by_requestor)
// @attention Parent may be closing before there was any child at all nor was child_evcl ever created
if (ctx->child_evcl) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINE, "pxy_conn_free: Freeing child_evcl, conn fd=%d, child_fd=%d, cfd=%d\n",
ctx->fd, ctx->child_fd, ctx->children ? ctx->children->fd : -1);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_conn_free: Freeing child_evcl, child fd=%d, children->fd=%d, fd=%d\n",
ctx->child_fd, ctx->children ? ctx->children->fd : -1, ctx->fd);
#endif /* DEBUG_PROXY */
// @attention child_evcl was created with LEV_OPT_CLOSE_ON_FREE, so do not close ctx->child_fd
@ -649,7 +662,8 @@ pxy_log_dbg_connect_type(pxy_conn_ctx_t *ctx, pxy_conn_desc_t *this)
if (this->ssl) {
char *keystr;
/* for SSL, we get two connect events */
log_dbg_printf("pxy_log_dbg_connect_type: SSL connected to [%s]:%s %s %s\n",
log_dbg_printf("%s connected to [%s]:%s %s %s\n",
protocol_names[ctx->proto],
STRORDASH(ctx->dsthost_str), STRORDASH(ctx->dstport_str),
SSL_get_version(this->ssl), SSL_get_cipher(this->ssl));
keystr = ssl_ssl_masterkey_to_str(this->ssl);
@ -662,9 +676,11 @@ pxy_log_dbg_connect_type(pxy_conn_ctx_t *ctx, pxy_conn_desc_t *this)
* beginning; mirror SSL debug output anyway
* in order not to confuse anyone who might be
* looking closely at the output */
log_dbg_printf("pxy_log_dbg_connect_type: TCP connected to [%s]:%s\n",
log_dbg_printf("%s connected to [%s]:%s\n",
protocol_names[ctx->proto],
STRORDASH(ctx->dsthost_str), STRORDASH(ctx->dstport_str));
log_dbg_printf("pxy_log_dbg_connect_type: TCP connected from [%s]:%s\n",
log_dbg_printf("%s connected from [%s]:%s\n",
protocol_names[ctx->proto],
STRORDASH(ctx->srchost_str), STRORDASH(ctx->srcport_str));
}
}
@ -714,7 +730,7 @@ pxy_log_dbg_evbuf_info(UNUSED pxy_conn_ctx_t *ctx, UNUSED pxy_conn_desc_t *this,
#ifdef DEBUG_PROXY
// Use ctx->conn, because this function is used by child conns too
if (OPTS_DEBUG(ctx->conn->opts)) {
log_dbg_printf("pxy_log_dbg_evbuf_info: evbuffer size at EOF: i:%zu o:%zu i:%zu o:%zu\n",
log_dbg_printf("evbuffer size at EOF: i:%zu o:%zu i:%zu o:%zu\n",
evbuffer_get_length(bufferevent_get_input(this->bev)),
evbuffer_get_length(bufferevent_get_output(this->bev)),
other->closed ? 0 : evbuffer_get_length(bufferevent_get_input(other->bev)),
@ -726,14 +742,13 @@ pxy_log_dbg_evbuf_info(UNUSED pxy_conn_ctx_t *ctx, UNUSED pxy_conn_desc_t *this,
static void
pxy_log_dbg_disconnect(pxy_conn_ctx_t *ctx)
{
// On parent connections, ctx->sslctx is enough to know the type of connection
/* we only get a single disconnect event here for both connections */
if (OPTS_DEBUG(ctx->opts)) {
log_dbg_printf("pxy_log_dbg_disconnect: %s disconnected to [%s]:%s, fd=%d\n",
ctx->sslctx ? "SSL" : "TCP",
log_dbg_printf("%s disconnected to [%s]:%s, fd=%d\n",
protocol_names[ctx->proto],
STRORDASH(ctx->dsthost_str), STRORDASH(ctx->dstport_str), ctx->fd);
log_dbg_printf("pxy_log_dbg_disconnect: %s disconnected from [%s]:%s, fd=%d\n",
ctx->sslctx ? "SSL" : "TCP",
log_dbg_printf("%s disconnected from [%s]:%s, fd=%d\n",
protocol_names[ctx->proto],
STRORDASH(ctx->srchost_str), STRORDASH(ctx->srcport_str), ctx->fd);
}
}
@ -741,14 +756,13 @@ pxy_log_dbg_disconnect(pxy_conn_ctx_t *ctx)
static void
pxy_log_dbg_disconnect_child(pxy_conn_child_ctx_t *ctx)
{
// On child connections, ctx->conn->sslctx is enough to know the type of connection
/* we only get a single disconnect event here for both connections */
if (OPTS_DEBUG(ctx->conn->opts)) {
log_dbg_printf("pxy_log_dbg_disconnect_child: %s disconnected to [%s]:%s, fd=%d, conn fd=%d\n",
ctx->conn->sslctx ? "SSL" : "TCP",
log_dbg_printf("Child %s disconnected to [%s]:%s, child fd=%d, fd=%d\n",
protocol_names[ctx->proto],
STRORDASH(ctx->conn->dsthost_str), STRORDASH(ctx->conn->dstport_str), ctx->fd, ctx->conn->fd);
log_dbg_printf("pxy_log_dbg_disconnect_child: %s disconnected from [%s]:%s, fd=%d, conn fd=%d\n",
ctx->conn->sslctx ? "SSL" : "TCP",
log_dbg_printf("Child %s disconnected from [%s]:%s, child fd=%d, fd=%d\n",
protocol_names[ctx->proto],
STRORDASH(ctx->conn->srchost_str), STRORDASH(ctx->conn->srcport_str), ctx->fd, ctx->conn->fd);
}
}
@ -796,7 +810,7 @@ char *bev_names[] = {
"srv_dst",
"NULL",
"UNKWN"
};
};
static char *
pxy_get_event_name(struct bufferevent *bev, pxy_conn_ctx_t *ctx)
@ -864,29 +878,30 @@ void
pxy_insert_sslproxy_header(pxy_conn_ctx_t *ctx, unsigned char *packet, size_t *packet_size)
{
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_insert_sslproxy_header: INSERT SSLproxy header, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_insert_sslproxy_header: INSERT, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
// @attention Cannot use string manipulation functions; we are dealing with binary arrays here, not NULL-terminated strings
memmove(packet + ctx->header_len + 2, packet, *packet_size);
memcpy(packet, ctx->header_str, ctx->header_len);
memcpy(packet + ctx->header_len, "\r\n", 2);
*packet_size+= ctx->header_len + 2;
ctx->sent_header = 1;
memmove(packet + ctx->sslproxy_header_len + 2, packet, *packet_size);
memcpy(packet, ctx->sslproxy_header, ctx->sslproxy_header_len);
memcpy(packet + ctx->sslproxy_header_len, "\r\n", 2);
*packet_size+= ctx->sslproxy_header_len + 2;
ctx->sent_sslproxy_header = 1;
}
void
pxy_try_remove_sslproxy_header(pxy_conn_child_ctx_t *ctx, unsigned char *packet, size_t *packet_size)
{
unsigned char *pos = memmem(packet, *packet_size, ctx->conn->header_str, ctx->conn->header_len);
// @attention Cannot use string manipulation functions; we are dealing with binary arrays here, not NULL-terminated strings
unsigned char *pos = memmem(packet, *packet_size, ctx->conn->sslproxy_header, ctx->conn->sslproxy_header_len);
if (pos) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_try_remove_sslproxy_header: REMOVE SSLproxy header, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_try_remove_sslproxy_header: REMOVE, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
memmove(pos, pos + ctx->conn->header_len + 2, *packet_size - (pos - packet) - (ctx->conn->header_len + 2));
*packet_size-= ctx->conn->header_len + 2;
ctx->removed_header = 1;
memmove(pos, pos + ctx->conn->sslproxy_header_len + 2, *packet_size - (pos - packet) - (ctx->conn->sslproxy_header_len + 2));
*packet_size-= ctx->conn->sslproxy_header_len + 2;
ctx->removed_sslproxy_header = 1;
}
}
@ -902,11 +917,11 @@ pxy_listener_acceptcb_child(UNUSED struct evconnlistener *listener, evutil_socke
conn->atime = time(NULL);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_listener_acceptcb_child: ENTER, fd=%d, conn fd=%d, child_fd=%d\n", fd, conn->fd, conn->child_fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_listener_acceptcb_child: ENTER, child fd=%d, conn->child_fd=%d, fd=%d\n", fd, conn->child_fd, conn->fd);
char *host, *port;
if (sys_sockaddr_str(peeraddr, peeraddrlen, &host, &port) == 0) {
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_listener_acceptcb_child: Peer addr=[%s]:%s, child fd=%d, conn fd=%d\n", host, port, fd, conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_listener_acceptcb_child: peer addr=[%s]:%s, child fd=%d, fd=%d\n", host, port, fd, conn->fd);
free(host);
free(port);
}
@ -922,7 +937,8 @@ pxy_listener_acceptcb_child(UNUSED struct evconnlistener *listener, evutil_socke
int dtable_count = getdtablecount();
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_listener_acceptcb_child: descriptor_table_size=%d, current fd count=%d, reserve=%d, fd=%d\n", descriptor_table_size, dtable_count, FD_RESERVE, fd);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_listener_acceptcb_child: descriptor_table_size=%d, current fd count=%d, reserve=%d, fd=%d\n",
descriptor_table_size, dtable_count, FD_RESERVE, fd);
#endif /* DEBUG_PROXY */
// Close the conn if we are out of file descriptors, or libevent will crash us, @see pxy_conn_setup() for explanation
@ -969,11 +985,11 @@ pxy_listener_acceptcb_child(UNUSED struct evconnlistener *listener, evutil_socke
if (OPTS_DEBUG(ctx->conn->opts)) {
char *host, *port;
if (sys_sockaddr_str((struct sockaddr *)&ctx->conn->addr, ctx->conn->addrlen, &host, &port) == 0) {
log_dbg_printf("pxy_listener_acceptcb_child: Connecting to [%s]:%s\n", host, port);
log_dbg_printf("Child connecting to [%s]:%s\n", host, port);
free(host);
free(port);
} else {
log_dbg_printf("pxy_listener_acceptcb_child: Connecting to [?]:?\n");
log_dbg_printf("Child connecting to [?]:?\n");
}
}
@ -1004,7 +1020,7 @@ pxy_setup_child_listener(pxy_conn_ctx_t *ctx)
if (!child_evcl) {
log_err_level_printf(LOG_CRIT, "Error creating child evconnlistener: %s\n", strerror(errno));
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_setup_child_listener: Error creating child evconnlistener: %s, fd=%d, child_fd=%d\n", strerror(errno), ctx->fd, ctx->child_fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "pxy_setup_child_listener: Error creating child evconnlistener: %s, fd=%d, child_fd=%d\n", strerror(errno), ctx->fd, ctx->child_fd);
#endif /* DEBUG_PROXY */
// @attention Cannot call proxy_listener_ctx_free() on child_evcl, child_evcl does not have any ctx with next listener
@ -1047,19 +1063,19 @@ pxy_setup_child_listener(pxy_conn_ctx_t *ctx)
// @todo Port may be less than 5 chars
// SSLproxy: + + [ + addr + ] + : + p + , + [ + srchost_str + ] + : + srcport_str + , + [ + dsthost_str + ] + : + dstport_str + , + s
// SSLPROXY_KEY_LEN + 1 + 1 + strlen(addr) + 1 + 1 + 5 + 1 + 1 + strlen(ctx->srchost_str) + 1 + 1 + strlen(ctx->srcport_str) + 1 + 1 + strlen(ctx->dsthost_str) + 1 + 1 + strlen(ctx->dstport_str) + 1 + 1
ctx->header_len = SSLPROXY_KEY_LEN + strlen(addr) + strlen(ctx->srchost_str) + strlen(ctx->srcport_str) + strlen(ctx->dsthost_str) + strlen(ctx->dstport_str) + 19;
ctx->sslproxy_header_len = SSLPROXY_KEY_LEN + strlen(addr) + strlen(ctx->srchost_str) + strlen(ctx->srcport_str) + strlen(ctx->dsthost_str) + strlen(ctx->dstport_str) + 19;
// @todo Always check malloc retvals. Should we close the conn if malloc fails?
// +1 for NULL
ctx->header_str = malloc(ctx->header_len + 1);
if (!ctx->header_str) {
ctx->sslproxy_header = malloc(ctx->sslproxy_header_len + 1);
if (!ctx->sslproxy_header) {
pxy_conn_free(ctx, 1);
return -1;
}
// printf(3): "snprintf() will write at most size-1 of the characters (the size'th character then gets the terminating NULL)"
// So, +1 for NULL
snprintf(ctx->header_str, ctx->header_len + 1, "%s [%s]:%u,[%s]:%s,[%s]:%s,%s",
snprintf(ctx->sslproxy_header, ctx->sslproxy_header_len + 1, "%s [%s]:%u,[%s]:%s,[%s]:%s,%s",
SSLPROXY_KEY, addr, ntohs(child_listener_addr.sin_port), STRORNONE(ctx->srchost_str), STRORNONE(ctx->srcport_str),
STRORNONE(ctx->dsthost_str), STRORNONE(ctx->dstport_str), ctx->spec->ssl ? "s":"p");
return 0;
@ -1128,7 +1144,7 @@ pxy_try_disconnect_child(pxy_conn_child_ctx_t *ctx, pxy_conn_desc_t *this,
this->bev = NULL;
if (other->closed) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_try_disconnect_child: other->closed, terminate conn, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_try_disconnect_child: other->closed, terminate conn, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
// Uses only ctx to log disconnect, never any of the bevs
@ -1144,7 +1160,7 @@ pxy_try_consume_last_input(struct bufferevent *bev, pxy_conn_ctx_t *ctx)
* handle it here, otherwise it will be lost. */
if (evbuffer_get_length(bufferevent_get_input(bev))) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_try_consume_last_input: evbuffer_get_length(inbuf) > 0, terminate conn, fd=%d\n", ctx->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "pxy_try_consume_last_input: evbuffer_get_length(inbuf) > 0, terminate conn, fd=%d\n", ctx->fd);
#endif /* DEBUG_PROXY */
ctx->protoctx->bev_readcb(bev, ctx);
@ -1158,7 +1174,7 @@ pxy_try_consume_last_input_child(struct bufferevent *bev, pxy_conn_child_ctx_t *
* handle it here, otherwise it will be lost. */
if (evbuffer_get_length(bufferevent_get_input(bev))) {
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_try_consume_last_input_child: evbuffer_get_length(inbuf) > 0, terminate conn, fd=%d, conn fd=%d\n", ctx->fd, ctx->conn->fd);
log_dbg_level_printf(LOG_DBG_MODE_FINE, "pxy_try_consume_last_input_child: evbuffer_get_length(inbuf) > 0, terminate conn, child fd=%d, fd=%d\n", ctx->fd, ctx->conn->fd);
#endif /* DEBUG_PROXY */
ctx->protoctx->bev_readcb(bev, ctx);
@ -1288,6 +1304,7 @@ pxy_bev_eventcb(struct bufferevent *bev, short events, void *arg)
// Passthrough proto does its own connect logging
if (ctx->proto != PROTO_PASSTHROUGH) {
if (bev == ctx->src.bev) {
// @todo When do we reach here? If proto is autossl? Otherwise, src is connected in acceptcb.
pxy_log_connect_src(ctx);
} else if (ctx->connected) {
if (pxy_prepare_logging(ctx) == -1) {
@ -1409,12 +1426,13 @@ pxy_conn_setup(evutil_socket_t fd,
char *host, *port;
if (sys_sockaddr_str(peeraddr, peeraddrlen, &host, &port) == 0) {
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_conn_setup: Peer=[%s]:%s, fd=%d\n", host, port, fd);
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_conn_setup: peer addr=[%s]:%s, fd=%d\n", host, port, fd);
free(host);
free(port);
}
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_conn_setup: descriptor_table_size=%d, current fd count=%d, reserve=%d\n", descriptor_table_size, dtable_count, FD_RESERVE);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_conn_setup: descriptor_table_size=%d, current fd count=%d, reserve=%d\n",
descriptor_table_size, dtable_count, FD_RESERVE);
#endif /* DEBUG_PROXY */
// Close the conn if we are out of file descriptors, or libevent will crash us

@ -48,7 +48,6 @@
#define STRORNONE(x) (((x)&&*(x))?(x):"")
#define WANT_CONNECT_LOG(ctx) ((ctx)->opts->connectlog||!(ctx)->opts->detach)
// XXX: Remove passthrough condition?
#define WANT_CONTENT_LOG(ctx) ((ctx)->opts->contentlog&&((ctx)->proto!=PROTO_PASSTHROUGH))
#define SSLPROXY_KEY "SSLproxy:"
@ -224,10 +223,10 @@ struct pxy_conn_ctx {
evutil_socket_t child_fd;
struct evconnlistener *child_evcl;
// SSL proxy specific info: The IP:port address the children are listening on, orig client addr, and orig target addr
char *header_str;
size_t header_len;
int sent_header;
// SSL proxy specific info: ip:port address the children are listening on, orig client addr, and orig target addr
char *sslproxy_header;
size_t sslproxy_header_len;
int sent_sslproxy_header;
// Child list of the conn
pxy_conn_child_ctx_t *children;
@ -284,7 +283,7 @@ struct pxy_conn_child_ctx {
evutil_socket_t src_fd;
evutil_socket_t dst_fd;
int removed_header;
int removed_sslproxy_header;
// Child index
unsigned int idx;

@ -119,6 +119,7 @@ static void
pxy_ssl_shutdown_cb(evutil_socket_t fd, UNUSED short what, void *arg)
{
pxy_ssl_shutdown_ctx_t *ctx = arg;
// @attention Increasing the delay to 500 or more fixes some ssl shutdown failures, they report SSL_ERROR_WANT_READ before eventually succeeding
// @todo Can/should we set an adaptive delay per conn here? Does it matter?
struct timeval retry_delay = {0, 100};
@ -147,9 +148,11 @@ pxy_ssl_shutdown_cb(evutil_socket_t fd, UNUSED short what, void *arg)
}
sslerr = SSL_get_error(ctx->ssl, rv);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINEST, "pxy_ssl_shutdown_cb: %s, retries=%d, fd=%d\n", pxy_ssl_shutdown_get_sslerr_name(sslerr), ctx->retries, fd);
#endif /* DEBUG_PROXY */
switch (sslerr) {
case SSL_ERROR_WANT_READ:
want = EV_READ;
@ -165,8 +168,9 @@ pxy_ssl_shutdown_cb(evutil_socket_t fd, UNUSED short what, void *arg)
default:
log_err_level_printf(LOG_CRIT, "Unhandled SSL_shutdown() error %i. Closing fd\n", sslerr);
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "Unhandled SSL_shutdown() error %i. Closing fd, fd=%d\n", sslerr, fd);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_ssl_shutdown_cb: Unhandled SSL_shutdown() error %i. Closing fd, fd=%d\n", sslerr, fd);
#endif /* DEBUG_PROXY */
goto complete;
}
goto complete;
@ -175,28 +179,31 @@ retry:
if (ctx->retries++ >= 50) {
log_err_level_printf(LOG_WARNING, "Failed to shutdown SSL connection cleanly: Max retries reached. Closing fd\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "WARNING: Failed to shutdown SSL connection cleanly: Max retries reached. Closing fd, fd=%d\n", fd);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_ssl_shutdown_cb: Failed to shutdown SSL connection cleanly: Max retries reached. Closing fd, fd=%d\n", fd);
#endif /* DEBUG_PROXY */
goto complete;
}
ctx->ev = event_new(ctx->evbase, fd, want, pxy_ssl_shutdown_cb, ctx);
if (ctx->ev) {
event_add(ctx->ev, &retry_delay);
return;
}
log_err_printf("Failed to shutdown SSL connection cleanly: Cannot create event. Closing fd\n");
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "ERROR: Failed to shutdown SSL connection cleanly: Cannot create event. Closing fd, fd=%d\n", fd);
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_ssl_shutdown_cb: Failed to shutdown SSL connection cleanly: Cannot create event. Closing fd, fd=%d\n", fd);
#endif /* DEBUG_PROXY */
complete:
if (OPTS_DEBUG(ctx->opts)) {
char *msg;
if (asprintf(&msg, "pxy_ssl_shutdown_cb: fd=%d, SSL_free() in state ", fd) != -1) {
log_dbg_print_free(ssl_ssl_state_to_str(ctx->ssl, msg));
free(msg);
}
log_dbg_print_free(ssl_ssl_state_to_str(ctx->ssl, "SSL_free() in state "));
}
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_ssl_shutdown_cb: fd=%d, %s", fd, ssl_ssl_state_to_str(ctx->ssl, "SSL_free() in state "));
#endif /* DEBUG_PROXY */
SSL_free(ctx->ssl);
evutil_closesocket(fd);
pxy_ssl_shutdown_ctx_free(ctx);
@ -221,12 +228,12 @@ pxy_ssl_shutdown(opts_t *opts, struct event_base *evbase, SSL *ssl,
sslshutctx = pxy_ssl_shutdown_ctx_new(opts, evbase, ssl);
if (!sslshutctx) {
if (OPTS_DEBUG(opts)) {
char *msg;
if (asprintf(&msg, "pxy_ssl_shutdown: fd=%d, SSL_free() in state ", fd) != -1) {
log_dbg_print_free(ssl_ssl_state_to_str(ssl, msg));
free(msg);
}
log_dbg_print_free(ssl_ssl_state_to_str(ssl, "SSL_free() in state "));
}
#ifdef DEBUG_PROXY
log_dbg_level_printf(LOG_DBG_MODE_FINER, "pxy_ssl_shutdown: fd=%d, %s", fd, ssl_ssl_state_to_str(ssl, "SSL_free() in state "));
#endif /* DEBUG_PROXY */
SSL_free(ssl);
evutil_closesocket(fd);
return;

Loading…
Cancel
Save