removed blocking code

added better macros for debugging

3 files changed, 154 insertions, 111 deletions

diff --git a/src/kernel/core.c b/src/kernel/core.c
index bf316d4..b945a55 100644
--- a/src/kernel/core.c
+++ b/src/kernel/core.c
@@ -105,8 +105,9 @@ static int dnbd3_handle_cmd(struct dnbd3_cmd *cmd, int 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);
-			blk_mq_start_request(req);
-			return -EINVAL;
+			dnbd3_requeue_cmd(cmd);
+			ret = 0;
+			goto out;
 		}
 		blk_mq_end_request(req, BLK_STS_IOERR);
 		return -EINVAL;
diff --git a/src/kernel/dnbd3.h b/src/kernel/dnbd3.h
index 72294b0..ccd3bf1 100644
--- a/src/kernel/dnbd3.h
+++ b/src/kernel/dnbd3.h
@@ -41,6 +41,7 @@
 #define RTT_THRESOULD_LIMIT(best_rtt) ((best_rtt) * 10)
 
 #define DEBUG
+#define DEBUG_FILE
 
 
 extern struct workqueue_struct *dnbd3_wq;
@@ -57,6 +58,24 @@ struct dnbd3_server {
 	uint64_t rtts[4];
 	uint16_t protocol_version;
 	uint8_t failures;
+
+	/*
+	 * TODO would this help?
+	 * uint8_t failures[4]
+	 * uint8_t avg_failures;
+	 *
+	 * in timer, calculate each x iterations average over failure array
+	 * then move elements in array to left
+	 * for (i = 3; i > 0; i--) {
+	 *     server->failures[i] = server->failures[i - 1]
+	 * }
+	 * server-failures[0] = 0;
+	 * failures always go to failures[0] / *failures
+	 *
+	 * - is this to much effort?
+	 * - what are the benefits?
+	 *   - could increase the rtt e.g. (rtt = rtt * failures)
+	 */
 };
 
 /**
@@ -71,7 +90,6 @@ struct dnbd3_server {
  * @keepalive_worker: worker to send a keepalive package
  * @receive_worker: worker to handle the incoming packages
  * @pending: the pending request which is going to be send
- * @receive_command: the last command the receiver got
  */
 struct dnbd3_sock {
 	uint8_t sock_nr;
@@ -88,7 +106,6 @@ struct dnbd3_sock {
 	struct work_struct receive_worker;
 
 	struct request *pending;
-	uint16_t receive_command;
 };
 
 /**
@@ -165,21 +182,54 @@ struct dnbd3_cmd {
 };
 
 
+/**
+ * macros for logging
+ * levels:
+ * 	- debug
+ * 	- info
+ * 	- warn
+ * 	- error
+ * 	methods:
+ * <level>(fmt,...)
+ *         print fmt
+ * <level>_dev(dev, fmt,...)
+ *         print fmt, adds device information to the log
+ * <level>_sock(sock, fmt,...)
+ *         print fmt, adds sock and device information to log
+ * <level>_server(dev, server, fmt,...)
+ *         print fmt, adds device and appends server information to the log
+ * DEBUG - if not defined switch of all debug messages
+ * DEBUG_FILE - if not defined switch of file and line number information
+ */
+
+
+#ifdef DEBUG_FILE
+
+#define __print(level, fmt,...) \
+	printk(level "%s:%d " fmt "\n", __FILE__, __LINE__, ## __VA_ARGS__)
+
+#else
+
+#define __print(level, fmt,...) \
+	printk(fmt,  ## __VA_ARGS__)
+
+#endif
+
 #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__); \
+			__print(level, "dnbd%d/%d %pI4:%d: " fmt, (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__); \
+			__print(level, "dnbd%d/%d %pI6:%d: " fmt, (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); \
+			__print(level, "dnbd%d: " fmt " %pI4:%d", (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); \
+			__print(level, "dnbd%d: " fmt " %pI6:%d", (dev)->minor, ## __VA_ARGS__, (server)->host.addr, (server)->host.port); \
 		} \
 	} while (0)
 
@@ -187,10 +237,10 @@ struct dnbd3_cmd {
 #ifdef DEBUG
 
 #define debug(fmt, ...) \
-	printk(KERN_DEBUG "dnbd: " fmt "\n", ## __VA_ARGS__)
+	__print(KERN_DEBUG, "dnbd: " fmt, ## __VA_ARGS__)
 
 #define debug_dev(dev, fmt, ...) \
-	printk(KERN_DEBUG "dnbd%d: " fmt "\n", (dev)->minor, ## __VA_ARGS__)
+	__print(KERN_DEBUG, "dnbd%d: " fmt, (dev)->minor, ## __VA_ARGS__)
 
 #define debug_sock(sock, fmt, ...) \
 	__print_sock(KERN_DEBUG, sock, fmt, ## __VA_ARGS__)
@@ -211,10 +261,10 @@ struct dnbd3_cmd {
 #endif
 
 #define info(fmt, ...) \
-	printk(KERN_INFO "dnbd: " fmt "\n", ## __VA_ARGS__)
+	__print(KERN_INFO, "dnbd: " fmt, ## __VA_ARGS__)
 
 #define info_dev(dev, fmt, ...) \
-	printk(KERN_INFO "dnbd%d: " fmt "\n", (dev)->minor, ## __VA_ARGS__)
+	__print(KERN_INFO, "dnbd%d: " fmt, (dev)->minor, ## __VA_ARGS__)
 
 #define info_sock(sock, fmt, ...) \
 	__print_sock(KERN_INFO, sock, fmt, ## __VA_ARGS__)
@@ -224,10 +274,10 @@ struct dnbd3_cmd {
 
 
 #define warn(fmt, ...) \
-	printk(KERN_WARNING "dnbd: " fmt "\n", ## __VA_ARGS__)
+	__print(KERN_WARNING, "dnbd: " fmt, ## __VA_ARGS__)
 
 #define warn_dev(dev, fmt, ...) \
-	printk(KERN_WARNING "dnbd%d: " fmt "\n", (dev)->minor, ## __VA_ARGS__)
+	__print(KERN_WARNING, "dnbd%d: " fmt, (dev)->minor, ## __VA_ARGS__)
 
 #define warn_sock(sock, fmt, ...) \
 	__print_sock(KERN_WARNING, sock, fmt, ## __VA_ARGS__)
@@ -237,10 +287,10 @@ struct dnbd3_cmd {
 
 
 #define error(fmt, ...) \
-	printk(KERN_ERR "dnbd: " fmt "\n", ## __VA_ARGS__)
+	__print(KERN_ERR, "dnbd: " fmt, ## __VA_ARGS__)
 
 #define error_dev(dev, fmt, ...) \
-	printk(KERN_ERR "dnbd%d: " fmt "\n", (dev)->minor, ## __VA_ARGS__)
+	__print(KERN_ERR, "dnbd%d: " fmt, (dev)->minor, ## __VA_ARGS__)
 
 #define error_sock(sock, fmt, ...) \
 	__print_sock(KERN_ERR, sock, fmt, ## __VA_ARGS__)
diff --git a/src/kernel/net.c b/src/kernel/net.c
index 2edb422..da9b897 100644
--- a/src/kernel/net.c
+++ b/src/kernel/net.c
@@ -35,6 +35,12 @@
 #define dnbd3_cmd_to_priv(req, cmd)   (req)->cmd_flags = DNBD3_REQ_OP_SPECIAL | ((cmd) << REQ_FLAG_BITS)
 #define dnbd3_connect(req)			  (req)->cmd_flags = DNBD3_REQ_OP_CONNECT | ((CMD_SELECT_IMAGE) << REQ_FLAG_BITS)
 #define dnbd3_priv_to_cmd(req)        ((req)->cmd_flags >> REQ_FLAG_BITS)
+#define dnbd3_test_block_to_req(req) \
+	do { \
+		(req)->cmd_flags = REQ_OP_READ; \
+		(req)->__data_len = RTT_BLOCK_SIZE; \
+		(req)->__sector = 0; \
+	} while (0)
 #define dnbd3_sock_create(af,type,proto,sock) sock_create_kern(&init_net, (af) == HOST_IP4 ? AF_INET : AF_INET6, type, proto, sock)
 
 #define REQUEST_TIMEOUT (HZ * SOCKET_TIMEOUT_CLIENT_DATA)
@@ -154,11 +160,10 @@ error:
 }
 
 
-static int dnbd3_send_request_blocking(struct dnbd3_sock *sock, uint16_t dnbd3_cmd)
+static int dnbd3_send_request_cmd(struct dnbd3_sock *sock, uint16_t dnbd3_cmd)
 {
 	int result;
 	struct request *req = kmalloc(sizeof(struct request), GFP_KERNEL);
-	debug_sock(sock, "starting blocking request %d", dnbd3_cmd);
 	if (!req) {
 		error_sock(sock, "kmalloc failed");
 		result = -EIO;
@@ -173,6 +178,9 @@ static int dnbd3_send_request_blocking(struct dnbd3_sock *sock, uint16_t dnbd3_c
 	case CMD_SELECT_IMAGE:
 		dnbd3_connect(req);
 		break;
+	case CMD_GET_BLOCK:
+		dnbd3_test_block_to_req(req);
+		break;
 	default:
 		warn_sock(sock, "unsupported command for blocking %d", dnbd3_cmd);
 		result = -EINVAL;
@@ -187,12 +195,6 @@ static int dnbd3_send_request_blocking(struct dnbd3_sock *sock, uint16_t dnbd3_c
 	}
 	mutex_unlock(&sock->tx_lock);
 
-	if (wait_event_interruptible_timeout(send_wq, sock->receive_command == dnbd3_cmd, REQUEST_TIMEOUT) <= 0) { // timeout or interrupt
-		warn_sock(sock, "request timed out, cmd %d", dnbd3_cmd);
-		result = -EIO;
-		goto error;
-	}
-
 error:
 	if (req) {
 		kfree(req);
@@ -291,6 +293,33 @@ static int dnbd3_receive_cmd_get_block_mq(struct dnbd3_device *dev, struct dnbd3
 	return result;
 }
 
+static int dnbd3_receive_cmd_get_block_test(struct dnbd3_sock *sock, dnbd3_reply_t *reply)
+{
+	struct msghdr msg;
+	struct kvec iov;
+	int result = 0;
+	char *buf = kmalloc(reply->size, GFP_KERNEL);
+	if (!buf) {
+		error_sock(sock, "kmalloc failed");
+		goto error;
+	}
+
+	init_msghdr(msg);
+	iov.iov_base = buf;
+	iov.iov_len = reply->size;
+	result = kernel_recvmsg(sock->sock, &msg, &iov, 1, reply->size, msg.msg_flags);
+	if (result != RTT_BLOCK_SIZE) {
+		error_sock(sock, "receive test block failed");
+		goto error;
+	}
+
+error:
+	if (buf) {
+		kfree(buf);
+	}
+	return result;
+}
+
 static int dnbd3_receive_cmd_get_servers(struct dnbd3_device *dev, struct dnbd3_sock *sock, dnbd3_reply_t *reply)
 {
 	struct msghdr msg;
@@ -482,8 +511,6 @@ static void dnbd3_receive_worker(struct work_struct *work)
 			break;
 		}
 error:
-		sock->receive_command = dnbd3_reply.cmd;
-		wake_up_interruptible(&send_wq);
 		if (result == 0) {
 			info_sock(sock, "result is 0, socket seems to be down");
 			sock->panic = true;
@@ -513,7 +540,7 @@ static void dnbd3_timer(struct timer_list *arg)
 			}
 		}
 	}
-	if (dev->timer_count % TIMER_INTERVAL_PROBE_NORMAL == 0) {
+	if (dev->timer_count % TIMER_INTERVAL_PROBE_NORMAL == 4) { // wait for 4 seconds
 		queue_work(dnbd3_wq, &dev->discovery_worker);
 	}
 
@@ -528,7 +555,7 @@ static void dnbd3_keepalive_worker(struct work_struct *work)
 {
 	struct dnbd3_sock *sock = container_of(work, struct dnbd3_sock, keepalive_worker);
 	debug_sock(sock, "starting keepalive worker");
-	dnbd3_send_request_blocking(sock, CMD_KEEPALIVE);
+	dnbd3_send_request_cmd(sock, CMD_KEEPALIVE);
 }
 
 static struct dnbd3_server *dnbd3_find_best_alt_server(struct dnbd3_device *dev) {
@@ -723,28 +750,17 @@ static void dnbd3_panic_worker(struct work_struct *work)
 
 static int dnbd3_meassure_rtt(struct dnbd3_device *dev, struct dnbd3_server *server)
 {
-	struct kvec iov;
 	struct timeval start, end;
-	dnbd3_request_t dnbd3_request;
-	dnbd3_reply_t dnbd3_reply;
-	struct dnbd3_sock sock;
-	struct msghdr msg;
-	char *buf;
+	dnbd3_reply_t reply;
 	struct request req;
-	uint64_t rtt = RTT_UNREACHABLE;
 	int result;
-
-	buf = kmalloc(RTT_BLOCK_SIZE, GFP_KERNEL);
-	if (!buf) {
-		debug_dev(dev, "kmalloc failed in rtt measurement");
-		result = -EIO;
-		goto error;
-	}
-
-	sock.sock_nr = NUMBER_CONNECTIONS;
-	sock.sock = NULL;
-	sock.device = dev;
-	sock.server = server;
+	uint64_t rtt = RTT_UNREACHABLE;
+	struct dnbd3_sock sock = {
+			.sock_nr = NUMBER_CONNECTIONS,
+			.sock = NULL,
+			.device = dev,
+			.server = server
+	};
 
 	result = __dnbd3_socket_connect(server, &sock);
 	if (result) {
@@ -752,73 +768,47 @@ static int dnbd3_meassure_rtt(struct dnbd3_device *dev, struct dnbd3_server *ser
 		goto error;
 	}
 	dnbd3_connect(&req);
-	result = dnbd3_send_request(&sock, &req, NULL);
+	result = dnbd3_send_request_cmd(&sock, CMD_SELECT_IMAGE);
 	if (result <= 0) {
 		error_sock(&sock, "request select image failed in rtt measurement");
 		goto error;
 	}
 
-	result = dnbd3_receive_cmd(&sock, &dnbd3_reply);
+	result = dnbd3_receive_cmd(&sock, &reply);
 	if (result <= 0) {
 		error_sock(&sock, "receive select image failed in rtt measurement");
 		goto error;
 
 	}
-	if (dnbd3_reply.magic != dnbd3_packet_magic || dnbd3_reply.cmd != CMD_SELECT_IMAGE || dnbd3_reply.size < 4) {
+	if (reply.magic != dnbd3_packet_magic || reply.cmd != CMD_SELECT_IMAGE || reply.size < 4) {
 		error_sock(&sock, "receive select image wrong header in rtt measurement");
 		result = -EIO;
 		goto error;
 	}
-	result = dnbd3_receive_cmd_select_image(dev, &sock, &dnbd3_reply);
+	result = dnbd3_receive_cmd_select_image(dev, &sock, &reply);
 	if (result <= 0) {
 		error_sock(&sock, "receive data select image failed in rtt measurement");
 		goto error;
 	}
 
-	// Request block
-	dnbd3_request.magic = dnbd3_packet_magic;
-	dnbd3_request.cmd = CMD_GET_BLOCK;
-	// Do *NOT* pick a random block as it has proven to cause severe
-	// cache thrashing on the server
-	dnbd3_request.offset = 0;
-	dnbd3_request.size = RTT_BLOCK_SIZE;
-	fixup_request(dnbd3_request);
-	iov.iov_base = &dnbd3_request;
-	iov.iov_len = sizeof(dnbd3_request);
 
-	init_msghdr(msg);
-	// start rtt measurement
 	do_gettimeofday(&start);
-
-	result = kernel_sendmsg(sock.sock, &msg, &iov, 1, sizeof(dnbd3_request));
+	result = dnbd3_send_request_cmd(&sock, CMD_GET_BLOCK);
 	if (result <= 0) {
 		error_sock(&sock, "request test block failed in rtt measurement");
 		goto error;
 	}
-	// receive net reply
-	iov.iov_base = &dnbd3_reply;
-	iov.iov_len = sizeof(dnbd3_reply);
-	result = kernel_recvmsg(sock.sock, &msg, &iov, 1, sizeof(dnbd3_reply), msg.msg_flags);
-	if (result != sizeof(dnbd3_reply)) {
-		error_sock(&sock, "receive header test block failed in rtt measurement");
-		goto error;
-	}
-	fixup_reply(dnbd3_reply);
-	if (dnbd3_reply.magic != dnbd3_packet_magic|| dnbd3_reply.cmd != CMD_GET_BLOCK || dnbd3_reply.size != RTT_BLOCK_SIZE) {
+	result = dnbd3_receive_cmd(&sock, &reply);
+	if (reply.magic != dnbd3_packet_magic|| reply.cmd != CMD_GET_BLOCK || reply.size != RTT_BLOCK_SIZE) {
 		error_sock(&sock, "receive header cmd test block failed in rtt measurement");
 		result = -EIO;
 		goto error;
 	}
-
-	// receive data
-	iov.iov_base = buf;
-	iov.iov_len = RTT_BLOCK_SIZE;
-	result = kernel_recvmsg(sock.sock, &msg, &iov, 1, dnbd3_reply.size, msg.msg_flags);
-	if (result != RTT_BLOCK_SIZE) {
+	result =  dnbd3_receive_cmd_get_block_test(&sock, &reply);
+	if (result <= 0) {
 		error_sock(&sock, "receive test block failed in rtt measurement");
 		goto error;
 	}
-
 	do_gettimeofday(&end); // end rtt measurement
 
 	rtt = (uint64_t)((end.tv_sec - start.tv_sec) * 1000000ull + (end.tv_usec - start.tv_usec));
@@ -830,9 +820,6 @@ error:
 	if (result <= 0) {
 		server->failures++;
 	}
-	if (buf) {
-		kfree(buf);
-	}
 	if (sock.sock) {
 		kernel_sock_shutdown(sock.sock, SHUT_RDWR);
 		sock.server = NULL;
@@ -846,31 +833,13 @@ error:
 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 = &dev->socks[dev->discovery_count % NUMBER_CONNECTIONS]; // just take the next
 	int i, j;
 	struct dnbd3_server *existing_server, *free_server, *failed_server;
 	dnbd3_server_entry_t *new_server;
 
-	if (!dnbd3_is_sock_alive(*sock)) {
-		sock = NULL;
-		for (i = 0; i < NUMBER_CONNECTIONS; i++) {
-			if (dnbd3_is_sock_alive(dev->socks[i])) {
-				sock = &dev->socks[i];
-			}
-		}
-		if (!sock) {
-			error_dev(dev, "discovery failed, no socket available");
-		}
-	}
-
 
-	debug_sock(sock, "starting discovery worker");
+	debug_dev(dev, "starting discovery worker new server num is %d", dev->new_servers_num);
 
-	if (dnbd3_send_request_blocking(sock, CMD_GET_SERVERS) <= 0) {
-		error_sock(sock, "failed to get servers in discovery");
-	}
-
-	debug_sock(sock, "new server num is %d", dev->new_servers_num);
 	if (dev->new_servers_num) {
 		mutex_lock(&dev->device_lock);
 
@@ -1004,6 +973,7 @@ static int dnbd3_socket_connect(struct dnbd3_device *dev, struct dnbd3_server *s
 	int i;
 	int sock_alive = 0;
 	int result = -EIO;
+	dnbd3_reply_t reply;
 	struct dnbd3_sock *sock = NULL;
 	for (i = 0; i < NUMBER_CONNECTIONS; i++) {
 		if (!dnbd3_is_sock_alive(dev->socks[i])) {
@@ -1035,21 +1005,36 @@ static int dnbd3_socket_connect(struct dnbd3_device *dev, struct dnbd3_server *s
 		goto error;
 	}
 
-	// start the receiver
-	INIT_WORK(&sock->receive_worker, dnbd3_receive_worker);
-	queue_work(dnbd3_wq, &sock->receive_worker);
 
-	result = dnbd3_send_request_blocking(sock, CMD_SELECT_IMAGE);
+	result = dnbd3_send_request_cmd(sock, CMD_SELECT_IMAGE);
 	if (result <= 0) {
 		error_sock(sock, "connection to image %s failed", dev->imgname);
-		server->failures++;
 		result = -EIO;
 		goto error;
-
 	}
-
+	result = dnbd3_receive_cmd(sock, &reply);
+	if (result <= 0) {
+		error_sock(sock, "receive cmd to image %s failed", dev->imgname);
+		result = -EIO;
+		goto error;
+	}
+	if (reply.magic != dnbd3_packet_magic || reply.cmd != CMD_SELECT_IMAGE || reply.size < 4) {
+		error_sock(sock, "receive select image wrong header %s", dev->imgname);
+		result = -EIO;
+		goto error;
+	}
+	result = dnbd3_receive_cmd_select_image(dev, sock, &reply);
+	if (result <= 0) {
+		error_sock(sock, "receive cmd select image %s failed", dev->imgname);
+		result = -EIO;
+		goto error;
+	}
 	debug_sock(sock, "connected to image %s, filesize %llu", dev->imgname, dev->reported_size);
 
+	// start the receiver
+	INIT_WORK(&sock->receive_worker, dnbd3_receive_worker);
+	queue_work(dnbd3_wq, &sock->receive_worker);
+
 	INIT_WORK(&sock->keepalive_worker, dnbd3_keepalive_worker);
 
 	for (i = 0; i < NUMBER_CONNECTIONS; i++) {
@@ -1066,8 +1051,15 @@ static int dnbd3_socket_connect(struct dnbd3_device *dev, struct dnbd3_server *s
 		add_timer(&dev->timer);
 	}
 	blk_mq_update_nr_hw_queues(&dev->tag_set, sock_alive);
+
+	// request alternative servers receiver will handle this
+	if (dnbd3_send_request_cmd(sock, CMD_GET_SERVERS) <= 0) {
+		error_sock(sock, "failed to get servers in discovery");
+	}
+
 	return 0;
 error:
+	server->failures++;
 	if (sock->sock) {
 		kernel_sock_shutdown(sock->sock, SHUT_RDWR);
 		cancel_work_sync(&sock->receive_worker);