Why is Gnu sieve so extremely fast to batch process an mbox file, but while Dovecot's sieve-filter is an order of magnitude slower?
Sequence: - mpop or getmail to pipeline download emails into temp mbox file - filter that file Gnu sieve just flies through a local mbox file and saving emails to other local mbox files. Gnu sieve rejects too many emails with "malformed" errors, so after a few years I bit the bullet and upgraded to Dovecot's sieve-filter. Dovecot's sieve-filter, at present, is an order of magnitude slower. Here's my filter command (one line): /usr/bin/sieve-filter -veW -c $HOME/etc/email/sieve-dovecot-config.conf -o mail_location=mbox:~/mail:INBOX=~/mail/Inbox:INDEX=:UTF-8:VOLATILEDIR=/tmp/dovecot-volatile/%2.256Nu/%u:SUBSCRIPTIONS=dovecot_subscriptions ~/etc/email/sieve.rc email-incoming-unsorted The sieve script is fine now that I have the correct "require" clauses (hint: "capability strings"). File ~/etc/email/sieve-dovecot-config.conf: protocols = pop lda_mailbox_autocreate = yes lda_mailbox_autosubscribe = yes mail_fsync = never There's no re-sending of emails into my local Postfix SMTP server - I checked the system logs and confirmed this (journalctl -f). I suspect that Gnu sieve was directly writing each email to the appropriate sieve-determined mbox file (perhaps with only a sync at the end of a single batch process - what I've attempted to achieve above with sieve-filter), and that sieve-filter is instead passing each email through some (dovecot) lda? Here's the output for a sieve-filter batch processing of 11 emails: $ /usr/bin/sieve-filter -veW -c /home/zen/etc/email/sieve-dovecot-config.conf -o mail_location=mbox:/home/zen/mail:INBOX=/home/zen/mail/Inbox:INDEX=:UTF-8:VOLATILEDIR=/tmp/dovecot-volatile/%2.256Nu/%u:SUBSCRIPTIONS=dovecot_subscriptions /home/zen/etc/email/sieve.rc email-incoming-unsorted # PS0 Timestamp: 20190912@07:02:23 info: filtering: [Tue, 3 Sep 2019 05:17:16 -0500; 10240 bytes] `Re: VentureBeat: The death of disk? H...'. info: msgid=<CAMjeLr91T9R7APsuxQVuM3WbqDsxAfwn4=oydedx4fmcord...@mail.gmail.com>: stored mail into mailbox 'l/cp/cp'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 3 Sep 2019 07:29:53 -0400; 12968 bytes] `[zfs-devel] xattr naming format in Zo...'. info: msgid=<15675101930.d5ba2e.12...@composer.zfsonlinux.topicbox.com>: stored mail into mailbox 'l/z/zdev'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 03 Sep 2019 15:29:09 +0300; 20461 bytes] `Re: [zfs-devel] xattr naming format i...'. info: msgid=<23955051567513...@sas1-02732547ccc0.qloud-c.yandex.net>: stored mail into mailbox 'l/z/zdev'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 3 Sep 2019 18:20:42 +0530; 18065 bytes] `Re: [Gluster-users] Issues with Geo-r...'. info: msgid=<CADmkyZMxrfOANrAP+_URAHJcMqCqh=igdajtszkfq5pczsu...@mail.gmail.com>: stored mail into mailbox 'l/gl/user'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 3 Sep 2019 09:34:20 -0400; 13342 bytes] `Re: tasksel'. info: msgid=<20190903133420.gs6...@eeg.ccf.org>: stored mail into mailbox 'l/deb/user'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 3 Sep 2019 06:56:07 -0700 (PDT); 12390 bytes] `[awx-project] Re: AWX on Kubernetes m...'. info: msgid=<0715adb7-540f-4cff-9282-e1252c53c...@googlegroups.com>: stored mail into mailbox 'l/ansible/awx'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 3 Sep 2019 07:01:27 -0700 (PDT); 12220 bytes] `[awx-project] Re: AWX on Kubernetes m...'. info: msgid=<949b2c17-4254-49f1-83b4-cd54d15aa...@googlegroups.com>: stored mail into mailbox 'l/ansible/awx'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 3 Sep 2019 10:14:58 -0400; 25313 bytes] `Re: [zfs-devel] xattr naming format i...'. info: msgid=<cab5c7xphcdfx1w3ya9fyrl-kq8buicr4jbidqrufjj9nogk...@mail.gmail.com>: stored mail into mailbox 'l/z/zdev'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 3 Sep 2019 17:10:22 +0200; 7567 bytes] `Re: [asterisk-users] Playing MP3's in...'. info: msgid=<20190903151022.354xpe6ds2vglher@red.localdomain>: stored mail into mailbox 'l/as/users'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 4 Sep 2019 01:04:49 +0900; 14858 bytes] `Re: [Hyperledger Fabric] a primitive ...'. info: msgid=<160901d8-b903-9e9a-91ac-267571b0e...@gmx.com>: stored mail into mailbox 'l/hl/fabric'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 3 Sep 2019 09:55:22 -0700 (PDT); 13337 bytes] `[awx-project] Re: AWX on Kubernetes m...'. info: msgid=<f9bc4e6a-8445-4b34-927a-35f577ffc...@googlegroups.com>: stored mail into mailbox 'l/ansible/awx'. info: message expunged from source mailbox upon successful move. 2 ▶︎️ zen@eye 20190912@07:02:30 ~ $ So about 3/4 of a second is spent by dovecot's sieve-filter, on each email that it processes - watching it is painful given how fast Gnu sieve has been for the last few years - it's almost (but not quite) as slow as my previous fetchmail email download per-email time. Attached is a -D debug run of sieve-filter on 20 emails - slightly longer than the above, and took roughly 15 seconds to run. Any help appreciated...
sieve-filter(zen): Debug: sieve: Pigeonhole version 0.5.4 () initializing sieve-filter(zen): 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/zen/etc/email/sieve.rc. debug: file script: Opened script `sieve.rc' from `/home/zen/etc/email/sieve.rc'. debug: Script binary /home/zen/etc/email/sieve.rc.svbin successfully loaded. debug: binary save: not saving binary /home/zen/etc/email/sieve.rc.svbin, because it is already stored. info: filtering: [Tue, 03 Sep 2019 22:30:31 +0200; 11609 bytes] `Re: AMD Vega 6 on Debian 10'. info: msgid=<87h85t2kd4....@turtle.gmx.de>: stored mail into mailbox 'l/deb/user'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 03 Sep 2019 21:14:09 +0000; 7815 bytes] `[Xfce-bugs] [Bug 15917] Thunar SendTo...'. info: msgid=<bug-15917-521-vmobv3k...@https.bugzilla.xfce.org/>: stored mail into mailbox 'l/xfce-bugs'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 03 Sep 2019 21:39:23 +0000; 7016 bytes] `[Xfce-bugs] [Bug 15917] Thunar SendTo...'. info: msgid=<bug-15917-521-hgmtige...@https.bugzilla.xfce.org/>: stored mail into mailbox 'l/xfce-bugs'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 3 Sep 2019 17:16:29 -0600; 14428 bytes] `[Freeswitch-users] Register-transport...'. info: msgid=<ca+wj8uycotmaaig_2suoy7pz9omr5wcvpcz-v5wusetzerl...@mail.gmail.com>: stored mail into mailbox 'l/fs/users'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 03 Sep 2019 23:53:52 +0000; 8738 bytes] `[Xfce-bugs] [Bug 15172] Clicking on M...'. info: msgid=<bug-15172-521-82b3nkr...@https.bugzilla.xfce.org/>: stored mail into mailbox 'l/xfce-bugs'. info: message expunged from source mailbox upon successful move. info: filtering: [Tue, 3 Sep 2019 19:07:47 -0500; 19469 bytes] `Re: [zfs-devel] xattr naming format i...'. info: msgid=<922dfa0b-77e6-1037-2e81-94fb772ea...@wiktel.com>: stored mail into mailbox 'l/z/zdev'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 4 Sep 2019 03:09:43 +0000; 51294 bytes] `=?utf-8?Q?Your=20Weekly=20Dose=20Of=2...'. info: msgid=<fca99a20c3621371bc4cf1f36.84251c9f9e.20190904030912.951596549c.4bb7c...@mail24.atl11.rsgsv.net>: left message in mailbox 'email-incoming-unsorted'. info: message kept in source mailbox. info: filtering: [Tue, 03 Sep 2019 21:09:52 -0700; 11180 bytes] `911TrutherFunnies: Forklift hits WTC ...'. info: msgid=<cb9b673c-19d7-442c-8900-ea30c8963...@riseup.net>: stored mail into mailbox 'l/cp/cp'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 4 Sep 2019 01:27:54 -0300; 7792 bytes] `Re: 911TrutherFunnies: Forklift hits ...'. info: msgid=<20190904042541.6bfa092c1d...@cock.li>: stored mail into mailbox 'l/cp/cp'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 4 Sep 2019 16:10:44 +0900; 19913 bytes] `Re: [Freeswitch-users] Register-trans...'. info: msgid=<cagjlwfj66jfymu36kujtgfe8lp+lcfpbjozsbzr3_qwr1ul...@mail.gmail.com>: stored mail into mailbox 'l/fs/users'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 04 Sep 2019 07:28:38 +0000; 10366 bytes] `[Xfce-bugs] [Bug 15917] Thunar SendTo...'. info: msgid=<bug-15917-521-jc3wdnp...@https.bugzilla.xfce.org/>: stored mail into mailbox 'l/xfce-bugs'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 4 Sep 2019 11:32:11 +0300; 10377 bytes] `Re: [OSGeo Oceania] membership - elec...'. info: msgid=<CAHY5hn_OhgaH==gv0y47xz84rvjjpzf-xcfwe_nk0t-z29r...@mail.gmail.com>: stored mail into mailbox 'l/wireless.aust-nz'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 4 Sep 2019 09:01:05 +0000 (UTC); 28831 bytes] `[asterisk-users] SIP trunk problem: M...'. info: msgid=<637726953.2368317.1567587665...@mail.yahoo.com>: stored mail into mailbox 'l/as/users'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 04 Sep 2019 12:21:04 +0300; 13976 bytes] `Re: [Gluster-users] Geo-Replication w...'. info: msgid=<v7xug17438ljasvk9va93drv.1567588864...@email.android.com>: stored mail into mailbox 'l/gl/user'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 04 Sep 2019 12:20:18 +0300; 8163 bytes] `Re: [Gluster-users] Geo-Replication ...'. info: msgid=<04c8bl33p672akyja74s7dd4.1567588818...@email.android.com>: stored mail into mailbox 'l/gl/user'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 4 Sep 2019 12:47:16 +0300; 14199 bytes] `Re: [Hyperledger Fabric] a primitive ...'. info: msgid=<capg-4yupmdu2vcxdpgm0di9ctg9rb0oeeyytkgjy36cisck...@mail.gmail.com>: stored mail into mailbox 'l/hl/fabric'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 4 Sep 2019 05:59:44 -0400; 15433 bytes] `Re: [Hyperledger Fabric] a primitive ...'. info: msgid=<cae6nkwq-kyn8xlo6+x+p3hqdeevp_t_uje79686u-otyesg...@mail.gmail.com>: stored mail into mailbox 'l/hl/fabric'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 4 Sep 2019 12:01:37 +0200; 48853 bytes] `Re: [GRASS-user] sample a strds at sp...'. info: msgid=<CABa=8QrL9GDF8p2dTsaAxHRbz0SnOqGp3=dhuyw2og_+3yv...@mail.gmail.com>: stored mail into mailbox 'l/grass-user'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 04 Sep 2019 06:43:43 -0300; 11311 bytes] `Re: [asterisk-users]? =?utf-8?q?SIP_t...'. info: msgid=<4b5d55c8-b3f5-4084-a2f0-42453a139...@www.fastmail.com>: stored mail into mailbox 'l/as/users'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 4 Sep 2019 03:42:04 -0700 (PDT); 149741 bytes] `[awx-project] Re: AWX on Kubernetes m...'. info: msgid=<e1ad68c7-0263-40f7-8fd0-903ce3f57...@googlegroups.com>: stored mail into mailbox 'l/ansible/awx'. info: message expunged from source mailbox upon successful move. info: filtering: [Wed, 4 Sep 2019 21:28:01 +1000; 12360 bytes] `Re: [OSGeo Oceania] membership - elec...'. info: msgid=<13f401c2-7f97-44e8-32e5-868d150f1...@gmail.com>: stored mail into mailbox 'l/wireless.aust-nz'. info: message expunged from source mailbox upon successful move.
