bug report: Dovecot sieve error logged when timestamp of `.svbin` is shared with `.sieve` source file

### 📝 Preliminary Checks

- [X] I tried searching for an existing issue and followed the [debugging docs](https://docker-mailserver.github.io/docker-mailserver/latest/config/debugging/) advice, but still need assistance.

### 👀 What Happened?

- Dovecot attempts to use the `.svbin` that was compiled during startup, but notices it is "outdated" since it has the same timestamp as the `.sieve` file.
- Dovecot then compiles it again, and attempts to write the new compiled binary to the global dir but fails due to lack of permissions (_[this is expected](https://doc.dovecot.org/configuration_manual/sieve/usage/#manually-compiling-sieve-scripts), the vmail user should not have write access to this location_).
- Errors are logged and it continues to run the compiled binary successfully.

### 👟 Reproduction Steps

Failure seems to occur during this part of startup when the files share the same timestamp between `.sieve` and `.svbin` extensions:

https://github.com/docker-mailserver/docker-mailserver/blob/bd96c1161e9f9b32bb0b3aaec4b930980a56945f/target/scripts/startup/setup.d/dovecot.sh#L79-L81

In the `dovecot_sieve.bats` test, these two emails trigger a `before` + `after` global sieve scripts:

https://github.com/docker-mailserver/docker-mailserver/blob/89cb6d85b90f6070d53c15e455ebee916c899c7a/test/tests/parallel/set1/dovecot/dovecot_sieve.bats#L28-L31

```console
# Failure due to identical timestamps between `.sieve` + `.svbin`:
$ ls -l --time-style full-iso /usr/lib/dovecot/sieve-global/before/
-rw-r--r-- 1 dovecot root 107 2023-09-30 03:40:18.188085494 +0000 50-before.dovecot.sieve
-rw-r--r-- 1 dovecot root 309 2023-09-30 03:40:18.188085494 +0000 50-before.dovecot.svbin
$ ls -l --time-style full-iso /usr/lib/dovecot/sieve-global/after
-rw-r--r-- 1 dovecot root 149 2023-09-30 03:40:18.208085480 +0000 spam_to_junk.sieve
-rw-r--r-- 1 dovecot root 329 2023-09-30 03:40:18.208085480 +0000 spam_to_junk.svbin

# No failure (`.svbin` is newer):
$ ls -l --time-style full-iso /usr/lib/dovecot/sieve-global/before/
-rw-r--r-- 1 dovecot root 107 2023-09-30 03:39:05.725548197 +0000 50-before.dovecot.sieve
-rw-r--r-- 1 dovecot root 309 2023-09-30 03:39:05.735548158 +0000 50-before.dovecot.svbin
$ ls -l --time-style full-iso /usr/lib/dovecot/sieve-global/after
-rw-r--r-- 1 dovecot root 149 2023-09-30 03:39:05.745548110 +0000 spam_to_junk.sieve
-rw-r--r-- 1 dovecot root 329 2023-09-30 03:39:05.755548059 +0000 spam_to_junk.svbin
```

Multiple runs of a test like [`vmail-id.bats`](https://github.com/docker-mailserver/docker-mailserver/blob/bd96c1161e9f9b32bb0b3aaec4b930980a56945f/test/tests/serial/vmail-id.bats#L54-L55) could be run before it was caught on my system. Other times it would occur frequently. Perhaps the system is a bit too fast (_Ryzen 7940HS + NVMe disk_), or WSL2 influenced the files being updated with the same timestamp 🤷‍♂️ 

---

I also observed a related failure with this part of the `rspamd_full.bats`:

https://github.com/docker-mailserver/docker-mailserver/blob/bd96c1161e9f9b32bb0b3aaec4b930980a56945f/test/tests/parallel/set1/spam_virus/rspamd_full.bats#L269-L271

Logs are shared below where the above snippet of the test is checking the logs for these:

https://github.com/docker-mailserver/docker-mailserver/blob/bd96c1161e9f9b32bb0b3aaec4b930980a56945f/test/tests/parallel/set1/spam_virus/rspamd_full.bats#L252-L258

I'm not sure why the `rspamd_full.bats` tests `mail.log` file had `Debug:` log entries. I wasn't able to reproduce those with the `dovecot_sieve.bats` test when inspecting `mail.log`, only the `Error:` log lines would show.

### 🐋 DMS Version

edge (will become v13)

### 💻 Operating System and Architecture

Linux Kernel 5.15.123 - WSL2 x86_64 (Windows with Ubuntu 22.04)

### ⚙️ Container configuration files

```yml
I only used the existing test suite. Logs provide the command used to run them
```


### 📜 Relevant log output

```Text
$ NAME=mailserver-testing:ci make test/dovecot_sieve
# dovecot_sieve.bats failure (with added test-case to grep for error from `vmail-id.bats`), logs:

Sep 30 03:15:15 mail dovecot: lmtp(user1@localhost.localdomain)<750><ZhTCH8OSF2XuAgAAUi6ngw>: Error: sieve: binary /usr/lib/dovecot/sieve-global/before/50-before.dovecot.svbin: save: failed to create temporary file: open(/usr/lib/dovecot/sieve-global/before/50-before.dovecot.svbin.) failed: Permission denied (euid=9042(docker) egid=9042(docker) missing +w perm: /usr/lib/dovecot/sieve-global/before, dir owned by 110:0 mode=0755)
Sep 30 03:15:15 mail dovecot: lmtp(user1@localhost.localdomain)<750><ZhTCH8OSF2XuAgAAUi6ngw>: Error: sieve: The LDA Sieve plugin does not have permission to save global Sieve script binaries; global Sieve scripts like `/usr/lib/dovecot/sieve-global/before/50-before.dovecot.sieve' need to be pre-compiled using the sievec tool
Sep 30 03:15:15 mail dovecot: lmtp(user2@otherdomain.tld)<750><kFy1K8OSF2XuAgAAUi6ngw>: Error: sieve: binary /usr/lib/dovecot/sieve-global/before/50-before.dovecot.svbin: save: failed to create temporary file: open(/usr/lib/dovecot/sieve-global/before/50-before.dovecot.svbin.) failed: Permission denied (euid=9042(docker) egid=9042(docker) missing +w perm: /usr/lib/dovecot/sieve-global/before, dir owned by 110:0 mode=0755)
Sep 30 03:15:15 mail dovecot: lmtp(user2@otherdomain.tld)<750><kFy1K8OSF2XuAgAAUi6ngw>: Error: sieve: The LDA Sieve plugin does not have permission to save global Sieve script binaries; global Sieve scripts like `/usr/lib/dovecot/sieve-global/before/50-before.dovecot.sieve' need to be pre-compiled using the sievec tool
Sep 30 03:15:15 mail dovecot: lmtp(user2@otherdomain.tld)<750><kFy1K8OSF2XuAgAAUi6ngw>: Error: sieve: binary /usr/lib/dovecot/sieve-global/after/spam_to_junk.svbin: save: failed to create temporary file: open(/usr/lib/dovecot/sieve-global/after/spam_to_junk.svbin.) failed: Permission denied (euid=9042(docker) egid=9042(docker) missing +w perm: /usr/lib/dovecot/sieve-global/after, dir owned by 110:0 mode=0755)
Sep 30 03:15:15 mail dovecot: lmtp(user2@otherdomain.tld)<750><kFy1K8OSF2XuAgAAUi6ngw>: Error: sieve: The LDA Sieve plugin does not have permission to save global Sieve script binaries; global Sieve scripts like `/usr/lib/dovecot/sieve-global/after/spam_to_junk.sieve' need to be pre-compiled using the sievec tool


$ make test/rspamd_full
# Failure logs output from the `RSPAMD_LEARN works` test-case:

Sep 30 02:39:42 mail dovecot: lmtp(user1@localhost.localdomain)<1032><iLMABm6KF2UIBAAAUi6ngw>: Debug: sieve: Loading script /usr/lib/dovecot/sieve-global/after/spam_to_junk.sieve
Sep 30 02:39:42 mail dovecot: lmtp(user1@localhost.localdomain)<1032><iLMABm6KF2UIBAAAUi6ngw>: Debug: sieve: file storage: script: Sieve binary `/usr/lib/dovecot/sieve-global/after/spam_to_junk.svbin' is not newer than the Sieve script `/usr/lib/dovecot/sieve-global/after/spam_to_junk.sieve' (2023-09-30 02:39:26.331550613 <= 2023-09-30 02:39:26.331550613)
Sep 30 02:39:42 mail dovecot: lmtp(user1@localhost.localdomain)<1032><iLMABm6KF2UIBAAAUi6ngw>: Debug: sieve: binary /usr/lib/dovecot/sieve-global/after/spam_to_junk.svbin: up-to-date: script metadata indicates that binary is not up-to-date
Sep 30 02:39:42 mail dovecot: lmtp(user1@localhost.localdomain)<1032><iLMABm6KF2UIBAAAUi6ngw>: Debug: sieve: Script binary /usr/lib/dovecot/sieve-global/after/spam_to_junk.svbin is not up-to-date
Sep 30 02:39:42 mail dovecot: lmtp(user1@localhost.localdomain)<1032><iLMABm6KF2UIBAAAUi6ngw>: Debug: sieve: file storage: script: Opened script for reading
Sep 30 02:39:42 mail dovecot: lmtp(user1@localhost.localdomain)<1032><iLMABm6KF2UIBAAAUi6ngw>: Debug: sieve: Script `spam_to_junk' from /usr/lib/dovecot/sieve-global/after/spam_to_junk.sieve successfully compiled
Sep 30 02:39:42 mail dovecot: lmtp(user1@localhost.localdomain)<1032><iLMABm6KF2UIBAAAUi6ngw>: Error: sieve: binary /usr/lib/dovecot/sieve-global/after/spam_to_junk.svbin: save: failed to create temporary file: open(/usr/lib/dovecot/sieve-global/after/spam_to_junk.svbin.) failed: Permission denied (euid=9042(docker) egid=9042(docker) missing +w perm: /usr/lib/dovecot/sieve-global/after, dir owned by 110:0 mode=0755)
Sep 30 02:39:42 mail dovecot: lmtp(user1@localhost.localdomain)<1032><iLMABm6KF2UIBAAAUi6ngw>: Error: sieve: The LDA Sieve plugin does not have permission to save global Sieve script binaries; global Sieve scripts like `/usr/lib/dovecot/sieve-global/after/spam_to_junk.sieve' need to be pre-compiled using the sievec tool
```


### Improvements to this form?

_No response_

	# Single mail sent from '[email protected]' that is handled by User (relocate) and Global (copy) sieves for user1:
	_send_email 'email-templates/sieve-spam-folder'
	# Mail for user2 triggers the sieve-pipe:
	_send_email 'email-templates/sieve-pipe'

	local LEARN_HAM_LINES=(
	"sieve: file storage: script: Opened script \`learn-ham'"
	'sieve: file storage: Using Sieve script path: /usr/lib/dovecot/sieve-pipe/learn-ham.sieve'
	"sieve: Executing script from \`/usr/lib/dovecot/sieve-pipe/learn-ham.svbin'"
	"Finished running script \`/usr/lib/dovecot/sieve-pipe/learn-ham.svbin'"
	"left message in mailbox 'INBOX'"
	)

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

bug report: Dovecot sieve error logged when timestamp of `.svbin` is shared with `.sieve` source file #3558

📝 Preliminary Checks

👀 What Happened?

👟 Reproduction Steps

🐋 DMS Version

💻 Operating System and Architecture

⚙️ Container configuration files

📜 Relevant log output

Improvements to this form?

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

	chown dovecot:root -R /usr/lib/dovecot/sieve-*
	find /usr/lib/dovecot/sieve-* -type d -exec chmod 755 {} +
	find /usr/lib/dovecot/sieve-{filter,pipe} -type f -exec chmod +x {} +

	for LINE in "${LEARN_SPAM_LINES[@]}"; do
	assert_output --partial "${LINE}"
	done

Uh oh!

bug report: Dovecot sieve error logged when timestamp of .svbin is shared with .sieve source file #3558

Description

📝 Preliminary Checks

👀 What Happened?

👟 Reproduction Steps

🐋 DMS Version

💻 Operating System and Architecture

⚙️ Container configuration files

📜 Relevant log output

Improvements to this form?

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions

bug report: Dovecot sieve error logged when timestamp of `.svbin` is shared with `.sieve` source file #3558