fsnotify: Improve error messages with more context

Add more diagnostic information to error and log messages throughout
fsnotify.c to aid debugging when dump or restore fails:

- Include device (s_dev), inode (i_ino), mask, and watch descriptor (wd)
  in error messages where relevant
- Include mount ID and path information in mount-related errors
- Distinguish between inotify and fanotify in log prefixes
- Use pr_perror instead of pr_err where errno is meaningful
- Clarify messages to indicate which operation failed (e.g., 'Can't add
  inotify watch' instead of 'Can't add watch')

These improvements help identify which specific watch or mark failed
and provide the context needed to diagnose issues.

Signed-off-by: 3idey <3idey@users.noreply.github.com>
This commit is contained in:
3idey 2026-01-22 16:35:52 +02:00
parent d5700a69c9
commit d70b155c3d

View file

@ -183,7 +183,7 @@ static char *alloc_openable(unsigned int s_dev, unsigned long i_ino, FhEntry *f_
openable_fd = openat(mntfd, __path, O_PATH);
if (openable_fd >= 0) {
if (fstat(openable_fd, &st)) {
pr_perror("Can't stat on %s", __path);
pr_perror("Can't stat on %s for inode %#lx dev %#x", __path, i_ino, s_dev);
close(openable_fd);
goto err;
}
@ -228,7 +228,8 @@ static int open_handle(unsigned int s_dev, unsigned long i_ino, FhEntry *f_handl
mntfd = __open_mountpoint(m);
if (mntfd < 0) {
pr_warn("Can't open mount for s_dev %x, continue\n", s_dev);
pr_warn("Can't open mount for inode (dev %#x ino %#lx mnt_id %d), trying next\n",
s_dev, i_ino, m->mnt_id);
continue;
}
@ -275,12 +276,12 @@ int check_open_handle(unsigned int s_dev, unsigned long i_ino, FhEntry *f_handle
mi = lookup_mnt_sdev(s_dev);
if (mi == NULL) {
pr_err("Unable to lookup a mount by dev 0x%x\n", s_dev);
pr_err("Unable to lookup mount for inode (dev %#x ino %#lx)\n", s_dev, i_ino);
goto err;
}
if ((mi->fstype->code == FSTYPE__TMPFS) || (mi->fstype->code == FSTYPE__DEVTMPFS)) {
pr_err("Can't find suitable path for handle (dev %#x ino %#lx): %d\n", s_dev, i_ino,
pr_err("Can't find suitable path for inode handle (dev %#x ino %#lx): %d\n", s_dev, i_ino,
(int)PTR_ERR(path));
goto err;
}
@ -301,7 +302,7 @@ fault:
pr_warn("\tHandle 0x%x:0x%lx cannot be opened\n", s_dev, i_ino);
irmap_path = irmap_lookup(s_dev, i_ino);
if (!irmap_path) {
pr_err("\tCan't dump that handle\n");
pr_err("\tCan't dump inode handle (dev %#x ino %#lx): no irmap path found\n", s_dev, i_ino);
return -1;
}
path = xstrdup(irmap_path);
@ -318,16 +319,19 @@ err:
static int check_one_wd(InotifyWdEntry *we)
{
pr_info("wd: wd %#08x s_dev %#08x i_ino %#16" PRIx64 " mask %#08x\n", we->wd, we->s_dev, we->i_ino, we->mask);
pr_info("inotify wd %#08x s_dev %#08x i_ino %#16" PRIx64 " mask %#08x\n", we->wd, we->s_dev, we->i_ino, we->mask);
pr_info("\t[fhandle] bytes %#08x type %#08x __handle %#016" PRIx64 ":%#016" PRIx64 "\n", we->f_handle->bytes,
we->f_handle->type, we->f_handle->handle[0], we->f_handle->handle[1]);
if (we->mask & KERNEL_FS_EVENT_ON_CHILD)
pr_warn_once("\t\tDetected FS_EVENT_ON_CHILD bit "
"in mask (will be ignored on restore)\n");
pr_warn_once("\t\tDetected FS_EVENT_ON_CHILD bit in inotify wd %#08x "
"mask %#08x (will be ignored on restore)\n", we->wd, we->mask);
if (check_open_handle(we->s_dev, we->i_ino, we->f_handle))
if (check_open_handle(we->s_dev, we->i_ino, we->f_handle)) {
pr_err("Failed to check inotify wd (wd %#08x, dev %#x, ino %#lx, mask %#x)\n",
we->wd, we->s_dev, (unsigned long)we->i_ino, we->mask);
return -1;
}
return 0;
}
@ -342,7 +346,7 @@ static int dump_one_inotify(int lfd, u32 id, const struct fd_parms *p)
if (ret < 0)
return -1;
else if (ret > 0)
pr_warn("The %#08x inotify events will be dropped\n", id);
pr_warn("inotify %#08x events will be dropped\n", id);
ie.id = id;
ie.flags = p->flags;
@ -359,7 +363,7 @@ static int dump_one_inotify(int lfd, u32 id, const struct fd_parms *p)
fe.id = ie.id;
fe.ify = &ie;
pr_info("id %#08x flags %#08x\n", ie.id, ie.flags);
pr_info("inotify id %#08x flags %#08x\n", ie.id, ie.flags);
if (pb_write_one(img_from_set(glob_imgset, CR_FD_FILES), &fe, PB_FILE))
goto free;
@ -400,14 +404,17 @@ static int check_one_mark(FanotifyMarkEntry *fme)
if (fme->type == MARK_TYPE__INODE) {
BUG_ON(!fme->ie);
pr_info("mark: s_dev %#08x i_ino %#016" PRIx64 " mask %#08x\n", fme->s_dev, fme->ie->i_ino, fme->mask);
pr_info("fanotify inode mark s_dev %#08x i_ino %#016" PRIx64 " mask %#08x\n", fme->s_dev, fme->ie->i_ino, fme->mask);
pr_info("\t[fhandle] bytes %#08x type %#08x __handle %#016" PRIx64 ":%#016" PRIx64 "\n",
fme->ie->f_handle->bytes, fme->ie->f_handle->type, fme->ie->f_handle->handle[0],
fme->ie->f_handle->handle[1]);
if (check_open_handle(fme->s_dev, fme->ie->i_ino, fme->ie->f_handle))
if (check_open_handle(fme->s_dev, fme->ie->i_ino, fme->ie->f_handle)) {
pr_err("Failed to check fanotify inode mark (dev %#x, ino %#lx, mask %#x)\n",
fme->s_dev, (unsigned long)fme->ie->i_ino, fme->mask);
return -1;
}
}
if (fme->type == MARK_TYPE__MOUNT) {
@ -417,14 +424,15 @@ static int check_one_mark(FanotifyMarkEntry *fme)
m = lookup_mnt_id(fme->me->mnt_id);
if (!m) {
pr_err("Can't find mnt_id 0x%x\n", fme->me->mnt_id);
pr_err("Can't find mount for fanotify mount mark (mnt_id %#x, path %s)\n",
fme->me->mnt_id, fme->me->path ? fme->me->path : "(null)");
return -1;
}
if (!(root_ns_mask & CLONE_NEWNS))
fme->me->path = m->ns_mountpoint + 1;
fme->s_dev = m->s_dev;
pr_info("mark: s_dev %#08x mnt_id %#08x mask %#08x\n", fme->s_dev, fme->me->mnt_id, fme->mask);
pr_info("fanotify mount mark s_dev %#08x mnt_id %#08x mask %#08x\n", fme->s_dev, fme->me->mnt_id, fme->mask);
}
return 0;
@ -440,7 +448,7 @@ static int dump_one_fanotify(int lfd, u32 id, const struct fd_parms *p)
if (ret < 0)
return -1;
else if (ret > 0)
pr_warn("The %#08x fanotify events will be dropped\n", id);
pr_warn("fanotify %#08x events will be dropped\n", id);
ret = -1;
fe.id = id;
@ -454,7 +462,7 @@ static int dump_one_fanotify(int lfd, u32 id, const struct fd_parms *p)
if (check_one_mark(fe.mark[i]))
goto free;
pr_info("id %#08x flags %#08x\n", fe.id, fe.flags);
pr_info("fanotify id %#08x flags %#08x\n", fe.id, fe.flags);
fle.type = FD_TYPES__FANOTIFY;
fle.id = fe.id;
@ -583,8 +591,8 @@ static int restore_one_inotify(int inotify_fd, struct fsnotify_mark_info *info)
if (kdat.has_inotify_setnextwd) {
if (ioctl(inotify_fd, INOTIFY_IOC_SETNEXTWD, iwe->wd)) {
pr_perror("Can't set next inotify wd");
return -1;
pr_perror("Can't set next inotify wd (fd %#x, wd %#08x)", inotify_fd, iwe->wd);
goto err;
}
}
@ -593,18 +601,20 @@ static int restore_one_inotify(int inotify_fd, struct fsnotify_mark_info *info)
wd = inotify_add_watch(inotify_fd, path, mask);
if (wd < 0) {
pr_perror("Can't add watch for 0x%x with 0x%x", inotify_fd, iwe->wd);
break;
pr_perror("Can't add inotify watch (fd %#x, wd %#08x, mask %#x) for path %s",
inotify_fd, iwe->wd, mask, path);
goto err;
} else if (wd == iwe->wd) {
ret = 0;
break;
} else if (wd > iwe->wd) {
pr_err("Unsorted watch 0x%x found for 0x%x with 0x%x\n", wd, inotify_fd, iwe->wd);
break;
pr_err("Unsorted inotify watch (got wd %#x) while restoring expected wd %#x on fd %#x for path %s\n",
wd, iwe->wd, inotify_fd, path);
goto err;
}
if (kdat.has_inotify_setnextwd)
return -1;
goto err;
inotify_rm_watch(inotify_fd, wd);
}
@ -630,7 +640,8 @@ static int restore_one_fanotify(int fd, struct fsnotify_mark_info *mark)
if (root_ns_mask & CLONE_NEWNS) {
m = lookup_mnt_id(fme->me->mnt_id);
if (!m) {
pr_err("Can't find mount mnt_id 0x%x\n", fme->me->mnt_id);
pr_err("Can't find mount for fanotify mount mark (mnt_id %#x, path %s)\n",
fme->me->mnt_id, fme->me->path ? fme->me->path : "(null)");
return -1;
}
nsid = m->nsid;
@ -641,7 +652,8 @@ static int restore_one_fanotify(int fd, struct fsnotify_mark_info *mark)
target = openat(mntns_root, p, O_PATH);
if (target == -1) {
pr_perror("Unable to open %s", p);
pr_perror("Unable to open mount path for fanotify mount mark (mnt_id %#x, path %s)",
fme->me->mnt_id, p);
goto err;
}
@ -654,7 +666,8 @@ static int restore_one_fanotify(int fd, struct fsnotify_mark_info *mark)
if (!path)
goto err;
} else {
pr_err("Bad fsnotify mark type 0x%x\n", fme->type);
pr_err("Bad fanotify mark type %#x for mark (id %#08x, mask %#x)\n",
fme->type, fme->id, fme->mask);
goto err;
}
@ -663,7 +676,8 @@ static int restore_one_fanotify(int fd, struct fsnotify_mark_info *mark)
if (mark->fme->mask) {
ret = fanotify_mark(fd, flags, fme->mask, AT_FDCWD, path);
if (ret) {
pr_err("Adding fanotify mask 0x%x on 0x%x/%s failed (%d)\n", fme->mask, fme->id, path, ret);
pr_perror("Can't add fanotify mark (id %#08x, mask %#x) on %s", fme->id, fme->mask,
path);
goto err;
}
}
@ -671,8 +685,8 @@ static int restore_one_fanotify(int fd, struct fsnotify_mark_info *mark)
if (fme->ignored_mask) {
ret = fanotify_mark(fd, flags | FAN_MARK_IGNORED_MASK, fme->ignored_mask, AT_FDCWD, path);
if (ret) {
pr_err("Adding fanotify ignored-mask 0x%x on 0x%x/%s failed (%d)\n", fme->ignored_mask, fme->id,
path, ret);
pr_perror("Can't add fanotify ignored-mask (id %#08x, mask %#x) on %s",
fme->id, fme->ignored_mask, path);
goto err;
}
}
@ -697,12 +711,12 @@ static int open_inotify_fd(struct file_desc *d, int *new_fd)
}
list_for_each_entry(wd_info, &info->marks, list) {
pr_info("\tRestore 0x%x wd for %#08x\n", wd_info->iwe->wd, wd_info->iwe->id);
pr_info("\tinotify wd %#x for id %#08x\n", wd_info->iwe->wd, wd_info->iwe->id);
if (restore_one_inotify(tmp, wd_info)) {
close_safe(&tmp);
return -1;
}
pr_info("\t 0x%x wd for %#08x is restored\n", wd_info->iwe->wd, wd_info->iwe->id);
pr_info("\tinotify wd %#x for id %#08x done\n", wd_info->iwe->wd, wd_info->iwe->id);
}
if (restore_fown(tmp, info->ife->fown))
@ -729,12 +743,12 @@ static int open_fanotify_fd(struct file_desc *d, int *new_fd)
ret = fanotify_init(flags, info->ffe->evflags);
if (ret < 0) {
pr_perror("Can't init fanotify mark (%d)", ret);
pr_perror("Can't init fanotify for id %#08x", info->ffe->id);
return -1;
}
list_for_each_entry(mark, &info->marks, list) {
pr_info("\tRestore fanotify for %#08x\n", mark->fme->id);
pr_info("\tfanotify mark for id %#08x\n", mark->fme->id);
if (restore_one_fanotify(ret, mark)) {
close_safe(&ret);
return -1;
@ -811,7 +825,7 @@ static int collect_one_inotify(void *o, ProtobufCMessage *msg, struct cr_img *im
info->ife = pb_msg(msg, InotifyFileEntry);
INIT_LIST_HEAD(&info->marks);
pr_info("Collected id %#08x flags %#08x\n", info->ife->id, info->ife->flags);
pr_info("inotify id %#08x flags %#08x\n", info->ife->id, info->ife->flags);
for (i = 0; i < info->ife->n_wd; i++) {
struct fsnotify_mark_info *mark;
@ -845,7 +859,7 @@ static int collect_one_fanotify(void *o, ProtobufCMessage *msg, struct cr_img *i
info->ffe = pb_msg(msg, FanotifyFileEntry);
INIT_LIST_HEAD(&info->marks);
pr_info("Collected id %#08x flags %#08x\n", info->ffe->id, info->ffe->flags);
pr_info("fanotify id %#08x flags %#08x\n", info->ffe->id, info->ffe->flags);
for (i = 0; i < info->ffe->n_mark; i++) {
struct fsnotify_mark_info *mark;
@ -896,7 +910,8 @@ static int collect_one_inotify_mark(void *o, ProtobufCMessage *msg, struct cr_im
d = find_file_desc_raw(FD_TYPES__INOTIFY, mark->iwe->id);
if (!d) {
pr_err("Can't find inotify with id %#08x\n", mark->iwe->id);
pr_err("Can't find inotify fd for mark (id %#08x, wd %#08x, mask %#x)\n",
mark->iwe->id, mark->iwe->wd, mark->iwe->mask);
return -1;
}
@ -924,7 +939,8 @@ static int collect_one_fanotify_mark(void *o, ProtobufCMessage *msg, struct cr_i
d = find_file_desc_raw(FD_TYPES__FANOTIFY, mark->fme->id);
if (!d) {
pr_err("Can't find fanotify with id %#08x\n", mark->fme->id);
pr_err("Can't find fanotify fd for mark (id %#08x, type %#x, mask %#x)\n",
mark->fme->id, mark->fme->type, mark->fme->mask);
return -1;
}