fluidB
/
webdiss
1
0
Fork 0
Code Pull Requests Activity

Add trace logs to websocket code, event loop functions

Browse Source 
Mostly adding trace logs to websocket.c, but also some in http.c and
worker.c for events relating to event loop and client requests and
responses. This is useful for debugging websocket issues.
master
Jessie Murray 3 years ago
parent 5a53c31a27
commit 873f1b5902
No known key found for this signature in database
GPG Key ID: E7E4D57EDDA744C5
3 changed files with 99 additions and 28 deletions
Show Stats Download Patch File Download Diff File

23
src/http.c
Unescape Escape View File

@ -2,6 +2,7 @@
#include "server.h"
#include "worker.h"
#include "client.h"
#include "slog.h"
#include <string.h>
#include <stdlib.h>
@ -98,7 +99,12 @@ http_response_cleanup(struct http_response *r, int fd, int success) {
free(r->out);
if(!r->keep_alive || !success) {
/* Close fd is client doesn't support Keep-Alive. */
fprintf(stderr, "http_response_cleanup: keep_alive=%d, success=%d -> closing\n", r->keep_alive, success);
if (r->w && slog_enabled(r->w->s, WEBDIS_TRACE)) {
char format[] = "http_response_cleanup: keep_alive=%d, success=%d -> closing";
char cleanup_msg[sizeof(format)];
snprintf(cleanup_msg, sizeof(cleanup_msg), format, r->keep_alive ? 1 : 0, success ? 1: 0);
slog(r->w->s, WEBDIS_TRACE, cleanup_msg, 0);
}
close(fd);
}
@ -125,8 +131,19 @@ http_can_write(int fd, short event, void *p) {
if(ret > 0)
r->sent += ret;
fprintf(stderr, "http_can_write: ret=%d, r->out_sz=%lu, r->sent=%d\n",
ret, r->out_sz, r->sent);
if (r->w && slog_enabled(r->w->s, WEBDIS_TRACE)) { /* trace logs */
char format[] = "http_can_write: wrote %d, remaining=%lu, total sent=%d";
size_t contents_sz = snprintf(NULL, 0, format, ret, r->out_sz - r->sent, r->sent);
char *contents_msg = calloc(contents_sz + 1, 1);
if (contents_msg) {
snprintf(contents_msg, contents_sz + 1, format, ret, r->out_sz - r->sent, r->sent);
slog(r->w->s, WEBDIS_TRACE, contents_msg, contents_sz);
free(contents_msg);
} else {
slog(r->w->s, WEBDIS_ERROR, "Failed allocation in http_can_write", 0);
}
}
if(ret <= 0 || r->out_sz - r->sent == 0) { /* error or done */
http_response_cleanup(r, fd, (int)r->out_sz == r->sent ? 1 : 0);
} else { /* reschedule write */

98
src/websocket.c
Unescape Escape View File

@ -6,6 +6,7 @@
#include "worker.h"
#include "pool.h"
#include "http.h"
#include "slog.h"
/* message parsers */
#include "formats/json.h"
@ -219,13 +220,13 @@ ws_execute(struct http_client *c, const char *frame, size_t frame_len) {
}
static struct ws_msg *
ws_msg_new() {
fprintf(stderr, "------------ NEW -----------\n");
ws_msg_new(struct server *s) {
slog(s, WEBDIS_TRACE, "ws_msg_new", 0);
return calloc(1, sizeof(struct ws_msg));
}
static void
ws_msg_add(struct ws_msg *m, const char *p, size_t psz, const unsigned char *mask) {
ws_msg_add(struct server *s, struct ws_msg *m, const char *p, size_t psz, const unsigned char *mask) {
/* add data to frame */
size_t i;
@ -236,22 +237,35 @@ ws_msg_add(struct ws_msg *m, const char *p, size_t psz, const unsigned char *mas
for(i = 0; i < psz && mask; ++i) {
m->payload[m->payload_sz + i] = (unsigned char)p[i] ^ mask[i%4];
}
fprintf(stderr, "CONTENTS=[%.*s] (%lu)\n", (int)psz, m->payload, psz);
if (slog_enabled(s, WEBDIS_TRACE)) {
char format[] = "ws_msg_add: %lu bytes, mask_enabled=%c";
char mask_enabled = mask ? 'Y' : 'N';
size_t contents_sz = snprintf(NULL, 0, format, psz, mask_enabled);
char *contents_msg = calloc(contents_sz + 1, 1);
if (contents_msg) {
snprintf(contents_msg, contents_sz + 1, format, psz, mask_enabled);
slog(s, WEBDIS_TRACE, contents_msg, contents_sz);
free(contents_msg);
} else {
slog(s, WEBDIS_ERROR, "Failed allocation in ws_msg_add", 0);
}
}
/* save new size */
m->payload_sz += psz;
}
static void
ws_msg_free(struct ws_msg **m) {
fprintf(stderr, "------------ /FREE -----------\n");
ws_msg_free(struct server *s, struct ws_msg **m) {
slog(s, WEBDIS_TRACE, "ws_msg_free", 0);
free((*m)->payload);
free(*m);
*m = NULL;
}
static enum ws_state
ws_parse_data(const char *frame, size_t sz, struct ws_msg **msg) {
ws_parse_data(struct server *s, const char *frame, size_t sz, struct ws_msg **msg) {
int has_mask;
uint64_t len;
@ -264,15 +278,30 @@ ws_parse_data(const char *frame, size_t sz, struct ws_msg **msg) {
}
has_mask = frame[1] & 0x80 ? 1:0;
fprintf(stderr, "has_mask=%d\n", has_mask);
if (slog_enabled(s, WEBDIS_TRACE)) {
char log_mask[]= "ws_parse_data: has_mask=?";
log_mask[sizeof(log_mask)-2] = has_mask ? 'Y' : 'N'; /* -1 for \0 and -1 again for last char */
slog(s, WEBDIS_TRACE, log_mask, sizeof(log_mask)-1);
}
/* get payload length */
len = frame[1] & 0x7f; /* remove leftmost bit */
fprintf(stderr, "len=%llu\n", len);
if (slog_enabled(s, WEBDIS_TRACE)) { /* log length */
char format[] = "ws_parse_data: payload length = %llu bytes";
size_t contents_sz = snprintf(NULL, 0, format, len);
char *contents_msg = calloc(contents_sz + 1, 1);
if (contents_msg) {
snprintf(contents_msg, contents_sz + 1, format, len);
slog(s, WEBDIS_TRACE, contents_msg, contents_sz);
free(contents_msg);
} else {
slog(s, WEBDIS_ERROR, "Failed allocation in ws_parse_data", 0);
}
}
if(len <= 125) { /* data starts right after the mask */
p = frame + 2 + (has_mask ? 4 : 0);
if(has_mask) memcpy(&mask, frame + 2, sizeof(mask));
if (has_mask) fprintf(stderr, "mask= %02x %02x %02x %02x\n", mask[0], mask[1], mask[2], mask[3]);
} else if(len == 126) {
uint16_t sz16;
memcpy(&sz16, frame + 2, sizeof(uint16_t));
@ -293,15 +322,15 @@ ws_parse_data(const char *frame, size_t sz, struct ws_msg **msg) {
}
if(!*msg)
*msg = ws_msg_new();
ws_msg_add(*msg, p, len, has_mask ? mask : NULL);
*msg = ws_msg_new(s);
ws_msg_add(s, *msg, p, len, has_mask ? mask : NULL);
(*msg)->total_sz += len + (p - frame);
if(frame[0] & 0x80) { /* FIN bit set */
fprintf(stderr, "FIN bit: SET\n");
slog(s, WEBDIS_TRACE, "ws_parse_data: FIN bit set", 0);
return WS_MSG_COMPLETE;
} else {
fprintf(stderr, "FIN bit: NOT SET\n");
slog(s, WEBDIS_TRACE, "ws_parse_data: FIN bit not set", 0);
return WS_READING; /* need more data */
}
}
@ -315,32 +344,43 @@ ws_add_data(struct http_client *c) {
enum ws_state state;
state = ws_parse_data(c->buffer, c->sz, &c->frame);
state = ws_parse_data(c->s, c->buffer, c->sz, &c->frame);
while(state == WS_MSG_COMPLETE) {
int ret = ws_execute(c, c->frame->payload, c->frame->payload_sz);
fprintf(stderr, "ws_execute returned %d\n", ret);
if (slog_enabled(c->s, WEBDIS_TRACE)) {
char format[] = "ws_add_data: ws_execute(payload_sz=%lu) returned %d";
size_t contents_sz = snprintf(NULL, 0, format, c->frame->payload_sz, ret);
char *contents_msg = calloc(contents_sz + 1, 1);
if (contents_msg) {
snprintf(contents_msg, contents_sz + 1, format, c->frame->payload_sz, ret);
slog(c->s, WEBDIS_TRACE, contents_msg, contents_sz);
free(contents_msg);
} else {
slog(c->s, WEBDIS_ERROR, "Failed allocation in ws_add_data", 0);
}
}
/* remove frame from client buffer */
http_client_remove_data(c, c->frame->total_sz);
/* free frame and set back to NULL */
ws_msg_free(&c->frame);
ws_msg_free(c->s, &c->frame);
if(ret != 0) {
/* can't process frame. */
slog(c->s, WEBDIS_WARNING, "ws_add_data: ws_execute failed", 0);
return WS_ERROR;
}
fprintf(stderr, "Calling ws_parse_data again...\n");
state = ws_parse_data(c->buffer, c->sz, &c->frame);
fprintf(stderr, "ws_parse_data returned %d\n", (int)state);
slog(c->s, WEBDIS_TRACE, "ws_add_data: calling ws_parse_data again", 0);
state = ws_parse_data(c->s, c->buffer, c->sz, &c->frame);
}
return state;
}
int
ws_reply(struct cmd *cmd, const char *p, size_t sz) {
fprintf(stderr, "ws_reply: '%.*s' (%lu bytes)\n", (int)sz, p, sz);
char *frame = malloc(sz + 8); /* create frame by prepending header */
size_t frame_sz = 0;
struct http_response *r;
@ -375,7 +415,7 @@ ws_reply(struct cmd *cmd, const char *p, size_t sz) {
/* send WS frame */
r = http_response_init(cmd->w, 0, NULL);
if (1 || cmd_is_subscribe(cmd)) {
if (cmd_is_subscribe(cmd)) {
r->keep_alive = 1;
}
@ -385,6 +425,20 @@ ws_reply(struct cmd *cmd, const char *p, size_t sz) {
r->out = frame;
r->out_sz = frame_sz;
r->sent = 0;
if (slog_enabled(cmd->w->s, WEBDIS_TRACE)) {
char format[] = "ws_reply: response is %lu bytes, frame is %lu";
size_t contents_sz = snprintf(NULL, 0, format, sz, frame_sz);
char *contents_msg = calloc(contents_sz + 1, 1);
if (contents_msg) {
snprintf(contents_msg, contents_sz + 1, format, sz, frame_sz);
slog(cmd->w->s, WEBDIS_TRACE, contents_msg, contents_sz);
free(contents_msg);
} else {
slog(cmd->w->s, WEBDIS_ERROR, "Failed allocation in ws_reply", 0);
}
}
http_schedule_write(cmd->fd, r);
return 0;

6
src/worker.c
Unescape Escape View File

@ -35,13 +35,13 @@ worker_new(struct server *s) {
void
worker_can_read(int fd, short event, void *p) {
fprintf(stderr, "worker_can_read\n");
struct http_client *c = p;
int ret, nparsed;
(void)fd;
(void)event;
slog(c->w->s, WEBDIS_TRACE, "worker_can_read", 0);
ret = http_client_read(c);
if(ret <= 0) {
if((client_error_t)ret == CLIENT_DISCONNECTED) {
@ -87,11 +87,11 @@ worker_can_read(int fd, short event, void *p) {
}
if(c->broken) { /* terminate client */
fprintf(stderr, "c->broken: http_client_free()\n");
slog(c->s, WEBDIS_TRACE, "worker_can_read: c->broken, calling http_client_free", 0);
http_client_free(c);
} else {
/* start monitoring input again */
fprintf(stderr, "worker_monitor_input()\n");
slog(c->s, WEBDIS_TRACE, "worker_can_read: calling worker_monitor_input again", 0);
worker_monitor_input(c);
}
}

Write Preview
Loading…
Cancel
Save