I have some global scripts that were running nicely.
Then I opened one in an editor and (probably, but not 100% sure) mindlessly saved the file, even though I hadn't made any changes.
Shortly after, Sieve errors started showing in the log:
Error: 4k5JA74R/1TlIwABG/SpMA: sieve: binary save: failed to create temporary file: open(/usr/local/var/dovecot/sieve/script2.svbin.example.com.4139.) failed: Permission denied... Error: 4k5JA74R/1TlIwABG/SpMA: sieve: The LDA Sieve plugin does not have permission to save global Sieve script binaries; global Sieve scripts like `/usr/local/var/dovecot/sieve/script2.sieve' need to be pre-compiled using the sievec tool
Well, OK, is it going by the timestamp on the files? Fine. I recompiled it by hand. Yet, I STILL got these errors!
I triple and quadruple checked that the timestamp on the svbin files was more recent. And Sieve was only complaining about one of the two scripts in the directory.
I restarted dovecot. No change.
So I removed read permission on the .sieve files and only left read permission on the .svbin files. THIS WORKED. No more error. I can live with that, but why was it not complaining before, why was it only complaining about one of my scripts and why would it complain at all when the timestamps on the svbin should have indicated on compilation is needed?
I've heard about this problem before. Do you have the opportunity to test this with the 0.4.7.rc1 release? That adds a few extra debug lines (shown when mail_debug=yes) that would indicate why Sieve is thinking the global script is not up-to-date.
Yes, I do as a matter of fact. I was just going to put in the RC in order to answer your email on the thread about the RC. Don't have the full answers yet, but when I installed the RC and restarted, I now get an error where Sieve doesn't like that I won't give it read permission on the .sieve file, so now I'm back to square one with this particular issue.
OTOH, regarding my earlier post about the RC ignoring seive files, at least it is seeing global scripts (or trying to). Not sure about personal scripts yet.
Error: TiQJHH2X/1S5UuAAM/SpMA: sieve: file script: Failed to open sieve script: open(/usr/local/var/dovecot/sieve/script1.sieve) failed: Permission denied...
I will do some more testing and report what I find.
I gave read permission to the .sieve files and the same original error happens as with .0.4.6. Now it's complaining about both scripts in my global directory. That it was working without these errors for a while and then complained only about one of the scripts, now both scripts seems to say something but I'm not sure what. Maybe I'll try to recreate the files for fun.
The relevant mail_debug lines seem to be these:
dovecot: lmtp(testuser <at> example.com): Debug: Be3h7iRf/1TnUw2PM/SpMA: sieve: Opening script 1 of 2 from
/usr/local/var/dovecot/sieve/script1.sieve' dovecot: lmtp(testuser <at> example.com): Debug: Be3h7iRf/1TnUw2PM/SpMA: sieve: Loading script /usr/local/var/dovecot/sieve/script1.sieve dovecot: lmtp(testuser <at> example.com): Debug: Be3h7iRf/1TnUw2PM/SpMA: sieve: binary open: binary /usr/local/var/dovecot/sieve/script1.svbin stored with different binary version 1.2 (!= 1.3; automatically fixed when re-compiled) dovecot: lmtp(testuser <at> example.com): Debug: Be3h7iRf/1TnUw2PM/SpMA: sieve: Scriptscript1' from /usr/local/var/dovecot/sieve/script1.sieve successfully compiledIs this possibly due to a mixing of 0.4.6 and 0.4.7 sievec command? Well, I'm not sure that would be it because when I started getting ther error, I recompiled the sieve scrips and restarted dovecot which presumably would have made software versions match up.
On the other hand, I don't know exactly what's happening: I downgraded to 0.4.6 again, intentionally triggered the error by updating the timestamp on the .sieve file, recompiled the script and now the error went away.
After editing one of the global scripts (and compiling it), I am able to get the error back again (and not able to get it to go away). The previous log info I found may have been unrelated and more to do with haivng switched to 0.4.7 without recompiling the scripts.
I'm back with 0.4.6 and the only thing I see in the log now is this:
Debug: lRgL3tO1/1RvOyA6M/SpMA: sieve: Script binary /usr/local/var/dovecot/sieve/script2.svbin is not up-to-date Debug: lRgL3tO1/1RvOyA6M/SpMA: sieve: Script `script2' from /usr/local/var/dovecot/sieve/script2.sieve successfully compiled Error: lRgL3tO1/1RvOyA6M/SpMA: sieve: binary save: failed to create temporary file: open(...
All I can think is that when I initially triggered the error, I noticed that I exited my editor and compiled the script within the *same minute* thus creating timestamps that were equal when compared without seconds. But now, even after recompiling to get a much later timestamp on the binary, I can't get the error to go away.
I upgraded to 0.4.7, and re-compiled one of my two scripts in the same way (during the same minute), and indeed, the first script (that I DID NOT recompile) gets the previous error I saw with the mismatched binary version notice -- that seems irrelevant then, only reltaed to the upgrade.
The script that I did recompile (during the same minute as I saved it) after upgrading causes the same error, so the bug seems consistent across versions. However, there is one additional debug line in version 0.4.7:
sieve: binary up-to-date: script metadata indicates that binary /usr/local/var/dovecot/sieve/script2.svbin is not up-to-date
Doesn't say which metadata.
Downgraded back to 0.4.6, deleted the svbin files, compiled again, and now the error persists. Tried deleting the .sieve source files, re-created them, waited until the next minute, compiled them. Error still in logs. Not sure how I got it to go away last time. Something being cached somewhere?