added macros for debugging

1 files changed, 120 insertions, 125 deletions

diff --git a/src/kernel/net.c b/src/kernel/net.c
index e4ab608..04dc5ba 100644
--- a/src/kernel/net.c
+++ b/src/kernel/net.c
@@ -24,7 +24,8 @@
 #include <net/sock.h>
 #include <linux/wait.h>
 
-#include "dnbd3.h"
+#include "net.h"
+#include "utils.h"
 #include "clientconfig.h"
 
 
@@ -36,10 +37,9 @@
 #define dnbd3_priv_to_cmd(req)        ((req)->cmd_flags >> REQ_FLAG_BITS)
 #define dnbd3_sock_create(af,type,proto,sock) sock_create_kern(&init_net, (af) == HOST_IP4 ? AF_INET : AF_INET6, type, proto, sock)
 
-#define KEEPALIVE_TIMER (jiffies + (HZ * TIMER_INTERVAL_KEEPALIVE_PACKET))
-#define DISCOVERY_TIMER (jiffies + (HZ * TIMER_INTERVAL_PROBE_NORMAL))
 #define REQUEST_TIMEOUT (HZ * SOCKET_TIMEOUT_CLIENT_DATA)
 
+
 #define init_msghdr(h) do { \
         h.msg_name = NULL; \
         h.msg_namelen = 0; \
@@ -49,29 +49,20 @@
 	} while (0)
 
 static DECLARE_WAIT_QUEUE_HEAD(send_wq);
-static volatile uint64_t send_wq_signal; //TODO make atomic atomic_64_t
+static atomic64_t send_wq_signal;
 
 static int dnbd3_socket_connect(struct dnbd3_device *dev, struct dnbd3_server *server);
 static int __dnbd3_socket_connect(struct dnbd3_server * server, struct dnbd3_sock *sock);
 static int dnbd3_socket_disconnect(struct dnbd3_device *dev, struct dnbd3_server *server, struct dnbd3_sock *sock);
 
 
-static void dnbd3_print_host(struct dnbd3_host_t *host, char *msg)
-{
-	if (host->type == HOST_IP4) {
-		printk(KERN_INFO "dnbd3: %s %pI4:%d\n", msg, host->addr, host->port);
-	} else {
-		printk(KERN_INFO "dnbd3: %s [%pI6]:%d\n", msg, host->addr, host->port);
-	}
-}
-
 static void dnbd3_print_server_list(struct dnbd3_device *dev)
 {
 	int i;
-	dnbd3_print_host(&dev->initial_server.host, "initial server is");
+	print_server(KERN_INFO, dev, &dev->initial_server, "initial server is");
 	for (i = 0; i < NUMBER_SERVERS; i++) {
 		if (dev->alt_servers[i].host.addr[0] != 0) {
-			dnbd3_print_host(&dev->alt_servers[i].host, "alternative server is");
+			print_server(KERN_INFO, dev, &dev->alt_servers[i], "alternative server is");
 		}
 	}
 }
