diff mbox series

[v5,09/24] fsverity: add tracepoints

Message ID 20240304191046.157464-11-aalbersh@redhat.com (mailing list archive)
State Superseded, archived
Headers show
Series fs-verity support for XFS | expand

Commit Message

Andrey Albershteyn March 4, 2024, 7:10 p.m. UTC 
fs-verity previously had debug printk but it was removed. This patch
adds trace points to the same places where printk were used (with a
few additional ones).

Signed-off-by: Andrey Albershteyn <aalbersh@redhat.com>
---
 MAINTAINERS                     |   1 +
 fs/verity/enable.c              |   3 +
 fs/verity/fsverity_private.h    |   2 +
 fs/verity/init.c                |   1 +
 fs/verity/signature.c           |   2 +
 fs/verity/verify.c              |   7 ++
 include/trace/events/fsverity.h | 181 ++++++++++++++++++++++++++++++++
 7 files changed, 197 insertions(+)
 create mode 100644 include/trace/events/fsverity.h

Comments

Eric Biggers March 5, 2024, 12:33 a.m. UTC | #1 
On Mon, Mar 04, 2024 at 08:10:32PM +0100, Andrey Albershteyn wrote:
> diff --git a/include/trace/events/fsverity.h b/include/trace/events/fsverity.h
> new file mode 100644
> index 000000000000..82966ecc5722
> --- /dev/null
> +++ b/include/trace/events/fsverity.h
> @@ -0,0 +1,181 @@
> +/* SPDX-License-Identifier: GPL-2.0 */
> +#undef TRACE_SYSTEM
> +#define TRACE_SYSTEM fsverity
> +
> +#if !defined(_TRACE_FSVERITY_H) || defined(TRACE_HEADER_MULTI_READ)
> +#define _TRACE_FSVERITY_H
> +
> +#include <linux/tracepoint.h>
> +
> +struct fsverity_descriptor;
> +struct merkle_tree_params;
> +struct fsverity_info;
> +
> +#define FSVERITY_TRACE_DIR_ASCEND	(1ul << 0)
> +#define FSVERITY_TRACE_DIR_DESCEND	(1ul << 1)
> +#define FSVERITY_HASH_SHOWN_LEN		20
> +
> +TRACE_EVENT(fsverity_enable,
> +	TP_PROTO(struct inode *inode, struct fsverity_descriptor *desc,
> +		struct merkle_tree_params *params),
> +	TP_ARGS(inode, desc, params),
> +	TP_STRUCT__entry(
> +		__field(ino_t, ino)
> +		__field(u64, data_size)
> +		__field(unsigned int, block_size)
> +		__field(unsigned int, num_levels)
> +		__field(u64, tree_size)
> +	),
> +	TP_fast_assign(
> +		__entry->ino = inode->i_ino;
> +		__entry->data_size = desc->data_size;
> +		__entry->block_size = params->block_size;
> +		__entry->num_levels = params->num_levels;
> +		__entry->tree_size = params->tree_size;
> +	),
> +	TP_printk("ino %lu data size %llu tree size %llu block size %u levels %u",
> +		(unsigned long) __entry->ino,
> +		__entry->data_size,
> +		__entry->tree_size,
> +		__entry->block_size,
> +		__entry->num_levels)
> +);

All pointer parameters to the tracepoints should be const, so that it's clear
that the pointed-to-data isn't being modified.

The desc parameter is not needed for fsverity_enable, since it's only being used
for the file size which is also available in inode->i_size.

