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(test@test.com): Error: stat(/mailstore/domains/test.com/test/mdbox/mailboxes/Spam) failed: Operation not permitted Aug 1 20:03:36 msgsrv dovecot: imap(test@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.