Hi,
While trying to use the `sieve_script_bin_path` option to have Pigeonhole auto-create directories for compiled sieve scripts, I ran into some permission issues: "Error: sieve: binary /run/dovecot2/sieve/jasper/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after.svbin: save: failed to create temporary file: open(/run/dovecot2/sieve/jasper/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after.svbin.) failed: Permission denied (euid=986(dovemail) egid=985(dovemail) missing +w perm: /run/dovecot2/sieve/jasper, dir owner missing perms)"
I'm using `bin_path` like this: `sieve_script_bin_path = "/run/dovecot2/sieve/%{user|username|lower}";`
and the permissions of the `sieve` directory are as follows:
```
$ ls -lah sieve
total 0
drwxr-xrwx 3 root root 60 Jul 5 13:01 .
drwxr-xr-x 10 root root 780 Jul 5 13:00 ..
dr-xr-xr-x 2 dovemail dovemail 40 Jul 5 13:01 jasper
```
`strace`ing Dovecot shows that it uses `0555` when creating this directory (but not before setting `umask` to `000`?):
```
260940 newfstatat(AT_FDCWD</var/vmail/jappie.dev/jasper>, "/run/dovecot2/sieve/jasper", 0x7fff4306af00, 0) = -1 ENOENT (No such file or directory)
260940 umask(000) = 077
260940 mkdir("/run/dovecot2/sieve/jasper", 0555) = 0
260940 umask(077) = 000
```
I also tried patching Pigeonhole's source to log the value of `mode`:
```
diff --git a/src/lib-sieve/sieve-storage.c b/src/lib-sieve/sieve-storage.c
index e68fe39f..4c7a081f 100644
--- a/src/lib-sieve/sieve-storage.c
+++ b/src/lib-sieve/sieve-storage.c
@@ -887,6 +887,6 @@ int sieve_storage_setup_bin_path(struct sieve_storage *storage, mode_t mode)
if (mkdir_parents(bin_path, mode) == 0) {
e_debug(storage->event,
- "Created directory for binaries: %s", bin_path);
+ "Created directory for binaries: %s %u", bin_path, mode);
return 1;
}
```
and this logged `365`, which - if I understand `mode_t` correctly - corresponds to `-wxrw-r-x`:
```
Debug: sieve: storage after: file: Created directory for binaries: /run/dovecot2/sieve/jasper 365
```
Needless to say, I'm a little confused as to what's going on here - am I missing something or does this look like a Pigeonhole / Dovecot bug?
Kind regards,
- Jasper
Full log:
```
dovecot[260506]: lmtp(260940): Connect from local
dovecot[260506]: lmtp(260940): Debug: auth-master: passdb lookup(jasper(a)jappie.dev): Started passdb lookup
dovecot[260506]: lmtp(260940): Debug: auth-master: conn unix:/run/dovecot2/auth-userdb: Connecting
dovecot[260506]: lmtp(260940): Debug: auth-master: conn unix:/run/dovecot2/auth-userdb (pid=260501,uid=0): Client connected (fd=14)
dovecot[260506]: lmtp(260940): Debug: auth-master: conn unix:/run/dovecot2/auth-userdb (pid=260501,uid=0): auth input: user=jasper(a)jappie.dev
dovecot[260506]: lmtp(260940): Debug: auth-master: passdb lookup(jasper(a)jappie.dev): auth PASS input: user=jasper(a)jappie.dev
dovecot[260506]: lmtp(260940): Debug: auth-master: passdb lookup(jasper(a)jappie.dev): Finished passdb lookup (user=jasper(a)jappie.dev)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: auth-master: userdb lookup(jasper(a)jappie.dev): Started userdb lookup
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: auth-master: conn unix:/run/dovecot2/auth-userdb (pid=260501,uid=0): auth input: jasper(a)jappie.dev
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: auth-master: userdb lookup(jasper(a)jappie.dev): auth USER input: jasper(a)jappie.dev
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: auth-master: userdb lookup(jasper(a)jappie.dev): Finished userdb lookup (username=jasper(a)jappie.dev )
dovecot[260506]: lmtp(260940): Debug: Mailbox <lmtp DATA local>: Mailbox opened
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: Effective uid=986, gid=985, home=/var/vmail/jappie.dev/jasper
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: open(/proc/self/io) failed: Permission denied (euid=986(dovemail) egid=985(dovemail) missing +r perm: /proc/self/io)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: maildir++: root=/var/vmail/jappie.dev/jasper/mail, index=, indexpvt=, control=, inbox=/var/vmail/jappie.dev/jasper/mail, alt=
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: Mailbox <lmtp DATA local>: Adding field hdr.From to cache for the first time (uid=1)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: Mailbox <lmtp DATA local>: Adding field hdr.Message-ID to cache for the first time (uid=1)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: Mailbox <lmtp DATA local>: Adding field hdr.Return-Path to cache for the first time (uid=1)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: Mailbox <lmtp DATA local>: Adding field hdr.Subject to cache for the first time (uid=1)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: Mailbox <lmtp DATA local>: Adding field hdr.To to cache for the first time (uid=1)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: Local delivery started
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: duplicate db: Initialize
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: Pigeonhole version 2.4.0 (1b2d5bb9) initializing
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: storage after: file: Directory for binaries: /run/dovecot2/sieve/jasper
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: storage after: file: Using Sieve script path: /nix/store/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after.sieve
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: storage after: file: script '84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after': Opened from 'after'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: Using the following personal Sieve script: after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: multi-script: Start execute sequence
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: Opening script 1 of 1 from 'after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: Loading script after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: storage after: file: script '84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after': Opened script for reading
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: Script 'after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after' successfully compiled
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: storage after: file: Created directory for binaries: /run/dovecot2/sieve/jasper 365
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: storage after: file: script '84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after': Saving binary to '/run/dovecot2/sieve/jasper/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after.svbin'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Error: sieve: binary /run/dovecot2/sieve/jasper/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after.svbin: save: failed to create temporary file: open(/run/dovecot2/sieve/jasper/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after.svbin.) failed: Permission denied (euid=986(dovemail) egid=985(dovemail) missing +w perm: /run/dovecot2/sieve/jasper, dir owner missing perms)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: Executing script from 'after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: multi-script: Run script 'after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: Started running script 'after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: Finished running script 'after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after' (status=ok, resource usage: no usage recorded)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: multi-script: Execute result
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Executing result (status=ok, commit=no)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Starting execution of actions
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Executing actions
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Executed explicit keep
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finished executing actions (status=ok, keep=explicit, executed=no)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finished executing result (no commit, status=ok, keep=yes)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: multi-script: Sequence active
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: multi-script: Finishing sequence (status=ok)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Executing result (status=ok, commit=yes)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Starting execution of actions
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Executing actions
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finished executing actions (status=ok, keep=implicit, executed=no)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Found deferred keep action
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Execute implicit keep (status=ok)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Start storing into mailbox INBOX
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Executing implicit keep action
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Execute storing into mailbox 'INBOX'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: Mailbox INBOX: Mailbox opened
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Saving to mailbox 'INBOX' successful so far
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finished executing implicit keep action (status=ok)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finalizing actions
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finished finalizing actions (status=ok, keep=implicit, committed=no)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finalize implicit keep (status=ok)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finalize implicit keep action(status=ok, action_status=ok, commit_status=ok)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Commit implicit keep action
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Commit storing into mailbox 'INBOX'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: stored mail into mailbox 'INBOX'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finish implicit keep action
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finishing actions
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finished executing result (final, status=ok, keep=yes)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: multi-script: Sequence finished (status=ok, keep=yes)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: multi-script: Destroy
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: sieve: storage after: file: script '84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after': Closed script
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: duplicate db: Cleanup
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: Local delivery finished successfully
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>: Debug: User session is finished
dovecot[260506]: lmtp(260940): Disconnect from local: Logged out (state=READY)
dovecot[260506]: lmtp(260940): Debug: User session is finished
```
Hi,
While trying to use the `sieve_script_bin_path` option to have Pigeonhole auto-
create directories for compiled sieve scripts, I ran into some permission
issues: "Error: sieve: binary /run/dovecot2/sieve/jasper/
84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after.svbin: save: failed to create temporary
file: open(/run/dovecot2/sieve/jasper/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-
after.svbin.) failed: Permission denied (euid=986(dovemail) egid=985(dovemail)
missing +w perm: /run/dovecot2/sieve/jasper, dir owner missing perms)"
I'm using `bin_path` like this: `sieve_script_bin_path = "/run/dovecot2/sieve/%
{user|username|lower}";`
and the permissions of the `sieve` directory are as follows:
```
$ ls -lah sieve
total 0
drwxr-xrwx 3 root root 60 Jul 5 13:01 .
drwxr-xr-x 10 root root 780 Jul 5 13:00 ..
dr-xr-xr-x 2 dovemail dovemail 40 Jul 5 13:01 jasper
```
`strace`ing Dovecot shows that it uses `0555` when creating this directory (but
not before setting `umask` to `000`?):
```
260940 newfstatat(AT_FDCWD</var/vmail/jappie.dev/jasper>, "/run/dovecot2/sieve/
jasper", 0x7fff4306af00, 0) = -1 ENOENT (No such file or directory)
260940 umask(000) = 077
260940 mkdir("/run/dovecot2/sieve/jasper", 0555) = 0
260940 umask(077) = 000
```
I also tried patching Pigeonhole's source to log the value of `mode`:
```
diff --git a/src/lib-sieve/sieve-storage.c b/src/lib-sieve/sieve-storage.c
index e68fe39f..4c7a081f 100644
--- a/src/lib-sieve/sieve-storage.c
+++ b/src/lib-sieve/sieve-storage.c
@@ -887,6 +887,6 @@ int sieve_storage_setup_bin_path(struct sieve_storage
*storage, mode_t mode)
if (mkdir_parents(bin_path, mode) == 0) {
e_debug(storage->event,
- "Created directory for binaries: %s", bin_path);
+ "Created directory for binaries: %s %u", bin_path, mode);
return 1;
}
```
and this logged `365`, which - if I understand `mode_t` correctly - corresponds
to `-wxrw-r-x`:
```
Debug: sieve: storage after: file: Created directory for binaries: /run/
dovecot2/sieve/jasper 365
```
Needless to say, I'm a little confused as to what's going on here - am I
missing something or does this look like a Pigeonhole / Dovecot bug?
Kind regards,
- Jasper
Full log:
```
dovecot[260506]: lmtp(260940): Connect from local
dovecot[260506]: lmtp(260940): Debug: auth-master: passdb lookup
(jasper(a)jappie.dev) Started passdb lookup
dovecot[260506]: lmtp(260940): Debug: auth-master: conn unix:/run/dovecot2/
auth-userdb: Connecting
dovecot[260506]: lmtp(260940): Debug: auth-master: conn unix:/run/dovecot2/
auth-userdb (pid=260501,uid=0): Client connected (fd=14)
dovecot[260506]: lmtp(260940): Debug: auth-master: conn unix:/run/dovecot2/
auth-userdb (pid=260501,uid=0): auth input: user=jasper(a)jappie.dev
dovecot[260506]: lmtp(260940): Debug: auth-master: passdb lookup
(jasper(a)jappie.dev) auth PASS input: user=jasper(a)jappie.dev
dovecot[260506]: lmtp(260940): Debug: auth-master: passdb lookup
(jasper(a)jappie.dev) Finished passdb lookup (user=jasper(a)jappie.dev)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: auth-master: userdb lookup(jasper(a)jappie.dev): Started userdb lookup
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: auth-master: conn unix:/run/dovecot2/auth-userdb (pid=260501,uid=0):
auth input: jasper(a)jappie.dev
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: auth-master: userdb lookup(jasper(a)jappie.dev): auth USER input:
jasper(a)jappie.dev
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: auth-master: userdb lookup(jasper(a)jappie.dev): Finished userdb lookup
(username=jasper(a)jappie.dev )
dovecot[260506]: lmtp(260940): Debug: Mailbox <lmtp DATA local>: Mailbox opened
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: Effective uid=986, gid=985, home=/var/vmail/jappie.dev/jasper
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: open(/proc/self/io) failed: Permission denied (euid=986(dovemail)
egid=985(dovemail) missing +r perm: /proc/self/io)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: Namespace inbox: type=private, prefix=, sep=, inbox=yes, hidden=no,
list=yes, subscriptions=yes
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: maildir++: root=/var/vmail/jappie.dev/jasper/mail, index=, indexpvt=,
control=, inbox=/var/vmail/jappie.dev/jasper/mail, alt=
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: Mailbox <lmtp DATA local>: Adding field hdr.From to cache for the first
time (uid=1)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: Mailbox <lmtp DATA local>: Adding field hdr.Message-ID to cache for the
first time (uid=1)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: Mailbox <lmtp DATA local>: Adding field hdr.Return-Path to cache for the
first time (uid=1)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: Mailbox <lmtp DATA local>: Adding field hdr.Subject to cache for the
first time (uid=1)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: Mailbox <lmtp DATA local>: Adding field hdr.To to cache for the first
time (uid=1)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: Local delivery started
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: duplicate db: Initialize
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: Pigeonhole version 2.4.0 (1b2d5bb9) initializing
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: storage after: file: Directory for binaries: /run/dovecot2/sieve/
jasper
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: storage after: file: Using Sieve script path: /nix/store/
84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after.sieve
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: storage after: file: script '84lkfddk8d88ib7zh3zh6hmy5lrvn54x-
after': Opened from 'after'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: Using the following personal Sieve script: after/
84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: multi-script: Start execute sequence
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: Opening script 1 of 1 from 'after/
84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: Loading script after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: storage after: file: script '84lkfddk8d88ib7zh3zh6hmy5lrvn54x-
after': Opened script for reading
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: Script 'after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after'
successfully compiled
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: storage after: file: Created directory for binaries: /run/
dovecot2/sieve/jasper 365
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: storage after: file: script '84lkfddk8d88ib7zh3zh6hmy5lrvn54x-
after': Saving binary to '/run/dovecot2/sieve/jasper/
84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after.svbin'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Error: sieve: binary /run/dovecot2/sieve/jasper/
84lkfddk8d88ib7zh3zh6hmy5lrvn54x-after.svbin: save: failed to create temporary
file: open(/run/dovecot2/sieve/jasper/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-
after.svbin.) failed: Permission denied (euid=986(dovemail) egid=985(dovemail)
missing +w perm: /run/dovecot2/sieve/jasper, dir owner missing perms)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: Executing script from 'after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-
after'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: multi-script: Run script 'after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-
after'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: Started running script 'after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-
after'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: Finished running script 'after/84lkfddk8d88ib7zh3zh6hmy5lrvn54x-
after' (status=ok, resource usage: no usage recorded)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: multi-script: Execute result
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>:
Executing result (status=ok, commit=no)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Starting
execution of actions
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>:
Executing actions
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Executed
explicit keep
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finished
executing actions (status=ok, keep=explicit, executed=no)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finished
executing result (no commit, status=ok, keep=yes)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: multi-script: Sequence active
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: multi-script: Finishing sequence (status=ok)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>:
Executing result (status=ok, commit=yes)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Starting
execution of actions
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>:
Executing actions
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finished
executing actions (status=ok, keep=implicit, executed=no)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Found
deferred keep action
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Execute
implicit keep (status=ok)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Start
storing into mailbox INBOX
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>:
Executing implicit keep action
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Execute
storing into mailbox 'INBOX'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: Mailbox INBOX: Mailbox opened
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Saving
to mailbox 'INBOX' successful so far
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finished
executing implicit keep action (status=ok)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>:
Finalizing actions
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finished
finalizing actions (status=ok, keep=implicit, committed=no)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finalize
implicit keep (status=ok)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finalize
implicit keep action(status=ok, action_status=ok, commit_status=ok)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Commit
implicit keep action
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Commit
storing into mailbox 'INBOX'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: stored mail
into mailbox 'INBOX'
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finish
implicit keep action
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>:
Finishing actions
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: msgid=<E62D66EA-D095-4EBC-AFFE-640FB6824F45(a)jappie.dev>: Finished
executing result (final, status=ok, keep=yes)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: multi-script: Sequence finished (status=ok, keep=yes)
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: multi-script: Destroy
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: sieve: storage after: file: script '84lkfddk8d88ib7zh3zh6hmy5lrvn54x-
after': Closed script
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: duplicate db: Cleanup
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: Local delivery finished successfully
dovecot[260506]: lmtp(jasper(a)jappie.dev)<260940><3P0ZDyQGaWhM+wMAbxW+ag>:
Debug: User session is finished
dovecot[260506]: lmtp(260940): Disconnect from local: Logged out (state=READY)
dovecot[260506]: lmtp(260940): Debug: User session is finished
```