> +TRACE_EVENT(fsverity_tree_done,
> +	TP_PROTO(struct inode *inode, struct fsverity_descriptor *desc,
> +		struct merkle_tree_params *params),
> +	TP_ARGS(inode, desc, params),
> +	TP_STRUCT__entry(
> +		__field(ino_t, ino)
> +		__field(unsigned int, levels)
> +		__field(unsigned int, tree_blocks)
> +		__field(u64, tree_size)
> +		__array(u8, tree_hash, 64)
> +	),
> +	TP_fast_assign(
> +		__entry->ino = inode->i_ino;
> +		__entry->levels = params->num_levels;
> +		__entry->tree_blocks =
> +			params->tree_size >> params->log_blocksize;
> +		__entry->tree_size = params->tree_size;
> +		memcpy(__entry->tree_hash, desc->root_hash, 64);
> +	),
> +	TP_printk("ino %lu levels %d tree_blocks %d tree_size %lld root_hash %s",
> +		(unsigned long) __entry->ino,
> +		__entry->levels,
> +		__entry->tree_blocks,
> +		__entry->tree_size,
> +		__print_hex(__entry->tree_hash, 64))
> +);

tree_blocks is using the wrong type (unsigned int instead of unsigned long), and
it doesn't seem very useful since there's already tree_size and the
fsverity_enable event which has block_size.

Also, the way this handles the hash is weird.  It shows 64 bytes, even if it's
shorter, and it doesn't show what algorithm it uses.  That makes the value hard
to use, as the same string could be shown for two hashes that are actually
different.  Maybe take a look at how fsverity-utils prints hashes.

Also, did you perhaps intend to use the file digest instead?  The "Merkle tree
root hash" isn't the actual file digest that userspace sees.  There's one more
level of hashing on top of that.

> +TRACE_EVENT(fsverity_verify_block,
> +	TP_PROTO(struct inode *inode, u64 offset),
> +	TP_ARGS(inode, offset),
> +	TP_STRUCT__entry(
> +		__field(ino_t, ino)
> +		__field(u64, offset)
> +		__field(unsigned int, block_size)
> +	),
> +	TP_fast_assign(
> +		__entry->ino = inode->i_ino;
> +		__entry->offset = offset;
> +		__entry->block_size =
> +			inode->i_verity_info->tree_params.block_size;
> +	),
> +	TP_printk("ino %lu data offset %lld data block size %u",
> +		(unsigned long) __entry->ino,
> +		__entry->offset,
> +		__entry->block_size)
> +);

This should be named fsverity_verify_data_block, since it's invoked when a data
block is verified, not when a hash block is verified.  Or did you perhaps intend
for this to be invoked for all blocks?

Also, please don't use 'offset', as it's ambiguous.  We should follow the
convention used in the pagecache code where 'pos' is used for an offset in
bytes, and 'index' is used for an offset in something else such as blocks.
Likewise in the other tracepoints that are using 'offset'.

Also, the derefenece of ->i_verity_info seems a bit out of place.  This probably
should be passed the merkle_tree_params directly.

> +TRACE_EVENT(fsverity_merkle_tree_block_verified,
> +	TP_PROTO(struct inode *inode,
> +		 struct fsverity_blockbuf *block,
> +		 u8 direction),
> +	TP_ARGS(inode, block, direction),
> +	TP_STRUCT__entry(
> +		__field(ino_t, ino)
> +		__field(u64, offset)
> +		__field(u8, direction)
> +	),
> +	TP_fast_assign(
> +		__entry->ino = inode->i_ino;
> +		__entry->offset = block->offset;
> +		__entry->direction = direction;
> +	),
> +	TP_printk("ino %lu block offset %llu %s",
> +		(unsigned long) __entry->ino,
> +		__entry->offset,
> +		__entry->direction == 0 ? "ascend" : "descend")
> +);

It looks like 'offset' is the index of the block in the whole Merkle tree, in
which case it should be called 'index'.  However perhaps it would be more useful
to provide a (level, index_in_level) pair?

Also, fsverity_merkle_tree_block_verified isn't just being invoked when a Merkle
tree block is being verified, but also when an already-verified block is seen.
That might make it confusing to use.  Perhaps it should be defined to be just
for when a block is being verified?

