sipp11
/
mbsync
mirror of https://git.code.sf.net/p/isync/isync
1
0
Fork 0
Code Issues Releases Wiki Activity
Browse Source

*** socket debug

wip/socket-debug
Oswald Buddenhagen 10 years ago
parent
22ba78fa78
commit
d7dc906077
1 changed files with 46 additions and 0 deletions
Whitespace
Show all changes Ignore whitespace when comparing lines Ignore changes in amount of whitespace Ignore changes in whitespace at EOL
Unified View
Diff Options
Show Stats Download Patch File Download Diff File
  1. 46
      src/socket.c

46
src/socket.c
Unescape View File

@ -782,6 +782,7 @@ static int
prepare_read( conn_t *sock, char **buf, uint *len ) prepare_read( conn_t *sock, char **buf, uint *len )
{ {
uint n = sock->offset + sock->bytes; uint n = sock->offset + sock->bytes;
fprintf(stderr, "prepare read on top of %u at %u\n", sock->bytes, sock->offset);
if (!(*len = sizeof(sock->buf) - n)) { if (!(*len = sizeof(sock->buf) - n)) {
error( "Socket error: receive buffer full. Probably protocol error.\n" ); error( "Socket error: receive buffer full. Probably protocol error.\n" );
socket_fail( sock ); socket_fail( sock );
@ -825,6 +826,8 @@ socket_filled( conn_t *conn, uint len )
{ {
uint off = conn->offset; uint off = conn->offset;
uint cnt = conn->bytes + len; uint cnt = conn->bytes + len;
fprintf(stderr, " notifying about read of %u on top of %u at %u, wanted %u, rd sz %u\n",
len, conn->bytes, off, conn->wanted, conn->readsz);
conn->bytes = cnt; conn->bytes = cnt;
if (conn->wanted) { if (conn->wanted) {
// Fulfill as much of the request as still fits into the buffer, // Fulfill as much of the request as still fits into the buffer,
@ -833,18 +836,23 @@ socket_filled( conn_t *conn, uint len )
return; return;
} else { } else {
// Need a full line // Need a full line
fprintf(stderr, " want line, scan off %u\n", conn->scanoff);
char *s = conn->buf + off; char *s = conn->buf + off;
char *p = memchr( s + conn->scanoff, '\n', cnt - conn->scanoff ); char *p = memchr( s + conn->scanoff, '\n', cnt - conn->scanoff );
if (!p) { if (!p) {
conn->scanoff = cnt; conn->scanoff = cnt;
fprintf(stderr, " no line yet\n");
if (off && off + cnt >= sizeof(conn->buf) - conn->readsz) { if (off && off + cnt >= sizeof(conn->buf) - conn->readsz) {
fprintf(stderr, " shifting down\n");
memmove( conn->buf, conn->buf + off, cnt ); memmove( conn->buf, conn->buf + off, cnt );
conn->offset = 0; conn->offset = 0;
} }
return; return;
} }
conn->scanoff = (uint)(p - s); conn->scanoff = (uint)(p - s);
fprintf(stderr, " line ends at %u\n", conn->scanoff);
} }
fprintf(stderr, " invoking read callback\n");
conn->read_callback( conn->callback_aux ); conn->read_callback( conn->callback_aux );
} }
@ -862,6 +870,8 @@ socket_fill_z( conn_t *sock )
sock->in_z->avail_out = len; sock->in_z->avail_out = len;
sock->in_z->next_out = (unsigned char *)buf; sock->in_z->next_out = (unsigned char *)buf;
fprintf(stderr, "socket fill, avail in %u, avail out %u\n",
sock->in_z->avail_in, sock->in_z->avail_out);
ret = inflate( sock->in_z, Z_SYNC_FLUSH ); ret = inflate( sock->in_z, Z_SYNC_FLUSH );
/* Z_BUF_ERROR happens here when the previous call both consumed /* Z_BUF_ERROR happens here when the previous call both consumed
* all input and exactly filled up the output buffer. */ * all input and exactly filled up the output buffer. */
@ -870,6 +880,8 @@ socket_fill_z( conn_t *sock )
socket_fail( sock ); socket_fail( sock );
return; return;
} }
fprintf(stderr, " now avail in %u, avail out %u\n",
sock->in_z->avail_in, sock->in_z->avail_out);
if (!sock->in_z->avail_out) if (!sock->in_z->avail_out)
conf_wakeup( &sock->z_fake, 0 ); conf_wakeup( &sock->z_fake, 0 );
@ -913,6 +925,7 @@ socket_fill( conn_t *sock )
if (sock->readsz > sizeof(sock->buf)) if (sock->readsz > sizeof(sock->buf))
sock->readsz = sizeof(sock->buf); sock->readsz = sizeof(sock->buf);
} }
fprintf(stderr, " read %d of %u intended, rd sz now %u\n", n, len, sock->readsz);
socket_filled( sock, (uint)n ); socket_filled( sock, (uint)n );
} }
@ -939,10 +952,13 @@ socket_expect_bytes( conn_t *conn, uint len )
{ {
conn->wanted = len; conn->wanted = len;
uint off = conn->offset; uint off = conn->offset;
fprintf(stderr, " want read of %u, offset %u\n", len, off);
if (off) { if (off) {
uint cnt = conn->bytes; uint cnt = conn->bytes;
fprintf(stderr, " already have %u\n", cnt);
if (off + len > sizeof(conn->buf) || if (off + len > sizeof(conn->buf) ||
off + cnt >= sizeof(conn->buf) - conn->readsz) { off + cnt >= sizeof(conn->buf) - conn->readsz) {
fprintf(stderr, " shifting down\n");
memmove( conn->buf, conn->buf + off, cnt ); memmove( conn->buf, conn->buf + off, cnt );
conn->offset = 0; conn->offset = 0;
} }
@ -958,7 +974,9 @@ socket_read( conn_t *conn, uint min_len, uint max_len, uint *out_len )
uint off = conn->offset; uint off = conn->offset;
uint cnt = conn->bytes; uint cnt = conn->bytes;
fprintf(stderr, " socket read min %u, max %u, have %u at %u\n", min_len, max_len, cnt, off);
if (cnt < min_len) { if (cnt < min_len) {
fprintf(stderr, " not enough buffered\n");
if (conn->state == SCK_EOF) if (conn->state == SCK_EOF)
return (void *)~0; return (void *)~0;
return NULL; return NULL;
@ -968,6 +986,7 @@ socket_read( conn_t *conn, uint min_len, uint max_len, uint *out_len )
conn->offset = cnt ? off + n : 0; conn->offset = cnt ? off + n : 0;
conn->bytes = cnt; conn->bytes = cnt;
*out_len = n; *out_len = n;
fprintf(stderr, " read %u, %u at %u remain\n", n, cnt, conn->offset);
return conn->buf + off; return conn->buf + off;
} }
@ -977,8 +996,10 @@ socket_read_line( conn_t *conn )
uint off = conn->offset; uint off = conn->offset;
uint cnt = conn->bytes; uint cnt = conn->bytes;
char *s = conn->buf + off; char *s = conn->buf + off;
fprintf(stderr, " socket read line, have %u at %u, scan off %u\n", cnt, off, conn->scanoff);
char *p = memchr( s + conn->scanoff, '\n', cnt - conn->scanoff ); char *p = memchr( s + conn->scanoff, '\n', cnt - conn->scanoff );
if (!p) { if (!p) {
fprintf(stderr, " no line yet\n");
if (conn->state == SCK_EOF) if (conn->state == SCK_EOF)
return (void *)~0; return (void *)~0;
conn->scanoff = cnt; conn->scanoff = cnt;
@ -992,6 +1013,7 @@ socket_read_line( conn_t *conn )
if (p != s && p[-1] == '\r') if (p != s && p[-1] == '\r')
p--; p--;
*p = 0; *p = 0;
fprintf(stderr, " read %u, %u at %u remain\n", n, cnt, conn->offset);
return s; return s;
} }
@ -1035,12 +1057,16 @@ do_queued_write( conn_t *conn )
{ {
buff_chunk_t *bc; buff_chunk_t *bc;
fprintf(stderr, " queued write\n");
if (!conn->write_buf) if (!conn->write_buf)
{ fprintf(stderr, " nothing there\n");
return 0; return 0;
}
while ((bc = conn->write_buf)) { while ((bc = conn->write_buf)) {
int n; int n;
uint len = bc->len - conn->write_offset; uint len = bc->len - conn->write_offset;
fprintf(stderr, " writing %u\n", len);
if ((n = do_write( conn, bc->data + conn->write_offset, len )) < 0) if ((n = do_write( conn, bc->data + conn->write_offset, len )) < 0)
return -1; return -1;
if (n != (int)len) { if (n != (int)len) {
@ -1054,6 +1080,7 @@ do_queued_write( conn_t *conn )
if (conn->ssl && SSL_pending( conn->ssl )) if (conn->ssl && SSL_pending( conn->ssl ))
conf_wakeup( &conn->ssl_fake, 0 ); conf_wakeup( &conn->ssl_fake, 0 );
#endif #endif
fprintf(stderr, " all written, calling back\n");
conn->write_callback( conn->callback_aux ); conn->write_callback( conn->callback_aux );
return -1; return -1;
} }
@ -1065,6 +1092,7 @@ do_append( conn_t *conn, buff_chunk_t *bc )
conn->buffer_mem += bc->len; conn->buffer_mem += bc->len;
*conn->write_buf_append = bc; *conn->write_buf_append = bc;
conn->write_buf_append = &bc->next; conn->write_buf_append = &bc->next;
fprintf(stderr, " appending %u\n", bc->len);
} }
/* This is big enough to avoid excessive chunking, but is /* This is big enough to avoid excessive chunking, but is
@ -1075,11 +1103,14 @@ static void
do_flush( conn_t *conn ) do_flush( conn_t *conn )
{ {
buff_chunk_t *bc = conn->append_buf; buff_chunk_t *bc = conn->append_buf;
fprintf(stderr, " do_flush\n");
#ifdef HAVE_LIBZ #ifdef HAVE_LIBZ
if (conn->out_z) { if (conn->out_z) {
uint buf_avail = conn->append_avail; uint buf_avail = conn->append_avail;
if (!conn->z_written) if (!conn->z_written)
{ fprintf(stderr, " nothing to flush\n");
return; return;
}
do { do {
int ret; int ret;
if (!bc) { if (!bc) {
@ -1091,6 +1122,8 @@ do_flush( conn_t *conn )
conn->out_z->avail_in = 0; conn->out_z->avail_in = 0;
conn->out_z->next_out = (uchar *)bc->data + bc->len; conn->out_z->next_out = (uchar *)bc->data + bc->len;
conn->out_z->avail_out = buf_avail; conn->out_z->avail_out = buf_avail;
fprintf(stderr, " pre-deflate: avail in %u, avail out %u\n",
conn->out_z->avail_in, conn->out_z->avail_out);
/* Z_BUF_ERROR cannot happen here, as zlib suppresses the error /* Z_BUF_ERROR cannot happen here, as zlib suppresses the error
* both upon increasing the flush level (1st iteration) and upon * both upon increasing the flush level (1st iteration) and upon
* a no-op after the output buffer was full (later iterations). */ * a no-op after the output buffer was full (later iterations). */
@ -1098,6 +1131,8 @@ do_flush( conn_t *conn )
error( "Fatal: Compression error: %s\n", z_err_msg( ret, conn->out_z ) ); error( "Fatal: Compression error: %s\n", z_err_msg( ret, conn->out_z ) );
abort(); abort();
} }
fprintf(stderr, " post-deflate: avail in %u, avail out %u\n",
conn->out_z->avail_in, conn->out_z->avail_out);
bc->len = (uint)((char *)conn->out_z->next_out - bc->data); bc->len = (uint)((char *)conn->out_z->next_out - bc->data);
if (bc->len) { if (bc->len) {
do_append( conn, bc ); do_append( conn, bc );
@ -1130,6 +1165,7 @@ socket_write( conn_t *conn, conn_iovec_t *iov, int iovcnt )
for (i = 0; i < iovcnt; i++) for (i = 0; i < iovcnt; i++)
total += iov[i].len; total += iov[i].len;
fprintf(stderr, "write %u bytes in %d chunks\n", total, iovcnt);
if (total >= WRITE_CHUNK_SIZE) { if (total >= WRITE_CHUNK_SIZE) {
/* If the new data is too big, queue the pending buffer to avoid latency. */ /* If the new data is too big, queue the pending buffer to avoid latency. */
do_flush( conn ); do_flush( conn );
@ -1154,6 +1190,7 @@ socket_write( conn_t *conn, conn_iovec_t *iov, int iovcnt )
buf_avail = WRITE_CHUNK_SIZE - bc->len; buf_avail = WRITE_CHUNK_SIZE - bc->len;
#endif #endif
} }
fprintf(stderr, " buffer with %u filled, %u available\n", bc->len, buf_avail);
while (total) { while (total) {
len = iov->len - offset; len = iov->len - offset;
#ifdef HAVE_LIBZ #ifdef HAVE_LIBZ
@ -1163,12 +1200,16 @@ socket_write( conn_t *conn, conn_iovec_t *iov, int iovcnt )
conn->out_z->avail_in = len; conn->out_z->avail_in = len;
conn->out_z->next_out = (uchar *)bc->data + bc->len; conn->out_z->next_out = (uchar *)bc->data + bc->len;
conn->out_z->avail_out = buf_avail; conn->out_z->avail_out = buf_avail;
fprintf(stderr, " pre-deflate: avail in %u, avail out %u\n",
conn->out_z->avail_in, conn->out_z->avail_out);
/* Z_BUF_ERROR is impossible here, as the input buffer always has data, /* Z_BUF_ERROR is impossible here, as the input buffer always has data,
* and the output buffer always has space. */ * and the output buffer always has space. */
if ((ret = deflate( conn->out_z, Z_NO_FLUSH )) != Z_OK) { if ((ret = deflate( conn->out_z, Z_NO_FLUSH )) != Z_OK) {
error( "Fatal: Compression error: %s\n", z_err_msg( ret, conn->out_z ) ); error( "Fatal: Compression error: %s\n", z_err_msg( ret, conn->out_z ) );
abort(); abort();
} }
fprintf(stderr, " post-deflate: avail in %u, avail out %u\n",
conn->out_z->avail_in, conn->out_z->avail_out);
bc->len = (uint)((char *)conn->out_z->next_out - bc->data); bc->len = (uint)((char *)conn->out_z->next_out - bc->data);
buf_avail = conn->out_z->avail_out; buf_avail = conn->out_z->avail_out;
len -= conn->out_z->avail_in; len -= conn->out_z->avail_in;
@ -1184,6 +1225,8 @@ socket_write( conn_t *conn, conn_iovec_t *iov, int iovcnt )
} }
offset += len; offset += len;
total -= len; total -= len;
fprintf(stderr, " buffered %u, buffer len %u, %u buffer remain, offset %u, %u total remain\n",
len, bc->len, buf_avail, offset, total);
if (offset == iov->len) { if (offset == iov->len) {
if (iov->takeOwn == GiveOwn) if (iov->takeOwn == GiveOwn)
free( iov->buf ); free( iov->buf );
@ -1264,6 +1307,8 @@ socket_fake_cb( void *aux )
{ {
conn_t *conn = (conn_t *)aux; conn_t *conn = (conn_t *)aux;
fprintf(stderr, " fake activity, %s writing\n",
(notifier_config( &conn->notify ) & POLLOUT) ? "already" : "not yet");
/* Ensure that a pending write gets queued. */ /* Ensure that a pending write gets queued. */
do_flush( conn ); do_flush( conn );
/* If no writes are ongoing, start writing now. */ /* If no writes are ongoing, start writing now. */
@ -1293,6 +1338,7 @@ z_fake_cb( void *aux )
{ {
conn_t *conn = (conn_t *)aux; conn_t *conn = (conn_t *)aux;
fprintf(stderr, " fake zlib activity\n");
socket_fill_z( conn ); socket_fill_z( conn );
} }
#endif #endif

Write Preview
Loading…
Cancel
Save