Btrfs-transaction and kworker processes writing huge amounts of data to eMMC

Hi.
I discovered that those two processes are writing very often to my eMMC partition. And I can’t understand why. I started to worry that this is slowly killing my eMMC. Can I stop this somehow? Or at least discover what is the reason? Is it possible to debug it further? Here are some of my findings:

iostat (with 36days uptime):

> Device:            tps    kB_read/s    kB_wrtn/s    kB_read    kB_wrtn
> mmcblk0          23.70        74.83       116.88  234984144  367041408

If I count correctly, this is 9GB/day


That would be worrisome indeed.

As for kworker it could be that it is swapping memory to disk or some sort of interrupt issue.


iotop might be useful https://programmer.help/blogs/case-18-find-out-the-real-culprit-of-disk-io-busy.html

You can check if you have swapping enabled by swapon -s sommand, but I doubt You have any enabled.

You can start by disabling as many servicess as possible (including for example logging) and check if that helps, because it might be related indirectly.

My second screenshot is from iotop.

I don’t have any swap enabled

I tried turning off everything. no changes, it looks like there is many writing operations written by kworker, and then all of them are written to disk in one btrfs transaction

Situation is so serious that I turned off the whole device and not using it. I feel blocked with not way out.

Since IOTOP is not available on TOS 5.x just turned on briefly echo 1 > /proc/sys/vm/block_dump

which though does not show the amount of data being written.

3:16:18+00:00 kernel: btrfs-transacti(1103): dirtied inode 1 (?) on sda2
3:16:18+00:00 kernel: btrfs-transacti(1103): dirtied inode 256 (?) on sda2
3:16:18+00:00 kernel: btrfs-transacti(1103): WRITE block 41000 on sda2 (128 sectors)
3:16:18+00:00 kernel: btrfs-transacti(1103): WRITE block 41000 on sda2 (128 sectors)
3:16:18+00:00 kernel: btrfs-transacti(1103): WRITE block 41000 on sda2 (128 sectors)
3:16:18+00:00 kernel: btrfs-transacti(1103): WRITE block 59328 on sda2 (704 sectors)
3:16:18+00:00 kernel: syslog-ng(8937): dirtied inode 339 (messages) on sda2
3:16:18+00:00 kernel: btrfs-transacti(1103): WRITE block 128 on sda2 (8 sectors)
3:16:18+00:00 kernel: btrfs-transacti(1103): WRITE block 131072 on sda2 (8 sectors)
3:16:29+00:00 kernel: kworker/u4:2(7431): WRITE block 38384 on sda2 (8 sectors)
3:16:29+00:00 kernel: kworker/u4:2(7431): WRITE block 38544 on sda2 (8 sectors)
3:16:42+00:00 kernel: syslog-ng(9067): dirtied inode 343 (wan.log) on sda2
3:16:49+00:00 kernel: nlbwmon(4206): dirtied inode 291 (20200601.db.gz) on sda2
3:16:49+00:00 kernel: kworker/u4:3(8995): WRITE block 38664 on sda2 (8 sectors)
3:16:49+00:00 kernel: kworker/u4:2(7431): WRITE block 38672 on sda2 (8 sectors)
3:16:49+00:00 kernel: kworker/u4:3(8995): WRITE block 478952 on sda2 (16 sectors)
3:16:49+00:00 kernel: syslog-ng(9067): dirtied inode 339 (messages) on sda2
3:16:59+00:00 kernel: btrfs-transacti(1103): dirtied inode 256 (?) on sda2
3:16:59+00:00 kernel: btrfs-transacti(1103): WRITE block 40872 on sda2 (128 sectors)
3:16:59+00:00 kernel: btrfs-transacti(1103): dirtied inode 257 (?) on sda2
3:16:59+00:00 kernel: btrfs-transacti(1103): WRITE block 481696 on sda2 (128 sectors)
3:16:59+00:00 kernel: btrfs-transacti(1103): WRITE block 40872 on sda2 (128 sectors)
3:16:59+00:00 kernel: btrfs-transacti(1103): WRITE block 481696 on sda2 (128 sectors)
3:16:59+00:00 kernel: btrfs-transacti(1103): WRITE block 40872 on sda2 (128 sectors)
3:16:59+00:00 kernel: btrfs-transacti(1103): WRITE block 60032 on sda2 (320 sectors)
3:16:59+00:00 kernel: btrfs-transacti(1103): WRITE block 60416 on sda2 (640 sectors)
3:16:59+00:00 kernel: btrfs-transacti(1103): WRITE block 128 on sda2 (8 sectors)
3:16:59+00:00 kernel: btrfs-transacti(1103): WRITE block 131072 on sda2 (8 sectors)
3:17:14+00:00 kernel: kworker/u4:2(7431): WRITE block 36688 on sda2 (8 sectors)
3:17:19+00:00 kernel: kworker/u4:3(8995): WRITE block 478048 on sda2 (8 sectors)
3:17:19+00:00 kernel: kworker/u4:0(8994): WRITE block 61056 on sda2 (256 sectors)
3:17:19+00:00 kernel: kworker/u4:0(8994): dirtied inode 1 (?) on sda2
3:17:19+00:00 kernel: syslog-ng(9228): dirtied inode 339 (messages) on sda2
3:17:40+00:00 kernel: syslog-ng(9360): dirtied inode 343 (wan.log) on sda2
3:17:44+00:00 kernel: btrfs-transacti(1103): dirtied inode 256 (?) on sda2
3:17:44+00:00 kernel: btrfs-transacti(1103): WRITE block 41000 on sda2 (128 sectors)
3:17:44+00:00 kernel: btrfs-transacti(1103): dirtied inode 257 (?) on sda2
3:17:44+00:00 kernel: btrfs-transacti(1103): WRITE block 41128 on sda2 (128 sectors)
3:17:44+00:00 kernel: btrfs-transacti(1103): WRITE block 41000 on sda2 (128 sectors)
3:17:44+00:00 kernel: btrfs-transacti(1103): WRITE block 41128 on sda2 (128 sectors)
3:17:44+00:00 kernel: btrfs-transacti(1103): WRITE block 41000 on sda2 (128 sectors)
3:17:44+00:00 kernel: btrfs-transacti(1103): WRITE block 61312 on sda2 (832 sectors)
3:17:44+00:00 kernel: btrfs-transacti(1103): WRITE block 128 on sda2 (8 sectors)
3:17:44+00:00 kernel: btrfs-transacti(1103): WRITE block 131072 on sda2 (8 sectors)
3:17:49+00:00 kernel: nlbwmon(4206): dirtied inode 291 (20200601.db.gz) on sda2
3:17:49+00:00 kernel: kworker/u4:0(8994): WRITE block 38384 on sda2 (8 sectors)
3:17:49+00:00 kernel: kworker/u4:0(8994): WRITE block 38592 on sda2 (8 sectors)
3:17:50+00:00 kernel: kworker/u4:3(8995): WRITE block 478096 on sda2 (8 sectors)
3:17:50+00:00 kernel: kworker/u4:3(8995): WRITE block 478400 on sda2 (8 sectors)
3:17:50+00:00 kernel: syslog-ng(9360): dirtied inode 339 (messages) on sda2