> +TRACE_EVENT(fsverity_invalidate_block,
> +	TP_PROTO(struct inode *inode, struct fsverity_blockbuf *block),
> +	TP_ARGS(inode, block),
> +	TP_STRUCT__entry(
> +		__field(ino_t, ino)
> +		__field(u64, offset)
> +		__field(unsigned int, block_size)
> +	),
> +	TP_fast_assign(
> +		__entry->ino = inode->i_ino;
> +		__entry->offset = block->offset;
> +		__entry->block_size = block->size;
> +	),
> +	TP_printk("ino %lu block position %llu block size %u",
> +		(unsigned long) __entry->ino,
> +		__entry->offset,
> +		__entry->block_size)
> +);

fsverity_invalidate_merkle_tree_block?  And again, call 'offset' something else.

> +TRACE_EVENT(fsverity_read_merkle_tree_block,
> +	TP_PROTO(struct inode *inode, u64 offset, unsigned int log_blocksize),
> +	TP_ARGS(inode, offset, log_blocksize),
> +	TP_STRUCT__entry(
> +		__field(ino_t, ino)
> +		__field(u64, offset)
> +		__field(u64, index)
> +		__field(unsigned int, block_size)
> +	),
> +	TP_fast_assign(
> +		__entry->ino = inode->i_ino;
> +		__entry->offset = offset;
> +		__entry->index = offset >> log_blocksize;
> +		__entry->block_size = 1 << log_blocksize;
> +	),
> +	TP_printk("ino %lu tree offset %llu block index %llu block hize %u",
> +		(unsigned long) __entry->ino,
> +		__entry->offset,
> +		__entry->index,
> +		__entry->block_size)
> +);

This tracepoint is never actually invoked.

Also it seems redundant to have both 'index' and 'offset'.

> +TRACE_EVENT(fsverity_verify_signature,
> +	TP_PROTO(const struct inode *inode, const u8 *signature, size_t sig_size),
> +	TP_ARGS(inode, signature, sig_size),
> +	TP_STRUCT__entry(
> +		__field(ino_t, ino)
> +		__dynamic_array(u8, signature, sig_size)
> +		__field(size_t, sig_size)
> +		__field(size_t, sig_size_show)
> +	),
> +	TP_fast_assign(
> +		__entry->ino = inode->i_ino;
> +		memcpy(__get_dynamic_array(signature), signature, sig_size);
> +		__entry->sig_size = sig_size;
> +		__entry->sig_size_show = (sig_size > FSVERITY_HASH_SHOWN_LEN ?
> +			FSVERITY_HASH_SHOWN_LEN : sig_size);
> +	),
> +	TP_printk("ino %lu sig_size %lu %s%s%s",
> +		(unsigned long) __entry->ino,
> +		__entry->sig_size,
> +		(__entry->sig_size ? "sig " : ""),
> +		__print_hex(__get_dynamic_array(signature),
> +			__entry->sig_size_show),
> +		(__entry->sig_size ? "..." : ""))
> +);

Do you actually have plans to use the builtin signature support?  It's been
causing a lot of issues for people, so I've been discouraging people from using
it.  If there is no use case for this tracepoint then we shouldn't add it.

The way it's printing the signature is also weird.  It's incorrectly referring
to it a "hash", and it's only showing the first 20 bytes which might just
contain PKCS#7 boilerplate and not the actual signature.  So I'm not sure what
the purpose of this is.

Also, this tracepoint gets invoked even when there is no signature, which is
confusing.

- Eric
diff mbox series

Patch

diff --git a/MAINTAINERS b/MAINTAINERS
index 2ecaaec6a6bf..49888dd5cbbd 100644
--- a/MAINTAINERS
+++ b/MAINTAINERS
@@ -8745,6 +8745,7 @@  T:	git https://git.kernel.org/pub/scm/fs/fsverity/linux.git
 F:	Documentation/filesystems/fsverity.rst
 F:	fs/verity/
 F:	include/linux/fsverity.h
