summary refs log tree commit diff stats
path: root/nbd/server.c
diff options
context:
space:
mode:
Diffstat (limited to 'nbd/server.c')
-rw-r--r--nbd/server.c401
1 files changed, 222 insertions, 179 deletions
diff --git a/nbd/server.c b/nbd/server.c
index 8a70c054a6..9b0c588146 100644
--- a/nbd/server.c
+++ b/nbd/server.c
@@ -19,6 +19,7 @@
 
 #include "qemu/osdep.h"
 #include "qapi/error.h"
+#include "trace.h"
 #include "nbd-internal.h"
 
 static int system_errno_to_nbd_errno(int err)
@@ -134,31 +135,33 @@ static void nbd_client_receive_next_request(NBDClient *client);
 /* Send a reply header, including length, but no payload.
  * Return -errno on error, 0 on success. */
 static int nbd_negotiate_send_rep_len(QIOChannel *ioc, uint32_t type,
-                                      uint32_t opt, uint32_t len)
+                                      uint32_t opt, uint32_t len, Error **errp)
 {
     uint64_t magic;
 
-    TRACE("Reply opt=%" PRIx32 " type=%" PRIx32 " len=%" PRIu32,
-          type, opt, len);
+    trace_nbd_negotiate_send_rep_len(opt, type, len);
 
     magic = cpu_to_be64(NBD_REP_MAGIC);
-    if (nbd_write(ioc, &magic, sizeof(magic), NULL) < 0) {
-        LOG("write failed (rep magic)");
+    if (nbd_write(ioc, &magic, sizeof(magic), errp) < 0) {
+        error_prepend(errp, "write failed (rep magic): ");
         return -EINVAL;
     }
+
     opt = cpu_to_be32(opt);
-    if (nbd_write(ioc, &opt, sizeof(opt), NULL) < 0) {
-        LOG("write failed (rep opt)");
+    if (nbd_write(ioc, &opt, sizeof(opt), errp) < 0) {
+        error_prepend(errp, "write failed (rep opt): ");
         return -EINVAL;
     }
+
     type = cpu_to_be32(type);
-    if (nbd_write(ioc, &type, sizeof(type), NULL) < 0) {
-        LOG("write failed (rep type)");
+    if (nbd_write(ioc, &type, sizeof(type), errp) < 0) {
+        error_prepend(errp, "write failed (rep type): ");
         return -EINVAL;
     }
+
     len = cpu_to_be32(len);
-    if (nbd_write(ioc, &len, sizeof(len), NULL) < 0) {
-        LOG("write failed (rep data length)");
+    if (nbd_write(ioc, &len, sizeof(len), errp) < 0) {
+        error_prepend(errp, "write failed (rep data length): ");
         return -EINVAL;
     }
     return 0;
@@ -166,16 +169,17 @@ static int nbd_negotiate_send_rep_len(QIOChannel *ioc, uint32_t type,
 
 /* Send a reply header with default 0 length.
  * Return -errno on error, 0 on success. */
-static int nbd_negotiate_send_rep(QIOChannel *ioc, uint32_t type, uint32_t opt)
+static int nbd_negotiate_send_rep(QIOChannel *ioc, uint32_t type, uint32_t opt,
+                                  Error **errp)
 {
-    return nbd_negotiate_send_rep_len(ioc, type, opt, 0);
+    return nbd_negotiate_send_rep_len(ioc, type, opt, 0, errp);
 }
 
 /* Send an error reply.
  * Return -errno on error, 0 on success. */
-static int GCC_FMT_ATTR(4, 5)
+static int GCC_FMT_ATTR(5, 6)
 nbd_negotiate_send_rep_err(QIOChannel *ioc, uint32_t type,
-                           uint32_t opt, const char *fmt, ...)
+                           uint32_t opt, Error **errp, const char *fmt, ...)
 {
     va_list va;
     char *msg;
@@ -187,17 +191,18 @@ nbd_negotiate_send_rep_err(QIOChannel *ioc, uint32_t type,
     va_end(va);
     len = strlen(msg);
     assert(len < 4096);
-    TRACE("sending error message \"%s\"", msg);
-    ret = nbd_negotiate_send_rep_len(ioc, type, opt, len);
+    trace_nbd_negotiate_send_rep_err(msg);
+    ret = nbd_negotiate_send_rep_len(ioc, type, opt, len, errp);
     if (ret < 0) {
         goto out;
     }
-    if (nbd_write(ioc, msg, len, NULL) < 0) {
-        LOG("write failed (error message)");
+    if (nbd_write(ioc, msg, len, errp) < 0) {
+        error_prepend(errp, "write failed (error message): ");
         ret = -EIO;
     } else {
         ret = 0;
     }
+
 out:
     g_free(msg);
     return ret;
@@ -205,7 +210,8 @@ out:
 
 /* Send a single NBD_REP_SERVER reply to NBD_OPT_LIST, including payload.
  * Return -errno on error, 0 on success. */
-static int nbd_negotiate_send_rep_list(QIOChannel *ioc, NBDExport *exp)
+static int nbd_negotiate_send_rep_list(QIOChannel *ioc, NBDExport *exp,
+                                       Error **errp)
 {
     size_t name_len, desc_len;
     uint32_t len;
@@ -213,79 +219,86 @@ static int nbd_negotiate_send_rep_list(QIOChannel *ioc, NBDExport *exp)
     const char *desc = exp->description ? exp->description : "";
     int ret;
 
-    TRACE("Advertising export name '%s' description '%s'", name, desc);
+    trace_nbd_negotiate_send_rep_list(name, desc);
     name_len = strlen(name);
     desc_len = strlen(desc);
     len = name_len + desc_len + sizeof(len);
-    ret = nbd_negotiate_send_rep_len(ioc, NBD_REP_SERVER, NBD_OPT_LIST, len);
+    ret = nbd_negotiate_send_rep_len(ioc, NBD_REP_SERVER, NBD_OPT_LIST, len,
+                                     errp);
     if (ret < 0) {
         return ret;
     }
 
     len = cpu_to_be32(name_len);
-    if (nbd_write(ioc, &len, sizeof(len), NULL) < 0) {
-        LOG("write failed (name length)");
+    if (nbd_write(ioc, &len, sizeof(len), errp) < 0) {
+        error_prepend(errp, "write failed (name length): ");
         return -EINVAL;
     }
-    if (nbd_write(ioc, name, name_len, NULL) < 0) {
-        LOG("write failed (name buffer)");
+
+    if (nbd_write(ioc, name, name_len, errp) < 0) {
+        error_prepend(errp, "write failed (name buffer): ");
         return -EINVAL;
     }
-    if (nbd_write(ioc, desc, desc_len, NULL) < 0) {
-        LOG("write failed (description buffer)");
+
+    if (nbd_write(ioc, desc, desc_len, errp) < 0) {
+        error_prepend(errp, "write failed (description buffer): ");
         return -EINVAL;
     }
+
     return 0;
 }
 
 /* Process the NBD_OPT_LIST command, with a potential series of replies.
  * Return -errno on error, 0 on success. */
-static int nbd_negotiate_handle_list(NBDClient *client, uint32_t length)
+static int nbd_negotiate_handle_list(NBDClient *client, uint32_t length,
+                                     Error **errp)
 {
     NBDExport *exp;
 
     if (length) {
-        if (nbd_drop(client->ioc, length, NULL) < 0) {
+        if (nbd_drop(client->ioc, length, errp) < 0) {
             return -EIO;
         }
         return nbd_negotiate_send_rep_err(client->ioc,
                                           NBD_REP_ERR_INVALID, NBD_OPT_LIST,
+                                          errp,
                                           "OPT_LIST should not have length");
     }
 
     /* For each export, send a NBD_REP_SERVER reply. */
     QTAILQ_FOREACH(exp, &exports, next) {
-        if (nbd_negotiate_send_rep_list(client->ioc, exp)) {
+        if (nbd_negotiate_send_rep_list(client->ioc, exp, errp)) {
             return -EINVAL;
         }
     }
     /* Finish with a NBD_REP_ACK. */
-    return nbd_negotiate_send_rep(client->ioc, NBD_REP_ACK, NBD_OPT_LIST);
+    return nbd_negotiate_send_rep(client->ioc, NBD_REP_ACK, NBD_OPT_LIST, errp);
 }
 
-static int nbd_negotiate_handle_export_name(NBDClient *client, uint32_t length)
+static int nbd_negotiate_handle_export_name(NBDClient *client, uint32_t length,
+                                            Error **errp)
 {
     char name[NBD_MAX_NAME_SIZE + 1];
 
     /* Client sends:
         [20 ..  xx]   export name (length bytes)
      */
-    TRACE("Checking length");
+    trace_nbd_negotiate_handle_export_name();
     if (length >= sizeof(name)) {
-        LOG("Bad length received");
+        error_setg(errp, "Bad length received");
         return -EINVAL;
     }
-    if (nbd_read(client->ioc, name, length, NULL) < 0) {
-        LOG("read failed");
+    if (nbd_read(client->ioc, name, length, errp) < 0) {
+        error_prepend(errp, "read failed: ");
         return -EINVAL;
     }
     name[length] = '\0';
 
-    TRACE("Client requested export '%s'", name);
+    trace_nbd_negotiate_handle_export_name_request(name);
 
     client->exp = nbd_export_find(name);
     if (!client->exp) {
-        LOG("export not found");
+        error_setg(errp, "export not found");
         return -EINVAL;
     }
 
@@ -298,38 +311,40 @@ static int nbd_negotiate_handle_export_name(NBDClient *client, uint32_t length)
 /* Handle NBD_OPT_STARTTLS. Return NULL to drop connection, or else the
  * new channel for all further (now-encrypted) communication. */
 static QIOChannel *nbd_negotiate_handle_starttls(NBDClient *client,
-                                                 uint32_t length)
+                                                 uint32_t length,
+                                                 Error **errp)
 {
     QIOChannel *ioc;
     QIOChannelTLS *tioc;
     struct NBDTLSHandshakeData data = { 0 };
 
-    TRACE("Setting up TLS");
+    trace_nbd_negotiate_handle_starttls();
     ioc = client->ioc;
     if (length) {
-        if (nbd_drop(ioc, length, NULL) < 0) {
+        if (nbd_drop(ioc, length, errp) < 0) {
             return NULL;
         }
         nbd_negotiate_send_rep_err(ioc, NBD_REP_ERR_INVALID, NBD_OPT_STARTTLS,
+                                   errp,
                                    "OPT_STARTTLS should not have length");
         return NULL;
     }
 
     if (nbd_negotiate_send_rep(client->ioc, NBD_REP_ACK,
-                               NBD_OPT_STARTTLS) < 0) {
+                               NBD_OPT_STARTTLS, errp) < 0) {
         return NULL;
     }
 
     tioc = qio_channel_tls_new_server(ioc,
                                       client->tlscreds,
                                       client->tlsaclname,
-                                      NULL);
+                                      errp);
     if (!tioc) {
         return NULL;
     }
 
     qio_channel_set_name(QIO_CHANNEL(tioc), "nbd-server-tls");
-    TRACE("Starting TLS handshake");
+    trace_nbd_negotiate_handle_starttls_handshake();
     data.loop = g_main_loop_new(g_main_context_default(), FALSE);
     qio_channel_tls_handshake(tioc,
                               nbd_tls_handshake,
@@ -342,20 +357,26 @@ static QIOChannel *nbd_negotiate_handle_starttls(NBDClient *client,
     g_main_loop_unref(data.loop);
     if (data.error) {
         object_unref(OBJECT(tioc));
-        error_free(data.error);
+        error_propagate(errp, data.error);
         return NULL;
     }
 
     return QIO_CHANNEL(tioc);
 }
 
-
-/* Process all NBD_OPT_* client option commands.
- * Return -errno on error, 0 on success. */
-static int nbd_negotiate_options(NBDClient *client)
+/* nbd_negotiate_options
+ * Process all NBD_OPT_* client option commands.
+ * Return:
+ * -errno  on error, errp is set
+ * 0       on successful negotiation, errp is not set
+ * 1       if client sent NBD_OPT_ABORT, i.e. on valid disconnect,
+ *         errp is not set
+ */
+static int nbd_negotiate_options(NBDClient *client, Error **errp)
 {
     uint32_t flags;
     bool fixedNewstyle = false;
+    Error *local_err = NULL;
 
     /* Client sends:
         [ 0 ..   3]   client flags
@@ -371,67 +392,67 @@ static int nbd_negotiate_options(NBDClient *client)
         ...           Rest of request
     */
 
-    if (nbd_read(client->ioc, &flags, sizeof(flags), NULL) < 0) {
-        LOG("read failed");
+    if (nbd_read(client->ioc, &flags, sizeof(flags), errp) < 0) {
+        error_prepend(errp, "read failed: ");
         return -EIO;
     }
-    TRACE("Checking client flags");
+    trace_nbd_negotiate_options_flags();
     be32_to_cpus(&flags);
     if (flags & NBD_FLAG_C_FIXED_NEWSTYLE) {
-        TRACE("Client supports fixed newstyle handshake");
+        trace_nbd_negotiate_options_newstyle();
         fixedNewstyle = true;
         flags &= ~NBD_FLAG_C_FIXED_NEWSTYLE;
     }
     if (flags & NBD_FLAG_C_NO_ZEROES) {
-        TRACE("Client supports no zeroes at handshake end");
+        trace_nbd_negotiate_options_no_zeroes();
         client->no_zeroes = true;
         flags &= ~NBD_FLAG_C_NO_ZEROES;
     }
     if (flags != 0) {
-        TRACE("Unknown client flags 0x%" PRIx32 " received", flags);
+        error_setg(errp, "Unknown client flags 0x%" PRIx32 " received", flags);
         return -EIO;
     }
 
     while (1) {
         int ret;
-        uint32_t clientflags, length;
+        uint32_t option, length;
         uint64_t magic;
 
-        if (nbd_read(client->ioc, &magic, sizeof(magic), NULL) < 0) {
-            LOG("read failed");
+        if (nbd_read(client->ioc, &magic, sizeof(magic), errp) < 0) {
+            error_prepend(errp, "read failed: ");
             return -EINVAL;
         }
-        TRACE("Checking opts magic");
-        if (magic != be64_to_cpu(NBD_OPTS_MAGIC)) {
-            LOG("Bad magic received");
+        magic = be64_to_cpu(magic);
+        trace_nbd_negotiate_options_check_magic(magic);
+        if (magic != NBD_OPTS_MAGIC) {
+            error_setg(errp, "Bad magic received");
             return -EINVAL;
         }
 
-        if (nbd_read(client->ioc, &clientflags,
-                      sizeof(clientflags), NULL) < 0)
-        {
-            LOG("read failed");
+        if (nbd_read(client->ioc, &option,
+                     sizeof(option), errp) < 0) {
+            error_prepend(errp, "read failed: ");
             return -EINVAL;
         }
-        clientflags = be32_to_cpu(clientflags);
+        option = be32_to_cpu(option);
 
-        if (nbd_read(client->ioc, &length, sizeof(length), NULL) < 0) {
-            LOG("read failed");
+        if (nbd_read(client->ioc, &length, sizeof(length), errp) < 0) {
+            error_prepend(errp, "read failed: ");
             return -EINVAL;
         }
         length = be32_to_cpu(length);
 
-        TRACE("Checking option 0x%" PRIx32, clientflags);
+        trace_nbd_negotiate_options_check_option(option);
         if (client->tlscreds &&
             client->ioc == (QIOChannel *)client->sioc) {
             QIOChannel *tioc;
             if (!fixedNewstyle) {
-                TRACE("Unsupported option 0x%" PRIx32, clientflags);
+                error_setg(errp, "Unsupported option 0x%" PRIx32, option);
                 return -EINVAL;
             }
-            switch (clientflags) {
+            switch (option) {
             case NBD_OPT_STARTTLS:
-                tioc = nbd_negotiate_handle_starttls(client, length);
+                tioc = nbd_negotiate_handle_starttls(client, length, errp);
                 if (!tioc) {
                     return -EIO;
                 }
@@ -441,32 +462,33 @@ static int nbd_negotiate_options(NBDClient *client)
 
             case NBD_OPT_EXPORT_NAME:
                 /* No way to return an error to client, so drop connection */
-                TRACE("Option 0x%x not permitted before TLS", clientflags);
+                error_setg(errp, "Option 0x%x not permitted before TLS",
+                           option);
                 return -EINVAL;
 
             default:
-                if (nbd_drop(client->ioc, length, NULL) < 0) {
+                if (nbd_drop(client->ioc, length, errp) < 0) {
                     return -EIO;
                 }
                 ret = nbd_negotiate_send_rep_err(client->ioc,
                                                  NBD_REP_ERR_TLS_REQD,
-                                                 clientflags,
+                                                 option, errp,
                                                  "Option 0x%" PRIx32
                                                  "not permitted before TLS",
-                                                 clientflags);
+                                                 option);
                 if (ret < 0) {
                     return ret;
                 }
                 /* Let the client keep trying, unless they asked to quit */
-                if (clientflags == NBD_OPT_ABORT) {
-                    return -EINVAL;
+                if (option == NBD_OPT_ABORT) {
+                    return 1;
                 }
                 break;
             }
         } else if (fixedNewstyle) {
-            switch (clientflags) {
+            switch (option) {
             case NBD_OPT_LIST:
-                ret = nbd_negotiate_handle_list(client, length);
+                ret = nbd_negotiate_handle_list(client, length, errp);
                 if (ret < 0) {
                     return ret;
                 }
@@ -476,25 +498,33 @@ static int nbd_negotiate_options(NBDClient *client)
                 /* NBD spec says we must try to reply before
                  * disconnecting, but that we must also tolerate
                  * guests that don't wait for our reply. */
-                nbd_negotiate_send_rep(client->ioc, NBD_REP_ACK, clientflags);
-                return -EINVAL;
+                nbd_negotiate_send_rep(client->ioc, NBD_REP_ACK, option,
+                                       &local_err);
+
+                if (local_err != NULL) {
+                    const char *error = error_get_pretty(local_err);
+                    trace_nbd_opt_abort_reply_failed(error);
+                    error_free(local_err);
+                }
+
+                return 1;
 
             case NBD_OPT_EXPORT_NAME:
-                return nbd_negotiate_handle_export_name(client, length);
+                return nbd_negotiate_handle_export_name(client, length, errp);
 
             case NBD_OPT_STARTTLS:
-                if (nbd_drop(client->ioc, length, NULL) < 0) {
+                if (nbd_drop(client->ioc, length, errp) < 0) {
                     return -EIO;
                 }
                 if (client->tlscreds) {
                     ret = nbd_negotiate_send_rep_err(client->ioc,
                                                      NBD_REP_ERR_INVALID,
-                                                     clientflags,
+                                                     option, errp,
                                                      "TLS already enabled");
                 } else {
                     ret = nbd_negotiate_send_rep_err(client->ioc,
                                                      NBD_REP_ERR_POLICY,
-                                                     clientflags,
+                                                     option, errp,
                                                      "TLS not configured");
                 }
                 if (ret < 0) {
@@ -502,15 +532,15 @@ static int nbd_negotiate_options(NBDClient *client)
                 }
                 break;
             default:
-                if (nbd_drop(client->ioc, length, NULL) < 0) {
+                if (nbd_drop(client->ioc, length, errp) < 0) {
                     return -EIO;
                 }
                 ret = nbd_negotiate_send_rep_err(client->ioc,
                                                  NBD_REP_ERR_UNSUP,
-                                                 clientflags,
+                                                 option, errp,
                                                  "Unsupported option 0x%"
                                                  PRIx32,
-                                                 clientflags);
+                                                 option);
                 if (ret < 0) {
                     return ret;
                 }
@@ -521,19 +551,26 @@ static int nbd_negotiate_options(NBDClient *client)
              * If broken new-style we should drop the connection
              * for anything except NBD_OPT_EXPORT_NAME
              */
-            switch (clientflags) {
+            switch (option) {
             case NBD_OPT_EXPORT_NAME:
-                return nbd_negotiate_handle_export_name(client, length);
+                return nbd_negotiate_handle_export_name(client, length, errp);
 
             default:
-                TRACE("Unsupported option 0x%" PRIx32, clientflags);
+                error_setg(errp, "Unsupported option 0x%" PRIx32, option);
                 return -EINVAL;
             }
         }
     }
 }
 
-static coroutine_fn int nbd_negotiate(NBDClient *client)
+/* nbd_negotiate
+ * Return:
+ * -errno  on error, errp is set
+ * 0       on successful negotiation, errp is not set
+ * 1       if client sent NBD_OPT_ABORT, i.e. on valid disconnect,
+ *         errp is not set
+ */
+static coroutine_fn int nbd_negotiate(NBDClient *client, Error **errp)
 {
     char buf[8 + 8 + 8 + 128];
     int ret;
@@ -563,66 +600,63 @@ static coroutine_fn int nbd_negotiate(NBDClient *client)
 
     qio_channel_set_blocking(client->ioc, false, NULL);
 
-    TRACE("Beginning negotiation.");
+    trace_nbd_negotiate_begin();
     memset(buf, 0, sizeof(buf));
     memcpy(buf, "NBDMAGIC", 8);
 
     oldStyle = client->exp != NULL && !client->tlscreds;
     if (oldStyle) {
-        TRACE("advertising size %" PRIu64 " and flags %x",
-              client->exp->size, client->exp->nbdflags | myflags);
+        trace_nbd_negotiate_old_style(client->exp->size,
+                                      client->exp->nbdflags | myflags);
         stq_be_p(buf + 8, NBD_CLIENT_MAGIC);
         stq_be_p(buf + 16, client->exp->size);
         stw_be_p(buf + 26, client->exp->nbdflags | myflags);
-    } else {
-        stq_be_p(buf + 8, NBD_OPTS_MAGIC);
-        stw_be_p(buf + 16, NBD_FLAG_FIXED_NEWSTYLE | NBD_FLAG_NO_ZEROES);
-    }
 
-    if (oldStyle) {
-        if (client->tlscreds) {
-            TRACE("TLS cannot be enabled with oldstyle protocol");
-            return -EINVAL;
-        }
-        if (nbd_write(client->ioc, buf, sizeof(buf), NULL) < 0) {
-            LOG("write failed");
+        if (nbd_write(client->ioc, buf, sizeof(buf), errp) < 0) {
+            error_prepend(errp, "write failed: ");
             return -EINVAL;
         }
     } else {
-        if (nbd_write(client->ioc, buf, 18, NULL) < 0) {
-            LOG("write failed");
+        stq_be_p(buf + 8, NBD_OPTS_MAGIC);
+        stw_be_p(buf + 16, NBD_FLAG_FIXED_NEWSTYLE | NBD_FLAG_NO_ZEROES);
+
+        if (nbd_write(client->ioc, buf, 18, errp) < 0) {
+            error_prepend(errp, "write failed: ");
             return -EINVAL;
         }
-        ret = nbd_negotiate_options(client);
+        ret = nbd_negotiate_options(client, errp);
         if (ret != 0) {
-            LOG("option negotiation failed");
+            if (ret < 0) {
+                error_prepend(errp, "option negotiation failed: ");
+            }
             return ret;
         }
 
-        TRACE("advertising size %" PRIu64 " and flags %x",
-              client->exp->size, client->exp->nbdflags | myflags);
+        trace_nbd_negotiate_new_style_size_flags(
+            client->exp->size, client->exp->nbdflags | myflags);
         stq_be_p(buf + 18, client->exp->size);
         stw_be_p(buf + 26, client->exp->nbdflags | myflags);
         len = client->no_zeroes ? 10 : sizeof(buf) - 18;
-        ret = nbd_write(client->ioc, buf + 18, len, NULL);
+        ret = nbd_write(client->ioc, buf + 18, len, errp);
         if (ret < 0) {
-            LOG("write failed");
+            error_prepend(errp, "write failed: ");
             return ret;
         }
     }
 
-    TRACE("Negotiation succeeded.");
+    trace_nbd_negotiate_success();
 
     return 0;
 }
 
-static int nbd_receive_request(QIOChannel *ioc, NBDRequest *request)
+static int nbd_receive_request(QIOChannel *ioc, NBDRequest *request,
+                               Error **errp)
 {
     uint8_t buf[NBD_REQUEST_SIZE];
     uint32_t magic;
     int ret;
 
-    ret = nbd_read(ioc, buf, sizeof(buf), NULL);
+    ret = nbd_read(ioc, buf, sizeof(buf), errp);
     if (ret < 0) {
         return ret;
     }
@@ -643,26 +677,23 @@ static int nbd_receive_request(QIOChannel *ioc, NBDRequest *request)
     request->from   = ldq_be_p(buf + 16);
     request->len    = ldl_be_p(buf + 24);
 
-    TRACE("Got request: { magic = 0x%" PRIx32 ", .flags = %" PRIx16
-          ", .type = %" PRIx16 ", from = %" PRIu64 ", len = %" PRIu32 " }",
-          magic, request->flags, request->type, request->from, request->len);
+    trace_nbd_receive_request(magic, request->flags, request->type,
+                              request->from, request->len);
 
     if (magic != NBD_REQUEST_MAGIC) {
-        LOG("invalid magic (got 0x%" PRIx32 ")", magic);
+        error_setg(errp, "invalid magic (got 0x%" PRIx32 ")", magic);
         return -EINVAL;
     }
     return 0;
 }
 
-static int nbd_send_reply(QIOChannel *ioc, NBDReply *reply)
+static int nbd_send_reply(QIOChannel *ioc, NBDReply *reply, Error **errp)
 {
     uint8_t buf[NBD_REPLY_SIZE];
 
     reply->error = system_errno_to_nbd_errno(reply->error);
 
-    TRACE("Sending response to client: { .error = %" PRId32
-          ", handle = %" PRIu64 " }",
-          reply->error, reply->handle);
+    trace_nbd_send_reply(reply->error, reply->handle);
 
     /* Reply
        [ 0 ..  3]    magic   (NBD_REPLY_MAGIC)
@@ -673,7 +704,7 @@ static int nbd_send_reply(QIOChannel *ioc, NBDReply *reply)
     stl_be_p(buf + 4, reply->error);
     stq_be_p(buf + 8, reply->handle);
 
-    return nbd_write(ioc, buf, sizeof(buf), NULL);
+    return nbd_write(ioc, buf, sizeof(buf), errp);
 }
 
 #define MAX_NBD_REQUESTS 16
@@ -759,7 +790,7 @@ static void blk_aio_attached(AioContext *ctx, void *opaque)
     NBDExport *exp = opaque;
     NBDClient *client;
 
-    TRACE("Export %s: Attaching clients to AIO context %p\n", exp->name, ctx);
+    trace_nbd_blk_aio_attached(exp->name, ctx);
 
     exp->ctx = ctx;
 
@@ -779,7 +810,7 @@ static void blk_aio_detach(void *opaque)
     NBDExport *exp = opaque;
     NBDClient *client;
 
-    TRACE("Export %s: Detaching clients from AIO context %p\n", exp->name, exp->ctx);
+    trace_nbd_blk_aio_detach(exp->name, exp->ctx);
 
     QTAILQ_FOREACH(client, &exp->clients, next) {
         qio_channel_detach_aio_context(client->ioc);
@@ -960,22 +991,26 @@ void nbd_export_close_all(void)
     }
 }
 
-static int nbd_co_send_reply(NBDRequestData *req, NBDReply *reply, int len)
+static int nbd_co_send_reply(NBDRequestData *req, NBDReply *reply, int len,
+                             Error **errp)
 {
     NBDClient *client = req->client;
     int ret;
 
     g_assert(qemu_in_coroutine());
+
+    trace_nbd_co_send_reply(reply->handle, reply->error, len);
+
     qemu_co_mutex_lock(&client->send_lock);
     client->send_coroutine = qemu_coroutine_self();
 
     if (!len) {
-        ret = nbd_send_reply(client->ioc, reply);
+        ret = nbd_send_reply(client->ioc, reply, errp);
     } else {
         qio_channel_set_cork(client->ioc, true);
-        ret = nbd_send_reply(client->ioc, reply);
+        ret = nbd_send_reply(client->ioc, reply, errp);
         if (ret == 0) {
-            ret = nbd_write(client->ioc, req->data, len, NULL);
+            ret = nbd_write(client->ioc, req->data, len, errp);
             if (ret < 0) {
                 ret = -EIO;
             }
@@ -994,17 +1029,18 @@ static int nbd_co_send_reply(NBDRequestData *req, NBDReply *reply, int len)
  * the client (although the caller may still need to disconnect after reporting
  * the error).
  */
-static int nbd_co_receive_request(NBDRequestData *req, NBDRequest *request)
+static int nbd_co_receive_request(NBDRequestData *req, NBDRequest *request,
+                                  Error **errp)
 {
     NBDClient *client = req->client;
 
     g_assert(qemu_in_coroutine());
     assert(client->recv_coroutine == qemu_coroutine_self());
-    if (nbd_receive_request(client->ioc, request) < 0) {
+    if (nbd_receive_request(client->ioc, request, errp) < 0) {
         return -EIO;
     }
 
-    TRACE("Decoding type");
+    trace_nbd_co_receive_request_decode_type(request->handle, request->type);
 
     if (request->type != NBD_CMD_WRITE) {
         /* No payload, we are ready to read the next request.  */
@@ -1014,7 +1050,6 @@ static int nbd_co_receive_request(NBDRequestData *req, NBDRequest *request)
     if (request->type == NBD_CMD_DISC) {
         /* Special case: we're going to disconnect without a reply,
          * whether or not flags, from, or len are bogus */
-        TRACE("Request type is DISCONNECT");
         return -EIO;
     }
 
@@ -1022,46 +1057,49 @@ static int nbd_co_receive_request(NBDRequestData *req, NBDRequest *request)
      * checks as possible until after reading any NBD_CMD_WRITE
      * payload, so we can try and keep the connection alive.  */
     if ((request->from + request->len) < request->from) {
-        LOG("integer overflow detected, you're probably being attacked");
+        error_setg(errp,
+                   "integer overflow detected, you're probably being attacked");
         return -EINVAL;
     }
 
     if (request->type == NBD_CMD_READ || request->type == NBD_CMD_WRITE) {
         if (request->len > NBD_MAX_BUFFER_SIZE) {
-            LOG("len (%" PRIu32" ) is larger than max len (%u)",
-                request->len, NBD_MAX_BUFFER_SIZE);
+            error_setg(errp, "len (%" PRIu32" ) is larger than max len (%u)",
+                       request->len, NBD_MAX_BUFFER_SIZE);
             return -EINVAL;
         }
 
         req->data = blk_try_blockalign(client->exp->blk, request->len);
         if (req->data == NULL) {
+            error_setg(errp, "No memory");
             return -ENOMEM;
         }
     }
     if (request->type == NBD_CMD_WRITE) {
-        TRACE("Reading %" PRIu32 " byte(s)", request->len);
-
-        if (nbd_read(client->ioc, req->data, request->len, NULL) < 0) {
-            LOG("reading from socket failed");
+        if (nbd_read(client->ioc, req->data, request->len, errp) < 0) {
+            error_prepend(errp, "reading from socket failed: ");
             return -EIO;
         }
         req->complete = true;
+
+        trace_nbd_co_receive_request_payload_received(request->handle,
+                                                      request->len);
     }
 
     /* Sanity checks, part 2. */
     if (request->from + request->len > client->exp->size) {
-        LOG("operation past EOF; From: %" PRIu64 ", Len: %" PRIu32
-            ", Size: %" PRIu64, request->from, request->len,
-            (uint64_t)client->exp->size);
+        error_setg(errp, "operation past EOF; From: %" PRIu64 ", Len: %" PRIu32
+                   ", Size: %" PRIu64, request->from, request->len,
+                   (uint64_t)client->exp->size);
         return request->type == NBD_CMD_WRITE ? -ENOSPC : -EINVAL;
     }
     if (request->flags & ~(NBD_CMD_FLAG_FUA | NBD_CMD_FLAG_NO_HOLE)) {
-        LOG("unsupported flags (got 0x%x)", request->flags);
+        error_setg(errp, "unsupported flags (got 0x%x)", request->flags);
         return -EINVAL;
     }
     if (request->type != NBD_CMD_WRITE_ZEROES &&
         (request->flags & NBD_CMD_FLAG_NO_HOLE)) {
-        LOG("unexpected flags (got 0x%x)", request->flags);
+        error_setg(errp, "unexpected flags (got 0x%x)", request->flags);
         return -EINVAL;
     }
 
@@ -1079,15 +1117,16 @@ static coroutine_fn void nbd_trip(void *opaque)
     int ret;
     int flags;
     int reply_data_len = 0;
+    Error *local_err = NULL;
 
-    TRACE("Reading request.");
+    trace_nbd_trip();
     if (client->closing) {
         nbd_client_put(client);
         return;
     }
 
     req = nbd_request_get(client);
-    ret = nbd_co_receive_request(req, &request);
+    ret = nbd_co_receive_request(req, &request, &local_err);
     client->recv_coroutine = NULL;
     nbd_client_receive_next_request(client);
     if (ret == -EIO) {
@@ -1112,13 +1151,11 @@ static coroutine_fn void nbd_trip(void *opaque)
 
     switch (request.type) {
     case NBD_CMD_READ:
-        TRACE("Request type is READ");
-
         /* XXX: NBD Protocol only documents use of FUA with WRITE */
         if (request.flags & NBD_CMD_FLAG_FUA) {
             ret = blk_co_flush(exp->blk);
             if (ret < 0) {
-                LOG("flush failed");
+                error_setg_errno(&local_err, -ret, "flush failed");
                 reply.error = -ret;
                 break;
             }
@@ -1127,26 +1164,20 @@ static coroutine_fn void nbd_trip(void *opaque)
         ret = blk_pread(exp->blk, request.from + exp->dev_offset,
                         req->data, request.len);
         if (ret < 0) {
-            LOG("reading from file failed");
+            error_setg_errno(&local_err, -ret, "reading from file failed");
             reply.error = -ret;
             break;
         }
 
         reply_data_len = request.len;
-        TRACE("Read %" PRIu32" byte(s)", request.len);
 
         break;
     case NBD_CMD_WRITE:
-        TRACE("Request type is WRITE");
-
         if (exp->nbdflags & NBD_FLAG_READ_ONLY) {
-            TRACE("Server is read-only, return error");
             reply.error = EROFS;
             break;
         }
 
-        TRACE("Writing to device");
-
         flags = 0;
         if (request.flags & NBD_CMD_FLAG_FUA) {
             flags |= BDRV_REQ_FUA;
@@ -1154,22 +1185,18 @@ static coroutine_fn void nbd_trip(void *opaque)
         ret = blk_pwrite(exp->blk, request.from + exp->dev_offset,
                          req->data, request.len, flags);
         if (ret < 0) {
-            LOG("writing to file failed");
+            error_setg_errno(&local_err, -ret, "writing to file failed");
             reply.error = -ret;
         }
 
         break;
     case NBD_CMD_WRITE_ZEROES:
-        TRACE("Request type is WRITE_ZEROES");
-
         if (exp->nbdflags & NBD_FLAG_READ_ONLY) {
-            TRACE("Server is read-only, return error");
+            error_setg(&local_err, "Server is read-only, return error");
             reply.error = EROFS;
             break;
         }
 
-        TRACE("Writing to device");
-
         flags = 0;
         if (request.flags & NBD_CMD_FLAG_FUA) {
             flags |= BDRV_REQ_FUA;
@@ -1180,7 +1207,7 @@ static coroutine_fn void nbd_trip(void *opaque)
         ret = blk_pwrite_zeroes(exp->blk, request.from + exp->dev_offset,
                                 request.len, flags);
         if (ret < 0) {
-            LOG("writing to file failed");
+            error_setg_errno(&local_err, -ret, "writing to file failed");
             reply.error = -ret;
         }
 
@@ -1190,46 +1217,58 @@ static coroutine_fn void nbd_trip(void *opaque)
         abort();
 
     case NBD_CMD_FLUSH:
-        TRACE("Request type is FLUSH");
-
         ret = blk_co_flush(exp->blk);
         if (ret < 0) {
-            LOG("flush failed");
+            error_setg_errno(&local_err, -ret, "flush failed");
             reply.error = -ret;
         }
 
         break;
     case NBD_CMD_TRIM:
-        TRACE("Request type is TRIM");
         ret = blk_co_pdiscard(exp->blk, request.from + exp->dev_offset,
                               request.len);
         if (ret < 0) {
-            LOG("discard failed");
+            error_setg_errno(&local_err, -ret, "discard failed");
             reply.error = -ret;
         }
 
         break;
     default:
-        LOG("invalid request type (%" PRIu32 ") received", request.type);
+        error_setg(&local_err, "invalid request type (%" PRIu32 ") received",
+                   request.type);
         reply.error = EINVAL;
     }
 
 reply:
+    if (local_err) {
+        /* If we are here local_err is not fatal error, already stored in
+         * reply.error */
+        error_report_err(local_err);
+        local_err = NULL;
+    }
+
+    if (nbd_co_send_reply(req, &reply, reply_data_len, &local_err) < 0) {
+        error_prepend(&local_err, "Failed to send reply: ");
+        goto disconnect;
+    }
+
     /* We must disconnect after NBD_CMD_WRITE if we did not
      * read the payload.
      */
-    if (nbd_co_send_reply(req, &reply, reply_data_len) < 0 || !req->complete) {
+    if (!req->complete) {
+        error_setg(&local_err, "Request handling failed in intermediate state");
         goto disconnect;
     }
 
-    TRACE("Request/Reply complete");
-
 done:
     nbd_request_put(req);
     nbd_client_put(client);
     return;
 
 disconnect:
+    if (local_err) {
+        error_reportf_err(local_err, "Disconnect client, due to: ");
+    }
     nbd_request_put(req);
     client_close(client, true);
     nbd_client_put(client);
@@ -1248,6 +1287,7 @@ static coroutine_fn void nbd_co_client_start(void *opaque)
 {
     NBDClient *client = opaque;
     NBDExport *exp = client->exp;
+    Error *local_err = NULL;
 
     if (exp) {
         nbd_export_get(exp);
@@ -1255,7 +1295,10 @@ static coroutine_fn void nbd_co_client_start(void *opaque)
     }
     qemu_co_mutex_init(&client->send_lock);
 
-    if (nbd_negotiate(client)) {
+    if (nbd_negotiate(client, &local_err)) {
+        if (local_err) {
+            error_report_err(local_err);
+        }
         client_close(client, false);
         return;
     }