From d3fdba3183636643ff9ce61481d94b3f5189239f Mon Sep 17 00:00:00 2001 From: Ankit Saurabh Date: Mon, 27 Nov 2023 10:47:00 +0000 Subject: [PATCH 1/4] Added Filename in InodeError Signed-off-by: Ankit Saurabh --- mountpoint-s3/src/fs.rs | 8 +++++++- mountpoint-s3/src/fs/error.rs | 2 +- mountpoint-s3/src/inode.rs | 14 +++++++------- mountpoint-s3/src/prefetch/part_stream.rs | 4 ++-- 4 files changed, 17 insertions(+), 11 deletions(-) diff --git a/mountpoint-s3/src/fs.rs b/mountpoint-s3/src/fs.rs index 91ed2ab13..57e1928a1 100644 --- a/mountpoint-s3/src/fs.rs +++ b/mountpoint-s3/src/fs.rs @@ -774,7 +774,13 @@ where let len = { let mut request = match &handle.typ { FileHandleType::Write(request) => request.lock().await, - FileHandleType::Read { .. } => return Err(err!(libc::EBADF, "file handle is not open for writes")), + FileHandleType::Read { .. } => { + return Err(err!( + libc::EBADF, + "file handle is not open for writes (key={:?})", + handle.full_key + )) + } }; request.write(offset, data, &handle.full_key).await? }; diff --git a/mountpoint-s3/src/fs/error.rs b/mountpoint-s3/src/fs/error.rs index 73fd10643..b9e5b46f0 100644 --- a/mountpoint-s3/src/fs/error.rs +++ b/mountpoint-s3/src/fs/error.rs @@ -111,7 +111,7 @@ impl ToErrno for InodeError { fn to_errno(&self) -> libc::c_int { match self { InodeError::ClientError(_) => libc::EIO, - InodeError::FileDoesNotExist => libc::ENOENT, + InodeError::FileDoesNotExist(_) => libc::ENOENT, InodeError::InodeDoesNotExist(_) => libc::ENOENT, InodeError::InvalidFileName(_) => libc::EINVAL, InodeError::NotADirectory(_) => libc::ENOTDIR, diff --git a/mountpoint-s3/src/inode.rs b/mountpoint-s3/src/inode.rs index 26035e51e..f4e083aae 100644 --- a/mountpoint-s3/src/inode.rs +++ b/mountpoint-s3/src/inode.rs @@ -326,7 +326,7 @@ impl Superblock { .await; match existing { Ok(lookup) => return Err(InodeError::FileAlreadyExists(lookup.inode.err())), - Err(InodeError::FileDoesNotExist) => (), + Err(InodeError::FileDoesNotExist(_)) => (), Err(e) => return Err(e), } @@ -801,7 +801,7 @@ impl SuperblockInner { InodeKindData::Directory { children, .. } => children.get(name), }; match (remote, inode) { - (None, None) => Err(InodeError::FileDoesNotExist), + (None, None) => Err(InodeError::FileDoesNotExist(name.into())), (Some(remote), Some(existing_inode)) => { let mut existing_state = existing_inode.get_mut_inode_state()?; let existing_is_remote = existing_state.write_status == WriteStatus::Remote; @@ -838,7 +838,7 @@ impl SuperblockInner { InodeKindData::Directory { children, .. } => children.get(name).cloned(), }; match (remote, inode) { - (None, None) => Err(InodeError::FileDoesNotExist), + (None, None) => Err(InodeError::FileDoesNotExist(name.into())), (None, Some(existing_inode)) => { let InodeKindData::Directory { children, @@ -868,7 +868,7 @@ impl SuperblockInner { // being written. It must have previously existed but been removed on the remote // side. children.remove(name); - Err(InodeError::FileDoesNotExist) + Err(InodeError::FileDoesNotExist(name.into())) } } (Some(remote), None) => { @@ -1485,8 +1485,8 @@ impl InodeStat { pub enum InodeError { #[error("error from ObjectClient")] ClientError(#[source] anyhow::Error), - #[error("file does not exist")] - FileDoesNotExist, + #[error("file {0:?} does not exist")] + FileDoesNotExist(OsString), #[error("inode {0} does not exist")] InodeDoesNotExist(InodeNo), #[error("invalid file name {0:?}")] @@ -2473,7 +2473,7 @@ mod tests { // All nested dirs disappear let dirname = nested_dirs.first().unwrap(); let lookedup = superblock.lookup(&client, FUSE_ROOT_INODE, dirname.as_ref()).await; - assert!(matches!(lookedup, Err(InodeError::FileDoesNotExist))); + assert!(matches!(lookedup, Err(InodeError::FileDoesNotExist(_)))); } #[tokio::test] diff --git a/mountpoint-s3/src/prefetch/part_stream.rs b/mountpoint-s3/src/prefetch/part_stream.rs index 96acb535b..5c9f3872e 100644 --- a/mountpoint-s3/src/prefetch/part_stream.rs +++ b/mountpoint-s3/src/prefetch/part_stream.rs @@ -196,7 +196,7 @@ where { Ok(get_object_result) => get_object_result, Err(e) => { - error!(error=?e, "GetObject request failed"); + error!(key, error=?e, "GetObject request failed"); part_queue_producer.push(Err(PrefetchReadError::GetRequestFailed(e))); return; } @@ -227,7 +227,7 @@ where } } Some(Err(e)) => { - error!(error=?e, "GetObject body part failed"); + error!(key, error=?e, "GetObject body part failed"); part_queue_producer.push(Err(PrefetchReadError::GetRequestFailed(e))); break; } From abc4a387150e0346967018128c42c71130efadec Mon Sep 17 00:00:00 2001 From: Ankit Saurabh Date: Tue, 28 Nov 2023 15:03:21 +0000 Subject: [PATCH 2/4] Added filename in lookup path error logs Signed-off-by: Ankit Saurabh --- mountpoint-s3/src/fs/error.rs | 1 + mountpoint-s3/src/inode.rs | 10 ++++++---- 2 files changed, 7 insertions(+), 4 deletions(-) diff --git a/mountpoint-s3/src/fs/error.rs b/mountpoint-s3/src/fs/error.rs index b9e5b46f0..dfe81aa87 100644 --- a/mountpoint-s3/src/fs/error.rs +++ b/mountpoint-s3/src/fs/error.rs @@ -112,6 +112,7 @@ impl ToErrno for InodeError { match self { InodeError::ClientError(_) => libc::EIO, InodeError::FileDoesNotExist(_) => libc::ENOENT, + InodeError::DirectoryDoesNotExist(_) => libc::ENOENT, InodeError::InodeDoesNotExist(_) => libc::ENOENT, InodeError::InvalidFileName(_) => libc::EINVAL, InodeError::NotADirectory(_) => libc::ENOTDIR, diff --git a/mountpoint-s3/src/inode.rs b/mountpoint-s3/src/inode.rs index f4e083aae..c4643df49 100644 --- a/mountpoint-s3/src/inode.rs +++ b/mountpoint-s3/src/inode.rs @@ -697,12 +697,12 @@ impl SuperblockInner { } // If the object is not found, might be a directory, so keep going Err(ObjectClientError::ServiceError(HeadObjectError::NotFound)) => {}, - Err(e) => return Err(InodeError::ClientError(anyhow!(e).context("HeadObject failed"))), + Err(e) => return Err(InodeError::ClientError(anyhow!(e).context(format!("HeadObject failed for {}", &full_path)))), } } result = dir_lookup => { - let result = result.map_err(|e| InodeError::ClientError(anyhow!(e).context("ListObjectsV2 failed")))?; + let result = result.map_err(|e| InodeError::ClientError(anyhow!(e).context(format!("ListObjectsV2 failed for {}", &full_path))))?; let found_directory = if result .common_prefixes @@ -1239,7 +1239,7 @@ impl Inode { fn get_inode_state(&self) -> Result, InodeError> { let inode_state = self.inner.sync.read().unwrap(); match &inode_state.kind_data { - InodeKindData::Directory { deleted, .. } if *deleted => Err(InodeError::InodeDoesNotExist(self.ino())), + InodeKindData::Directory { deleted, .. } if *deleted => Err(InodeError::DirectoryDoesNotExist(self.err())), _ => Ok(inode_state), } } @@ -1248,7 +1248,7 @@ impl Inode { fn get_mut_inode_state(&self) -> Result, InodeError> { let inode_state = self.inner.sync.write().unwrap(); match &inode_state.kind_data { - InodeKindData::Directory { deleted, .. } if *deleted => Err(InodeError::InodeDoesNotExist(self.ino())), + InodeKindData::Directory { deleted, .. } if *deleted => Err(InodeError::DirectoryDoesNotExist(self.err())), _ => Ok(inode_state), } } @@ -1487,6 +1487,8 @@ pub enum InodeError { ClientError(#[source] anyhow::Error), #[error("file {0:?} does not exist")] FileDoesNotExist(OsString), + #[error("directory does not exist at inode {0}")] + DirectoryDoesNotExist(InodeErrorInfo), #[error("inode {0} does not exist")] InodeDoesNotExist(InodeNo), #[error("invalid file name {0:?}")] From 264132b28078a1436c2ad3d93252e862afa4bfe3 Mon Sep 17 00:00:00 2001 From: Ankit Saurabh Date: Thu, 30 Nov 2023 01:39:27 +0000 Subject: [PATCH 3/4] Added all the error loggings with filename/object key wherever possible Signed-off-by: Ankit Saurabh --- mountpoint-s3/src/fs.rs | 31 +++++++++++++++++++++---------- mountpoint-s3/src/fuse.rs | 4 ++-- mountpoint-s3/src/upload.rs | 20 ++++++++++++++------ 3 files changed, 37 insertions(+), 18 deletions(-) diff --git a/mountpoint-s3/src/fs.rs b/mountpoint-s3/src/fs.rs index 57e1928a1..4bb8d182a 100644 --- a/mountpoint-s3/src/fs.rs +++ b/mountpoint-s3/src/fs.rs @@ -112,7 +112,7 @@ where let key = lookup.inode.full_key(); let handle = match fs.uploader.put(&fs.bucket, key).await { Err(e) => { - return Err(err!(libc::EIO, source:e, "put failed to start")); + return Err(err!(libc::EIO, source:e, "put failed to start (key={})", lookup.inode.full_key())); } Ok(request) => FileHandleType::Write(UploadState::InProgress { request, handle }.into()), }; @@ -124,14 +124,22 @@ where if !lookup.stat.is_readable { return Err(err!( libc::EACCES, - "objects in flexible retrieval storage classes are not accessible", + "objects in flexible retrieval storage classes are not accessible (key={})", + lookup.inode.full_key(), )); } lookup.inode.start_reading()?; let handle = FileHandleType::Read { request: Default::default(), etag: match &lookup.stat.etag { - None => return Err(err!(libc::EBADF, "no E-Tag for inode {}", lookup.inode.ino())), + None => { + return Err(err!( + libc::EBADF, + "no E-Tag for inode {} (key={})", + lookup.inode.ino(), + lookup.inode.full_key() + )) + } Some(etag) => ETag::from_str(etag).expect("E-Tag should be set"), }, }; @@ -227,11 +235,11 @@ impl UploadState { debug!(key, size, "put succeeded"); Ok(()) } - Err(e) => Err(err!(libc::EIO, source:e, "put failed")), + Err(e) => Err(err!(libc::EIO, source:e, "put failed (key={:?})", key)), }; if let Err(err) = handle.finish_writing() { // Log the issue but still return put_result. - error!(?err, "error updating the inode status"); + error!(?err, "error updating the inode status (key={:?})", key); } put_result } @@ -688,16 +696,18 @@ where match request.as_mut().unwrap().read(offset as u64, size as usize).await { Ok(checksummed_bytes) => match checksummed_bytes.into_bytes() { Ok(bytes) => reply.data(&bytes), - Err(e) => reply.error(err!(libc::EIO, source:e, "integrity error")), + Err(e) => reply.error(err!(libc::EIO, source:e, "integrity error(key={:?})", handle.full_key)), }, Err(PrefetchReadError::GetRequestFailed(ObjectClientError::ServiceError( GetObjectError::PreconditionFailed, ))) => reply.error(err!(libc::ESTALE, "object was mutated remotely")), - Err(PrefetchReadError::Integrity(e)) => reply.error(err!(libc::EIO, source:e, "integrity error")), + Err(PrefetchReadError::Integrity(e)) => { + reply.error(err!(libc::EIO, source:e, "integrity error(key={:?})", handle.full_key)) + } Err(e @ PrefetchReadError::GetRequestFailed(_)) | Err(e @ PrefetchReadError::GetRequestTerminatedUnexpectedly) | Err(e @ PrefetchReadError::GetRequestReturnedWrongOffset { .. }) => { - reply.error(err!(libc::EIO, source:e, "get request failed")) + reply.error(err!(libc::EIO, source:e, "get request failed(key={:?})", handle.full_key)) } } } @@ -713,8 +723,9 @@ where if mode & libc::S_IFMT != libc::S_IFREG { return Err(err!( libc::EINVAL, - "invalid mknod type {}; only regular files are supported", - mode & libc::S_IFMT + "invalid mknod type {}; only regular files are supported (filename={:?})", + mode & libc::S_IFMT, + name )); } diff --git a/mountpoint-s3/src/fuse.rs b/mountpoint-s3/src/fuse.rs index 324e32e75..15c1d97ad 100644 --- a/mountpoint-s3/src/fuse.rs +++ b/mountpoint-s3/src/fuse.rs @@ -6,7 +6,7 @@ use std::ffi::OsStr; use std::path::Path; use std::time::SystemTime; use time::OffsetDateTime; -use tracing::{instrument, Instrument}; +use tracing::{field, instrument, Instrument}; use crate::fs::{ self, DirectoryEntry, DirectoryReplier, InodeNo, ReadReplier, S3Filesystem, S3FilesystemConfig, ToErrno, @@ -322,7 +322,7 @@ where } } - #[instrument(level="warn", skip_all, fields(req=_req.unique(), ino=ino, fh=fh, offset=offset, length=data.len(), pid=_req.pid()))] + #[instrument(level="warn", skip_all, fields(req=_req.unique(), ino=ino, fh=fh, offset=offset, length=data.len(), pid=_req.pid(), key=field::Empty))] fn write( &self, _req: &Request<'_>, diff --git a/mountpoint-s3/src/upload.rs b/mountpoint-s3/src/upload.rs index 0dc8ed7d5..9e4b1dc46 100644 --- a/mountpoint-s3/src/upload.rs +++ b/mountpoint-s3/src/upload.rs @@ -49,11 +49,15 @@ pub enum UploadWriteError { #[error("put request failed")] PutRequestFailed(#[from] E), - #[error("out of order write; expected offset {expected_offset:?} but got {write_offset:?}")] - OutOfOrderWrite { write_offset: u64, expected_offset: u64 }, - - #[error("object exceeded maximum upload size of {maximum_size} bytes")] - ObjectTooBig { maximum_size: usize }, + #[error("out of order write for {key:?}; expected offset {expected_offset:?} but got {write_offset:?}")] + OutOfOrderWrite { + key: String, + write_offset: u64, + expected_offset: u64, + }, + + #[error("object {key:?} exceeded maximum upload size of {maximum_size} bytes")] + ObjectTooBig { key: String, maximum_size: usize }, } /// Manages the upload of an object to S3. @@ -105,13 +109,17 @@ impl UploadRequest { let next_offset = self.next_request_offset; if offset != next_offset as i64 { return Err(UploadWriteError::OutOfOrderWrite { + key: self.key.clone(), write_offset: offset as u64, expected_offset: next_offset, }); } if let Some(maximum_size) = self.maximum_upload_size { if next_offset + data.len() as u64 > maximum_size as u64 { - return Err(UploadWriteError::ObjectTooBig { maximum_size }); + return Err(UploadWriteError::ObjectTooBig { + key: self.key.clone(), + maximum_size, + }); } } From 266d93bd40284fd150d61eef9cd093b90c83d240 Mon Sep 17 00:00:00 2001 From: Ankit Saurabh Date: Thu, 30 Nov 2023 02:53:36 +0000 Subject: [PATCH 4/4] Removed empty key from span Signed-off-by: Ankit Saurabh --- mountpoint-s3/src/fuse.rs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/mountpoint-s3/src/fuse.rs b/mountpoint-s3/src/fuse.rs index 15c1d97ad..324e32e75 100644 --- a/mountpoint-s3/src/fuse.rs +++ b/mountpoint-s3/src/fuse.rs @@ -6,7 +6,7 @@ use std::ffi::OsStr; use std::path::Path; use std::time::SystemTime; use time::OffsetDateTime; -use tracing::{field, instrument, Instrument}; +use tracing::{instrument, Instrument}; use crate::fs::{ self, DirectoryEntry, DirectoryReplier, InodeNo, ReadReplier, S3Filesystem, S3FilesystemConfig, ToErrno, @@ -322,7 +322,7 @@ where } } - #[instrument(level="warn", skip_all, fields(req=_req.unique(), ino=ino, fh=fh, offset=offset, length=data.len(), pid=_req.pid(), key=field::Empty))] + #[instrument(level="warn", skip_all, fields(req=_req.unique(), ino=ino, fh=fh, offset=offset, length=data.len(), pid=_req.pid()))] fn write( &self, _req: &Request<'_>,