--- a/src/server/daemon/sessionhandler.c Sat Aug 24 22:37:12 2024 +0200
+++ b/src/server/daemon/sessionhandler.c Fri Sep 13 23:19:04 2024 +0200
@@ -258,6 +258,8 @@
}
void evt_enq_conn(SessionHandler *handler, Connection *conn) {
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx enqueue connection", (unsigned long long int)conn->id);
+
Event *start_request = malloc(sizeof(Event));
if(!start_request) {
connection_destroy(conn);
@@ -273,6 +275,7 @@
EventHttpIO *io = evt_req_init(handler, conn);
if(!io) {
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx connection destroyed | evt_req_init failed", (unsigned long long int)conn->id);
connection_destroy(conn);
free(start_request);
free(event);
@@ -299,6 +302,7 @@
start_request->finish = ev_free_event;
start_request->error = 0;
if(event_send(ev, start_request)) {
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx connection destroyed | event_send failed", (unsigned long long int)conn->id);
log_ereport(LOG_FAILURE, "Cannot start request timeout: event_send failed");
evt_request_error(ev, event);
free(start_request);
@@ -375,8 +379,11 @@
EventHttpIO *io = event->cookie;
Connection *conn = io->request->connection;
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx ssl accept", (unsigned long long int)conn->id);
+
int ret = SSL_accept(conn->ssl);
if(ret <= 0) {
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx ssl accept | error", (unsigned long long int)conn->id);
int error = SSL_get_error(conn->ssl, ret);
char *errstr;
switch(error) {
@@ -421,21 +428,28 @@
conn,
buf->inbuf + buf->pos,
buf->maxsize - buf->pos);
+
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx request input | r=%d", (unsigned long long int)conn->id, r);
+
if(r <= 0) {
if(conn->ssl) {
// SSL specific error handling
switch(conn->ssl_error) {
case SSL_ERROR_WANT_READ: {
event->events = EVENT_POLLIN;
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx request input | ssl want read", (unsigned long long int)conn->id);
return 1;
}
case SSL_ERROR_WANT_WRITE: {
event->events = EVENT_POLLOUT;
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx request input | ssl want write", (unsigned long long int)conn->id);
return 1;
}
}
}
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx request input | error", (unsigned long long int)conn->id);
+
event->finish = evt_request_error;
io->error = 1;
return 0;
@@ -446,6 +460,8 @@
buf->cursize += r;
state = http_parser_process(parser);
if(state == 2) {
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx request input | http parser error", (unsigned long long int)conn->id);
+
// parse error
fatal_error(request, 400);
log_ereport(LOG_VERBOSE, "http parser: bad request");
@@ -459,6 +475,7 @@
* we need more data -> return 1 to tell the event handler to
* continue polling
*/
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx request input | event_pollin", (unsigned long long int)conn->id);
event->events = EVENT_POLLIN;
return 1;
}
@@ -472,12 +489,14 @@
}
if (fcntl(request->connection->fd, F_SETFL, flags & ~O_NONBLOCK) != 0) {
// just close the connection if fcntl fails
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx request input | fcntl error", (unsigned long long int)conn->id);
event->finish = evt_request_error;
io->error = 3;
return 0;
}
if(!http_parser_validate(parser)) {
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx request input | http parser validate error", (unsigned long long int)conn->id);
log_ereport(LOG_FAILURE, "http_parser_validate failed");
fatal_error(request, 400);
event->finish = evt_request_error;
@@ -498,6 +517,8 @@
HttpParser *parser = io->parser;
HTTPRequest *request = io->request;
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx request finish", (unsigned long long int)request->connection->id);
+
// remove timeout
if(io->watch.intdata) {
ev_watchlist_remove(h, &io->watch);
@@ -505,6 +526,7 @@
int r = handle_request(request, NULL, h);
if(r != 0) {
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx request finish | handle_request failed", (unsigned long long int)request->connection->id);
connection_destroy(request->connection);
free(request->netbuf->inbuf);
free(request->netbuf);
@@ -554,6 +576,9 @@
}
void evt_keep_alive(SessionHandler *handler, Connection *conn) {
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx keep alive", (unsigned long long int)conn->id);
+
+ conn->id++;
Event *event = malloc(sizeof(Event));
if(!event) {
connection_destroy(conn);
@@ -567,6 +592,7 @@
EventHandler *ev = ev_instance(((EventSessionHandler*)handler)->eventhandler);
if(event_send(ev, event)) {
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx connection destroyed | keep_alive event error", (unsigned long long int)conn->id);
log_ereport(LOG_FAILURE, "Keep-Alive: ev_send failed");
connection_destroy(conn);
free(event);
@@ -605,6 +631,7 @@
ioevent->finish = ev_free_event;
ioevent->cookie = keepalive;
if(ev_pollin(h, conn->fd, ioevent) != 0) {
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx connection destroyed | keep_alive_enqueue", (unsigned long long int)conn->id);
log_ereport(LOG_FAILURE, "Cannot enqueue connection");
ev_watchlist_remove(h, keepalive);
connection_destroy(conn);
@@ -626,6 +653,7 @@
// prepare http io
EventHttpIO *io = evt_req_init(conn->session_handler, conn);
if(!io) {
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx connection destroyed | keep alive input", (unsigned long long int)conn->id);
connection_destroy(conn);
return 0;
}
@@ -647,6 +675,7 @@
log_ereport(LOG_FAILURE, "sessionhandler: keep-alive timeout: cannot remove poll");
}
+ log_ereport(LOG_DEBUG, "trace reqid: %016llx connection destroyed | keep_alive timeout", (unsigned long long int)conn->id);
connection_destroy(conn);
free(ioevent);
free(item);