Re: Executing a sieve-extprograms pipe script as non-root
Roland Hieber via dovecot <[email protected]>
| Newsgroups | gmane.mail.imap.dovecot |
|---|---|
| Message-ID | <1773151284-62866cc0ad02b9ac35537c8c@pty> |
On Thu, Mar 05, 2026 at 09:17:34AM +0200, Aki Tuomi wrote: > > > On 05/03/2026 01:00 EET rhi--- via dovecot <[email protected]> wrote: > > > > > > > Hello, have you put DROPPRIVS=yes in /etc/procmailrc > > > > No. As I said above: > > > > Note that the `procmail` in the pstree output > > above is really the wrapper script in /usr/lib/dovecot/sieve-pipe/procmail, not > > /usr/bin/procmail. > > I am very puzzled how it can even run as root. > > Can you run dovecot with > > log_debug=category=lmtp > > and provide the resultant logs during delivery? Sorry, I got interrupted while collecting logs last week… I have now stripped down my `/usr/lib/dovecot/sieve-pipe/procmail` wrapper to the following: #!/bin/sh set -ex ( whoami; id; pstree -s -u $$; ps -Ao pid,ppid,cgroup,ouid,euser,ruser,suser,fuser,luid,stime,flags,cmd | grep $$'\|dove\|lmtp' ; ) >&2 This should print all relevant UIDs for all relevant processes. From the 'ps' manpage, these are: ouid displays the Unix user identifier of the owner of the session of a process, if systemd support has been included. euser effective user name. ruser real user ID. suser saved user name. fuser filesystem access user ID. luid displays Login ID associated with a process. flags (see PROCESS FLAGS) -> The sum of these values is displayed in the "F" column, which is provided by the flags output specifier: 1 forked but didn't exec 4 used super-user privileges The full logs with `log_debug=category=lmtp` in the Dovecot config while receiving a test mail are attached below; but I don't see anything unusual in them, except: * The dovecot/lmtp process (PID 578427) was started as superuser and dropped privileges afterwards (euser=rhi, ruser=root, suser=root, flags=4) * The sieve-pipe/procamil wrapper (PID 578429) is forked off by the dovecot/lmtp process and running as root (euser=root, ruser=root, flags=4) but with saved UID rhi. * For some reason there are two instances of the procmail wrapper (PID 578429 and PID 578430, with same UIDs), which I cannot explain… I'm currently researching how EUID and SUID are behaving during fork() and what the sieve-extprograms code does… - Roland Full log output: ``` Mär 10 12:23:02 ptx sshd-session[578422]: Connection closed by 10.14.1.6 port 32966 [preauth] Mär 10 12:23:31 ptx socat[1161]: 2026/03/10 12:23:31 socat[1161] N accepting connection from AF=10 [2a0a:edc0:0000:0b01:001d:0000:0000:0107]:39768 on AF=10 [2a0a:edc0:0000:0900:001d:0000:0000:0109]:24 Mär 10 12:23:31 ptx socat[1161]: 2026/03/10 12:23:31 socat[1161] N forked off child process 578426 Mär 10 12:23:31 ptx socat[1161]: 2026/03/10 12:23:31 socat[1161] N listening on AF=10 [0000:0000:0000:0000:0000:0000:0000:0000]:24 Mär 10 12:23:31 ptx socat[578426]: 2026/03/10 12:23:31 socat[578426] N trusting certificate, no check of commonName Mär 10 12:23:31 ptx socat[578426]: 2026/03/10 12:23:31 socat[578426] N SSL proto version used: TLSv1.3 Mär 10 12:23:31 ptx socat[578426]: 2026/03/10 12:23:31 socat[578426] N SSL connection using TLS_AES_256_GCM_SHA384 Mär 10 12:23:31 ptx socat[578426]: 2026/03/10 12:23:31 socat[578426] N SSL connection compression "none" Mär 10 12:23:31 ptx socat[578426]: 2026/03/10 12:23:31 socat[578426] N SSL connection expansion "none" Mär 10 12:23:31 ptx socat[578426]: 2026/03/10 12:23:31 socat[578426] N opening connection to AF=1 "/run/dovecot/lmtp" Mär 10 12:23:31 ptx socat[578426]: 2026/03/10 12:23:31 socat[578426] N successfully connected from local address AF=1 "\b\xC1\xA4U" Mär 10 12:23:31 ptx socat[578426]: 2026/03/10 12:23:31 socat[578426] N starting data transfer loop with FDs [7,7] and [6,6] Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Server accepted connection (fd=12) Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Connection created Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Connect from local Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Connection started Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Sent: 220 ptx.office.stw.pengutronix.de Dovecot ready. Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Timeout start Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Received new command: LHLO mx1.white.stw.pengutronix.de Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: New command Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: Execute command Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: Pipeline blocked Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: 250 reply: Submitted Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: Replied Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: Ready to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Trigger output Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: Next to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Timeout stop Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Sending replies Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: Next to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: Completed Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Command pipeline is full (pipelined commands 1 > limit 1) Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: Pipeline unblocked Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Connection state reset Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: 250 reply: Sent: 250-ptx.office.stw.pengutronix.de 8BITMIME CHUNKING ENHANCEDSTATUSCODES PIPELINING STARTTLS Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: Finished Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: Destroy Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command LHLO: 250 reply: Destroy Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Trigger output Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: No more commands pending Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Timeout start Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Sending replies Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: No more commands pending Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Received new command: MAIL FROM:<[email protected]> Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command MAIL: New command Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command MAIL: Execute command Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command MAIL: 250 reply: Submitted Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command MAIL: Replied Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command MAIL: Ready to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Trigger output Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command MAIL: Next to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Timeout stop Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Command pipeline is full (pipelined commands 1 > limit 1) Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Sending replies Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command MAIL: Next to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command MAIL: Completed Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: trans <fon3CzP/r2l70wgALA9PpQ>: Start Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command MAIL: 250 reply: Sent: 250 2.1.0 OK Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command MAIL: Finished Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command MAIL: Destroy Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command MAIL: 250 reply: Destroy Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Trigger output Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: No more commands pending Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Timeout start Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Received new command: RCPT TO:<[email protected]> Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command RCPT: New command Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command RCPT: Execute command Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command RCPT: Next to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Timeout stop Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Command pipeline is full (pipelined commands 1 > limit 1) Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Sending replies Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command RCPT: Next to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Command pipeline is full (pipelined commands 1 > limit 1) Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command RCPT: 250 reply: Submitted Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command RCPT: Replied Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command RCPT: Ready to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Trigger output Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Sending replies Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command RCPT: Next to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command RCPT: Completed Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: rcpt [email protected]: Approved Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command RCPT: 250 reply: Sent: 250 2.1.5 OK Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command RCPT: Finished Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command RCPT: Destroy Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command RCPT: 250 reply: Destroy Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Trigger output Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: No more commands pending Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Timeout start Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Received new command: DATA Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: New command Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: Execute command Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: Next to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Sent: 354 OK Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: Command is next to be replied Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: First chunk Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Sending replies Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: Next to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: Effective uid=1059, gid=1059, home=/srv/mail/rhi Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: Namespace inbox: type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: maildir++: root=/srv/mail/rhi/mail, index=, indexpvt=, control=, inbox=/srv/mail/rhi/mail/INBOX, alt= Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: Local delivery started Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: duplicate db: Initialize Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: Pigeonhole version 2.4.1-4 (0a86619f) initializing Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: storage personal: file: Using active Sieve script path: /srv/mail/rhi/.dovecot.sieve Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: storage personal: file: Using script storage path: /srv/mail/rhi/sieve Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: storage personal: file: Relative path to sieve storage in active link: sieve/ Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: storage personal: file: Using Sieve script path: /srv/mail/rhi/.dovecot.sieve Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: storage personal: file: script 'sieve': Opened from 'personal' Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: Using the following personal Sieve script: personal/sieve Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: multi-script: Start execute sequence Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: Opening script 1 of 1 from 'personal/sieve' Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: Loading script personal/sieve Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: Script binary /srv/mail/rhi/.dovecot.svbin successfully loaded Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: storage personal: file: script 'sieve': Saving binary to '/srv/mail/rhi/.dovecot.svbin' Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: binary /srv/mail/rhi/.dovecot.svbin: save: not saving binary, because it is already stored Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: Executing script from '/srv/mail/rhi/.dovecot.svbin' Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: multi-script: Run script '/srv/mail/rhi/.dovecot.svbin' Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: Started running script '/srv/mail/rhi/.dovecot.svbin' Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: Finished running script '/srv/mail/rhi/.dovecot.svbin' (status=ok, resource usage: no usage recorded) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: multi-script: Execute result Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Executing result (status=ok, commit=no) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Starting execution of actions Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Executing actions Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Executing pipe action Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: action pipe: running program: procmail Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: action pipe: socket path '/run/dovecot/sieve-pipe/procmail' for program 'procmail' not found Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute fork:/usr/lib/dovecot/sieve-pipe/procmail: Created (args=) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute fork:/usr/lib/dovecot/sieve-pipe/procmail: Pass environment: [email protected] Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute fork:/usr/lib/dovecot/sieve-pipe/procmail: Pass environment: HOME=/srv/mail/rhi Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute fork:/usr/lib/dovecot/sieve-pipe/procmail: Pass environment: HOST=ptx.office.stw.pengutronix.de Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute fork:/usr/lib/dovecot/sieve-pipe/procmail: Pass environment: [email protected] Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute fork:/usr/lib/dovecot/sieve-pipe/procmail: Pass environment: [email protected] Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute fork:/usr/lib/dovecot/sieve-pipe/procmail: Pass environment: [email protected] Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Finished executing pipe action (status=ok, keep=canceled) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Finished executing actions (status=ok, keep=none, executed=yes) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Finished executing result (no commit, status=ok, keep=no) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: multi-script: Sequence ended Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: multi-script: Finishing sequence (status=ok) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Executing result (status=ok, commit=yes) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Starting execution of actions Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Executing actions Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Finished executing actions (status=ok, keep=none, executed=yes) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Finalizing actions Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Finalize pipe action (status=ok, action_status=ok, commit_status=ok, pre-commit=yes) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Commit pipe action Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute fork:/usr/lib/dovecot/sieve-pipe/procmail: Establishing connection Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute fork:/usr/lib/dovecot/sieve-pipe/procmail: Forked child process Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute exec:/usr/lib/dovecot/sieve-pipe/procmail (578429): Connected to program Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute exec:/usr/lib/dovecot/sieve-pipe/procmail (578429): Finished streaming payload to program Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute exec:/usr/lib/dovecot/sieve-pipe/procmail (578429): Finished input to program Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute exec:/usr/lib/dovecot/sieve-pipe/procmail (578429): Disconnected Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute exec:/usr/lib/dovecot/sieve-pipe/procmail (578429): Waiting for program to finish after 0 msecs (timeout = 0 msecs) Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: + whoami Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: root Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: + id Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: uid=0(root) gid=1059(rhi) groups=1059(rhi),116(dovecot) Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: + pstree -s -u 578429 Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: systemd---dovecot---lmtp(rhi)---procmail(root)---procmail---pstree Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: + ps -Ao pid,ppid,cgroup,ouid,euser,ruser,suser,fuser,luid,stime,flags,cmd Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: + grep 578429\|dove\|lmtp Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 1064 1 0::/system.slice/dovecot.se - root root root root - Feb22 4 /usr/sbin/dovecot -F Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 1158 1064 0::/system.slice/dovecot.se - root root root root - Feb22 4 dovecot/anvil [5 connections, 0 requests, 0 user-lists, 0 user-kicks] Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 1161 1 0::/system.slice/dovecot-lm - root root root root - Feb22 4 /usr/bin/socat -dd OPENSSL-LISTEN:24,pf=ip6,reuseaddr,fork,cert=/etc/lmtp-ca/local.crt,key=/etc/lmtp-ca/private/local.key,cafile=/etc/lmtp-ca/ca.crt,verify UNIX-CONNECT:/run/dovecot/lmtp Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 437658 103217 0::/user.slice/user-1059.sl 1059 root root root root 1059 Mar06 4 vi /etc/dovecot/conf.d/20-lmtp.conf Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 437689 1064 0::/system.slice/dovecot.se - root root root root - Mar06 4 dovecot/log Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 437695 1064 0::/system.slice/dovecot.se - dovecot dovecot dovecot dovecot - Mar06 4 dovecot/stats [5 connections] Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 437696 1064 0::/system.slice/dovecot.se - root root root root - Mar06 4 dovecot/config Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 575864 1064 0::/system.slice/dovecot.se - dovenull dovenull dovenull dovenull - 10:46 4 dovecot/imap-login [2a0a:edc0:0:900:1d::77 TLS proxy] Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 575866 1064 0::/system.slice/dovecot.se - rhi rhi rhi rhi - 10:46 4 dovecot/imap [[email protected] 2a0a:edc0:0:900:1d::77 IDLE] Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 578426 1161 0::/system.slice/dovecot-lm - root root root root - 12:23 1 /usr/bin/socat -dd OPENSSL-LISTEN:24,pf=ip6,reuseaddr,fork,cert=/etc/lmtp-ca/local.crt,key=/etc/lmtp-ca/private/local.key,cafile=/etc/lmtp-ca/ca.crt,verify UNIX-CONNECT:/run/dovecot/lmtp Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 578427 1064 0::/system.slice/dovecot.se - rhi root root rhi - 12:23 4 dovecot/lmtp [local DATA [email protected]] Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 578428 1064 0::/system.slice/dovecot.se - dovecot dovecot dovecot dovecot - 12:23 4 dovecot/auth [0 wait, 0 passdb, 0 userdb] Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 578429 578427 0::/system.slice/dovecot.se - root root rhi root - 12:23 4 /bin/sh /usr/lib/dovecot/sieve-pipe/procmail Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 578430 578429 0::/system.slice/dovecot.se - root root rhi root - 12:23 1 /bin/sh /usr/lib/dovecot/sieve-pipe/procmail Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 578434 578430 0::/system.slice/dovecot.se - root root root root - 12:23 4 ps -Ao pid,ppid,cgroup,ouid,euser,ruser,suser,fuser,luid,stime,flags,cmd Mär 10 12:23:31 ptx dovecot[437689]: lmtp: Error: 578435 578430 0::/system.slice/dovecot.se - root root root root - 12:23 0 grep 578429\|dove\|lmtp Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute exec:/usr/lib/dovecot/sieve-pipe/procmail (578429): Child process ended Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: execute exec:/usr/lib/dovecot/sieve-pipe/procmail (578429): Destroy Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: sieve: msgid=<[email protected]>: pipe action: piped message to program 'procmail' Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Finished finalizing actions (status=ok, keep=none, committed=yes) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Finishing actions Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Finish pipe action Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: msgid=<[email protected]>: Finished executing result (final, status=ok, keep=no) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: multi-script: Sequence finished (status=ok, keep=no) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: sieve: multi-script: Destroy Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: duplicate db: Cleanup Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: Local delivery finished successfully Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: 250 reply: Submitted Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: Replied Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Command pipeline is full (pipelined commands 1 > limit 1) Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: Ready to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Trigger output Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: User session is finished Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: End of data Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Timeout stop Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Sending replies Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: Next to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: Completed Mär 10 12:23:31 ptx socat[578426]: 2026/03/10 12:23:31 socat[578426] N socket 2 (fd 6) is at EOF Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: rcpt [email protected]: Finished Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: trans <fon3CzP/r2l70wgALA9PpQ>: Finished Mär 10 12:23:31 ptx dovecot[437689]: lmtp([email protected])<578427><fon3CzP/r2l70wgALA9PpQ>: Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Connection state reset Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: 250 reply: Sent: 250 2.0.0 <[email protected]> fon3CzP/r2l70wgALA9PpQ Saved Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: Finished Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: Destroy Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command DATA: 250 reply: Destroy Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Trigger output Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: No more commands pending Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Timeout start Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Received new command: QUIT Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command QUIT: New command Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command QUIT: Execute command Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command QUIT: 221 reply: Submitted Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command QUIT: Replied Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command QUIT: Ready to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Trigger output Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command QUIT: Next to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Timeout stop Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Command pipeline is full (pipelined commands 1 > limit 1) Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Sending replies Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command QUIT: Next to reply Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command QUIT: Completed Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command QUIT: 221 reply: Sent: 221 2.0.0 Bye Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command QUIT: Finished Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Disconnected: Logged out (state=READY) Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Connection state reset Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Disconnect from local: Logged out (state=READY) Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Disconnected: Connection closed (fd=12) Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command QUIT: Destroy Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: command QUIT: 221 reply: Destroy Mär 10 12:23:31 ptx dovecot[437689]: lmtp(578427): Debug: lmtp-server: conn unix:pid=578426,uid=0 [1]: Connection destroy Mär 10 12:23:31 ptx socat[578426]: 2026/03/10 12:23:31 socat[578426] N socket 1 (fd 7) is at EOF Mär 10 12:23:31 ptx socat[578426]: 2026/03/10 12:23:31 socat[578426] N exiting with status 0 Mär 10 12:23:31 ptx socat[1161]: 2026/03/10 12:23:31 socat[1161] N childdied(): handling signal 17 ``` -- Roland Hieber, Pengutronix e.K. | [email protected] | Steuerwalder Str. 21 | https://www.pengutronix.de/ | 31137 Hildesheim, Germany | Phone: +49-5121-206917-0 | Amtsgericht Hildesheim, HRA 2686 | Fax: +49-5121-206917-5555 | _______________________________________________ dovecot mailing list -- [email protected] To unsubscribe send an email to [email protected]