summary |
shortlog |
log |
commit | commitdiff |
tree
raw |
patch |
inline | side by side (from parent 1:
72b3135)
All messages from UTCP itself are now of the form:
timestamp srcport:dstport foo 123 bar 456 ...
The UNIX timestamp is wall clock time, to allow data from multiple
computers that are synchronised via NTP to be correlated.
Only part of the payload is now dumped by default to make the logs more
easily readable.
The test program now also adds the same format timestamp to its debug
messages.
int reorder_countdown;
#if UTCP_DEBUG
int reorder_countdown;
#if UTCP_DEBUG
-void debug(const char *format, ...) {
- struct timeval now;
- gettimeofday(&now, NULL);
- fprintf(stderr, "%lu.%lu ", now.tv_sec, now.tv_usec / 1000);
+static void debug(const char *format, ...) {
+ struct timespec tv;
+ char buf[1024];
+ int len;
+
+ clock_gettime(CLOCK_REALTIME, &tv);
+ len = snprintf(buf, sizeof(buf), "%ld.%06lu ", (long)tv.tv_sec, tv.tv_nsec / 1000);
va_list ap;
va_start(ap, format);
va_list ap;
va_start(ap, format);
- vfprintf(stderr, format, ap);
+ len += vsnprintf(buf + len, sizeof(buf) - len, format, ap);
+
+ if(len > 0 && (size_t)len < sizeof(buf)) {
+ fwrite(buf, len, 1, stderr);
+ }
}
#else
#define debug(...) do {} while(0)
}
#else
#define debug(...) do {} while(0)
- fprintf(stderr, "Using MTU %lu\n", mtu);
+ debug("Using MTU %lu\n", mtu);
utcp_set_mtu(u, mtu ? mtu - 48 : 1300);
}
utcp_set_mtu(u, mtu ? mtu - 48 : 1300);
}
if(fds[0].revents) {
fds[0].revents = 0;
if(fds[0].revents) {
fds[0].revents = 0;
ssize_t len = read(0, buf, max);
ssize_t len = read(0, buf, max);
+ debug("stdin %zd\n", len);
if(len <= 0) {
fds[0].fd = -1;
if(len <= 0) {
fds[0].fd = -1;
if(fds[1].revents) {
fds[1].revents = 0;
if(fds[1].revents) {
fds[1].revents = 0;
struct sockaddr_storage ss;
socklen_t sl = sizeof(ss);
int len = recvfrom(s, buf, sizeof(buf), MSG_DONTWAIT, (struct sockaddr *)&ss, &sl);
struct sockaddr_storage ss;
socklen_t sl = sizeof(ss);
int len = recvfrom(s, buf, sizeof(buf), MSG_DONTWAIT, (struct sockaddr *)&ss, &sl);
+ debug("netin %zu\n", len);
if(len <= 0) {
debug("Error receiving UDP packet: %s\n", strerror(errno));
if(len <= 0) {
debug("Error receiving UDP packet: %s\n", strerror(errno));
#include <unistd.h>
#include <sys/time.h>
#include <sys/socket.h>
#include <unistd.h>
#include <sys/time.h>
#include <sys/socket.h>
#ifdef UTCP_DEBUG
#include <stdarg.h>
#ifdef UTCP_DEBUG
#include <stdarg.h>
-static void debug(const char *format, ...) {
+#ifndef UTCP_DEBUG_DATALEN
+#define UTCP_DEBUG_DATALEN 20
+#endif
+
+static void debug(struct utcp_connection *c, const char *format, ...) {
+ struct timespec tv;
+ char buf[1024];
+ int len;
+
+ clock_gettime(CLOCK_REALTIME, &tv);
+ len = snprintf(buf, sizeof(buf), "%ld.%06lu %u:%u ", (long)tv.tv_sec, tv.tv_nsec / 1000, c ? c->src : 0, c ? c->dst : 0);
va_list ap;
va_start(ap, format);
va_list ap;
va_start(ap, format);
- vfprintf(stderr, format, ap);
+ len += vsnprintf(buf + len, sizeof(buf) - len, format, ap);
+
+ if(len > 0 && (size_t)len < sizeof(buf)) {
+ fwrite(buf, len, 1, stderr);
+ }
-static void print_packet(struct utcp *utcp, const char *dir, const void *pkt, size_t len) {
+static void print_packet(struct utcp_connection *c, const char *dir, const void *pkt, size_t len) {
struct hdr hdr;
if(len < sizeof(hdr)) {
struct hdr hdr;
if(len < sizeof(hdr)) {
- debug("%p %s: short packet (%lu bytes)\n", utcp, dir, (unsigned long)len);
+ debug(c, "%s: short packet (%lu bytes)\n", dir, (unsigned long)len);
return;
}
memcpy(&hdr, pkt, sizeof(hdr));
return;
}
memcpy(&hdr, pkt, sizeof(hdr));
- debug("%p %s: len=%lu, src=%u dst=%u seq=%u ack=%u wnd=%u aux=%x ctl=", utcp, dir, (unsigned long)len, hdr.src, hdr.dst, hdr.seq, hdr.ack, hdr.wnd, hdr.aux);
- if(hdr.ctl & SYN) {
- debug("SYN");
- }
- if(hdr.ctl & RST) {
- debug("RST");
- }
-
- if(hdr.ctl & FIN) {
- debug("FIN");
- }
-
- if(hdr.ctl & ACK) {
- debug("ACK");
+ if(len > sizeof(hdr)) {
+ datalen = min(len - sizeof(hdr), UTCP_DEBUG_DATALEN);
+ } else {
+ datalen = 0;
- if(len > sizeof(hdr)) {
- uint32_t datalen = len - sizeof(hdr);
- const uint8_t *data = (uint8_t *)pkt + sizeof(hdr);
- char str[datalen * 2 + 1];
- char *p = str;
- for(uint32_t i = 0; i < datalen; i++) {
- *p++ = "0123456789ABCDEF"[data[i] >> 4];
- *p++ = "0123456789ABCDEF"[data[i] & 15];
- }
+ const uint8_t *data = (uint8_t *)pkt + sizeof(hdr);
+ char str[datalen * 2 + 1];
+ char *p = str;
- *p = 0;
-
- debug(" data=%s", str);
+ for(uint32_t i = 0; i < datalen; i++) {
+ *p++ = "0123456789ABCDEF"[data[i] >> 4];
+ *p++ = "0123456789ABCDEF"[data[i] & 15];
+ *p = 0;
+
+ debug(c, "%s: len %lu src %u dst %u seq %u ack %u wnd %u aux %x ctl %s%s%s%s data %s\n",
+ dir, (unsigned long)len, hdr.src, hdr.dst, hdr.seq, hdr.ack, hdr.wnd, hdr.aux,
+ hdr.ctl & SYN ? "SYN" : "",
+ hdr.ctl & RST ? "RST" : "",
+ hdr.ctl & FIN ? "FIN" : "",
+ hdr.ctl & ACK ? "ACK" : "",
+ str
+ );
}
static void debug_cwnd(struct utcp_connection *c) {
}
static void debug_cwnd(struct utcp_connection *c) {
- debug("snd.cwnd = %u\n", c->snd.cwnd);
+ debug(c, "snd.cwnd %u snd.ssthresh %u\n", c->snd.cwnd, c->snd.ssthresh);
}
#else
#define debug(...) do {} while(0)
}
#else
#define debug(...) do {} while(0)
timerclear(&c->conn_timeout);
}
timerclear(&c->conn_timeout);
}
- debug("%p new state: %s\n", c->utcp, strstate[state]);
+ debug(c, "state %s\n", strstate[state]);
}
static bool fin_wanted(struct utcp_connection *c, uint32_t seq) {
}
static bool fin_wanted(struct utcp_connection *c, uint32_t seq) {
// Store data into the buffer
static ssize_t buffer_put_at(struct buffer *buf, size_t offset, const void *data, size_t len) {
// Store data into the buffer
static ssize_t buffer_put_at(struct buffer *buf, size_t offset, const void *data, size_t len) {
- debug("buffer_put_at %lu %lu %lu\n", (unsigned long)buf->used, (unsigned long)offset, (unsigned long)len);
+ debug(NULL, "buffer_put_at %lu %lu %lu\n", (unsigned long)buf->used, (unsigned long)offset, (unsigned long)len);
size_t required = offset + len;
size_t required = offset + len;
c->snd.nxt = c->snd.iss + 1;
c->snd.last = c->snd.nxt;
c->snd.cwnd = (utcp->mtu > 2190 ? 2 : utcp->mtu > 1095 ? 3 : 4) * utcp->mtu;
c->snd.nxt = c->snd.iss + 1;
c->snd.last = c->snd.nxt;
c->snd.cwnd = (utcp->mtu > 2190 ? 2 : utcp->mtu > 1095 ? 3 : 4) * utcp->mtu;
+#if UTCP_DEBUG
+ c->snd.ssthresh = c->sndbuf.maxsize;
+#else
debug_cwnd(c);
c->utcp = utcp;
debug_cwnd(c);
c->utcp = utcp;
// Update RTT variables. See RFC 6298.
static void update_rtt(struct utcp_connection *c, uint32_t rtt) {
if(!rtt) {
// Update RTT variables. See RFC 6298.
static void update_rtt(struct utcp_connection *c, uint32_t rtt) {
if(!rtt) {
- debug("invalid rtt\n");
+ debug(c, "invalid rtt\n");
- debug("rtt %u srtt %u rttvar %u rto %u\n", rtt, utcp->srtt, utcp->rttvar, utcp->rto);
+ debug(c, "rtt %u srtt %u rttvar %u rto %u\n", rtt, utcp->srtt, utcp->rttvar, utcp->rto);
}
static void start_retransmit_timer(struct utcp_connection *c) {
}
static void start_retransmit_timer(struct utcp_connection *c) {
c->rtrx_timeout.tv_sec++;
}
c->rtrx_timeout.tv_sec++;
}
- debug("timeout set to %lu.%06lu (%u)\n", c->rtrx_timeout.tv_sec, c->rtrx_timeout.tv_usec, c->utcp->rto);
+ debug(c, "rtrx_timeout %ld.%06lu\n", c->rtrx_timeout.tv_sec, c->rtrx_timeout.tv_usec);
}
static void stop_retransmit_timer(struct utcp_connection *c) {
timerclear(&c->rtrx_timeout);
}
static void stop_retransmit_timer(struct utcp_connection *c) {
timerclear(&c->rtrx_timeout);
- debug("timeout cleared\n");
+ debug(c, "rtrx_timeout cleared\n");
}
struct utcp_connection *utcp_connect_ex(struct utcp *utcp, uint16_t dst, utcp_recv_t recv, void *priv, uint32_t flags) {
}
struct utcp_connection *utcp_connect_ex(struct utcp *utcp, uint16_t dst, utcp_recv_t recv, void *priv, uint32_t flags) {
- print_packet(utcp, "send", &pkt, sizeof(pkt));
+ print_packet(c, "send", &pkt, sizeof(pkt));
utcp->send(utcp, &pkt, sizeof(pkt));
gettimeofday(&c->conn_timeout, NULL);
utcp->send(utcp, &pkt, sizeof(pkt));
gettimeofday(&c->conn_timeout, NULL);
void utcp_accept(struct utcp_connection *c, utcp_recv_t recv, void *priv) {
if(c->reapable || c->state != SYN_RECEIVED) {
void utcp_accept(struct utcp_connection *c, utcp_recv_t recv, void *priv) {
if(c->reapable || c->state != SYN_RECEIVED) {
- debug("Error: accept() called on invalid connection %p in state %s\n", c, strstate[c->state]);
+ debug(c, "accept() called on invalid connection in state %s\n", c, strstate[c->state]);
- debug("%p accepted, %p %p\n", c, recv, priv);
+ debug(c, "accepted %p %p\n", c, recv, priv);
c->recv = recv;
c->priv = priv;
set_state(c, ESTABLISHED);
c->recv = recv;
c->priv = priv;
set_state(c, ESTABLISHED);
- debug("cwndleft = %d, left = %d\n", cwndleft, left);
+ debug(c, "cwndleft %d left %d\n", cwndleft, left);
if(!left && !sendatleastone) {
return;
if(!left && !sendatleastone) {
return;
// Start RTT measurement
gettimeofday(&c->rtt_start, NULL);
c->rtt_seq = pkt->hdr.seq + seglen;
// Start RTT measurement
gettimeofday(&c->rtt_start, NULL);
c->rtt_seq = pkt->hdr.seq + seglen;
- debug("Starting RTT measurement, expecting ack %u\n", c->rtt_seq);
+ debug(c, "starting RTT measurement, expecting ack %u\n", c->rtt_seq);
- print_packet(c->utcp, "send", pkt, sizeof(pkt->hdr) + seglen);
+ print_packet(c, "send", pkt, sizeof(pkt->hdr) + seglen);
c->utcp->send(c->utcp, pkt, sizeof(pkt->hdr) + seglen);
} while(left);
c->utcp->send(c->utcp, pkt, sizeof(pkt->hdr) + seglen);
} while(left);
ssize_t utcp_send(struct utcp_connection *c, const void *data, size_t len) {
if(c->reapable) {
ssize_t utcp_send(struct utcp_connection *c, const void *data, size_t len) {
if(c->reapable) {
- debug("Error: send() called on closed connection %p\n", c);
+ debug(c, "send() called on closed connection\n");
errno = EBADF;
return -1;
}
errno = EBADF;
return -1;
}
switch(c->state) {
case CLOSED:
case LISTEN:
switch(c->state) {
case CLOSED:
case LISTEN:
- debug("Error: send() called on unconnected connection %p\n", c);
+ debug(c, "send() called on unconnected connection\n");
errno = ENOTCONN;
return -1;
errno = ENOTCONN;
return -1;
case CLOSING:
case LAST_ACK:
case TIME_WAIT:
case CLOSING:
case LAST_ACK:
case TIME_WAIT:
- debug("Error: send() called on closing connection %p\n", c);
+ debug(c, "send() called on closed connection\n");
errno = EPIPE;
return -1;
}
errno = EPIPE;
return -1;
}
static void fast_retransmit(struct utcp_connection *c) {
if(c->state == CLOSED || c->snd.last == c->snd.una) {
static void fast_retransmit(struct utcp_connection *c) {
if(c->state == CLOSED || c->snd.last == c->snd.una) {
- debug("fast_retransmit() called but nothing to retransmit!\n");
+ debug(c, "fast_retransmit() called but nothing to retransmit!\n");
}
buffer_copy(&c->sndbuf, pkt->data, 0, len);
}
buffer_copy(&c->sndbuf, pkt->data, 0, len);
- print_packet(c->utcp, "rtrx", pkt, sizeof(pkt->hdr) + len);
+ print_packet(c, "rtrx", pkt, sizeof(pkt->hdr) + len);
utcp->send(utcp, pkt, sizeof(pkt->hdr) + len);
break;
utcp->send(utcp, pkt, sizeof(pkt->hdr) + len);
break;
static void retransmit(struct utcp_connection *c) {
if(c->state == CLOSED || c->snd.last == c->snd.una) {
static void retransmit(struct utcp_connection *c) {
if(c->state == CLOSED || c->snd.last == c->snd.una) {
- debug("Retransmit() called but nothing to retransmit!\n");
+ debug(c, "retransmit() called but nothing to retransmit!\n");
stop_retransmit_timer(c);
return;
}
stop_retransmit_timer(c);
return;
}
pkt->data[1] = 0;
pkt->data[2] = 0;
pkt->data[3] = c->flags & 0x7;
pkt->data[1] = 0;
pkt->data[2] = 0;
pkt->data[3] = c->flags & 0x7;
- print_packet(c->utcp, "rtrx", pkt, sizeof(pkt->hdr) + 4);
+ print_packet(c, "rtrx", pkt, sizeof(pkt->hdr) + 4);
utcp->send(utcp, pkt, sizeof(pkt->hdr) + 4);
break;
utcp->send(utcp, pkt, sizeof(pkt->hdr) + 4);
break;
pkt->hdr.seq = c->snd.nxt;
pkt->hdr.ack = c->rcv.nxt;
pkt->hdr.ctl = SYN | ACK;
pkt->hdr.seq = c->snd.nxt;
pkt->hdr.ack = c->rcv.nxt;
pkt->hdr.ctl = SYN | ACK;
- print_packet(c->utcp, "rtrx", pkt, sizeof(pkt->hdr));
+ print_packet(c, "rtrx", pkt, sizeof(pkt->hdr));
utcp->send(utcp, pkt, sizeof(pkt->hdr));
break;
utcp->send(utcp, pkt, sizeof(pkt->hdr));
break;
debug_cwnd(c);
buffer_copy(&c->sndbuf, pkt->data, 0, len);
debug_cwnd(c);
buffer_copy(&c->sndbuf, pkt->data, 0, len);
- print_packet(c->utcp, "rtrx", pkt, sizeof(pkt->hdr) + len);
+ print_packet(c, "rtrx", pkt, sizeof(pkt->hdr) + len);
utcp->send(utcp, pkt, sizeof(pkt->hdr) + len);
break;
utcp->send(utcp, pkt, sizeof(pkt->hdr) + len);
break;
* - the SACK entry is completely before ^, in that case delete it.
*/
static void sack_consume(struct utcp_connection *c, size_t len) {
* - the SACK entry is completely before ^, in that case delete it.
*/
static void sack_consume(struct utcp_connection *c, size_t len) {
- debug("sack_consume %lu\n", (unsigned long)len);
+ debug(c, "sack_consume %lu\n", (unsigned long)len);
if(len > c->rcvbuf.used) {
if(len > c->rcvbuf.used) {
- debug("All SACK entries consumed");
+ debug(c, "all SACK entries consumed\n");
c->sacks[0].len = 0;
return;
}
c->sacks[0].len = 0;
return;
}
}
for(int i = 0; i < NSACKS && c->sacks[i].len; i++) {
}
for(int i = 0; i < NSACKS && c->sacks[i].len; i++) {
- debug("SACK[%d] offset %u len %u\n", i, c->sacks[i].offset, c->sacks[i].len);
+ debug(c, "SACK[%d] offset %u len %u\n", i, c->sacks[i].offset, c->sacks[i].len);
}
}
static void handle_out_of_order(struct utcp_connection *c, uint32_t offset, const void *data, size_t len) {
}
}
static void handle_out_of_order(struct utcp_connection *c, uint32_t offset, const void *data, size_t len) {
- debug("out of order packet, offset %u\n", offset);
+ debug(c, "out of order packet, offset %u\n", offset);
// Packet loss or reordering occured. Store the data in the buffer.
ssize_t rxd = buffer_put_at(&c->rcvbuf, offset, data, len);
// Packet loss or reordering occured. Store the data in the buffer.
ssize_t rxd = buffer_put_at(&c->rcvbuf, offset, data, len);
// Make note of where we put it.
for(int i = 0; i < NSACKS; i++) {
if(!c->sacks[i].len) { // nothing to merge, add new entry
// Make note of where we put it.
for(int i = 0; i < NSACKS; i++) {
if(!c->sacks[i].len) { // nothing to merge, add new entry
- debug("New SACK entry %d\n", i);
+ debug(c, "new SACK entry %d\n", i);
c->sacks[i].offset = offset;
c->sacks[i].len = rxd;
break;
} else if(offset < c->sacks[i].offset) {
if(offset + rxd < c->sacks[i].offset) { // insert before
if(!c->sacks[NSACKS - 1].len) { // only if room left
c->sacks[i].offset = offset;
c->sacks[i].len = rxd;
break;
} else if(offset < c->sacks[i].offset) {
if(offset + rxd < c->sacks[i].offset) { // insert before
if(!c->sacks[NSACKS - 1].len) { // only if room left
- debug("Insert SACK entry at %d\n", i);
+ debug(c, "insert SACK entry at %d\n", i);
memmove(&c->sacks[i + 1], &c->sacks[i], (NSACKS - i - 1) * sizeof(c->sacks)[i]);
c->sacks[i].offset = offset;
c->sacks[i].len = rxd;
} else {
memmove(&c->sacks[i + 1], &c->sacks[i], (NSACKS - i - 1) * sizeof(c->sacks)[i]);
c->sacks[i].offset = offset;
c->sacks[i].len = rxd;
} else {
- debug("SACK entries full, dropping packet\n");
+ debug(c, "SACK entries full, dropping packet\n");
}
break;
} else { // merge
}
break;
} else { // merge
- debug("Merge with start of SACK entry at %d\n", i);
+ debug(c, "merge with start of SACK entry at %d\n", i);
c->sacks[i].offset = offset;
break;
}
} else if(offset <= c->sacks[i].offset + c->sacks[i].len) {
if(offset + rxd > c->sacks[i].offset + c->sacks[i].len) { // merge
c->sacks[i].offset = offset;
break;
}
} else if(offset <= c->sacks[i].offset + c->sacks[i].len) {
if(offset + rxd > c->sacks[i].offset + c->sacks[i].len) { // merge
- debug("Merge with end of SACK entry at %d\n", i);
+ debug(c, "merge with end of SACK entry at %d\n", i);
c->sacks[i].len = offset + rxd - c->sacks[i].offset;
// TODO: handle potential merge with next entry
}
c->sacks[i].len = offset + rxd - c->sacks[i].offset;
// TODO: handle potential merge with next entry
}
}
for(int i = 0; i < NSACKS && c->sacks[i].len; i++) {
}
for(int i = 0; i < NSACKS && c->sacks[i].len; i++) {
- debug("SACK[%d] offset %u len %u\n", i, c->sacks[i].offset, c->sacks[i].len);
+ debug(c, "SACK[%d] offset %u len %u\n", i, c->sacks[i].offset, c->sacks[i].len);
}
}
static void handle_in_order(struct utcp_connection *c, const void *data, size_t len) {
// Check if we can process out-of-order data now.
if(c->sacks[0].len && len >= c->sacks[0].offset) { // TODO: handle overlap with second SACK
}
}
static void handle_in_order(struct utcp_connection *c, const void *data, size_t len) {
// Check if we can process out-of-order data now.
if(c->sacks[0].len && len >= c->sacks[0].offset) { // TODO: handle overlap with second SACK
- debug("incoming packet len %lu connected with SACK at %u\n", (unsigned long)len, c->sacks[0].offset);
+ debug(c, "incoming packet len %lu connected with SACK at %u\n", (unsigned long)len, c->sacks[0].offset);
buffer_put_at(&c->rcvbuf, 0, data, len); // TODO: handle return value
len = max(len, c->sacks[0].offset + c->sacks[0].len);
data = c->rcvbuf.data;
buffer_put_at(&c->rcvbuf, 0, data, len); // TODO: handle return value
len = max(len, c->sacks[0].offset + c->sacks[0].len);
data = c->rcvbuf.data;
- print_packet(utcp, "recv", data, len);
-
// Drop packets smaller than the header
struct hdr hdr;
if(len < sizeof(hdr)) {
// Drop packets smaller than the header
struct hdr hdr;
if(len < sizeof(hdr)) {
+ print_packet(NULL, "recv", data, len);
errno = EBADMSG;
return -1;
}
errno = EBADMSG;
return -1;
}
// Make a copy from the potentially unaligned data to a struct hdr
memcpy(&hdr, ptr, sizeof(hdr));
// Make a copy from the potentially unaligned data to a struct hdr
memcpy(&hdr, ptr, sizeof(hdr));
+
+ // Try to match the packet to an existing connection
+
+ struct utcp_connection *c = find_connection(utcp, hdr.dst, hdr.src);
+ print_packet(c, "recv", data, len);
+
+ // Process the header
+
ptr += sizeof(hdr);
len -= sizeof(hdr);
// Drop packets with an unknown CTL flag
if(hdr.ctl & ~(SYN | ACK | RST | FIN)) {
ptr += sizeof(hdr);
len -= sizeof(hdr);
// Drop packets with an unknown CTL flag
if(hdr.ctl & ~(SYN | ACK | RST | FIN)) {
+ print_packet(NULL, "recv", data, len);
errno = EBADMSG;
return -1;
}
errno = EBADMSG;
return -1;
}
bool has_data = len || (hdr.ctl & (SYN | FIN));
bool has_data = len || (hdr.ctl & (SYN | FIN));
- // Try to match the packet to an existing connection
-
- struct utcp_connection *c = find_connection(utcp, hdr.dst, hdr.src);
-
// Is it for a new connection?
if(!c) {
// Is it for a new connection?
if(!c) {
pkt.data[1] = 0;
pkt.data[2] = 0;
pkt.data[3] = c->flags & 0x7;
pkt.data[1] = 0;
pkt.data[2] = 0;
pkt.data[3] = c->flags & 0x7;
- print_packet(c->utcp, "send", &pkt, sizeof(hdr) + 4);
+ print_packet(c, "send", &pkt, sizeof(hdr) + 4);
utcp->send(utcp, &pkt, sizeof(hdr) + 4);
} else {
pkt.hdr.aux = 0;
utcp->send(utcp, &pkt, sizeof(hdr) + 4);
} else {
pkt.hdr.aux = 0;
- print_packet(c->utcp, "send", &pkt, sizeof(hdr));
+ print_packet(c, "send", &pkt, sizeof(hdr));
utcp->send(utcp, &pkt, sizeof(hdr));
}
} else {
utcp->send(utcp, &pkt, sizeof(hdr));
}
} else {
- debug("%p state %s\n", c->utcp, strstate[c->state]);
+ debug(c, "state %s\n", strstate[c->state]);
// In case this is for a CLOSED connection, ignore the packet.
// TODO: make it so incoming packets can never match a CLOSED connection.
if(c->state == CLOSED) {
// In case this is for a CLOSED connection, ignore the packet.
// TODO: make it so incoming packets can never match a CLOSED connection.
if(c->state == CLOSED) {
- debug("Got packet for closed connection\n");
+ debug(c, "got packet for closed connection\n");
- debug("Packet not acceptable, %u <= %u + %lu < %u\n", c->rcv.nxt, hdr.seq, (unsigned long)len, c->rcv.nxt + c->rcvbuf.maxsize);
+ debug(c, "packet not acceptable, %u <= %u + %lu < %u\n", c->rcv.nxt, hdr.seq, (unsigned long)len, c->rcv.nxt + c->rcvbuf.maxsize);
// Ignore unacceptable RST packets.
if(hdr.ctl & RST) {
// Ignore unacceptable RST packets.
if(hdr.ctl & RST) {
}
if(hdr.ctl & ACK && (seqdiff(hdr.ack, c->snd.last) > 0 || seqdiff(hdr.ack, c->snd.una) < 0)) {
}
if(hdr.ctl & ACK && (seqdiff(hdr.ack, c->snd.last) > 0 || seqdiff(hdr.ack, c->snd.una) < 0)) {
- debug("Packet ack seqno out of range, %u <= %u < %u\n", c->snd.una, hdr.ack, c->snd.una + c->sndbuf.used);
+ debug(c, "packet ack seqno out of range, %u <= %u < %u\n", c->snd.una, hdr.ack, c->snd.una + c->sndbuf.used);
// Ignore unacceptable RST packets.
if(hdr.ctl & RST) {
// Ignore unacceptable RST packets.
if(hdr.ctl & RST) {
update_rtt(c, diff.tv_sec * 1000000 + diff.tv_usec);
c->rtt_start.tv_sec = 0;
} else if(c->rtt_seq < hdr.ack) {
update_rtt(c, diff.tv_sec * 1000000 + diff.tv_usec);
c->rtt_start.tv_sec = 0;
} else if(c->rtt_seq < hdr.ack) {
- debug("Cancelling RTT measurement: %u < %u\n", c->rtt_seq, hdr.ack);
+ debug(c, "cancelling RTT measurement: %u < %u\n", c->rtt_seq, hdr.ack);
c->rtt_start.tv_sec = 0;
}
}
c->rtt_start.tv_sec = 0;
}
}
if(c->dupack) {
if(c->dupack >= 3) {
if(c->dupack) {
if(c->dupack >= 3) {
+ debug(c, "fast recovery ended\n");
c->snd.cwnd = c->snd.ssthresh;
}
c->snd.cwnd = c->snd.ssthresh;
}
} else {
if(!len && is_reliable(c)) {
c->dupack++;
} else {
if(!len && is_reliable(c)) {
c->dupack++;
+ debug(c, "duplicate ACK %d\n", c->dupack);
- debug("Triplicate ACK\n");
-
// RFC 5681 fast recovery
// RFC 5681 fast recovery
+ debug(c, "fast recovery started\n", c->dupack);
c->snd.ssthresh = max(c->snd.cwnd / 2, utcp->mtu * 2); // eq. 4
c->snd.cwnd = min(c->snd.ssthresh + 3 * utcp->mtu, c->sndbuf.maxsize);
c->snd.ssthresh = max(c->snd.cwnd / 2, utcp->mtu * 2); // eq. 4
c->snd.cwnd = min(c->snd.ssthresh + 3 * utcp->mtu, c->sndbuf.maxsize);
- print_packet(utcp, "send", &hdr, sizeof(hdr));
+ print_packet(c, "send", &hdr, sizeof(hdr));
utcp->send(utcp, &hdr, sizeof(hdr));
return 0;
}
int utcp_shutdown(struct utcp_connection *c, int dir) {
utcp->send(utcp, &hdr, sizeof(hdr));
return 0;
}
int utcp_shutdown(struct utcp_connection *c, int dir) {
- debug("%p shutdown %d at %u\n", c ? c->utcp : NULL, dir, c ? c->snd.last : 0);
+ debug(c, "shutdown %d at %u\n", dir, c ? c->snd.last : 0);
- debug("Error: shutdown() called on closed connection %p\n", c);
+ debug(c, "shutdown() called on closed connection\n");
errno = EBADF;
return -1;
}
errno = EBADF;
return -1;
}
- debug("Error: abort() called on closed connection %p\n", c);
+ debug(c, "abort() called on closed connection\n");
errno = EBADF;
return false;
}
errno = EBADF;
return false;
}
hdr.wnd = 0;
hdr.ctl = RST;
hdr.wnd = 0;
hdr.ctl = RST;
- print_packet(c->utcp, "send", &hdr, sizeof(hdr));
+ print_packet(c, "send", &hdr, sizeof(hdr));
c->utcp->send(c->utcp, &hdr, sizeof(hdr));
return true;
}
c->utcp->send(c->utcp, &hdr, sizeof(hdr));
return true;
}
// delete connections that have been utcp_close()d.
if(c->state == CLOSED) {
if(c->reapable) {
// delete connections that have been utcp_close()d.
if(c->state == CLOSED) {
if(c->reapable) {
- debug("Reaping %p\n", c);
free_connection(c);
i--;
}
free_connection(c);
i--;
}
}
if(timerisset(&c->rtrx_timeout) && timercmp(&c->rtrx_timeout, &now, <)) {
}
if(timerisset(&c->rtrx_timeout) && timercmp(&c->rtrx_timeout, &now, <)) {
- debug("retransmit()\n");
+ debug(c, "retransmitting after timeout\n");