dovecot - Sep 2018 - v2.3.3 rc1 - Error: sieve: !!BUG!!: Binary compiled from dovecot.sieve is still corrupt

On 24/09/2018 13:35, Stephan Bosch wrote:
> You can enable `-d -' and `-t - -Tlevel=matching' as well.
$ sieve-test -D -d - -t - -Tlevel=matching -c dovecot.conf sieve message
sieve-test(james): Debug: Effective uid=1001, gid=10, home=/home/james
sieve-test(james): Debug: maildir++: root=/path/to//james/Maildir, 
index=, indexpvt=, control=, inbox=/path/to//james/Maildir,
altsieve-test(james): Debug: sieve: Pigeonhole version 0.5.2 (7704de5e)
initializing
sieve-test(james): Debug: sieve: include: sieve_global is not set; it is 
currently not possible to include `:global' scripts.
debug: file storage: Using Sieve script path: /home/james/sieve.
debug: file script: Opened script `sieve' from `/home/james/sieve'.
debug: Script `sieve' from /home/james/sieve successfully compiled.

* Script metadata (block: 0):

class = file
class.version = 0
location = /home/james/sieve

* Required extensions (block: 1):

   0: vacation (id: 9)

* Main program (block: 2):

Address   Line  Code
00000000:       DEBUG BLOCK: 3
00000001:       EXTENSIONS [1]:
00000002:         vacation
00000004:    2: VACATION
00000007:    4:   seconds: NUM 5
00000009:         Binary is corrupt.


       ## Started executing script 'sieve'
       VACATION: #ERROR#: unknown optional operand
    2: [[EXECUTION ABORTED]]
       ## Finished executing script 'sieve'

sieve-test(james): Info: corrupt binary deleted.
sieve-test(james): Error: unlink((null)) failed: Bad address (in 
sieve-test.c:426)
sieve-test(james): Info: final result: failed; resolved with successful 
implicit keep

Ok, will fix...


Op 24-9-2018 om 15:06 schreef James:
> On 24/09/2018 13:35, Stephan Bosch wrote:
>
>> You can enable `-d -' and `-t - -Tlevel=matching' as well.
>
> $ sieve-test -D -d - -t - -Tlevel=matching -c dovecot.conf sieve message
> sieve-test(james): Debug: Effective uid=1001, gid=10, home=/home/james
> sieve-test(james): Debug: maildir++: root=/path/to//james/Maildir, 
> index=, indexpvt=, control=, inbox=/path/to//james/Maildir, alt>
sieve-test(james): Debug: sieve: Pigeonhole version 0.5.2 (7704de5e)
> initializing
> sieve-test(james): Debug: sieve: include: sieve_global is not set; it 
> is currently not possible to include `:global' scripts.
> debug: file storage: Using Sieve script path: /home/james/sieve.
> debug: file script: Opened script `sieve' from `/home/james/sieve'.
> debug: Script `sieve' from /home/james/sieve successfully compiled.
>
> * Script metadata (block: 0):
>
> class = file
> class.version = 0
> location = /home/james/sieve
>
> * Required extensions (block: 1):
>
> ? 0: vacation (id: 9)
>
> * Main program (block: 2):
>
> Address?? Line? Code
> 00000000:?????? DEBUG BLOCK: 3
> 00000001:?????? EXTENSIONS [1]:
> 00000002:???????? vacation
> 00000004:??? 2: VACATION
> 00000007:??? 4:?? seconds: NUM 5
> 00000009:???????? Binary is corrupt.
>
>
> ????? ## Started executing script 'sieve'
> ????? VACATION: #ERROR#: unknown optional operand
> ?? 2: [[EXECUTION ABORTED]]
> ????? ## Finished executing script 'sieve'
>
> sieve-test(james): Info: corrupt binary deleted.
> sieve-test(james): Error: unlink((null)) failed: Bad address (in 
> sieve-test.c:426)
> sieve-test(james): Info: final result: failed; resolved with 
> successful implicit keep
>

Hi,

Something mightily weird is going on at your end. It doesn't fail here 
(see below). First of all, what is your configuration (output from 
`dovecot -n`)?

Also, can you make a hex dump of the binary (using `sieve-dump -h 
<your-script-binary>.svbin`). See below for an example at my end.

Finally, can you try to explicitly delete the binary (preferably after 
preserving it elsewhere) so that it is guaranteed to be created fresh? 
That should not matter, but you never know.

## Success at my end:

$ sieve-test -D -d - -t - -Tlevel=matching ~/frop.sieve ~/message.eml
sieve-test(stephan)<27390><>: Debug: Loading modules from directory:
/usr/lib/dovecot/modules
sieve-test(stephan)<27390><>: Debug: Module loaded: 
/usr/lib/dovecot/modules/lib01_acl_plugin.so
sieve-test(stephan)<27390><>: Debug: Module loaded: 
/usr/lib/dovecot/modules/lib20_virtual_plugin.so
sieve-test(stephan): Debug: Effective uid=1000, gid=1000, home=/home/stephan
sieve-test(stephan): Debug: acl: No acl_shared_dict setting - shared 
mailbox listing is disabled
sieve-test(stephan): Debug: Namespace inbox: type=private, 
prefix=INBOX/, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes 
location=maildir:~/Maildir
sieve-test(stephan): Debug: maildir++: root=/home/stephan/Maildir, 
index=, indexpvt=, control=, inbox=/home/stephan/Maildir,
altsieve-test(stephan): Debug: acl: initializing backend with data: vfile
sieve-test(stephan): Debug: acl: acl username = stephan
sieve-test(stephan): Debug: acl: owner = 1
sieve-test(stephan): Debug: acl vfile: Global ACLs disabled
sieve-test(stephan): Debug: Namespace : type=private, prefix=Archive/, 
sep=/, inbox=no, hidden=no, list=yes, subscriptions=yes 
location=maildir:~/MailArchive
sieve-test(stephan): Debug: maildir++: root=/home/stephan/MailArchive, 
index=, indexpvt=, control=, inbox=, altsieve-test(stephan): Debug: acl:
initializing backend with data: vfile
sieve-test(stephan): Debug: acl: acl username = stephan
sieve-test(stephan): Debug: acl: owner = 1
sieve-test(stephan): Debug: acl vfile: Global ACLs disabled
sieve-test(stephan): Debug: Namespace : type=public, prefix=Public/, 
sep=/, inbox=no, hidden=no, list=yes, subscriptions=no 
location=maildir:/var/mail/public
sieve-test(stephan): Debug: maildir++: root=/var/mail/public, index=, 
indexpvt=, control=, inbox=, altsieve-test(stephan): Debug: acl: initializing
backend with data: vfile
sieve-test(stephan): Debug: acl: acl username = stephan
sieve-test(stephan): Debug: acl: owner = 0
sieve-test(stephan): Debug: acl vfile: Global ACLs disabled
sieve-test(stephan): Debug: Namespace : type=private, prefix=virtual/, 
sep=/, inbox=no, hidden=no, list=yes, subscriptions=yes 
location=virtual:~/Maildir/virtual
sieve-test(stephan): Debug: fs: root=/home/stephan/Maildir/virtual, 
index=, indexpvt=, control=, inbox=, altsieve-test(stephan): Debug: acl:
initializing backend with data: vfile
sieve-test(stephan): Debug: acl: acl username = stephan
sieve-test(stephan): Debug: acl: owner = 1
sieve-test(stephan): Debug: acl vfile: Global ACLs disabled
sieve-test(stephan): Debug: Namespace : type=private, prefix=, sep=, 
inbox=no, hidden=yes, list=no, subscriptions=no location=fail::LAYOUT=none
sieve-test(stephan): Debug: none: root=, index=, indexpvt=, control=, 
inbox=, altsieve-test(stephan): Debug: sieve: Pigeonhole version 0.5.3.rc1 
(b29d6a24) initializing
sieve-test(stephan): Debug: sieve: Sieve imapsieve plugin for Pigeonhole 
version 0.5.3.rc1 (b29d6a24) loaded
sieve-test(stephan): Debug: sieve: Sieve Extprograms plugin for 
Pigeonhole version 0.5.3.rc1 (b29d6a24) loaded
sieve-test(stephan): Debug: sieve: vnd.dovecot.pipe extension: no bin or 
socket directory specified; extension is unconfigured (both 
sieve_pipe_bin_dir and sieve_pipe_socket_dir are not set)
sieve-test(stephan): Debug: sieve: vnd.dovecot.filter extension: no bin 
or socket directory specified; extension is unconfigured (both 
sieve_filter_bin_dir and sieve_filter_socket_dir are not set)
debug: file storage: Using Sieve script path: /home/stephan/frop.sieve.
debug: file script: Opened script `frop' from
`/home/stephan/frop.sieve'.
debug: binary save: not saving binary /home/stephan/frop.svbin, because 
it is already stored.

* Script metadata (block: 0):

class = file
class.version = 0
location = /home/stephan/frop.sieve

* Required extensions (block: 1):

 ? 0: vacation (id: 9)

* Main program (block: 2):

Address?? Line? Code
00000000:?????? DEBUG BLOCK: 3
00000001:?????? EXTENSIONS [1]:
00000002:???????? vacation
00000004:??? 3: VACATION
00000007:??? 5:?? seconds: NUM 86400
0000000c:??? 6:?? subject: STR[19] "Out of office reply"
00000023:?? 10:?? addresses: STRLIST [2] (end: 00000054)
00000029:?????????? STR[17] "j.doe at company.dom"
0000003d:?????????? STR[20] "john.doe at company.dom"
00000055:?? 11:?? reason: STR[75] "I'm out of office, please contact 
Joan Doe instead.??Best regards??John Doe"
000000a3:??? 3:?? handle: STR[117] "I'm out of office, please contact 
Joan Doe instead.??Best regards??John DoeOu...
0000011b:??? 3: [End of code]

sieve-test(stephan): Debug: acl: No acl_shared_dict setting - shared 
mailbox listing is disabled
sieve-test(stephan): Debug: none: root=, index=, indexpvt=, control=, 
inbox=, altsieve-test(stephan): Debug: Mailbox /home/stephan/message.eml: Opened
mail UID=1 because: header Message-ID (Cache file is unusable)
sieve-test(stephan): Debug: Mailbox /home/stephan/message.eml: Opened 
mail UID=1 because: header Sender (Cache file is unusable)
sieve-test(stephan): Debug: Mailbox /home/stephan/message.eml: Opened 
mail UID=1 because: header Envelope-To (Cache file is unusable)
sieve-test(stephan): Debug: Mailbox /home/stephan/message.eml: Opened 
mail UID=1 because: header To (Cache file is unusable)

 ????? ## Started executing script 'frop'
 ?? 3: vacation action
 ?? 3:?? auto-reply with message `I'm out of office, please contact Joan 
