diff --git a/Cargo.lock b/Cargo.lock index d27d206..bef3ba5 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -8,6 +8,15 @@ version = "2.0.1" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "320119579fcad9c21884f5c4861d16174d0e06250625266f50fe6898340abefa" +[[package]] +name = "aho-corasick" +version = "1.1.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ddd31a130427c27518df266943a5308ed92d4b226cc639f5a8f1002816174301" +dependencies = [ + "memchr", +] + [[package]] name = "alloc-no-stdlib" version = "2.0.4" @@ -93,6 +102,15 @@ dependencies = [ "generic-array", ] +[[package]] +name = "block2" +version = "0.6.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "cdeb9d870516001442e364c5220d3574d2da8dc765554b4a617230d33fa58ef5" +dependencies = [ + "objc2", +] + [[package]] name = "brotli" version = "8.0.2" @@ -224,6 +242,17 @@ dependencies = [ "typenum", ] +[[package]] +name = "ctrlc" +version = "3.5.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "e0b1fab2ae45819af2d0731d60f2afe17227ebb1a1538a236da84c93e9a60162" +dependencies = [ + "dispatch2", + "nix 0.31.2", + "windows-sys 0.61.2", +] + [[package]] name = "deranged" version = "0.5.8" @@ -244,6 +273,18 @@ dependencies = [ "subtle", ] +[[package]] +name = "dispatch2" +version = "0.3.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1e0e367e4e7da84520dedcac1901e4da967309406d1e51017ae1abfb97adbd38" +dependencies = [ + "bitflags", + "block2", + "libc", + "objc2", +] + [[package]] name = "displaydoc" version = "0.2.5" @@ -308,7 +349,7 @@ dependencies = [ "libc", "log", "memchr", - "nix", + "nix 0.30.1", "num_enum", "page_size", "parking_lot", @@ -738,6 +779,12 @@ dependencies = [ "libc", ] +[[package]] +name = "lazy_static" +version = "1.5.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "bbd2bcb4c963f2ddae06a2efc7e9f3591312473c50c6685e1f298068316e66fe" + [[package]] name = "leb128fmt" version = "0.1.0" @@ -771,6 +818,15 @@ version = "0.4.29" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "5e5032e24019045c762d3c0f28f5b6b8bbf38563a65908389bf7978758920897" +[[package]] +name = "matchers" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d1525a2a28c7f4fa0fc98bb91ae755d1e2d1505079e05539e35bc876b5d65ae9" +dependencies = [ + "regex-automata", +] + [[package]] name = "md-5" version = "0.10.6" @@ -836,6 +892,27 @@ dependencies = [ "memoffset", ] +[[package]] +name = "nix" +version = "0.31.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "5d6d0705320c1e6ba1d912b5e37cf18071b6c2e9b7fa8215a1e8a7651966f5d3" +dependencies = [ + "bitflags", + "cfg-if", + "cfg_aliases", + "libc", +] + +[[package]] +name = "nu-ansi-term" +version = "0.50.3" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "7957b9740744892f114936ab4a57b3f487491bbeafaf8083688b16841a4240e5" +dependencies = [ + "windows-sys 0.61.2", +] + [[package]] name = "num-conv" version = "0.2.0" @@ -864,6 +941,21 @@ dependencies = [ "syn", ] +[[package]] +name = "objc2" +version = "0.6.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "3a12a8ed07aefc768292f076dc3ac8c48f3781c8f2d5851dd3d98950e8c5a89f" +dependencies = [ + "objc2-encode", +] + +[[package]] +name = "objc2-encode" +version = "4.1.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ef25abbcd74fb2609453eb695bd2f860d389e457f67dc17cafc8b8cbc89d0c33" + [[package]] name = "once_cell" version = "1.21.3" @@ -1053,6 +1145,23 @@ dependencies = [ "syn", ] +[[package]] +name = "regex-automata" +version = "0.4.14" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "6e1dd4122fc1595e8162618945476892eefca7b88c52820e74af6262213cae8f" +dependencies = [ + "aho-corasick", + "memchr", + "regex-syntax", +] + +[[package]] +name = "regex-syntax" +version = "0.8.10" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "dc897dd8d9e8bd1ed8cdad82b5966c3e0ecae09fb1907d58efaa013543185d0a" + [[package]] name = "reqx" version = "0.1.27" @@ -1334,6 +1443,15 @@ dependencies = [ "digest", ] +[[package]] +name = "sharded-slab" +version = "0.1.7" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f40ca3c46823713e0d4209592e8d6e826aa57e928f09752619fc696c499637f6" +dependencies = [ + "lazy_static", +] + [[package]] name = "shlex" version = "1.3.0" @@ -1385,9 +1503,12 @@ name = "swfss3" version = "0.1.0" dependencies = [ "argh", + "ctrlc", "fuser", "libc", "s3", + "tracing", + "tracing-subscriber", ] [[package]] @@ -1452,6 +1573,15 @@ dependencies = [ "syn", ] +[[package]] +name = "thread_local" +version = "1.1.9" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f60246a4944f24f6e018aa17cdeffb7818b76356965d03b07d6a9886e8962185" +dependencies = [ + "cfg-if", +] + [[package]] name = "time" version = "0.3.47" @@ -1606,6 +1736,36 @@ source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "db97caf9d906fbde555dd62fa95ddba9eecfd14cb388e4f491a66d74cd5fb79a" dependencies = [ "once_cell", + "valuable", +] + +[[package]] +name = "tracing-log" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ee855f1f400bd0e5c02d150ae5de3840039a3f54b025156404e34c23c03f47c3" +dependencies = [ + "log", + "once_cell", + "tracing-core", +] + +[[package]] +name = "tracing-subscriber" +version = "0.3.22" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "2f30143827ddab0d256fd843b7a66d164e9f271cfa0dde49142c5ca0ca291f1e" +dependencies = [ + "matchers", + "nu-ansi-term", + "once_cell", + "regex-automata", + "sharded-slab", + "smallvec", + "thread_local", + "tracing", + "tracing-core", + "tracing-log", ] [[package]] @@ -1691,6 +1851,12 @@ version = "1.0.4" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "b6c140620e7ffbb22c2dee59cafe6084a59b5ffc27a8859a5f0d494b5d52b6be" +[[package]] +name = "valuable" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "ba73ea9cf16a25df0c8caa16c51acb937d5712a8429db78a3ee29d5dcacd3a65" + [[package]] name = "version_check" version = "0.9.5" diff --git a/Cargo.toml b/Cargo.toml index 5a0f69e..4c083c4 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -4,7 +4,10 @@ version = "0.1.0" edition = "2024" [dependencies] -argh = "0.1.13" -fuser = "0.17.0" -libc = "0.2.183" -s3 = { version = "0.1.22", features = ["blocking", "rustls"] } +argh = "^0" +fuser = "^0" +libc = "^0" +s3 = { version = "^0", features = ["blocking", "rustls"] } +tracing = "0.1.41" +tracing-subscriber = { version = "0.3.20", features = ["env-filter"] } +ctrlc = "^3" diff --git a/src/fuse_mount.rs b/src/fuse_mount.rs index 52e2cbf..e6610c1 100644 --- a/src/fuse_mount.rs +++ b/src/fuse_mount.rs @@ -5,7 +5,9 @@ use std::{ ffi::OsStr, io::Cursor, path::Path, - sync::{Arc, Mutex}, + sync::atomic::{AtomicBool, Ordering}, + sync::{Arc, Mutex, Once}, + thread, time::{Duration, SystemTime}, }; @@ -20,6 +22,22 @@ use crate::vfs::{ObjectStat, VfsError, VirtualFilesystem}; const ROOT_INO: u64 = 1; const TTL: Duration = Duration::from_secs(1); +static LOG_INIT: Once = Once::new(); + +fn init_logging() { + LOG_INIT.call_once(|| { + // Opt-in via RUST_LOG, otherwise default to fuse debug logs. + // Example: RUST_LOG=swfss3=debug,fuser=info + let env_filter = tracing_subscriber::EnvFilter::try_from_default_env() + .unwrap_or_else(|_| tracing_subscriber::EnvFilter::new("swfss3=debug")); + tracing_subscriber::fmt() + .with_env_filter(env_filter) + .with_target(true) + .without_time() + .init(); + }); +} + #[derive(Debug, Clone)] enum NodeKind { Dir, @@ -75,6 +93,27 @@ pub fn mount_bucket( read_write: bool, allow_other: bool, ) -> Result<(), VfsError> { + init_logging(); + + // If a previous FUSE mount crashed, the mountpoint may be left in a stale state where + // any access returns ENOTCONN ("Transport endpoint is not connected"). + // Fail fast with a clear message instead of returning the raw OS error from mount2. + if mountpoint.exists() { + if let Err(e) = std::fs::read_dir(mountpoint) { + if e.raw_os_error() == Some(libc::ENOTCONN) { + return Err(VfsError::Io(std::io::Error::new( + std::io::ErrorKind::Other, + format!( + "mountpoint {} is a stale FUSE mount (Transport endpoint is not connected). Unmount it first (e.g. `fusermount3 -u {}` or `umount -l {}`)", + mountpoint.display(), + mountpoint.display(), + mountpoint.display() + ), + ))); + } + } + } + let prefix = normalize_prefix(base_prefix); let fs = S3FuseFs::new(vfs, prefix, read_write); @@ -95,7 +134,39 @@ pub fn mount_bucket( cfg.acl = fuser::SessionACL::All; } - fuser::mount2(fs, mountpoint, &cfg).map_err(VfsError::Io)?; + tracing::info!( + mountpoint = %mountpoint.display(), + prefix = %base_prefix, + read_write, + allow_other, + "mounting fuse filesystem" + ); + + // Run in background so we can intercept Ctrl+C and unmount cleanly. + let session = fuser::spawn_mount2(fs, mountpoint, &cfg).map_err(VfsError::Io)?; + + let stop = Arc::new(AtomicBool::new(false)); + { + let stop = Arc::clone(&stop); + ctrlc::set_handler(move || { + stop.store(true, Ordering::SeqCst); + }) + .map_err(|e| VfsError::Io(std::io::Error::new(std::io::ErrorKind::Other, e)))?; + } + + // Wait until Ctrl+C or until unmounted externally. + while !stop.load(Ordering::SeqCst) && !session.guard.is_finished() { + thread::sleep(Duration::from_millis(100)); + } + + if stop.load(Ordering::SeqCst) { + tracing::info!("received Ctrl+C, unmounting"); + session.umount_and_join().map_err(VfsError::Io)?; + return Ok(()); + } + + tracing::info!("filesystem session ended, joining"); + session.join().map_err(VfsError::Io)?; Ok(()) } @@ -326,6 +397,7 @@ impl S3FuseFs { impl Filesystem for S3FuseFs { fn getattr(&self, _req: &Request, ino: INodeNo, _fh: Option, reply: ReplyAttr) { let ino: u64 = ino.into(); + tracing::debug!(ino, "getattr"); let Some(node) = self.get_node(ino) else { reply.error(Errno::ENOENT); return; @@ -351,10 +423,14 @@ impl Filesystem for S3FuseFs { reply.error(Errno::ENOENT); return; }; + tracing::debug!(parent, name = %name, "lookup"); match self.resolve_on_demand(parent, name) { Ok(Some(node)) => reply.entry(&TTL, &self.node_attr(&node), Generation(0)), Ok(None) => reply.error(Errno::ENOENT), - Err(_) => reply.error(Errno::EIO), + Err(e) => { + tracing::warn!(parent, name = %name, err = %e, "lookup failed"); + reply.error(Errno::EIO) + } } } @@ -367,6 +443,7 @@ impl Filesystem for S3FuseFs { mut reply: ReplyDirectory, ) { let ino: u64 = ino.into(); + tracing::debug!(ino, offset, "readdir"); let Some(node) = self.get_node(ino) else { reply.error(Errno::ENOENT); return; @@ -380,6 +457,7 @@ impl Filesystem for S3FuseFs { let page = match self.vfs.list_page(&dir_prefix_key, false, None) { Ok(p) => p, Err(_) => { + tracing::warn!(ino, key = %dir_prefix_key, "readdir list failed"); reply.error(Errno::EIO); return; } @@ -444,6 +522,7 @@ impl Filesystem for S3FuseFs { fn open(&self, _req: &Request, ino: INodeNo, flags: OpenFlags, reply: ReplyOpen) { let ino: u64 = ino.into(); + tracing::debug!(ino, flags = %format_args!("{:#x}", flags), "open"); let Some(node) = self.get_node(ino) else { reply.error(Errno::ENOENT); return; @@ -507,6 +586,7 @@ impl Filesystem for S3FuseFs { reply: ReplyData, ) { let ino: u64 = ino.into(); + tracing::debug!(ino, offset, size, "read"); let Some(node) = self.get_node(ino) else { reply.error(Errno::ENOENT); return; @@ -517,7 +597,10 @@ impl Filesystem for S3FuseFs { }; match self.read_object_range(&key, offset as i64, size) { Ok(bytes) => reply.data(&bytes), - Err(_) => reply.error(Errno::EIO), + Err(e) => { + tracing::warn!(ino, key = %key, offset, size, err = %e, "read failed"); + reply.error(Errno::EIO) + } } } @@ -540,6 +623,7 @@ impl Filesystem for S3FuseFs { reply.error(Errno::EINVAL); return; }; + tracing::debug!(parent, name = %name, flags = %format_args!("{:#x}", flags), "create"); let Some(parent_node) = self.get_node(parent) else { reply.error(Errno::ENOENT); return; @@ -612,6 +696,7 @@ impl Filesystem for S3FuseFs { return; } let fh = fh.0; + tracing::debug!(fh, offset, size = data.len(), "write"); let mut st = self.state.lock().unwrap(); let Some(of) = st.open_files.get_mut(&fh) else { reply.error(Errno::EBADF); @@ -633,6 +718,7 @@ impl Filesystem for S3FuseFs { return; } let fh = fh.0; + tracing::debug!(fh, "flush"); let mut st = self.state.lock().unwrap(); let Some(of) = st.open_files.get_mut(&fh) else { reply.error(Errno::EBADF); @@ -651,6 +737,7 @@ impl Filesystem for S3FuseFs { .vfs .write_from_reader(&key, len, Box::new(cur), None) { + tracing::warn!(fh, key = %key, len, "flush upload failed"); reply.error(Errno::EIO); return; } @@ -672,6 +759,7 @@ impl Filesystem for S3FuseFs { _flush: bool, reply: ReplyEmpty, ) { + tracing::debug!(fh = fh.0, "release"); let mut st = self.state.lock().unwrap(); st.open_files.remove(&fh.0); reply.ok(); @@ -687,6 +775,7 @@ impl Filesystem for S3FuseFs { reply.error(Errno::EINVAL); return; }; + tracing::debug!(parent, name = %name, "unlink"); let Some(node) = self.lookup_child(parent, name) else { reply.error(Errno::ENOENT); return; @@ -696,6 +785,7 @@ impl Filesystem for S3FuseFs { return; }; if let Err(_) = self.vfs.delete(&key) { + tracing::warn!(parent, name = %name, key = %key, "unlink delete failed"); reply.error(Errno::EIO); return; } @@ -723,6 +813,7 @@ impl Filesystem for S3FuseFs { }; let parent: u64 = parent.into(); let newparent: u64 = newparent.into(); + tracing::debug!(parent, name = %name, newparent, newname = %newname, "rename"); let Some(node) = self.lookup_child(parent, name) else { reply.error(Errno::ENOENT); return; @@ -747,6 +838,15 @@ impl Filesystem for S3FuseFs { let dst_key = join_key(&self.prefix, &new_path); if let Err(_) = self.vfs.copy(&src_key, &dst_key).and_then(|_| self.vfs.delete(&src_key)) { + tracing::warn!( + parent, + name = %name, + newparent, + newname = %newname, + src_key = %src_key, + dst_key = %dst_key, + "rename copy+delete failed" + ); reply.error(Errno::EIO); return; }