samba causing disk activity every minute
Andrew Bartlett
abartlet at samba.org
Thu Jul 5 03:07:02 UTC 2018
On Wed, 2018-07-04 at 22:45 -0400, George via samba-technical wrote:
> I posted the following on July 2. No response. So I'm posting it here. This strace is from a fourth smbd process
>
> This trace code runs for hours and hours. Though for some reason after a day or so it stopped. The network consists
> of three my Clouds two windows 10 pro PC's and a Linux Debian 8 system usually turned off. Only the Public share on the
>
> My Clouds is mapped to the windows PC's. Just as an aside do we issue the same system call in pairs or triplicate to compare the results?
> I mean why do two or three gettimeofday one right after the other.
>
>
>
> The latest version that Western Digital has shipped with the My cloud devices accesses the disk
> about twice a minute. The access to /dev/sda2 is causing the system to keep the disk from going
> into standby mode. I don't understand the call to quotactl every minute when no one is trying to access the share.
> An strace of one of the processes shows the following:
G'Day,
I hope this helps clarify some things.
> poll([{fd=13, events=POLLIN|POLLHUP}, {fd=6, events=POLLIN|POLLHUP}, {fd=12, events=POLLIN|POLLHUP}, {fd=31, events=POLLIN|POLLHUP}], 4, 60000) = 1 ([{fd=31, revents=POLLIN}])
This is the system returning from poll, because something happened.
Exciting times ahead!
> readv(31, [{"\0\0\0\230", 4}], 1) = 4
> readv(31, [{"\376SMB@\0\1\0\0\0\0\0\5\0\1\0000\0\0\0\0\0\0\0V\1\0\0\0\0\0\0"..., 152}], 1) = 152
This is us reading a network packet from the client.
> gettimeofday({1530539063, 52936}, NULL) = 0
It is helpful to know the time.
> geteuid32() = 0
> getegid32() = 0
> setgroups32(3, [1000, 501, 2000]) = 0
> setresgid32(-1, 1000, -1) = 0
> getegid32() = 1000
> setresuid32(1002, 1002, -1) = 0
> geteuid32() = 1002
We become the user, and take great care to ensure we know what user we
were and what user we have become. Old, old bugs cause us to be very
careful here, because for some of these calls if you call with -1
nothing happens.
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> getxattr(".", "system.posix_acl_access", 0xbeb26ee0, 132) = -1 ENODATA (No data available)
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> getxattr(".", "system.posix_acl_default", 0xbeb26ee0, 132) = -1 ENODATA (No data available)
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
Checking for the access that packet required
> gettimeofday({1530539063, 61427}, NULL) = 0
> gettimeofday({1530539063, 61912}, NULL) = 0
> gettimeofday({1530539063, 62268}, NULL) = 0
More timing, perhaps to check if it is time for a timed even tto run.
> fcntl64(28, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=340, len=1}, 0xbeb26f48) = 0
> fcntl64(28, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=164, len=1}, 0xbeb26e48) = 0
> fcntl64(28, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=164, len=1}, 0xbeb26e88) = 0
> fcntl64(28, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=340, len=1}, 0xbeb26f58) = 0
Locking and unlocking a TDB (the TDB read isn't shown as it is an
mmapped() area).
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> fcntl64(20, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=8560, len=1}, 0xbeb26fb0) = 0
> fcntl64(15, F_SETLKW64, {type=F_RDLCK, whence=SEEK_SET, start=548, len=1}, 0xbeb26de0) = 0
> fcntl64(15, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=548, len=1}, 0xbeb26e20) = 0
> fcntl64(20, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=8560, len=1}, 0xbeb26f60) = 0
Even more TDB access.
> writev(31, [{"\0\0\0\320", 4}, {NULL, 0}, {"\376SMB@\0\1\0\0\0\0\0\5\0\1\0001\0\0\0\0\0\0\0V\1\0\0\0\0\0\0"..., 64}, {"Y\0\0\0\1\0\0\0.\325\236\241\240\316\322\1.\325\236\241\240\316\322\1~\3657`V\16\324\1"..., 88}, {"\0\0\0\0\20\0\4\0\0\0\30\0 \0\0\0QFid\0\0\0\0\1\0\t\1\0\0\0\0"..., 56}], 5) = 212
Write the result back to the client.
> gettimeofday({1530539063, 70393}, NULL) = 0
> gettimeofday({1530539063, 70711}, NULL) = 0
> poll([{fd=13, events=POLLIN|POLLHUP}, {fd=6, events=POLLIN|POLLHUP}, {fd=12, events=POLLIN|POLLHUP}, {fd=31, events=POLLIN|POLLHUP}], 4, 30064) = 1 ([{fd=31, revents=POLLIN}])
> readv(31, [{"\0\0\0h", 4}], 1) = 4
> readv(31, [{"\376SMB@\0\1\0\0\0\0\0\20\0\1\0000\0\0\0\0\0\0\0W\1\0\0\0\0\0\0"..., 104}], 1) = 104
Another network packet
> gettimeofday({1530539063, 72650}, NULL) = 0
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> statfs64(".", 88, {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=1451469082, f_bfree=912073125, f_bavail=897438740, f_files=182882304, f_ffree=182881143, f_fsid={2141529791, -1094344988}, f_namelen=255, f_frsize=4096}) = 0
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> geteuid32() = 1002
Good, we are still the right user
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> open("/etc/mtab", O_RDONLY|O_CLOEXEC) = 8
> fstat64(8, {st_mode=S_IFREG|0755, st_size=693, ...}) = 0
> mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb4ca0000
> read(8, "%root% / unknown rw 0 0\nproc /pr"..., 1024) = 693
> stat64("/", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
> stat64("/proc", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0
> stat64("/", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
> stat64("/sys", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0
> stat64("/dev", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=3760, ...}) = 0
> stat64("/proc", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0
> stat64("/sys/fs/cgroup", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
> stat64("/boot", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
> stat64("/usr/local/config", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
> stat64("/usr/local/modules", {st_mode=S_IFDIR|0755, st_size=954, ...}) = 0
> stat64("/mnt", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=120, ...}) = 0
> stat64("/var/log", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=300, ...}) = 0
> stat64("/tmp", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=1200, ...}) = 0
> stat64("/mnt/HD_a4", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
> stat64("/mnt/HD/HD_a2", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> close(8) = 0
> munmap(0xb4ca0000, 4096) = 0
> quotactl(Q_GETQUOTA|USRQUOTA, "/dev/sda2", 1002, {bhardlimit=0, bsoftlimit=0, curspace=0, ihardlimit=0, isoftlimit=0, curinodes=0, ...}) = 0
> getegid32() = 1000
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> open("/etc/mtab", O_RDONLY|O_CLOEXEC) = 8
> fstat64(8, {st_mode=S_IFREG|0755, st_size=693, ...}) = 0
> mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb4ca0000
> read(8, "%root% / unknown rw 0 0\nproc /pr"..., 1024) = 693
> stat64("/", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
> stat64("/proc", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0
> stat64("/", {st_mode=S_IFDIR|0755, st_size=1024, ...}) = 0
> stat64("/sys", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0
> stat64("/dev", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=3760, ...}) = 0
> stat64("/proc", {st_mode=S_IFDIR|0555, st_size=0, ...}) = 0
> stat64("/sys/fs/cgroup", {st_mode=S_IFDIR|0755, st_size=0, ...}) = 0
> stat64("/boot", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
> stat64("/usr/local/config", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
> stat64("/usr/local/modules", {st_mode=S_IFDIR|0755, st_size=954, ...}) = 0
> stat64("/mnt", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=120, ...}) = 0
> stat64("/var/log", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=300, ...}) = 0
> stat64("/tmp", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=1200, ...}) = 0
> stat64("/mnt/HD_a4", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
> stat64("/mnt/HD/HD_a2", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> close(8) = 0
> munmap(0xb4ca0000, 4096) = 0
> quotactl(Q_GETQUOTA|GRPQUOTA, "/dev/sda2", 1000, {bhardlimit=0, bsoftlimit=0, curspace=0, ihardlimit=0, isoftlimit=0, curinodes=186, ...}) = 0
The quota stuff you noticed. Perhaps the client run 'df'?
> writev(31, [{"\0\0\0h", 4}, {NULL, 0}, {"\376SMB@\0\1\0\0\0\0\0\20\0\1\0001\0\0\0\0\0\0\0W\1\0\0\0\0\0\0"..., 64}, {"\t\0H\0 \0\0\0", 8}, {"h\244\16Z\1\0\0\0PP\367\325\0\0\0\0PP\367\325\0\0\0\0\2\0\0\0\0\2\0\0", 32}], 5) = 108
Send it back to the client.
> gettimeofday({1530539063, 125987}, NULL) = 0
> gettimeofday({1530539063, 126298}, NULL) = 0
> poll([{fd=13, events=POLLIN|POLLHUP}, {fd=6, events=POLLIN|POLLHUP}, {fd=12, events=POLLIN|POLLHUP}, {fd=31, events=POLLIN|POLLHUP}], 4, 30009) = 1 ([{fd=31, revents=POLLIN}])
> readv(31, [{"\0\0\0X", 4}], 1) = 4
> readv(31, [{"\376SMB@\0\1\0\0\0\0\0\6\0\1\0000\0\0\0\0\0\0\0X\1\0\0\0\0\0\0"..., 88}], 1) = 88
Another network packet
> gettimeofday({1530539063, 128363}, NULL) = 0
> fcntl64(20, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=8560, len=1}, 0xbeb272b8) = 0
> fcntl64(15, F_SETLKW64, {type=F_RDLCK, whence=SEEK_SET, start=548, len=1}, 0xbeb27118) = 0
> fcntl64(15, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=548, len=1}, 0xbeb27158) = 0
> fcntl64(20, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=8560, len=1}, 0xbeb27298) = 0
> fcntl64(28, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=340, len=1}, 0xbeb27290) = 0
> fcntl64(28, F_SETLK64, {type=F_WRLCK, whence=SEEK_SET, start=32256, len=1}, 0xbeb27298) = 0
> fcntl64(28, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=32256, len=1}, 0xbeb272a8) = 0
> fcntl64(28, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=164, len=1}, 0xbeb27228) = 0
> fcntl64(28, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=164, len=1}, 0xbeb27268) = 0
> fcntl64(28, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=340, len=1}, 0xbeb272e8) = 0
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> writev(31, [{"\0\0\0|", 4}, {NULL, 0}, {"\376SMB@\0\1\0\0\0\0\0\6\0\1\0001\0\0\0\0\0\0\0X\1\0\0\0\0\0\0"..., 64}, {"<\0\1\0\0\0\0\0.\325\236\241\240\316\322\1.\325\236\241\240\316\322\1~\3657`V\16\324\1"..., 60}, {NULL, 0}], 5) = 128
> gettimeofday({1530539063, 137410}, NULL) = 0
> gettimeofday({1530539063, 137770}, NULL) = 0
> poll([{fd=13, events=POLLIN|POLLHUP}, {fd=6, events=POLLIN|POLLHUP}, {fd=12, events=POLLIN|POLLHUP}, {fd=31, events=POLLIN|POLLHUP}], 4, 29997) = 0 (Timeout)
> gettimeofday({1530539093, 160484}, NULL) = 0
> gettimeofday({1530539093, 160876}, NULL) = 0
> geteuid32() = 1002
> setresuid32(0, 0, -1) = 0
> geteuid32() = 0
> geteuid32() = 0
> getegid32() = 1000
> setresgid32(-1, 0, -1) = 0
> getegid32() = 0
> getegid32() = 0
> setgroups32(0, []) = 0
> setresgid32(-1, 0, -1) = 0
> getegid32() = 0
> setresuid32(0, 0, -1) = 0
> geteuid32() = 0
> clock_gettime(0x7 /* CLOCK_??? */, {36445, 372815200}) = 0
> stat64("", 0xbeb276e0) = -1 ENOENT (No such file or directory)
> umask(022) = 0
> > open("/var/log/samba/log.smbd", O_WRONLY|O_CREAT|O_APPEND|O_LARGEFILE, 0644) = 8
Open the logs
> fcntl64(8, F_GETFD) = 0
> fcntl64(8, F_SETFD, FD_CLOEXEC) = 0
Don't leave the log file open in a fork()/exec() child. Safer this way
> close(29) = 0
> umask(0) = 022
> dup2(8, 2) = 2
> stat64("/etc/samba/tm_config.conf", {st_mode=S_IFREG|0644, st_size=206, ...}) = 0
> stat64("/etc/samba/smb.conf", {st_mode=S_IFREG|0644, st_size=2590, ...}) = 0
Check if the smb.conf changed
> geteuid32() = 0
> fstat64(8, {st_mode=S_IFREG|0644, st_size=1280, ...}) = 0
> gettimeofday({1530539093, 168511}, NULL) = 0
> gettimeofday({1530539093, 168765}, NULL) = 0
> poll([{fd=13, events=POLLIN|POLLHUP}, {fd=6, events=POLLIN|POLLHUP}, {fd=12, events=POLLIN|POLLHUP}, {fd=31, events=POLLIN|POLLHUP}], 4, 59992) = 1 ([{fd=31, revents=POLLIN}])
> readv(31, [{"\0\0\0\230", 4}], 1) = 4
> readv(31, [{"\376SMB@\0\1\0\0\0\0\0\5\0\1\0000\0\0\0\0\0\0\0Y\1\0\0\0\0\0\0"..., 152}], 1) = 152
Yet another network packet. A busy network! (joke)
> gettimeofday({1530539097, 493514}, NULL) = 0
> geteuid32() = 0
> getegid32() = 0
> setgroups32(3, [1000, 501, 2000]) = 0
> setresgid32(-1, 1000, -1) = 0
> getegid32() = 1000
> setresuid32(1002, 1002, -1) = 0
> geteuid32() = 1002
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> getxattr(".", "system.posix_acl_access", 0xbeb26ee0, 132) = -1 ENODATA (No data available)
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> getxattr(".", "system.posix_acl_default", 0xbeb26ee0, 132) = -1 ENODATA (No data available)
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> gettimeofday({1530539097, 501714}, NULL) = 0
> gettimeofday({1530539097, 502110}, NULL) = 0
> gettimeofday({1530539097, 502535}, NULL) = 0
> fcntl64(28, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=188, len=1}, 0xbeb26f48) = 0
> fcntl64(28, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=164, len=1}, 0xbeb26e48) = 0
> fcntl64(28, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=164, len=1}, 0xbeb26e88) = 0
> fcntl64(28, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=188, len=1}, 0xbeb26f58) = 0
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> fcntl64(20, F_SETLKW64, {type=F_WRLCK, whence=SEEK_SET, start=8560, len=1}, 0xbeb26fb0) = 0
> fcntl64(15, F_SETLKW64, {type=F_RDLCK, whence=SEEK_SET, start=548, len=1}, 0xbeb26de0) = 0
> fcntl64(15, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=548, len=1}, 0xbeb26e20) = 0
> fcntl64(20, F_SETLKW64, {type=F_UNLCK, whence=SEEK_SET, start=8560, len=1}, 0xbeb26f60) = 0
> writev(31, [{"\0\0\0\320", 4}, {NULL, 0}, {"\376SMB@\0\1\0\0\0\0\0\5\0\1\0001\0\0\0\0\0\0\0Y\1\0\0\0\0\0\0"..., 64}, {"Y\0\0\0\1\0\0\0.\325\236\241\240\316\322\1.\325\236\241\240\316\322\1~\3657`V\16\324\1"..., 88}, {"\0\0\0\0\20\0\4\0\0\0\30\0 \0\0\0QFid\0\0\0\0\1\0\t\1\0\0\0\0"..., 56}], 5) = 212
> gettimeofday({1530539097, 510897}, NULL) = 0
> gettimeofday({1530539097, 511285}, NULL) = 0
> poll([{fd=13, events=POLLIN|POLLHUP}, {fd=6, events=POLLIN|POLLHUP}, {fd=12, events=POLLIN|POLLHUP}, {fd=31, events=POLLIN|POLLHUP}], 4, 55650) = 1 ([{fd=31, revents=POLLIN}])
> readv(31, [{"\0\0\0h", 4}], 1) = 4
> readv(31, [{"\376SMB@\0\1\0\0\0\0\0\20\0\1\0000\0\0\0\0\0\0\0Z\1\0\0\0\0\0\0"..., 104}], 1) = 104
> gettimeofday({1530539097, 513111}, NULL) = 0
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> statfs64(".", 88, {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=1451469082, f_bfree=912073125, f_bavail=897438740, f_files=182882304, f_ffree=182881143, f_fsid={2141529791, -1094344988}, f_namelen=255, f_frsize=4096}) = 0
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> geteuid32() = 1002
> stat64(".", {st_mode=S_IFDIR|0777, st_size=4096, ...}) = 0
> open("/etc/mtab", O_RDONLY|O_CLOEXEC) = 29
> fstat64(29, {st_mode=S_IFREG|0755, st_size=693, ...}) = 0
> mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb4ca0000
> read(29, "%root% / unknown rw 0 0\nproc /pr"..., 1024) = 693
You get the idea. In short, work out why you are getting network
packets and that will tell you why you are waking up smbd.
Andrew Bartlett
--
Andrew Bartlett
https://samba.org/~abartlet/
Authentication Developer, Samba Team https://samba.org
Samba Development and Support, Catalyst IT
https://catalyst.net.nz/services/samba
More information about the samba-technical
mailing list