Doe instead.??Best regards??John Doe'
 ????? ## Finished executing script 'frop'


Performed actions:

 ?* send vacation message:
 ??? => seconds : 86400
 ??? => subject : Out of office reply
 ??? => handle? : I'm out of office, please contact Joan Doe instead.
Best regards
John DoeOut of office reply<default-from><NO-MIME>

START MESSAGE
I'm out of office, please contact Joan Doe instead.
Best regards
John Doe
END MESSAGE

Implicit keep:

 ?* store message in folder: INBOX

sieve-test(stephan): Info: final result: success


## Binary hex dump:


$ sieve-dump -h ~/frop.svbin
sieve-dump(stephan)<27527><>: Debug: Loading modules from directory:
/usr/lib/dovecot/modules
sieve-dump(stephan)<27527><>: Debug: Module loaded: 
/usr/lib/dovecot/modules/lib01_acl_plugin.so
sieve-dump(stephan)<27527><>: Debug: Module loaded: 
/usr/lib/dovecot/modules/lib20_virtual_plugin.so
sieve-dump(stephan): Debug: Effective uid=1000, gid=1000, home=/home/stephan
sieve-dump(stephan): Debug: acl: No acl_shared_dict setting - shared 
mailbox listing is disabled

* Binary blocks (count: 4):

 ? 0: size: 33 bytes
 ? 1: size: 13 bytes
 ? 2: size: 283 bytes
 ? 3: size: 26 bytes