@@ -112,18 +103,18 @@ int dnbd3_send_request(struct dnbd3_sock *sock, struct request *req, struct dnbd
 
 	switch (req_op(req)) {
 	case REQ_OP_READ:
-		printk(KERN_DEBUG "dnbd3: request operation read\n");
+		debug_sock(sock, "request operation read");
 		dnbd3_request.cmd = CMD_GET_BLOCK;
 		dnbd3_request.offset = blk_rq_pos(req) << 9; // *512
 		dnbd3_request.size = blk_rq_bytes(req); // bytes left to complete entire request
 		break;
 	case DNBD3_REQ_OP_SPECIAL:
-		printk(KERN_DEBUG "dnbd3: request operation special\n");
+		debug_sock(sock, "request operation special");
 		dnbd3_request.cmd = dnbd3_priv_to_cmd(req);
 		dnbd3_request.size = 0;
 		break;
 	case DNBD3_REQ_OP_CONNECT:
-		printk(KERN_DEBUG "dnbd3: request operation connect to %s\n", sock->device->imgname);
+		debug_sock(sock, "request operation connect to %s", sock->device->imgname);
 		dnbd3_request.cmd = CMD_SELECT_IMAGE;
 		serializer_reset_write(&payload_buffer);
 		serializer_put_uint16(&payload_buffer, PROTOCOL_VERSION);
@@ -152,7 +143,7 @@ int dnbd3_send_request(struct dnbd3_sock *sock, struct request *req, struct dnbd
 	iov[0].iov_len = sizeof(dnbd3_request);
 	send_len = iov_num == 1 ? sizeof(dnbd3_request) : iov[0].iov_len + iov[1].iov_len;
 	if ((result = kernel_sendmsg(sock->sock, &msg, iov, iov_num, send_len)) != send_len) {
-		printk(KERN_ERR "dnbd3: connection to server lost\n");
+		error_sock(sock, "connection to server lost");
 		goto error;
 	}
 
@@ -168,9 +159,9 @@ int dnbd3_send_request_blocking(struct dnbd3_sock *sock, int dnbd3_cmd)
 	int result = 0;
 	uint64_t handle;
 	struct request *req = kmalloc(sizeof(struct request), GFP_KERNEL);
-	printk(KERN_DEBUG "dnbd3: starting blocking request\n");
+	debug_sock(sock, "request starting blocking request");
 	if (!req) {
-		printk(KERN_ERR "dnbd3: kmalloc failed\n");
+		error_sock(sock, "kmalloc failed");
 		goto error;
 	}
 
@@ -183,7 +174,7 @@ int dnbd3_send_request_blocking(struct dnbd3_sock *sock, int dnbd3_cmd)
 		dnbd3_connect(req);
 		break;
 	default:
-		printk(KERN_WARNING "dnbd3: unsupported command for blocking %d\n", dnbd3_cmd);
+		warn_sock(sock, "unsupported command for blocking %d", dnbd3_cmd);
 		result = -EINVAL;
 		goto error;
 	}
@@ -194,19 +185,16 @@ int dnbd3_send_request_blocking(struct dnbd3_sock *sock, int dnbd3_cmd)
 		mutex_unlock(&sock->lock);
 		goto error;
 	}
-	send_wq_signal = 0;
+	atomic64_set(&send_wq_signal, 0);
 	handle = dnbd3_to_wq_signal(sock->device->minor, dnbd3_cmd, sock->sock_nr);
 
 	mutex_unlock(&sock->lock);
 
-	printk(KERN_DEBUG "dnbd3: blocking request going to sleep for %d  wait for handle %llu\n", REQUEST_TIMEOUT, handle);
-	if (wait_event_interruptible_timeout(send_wq, handle == send_wq_signal, REQUEST_TIMEOUT) <= 0) { // timeout or interrupt
-		printk(KERN_WARNING "dndbd3: request timed out\n");
+	if (wait_event_interruptible_timeout(send_wq, atomic64_read(&send_wq_signal) == handle, REQUEST_TIMEOUT) <= 0) { // timeout or interrupt
+		warn_sock(sock, "request timed out");
 		result = -EIO;
 		goto error;
 	}
-	printk(KERN_DEBUG "dnbd3: blocking request woke up with handle %llu\n", handle);
-
 
 error:
 	if (req) {
@@ -231,12 +219,12 @@ static int dnbd3_receive_cmd(struct dnbd3_sock *sock, dnbd3_reply_t *reply)
 
 	// check error
 	if (reply->magic != dnbd3_packet_magic) {
-		printk(KERN_ERR "dnbd3: receive cmd wrong magic packet\n");
+		error_sock(sock, "receive cmd wrong magic packet");
 		return -EIO;
 	}
 
 	if (reply->cmd == 0) {
-		printk(KERN_ERR "dnbd3: receive command was 0\n");
+		error_sock(sock, "receive command was 0");
 		return -EIO;
 	}
 	return result;
@@ -259,7 +247,6 @@ static int dnbd3_receive_cmd_get_block_mq(struct dnbd3_device *dev, struct dnbd3
 	uint64_t handle;
 	init_msghdr(msg);
 
-	printk(KERN_DEBUG "dnbd3: handle is %llu\n", reply->handle);
 	memcpy(&handle, &reply->handle, sizeof(handle));
 	cookie = dnbd3_arg1_from_handle(handle);
 	tag = dnbd3_arg0_from_handle(handle);
@@ -294,7 +281,7 @@ static int dnbd3_receive_cmd_get_block_mq(struct dnbd3_device *dev, struct dnbd3
 		if (result != bvec->bv_len) {
 			kunmap(bvec->bv_page);
 			sigprocmask(SIG_SETMASK, &oldset, NULL );
-			printk(KERN_ERR "dnbd3: could not receive form net to block layer\n");
+			error_sock(sock, "could not receive form net to block layer");
 			mutex_unlock(&cmd->lock);
 			return result;
 		}
@@ -316,7 +303,7 @@ static int dnbd3_receive_cmd_get_servers(struct dnbd3_device *dev, struct dnbd3_
 	int count, remaining;
 	init_msghdr(msg);
 
-	printk(KERN_DEBUG "dnbd3: get servers received\n");
+	debug_sock(sock, "get servers received");
 	mutex_lock(&dev->device_lock);
 	if (!dev->use_server_provided_alts) {
 		remaining = reply->size;
@@ -330,10 +317,10 @@ static int dnbd3_receive_cmd_get_servers(struct dnbd3_device *dev, struct dnbd3_
 		iov.iov_len = count * sizeof(dnbd3_server_entry_t);
 		result = kernel_recvmsg(sock->sock, &msg, &iov, 1, (count * sizeof(dnbd3_server_entry_t)), msg.msg_flags);
 		if (result <= 0) {
-			printk(KERN_ERR "dnbd3: failed to receive get servers %d\n", result);
+			error_sock(sock, "failed to receive get servers %d", result);
 			return result;
 		} else if (result != (count * sizeof(dnbd3_server_entry_t))) {
-			printk(KERN_ERR "dnbd3: failed to get servers\n");
+			error_sock(sock, "failed to get servers");
 			mutex_unlock(&dev->device_lock);
 			return -EIO;
 		}
@@ -348,7 +335,7 @@ consume_payload:
 		iov.iov_len = count;
 		result = kernel_recvmsg(sock->sock, &msg, &iov, 1, count, msg.msg_flags);
 		if (result <= 0) {
-			printk(KERN_ERR "dnbd3: failed to receive payload from get servers\n");
+			error_sock(sock, "failed to receive payload from get servers");
 			mutex_unlock(&dev->device_lock);
 			return result;
 		}
@@ -356,6 +343,7 @@ consume_payload:
 	mutex_unlock(&dev->device_lock);
 	return result;
 }
+
 static int dnbd3_receive_cmd_latest_rid(struct dnbd3_device *dev, struct dnbd3_sock *sock, dnbd3_reply_t *reply)
 {
 	struct kvec iov;
@@ -363,21 +351,21 @@ static int dnbd3_receive_cmd_latest_rid(struct dnbd3_device *dev, struct dnbd3_s
 	int result;
 	struct msghdr msg;
 	init_msghdr(msg);
-	printk(KERN_DEBUG "dnbd3: latest rid received\n");
+	debug_sock(sock, "latest rid received");
 
 	if (reply->size != 2) {
-		printk(KERN_ERR "dnbd3: failed to get latest rid, wrong size\n");
+		error_sock(sock, "failed to get latest rid, wrong size");
 		return -EIO;
 	}
 	iov.iov_base = &rid;
 	iov.iov_len = sizeof(rid);
 	result = kernel_recvmsg(sock->sock, &msg, &iov, 1, iov.iov_len, msg.msg_flags);
 	if (result <= 0) {
-		printk(KERN_ERR "dnbd3: failed to receive latest rid\n");
+		error_sock(sock, "failed to receive latest rid");
 		return result;
 	}
 	rid = net_order_16(rid);
-	printk("Latest rid of %s is %d (currently using %d)\n", dev->imgname, (int)rid, (int)dev->rid);
+	debug_sock(sock, "latest rid of %s is %d (currently using %d)", dev->imgname, (int)rid, (int)dev->rid);
 	dev->update_available = (rid > dev->rid ? 1 : 0);
 	return result;
 }
@@ -392,16 +380,16 @@ static int dnbd3_receive_cmd_select_image(struct dnbd3_device *dev, struct dnbd3
 	serialized_buffer_t payload_buffer;
 	uint64_t reported_size;
 	init_msghdr(msg);
-	printk(KERN_DEBUG "dnbd3: select image received\n");
+	debug_sock(sock, "select image received");
 	// receive reply payload
 	iov.iov_base = &payload_buffer;
 	iov.iov_len = reply->size;
 	result = kernel_recvmsg(sock->sock, &msg, &iov, 1, iov.iov_len, msg.msg_flags);
 	if (result <= 0) {
-		printk(KERN_ERR "dnbd3: failed to receive select image %d\n", result);
+		error_sock(sock, "failed to receive select image %d", result);
 		return result;
 	} else if (result != reply->size) {
-		printk(KERN_ERR "dnbd3: could not read CMD_SELECT_IMAGE payload on handshake, size is %d and should be%d\n",
+		error_sock(sock, "could not read CMD_SELECT_IMAGE payload on handshake, size is %d and should be %d",
 				result, reply->size);
 		return -EIO;
 	}
@@ -410,7 +398,7 @@ static int dnbd3_receive_cmd_select_image(struct dnbd3_device *dev, struct dnbd3
 	serializer_reset_read(&payload_buffer, reply->size);
 	sock->server->protocol_version = serializer_get_uint16(&payload_buffer);
 	if (sock->server->protocol_version < MIN_SUPPORTED_SERVER) {
-		printk(KERN_ERR "dnbd3: server version is lower than min supported version\n");
+		error_sock(sock, "server version is lower than min supported version");
 		return -EIO;
 	}
 
@@ -419,20 +407,20 @@ static int dnbd3_receive_cmd_select_image(struct dnbd3_device *dev, struct dnbd3
 	name = serializer_get_string(&payload_buffer);
 	rid = serializer_get_uint16(&payload_buffer);
 	if (dev->rid != rid && strcmp(name, dev->imgname) != 0) {
-		printk(KERN_ERR "dnbd3: server offers image '%s', requested '%s'\n", name, dev->imgname);
+		error_sock(sock, "server offers image '%s', requested '%s'", name, dev->imgname);
 		return -EIO;
 	}
 
 	reported_size = serializer_get_uint64(&payload_buffer);
 	if (!dev->reported_size) {
 		if (reported_size < 4096) {
-			printk(KERN_ERR "dnbd3: reported size by server is < 4096\n");
+			error_sock(sock, "reported size by server is < 4096");
 			return -EIO;
 		}
 		dev->reported_size = reported_size;
 		set_capacity(dev->disk, dev->reported_size >> 9); /* 512 Byte blocks */
 	} else if (dev->reported_size != reported_size) {
-		printk(KERN_ERR "dnbd3: reported size by server is %llu but should be %llu\n", reported_size, dev->reported_size);
+		error_sock(sock, "reported size by server is %llu but should be %llu", reported_size, dev->reported_size);
 		return -EIO;
 	}
 	return result;
@@ -446,13 +434,12 @@ static void dnbd3_receive_worker(struct work_struct *work)
 	uint64_t handle;
 	int result;
 
-	while(sock->sock && sock->server) {
+	while(dnbd3_is_sock_alive(*sock)) {
 		result = dnbd3_receive_cmd(sock, &dnbd3_reply);
-//				kernel_recvmsg(sock->sock, &msg, &iov, 1, sizeof(dnbd3_reply), msg.msg_flags);
 		if (result == -EAGAIN) {
 			continue;
 		} else if (result <= 0) {
-			printk(KERN_ERR "dnbd3: connection to server lost %d\n", result);
+			error_sock(sock, "connection to server lost %d", result);
 			goto error;
 
 		}
@@ -461,59 +448,58 @@ static void dnbd3_receive_worker(struct work_struct *work)
 		case CMD_GET_BLOCK:
 			result = dnbd3_receive_cmd_get_block_mq(dev, sock, &dnbd3_reply);
 			if (result <= 0) {
-				printk(KERN_ERR "dnbd3: receive cmd get block mq failed %d\n", result);
+				error_sock(sock, "receive cmd get block mq failed %d", result);
 				goto error;
 			}
-			break;
+			continue; // we do not need to wake up anyone, wait for next cmd (block)
 		case CMD_GET_SERVERS:
 			result = dnbd3_receive_cmd_get_servers(dev, sock, &dnbd3_reply);
 			if (result <= 0) {
-				printk(KERN_ERR "dnbd3: receive cmd get servers failed %d\n", result);
+				error_sock(sock, "receive cmd get servers failed %d", result);
 				goto error;
 			}
 			break;
 		case CMD_LATEST_RID:
 			result = dnbd3_receive_cmd_latest_rid(dev, sock, &dnbd3_reply);
 			if (result <= 0) {
-				printk(KERN_ERR "dnbd3: receive cmd latest rid failed %d\n", result);
+				error_sock(sock, "receive cmd latest rid failed %d", result);
 				goto error;
 			}
 			break;
 		case CMD_KEEPALIVE:
 			if (dnbd3_reply.size != 0) {
-				printk(KERN_ERR "dnbd3: got keep alive packet with payload\n");
+				error_sock(sock, "got keep alive packet with payload");
 				goto error;
 			}
-			printk(KERN_DEBUG "dnbd3: keep alive received\n");
+			debug_sock(sock, "keep alive received");
 			break;
 		case CMD_SELECT_IMAGE:
 			result = dnbd3_receive_cmd_select_image(dev, sock, &dnbd3_reply);
 			if (result <= 0) {
-				printk(KERN_ERR "dnbd3: receive cmd select image failed %d\n", result);
+				error_sock(sock, "receive cmd select image failed %d", result);
 				goto error;
 			}
 			break;
 		default:
-			printk(KERN_WARNING "dnbd3: Unknown command (Receive)\n");
+			warn_sock(sock, "unknown command eeceived");
 			break;
 		}
 error:
 		handle = dnbd3_to_wq_signal(dev->minor, dnbd3_reply.cmd, sock->sock_nr);
-		printk(KERN_DEBUG "dnbd3: try to wake up queue with handle %llu\n", handle);
-		send_wq_signal = handle;
+		atomic64_set(&send_wq_signal, handle);
 		wake_up_interruptible(&send_wq);
 		if (result == 0) {
-			printk(KERN_INFO "dnbd3: result is 0, socket seems to be down\n");
+			info_sock(sock, "result is 0, socket seems to be down");
 			sock->panic = 1;
-//			dnbd3_socket_disconnect(dev, NULL, sock, false);//TODO use panic or something or start worker to reconnect?
 			break; //the socket seems to be down
 		} else if (result < 0) {
 			sock->server->failures++; // discovery takes care of to many failures
-			printk(KERN_WARNING "dnbd3: receive error happened %d, total failures %d\n", result, sock->server->failures);
+			warn_sock(sock, "receive error happened %d, total failures %d", result, sock->server->failures);
 		}
-		printk(KERN_DEBUG "dnbd3: receive completed, waiting for next receive\n");
+		debug_sock(sock, "receive completed, waiting for next receive");
 	}
-	printk(KERN_DEBUG "dnbd3: receive work queue is stopped\n");
+
+	debug_dev(dev, "receive work queue is stopped");
 }
 
 
@@ -526,7 +512,7 @@ static void dnbd3_timer(struct timer_list *arg)
 
 	if (dev->timer_count % TIMER_INTERVAL_KEEPALIVE_PACKET == 0) {
 		for (i = 0; i < NUMBER_CONNECTIONS; i++) {
-			if (dev->socks[i].sock && dev->socks[i].server) {
+			if (dnbd3_is_sock_alive(dev->socks[i])) {
 				queue_work(dnbd3_wq, &dev->socks[i].keepalive_worker);
 			}
 		}
@@ -545,7 +531,7 @@ static void dnbd3_timer(struct timer_list *arg)
 static void dnbd3_keepalive_worker(struct work_struct *work)
 {
 	struct dnbd3_sock *sock = container_of(work, struct dnbd3_sock, keepalive_worker);
-	printk(KERN_DEBUG "dnbd3: starting keepalive worker\n");
+	debug_sock(sock, "starting keepalive worker");
 	dnbd3_send_request_blocking(sock, CMD_KEEPALIVE);
 }
 
@@ -555,14 +541,16 @@ static struct dnbd3_server *dnbd3_find_best_alt_server(struct dnbd3_device *dev)
 	uint64_t best_rtt = RTT_UNREACHABLE;
 	struct dnbd3_server *best_alt_server = NULL;
 	for (i = 0; i < NUMBER_SERVERS; i++) {
-		rtt = (dev->alt_servers[i].rtts[0] + dev->alt_servers[i].rtts[1]
-				+ dev->alt_servers[i].rtts[2] + dev->alt_servers[i].rtts[3]) / 4;
-		if (rtt < best_rtt) {
-			best_alt_server = &dev->alt_servers[i];
-			for (j = 0; j < NUMBER_CONNECTIONS; j++) {
-				if (best_alt_server == dev->socks[j].server) {
-					best_alt_server = NULL; // found already connected server
-					break;
+		if (dev->alt_servers[i].host.type != 0) {
+			rtt = (dev->alt_servers[i].rtts[0] + dev->alt_servers[i].rtts[1]
+					+ dev->alt_servers[i].rtts[2] + dev->alt_servers[i].rtts[3]) / 4;
+			if (rtt <= best_rtt) {
+				best_alt_server = &dev->alt_servers[i];
+				for (j = 0; j < NUMBER_CONNECTIONS; j++) {
+					if (best_alt_server == dev->socks[j].server) {
+						best_alt_server = NULL; // found already connected server
+						break;
+					}
 				}
 			}
 		}
@@ -580,29 +568,31 @@ static void dnbd3_panic_worker(struct work_struct *work)
 	for (i = 0; i < NUMBER_CONNECTIONS; i++) {
 		if (dev->socks[i].panic) {
 			panicked_sock = &dev->socks[i];
-		} else if (dev->socks[i].sock && dev->socks[i].server) {
+		} else if (dnbd3_is_sock_alive(dev->socks[i])) {
 			sock_alive++;
 		}
 	}
 	if (panicked_sock) {
-		printk(KERN_WARNING "dnbd3: socket %d panicked, connections still alive %d\n", panicked_sock->sock_nr, sock_alive);
+		warn_sock(panicked_sock, "panicked, connections still alive %d", sock_alive);
 		panicked_server = panicked_sock->server;
 		dnbd3_socket_disconnect(dev, panicked_server, panicked_sock);
 
 		new_server = dnbd3_find_best_alt_server(dev);
 		if (new_server != NULL && new_server != panicked_server) {
-			printk(KERN_INFO "dnbd3: found replacement server\n");
+			print_server(KERN_INFO, dev, new_server, "found replacement");
 			dnbd3_socket_connect(dev, new_server);
 		} else if (sock_alive > 0) {
-			printk(KERN_INFO "dnbd3: found no replacement server but still connected to %d servers\n", sock_alive);
+			info_sock(panicked_sock, "found no replacement server but still connected to %d servers", sock_alive);
 		} else {
-			printk(KERN_ERR "dnbd3: could not reconnect to server\n");
+			error_sock(panicked_sock, "could not reconnect to server");
 		}
 	} else if (sock_alive == 0) {
 		new_server = dnbd3_find_best_alt_server(dev);
 		if (new_server != NULL) {
-			printk(KERN_INFO "dnbd3: reconnect to server\n");
+			print_server(KERN_INFO, dev, new_server, "reconnect to server");
 			dnbd3_socket_connect(dev, new_server);
+		} else {
+			error_sock(panicked_sock, "could not reconnect to server");
 		}
 	}
 }
@@ -611,7 +601,7 @@ static void dnbd3_panic_worker(struct work_struct *work)
 static void dnbd3_discovery_worker(struct work_struct *work)
 {
 	struct dnbd3_device *dev = container_of(work, struct dnbd3_device, discovery_worker);
-	struct dnbd3_sock *sock = NULL;
+	struct dnbd3_sock *sock = &dev->socks[0];
 	int i, j;
 	struct dnbd3_server *existing_server, *free_server, *failed_server;
 	dnbd3_server_entry_t *new_server;
@@ -624,11 +614,11 @@ static void dnbd3_discovery_worker(struct work_struct *work)
 	struct request *req = NULL;
 	uint64_t rtt;
 	serialized_buffer_t *payload;
-	printk(KERN_DEBUG "dnbd3: starting discovery worker\n");
+	debug_sock(sock, "starting discovery worker");
 
-	dnbd3_send_request_blocking(&dev->socks[0], CMD_GET_SERVERS);
+	dnbd3_send_request_blocking(sock, CMD_GET_SERVERS);
 
-	printk(KERN_DEBUG "dnbd3: new server num is %d\n", dev->new_servers_num);
+	debug_sock(sock, "new server num is %d", dev->new_servers_num);
 	if (dev->new_servers_num) {
 		mutex_lock(&dev->device_lock);
 
@@ -657,7 +647,7 @@ static void dnbd3_discovery_worker(struct work_struct *work)
 
 				if (existing_server) {
 					if (new_server->failures == 1) { // remove is requested
-						dnbd3_print_host(&existing_server->host, "remove server");
+						print_server(KERN_INFO, dev, new_server, "remove server is requested");
 						dnbd3_socket_disconnect(dev, existing_server, NULL); // TODO what to do when only one connection?
 						existing_server->host.type = 0;
 					}
@@ -672,7 +662,7 @@ static void dnbd3_discovery_worker(struct work_struct *work)
 					//no server found to replace
 					continue;
 				}
-				dnbd3_print_host(&free_server->host, "got new alt server");
+				print_server(KERN_INFO, dev, free_server, "got new alt server");
 				free_server->failures = 0;
 				free_server->protocol_version = 0;
 				free_server->rtts[0] = free_server->rtts[1] = free_server->rtts[2] = free_server->rtts[3] = RTT_UNREACHABLE;
@@ -683,22 +673,23 @@ static void dnbd3_discovery_worker(struct work_struct *work)
 	}
 	buf = kmalloc(RTT_BLOCK_SIZE, GFP_KERNEL);
 	if (!buf) {
-		printk(KERN_ERR "dnbd3: kmalloc failed\n");
+		error_dev(dev, "kmalloc failed");
 		goto error;
 	}
 	payload = (serialized_buffer_t *)buf;
 	req = kmalloc(sizeof(struct request), GFP_KERNEL);
 	if (!req) {
-		printk(KERN_ERR "dnbd3: kmalloc failed\n");
+		error_dev(dev, "kmalloc failed");
 		goto error;
 	}
 	sock = kmalloc(sizeof(struct dnbd3_sock), GFP_KERNEL);
 	if (!sock) {
-		printk(KERN_ERR "dnbd3: kmalloc failed\n");
+		error_dev(dev, "kmalloc failed");
 		goto error;
 	}
 	mutex_init(&sock->lock);
 	mutex_lock(&sock->lock);
+	sock->sock_nr = NUMBER_CONNECTIONS;
 	// measure rtt for all alt servers
 	for (i = 0; i < NUMBER_SERVERS; i++) {
 		existing_server = &dev->alt_servers[i];
@@ -707,27 +698,27 @@ static void dnbd3_discovery_worker(struct work_struct *work)
 			sock->device = dev;
 			sock->server = existing_server;
 			if (__dnbd3_socket_connect(existing_server, sock)) {
-				printk(KERN_ERR "dnbd3: socket connect failed in rtt measurement\n");
+				error_sock(sock, "socket connect failed in rtt measurement");
 				goto rtt_error;
 			}
 			dnbd3_connect(req);
 			if (dnbd3_send_request(sock, req, NULL)) {
-				printk(KERN_ERR "dnbd3: request select image failed in rtt measurement\n");
+				error_sock(sock, "request select image failed in rtt measurement");
 				goto rtt_error;
 			}
 
 			if (dnbd3_receive_cmd(sock, &dnbd3_reply) <= 0) {
-				printk(KERN_ERR "dnbd3: receive select image failed in rtt measurement\n");
+				error_sock(sock, "receive select image failed in rtt measurement");
 				goto rtt_error;
 
 			}
 			if (dnbd3_reply.magic != dnbd3_packet_magic || dnbd3_reply.cmd != CMD_SELECT_IMAGE || dnbd3_reply.size < 4) {
-				printk(KERN_ERR "dnbd3: receive select image wrong header in rtt measurement\n");
+				error_sock(sock, "receive select image wrong header in rtt measurement");
 				goto rtt_error;
 			}
 
 			if (dnbd3_receive_cmd_select_image(dev, sock, &dnbd3_reply) <= 0) {
-				printk(KERN_ERR "dnbd3: receive data select image failed in rtt measurement\n");
+				error_sock(sock, "receive data select image failed in rtt measurement");
 				goto rtt_error;
 			}
 
@@ -746,19 +737,19 @@ static void dnbd3_discovery_worker(struct work_struct *work)
 			do_gettimeofday(&start);
 
 			if (kernel_sendmsg(sock->sock, &msg, &iov, 1, sizeof(dnbd3_request)) <= 0) {
-				printk(KERN_ERR "dnbd3: request test block failed in rtt measurement\n");
+				error_sock(sock, "request test block failed in rtt measurement");
 				goto rtt_error;
 			}
 			// receive net reply
 			iov.iov_base = &dnbd3_reply;
 			iov.iov_len = sizeof(dnbd3_reply);
 			if ((j = kernel_recvmsg(sock->sock, &msg, &iov, 1, sizeof(dnbd3_reply), msg.msg_flags)) != sizeof(dnbd3_reply)) {
-				printk(KERN_ERR "dnbd3: receive header test block failed in rtt measurement %d %ld\n", j, sizeof(dnbd3_reply));
+				error_sock(sock, "receive header test block failed in rtt measurement %d %ld", j, sizeof(dnbd3_reply));
 				goto rtt_error;
 			}
 			fixup_reply(dnbd3_reply);
 			if (dnbd3_reply.magic != dnbd3_packet_magic|| dnbd3_reply.cmd != CMD_GET_BLOCK || dnbd3_reply.size != RTT_BLOCK_SIZE) {
-				printk(KERN_ERR "dnbd3: receive header cmd test block failed in rtt measurement\n");
+				error_sock(sock, "receive header cmd test block failed in rtt measurement");
 				goto rtt_error;
 			}
 
@@ -766,7 +757,7 @@ static void dnbd3_discovery_worker(struct work_struct *work)
 			iov.iov_base = buf;
 			iov.iov_len = RTT_BLOCK_SIZE;
 			if (kernel_recvmsg(sock->sock, &msg, &iov, 1, dnbd3_reply.size, msg.msg_flags) != RTT_BLOCK_SIZE) {
-				printk(KERN_ERR "dnbd3: receive test block failed in rtt measurement\n");
+				error_sock(sock, "receive test block failed in rtt measurement");
 				goto rtt_error;
 			}
 
@@ -774,7 +765,7 @@ static void dnbd3_discovery_worker(struct work_struct *work)
 
 			rtt = (uint64_t)((end.tv_sec - start.tv_sec) * 1000000ull + (end.tv_usec - start.tv_usec));
 
-			printk(KERN_DEBUG "dnbd3: new rrt for %pI4 is %llu\n", existing_server->host.addr, rtt);
+			debug_sock(sock, "new rrt is %llu", rtt);
 
 rtt_error:
 			if (sock->sock) {
@@ -811,11 +802,11 @@ static int __dnbd3_socket_connect(struct dnbd3_server *server, struct dnbd3_sock
 	struct timeval timeout;
 
 	if (server->host.port == 0 || server->host.type == 0) {
-		printk(KERN_ERR "dnbd3: host or port not set\n");
+		error_sock(sock, "host or port not set");
 		return -EIO;
 	}
 	if (sock->sock) {
-		printk(KERN_WARNING "dnbd3: socket already connected\n");
+		warn_sock(sock, "already connected");
 		return -EIO;
 	}
 
@@ -823,7 +814,7 @@ static int __dnbd3_socket_connect(struct dnbd3_server *server, struct dnbd3_sock
 	timeout.tv_usec = 0;
 
 	if ((result = dnbd3_sock_create(server->host.type, SOCK_STREAM, IPPROTO_TCP, &sock->sock)) < 0) {
-		printk(KERN_ERR "dnbd3: could not create socket\n");
+		error_sock(sock, "could not create socket");
 		goto error;
 	}
 
@@ -837,7 +828,7 @@ static int __dnbd3_socket_connect(struct dnbd3_server *server, struct dnbd3_sock
 		memcpy(&(sin.sin_addr), server->host.addr, 4);
 		sin.sin_port = server->host.port;
 		if ((result = kernel_connect(sock->sock, (struct sockaddr *)&sin, sizeof(sin), 0)) != 0) {
-			printk(KERN_ERR "dnbd3: connection to host failed (ipv4)\n");
+			error_sock(sock, "connection to host failed");
 			goto error;
 		}
 	} else {
@@ -847,7 +838,7 @@ static int __dnbd3_socket_connect(struct dnbd3_server *server, struct dnbd3_sock
 		memcpy(&(sin.sin6_addr), server->host.addr, 16);
 		sin.sin6_port = server->host.port;
 		if ((result = kernel_connect(sock->sock, (struct sockaddr *)&sin, sizeof(sin), 0)) != 0){
-			printk(KERN_ERR "dnbd3: connection to host failed (ipv6)\n");
+			error_sock(sock, "connection to host failed");
 			goto error;
 		}
 	}
@@ -868,18 +859,19 @@ static int dnbd3_socket_connect(struct dnbd3_device *dev, struct dnbd3_server *s
 	int result = -EIO;
 	struct dnbd3_sock *sock = NULL;
 	for (i = 0; i < NUMBER_CONNECTIONS; i++) {
-		if (!dev->socks[i].sock) {
+		if (!dnbd3_is_sock_alive(dev->socks[i])) {
 			sock = &dev->socks[i];
 			break;
 		}
 	}
 	if (sock == NULL) {
-		printk(KERN_WARNING "dnbd3: could not connect to socket, to many connections\n");
+		print_server(KERN_ERR, dev, server, "could not connect to socket, to many connections");
 		return -EIO;
 	}
 	sock->server = server;
 
-	printk(KERN_DEBUG "dnbd3: socket connect device %i\n", dev->minor);
+
+	debug_sock(sock, "socket connect");
 
 
 	mutex_init(&sock->lock);
@@ -887,7 +879,7 @@ static int dnbd3_socket_connect(struct dnbd3_device *dev, struct dnbd3_server *s
 	__dnbd3_socket_connect(server, sock);
 	mutex_unlock(&sock->lock);
 	if (!sock->sock) {
-		printk(KERN_DEBUG "dnbd3: socket is not connected\n");
+		error_sock(sock, "socket is not connected");
 		result = -EIO;
 		goto error;
 	}
@@ -898,12 +890,12 @@ static int dnbd3_socket_connect(struct dnbd3_device *dev, struct dnbd3_server *s
 
 	result = dnbd3_send_request_blocking(sock, CMD_SELECT_IMAGE);
 	if (result) {
-		printk(KERN_ERR "dnbd3: connection to image %s failed\n", dev->imgname);
+		error_sock(sock, "connection to image %s failed", dev->imgname);
 		goto error;
 
 	}
 
-	printk(KERN_DEBUG "dnbd3: connected to image %s, filesize %llu\n", dev->imgname, dev->reported_size);
+	debug_sock(sock, "connected to image %s, filesize %llu", dev->imgname, dev->reported_size);
 
 	INIT_WORK(&sock->keepalive_worker, dnbd3_keepalive_worker);
 
@@ -912,6 +904,14 @@ static int dnbd3_socket_connect(struct dnbd3_device *dev, struct dnbd3_server *s
 			sock_alive++;
 		}
 	}
+	if (sock_alive == 1) { // first socket to connect, start timer and workers
+		debug_sock(sock, "first connection to server, starting workers");
+		INIT_WORK(&dev->discovery_worker, dnbd3_discovery_worker);
+		INIT_WORK(&dev->panic_worker, dnbd3_panic_worker);
+		timer_setup(&dev->timer, dnbd3_timer, 0);
+		dev->timer.expires = jiffies + HZ;
+		add_timer(&dev->timer);
+	}
 	blk_mq_update_nr_hw_queues(&dev->tag_set, sock_alive);
 	return 0;
 error:
@@ -931,17 +931,17 @@ static int dnbd3_socket_disconnect(struct dnbd3_device *dev, struct dnbd3_server
 		if (sock == NULL && dev->socks[i].server == server) {
 			sock = &dev->socks[i];
 		}
-		if (dev->socks[i].sock && dev->socks[i].server) {
+		if (dnbd3_is_sock_alive(dev->socks[i])) {
 			sock_alive++;
 		}
 	}
 	if (!sock || !sock->sock) {
-		printk(KERN_WARNING "dnbd3: could not find socket to disconnect\n");
+		warn_dev(dev, "could not find socket to disconnect");
 		return -EIO;
 	}
 	blk_mq_update_nr_hw_queues(&dev->tag_set, sock_alive - 1);
 	if (sock_alive <= 1) {
-		printk(KERN_INFO "dnbd3: shutting down last socket and stopping discovery\n");
+		info_sock(sock, "shutting down last socket and stopping discovery");
 		del_timer_sync(&dev->timer);
 		dev->timer_count = 0;
 		cancel_work_sync(&dev->discovery_worker);
@@ -950,7 +950,7 @@ static int dnbd3_socket_disconnect(struct dnbd3_device *dev, struct dnbd3_server
 	}
 	cancel_work_sync(&sock->keepalive_worker);
 
-	printk(KERN_DEBUG "dnbd3: socket disconnect device %i\n", dev->minor);
+	debug_sock(sock, "socket disconnect");
 	mutex_lock(&sock->lock);
 
 	/*
@@ -964,12 +964,10 @@ static int dnbd3_socket_disconnect(struct dnbd3_device *dev, struct dnbd3_server
 	 */
 	if (sock->sock) {
 		kernel_sock_shutdown(sock->sock, SHUT_RDWR);
-		sock->server = NULL;
 	}
 	mutex_unlock(&sock->lock);
 	mutex_destroy(&sock->lock);
 
-	printk(KERN_DEBUG "dnbd3: cancel receiver work device %i\n", dev->minor);
 	cancel_work_sync(&sock->receive_worker);
 
 	if (sock->sock) {
@@ -977,6 +975,7 @@ static int dnbd3_socket_disconnect(struct dnbd3_device *dev, struct dnbd3_server
 		sock->sock = NULL;
 	}
 	sock->panic = 0;
+	sock->server = NULL;
 	return 0;
 }
 
@@ -998,20 +997,16 @@ int dnbd3_net_disconnect(struct dnbd3_device *dev)
 
 int dnbd3_net_connect(struct dnbd3_device *dev)
 {
-	// TODO decide which socket to connect
 	int result;
-	if (dnbd3_socket_connect(dev, &dev->alt_servers[0]) == 0) {
+	debug_dev(dev, "connecting to server");
+
+	if (dnbd3_socket_connect(dev, &dev->initial_server) == 0) {
 		dnbd3_print_server_list(dev);
 
-		INIT_WORK(&dev->discovery_worker, dnbd3_discovery_worker);
-		INIT_WORK(&dev->panic_worker, dnbd3_panic_worker);
-		timer_setup(&dev->timer, dnbd3_timer, 0);
-		dev->timer.expires = jiffies + HZ;
-		add_timer(&dev->timer);
 
 		result = 0;
 	} else {
-		printk(KERN_ERR "dnbd3: failed to connect to initial server\n");
+		error_dev(dev, "failed to connect to initial server");
 		result = -ENOENT;
 		dev->imgname = NULL;
 		dev->socks[0].server = NULL;