+F:	include/trace/events/fsverity.h
 F:	include/uapi/linux/fsverity.h
 
 FT260 FTDI USB-HID TO I2C BRIDGE DRIVER
diff --git a/fs/verity/enable.c b/fs/verity/enable.c
index 04e060880b79..945eba0092ab 100644
--- a/fs/verity/enable.c
+++ b/fs/verity/enable.c
@@ -227,6 +227,8 @@  static int enable_verity(struct file *filp,
 	if (err)
 		goto out;
 
+	trace_fsverity_enable(inode, desc, &params);
+
 	/*
 	 * Start enabling verity on this file, serialized by the inode lock.
 	 * Fail if verity is already enabled or is already being enabled.
@@ -255,6 +257,7 @@  static int enable_verity(struct file *filp,
 		fsverity_err(inode, "Error %d building Merkle tree", err);
 		goto rollback;
 	}
+	trace_fsverity_tree_done(inode, desc, &params);
 
 	/*
 	 * Create the fsverity_info.  Don't bother trying to save work by
diff --git a/fs/verity/fsverity_private.h b/fs/verity/fsverity_private.h
index dad33e6ff0d6..fd8f5a8d1f6a 100644
--- a/fs/verity/fsverity_private.h
+++ b/fs/verity/fsverity_private.h
@@ -162,4 +162,6 @@  void __init fsverity_init_workqueue(void);
 void fsverity_drop_block(struct inode *inode,
 			 struct fsverity_blockbuf *block);
 
+#include <trace/events/fsverity.h>
+
 #endif /* _FSVERITY_PRIVATE_H */
diff --git a/fs/verity/init.c b/fs/verity/init.c
index cb2c9aac61ed..3769d2dc9e3b 100644
--- a/fs/verity/init.c
+++ b/fs/verity/init.c
@@ -5,6 +5,7 @@ 
  * Copyright 2019 Google LLC
  */
 
+#define CREATE_TRACE_POINTS
 #include "fsverity_private.h"
 
 #include <linux/ratelimit.h>
diff --git a/fs/verity/signature.c b/fs/verity/signature.c
index 90c07573dd77..c1f08bb32ed1 100644
--- a/fs/verity/signature.c
+++ b/fs/verity/signature.c
@@ -53,6 +53,8 @@  int fsverity_verify_signature(const struct fsverity_info *vi,
 	struct fsverity_formatted_digest *d;
 	int err;
 
+	trace_fsverity_verify_signature(inode, signature, sig_size);
+
 	if (sig_size == 0) {
 		if (fsverity_require_signatures) {
 			fsverity_err(inode,
diff --git a/fs/verity/verify.c b/fs/verity/verify.c
index de71911d400c..614776e7a2b6 100644
--- a/fs/verity/verify.c
+++ b/fs/verity/verify.c
@@ -118,6 +118,7 @@  verify_data_block(struct inode *inode, struct fsverity_info *vi,
 		/* Byte offset of the wanted hash relative to @addr */
 		unsigned int hoffset;
 	} hblocks[FS_VERITY_MAX_LEVELS];
+	trace_fsverity_verify_block(inode, data_pos);
 	/*
 	 * The index of the previous level's block within that level; also the
 	 * index of that block's hash within the current level.
@@ -215,6 +216,8 @@  verify_data_block(struct inode *inode, struct fsverity_info *vi,
 		if (is_hash_block_verified(inode, block, hblock_idx)) {
 			memcpy(_want_hash, block->kaddr + hoffset, hsize);
 			want_hash = _want_hash;
+			trace_fsverity_merkle_tree_block_verified(inode,
+					block, FSVERITY_TRACE_DIR_ASCEND);
 			fsverity_drop_block(inode, block);
 			goto descend;
 		}
@@ -248,6 +251,8 @@  verify_data_block(struct inode *inode, struct fsverity_info *vi,
 			SetPageChecked(hpage);
 		memcpy(_want_hash, haddr + hoffset, hsize);
 		want_hash = _want_hash;
+		trace_fsverity_merkle_tree_block_verified(inode, block,
+				FSVERITY_TRACE_DIR_DESCEND);
 		fsverity_drop_block(inode, block);
 	}
 
@@ -405,6 +410,8 @@  void fsverity_invalidate_block(struct inode *inode,
 	struct fsverity_info *vi = inode->i_verity_info;
 	const unsigned int log_blocksize = vi->tree_params.log_blocksize;
 
+	trace_fsverity_invalidate_block(inode, block);
+
 	if (block->offset > vi->tree_params.tree_size) {
 		fsverity_err(inode,
 "Trying to invalidate beyond Merkle tree (tree %lld, offset %lld)",
diff --git a/include/trace/events/fsverity.h b/include/trace/events/fsverity.h
new file mode 100644
index 000000000000..82966ecc5722
--- /dev/null
+++ b/include/trace/events/fsverity.h
@@ -0,0 +1,181 @@ 
+/* SPDX-License-Identifier: GPL-2.0 */
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM fsverity
+
+#if !defined(_TRACE_FSVERITY_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_FSVERITY_H
+
+#include <linux/tracepoint.h>
+
+struct fsverity_descriptor;
+struct merkle_tree_params;
+struct fsverity_info;
+
+#define FSVERITY_TRACE_DIR_ASCEND	(1ul << 0)
+#define FSVERITY_TRACE_DIR_DESCEND	(1ul << 1)
+#define FSVERITY_HASH_SHOWN_LEN		20
+
+TRACE_EVENT(fsverity_enable,
+	TP_PROTO(struct inode *inode, struct fsverity_descriptor *desc,
+		struct merkle_tree_params *params),
+	TP_ARGS(inode, desc, params),
+	TP_STRUCT__entry(
+		__field(ino_t, ino)
+		__field(u64, data_size)
+		__field(unsigned int, block_size)
+		__field(unsigned int, num_levels)
+		__field(u64, tree_size)
+	),
+	TP_fast_assign(
+		__entry->ino = inode->i_ino;
+		__entry->data_size = desc->data_size;
+		__entry->block_size = params->block_size;
+		__entry->num_levels = params->num_levels;
+		__entry->tree_size = params->tree_size;
+	),
+	TP_printk("ino %lu data size %llu tree size %llu block size %u levels %u",
+		(unsigned long) __entry->ino,
+		__entry->data_size,
+		__entry->tree_size,
+		__entry->block_size,
+		__entry->num_levels)
+);
+
+TRACE_EVENT(fsverity_tree_done,
+	TP_PROTO(struct inode *inode, struct fsverity_descriptor *desc,
+		struct merkle_tree_params *params),
+	TP_ARGS(inode, desc, params),
+	TP_STRUCT__entry(
+		__field(ino_t, ino)
+		__field(unsigned int, levels)
+		__field(unsigned int, tree_blocks)
+		__field(u64, tree_size)
+		__array(u8, tree_hash, 64)
+	),
+	TP_fast_assign(
+		__entry->ino = inode->i_ino;
+		__entry->levels = params->num_levels;
+		__entry->tree_blocks =
+			params->tree_size >> params->log_blocksize;
+		__entry->tree_size = params->tree_size;
+		memcpy(__entry->tree_hash, desc->root_hash, 64);
+	),
+	TP_printk("ino %lu levels %d tree_blocks %d tree_size %lld root_hash %s",
+		(unsigned long) __entry->ino,
+		__entry->levels,
+		__entry->tree_blocks,
+		__entry->tree_size,
+		__print_hex(__entry->tree_hash, 64))
+);
+
+TRACE_EVENT(fsverity_verify_block,
+	TP_PROTO(struct inode *inode, u64 offset),
+	TP_ARGS(inode, offset),
+	TP_STRUCT__entry(
+		__field(ino_t, ino)
+		__field(u64, offset)
+		__field(unsigned int, block_size)
+	),
+	TP_fast_assign(
+		__entry->ino = inode->i_ino;
+		__entry->offset = offset;
+		__entry->block_size =
+			inode->i_verity_info->tree_params.block_size;
+	),
+	TP_printk("ino %lu data offset %lld data block size %u",
+		(unsigned long) __entry->ino,
+		__entry->offset,
+		__entry->block_size)
+);
+
+TRACE_EVENT(fsverity_merkle_tree_block_verified,
+	TP_PROTO(struct inode *inode,
+		 struct fsverity_blockbuf *block,
+		 u8 direction),
+	TP_ARGS(inode, block, direction),
+	TP_STRUCT__entry(
+		__field(ino_t, ino)
+		__field(u64, offset)
+		__field(u8, direction)
+	),
+	TP_fast_assign(
+		__entry->ino = inode->i_ino;
+		__entry->offset = block->offset;
+		__entry->direction = direction;
+	),
+	TP_printk("ino %lu block offset %llu %s",
+		(unsigned long) __entry->ino,
+		__entry->offset,
+		__entry->direction == 0 ? "ascend" : "descend")
+);
+
+TRACE_EVENT(fsverity_invalidate_block,
+	TP_PROTO(struct inode *inode, struct fsverity_blockbuf *block),
+	TP_ARGS(inode, block),
+	TP_STRUCT__entry(
+		__field(ino_t, ino)
+		__field(u64, offset)
+		__field(unsigned int, block_size)
+	),
+	TP_fast_assign(
+		__entry->ino = inode->i_ino;
+		__entry->offset = block->offset;
+		__entry->block_size = block->size;
+	),
+	TP_printk("ino %lu block position %llu block size %u",
+		(unsigned long) __entry->ino,
+		__entry->offset,
+		__entry->block_size)
+);
+
+TRACE_EVENT(fsverity_read_merkle_tree_block,
+	TP_PROTO(struct inode *inode, u64 offset, unsigned int log_blocksize),
+	TP_ARGS(inode, offset, log_blocksize),
+	TP_STRUCT__entry(
+		__field(ino_t, ino)
+		__field(u64, offset)
+		__field(u64, index)
+		__field(unsigned int, block_size)
+	),
+	TP_fast_assign(
+		__entry->ino = inode->i_ino;
+		__entry->offset = offset;
+		__entry->index = offset >> log_blocksize;
+		__entry->block_size = 1 << log_blocksize;
+	),
+	TP_printk("ino %lu tree offset %llu block index %llu block hize %u",
+		(unsigned long) __entry->ino,
+		__entry->offset,
+		__entry->index,
+		__entry->block_size)
+);
+
+TRACE_EVENT(fsverity_verify_signature,
+	TP_PROTO(const struct inode *inode, const u8 *signature, size_t sig_size),
+	TP_ARGS(inode, signature, sig_size),
+	TP_STRUCT__entry(
+		__field(ino_t, ino)
+		__dynamic_array(u8, signature, sig_size)
+		__field(size_t, sig_size)
+		__field(size_t, sig_size_show)
+	),
+	TP_fast_assign(
+		__entry->ino = inode->i_ino;
+		memcpy(__get_dynamic_array(signature), signature, sig_size);
+		__entry->sig_size = sig_size;
+		__entry->sig_size_show = (sig_size > FSVERITY_HASH_SHOWN_LEN ?
+			FSVERITY_HASH_SHOWN_LEN : sig_size);
+	),
+	TP_printk("ino %lu sig_size %lu %s%s%s",
+		(unsigned long) __entry->ino,
+		__entry->sig_size,
+		(__entry->sig_size ? "sig " : ""),
+		__print_hex(__get_dynamic_array(signature),
+			__entry->sig_size_show),
+		(__entry->sig_size ? "..." : ""))
+);
+
+#endif /* _TRACE_FSVERITY_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>