* Block 0 (33 bytes, file offset 00000054):

00000000? 04 66 69 6c 65 00 00 18? 2f 68 6f 6d 65 2f 73 74 
|.file.../home/st|
00000010? 65 70 68 61 6e 2f 66 72? 6f 70 2e 73 69 65 76 65 
|ephan/frop.sieve|
00000020? 00??????????????????????????????????????????????? |.|
00000021

* Block 1 (13 bytes, file offset 00000080):

00000000? 01 08 76 61 63 61 74 69? 6f 6e 00 00 00 |..vacation...|
0000000d

* Block 2 (283 bytes, file offset 00000098):

00000000? 03 01 00 00 0d 00 01 01? 85 a3 00 02 02 13 4f 75 
|..............Ou|
00000010? 74 20 6f 66 20 6f 66 66? 69 63 65 20 72 65 70 6c? |t of office 
repl|
00000020? 79 00 04 03 00 00 00 30? 02 02 11 6a 2e 64 6f 65 
|y......0...j.doe|
00000030? 40 63 6f 6d 70 61 6e 79? 2e 64 6f 6d 00 02 14 6a 
|@company.dom...j|
00000040? 6f 68 6e 2e 64 6f 65 40? 63 6f 6d 70 61 6e 79 2e 
|ohn.doe at company.|
00000050? 64 6f 6d 00 00 02 4b 49? 27 6d 20 6f 75 74 20 6f |dom...KI'm 
out o|
00000060? 66 20 6f 66 66 69 63 65? 2c 20 70 6c 65 61 73 65? |f office, 
please|
00000070? 20 63 6f 6e 74 61 63 74? 20 4a 6f 61 6e 20 44 6f? | contact 
Joan Do|
00000080? 65 20 69 6e 73 74 65 61? 64 2e 0d 0a 42 65 73 74? |e 
instead...Best|
00000090? 20 72 65 67 61 72 64 73? 0d 0a 4a 6f 68 6e 20 44? | 
regards..John D|
000000a0? 6f 65 00 02 75 49 27 6d? 20 6f 75 74 20 6f 66 20 |oe..uI'm out 
of |
000000b0? 6f 66 66 69 63 65 2c 20? 70 6c 65 61 73 65 20 63 |office, 
please c|
000000c0? 6f 6e 74 61 63 74 20 4a? 6f 61 6e 20 44 6f 65 20 |ontact Joan 
Doe |
000000d0? 69 6e 73 74 65 61 64 2e? 0d 0a 42 65 73 74 20 72 
|instead...Best r|
000000e0? 65 67 61 72 64 73 0d 0a? 4a 6f 68 6e 20 44 6f 65 |egards..John 
Doe|
000000f0? 4f 75 74 20 6f 66 20 6f? 66 66 69 63 65 20 72 65? |Out of 
office re|
00000100? 70 6c 79 3c 64 65 66 61? 75 6c 74 2d 66 72 6f 6d 
|ply<default-from|
00000110? 3e 3c 4e 4f 2d 4d 49 4d? 45 3e 00 |><NO-MIME>.|
0000011b