On my node it seems mostly caused by various monitors / logs writing by purpose to the SSD (the OS is running from SSD entirely).

So not sure, most logs would go to /tmp which is mounted as ram disk but there might be some monitor stuff like collectd, suricata, pakon, nextcloud, lxc, sql and the likes that may not dump to the ram disk or SSD (if installed).

With nothing supposedly writing to the local disk I still get:

Device             tps    kB_read/s    kB_wrtn/s    kB_read    kB_wrtn 
mmcblk0           1.61        10.58         7.69    4592296    3340796

which works out to 664416 kB per day. I’ll leave the block_dump logs going for a few minutes to see if there’s something other than btrfs writing to the disk.

Some results for me:
Log start: Jun 24 08:26:05
Log end: Jun 24 08:32:35
Number of lines of log for mmc: 118
btrfs-transaction:
3 dirtied inodes
1296 sectors written
sed (it gives a PID and a file? “paths.shcMbcMg”, but PID is no longer available):
2 dirtied inodes
kworker:
952 sectors written

btrfs-transacti appears to be related the btrfs’s fragmentation handling https://btrfs.wiki.kernel.org/index.php/Gotchas

there are also some mount options that may reduce the occurrence but may come with caveats.

Notwithstanding

OK, I found the source of my writes. It was YAMon4. I think it’s /opt/YAMon4/includes/paths.sh, which appears to be written to fairly often (every 4 minutes from /opt/YAMon4/update-reports.sh). Perhaps @al_c can help out with this.

I think for now, I’ll move the whole /opt/YAMon4/includes directory on to my ssd.