From d5e66d8f51e41841356b9b268e8a4a9ec4b7828f Mon Sep 17 00:00:00 2001
From: Tom Smeding <tom.smeding@gmail.com>
Date: Thu, 9 Jul 2020 23:14:18 +0200
Subject: ssh server: Less noise
---
ssh/server.c | 97 ++++++++++++++++++++++++++++++++++--------------------------
1 file changed, 55 insertions(+), 42 deletions(-)
diff --git a/ssh/server.c b/ssh/server.c
index 96fc09e..84f0587 100644
--- a/ssh/server.c
+++ b/ssh/server.c
@@ -1,5 +1,6 @@
#include <stdio.h>
#include <stdlib.h>
+#include <stdarg.h>
#include <stdbool.h>
#include <stdatomic.h>
#include <string.h>
@@ -20,6 +21,18 @@
#define RESOURCE_ERROR_SLEEP_MS 10000
+static const bool debug_enabled = false;
+
+
+__attribute__((format (printf, 1, 2)))
+static void debug(const char *restrict format, ...) {
+ if (debug_enabled) {
+ va_list ap;
+ va_start(ap, format);
+ vfprintf(stderr, format, ap);
+ va_end(ap);
+ }
+}
static void xxd(FILE *stream, const void *buf_, size_t length) {
unsigned char *buf = (unsigned char*)buf_;
@@ -70,10 +83,10 @@ static int channel_subsystem_request_cb(ssh_session session, ssh_channel channel
(void)channel;
struct thread_data *tdata = (struct thread_data*)tdata_;
if (strcmp(subsystem, "tomsg") == 0) {
- printf("[%d] subsystem request: <%s>, allowing\n", tdata->thread_id, subsystem);
+ debug("[%d] subsystem request: <%s>, allowing\n", tdata->thread_id, subsystem);
return 0;
} else {
- printf("[%d] subsystem request: <%s>, denying!\n", tdata->thread_id, subsystem);
+ debug("[%d] subsystem request: <%s>, denying!\n", tdata->thread_id, subsystem);
return 1;
}
}
@@ -81,51 +94,50 @@ static int channel_subsystem_request_cb(ssh_session session, ssh_channel channel
static void channel_close_cb(ssh_session session, ssh_channel channel, void *tdata_) {
(void)session; (void)channel;
struct thread_data *tdata = (struct thread_data*)tdata_;
- printf("[%d] channel close!\n", tdata->thread_id);
+ debug("[%d] channel close!\n", tdata->thread_id);
}
static void channel_eof_cb(ssh_session session, ssh_channel channel, void *tdata_) {
(void)session; (void)channel;
struct thread_data *tdata = (struct thread_data*)tdata_;
- printf("[%d] eof on channel, setting close flag\n", tdata->thread_id);
+ debug("[%d] eof on channel, setting close flag\n", tdata->thread_id);
tdata->should_close = true;
}
static int channel_data_cb(ssh_session session, ssh_channel channel, void *data, uint32_t len, int is_stderr, void *tdata_) {
(void)is_stderr; (void)data; (void)channel; (void)session;
struct thread_data *tdata = (struct thread_data*)tdata_;
- printf("[%d] data on channel (length %u):\n", tdata->thread_id, len);
- xxd(stdout, data, len);
- // printf("[%d] echoing back!\n", tdata->thread_id);
+
+ debug("[%d] data on channel (length %u):\n", tdata->thread_id, len);
+ if (debug_enabled) xxd(stdout, data, len);
+
+ // debug("[%d] echoing back!\n", tdata->thread_id);
// if (ssh_channel_write(channel, data, len) == SSH_ERROR) {
- // printf("[%d] write to channel failed! Setting close flag\n", tdata->thread_id);
+ // debug("[%d] write to channel failed! Setting close flag\n", tdata->thread_id);
// tdata->should_close = true;
// }
+
const char *start = (const char*)data;
const char *cursor = start;
const char *end = start + len;
+
while (cursor < end) {
ssize_t nw = write(tdata->backend_fd, cursor, end - cursor);
if (nw < 0) {
if (errno == EINTR) continue;
- printf("[%d] error writing to backend socket: %s\n", tdata->thread_id, strerror(errno));
+ debug("[%d] error writing to backend socket: %s\n", tdata->thread_id, strerror(errno));
tdata->should_close = true;
return cursor - start;
}
if (nw == 0) { // should not happen?
- printf("[%d] write(2) returned 0?\n", tdata->thread_id);
+ debug("[%d] write(2) returned 0?\n", tdata->thread_id);
tdata->should_close = true;
return cursor - start;
}
cursor += nw;
}
- return len;
-}
-static int channel_write_wontblock_cb(ssh_session session, ssh_channel channel, size_t bytes, void *tdata_) {
- (void)channel; (void)session;
- printf("[%d] write won't block for %zu bytes notification\n", ((struct thread_data*)tdata_)->thread_id, bytes);
- return 0;
+ return len;
}
////////// SERVER CALLBACKS //////////
@@ -133,7 +145,7 @@ static int channel_write_wontblock_cb(ssh_session session, ssh_channel channel,
static int auth_none_cb(ssh_session session, const char *user, void *tdata_) {
(void)session;
struct thread_data *tdata = (struct thread_data*)tdata_;
- printf("[%d] auth none (user <%s>), accepting\n", tdata->thread_id, user);
+ debug("[%d] auth none (user <%s>), accepting\n", tdata->thread_id, user);
return SSH_AUTH_SUCCESS;
}
@@ -141,10 +153,10 @@ static int service_request_cb(ssh_session session, const char *service, void *td
(void)session;
struct thread_data *tdata = (struct thread_data*)tdata_;
if (strcmp(service, "ssh-userauth") == 0) {
- printf("[%d] ssh-userauth service request, allowing through\n", tdata->thread_id);
+ debug("[%d] ssh-userauth service request, allowing through\n", tdata->thread_id);
return 0;
} else {
- printf("[%d] service request <%s>, not allowing\n", tdata->thread_id, service);
+ debug("[%d] service request <%s>, not allowing\n", tdata->thread_id, service);
return -1;
}
}
@@ -155,7 +167,7 @@ static ssh_channel chan_open_request_cb(ssh_session session, void *tdata_) {
ssh_channel chan = ssh_channel_new(session);
if (chan != NULL) {
if (ssh_set_channel_callbacks(chan, &tdata->chan_cb) == SSH_OK) {
- printf("[%d] channel open request, allowing\n", tdata->thread_id);
+ debug("[%d] channel open request, allowing\n", tdata->thread_id);
tdata->channel = chan;
return chan;
}
@@ -163,7 +175,7 @@ static ssh_channel chan_open_request_cb(ssh_session session, void *tdata_) {
ssh_channel_free(chan);
}
}
- printf("[%d] channel open request, denying!\n", tdata->thread_id);
+ debug("[%d] channel open request, denying!\n", tdata->thread_id);
return NULL;
}
@@ -171,6 +183,7 @@ static int backend_data_cb(int fd, int revents, void *tdata_) {
struct thread_data *tdata = (struct thread_data*)tdata_;
if (revents & (POLLERR|POLLHUP|POLLNVAL)) {
+ // Print this always, because backend issues are interesting
char descr[64] = "";
if (revents & POLLERR) strcat(descr, "|POLLERR");
if (revents & POLLHUP) strcat(descr, "|POLLHUP");
@@ -185,6 +198,7 @@ static int backend_data_cb(int fd, int revents, void *tdata_) {
ssize_t nr = read(fd, buffer, sizeof buffer);
if (nr < 0) {
if (errno == EINTR) return 0;
+ // Backend issues are interesting, not noise
printf("[%d] Error reading from backend socket: %s\n", tdata->thread_id, strerror(errno));
tdata->should_close = true;
return 0;
@@ -199,7 +213,7 @@ static int backend_data_cb(int fd, int revents, void *tdata_) {
while (cursor < nr) {
int nw = ssh_channel_write(tdata->channel, buffer + cursor, nr - cursor);
if (nw == SSH_ERROR) {
- printf("[%d] Error writing to ssh channel: %s\n", tdata->thread_id, ssh_get_error(tdata->channel));
+ debug("[%d] Error writing to ssh channel: %s\n", tdata->thread_id, ssh_get_error(tdata->channel));
tdata->should_close = true;
return 0;
}
@@ -266,13 +280,13 @@ static bool lookup_backend(const char *host, int port, struct addrinfo *dst) {
int last_failure = 0;
bool success = false;
for (struct addrinfo *item = result; item; ) {
- printf("lookup_backend: option ");
- print_addrinfo(stdout, item);
+ debug("lookup_backend: option ");
+ if (debug_enabled) print_addrinfo(stdout, item);
int sock = socket(item->ai_family, item->ai_socktype, item->ai_protocol);
if (sock == -1) {
last_failure = errno;
- printf(" socket() failure: %s\n", strerror(last_failure));
+ debug(" socket() failure: %s\n", strerror(last_failure));
continue;
}
@@ -281,7 +295,7 @@ static bool lookup_backend(const char *host, int port, struct addrinfo *dst) {
close(sock);
if (ret == 0) {
- printf(" success!\n");
+ debug(" success!\n");
success = true;
// Free the rest of the linked list, keeping this item intact.
freeaddrinfo(item->ai_next);
@@ -289,10 +303,10 @@ static bool lookup_backend(const char *host, int port, struct addrinfo *dst) {
dst->ai_next = NULL;
break;
} else {
- printf(" connect() failure: %s\n", strerror(last_failure));
+ debug(" connect() failure: %s\n", strerror(last_failure));
}
- printf(" next=%p\n", item->ai_next);
+ debug(" next=%p\n", item->ai_next);
// Free this element in the linked list, but preserve (and switch to) the tail.
struct addrinfo *next = item->ai_next;
@@ -315,7 +329,7 @@ static int connect_backend(const struct thread_data *tdata) {
if (sock == -1) return -1;
if (connect(sock, item->ai_addr, item->ai_addrlen) == 0) {
- printf("connect_backend: sock=%d\n", sock);
+ debug("connect_backend: sock=%d\n", sock);
return sock;
}
@@ -329,7 +343,7 @@ static void* thread_entry(void *tdata_) {
const ssh_session session = tdata->session;
ssh_event event = NULL;
- printf("[%d] Thread started\n", tid);
+ debug("[%d] Thread started\n", tid);
memset(&tdata->server_cb, 0, sizeof tdata->server_cb);
ssh_callbacks_init(&tdata->server_cb);
@@ -345,34 +359,33 @@ static void* thread_entry(void *tdata_) {
tdata->chan_cb.channel_close_function = channel_close_cb;
tdata->chan_cb.channel_eof_function = channel_eof_cb;
tdata->chan_cb.channel_data_function = channel_data_cb;
- tdata->chan_cb.channel_write_wontblock_function = channel_write_wontblock_cb;
if (ssh_set_server_callbacks(session, &tdata->server_cb) != SSH_OK) {
- printf("[%d] Failed setting server callbacks: %s\n", tid, ssh_get_error(session));
+ debug("[%d] Failed setting server callbacks: %s\n", tid, ssh_get_error(session));
goto cleanup;
}
ssh_set_auth_methods(session, SSH_AUTH_METHOD_NONE);
if (ssh_handle_key_exchange(session) != SSH_OK) {
- printf("[%d] Key exchange failed: %s\n", tid, ssh_get_error(session));
+ debug("[%d] Key exchange failed: %s\n", tid, ssh_get_error(session));
goto cleanup;
}
- printf("[%d] Handled key exchange\n", tid);
+ debug("[%d] Handled key exchange\n", tid);
tdata->backend_fd = connect_backend(tdata);
if (tdata->backend_fd == -1) {
- printf("[%d] Failed to connect to backend: %s\n", tid, strerror(errno));
+ debug("[%d] Failed to connect to backend: %s\n", tid, strerror(errno));
goto cleanup;
}
- printf("[%d] Connected to backend (fd=%d)\n", tid, tdata->backend_fd);
+ debug("[%d] Connected to backend (fd=%d)\n", tid, tdata->backend_fd);
event = ssh_event_new();
if (!event
|| ssh_event_add_session(event, session) != SSH_OK
|| ssh_event_add_fd(event, tdata->backend_fd, POLLIN, backend_data_cb, tdata) != SSH_OK) {
- printf("[%d] Failed to create ssh event context\n", tid);
+ debug("[%d] Failed to create ssh event context\n", tid);
goto cleanup;
}
@@ -382,7 +395,7 @@ static void* thread_entry(void *tdata_) {
int status = ssh_get_status(session);
if (status & (SSH_CLOSED | SSH_CLOSED_ERROR)) goto cleanup;
if (status & SSH_READ_PENDING) {
- printf("[%d] read pending?\n", tid);
+ debug("[%d] read pending?\n", tid);
}
}
@@ -396,12 +409,12 @@ cleanup:
if (session) {
ssh_disconnect(session);
ssh_free(session);
- printf("[%d] Disconnected\n", tid);
+ debug("[%d] Disconnected\n", tid);
}
free(tdata);
int num_threads = atomic_fetch_sub(&g_thread_count, 1);
- printf("[%d] Exiting! (%d threads remaining)\n", tid, num_threads - 1);
- pthread_exit(NULL);
+ debug("[%d] Exiting! (%d threads remaining)\n", tid, num_threads - 1);
+ return NULL;
}
static void generate_key(const char *outfile) {
@@ -549,7 +562,7 @@ int main(int argc, char **argv) {
}
int num_existing_threads = atomic_fetch_add(&g_thread_count, 1);
- printf("Accepted connection, spinning up thread (currently %d threads)\n",
+ debug("Accepted connection, spinning up thread (currently %d threads)\n",
num_existing_threads + 1);
struct thread_data *tdata = calloc(1, sizeof(struct thread_data));
--
cgit v1.2.3-70-g09d2