JuiceFS 故障诊断与性能分析方法从客户端日志、访问日志到 profile、stats 与 pprof 的完整排查指南【免费下载链接】juicefsJuiceFS is a distributed POSIX file system built on top of Redis and S3.项目地址: https://gitcode.com/GitHub_Trending/ju/juicefs导读本文基于 JuiceFS 官方文档《问题排查方法》展开系统介绍 JuiceFS 挂载点、Kubernetes CSI 驱动、S3 网关、Hadoop Java SDK 四类客户端的日志与访问日志获取方式并深入讲解juicefs debug一键信息收集、juicefs profile/juicefs stats实时性能监控以及基于 pprof 的运行时剖析含 Pyroscope 持续剖析集成。读完本文你将掌握从日志定位问题到性能可视化分析再到运行时 Profiling的完整故障诊断链路并能结合仓库源码理解各指标的真实含义与底层实现。一、客户端日志故障诊断的第一现场JuiceFS 客户端在运行过程中会持续输出日志用于故障诊断。日志等级从低到高依次为DEBUG、INFO、WARNING、ERROR、FATAL默认只输出 INFO 级别及以上的日志。如果需要输出 DEBUG 级别日志需要在运行 JuiceFS 客户端时显式开启例如加上--debug选项。从源码看日志等级的管理位于 pkg/utils/logger.go其中SetLogLevel会同步设置所有 logger 的等级ERROR/FATAL/Panic 级别会输出到 stderrWarn 级别输出WARNINGInfo 级别输出INFO其余则属于 DEBUG 级别。这就是访问日志示例中ERROR这类标签的来源。不同 JuiceFS 客户端获取日志的方式不同以下分别介绍。1.1 挂载点Mount Point当挂载 JuiceFS 文件系统时加上-d选项表示后台运行即 daemon 模式日志会同时输出到系统日志和本地日志文件。取决于挂载文件系统时的运行用户本地日志文件的路径稍有区别运行用户本地日志文件路径root/var/log/juicefs.log非 root$HOME/.juicefs/juicefs.log具体的日志路径由--log选项控制可参考 mount 命令参考。取决于操作系统可以通过不同命令获取系统日志或直接读取本地日志文件# 方式一直接读取本地日志文件通用 tail -n 100 /var/log/juicefs.log # 方式二macOS 系统日志 syslog | grep juicefs # 方式三Debian 系系统日志 cat /var/log/syslog | grep juicefs # 方式四CentOS/RHEL 系系统日志 cat /var/log/messages | grep juicefs可以使用grep过滤不同等级的日志从而进行性能统计和故障追踪例如只查看 ERROR 级别的日志cat /var/log/syslog | grep juicefs | grep ERROR1.2 Kubernetes CSI 驱动根据你使用的 JuiceFS CSI 驱动版本获取日志的方式有所不同部分版本需要在mount pod内查看日志部分版本需要查看CSI 驱动 pod的日志具体取决于驱动版本与部署形态动态/静态供给。可参考 CSI 驱动的官方故障排查文档部署相关文档可帮助确认 CSI 驱动部署架构。1.3 S3 网关S3 网关juicefs gateway仅支持在前台运行因此客户端日志会直接输出到终端。如果是在 Kubernetes 中部署 S3 网关则需要查看对应 pod 的日志如kubectl logs gateway-pod。1.4 Hadoop Java SDK使用 JuiceFS Hadoop Java SDK 的应用进程如 Spark executor的日志中会包含 JuiceFS 客户端日志。由于这些日志和应用自身产生的日志混杂在一起需要通过特定关键词来过滤筛选例如juicefs注意大小写不敏感。二、文件系统访问日志Access Log2.1 日志格式每个 JuiceFS 客户端都有一个访问日志其中详细记录了文件系统上的所有操作如操作类型、用户 ID、用户组 ID、文件 inode 及其花费的时间。访问日志的用途非常广泛性能分析、审计、故障诊断。访问日志的示例格式如下2021.01.15 08:26:11.003330 [uid:0,gid:0,pid:4403] write (17669,8666,4993160): OK 0.000010每一列的含义为字段含义2021.01.15 08:26:11.003330当前操作的时间精确到微秒[uid:0,gid:0,pid:4403]当前操作的用户 ID、用户组 ID、进程 IDwrite操作类型(17669,8666,4993160)操作类型的输入参数例如write的参数分别是写入文件的 inode、写入数据大小、写入文件的偏移OK当前操作是否成功如果不成功会输出具体的失败信息0.000010当前操作花费的时间单位秒源码级解读这条日志是怎么生成的访问日志的行格式定义在 pkg/vfs/accesslog.go 的logit函数中核心代码如下cmd : fmt.Sprintf(method format, args...) t : utils.Now() ts : t.Format(2006.01.02 15:04:05.000000) cmd fmt.Sprintf( - %s %.6f, strerr(err), used.Seconds()) if ctx.Pid() ! 0 used time.Second*10 { logger.Infof(slow operation: %s, cmd) } line : []byte(fmt.Sprintf(%s [uid:%d,gid:%d,pid:%d] %s\n, ts, ctx.Uid(), ctx.Gid(), ctx.Pid(), cmd))从源码可以得出两个重要的额外信息慢操作自动告警任何操作如果耗时超过 10 秒used time.Second*10且存在进程上下文会自动以slow operation: ...的形式写入客户端主日志即使你没有开启 DEBUG 级别也能看到。这为定位卡死类问题提供了捷径。缓冲机制访问日志通过内存管道buffer: make(chan []byte, 10240)即最多缓存 10240 行分发给读取者若读取方消费不及时新日志会被丢弃default:分支保证访问日志的读取不会阻塞文件系统主流程。每种操作的具体参数格式定义在 pkg/vfs/vfs.go 中例如lookup (parent,name):entry— 目录项查找getattr (inode):entry— 获取属性read (inode,size,off,fh): (n)— 读操作参数为 inode、读取大小、偏移、文件句柄结果为实际读取字节数write (inode,size,off,fh)— 写操作参数为 inode、写入大小、偏移、文件句柄rename (parent,name,newparent,newname,flags)— 重命名flush (inode,fh,lockOwner)— 刷盘fsync (inode,datasync)— 数据同步需要指出的是访问日志量很大直接阅读难以把握系统性能全貌推荐使用juicefs profile直接基于日志做性能可视化分析。2.2 挂载点通过虚拟文件.accesslog读取在 JuiceFS 文件系统挂载点的根目录中有一个名为.accesslog的虚拟文件通过cat命令可以持续查看其中的内容命令不会退出Ctrl-C 停止。例如假设挂载点根目录为/jfscat /jfs/.accesslog2021.01.15 08:26:11.003330 [uid:0,gid:0,pid:4403] write (17669,8666,4993160): OK 0.000010 2021.01.15 08:26:11.003473 [uid:0,gid:0,pid:4403] write (17675,198,997439): OK 0.000014 2021.01.15 08:26:11.003616 [uid:0,gid:0,pid:4403] write (17666,390,951582): OK 0.000006在挂载点目录下还存在.config客户端配置含 pprof 端口信息与.statsPrometheus 格式监控数据等虚拟文件分别用于后续 debug 收集与 stats 监控。2.3 Kubernetes CSI 驱动找到 mount pod 或 CSI 驱动 pod取决于 CSI 驱动版本在 pod 内的 JuiceFS 文件系统挂载点根目录查看.accesslog文件即可。Pod 内的挂载点路径为/jfs/pv_volumeHandle。假设 mount pod 名称是juicefs-1.2.3.4-pvc-d4b8fb4f-2c0b-48e8-a2dc-530799435373pv_volumeHandle为pvc-d4b8fb4f-2c0b-48e8-a2dc-530799435373可使用如下命令查看kubectl -n kube-system exec juicefs-1.2.3.4-pvc-d4b8fb4f-2c0b-48e8-a2dc-530799435373 -- cat /jfs/pvc-d4b8fb4f-2c0b-48e8-a2dc-530799435373/.accesslog2.4 S3 网关--access-log选项S3 网关默认不输出访问日志需要在启动网关时新增--access-log选项指定访问日志输出的路径例如juicefs gateway --access-log /var/log/juicefs.accesslog redis://localhost /tmp/jfs该选项在 cmd/gateway.go 中定义--access-log并被写入vfsConf.AccessLog用于控制访问日志的输出位置详见 gateway 命令参考。2.5 Hadoop Java SDKjuicefs.access-log配置项在 JuiceFS Hadoop Java SDK 的客户端配置中新增juicefs.access-log配置项指定访问日志输出的路径默认同样不输出访问日志。具体配置方式可参考 Hadoop Java SDK 部署文档 中的其它配置一节。三、juicefs debug一键收集诊断信息juicefs debug子命令可以自动搜集指定挂载点的各类信息方便进行故障诊断juicefs debug mountpoint3.1 收集的信息清单该命令会收集以下信息JuiceFS version操作系统版本与内核版本JuiceFS.config内部文件内容JuiceFS.stats内部文件的内容并在 5 秒后再记录一次mount 命令行参数Go pprofGoroutine、CPU、内存、trace 等JuiceFS 日志默认最后 5000 行3.2 输出目录结构默认会在当前目录下创建debug目录并将收集到的信息保存在该目录下同时自动打包为 zip。下面是一个示例$ juicefs debug /tmp/mountpoint $ tree ./debug ./debug ├── tmp-test1-20230609104324 │ ├── config.txt │ ├── juicefs.log │ ├── pprof │ │ ├── juicefs.allocs.pb.gz │ │ ├── juicefs.block.pb.gz │ │ ├── juicefs.cmdline.txt │ │ ├── juicefs.goroutine.pb.gz │ │ ├── juicefs.goroutine.stack.txt │ │ ├── juicefs.heap.pb.gz │ │ ├── juicefs.mutex.pb.gz │ │ ├── juicefs.profile.30s.pb.gz │ │ ├── juicefs.threadcreate.pb.gz │ │ └── juicefs.trace.5s.pb.gz │ ├── stats.5s.txt │ ├── stats.txt │ └── system-info.log └── tmp-test1-20230609104324.zip3.3 源码级实现细节可用参数debug命令实现在 cmd/debug.go 中它提供以下可调参数比文档示例更丰富参数默认值作用--out-dir./debug当前目录下 debug 目录结果文件输出目录--limit5000收集日志的最后 N 行--stats-sec5.stats两次采样的间隔秒数--trace-sec5pprof trace 采样时长秒--profile-sec30pprof CPU profile 采样时长秒# 输出到 /var/log/ 目录 $ juicefs debug --out-dir/var/log /mnt/jfs # 只收集最后 1000 行日志 $ juicefs debug --out-dir/var/log --limit1000 /mnt/jfs实现上有几个值得注意的细节挂载点校验命令会先校验传入路径的 inode 是否为根 inodemeta.RootInode如果不是则报错path %s is not a mount point避免误用。日志收集collectLog会从 mount 命令行中解析--log参数获取日志路径若挂载是前台运行未加-d/--background会提示前台运行无法收集日志。Windows 下则通过 PowerShell 的Get-Content -Tail实现。pprof 端口探测getPprofPort优先从.config的DebugAgent字段解析端口若失败则通过lsof查找监听在 6060~6099 范围内的端口并用/debug/pprof/cmdline?debug1校验该端口确实属于目标挂载点防止误采到同机其他 JuiceFS 实例。pprof 采集项collectPprof并发采集 allocs、block、cmdline、goroutine含debug1堆栈文本与debug2详细堆栈、heap、mutex、threadcreate、trace、profile 等 11 类数据分别保存为.pb.gz与.txt文件。自动打包收集完成后通过geneZipFile将整个目录压缩为 zip方便直接发送给支持团队。关于juicefs debug的更多信息可查看 debug 命令参考。四、实时性能监控juicefs profile与juicefs statsJuiceFS 客户端提供profile和stats两个子命令来对性能数据进行可视化呈现。其中profile命令通过读取「文件系统访问日志」进行汇总输出而stats则依赖客户端监控数据Prometheus 指标。4.1juicefs profile操作级延迟分析juicefs profile会对「文件系统访问日志」进行汇总。运行juicefs profile MOUNTPOINT命令便能看到根据最新访问日志获取的各个文件系统操作的实时统计信息1实时分析挂载点juicefs profile /mnt/jfs输出表格包含各操作类型的Count请求数、Average(us)平均时延、Total(us)总时延与Percent(%)占比并按总时延降序排列方便快速找出开销最大的操作。2回放模式分析历史日志除了对挂载点进行实时分析该命令还提供回放模式replay可以对预先收集的日志进行回放分析# 预先收集日志Ctrl-C 停止收集 cat /jfs/.accesslog /tmp/juicefs.accesslog # 性能问题复现后重放日志分析各调用耗时找出性能瓶颈 juicefs profile /tmp/juicefs.accesslog如果认为回放日志的速度太快可以用Enter/Return 键暂停/继续回放。如果太慢则设置--interval 0来立即回放整个日志文件并直接显示最终统计结果juicefs profile /tmp/juicefs.accesslog --interval 03按用户/进程过滤如果只对某个用户或进程感兴趣可以通过指定其 ID 来过滤掉其他用户或进程可同时指定多个用逗号分隔# 只统计 uid 为 12345 的用户产生的操作 juicefs profile /tmp/juicefs.accesslog --uid 12345 # 也支持按 gid、pid 过滤 juicefs profile /tmp/juicefs.accesslog --gid 1000 --pid 4403从源码 cmd/profile.go 看profile命令支持--uid/-u、--gid/-g、--pid/-p过滤与--interval默认 2 秒刷新一次参数回放模式下--interval也用于控制回放速度。其parseLine函数会按访问日志的时间戳格式2006.01.02 15:04:05.000000与0.000003时延字段解析每一行并在内部按操作类型聚合计数与总时延最终以百分比形式展示。4.2juicefs stats系统级指标监控juicefs stats命令通过读取 JuiceFS 客户端的监控数据挂载点根目录下的.jfs.stats/.stats虚拟文件内容为 Prometheus 格式文本以类似 Linuxdstat工具的形式实时打印各个指标的每秒变化情况juicefs stats /mnt/jfs从源码 cmd/stats.go 可以确认其完整参数参数默认值作用--schemaufmco输出板块组合字符含义t(时间)、u(usage)、f(fuse)、m(meta)、c(blockcache)、o(object)、g(go)--interval1每次刷新的间隔秒数--verbosity/-l0详细程度0 或 1 足够大多数场景--count/-c0不限显示多少次更新后退出# 显示更多指标txn、retry、get_c、put_c、del_c、cache 等 juicefs stats /mnt/jfs -l 1各板块指标介绍如下usagecpu进程的 CPU 使用率对应指标juicefs_cpu_usage。mem进程的物理内存使用量juicefs_memory。buf进程已使用的读写缓冲区大小juicefs_used_buffer_size_bytes。如果该数值逼近甚至超过客户端所设置的--buffer-size说明读写缓冲区空间不足需要视情况扩大或降低应用读写负载。cache内部指标无需关注juicefs_store_cache_size_bytes仅-l 1时显示。fuseops/lat通过 FUSE 接口处理的每秒请求数及其平均时延单位毫秒。对应juicefs_fuse_ops_durations_histogram_seconds。read/write通过 FUSE 接口处理的读写带宽juicefs_fuse_read_size_bytes_sum/juicefs_fuse_written_size_bytes_sum。metaops/lat每秒处理的元数据请求数和平均时延毫秒。注意部分能在缓存中直接处理的元数据请求未列入统计以更好地体现客户端与元数据引擎交互的耗时juicefs_meta_ops_durations_histogram_seconds。txn/lat元数据引擎每秒处理的写事务个数及其平均时延毫秒仅-l 1时显示。只读请求如getattr只会计入ops而不会计入txnjuicefs_transaction_durations_histogram_seconds。retry元数据引擎每秒重试写事务的次数仅-l 1时显示juicefs_transaction_restart。若该值持续不为 0说明元数据引擎存在事务冲突或临时故障。blockcacheblockcache代表本地数据缓存块缓存。需要特别注意如果读请求已经被内核页缓存命中流量将不会体现在blockcache相关指标下。因此如果反复读取相同文件却发现持续产生blockcache流量说明文件始终未能被内核页缓存收录应考虑往该方向排查比如内存吃紧不足以缓存更多文件。read/write客户端本地数据缓存的每秒读写流量juicefs_blockcache_hit_bytes/juicefs_blockcache_write_bytes。objectobject代表与对象存储相关的指标。在缓存场景下读请求穿透到对象存储将会明显降低读性能可以用该指标来断定数据是否完整缓存。另一方面通过对比 GET 请求流量和 FUSE 读流量的关系也能初步判断读放大的情况。get/get_c/lat对象存储每秒处理读请求的带宽值、请求个数及其平均时延毫秒。get_c/lat仅-l 1时显示。put/put_c/lat对象存储每秒处理写请求的带宽值、请求个数及其平均时延毫秒。put_c/lat仅-l 1时显示。del_c/lat对象存储每秒处理删除请求的个数和平均时延毫秒仅-l 1时显示。判断读放大的快捷方法当缓存未命中时JuiceFS 通常需要按固定块大小默认 4 MiB 的 chunk 粒度内的 block从对象存储拉取数据。若object板块的 GET 流量明显大于 FUSE 读流量如随机小读场景即可初步判断存在读放大现象具体应对策略可参考故障排查文档中的读放大章节。五、用 pprof 获取运行时信息5.1 定位 pprof 监听端口JuiceFS 客户端默认会通过 Go 标准库的net/http/pprof在本地监听一个 TCP 端口用以获取运行时信息如 Goroutine 堆栈信息、CPU 性能统计、内存分配统计。可以通过挂载点下的.config文件查看当前 JuiceFS 客户端监听的具体端口号# 假设挂载点是 /jfs $ cat /jfs/.config | grep DebugAgent DebugAgent: 127.0.0.1:6064,默认 pprof 监听的端口号范围是从6060 开始至 6099 结束共 40 个端口避免同一主机多实例冲突上例中实际端口是 6064。5.2 获取运行时信息拿到监听端口后即可通过http://localhost:port/debug/pprof地址查看所有可供查询的运行时信息。一些重要的运行时信息如下信息类型访问地址Goroutine 堆栈信息http://localhost:port/debug/pprof/goroutine?debug1CPU 性能统计http://localhost:port/debug/pprof/profile?seconds30内存分配统计http://localhost:port/debug/pprof/heap为便于分析可以将这些运行时信息保存到本地# 保存 Goroutine 堆栈文本 curl http://localhost:port/debug/pprof/goroutine?debug1 juicefs.goroutine.txt # 保存 30 秒 CPU profile curl http://localhost:port/debug/pprof/profile?seconds30 juicefs.cpu.pb.gz # 保存内存分配 profile curl http://localhost:port/debug/pprof/heap juicefs.heap.pb.gz更省事的方式也可以直接使用juicefs debug命令自动收集这些运行时信息并保存到本地默认保存到当前目录下的debug目录中juicefs debug /mnt/jfs5.3 使用go tool pprof分析如果安装了go命令可以通过go tool pprof直接分析例如分析 CPU 性能统计$ go tool pprof http://localhost:port/debug/pprof/profile?seconds30 Fetching profile over HTTP from http://localhost:port/debug/pprof/profile?seconds30 Saved profile in /Users/xxx/pprof/pprof.samples.cpu.001.pb.gz Type: cpu Time: Dec 17, 2021 at 1:41pm (CST) Duration: 30.12s, Total samples 32.06s (106.42%) Entering interactive mode (type help for commands, o for options) (pprof) top Showing nodes accounting for 30.57s, 95.35% of 32.06s total Dropped 285 nodes (cum 0.16s) Showing top 10 nodes out of 192 flat flat% sum% cum cum% 14.73s 45.95% 45.95% 14.74s 45.98% runtime.cgocall 7.39s 23.05% 69.00% 7.41s 23.11% syscall.syscall 2.92s 9.11% 78.10% 2.92s 9.11% runtime.pthread_cond_wait 2.35s 7.33% 85.43% 2.35s 7.33% runtime.pthread_cond_signal 1.13s 3.52% 88.96% 1.14s 3.56% runtime.nanotime1 0.77s 2.40% 91.36% 0.77s 2.40% syscall.Syscall 0.49s 1.53% 92.89% 0.49s 1.53% runtime.memmove 0.31s 0.97% 93.86% 0.31s 0.97% runtime.kevent 0.27s 0.84% 94.70% 0.27s 0.84% runtime.usleep 0.21s 0.66% 95.35% 0.21s 0.66% runtime.madvise上述输出中flat表示该函数自身消耗的 CPU 时间cum表示包含其调用的子函数在内的累计 CPU 时间。例如上例中runtime.cgocall占了近 46% 的 CPU说明大量时间花费在 CGO 调用FUSE 与内核交互上这在正常的高负载挂载场景中属于预期现象但如果配合对象存储 GET/PUT 流量异常升高则需进一步结合 stats 分析。也可以将运行时信息导出为可视化图表以更直观的方式分析。可视化图表支持导出为多种格式如 HTML、PDF、SVG、PNG 等。例如导出内存分配统计信息为 PDF注意导出可视化图表功能依赖 Graphvizdot命令请先安装好它。go tool pprof -pdf http://localhost:port/debug/pprof/heap juicefs.heap.pdf5.4 使用 Pyroscope 进行持续性能剖析Pyroscope 是一个开源的持续性能剖析平台适合在生产环境长期运行。它能够帮你找出源代码中的性能问题和瓶颈解决 CPU 利用率高的问题理解应用程序的调用树call tree追踪随时间变化的性能情况JuiceFS 支持使用--pyroscope选项传入 Pyroscope 服务端地址指标以每隔 10 秒的频率推送到服务端。如果服务端开启了权限校验校验信息 API Key 可以通过环境变量PYROSCOPE_AUTH_TOKEN传入export PYROSCOPE_AUTH_TOKENxxxxxxxxxxxxxxxx juicefs mount --pyroscope http://localhost:4040 redis://localhost /mnt/jfs juicefs dump --pyroscope http://localhost:4040 redis://localhost dump.json与手动抓取 pprof 相比Pyroscope 的优势在于时间维度上的持续性你可以随时回看任意历史时间段的 CPU/内存火焰图便于在问题复现后回溯根因特别适合偶发性能问题的定位。六、故障排查方法速查表排查目标推荐工具关键操作客户端运行日志ERROR 过滤系统日志/本地日志 grepcat /var/log/syslog \| grep juicefs \| grep ERROR逐操作追踪审计/时延.accesslog虚拟文件cat /jfs/.accesslog一键收集诊断包juicefs debugjuicefs debug /mnt/jfs产出 zip 包操作级性能分析juicefs profilejuicefs profile /mnt/jfs或回放日志系统级实时监控juicefs statsjuicefs stats /mnt/jfs -l 1运行时 Profilingpprof /juicefs debugcurl http://localhost:port/debug/pprof/goroutine?debug1持续性能剖析Pyroscopejuicefs mount --pyroscope http://server:4040 ...推荐排障流程先看日志按ERROR过滤客户端日志确认是否有明确报错再抓现场问题复现时立即执行juicefs debug mountpoint一次性收集版本、系统信息、config、stats、pprof、日志并打包性能分析若问题为性能劣化用juicefs profile定位慢操作类型用juicefs stats观察 fuse/meta/blockcache/object 各层指标判断瓶颈位于元数据引擎、本地缓存还是对象存储深入剖析必要时通过 pprof或 Pyroscope 持续剖析获取 CPU/内存火焰图定位代码级热点并与juicefs profile的操作延迟分布互相印证。以上方法与工具组合构成了从现象确认到根因定位的完整闭环可覆盖大多数挂载点、S3 网关与 Hadoop Java SDK 场景下的故障诊断与性能分析需求。【免费下载链接】juicefsJuiceFS is a distributed POSIX file system built on top of Redis and S3.项目地址: https://gitcode.com/GitHub_Trending/ju/juicefs创作声明：本文部分内容由AI辅助生成（AIGC），仅供参考