static ssize_t socket_read_ssl(struct bus *b, listener *l, int pfd_i, connection_info *ci) { BUS_ASSERT(b, b->udata, ci->ssl); ssize_t accum = 0; while (ci->to_read_size > 0) { // ssize_t pending = SSL_pending(ci->ssl); ssize_t size = (ssize_t)syscall_SSL_read(ci->ssl, l->read_buf, ci->to_read_size); if (size == -1) { int reason = syscall_SSL_get_error(ci->ssl, size); switch (reason) { case SSL_ERROR_WANT_READ: BUS_LOG_SNPRINTF(b, 3, LOG_LISTENER, b->udata, 64, "SSL_read fd %d: WANT_READ", ci->fd); return accum; case SSL_ERROR_WANT_WRITE: BUS_ASSERT(b, b->udata, false); case SSL_ERROR_SYSCALL: { if (errno == 0) { print_SSL_error(b, ci, 1, "SSL_ERROR_SYSCALL errno 0"); BUS_ASSERT(b, b->udata, false); } else if (Util_IsResumableIOError(errno)) { errno = 0; continue; } else { BUS_LOG_SNPRINTF(b, 3, LOG_LISTENER, b->udata, 64, "SSL_read fd %d: errno %d", ci->fd, errno); print_SSL_error(b, ci, 1, "SSL_ERROR_SYSCALL"); set_error_for_socket(l, pfd_i, ci->fd, RX_ERROR_READ_FAILURE); return -1; } break; } case SSL_ERROR_ZERO_RETURN: { BUS_LOG_SNPRINTF(b, 3, LOG_LISTENER, b->udata, 64, "SSL_read fd %d: ZERO_RETURN (HUP)", ci->fd); set_error_for_socket(l, pfd_i, ci->fd, RX_ERROR_POLLHUP); return -1; } default: print_SSL_error(b, ci, 1, "SSL_ERROR UNKNOWN"); set_error_for_socket(l, pfd_i, ci->fd, RX_ERROR_READ_FAILURE); BUS_ASSERT(b, b->udata, false); } } else if (size > 0) { sink_socket_read(b, l, ci, size); accum += size; if ((size_t)accum == ci->to_read_size) { break; } } else { break; } } return accum; }
static ssize_t socket_read_plain(struct bus *b, listener *l, int pfd_i, connection_info *ci) { ssize_t accum = 0; while (ci->to_read_size > 0) { ssize_t size = syscall_read(ci->fd, l->read_buf, ci->to_read_size); if (size == -1) { BUS_LOG_SNPRINTF(b, 6, LOG_LISTENER, b->udata, 64, "read: size %zd, errno %d", size, errno); if (errno == EAGAIN) { errno = 0; return accum; } else if (Util_IsResumableIOError(errno)) { errno = 0; continue; } else { BUS_LOG_SNPRINTF(b, 3, LOG_LISTENER, b->udata, 64, "read: socket error reading, %d", errno); set_error_for_socket(l, pfd_i, ci->fd, RX_ERROR_READ_FAILURE); errno = 0; return -1; } } if (size > 0) { BUS_LOG_SNPRINTF(b, 5, LOG_LISTENER, b->udata, 64, "read: %zd", size); sink_socket_read(b, l, ci, size); accum += size; } else { return accum; } } return accum; }
static ssize_t write_plain(struct bus *b, boxed_msg *box) { int fd = box->fd; uint8_t *msg = box->out_msg; size_t msg_size = box->out_msg_size; size_t sent_size = box->out_sent_size; size_t rem = msg_size - sent_size; BUS_LOG_SNPRINTF(b, 10, LOG_SENDER, b->udata, 64, "write %p to %d, %zd bytes", (void*)&msg[sent_size], fd, rem); /* Attempt a single write. ('for' is due to continue-based retry.) */ for (;;) { ssize_t wrsz = syscall_write(fd, &msg[sent_size], rem); if (wrsz == -1) { if (Util_IsResumableIOError(errno)) { errno = 0; continue; } else { /* will notify about closed socket upstream */ BUS_LOG_SNPRINTF(b, 1, LOG_SENDER, b->udata, 64, "write: socket error writing, %s", strerror(errno)); errno = 0; return -1; } } else if (wrsz > 0) { BUS_LOG_SNPRINTF(b, 5, LOG_SENDER, b->udata, 64, "sent: %zd", wrsz); return wrsz; } else { return 0; } } }
static bool do_blocking_connection(struct bus *b, SSL *ssl, int fd) { BUS_LOG_SNPRINTF(b, 2, LOG_SOCKET_REGISTERED, b->udata, 128, "SSL_Connect handshake for socket %d", fd); struct pollfd fds[1]; fds[0].fd = fd; fds[0].events = POLLOUT; bool connected = false; size_t elapsed = 0; while (!connected) { int pres = syscall_poll(fds, 1, TIMEOUT_MSEC); BUS_LOG_SNPRINTF(b, 5, LOG_SOCKET_REGISTERED, b->udata, 128, "SSL_Connect handshake for socket %d, poll res %d", fd, pres); if (pres < 0) { if (Util_IsResumableIOError(errno)) { errno = 0; } else { /* */ assert(false); } } else if (pres > 0) { if (fds[0].revents & (POLLOUT | POLLIN)) { int connect_res = SSL_connect(ssl); BUS_LOG_SNPRINTF(b, 5, LOG_SOCKET_REGISTERED, b->udata, 128, "socket %d: connect_res %d", fd, connect_res); if (connect_res == 1) { BUS_LOG_SNPRINTF(b, 5, LOG_SOCKET_REGISTERED, b->udata, 128, "socket %d: successfully connected", fd); connected = true; } else if (connect_res < 0) { int reason = SSL_get_error(ssl, connect_res); switch (reason) { case SSL_ERROR_WANT_WRITE: BUS_LOG(b, 4, LOG_SOCKET_REGISTERED, "WANT_WRITE", b->udata); fds[0].events = POLLOUT; break; case SSL_ERROR_WANT_READ: BUS_LOG(b, 4, LOG_SOCKET_REGISTERED, "WANT_READ", b->udata); fds[0].events = POLLIN; break; case SSL_ERROR_SYSCALL: { if (Util_IsResumableIOError(errno)) { errno = 0; break; } else { unsigned long errval = ERR_get_error(); char ebuf[256]; BUS_LOG_SNPRINTF(b, 1, LOG_SOCKET_REGISTERED, b->udata, 128, "socket %d: ERROR -- %s", fd, ERR_error_string(errval, ebuf)); } } break; default: { unsigned long errval = ERR_get_error(); char ebuf[256]; BUS_LOG_SNPRINTF(b, 1, LOG_SOCKET_REGISTERED, b->udata, 128, "socket %d: ERROR %d -- %s", fd, reason, ERR_error_string(errval, ebuf)); assert(false); } } } else { BUS_LOG_SNPRINTF(b, 5, LOG_SOCKET_REGISTERED, b->udata, 128, "socket %d: unknown state, setting event bask to (POLLIN | POLLOUT)", fd); fds[0].events = (POLLIN | POLLOUT); } } else if (fds[0].revents & POLLHUP) { BUS_LOG_SNPRINTF(b, 1, LOG_SOCKET_REGISTERED, b->udata, 128, "SSL_Connect: HUP on %d", fd); return false; } else if (fds[0].revents & POLLERR) { BUS_LOG_SNPRINTF(b,12, LOG_SOCKET_REGISTERED, b->udata, 128, "SSL_Connect: ERR on %d", fd); return false; } } else { BUS_LOG(b, 4, LOG_SOCKET_REGISTERED, "poll timeout", b->udata); elapsed += TIMEOUT_MSEC; if (elapsed > MAX_TIMEOUT) { BUS_LOG(b, 2, LOG_SOCKET_REGISTERED, "timed out", b->udata); return false; } } } return connected; }
bool BusPoll_OnCompletion(struct bus *b, int fd) { /* POLL in a pipe */ #ifndef TEST struct pollfd fds[1]; #endif fds[0].fd = fd; fds[0].events = POLLIN; for (;;) { BUS_LOG(b, 5, LOG_SENDING_REQUEST, "Polling on completion...tick...", b->udata); #ifdef TEST errno = poll_errno; #endif BUS_LOG_SNPRINTF(b, 5, LOG_SENDING_REQUEST, b->udata, 64, "poll_on_completion, polling %d", fd); int res = syscall_poll(fds, 1, -1); BUS_LOG_SNPRINTF(b, 5, LOG_SENDING_REQUEST, b->udata, 64, "poll_on_completion for %d, res %d (errno %d)", fd, res, errno); if (res == -1) { if (Util_IsResumableIOError(errno)) { BUS_LOG_SNPRINTF(b, 5, LOG_SENDING_REQUEST, b->udata, 64, "poll_on_completion, resumable IO error %d", errno); errno = 0; continue; } else { BUS_LOG_SNPRINTF(b, 1, LOG_SENDING_REQUEST, b->udata, 64, "poll_on_completion, non-resumable IO error %d", errno); return false; } } else if (res == 1) { uint16_t msec = 0; #ifndef TEST uint8_t read_buf[sizeof(uint8_t) + sizeof(uint16_t)]; #endif if (fds[0].revents & (POLLERR | POLLHUP | POLLNVAL)) { BUS_LOG(b, 1, LOG_SENDING_REQUEST, "failed (broken alert pipe)", b->udata); return false; } BUS_LOG(b, 3, LOG_SENDING_REQUEST, "Reading alert pipe...", b->udata); #ifdef TEST errno = read_errno; #endif ssize_t sz = syscall_read(fd, read_buf, sizeof(read_buf)); if (sz == sizeof(read_buf)) { /* Payload: little-endian uint16_t, msec of backpressure. */ assert(read_buf[0] == LISTENER_MSG_TAG); msec = (read_buf[1] << 0) + (read_buf[2] << 8); Bus_BackpressureDelay(b, msec, LISTENER_BACKPRESSURE_SHIFT); BUS_LOG(b, 4, LOG_SENDING_REQUEST, "sent!", b->udata); return true; } else if (sz == -1) { if (Util_IsResumableIOError(errno)) { BUS_LOG_SNPRINTF(b, 5, LOG_SENDING_REQUEST, b->udata, 64, "poll_on_completion read, resumable IO error %d", errno); errno = 0; continue; } else { BUS_LOG_SNPRINTF(b, 2, LOG_SENDING_REQUEST, b->udata, 64, "poll_on_completion read, non-resumable IO error %d", errno); errno = 0; return false; } } else { BUS_LOG_SNPRINTF(b, 1, LOG_SENDING_REQUEST, b->udata, 64, "poll_on_completion bad read size %zd", sz); return false; } } else { /* This should never happen, but I have seen it occur on OSX. * If we log it, reset errno, and continue, it does not appear * to fall into busywaiting by always returning 0. */ BUS_LOG_SNPRINTF(b, 1, LOG_SENDING_REQUEST, b->udata, 64, "poll_on_completion, blocking forever returned %d, errno %d", res, errno); errno = 0; } } }
static ssize_t write_ssl(struct bus *b, boxed_msg *box, SSL *ssl) { uint8_t *msg = box->out_msg; size_t msg_size = box->out_msg_size; ssize_t rem = msg_size - box->out_sent_size; int fd = box->fd; (void)fd; ssize_t written = 0; assert(rem >= 0); while (rem > 0) { ssize_t wrsz = syscall_SSL_write(ssl, &msg[box->out_sent_size], rem); BUS_LOG_SNPRINTF(b, 5, LOG_SENDER, b->udata, 64, "SSL_write: socket %d, write %zd => wrsz %zd", fd, rem, wrsz); if (wrsz > 0) { written += wrsz; return written; } else if (wrsz < 0) { int reason = syscall_SSL_get_error(ssl, wrsz); switch (reason) { case SSL_ERROR_WANT_WRITE: /* We need to write more, but currently cannot write. * Log and go back to the poll() loop. */ BUS_LOG_SNPRINTF(b, 3, LOG_SENDER, b->udata, 64, "SSL_write: socket %d: WANT_WRITE", fd); return 0; case SSL_ERROR_WANT_READ: BUS_LOG_SNPRINTF(b, 0, LOG_SENDER, b->udata, 64, "SSL_write: socket %d: WANT_READ", fd); assert(false); // shouldn't get this; we're writing. break; case SSL_ERROR_SYSCALL: { if (Util_IsResumableIOError(errno)) { errno = 0; /* don't break; we want to retry on EINTR etc. until * we get WANT_WRITE, otherwise poll(2) may not retry * the socket for too long */ continue; } else { /* will notify about socket error upstream */ BUS_LOG_SNPRINTF(b, 1, LOG_SENDER, b->udata, 64, "SSL_write on fd %d: SSL_ERROR_SYSCALL -- %s", fd, strerror(errno)); errno = 0; return -1; } } case SSL_ERROR_SSL: BUS_LOG_SNPRINTF(b, 1, LOG_SENDER, b->udata, 64, "SSL_write: socket %d: error SSL (wrsz %zd)", box->fd, wrsz); /* Log error messages from OpenSSL */ for (;;) { unsigned long e = ERR_get_error(); if (e == 0) { break; } // no more errors BUS_LOG_SNPRINTF(b, 1, LOG_SENDER, b->udata, 128, "SSL_write error: %s", ERR_error_string(e, NULL)); } return -1; default: { BUS_LOG_SNPRINTF(b, 1, LOG_SENDER, b->udata, 64, "SSL_write on socket %d: match fail: error %d", box->fd, reason); return -1; } } } else { /* SSL_write should give SSL_ERROR_WANT_WRITE when unable * to write further. */ } } BUS_LOG_SNPRINTF(b, 3, LOG_SENDER, b->udata, 64, "SSL_write: leaving loop, %zd bytes written", written); return written; }