I'm seeing the following error in our logs when removing mailboxes (we are
using mdbox and dovecot 2.1.8):
Aug 1 20:03:36 msgsrv dovecot: imap(t...@test.com): Error:
stat(/mailstore/domains/test.com/test/mdbox/mailboxes/Spam) failed: Operation
not permitted
Aug 1 20:03:36 msgsrv dovecot: imap(t...@test.com): Mailbox deleted: Spam
When I run truss against the process it appears the error relates to attempted
unlink of a directory, not a stat of it, as reported by the log. However the
mailbox does appear to be deleted fine, so it appears to be an erroneous error.
Here is the truss output from the "3 DELETE INBOX.Spam" IMAP command:
gettimeofday({1343808204.962165 },0x0) = 0 (0x0)
gettimeofday({1343808204.962351 },0x0) = 0 (0x0)
kevent(9,0x0,0,{0xb,EVFILT_READ,0x0,0,0x15,0x21c17a40},6,{1786.679649000 }) = 1
(0x1)
gettimeofday({1343808216.031493 },0x0) = 0 (0x0)
gettimeofday({1343808216.031676 },0x0) = 0 (0x0)
read(11,"3 DELETE INBOX.Spam\r\n",8179) = 21 (0x15)
getpid() = 6293 (0x1895)
__sysctl(0x7fffffffd850,0x4,0x0,0x0,0x21c8f000,0x2a) = 0 (0x0)
clock_gettime(13,{1343808216.000000000 }) = 0 (0x0)
stat("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam/dbox-Mails",{
mode=drwx------ ,inode=28761,size=3,blksize=131072 }) = 0 (0x0)
stat("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam/dbox-Mails",{
mode=drwx------ ,inode=28761,size=3,blksize=131072 }) = 0 (0x0)
stat("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam",{ mode=drwx------
,inode=28760,size=3,blksize=131072 }) = 0 (0x0)
open("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam/dbox-Mails/dovecot.index.log",O_RDWR,037777753160)
= 10 (0xa)
fstat(10,{ mode=-rw------- ,inode=28762,size=144,blksize=4096 }) = 0 (0x0)
pread(0xa,0x21c30000,0x90,0x0,0x1000,0x0) = 144 (0x90)
open("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam/dbox-Mails/dovecot.index",O_RDWR,037777731760)
ERR#2 'No such file or directory'
open("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam/dbox-Mails/dovecot.index.log.2",O_RDWR,037777731520)
ERR#2 'No such file or directory'
fstat(10,{ mode=-rw------- ,inode=28762,size=144,blksize=4096 }) = 0 (0x0)
unlink("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam") ERR#1
'Operation not permitted'
stat("/usr/share/nls/C/libc.cat",0x7fffffffd0a0) ERR#2 'No such file or
directory'
stat("/usr/share/nls/libc/C",0x7fffffffd0a0) ERR#2 'No such file or
directory'
stat("/usr/local/share/nls/C/libc.cat",0x7fffffffd0a0) ERR#2 'No such file or
directory'
stat("/usr/local/share/nls/libc/C",0x7fffffffd0a0) ERR#2 'No such file or
directory'
write(2,"\^A\b6293 prefix=imap(test@test."...,36) = 36 (0x24)
write(2,"\^A\^D6293 stat(/mailstore/domai"...,99) = 99 (0x63)
access("/etc/localtime",4) = 0 (0x0)
open("/etc/localtime",O_RDONLY,04160026530) = 12 (0xc)
fstat(12,{ mode=-r--r--r-- ,inode=16454,size=2434,blksize=4096 }) = 0 (0x0)
read(12,"TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0"...,41448) = 2434 (0x982)
close(12) = 0 (0x0)
issetugid(0x20ee7fd1,0x21e72000,0x0,0xa7,0x4e,0xc) = 1 (0x1)
open("/usr/share/zoneinfo/posixrules",O_RDONLY,056) = 12 (0xc)
fstat(12,{ mode=-r--r--r-- ,inode=545,size=3519,blksize=4096 }) = 0 (0x0)
read(12,"TZif2\0\0\0\0\0\0\0\0\0\0\0\0\0"...,41448) = 3519 (0xdbf)
close(12) = 0 (0x0)
madvise(0x21eba000,0xb000,0x5,0x2b9,0x17,0x1) = 0 (0x0)
madvise(0x21e72000,0x5000,0x5,0x271,0x17,0x1) = 0 (0x0)
madvise(0x21e63000,0xc000,0x5,0x262,0x7fffffffcbf0,0x7fffffffcbf0) = 0 (0x0)
stat("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam/dbox-Mails/dovecot.index.log",{
mode=-rw------- ,inode=28762,size=144,blksize=4096 }) = 0 (0x0)
fstat(10,{ mode=-rw------- ,inode=28762,size=144,blksize=4096 }) = 0 (0x0)
gettimeofday({1343808216.048607 },0x0) = 0 (0x0)
stat("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam/dbox-Mails/dovecot.index.log.2",0x7fffffffd600)
ERR#2 'No such file or directory'
setitimer(0,{0.000000, 180.000000 },{0.000000, 0.000000 }) = 0 (0x0)
fcntl(10,F_SETLKW,0x7fffffffd520) = 0 (0x0)
setitimer(0,{0.000000, 0.000000 },{0.000000, 180.000000 }) = 0 (0x0)
clock_gettime(13,{1343808216.000000000 }) = 0 (0x0)
stat("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam/dbox-Mails/dovecot.index.log",{
mode=-rw------- ,inode=28762,size=144,blksize=4096 }) = 0 (0x0)
fstat(10,{ mode=-rw------- ,inode=28762,size=144,blksize=4096 }) = 0 (0x0)
pwrite(0xa,0x21c09000,0xc,0x90,0x10ab6b8,0x2) = 12 (0xc)
pwrite(0xa,0x7fffffffd69c,0x4,0x90,0x10ab6b8,0x2) = 4 (0x4)
clock_gettime(13,{1343808216.000000000 }) = 0 (0x0)
fcntl(10,F_SETLK,0x7fffffffd5e0) = 0 (0x0)
stat("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam/dbox-Mails/dovecot.index.log",{
mode=-rw------- ,inode=28762,size=156,blksize=4096 }) = 0 (0x0)
fstat(10,{ mode=-rw------- ,inode=28762,size=156,blksize=4096 }) = 0 (0x0)
stat("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam/dbox-Mails/dovecot.index.log",{
mode=-rw------- ,inode=28762,size=156,blksize=4096 }) = 0 (0x0)
fstat(10,{ mode=-rw------- ,inode=28762,size=156,blksize=4096 }) = 0 (0x0)
setitimer(0,{0.000000, 180.000000 },{0.000000, 0.000000 }) = 0 (0x0)
fcntl(10,F_SETLKW,0x7fffffffd1f0) = 0 (0x0)
setitimer(0,{0.000000, 0.000000 },{0.000000, 180.000000 }) = 0 (0x0)
clock_gettime(13,{1343808216.000000000 }) = 0 (0x0)
stat("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam/dbox-Mails/dovecot.index.log",{
mode=-rw------- ,inode=28762,size=156,blksize=4096 }) = 0 (0x0)
fstat(10,{ mode=-rw------- ,inode=28762,size=156,blksize=4096 }) = 0 (0x0)
pwrite(0xa,0x21c09400,0x1c,0x9c,0xffff800021c0bea4,0x7fffffffa9f0) = 28 (0x1c)
pwrite(0xa,0x7fffffffd57c,0x4,0x9c,0xffff800021c0bea4,0x7fffffffa9f0) = 4 (0x4)
clock_gettime(13,{1343808216.000000000 }) = 0 (0x0)
fcntl(10,F_SETLK,0x7fffffffd610) = 0 (0x0)
stat("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam/dbox-Mails/dovecot.index.log",{
mode=-rw------- ,inode=28762,size=184,blksize=4096 }) = 0 (0x0)
fstat(10,{ mode=-rw------- ,inode=28762,size=184,blksize=4096 }) = 0 (0x0)
rename("/mailstore/domains/test.com/test/mdbox/mailboxes/Spam/dbox-Mails","/mailstore/domains/test.com/test/mdbox/..DOVECOT-TrasH")
= 0 (0x0)
open(".",O_RDONLY,00) = 12 (0xc)
open("/mailstore/domains/test.com/test/mdbox/..DOVECOT-TrasH",O_NOFOLLOW,00) =
13 (0xd)
fchdir(0xd,0x100,0x0,0x7b30,0x101010101010101,0x8080808080808080) = 0 (0x0)
stat(".",{ mode=drwx------ ,inode=28761,size=3,blksize=131072 }) = 0 (0x0)
open(".",O_NONBLOCK|0x20000,00) = 14 (0xe)
fstat(14,{ mode=drwx------ ,inode=28761,size=3,blksize=131072 }) = 0 (0x0)
fcntl(14,F_SETFD,FD_CLOEXEC) = 0 (0x0)
fstatfs(0xe,0x7fffffffd3a0,0x21c00400,0x29,0x61ff20,0x0) = 0 (0x0)
getdirentries(0xe,0x21c31000,0x1000,0x21c284e8,0x61ff20,0x0) = 52 (0x34)
unlink("dovecot.index.log") = 0 (0x0)
getdirentries(0xe,0x21c31000,0x1000,0x21c284e8,0x61ff20,0x0) = 0 (0x0)
close(13) = 0 (0x0)
lseek(14,0x0,SEEK_SET) = 0 (0x0)
close(14) = 0 (0x0)
fchdir(0xc,0x0,0x21c07400,0x28,0x61ff20,0x0) = 0 (0x0)
close(12) = 0 (0x0)
rmdir(0x21c18470,0x0,0x21c07400,0x28,0x61ff20,0x0) = 0 (0x0)
rmdir(0x21c184f0,0x4,0x21c18000,0x7af8,0xffffffffffdd6669,0x21c8c298) = 0 (0x0)
open("/mailstore/domains/test.com/test/mdbox/dovecot.mailbox.log",O_RDWR|O_APPEND,0125337603)
= 12 (0xc)
write(12,"\^A\0\0\0\M^L\M-M%\^E\M^F\M-b\^X"...,24) = 24 (0x18)
fstat(12,{ mode=-rw------- ,inode=28751,size=144,blksize=4096 }) = 0 (0x0)
rmdir(0x21c186d0,0x21e41eb8,0x21c186d0,0x7918,0xffffffffffdd6849,0x21c8c298)
ERR#2 'No such file or directory'
write(12,"\^B\0\0\0\M-Xb\M^JRY\M-I{x\M--C"...,24) = 24 (0x18)
fstat(12,{ mode=-rw------- ,inode=28751,size=168,blksize=4096 }) = 0 (0x0)
write(2,"\^A\^B6293 Mailbox deleted: Spam"...,29) = 29 (0x1d)
gettimeofday({1343808216.058749 },0x0) = 0 (0x0)
madvise(0x21e65000,0x1000,0x5,0x264,0x7fffffffcfa0,0xffffffff) = 0 (0x0)
madvise(0x21e63000,0x1000,0x5,0x262,0x7fffffffcfa0,0xffffffff) = 0 (0x0)
madvise(0x21e41000,0x2000,0x5,0x240,0x7fffffffcfa0,0xffffffff) = 0 (0x0)
madvise(0x21d8d000,0x4000,0x5,0x18c,0x7fffffffcfa0,0xffffffff) = 0 (0x0)
madvise(0x21c91000,0x2000,0x5,0x90,0x7fffffffcfa0,0xffffffff) = 0 (0x0)
gettimeofday({1343808216.059531 },0x0) = 0 (0x0)
getpid() = 6293 (0x1895)
__sysctl(0x7fffffffd830,0x4,0x0,0x0,0x21c8f000,0x23) = 0 (0x0)
write(11,"3 OK Delete completed.\r\n",24) = 24 (0x18)
gettimeofday({1343808216.060105 },0x0) = 0 (0x0)
Regard, Nikolai.
