added macros for debugging

4 files changed, 225 insertions, 185 deletions

diff --git a/src/kernel/core.c b/src/kernel/core.c
index 4704b0d..2664090 100644
--- a/src/kernel/core.c
+++ b/src/kernel/core.c
@@ -82,7 +82,7 @@ static int dnbd3_handle_cmd(struct dnbd3_cmd *cmd, int index)
 	int i;
 	int sock_alive = 0;
 
-	printk(KERN_DEBUG "dnbd3: handle request at position %lu and size %d, device %i\n", blk_rq_pos(req), blk_rq_bytes(req), dev->minor);
+	debug_dev(dev, "handle request at position %lu and size %d", blk_rq_pos(req), blk_rq_bytes(req));
 
 //	if (index >= 1) { // TODO use next server with good rtt for this request
 //		printk(KERN_INFO "dnbd3: index is %d", index);
@@ -92,7 +92,7 @@ static int dnbd3_handle_cmd(struct dnbd3_cmd *cmd, int index)
 //	}
 
 	for (i = 0; i < NUMBER_CONNECTIONS; i++) {
-		if (dev->socks[i].sock && dev->socks[i].server) {
+		if (dnbd3_is_sock_alive(dev->socks[i])) {
 			if (index == sock_alive) {
 				sock = &dev->socks[index];
 			}
@@ -101,7 +101,7 @@ static int dnbd3_handle_cmd(struct dnbd3_cmd *cmd, int index)
 	}
 
 	if (!sock) {
-		printk(KERN_INFO "dnbd3: index is %d but no socket was found\n", index);
+		warn_dev(dev, "index is %d but no socket was found", index);
 		dev_err_ratelimited(disk_to_dev(dev->disk), "attempted send on invalid socket\n");
 		if (sock_alive > 0) {
 			blk_mq_update_nr_hw_queues(&dev->tag_set, sock_alive);
@@ -115,13 +115,10 @@ static int dnbd3_handle_cmd(struct dnbd3_cmd *cmd, int index)
 
 	cmd->status = BLK_STS_OK;
 
-again:
-
-
 	mutex_lock(&sock->lock);
 	if (unlikely(!sock->sock)) {
 		mutex_unlock(&sock->lock);
-		printk(KERN_DEBUG "dnbd3: not connected\n");
+		warn_sock(sock, "not connected");
 		return -EIO;
 	}
 
@@ -149,8 +146,7 @@ static blk_status_t dnbd3_queue_rq(struct blk_mq_hw_ctx *hctx, const struct blk_
 	int ret;
 	struct dnbd3_device *dev = cmd->dnbd3;
 
-	printk(KERN_DEBUG "dnbd3: queue request device %i\n", dev->minor);
-
+	debug_dev(dev, "queue request");
 
 	mutex_lock(&cmd->lock);
 	clear_bit(DNBD3_CMD_REQUEUED, &cmd->flags);
@@ -167,12 +163,6 @@ static blk_status_t dnbd3_queue_rq(struct blk_mq_hw_ctx *hctx, const struct blk_
 	return ret;
 }
 
-static void dnbd3_complete_rq(struct request *req)
-{
-	printk(KERN_DEBUG "dnbd3: dnbd3_complete_rq\n");
-
-}
-
 static int dnbd3_init_request(struct blk_mq_tag_set *set, struct request *rq, unsigned int hctx_idx, unsigned int numa_node)
 {
 	struct dnbd3_cmd *cmd = blk_mq_rq_to_pdu(rq);
@@ -186,15 +176,15 @@ static enum blk_eh_timer_return dnbd3_xmit_timeout(struct request *req, bool res
 	struct dnbd3_cmd *cmd = blk_mq_rq_to_pdu(req);
 	struct dnbd3_device *dev = cmd->dnbd3;
 	int i;
-	printk(KERN_WARNING "dnbd3: received timeout\n");
+	warn_dev(dev, "received timeout");
 
 	if (!mutex_trylock(&cmd->lock)) {
 		return BLK_EH_RESET_TIMER;
 	}
 
 	for (i = 0; i < NUMBER_CONNECTIONS; i++) {
-		if (dev->socks[i].sock && dev->socks[i].server) {
-			printk(KERN_INFO "dnbd3: reset request\n");
+		if (dnbd3_is_sock_alive(dev->socks[i])) {
+			info_sock(&dev->socks[i], "reset request to new socket");
 			dnbd3_requeue_cmd(cmd);
 			return BLK_EH_DONE;
 		}
@@ -210,7 +200,6 @@ static enum blk_eh_timer_return dnbd3_xmit_timeout(struct request *req, bool res
 
 static struct blk_mq_ops dnbd3_mq_ops = {
 	.queue_rq = dnbd3_queue_rq,
-	.complete = dnbd3_complete_rq,
 	.init_request = dnbd3_init_request,
 	.timeout = dnbd3_xmit_timeout,
 };
@@ -218,13 +207,6 @@ static struct blk_mq_ops dnbd3_mq_ops = {
 
 
 
-static void dnbd3_blk_fail_all_requests(struct dnbd3_device *dev)
-{
-	printk(KERN_DEBUG "dnbd3: fail all requests device %i\n", dev->minor);
-}
-
-
-
 static int dnbd3_ioctl(struct block_device *bdev, fmode_t mode, unsigned int cmd, unsigned long arg)
 {
 	int result = -EIO;
@@ -232,7 +214,8 @@ static int dnbd3_ioctl(struct block_device *bdev, fmode_t mode, unsigned int cmd
 	char *imgname = NULL;
 	dnbd3_ioctl_t *msg = NULL;
 
-	printk(KERN_DEBUG "dnbd3: ioctl device %i, cmd %i, arg %lu\n", dev->minor, cmd, arg);
+
+	debug_dev(dev, "ioctl cmd %i, arg %lu", cmd, arg);
 
 	if (arg != 0) {
 		msg = kmalloc(sizeof(*msg), GFP_KERNEL);
@@ -257,14 +240,14 @@ static int dnbd3_ioctl(struct block_device *bdev, fmode_t mode, unsigned int cmd
 			}
 			imgname[msg->imgnamelen] = '\0';
 
-			printk(KERN_DEBUG "dnbd3: ioctl image name of len %i is %s\n", (int)msg->imgnamelen, imgname);
+			debug_dev(dev, "ioctl image name of len %i is %s", (int)msg->imgnamelen, imgname);
 		}
 	}
 
 	mutex_lock(&dev->device_lock);
 	switch (cmd) {
 	case IOCTL_OPEN:
-		printk(KERN_DEBUG "dnbd3: ioctl open\n");
+		debug_dev(dev, "ioctl open");
 		if (dev->imgname != NULL) {
 			result = -EBUSY;
 		} else if (imgname == NULL) {
@@ -273,7 +256,7 @@ static int dnbd3_ioctl(struct block_device *bdev, fmode_t mode, unsigned int cmd
 			result = -EINVAL;
 		} else {
 			if (sizeof(msg->host) != sizeof(dev->initial_server.host)) {
-				printk(KERN_INFO "dnbd3: odd size bug#1 triggered in ioctl\n");
+				warn_dev(dev, "odd size bug#1 triggered in ioctl");
 			}
 			memcpy(&dev->initial_server.host, &msg->host, sizeof(msg->host));
 			dev->initial_server.failures = 0;
@@ -284,25 +267,14 @@ static int dnbd3_ioctl(struct block_device *bdev, fmode_t mode, unsigned int cmd
 			// Forget all alt servers on explicit connect, set first alt server to initial server
 			memset(dev->alt_servers, 0, sizeof(dev->alt_servers[0])*NUMBER_SERVERS);
 			memcpy(dev->alt_servers, &dev->initial_server, sizeof(dev->alt_servers[0]));
-//#if LINUX_VERSION_CODE >= KERNEL_VERSION(4, 11, 0)
-//			if (blk_queue->backing_dev_info != NULL) {
-//				blk_queue->backing_dev_info->ra_pages = (msg->read_ahead_kb * 1024) / PAGE_SIZE;
-//			}
-//#else
-//			blk_queue->backing_dev_info.ra_pages = (msg->read_ahead_kb * 1024) / PAGE_SIZE;
-//#endif
-
-
 			result = dnbd3_net_connect(dev);
 			imgname = NULL;
 		}
 		break;
 
 	case IOCTL_CLOSE:
-		printk(KERN_DEBUG "dnbd3: ioctl close\n");
-		dnbd3_blk_fail_all_requests(dev);
+		debug_dev(dev, "ioctl close");
 		result = dnbd3_net_disconnect(dev);
-		dnbd3_blk_fail_all_requests(dev);
 		set_capacity(dev->disk, 0);
 		if (dev->imgname) {
 			kfree(dev->imgname);
@@ -313,13 +285,13 @@ static int dnbd3_ioctl(struct block_device *bdev, fmode_t mode, unsigned int cmd
 		break;
 
 	case IOCTL_SWITCH:
-		printk(KERN_DEBUG "dnbd3: ioctl switch\n");
+		debug_dev(dev, "ioctl switch");
 		result = -EINVAL;
 		break;
 
 	case IOCTL_ADD_SRV:
 	case IOCTL_REM_SRV:
-		printk(KERN_DEBUG "dnbd3: ioctl add/rem srv\n");
+		debug_dev(dev, "ioctl add/rem srv");
 		if (dev->imgname == NULL) {
 			result = -ENOENT;
 		} else if (dev->new_servers_num >= NUMBER_SERVERS) {
@@ -335,12 +307,12 @@ static int dnbd3_ioctl(struct block_device *bdev, fmode_t mode, unsigned int cmd
 		break;
 
 	case BLKFLSBUF:
-		printk(KERN_DEBUG "dnbd3: ioctl blkflsbuf\n");
+		debug_dev(dev, "ioctl blkflsbuf");
 		result = 0;
 		break;
 
 	default:
-		printk(KERN_DEBUG "dnbd3: ioctl unhandled cmd %d\n", cmd);
+		warn_dev(dev, "ioctl unhandled cmd %d", cmd);
 		result = -EIO;
 		break;
 	}
@@ -371,7 +343,7 @@ int dnbd3_add_device(struct dnbd3_device *dev, int minor)
 	struct request_queue *q;
 	int err = -ENOMEM;
 	int i;
-	printk(KERN_DEBUG "dnbd3: adding device %i\n", minor);
+	debug("adding device %d", minor);
 
 	mutex_init(&dev->device_lock);
 	mutex_lock(&dev->device_lock);
@@ -383,13 +355,13 @@ int dnbd3_add_device(struct dnbd3_device *dev, int minor)
 
 	disk = alloc_disk(1);
 	if (!disk) {
-		printk(KERN_WARNING "dnbd3: alloc_disc failed device %i\n", minor);
+		error_dev(dev, "allocating disc failed");
 		goto out_free_dnbd3;
 	}
 
 	err = idr_alloc(&dnbd3_index_idr, dev, minor, minor + 1, GFP_KERNEL);
 	if (err == -ENOSPC) {
-		printk(KERN_WARNING "dnbd3: idr_alloc failed device %i\n", minor);
+		error_dev(dev, "idr alloc failed");
 		err = -EEXIST;
 	}
 
@@ -437,11 +409,9 @@ int dnbd3_add_device(struct dnbd3_device *dev, int minor)
 	disk->fops = &dnbd3_fops;
 	disk->private_data = dev;
 	sprintf(disk->disk_name, "dnbd%i", minor);
-	printk(KERN_DEBUG "dnbd3: add disk device %s\n", disk->disk_name);
 	add_disk(disk);
 	dnbd3_sysfs_init(dev);
 
-
 	mutex_unlock(&dev->device_lock);
 	return minor;
 
@@ -454,7 +424,7 @@ out_free_disk:
 out_free_dnbd3:
 	kfree(dev);
 	mutex_unlock(&dev->device_lock);
-	printk(KERN_DEBUG "dnbd3: destroy device %i\n", minor);
+	warn_dev(dev, "failed to create device");
 	return err;
 }
 
@@ -464,30 +434,30 @@ out_free_dnbd3:
 static int __init dnbd3_init(void)
 {
 	int i;
-	printk(KERN_DEBUG "dnbd3: starting kernel module\n");
+	debug("starting kernel module");
 
 	dnbd3_wq = alloc_workqueue("kdnbd3", WQ_MEM_RECLAIM | WQ_FREEZABLE | WQ_UNBOUND, 0);
 
 	if (max_devs < 0) {
-		printk(KERN_ERR "dnbd3: max_devs must be >= 0\n");
+		error("max_devs must be >= 0");
 		return -EINVAL;
 	}
 
 
 	device = kcalloc(max_devs, sizeof(*device), GFP_KERNEL);
 	if (!device) {
-		printk(KERN_ERR "dnbd3: failed to create dnbd3 device\n");
+		error("failed to create dnbd3 device");
 		return -ENOMEM;
 	}
 
 	// initialize block device
 	major = register_blkdev(0, "dnbd3");
 	if (major == 0) {
-		printk(KERN_ERR "dnbd3: register_blkdev failed\n");
+		error("register_blkdev failed");
 		return -EIO;
 	}
 
-	printk(KERN_DEBUG "dnbd3: kernel module loaded. Machine type: " ENDIAN_MODE "\n");
+	debug("kernel module loaded. Machine type: " ENDIAN_MODE);
 
 	// add MAX_NUMBER_DEVICES devices
 	mutex_lock(&dnbd3_index_mutex);
@@ -496,7 +466,7 @@ static int __init dnbd3_init(void)
 	}
 	mutex_unlock(&dnbd3_index_mutex);
 
-	printk(KERN_INFO "dnbd3: init successful (%i devices).\n", max_devs);
+	info("init successful (%i devices)", max_devs);
 
 	return 0;
 }
@@ -545,7 +515,7 @@ static void __exit dnbd3_exit(void)
 {
 	struct dnbd3_device *dnbd3;
 	LIST_HEAD(del_list);
-	printk(KERN_DEBUG "dnbd3: stopping kernel module\n");
+	debug("stopping kernel module");
 
 	mutex_lock(&dnbd3_index_mutex);
 	idr_for_each(&dnbd3_index_idr, &dnbd3_exit_cb, &del_list);
@@ -565,7 +535,7 @@ static void __exit dnbd3_exit(void)
 
 	destroy_workqueue(dnbd3_wq);
 
-	printk(KERN_INFO "dnbd3: stopped kernel module\n");
+	info("stopped kernel module");
 }
 
 
diff --git a/src/kernel/dnbd3.h b/src/kernel/dnbd3.h
index feb09ae..0b225c9 100644
--- a/src/kernel/dnbd3.h
+++ b/src/kernel/dnbd3.h
@@ -32,6 +32,7 @@
 
 
 #define NUMBER_CONNECTIONS 4
+#define DEBUG
 
 
 extern struct workqueue_struct *dnbd3_wq;
@@ -101,4 +102,75 @@ struct dnbd3_cmd {
 };
 
 
+#define _print_sock(level, sock, fmt, ...) \
+	do { \
+		if ((sock)->server->host.type == HOST_IP4) { \
+			printk(level "dnbd%d/%d %pI4:%d: " fmt "\n", (sock)->device->minor, (sock)->sock_nr, (sock)->server->host.addr, (sock)->server->host.port, ## __VA_ARGS__); \
+		} else { \
+			printk(level "dnbd%d/%d %pI6:%d: " fmt "\n", (sock)->device->minor, (sock)->sock_nr, (sock)->server->host.addr, (sock)->server->host.port, ## __VA_ARGS__); \
+		} \
+	} while (0)
+
+#define print_server(level, dev, server, fmt, ...) \
+	do { \
+		if ((server)->host.type == HOST_IP4) { \
+			printk(level "dnbd%d: " fmt " %pI4:%d\n", (dev)->minor, ## __VA_ARGS__, (server)->host.addr, (server)->host.port); \
+		} else { \
+			printk(level "dnbd%d: " fmt " %pI6:%d\n", (dev)->minor, ## __VA_ARGS__, (server)->host.addr, (server)->host.port); \
+		} \
+	} while (0)
+
+
+#ifdef DEBUG
+
+#define debug(fmt, ...) \
+	printk(KERN_DEBUG "dnbd: " fmt "\n", ## __VA_ARGS__)
+
+#define debug_dev(dev, fmt, ...) \
+	printk(KERN_DEBUG "dnbd%d: " fmt "\n", (dev)->minor, ## __VA_ARGS__)
+
+#define debug_sock(sock, fmt, ...) \
+	_print_sock(KERN_DEBUG, sock, fmt, ## __VA_ARGS__)
+
+
+#else
+
+#define debug(fmt, ...)
+
+#define debug_dev(dev, fmt, ...)
+
+#define debug_sock(sock, fmt, ...)
+
+
+#endif
+
+#define info(fmt, ...) \
+	printk(KERN_INFO "dnbd: " fmt "\n", ## __VA_ARGS__)
+
+#define info_dev(dev, fmt, ...) \
+	printk(KERN_INFO "dnbd%d: " fmt "\n", (dev)->minor, ## __VA_ARGS__)
+
+#define info_sock(sock, fmt, ...) \
+	_print_sock(KERN_DEBUG, sock, fmt, ## __VA_ARGS__)
+
+
+#define warn(fmt, ...) \
+	printk(KERN_WARNING "dnbd: " fmt "\n", ## __VA_ARGS__)
+
+#define warn_dev(dev, fmt, ...) \
+	printk(KERN_WARNING "dnbd%d: " fmt "\n", (dev)->minor, ## __VA_ARGS__)
+
+#define warn_sock(sock, fmt, ...) \
+	_print_sock(KERN_WARNING, sock, fmt, ## __VA_ARGS__)
+
+
+#define error(fmt, ...) \
+	printk(KERN_ERR "dnbd: " fmt "\n", ## __VA_ARGS__)
+
+#define error_dev(dev, fmt, ...) \
+	printk(KERN_ERR "dnbd%d: " fmt "\n", (dev)->minor, ## __VA_ARGS__)
+
+#define error_sock(sock, fmt, ...) \
+	_print_sock(KERN_ERR, sock, fmt, ## __VA_ARGS__)
+
 #endif /* DNBD_H_ */
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;
diff --git a/src/kernel/net.h b/src/kernel/net.h
index 435e39c..7efe859 100644
--- a/src/kernel/net.h
+++ b/src/kernel/net.h
@@ -23,6 +23,9 @@
 #ifndef NET_H_
 #define NET_H_
 
+#include "dnbd3.h"
+
+#define dnbd3_is_sock_alive(s) ((s).sock && (s).server)
 
 int dnbd3_send_request(struct dnbd3_sock *sock, struct request *req, struct dnbd3_cmd *cmd);