testing: Add some debugging output into swtpm_ioctl's -h path

stefanberger · Jan 21, 2020 · ce29c60 · ce29c60
1 parent 930c7ba
commit ce29c60
Show file tree

Hide file tree

Showing 6 changed files with 74 additions and 14 deletions.
diff --git a/src/swtpm_ioctl/tpm_ioctl.c b/src/swtpm_ioctl/tpm_ioctl.c
@@ -116,6 +116,8 @@ static int ctrlcmd(int fd, unsigned long cmd, void *msg, size_t msg_len_in,
     }
 
     if ((statbuf.st_mode & S_IFMT) == S_IFCHR) {
+        if (cmd == PTM_HASH_DATA)
+             fprintf(stderr, "ctrlcmd: before ioctl\n");
         n = ioctl(fd, cmd, msg);
     } else {
         uint32_t cmd_no = htobe32(ioctl_to_cmd(cmd));
@@ -129,14 +131,23 @@ static int ctrlcmd(int fd, unsigned long cmd, void *msg, size_t msg_len_in,
             },
         };
 
+        if (cmd == PTM_HASH_DATA)
+             fprintf(stderr, "ctrlcmd: before writev msg: %p msg_len_in: %zu\n", msg, msg_len_in);
         n = writev(fd, iov, 2);
+        if (cmd == PTM_HASH_DATA)
+             fprintf(stderr, "ctrclmd: writev return: %d  errno: %d)\n", n, errno);
         if (n > 0) {
             if (msg_len_out > 0) {
+                if (cmd == PTM_HASH_DATA)
+                    fprintf(stderr, "ctrlcmd: before read\n");
                 n = read(fd, msg, msg_len_out);
             } else {
                 /* we read 0 bytes */
                 n = 0;
             }
+        } else {
+            if (cmd == PTM_HASH_DATA)
+                fprintf(stderr, "ctrlcmd: writev failed: %s\n", strerror(errno));
         }
     }
     return n;
@@ -152,14 +163,20 @@ static int do_hash_start_data_end(int fd, bool is_chardev, const char *input)
     int n;
     size_t idx;
     ptm_hdata hdata;
+    size_t inputlen;
 
     memset(&hdata, 0, sizeof(hdata));
 
+    fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
+
     if (!input) {
         fprintf(stderr,
                 "Input buffer for hashing must not be NULL.\n");
         return 1;
     }
+    inputlen = strlen(input);
+
+    fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
 
     /* hash string given on command line */
     n = ctrlcmd(fd, PTM_HASH_START, &res, 0, sizeof(res));
@@ -169,18 +186,21 @@ static int do_hash_start_data_end(int fd, bool is_chardev, const char *input)
                 "%s\n", strerror(errno));
         return 1;
     }
+    fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
     if (devtoh32(is_chardev, res) != 0) {
         fprintf(stderr,
                 "TPM result from PTM_HASH_START: 0x%x\n",
                 devtoh32(is_chardev, res));
         return 1;
     }
