From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from firstgate.proxmox.com (firstgate.proxmox.com [212.224.123.68]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits)) (No client certificate requested) by lists.proxmox.com (Postfix) with ESMTPS id DD8E495640 for ; Wed, 18 Jan 2023 13:21:14 +0100 (CET) Received: from firstgate.proxmox.com (localhost [127.0.0.1]) by firstgate.proxmox.com (Proxmox) with ESMTP id B9CD51FB3A for ; Wed, 18 Jan 2023 13:21:14 +0100 (CET) Received: from proxmox-new.maurer-it.com (proxmox-new.maurer-it.com [94.136.29.106]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits)) (No client certificate requested) by firstgate.proxmox.com (Proxmox) with ESMTPS for ; Wed, 18 Jan 2023 13:21:14 +0100 (CET) Received: from proxmox-new.maurer-it.com (localhost.localdomain [127.0.0.1]) by proxmox-new.maurer-it.com (Proxmox) with ESMTP id C497745072 for ; Wed, 18 Jan 2023 13:21:13 +0100 (CET) From: Fiona Ebner To: pve-devel@lists.proxmox.com Date: Wed, 18 Jan 2023 13:21:07 +0100 Message-Id: <20230118122109.304270-2-f.ebner@proxmox.com> X-Mailer: git-send-email 2.30.2 In-Reply-To: <20230118122109.304270-1-f.ebner@proxmox.com> References: <20230118122109.304270-1-f.ebner@proxmox.com> MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-SPAM-LEVEL: Spam detection results: 0 AWL 0.022 Adjusted score from AWL reputation of From: address BAYES_00 -1.9 Bayes spam probability is 0 to 1% KAM_DMARC_STATUS 0.01 Test Rule for DKIM or SPF Failure with Strict Alignment SPF_HELO_NONE 0.001 SPF: HELO does not publish an SPF Record SPF_PASS -0.001 SPF: sender matches SPF record Subject: [pve-devel] [PATCH swtpm 1/1] control channel: add error logs upon receiving short input X-BeenThere: pve-devel@lists.proxmox.com X-Mailman-Version: 2.1.29 Precedence: list List-Id: Proxmox VE development discussion List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Wed, 18 Jan 2023 12:21:14 -0000 There was a recent failure when migrating a production VM > kvm: tpm-emulator: Setting the stateblob (type 1) failed with a TPM error 0x3 a parameter is bad > kvm: error while loading state for instance 0x0 of device 'tpm-emulator' > kvm: load of migration failed: Input/output error and it's not clear what exactly triggered it. Note that 0x3 is TPM_BAD_PARAMETER. The timeout check when receiving the command+body is a good candidate, but since poll() is called with the remaining timeout, it seems hard to trigger. In both cases with short input, QEMU would've not managed to even send the full header (16 bytes for CMD_SET_STATEBLOB). Another possibility is that the blob header got corrupted and the TPM_BAD_PARAMETER error orignated from the SWTPM_NVRAM_SetStateBlob() call. The checks there already have logging. Signed-off-by: Fiona Ebner --- src/swtpm/ctrlchannel.c | 17 +++++++++++++++-- 1 file changed, 15 insertions(+), 2 deletions(-) diff --git a/src/swtpm/ctrlchannel.c b/src/swtpm/ctrlchannel.c index 7b77a04..6538a54 100644 --- a/src/swtpm/ctrlchannel.c +++ b/src/swtpm/ctrlchannel.c @@ -419,8 +419,16 @@ wait_chunk: clock_gettime(CLOCK_REALTIME, &now); timespec_diff(&deadline, &now, &timeout); - if (timeout.tv_sec < 0) + if (timeout.tv_sec < 0) { + const char *msg_start = "Error: ctrlchannel_recv_cmd: timed out waiting for chunk"; + if (recvd >= offsetof(struct input, body)) { + logprintf(STDERR_FILENO, "%s for command 0x%08x\n", msg_start, be32toh(input->cmd)); + SWTPM_PrintAll("Input body", "", input->body, recvd - offsetof(struct input, body)); + } else { + logprintf(STDERR_FILENO, "%s before receiving full command\n", msg_start); + } break; + } to = timeout.tv_sec * 1000 + timeout.tv_nsec / 1E6; /* wait for the next chunk */ @@ -544,6 +552,7 @@ int ctrlchannel_process_fd(int fd, SWTPM_PrintAll(" Ctrl Cmd:", " ", msg.msg_iov->iov_base, min(n, 1024)); if ((size_t)n < sizeof(input.cmd)) { + logprintf(STDERR_FILENO, "Error: ctrlchannel_process_fd: input too short\n"); goto err_bad_input; } @@ -780,8 +789,12 @@ int ctrlchannel_process_fd(int fd, goto err_io; pss = (ptm_setstate *)input.body; - if (n < (ssize_t)offsetof(ptm_setstate, u.req.data)) /* rw */ + if (n < (ssize_t)offsetof(ptm_setstate, u.req.data)) { /* rw */ + logprintf(STDERR_FILENO, "Error: ctrlchannel_process_fd: input too " + "short for CMD_SET_STATEBLOB\n"); + SWTPM_PrintAll("Input body", "", input.body, n); goto err_bad_input; + } return ctrlchannel_receive_state(pss, n, fd); -- 2.30.2