* Block 3 (26 bytes, file offset 000001bc):

00000000? 17 00 12 00 19 00 02 04? 01 17 00 1c 00 54 00 65 
|.............T.e|
00000010? 00 02 8f ff ff ff 78 01? 4e 00 |......x.N.|
0000001a

Regards,


Stephan.


Op 24/09/2018 om 15:06 schreef James:
> On 24/09/2018 13:35, Stephan Bosch wrote:
>
>> You can enable `-d -' and `-t - -Tlevel=matching' as well.
>
> $ sieve-test -D -d - -t - -Tlevel=matching -c dovecot.conf sieve message
> sieve-test(james): Debug: Effective uid=1001, gid=10, home=/home/james
> sieve-test(james): Debug: maildir++: root=/path/to//james/Maildir, 
> index=, indexpvt=, control=, inbox=/path/to//james/Maildir, alt>
sieve-test(james): Debug: sieve: Pigeonhole version 0.5.2 (7704de5e)
> initializing
> sieve-test(james): Debug: sieve: include: sieve_global is not set; it 
> is currently not possible to include `:global' scripts.
> debug: file storage: Using Sieve script path: /home/james/sieve.
> debug: file script: Opened script `sieve' from `/home/james/sieve'.
> debug: Script `sieve' from /home/james/sieve successfully compiled.
>
> * Script metadata (block: 0):
>
> class = file
> class.version = 0
> location = /home/james/sieve
>
> * Required extensions (block: 1):
>
> ? 0: vacation (id: 9)
>
> * Main program (block: 2):
>
> Address?? Line? Code
> 00000000:?????? DEBUG BLOCK: 3
> 00000001:?????? EXTENSIONS [1]:
> 00000002:???????? vacation
> 00000004:??? 2: VACATION
> 00000007:??? 4:?? seconds: NUM 5
> 00000009:???????? Binary is corrupt.
>
>
> ????? ## Started executing script 'sieve'
> ????? VACATION: #ERROR#: unknown optional operand
> ?? 2: [[EXECUTION ABORTED]]
> ????? ## Finished executing script 'sieve'
>
> sieve-test(james): Info: corrupt binary deleted.
> sieve-test(james): Error: unlink((null)) failed: Bad address (in 
> sieve-test.c:426)
> sieve-test(james): Info: final result: failed; resolved with 
> successful implicit keep
>

On 25/09/2018 22:39, Stephan Bosch wrote:
> Something mightily weird is going on at your end. It doesn't fail here
> (see below). First of all, what is your configuration (output from
> `dovecot -n`)?
You have dovecot.conf but...

$ dovecot -c dovecot.conf -n
# 2.3.3.rc1 (14e4920d8): dovecot.conf
# Pigeonhole version 0.5.2 (7704de5e)
# OS: SunOS 5.11 i86pc
# Hostname: mailhost
doveconf: Warning: please set ssl_dh=</etc/opt/xxx/dovecot/dh.pem
doveconf: Warning: You can generate it with: dd 
if=/var/opt/xxx/lib/dovecot/ssl-parameters.dat bs=1 skip=88 | openssl 
dhparam -inform der > /etc/opt/xxx/dovecot/dh.pem
mail_debug = yes
mail_gid = staff
mail_location = maildir:/path/to/%d/%n/Maildir
mail_uid = james
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope 
encoded-character vacation subaddress comparator-i;ascii-numeric 
relational regex imap4flags copy include variables body enotify 
environment mailbox date index ihave duplicate mime foreverypart extracttext
postmaster_address = postmaster at domain.tld
ssl_dh = # hidden, use -P to show it


> Also, can you make a hex dump of the binary (using `sieve-dump -h
> <your-script-binary>.svbin`).
As said the svbin is identical to the one create by the previous version.

Comparing the dump:
Block 0 differs because it has the source file name.
Block 1 is identical
Block 2 is identical. It is this block that is declared corrupt.


> Finally, can you try to explicitly delete the binary (preferably after
> preserving it elsewhere) so that it is guaranteed to be created fresh?
I did each time.


> ## Success at my end:
Spot the difference...
> Address   Line  Code
> 00000000:       DEBUG BLOCK: 3
> 00000001:       EXTENSIONS [1]:
> 00000002:         vacation
> 00000004:    3: VACATION
> 00000007:    5:   seconds: NUM 86400
Address   Line  Code
00000000:       DEBUG BLOCK: 3
00000001:       EXTENSIONS [1]:
00000002:         vacation
00000004:    2: VACATION
00000007:    4:   seconds: NUM 5
00000009:         Binary is corrupt.

The line numbers differs and 86400 is read as 5.  It is like it has 
forgotten the size of an integer or is confused about endianness.  There 
is something strange, like an #if that guesses wrong.  At least I have 
somewhere to start looking.

Thank you for checking at your end, I was worried the RC had introduced 
an error and your result suggests not.  RCs are for testing and I am.

On 25/09/2018 22:39, Stephan Bosch wrote:

Hello,
> Something mightily weird is going on at your end. It doesn't fail here
This is correct.  I believe there to be a compiler problem.  Removing 
optimisation from sieve-binary-code.c gives success.

Thank you to Stephan Bosch for testing this for me and pointing me in 
the right direction.

My debugging was confused because dovecot flags are passed to 
pigeonhole, eg $DOVECOT_CFLAGS.  This is why the build of dovecot 
affects pigeonhole.  Once I removed these I could control the pigeonhole 
build and I was able to isolate the problem.



James.