-    if (strlen(input) == 1 && input[0] == '-') {
+    fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
+    if (inputlen == 1 && input[0] == '-') {
         /* read data from stdin */
         while (1) {
             idx = 0;
             int c = 0;
 
+  //          fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
             while (idx < sizeof(hdata.u.req.data)) {
                 c = fgetc(stdin);
                 if (c == EOF)
@@ -191,53 +211,64 @@ static int do_hash_start_data_end(int fd, bool is_chardev, const char *input)
             }
             hdata.u.req.length = htodev32(is_chardev, idx);
 
+ //           fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
             n = ctrlcmd(fd, PTM_HASH_DATA, &hdata,
                         offsetof(ptm_hdata, u.req.data) + idx,
                         sizeof(hdata.u.resp));
 
+//            fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
             res = devtoh32(is_chardev, hdata.u.resp.tpm_result);
             if (n < 0 || res != 0 || c == EOF)
                 break;
         }
     } else {
         idx = 0;
-        while (idx < strlen(input)) {
-            size_t tocopy = strlen(input) - idx;
+        while (idx < inputlen) {
+            size_t tocopy = inputlen - idx;
 
+//            fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
             if (tocopy > sizeof(hdata.u.req.data))
                 tocopy = sizeof(hdata.u.req.data);
 
+ //           fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
             hdata.u.req.length = htodev32(is_chardev, tocopy);
             memcpy(hdata.u.req.data, &input[idx], tocopy);
             idx += tocopy;
 
+            fprintf(stderr, "%s @ %d  tocopy: %zu\n", __func__, __LINE__, tocopy);
             n = ctrlcmd(fd, PTM_HASH_DATA, &hdata,
                         offsetof(ptm_hdata, u.req.data) + tocopy,
                         sizeof(hdata.u.resp));
 
+//            fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
             res = devtoh32(is_chardev, hdata.u.resp.tpm_result);
             if (n < 0 || res != 0)
                 break;
         }
     }
+    fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
     if (n < 0) {
         fprintf(stderr,
                 "Could not execute ioctl PTM_HASH_DATA: "
                 "%s\n", strerror(errno));
         return 1;
     }
+    fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
     if (res != 0) {
         fprintf(stderr,
                "TPM result from PTM_HASH_DATA: 0x%x\n", res);
         return 1;
     }
+    fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
     n = ctrlcmd(fd, PTM_HASH_END, &res, 0, sizeof(res));
+    fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
     if (n < 0) {
         fprintf(stderr,
                 "Could not execute ioctl PTM_HASH_END: "
                 "%s\n", strerror(errno));
         return 1;
     }
+    fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
     if (devtoh32(is_chardev, res) != 0) {
         fprintf(stderr,
                 "TPM result from PTM_HASH_END: 0x%x\n",
@@ -984,6 +1015,10 @@ int main(int argc, char *argv[])
         goto exit;
     }
 
+    if (command && !strcmp(command, "-h")) {
+        fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
+    }
+
     if (!tpm_device && !tcp_hostname && !unix_path) {
         if (optind == argc) {
             fprintf(stderr, "Error: Missing device name.\n");
@@ -995,6 +1030,10 @@ int main(int argc, char *argv[])
         }
     }
 
+    if (command && !strcmp(command, "-h")) {
+        fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
+    }
+
     is_chardev = (tpm_device != NULL);
     if (is_chardev) {
         tmp = getenv("SWTPM_IOCTL_BUFFERSIZE");
@@ -1004,11 +1043,20 @@ int main(int argc, char *argv[])
         }
     }
 
+    if (command && !strcmp(command, "-h")) {
+        fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
+    }
+
     fd = open_connection(tpm_device, tcp_hostname, tcp_port, unix_path);
     if (fd < 0) {
+        fprintf(stderr, "Could not create connection\n");
         goto exit;
     }
 
+    if (command && !strcmp(command, "-h")) {
+        fprintf(stderr, "%s @ %d\n", __func__, __LINE__);
+    }
+
     if (!strcmp(command, "-c")) {
         n = ctrlcmd(fd, PTM_GET_CAPABILITY, &cap, 0, sizeof(cap));
         if (n < 0) {
@@ -1122,10 +1170,12 @@ int main(int argc, char *argv[])
         }
 
     } else if (!strcmp(command, "-h")) {
+        fprintf(stderr, "hashing now!\n");
         if (do_hash_start_data_end(fd, is_chardev, hashdata)) {
+            fprintf(stderr, "hashing failed\n");
             goto exit;
         }
-
+        fprintf(stderr, "hashing succeeded\n");
     } else if (!strcmp(command, "-C")) {
         n = ctrlcmd(fd, PTM_CANCEL_TPM_CMD, &res, 0, sizeof(res));
         if (n < 0) {
@@ -1231,5 +1281,10 @@ int main(int argc, char *argv[])
 
 exit:
     free(tcp_hostname);
+
+    if (command && !strcmp(command, "-h")) {
+        fprintf(stderr, "Exiting with ret=%d\n", ret);
+    }
+
     return ret;
 }
diff --git a/tests/_test_hashing b/tests/_test_hashing
@@ -80,8 +80,9 @@ if [ "$RES" != "$exp" ]; then
 fi
 
 run_swtpm_ioctl ${SWTPM_INTERFACE} -h 1234
-if [ $? -ne 0 ]; then
-	echo "Error: Hash command did not work."
+rc=$?
+if [ $rc -ne 0 ]; then
+	echo "Error: Hash command did not work: $rc     ${PIPESTATUS[@]}"
 	exit 1
 fi
 

diff --git a/tests/_test_hashing2 b/tests/_test_hashing2
@@ -82,8 +82,9 @@ if [ "$RES" != "$exp" ]; then
 fi
 
 run_swtpm_ioctl ${SWTPM_INTERFACE} -h 1234
-if [ $? -ne 0 ]; then
-	echo "Error: Hash command did not work."
+rc=$?
+if [ $rc -ne 0 ]; then
+	echo "Error: Hash command did not work: $rc   ${PIPESTATUS[@]}"
 	exit 1
 fi
 

diff --git a/tests/_test_tpm2_hashing b/tests/_test_tpm2_hashing
@@ -82,8 +82,9 @@ if [ "$RES" != "$exp" ]; then
 fi
 
 run_swtpm_ioctl ${SWTPM_INTERFACE} -h 1234
-if [ $? -ne 0 ]; then
-	echo "Error: The hash command failed."
+rc=$?
+if [ $rc -ne 0 ]; then
+	echo "Error: The hash command failed: $rc   ${PIPESTATUS[@]}"
 	exit 1
 fi
 

diff --git a/tests/_test_tpm2_hashing2 b/tests/_test_tpm2_hashing2
@@ -81,8 +81,9 @@ if [ "$RES" != "$exp" ]; then
 fi
 
 run_swtpm_ioctl ${SWTPM_INTERFACE} -h 1234
-if [ $? -ne 0 ]; then
-	echo "Error: The hash command failed."
+rc=$?
+if [ $rc -ne 0 ]; then
+	echo "Error: The hash command failed: $rc   ${PIPESTATUS[@]}"
 	exit 1
 fi
 

diff --git a/tests/_test_tpm2_hashing3 b/tests/_test_tpm2_hashing3
@@ -74,8 +74,9 @@ fi
 
 # Hash
 run_swtpm_ioctl ${SWTPM_INTERFACE} -h 1234
-if [ $? -ne 0 ]; then
-	echo "Error: The hash command failed."
+rc=$?
+if [ $rc -ne 0 ]; then
+	echo "Error: The hash command failed: $rc   ${PIPESTATUS[@]}"
 	exit 1
 fi