Why is Sieve trying to re-compile global scripts?

E.B. emailbuilder88 at yahoo.com
Wed Mar 11 04:25:44 UTC 2015


> > > > > 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: Script `script1' from
> /usr/local/var/dovecot/sieve/script1.sieve successfully compiled
>
> Is 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?



More information about the dovecot mailing list