[Dovecot] Strange behavior of header_filter_callback

[Konstantin Lepa]

Hello. I asked about the problem in http://markmail.org/message/zsry62fcig5hqka3 
  . And I created simple example plug-in for deliver. It is attached  
(I don't want to paste so much code)

For compile in command-line run:
# DOVECOT=<path to dovecot> gmake
...send mail...
...view dovecot lda log...
# gmake clean
# WITH_ONLY_HEADERS=1 DOVECOT=<path to dovecot> gmake
...send mail...
...view dovecot lda log...

My log (notice strings start with #):
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: Loading  
modules from directory: /usr/local/lib/dovecot/lda
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: Module  
loaded: /usr/local/lib/dovecot/lda/lib90_example_plugin.so
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: auth input:  
uid=1002
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: auth input:  
gid=1002
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: auth input: home=/var/spool/mail/pitman at virtualworld.com
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
example_plugin_init is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: mbox: data=/var/spool/mail/pitman at virtualworld.com 
:INDEX=/var/indexes/pitman at virtualworld.com
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: mbox: INBOX  
defaulted to /var/spool/mail/pitman at virtualworld.com/inbox
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: fs: root=/var/spool/mail/pitman at virtualworld.com 
, index=/var/indexes/pitman at virtualworld.com, control=, inbox=/var/spool/mail/pitman at virtualworld.com 
/inbox
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
example_deliver_mail is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
example_get_stream is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
make_header_filter is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
create_header_stream is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
create_stream_for_msgbody is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: #Message 1:
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
example_get_stream is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
make_header_filter is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
create_header_stream is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
create_stream_for_msgbody is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: #Message 1:
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: msgid=: saved  
mail to INBOX
deliver(pitman at virtualworld.com): Apr 08 13:52:39 Info: example: func  
example_plugin_deinit is called

My log (WITH_ONLY_HEADERS=1):
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: Loading  
modules from directory: /usr/local/lib/dovecot/lda
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: Module  
loaded: /usr/local/lib/dovecot/lda/lib90_example_plugin.so
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: auth input:  
uid=1002
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: auth input:  
gid=1002
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: auth input: home=/var/spool/mail/pitman at virtualworld.com
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_plugin_init is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: mbox: data=/var/spool/mail/pitman at virtualworld.com 
:INDEX=/var/indexes/pitman at virtualworld.com
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: mbox: INBOX  
defaulted to /var/spool/mail/pitman at virtualworld.com/inbox
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: fs: root=/var/spool/mail/pitman at virtualworld.com 
, index=/var/indexes/pitman at virtualworld.com, control=, inbox=/var/spool/mail/pitman at virtualworld.com 
/inbox
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_deliver_mail is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_get_stream is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
make_header_filter is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #Return-Path: <pupkin at virtualworld.com 
 >
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #Delivered-To: pitman at virtualworld.comm 
 >
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #Received:  
from localhost.virtualworld.com (localhost [127.0.0.1])
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info:  
#Received:      by bsdman.virtualworld.com (Postfix) with ESMTP id  
3B3E11FE
         for <pitman at virtualworld.com>; Wed,  8 Apr 2009 13:53:51  
+0400 (MSD)
Content-Type: text/plain; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Subject: 2009-04-08T13:53:51.199182+1
From: pupkin at virtualworld.com
Reply-to: Konstantin at bsdman.virtualworld.com,
         Lepa at bsdman.virtualworld.com
To: pitman at virtualworld.com
Message-Id: <20090408095351.3B3E11FE at bsdman.virtualworld.com>
Date: Wed,  8 Apr 2009 13:53:51 +0400 (MSD)

Message 1

deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info:  
#Received:      for <pitman at virtualworld.com>; Wed,  8 Apr 2009  
13:53:51 +0400 (MSD)
Content-Type: text/plain; charset="us-ascii"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
Subject: 2009-04-08T13:53:51.199182+1
From: pupkin at virtualworld.com
Reply-to: Konstantin at bsdman.virtualworld.com,
         Lepa at bsdman.virtualworld.com
To: pitman at virtualworld.com
Message-Id: <20090408095351.3B3E11FE at bsdman.virtualworld.com>
Date: Wed,  8 Apr 2009 13:53:51 +0400 (MSD)

Message 1

deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #Content-Type:  
text/plain; charset="us-ascii"m (localhost [127.0.0.1])
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #MIME-Version:  
1.0t/plain; charset="us-ascii"m (localhost [127.0.0.1])
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #Content- 
Transfer-Encoding: 7bit/plain; charset="us-ascii"m (localhost  
[127.0.0.1])
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #Subject:  
2009-04-08T13:53:51.199182+1i"m (localhost [127.0.0.1])
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #From: pupkin at virtualworld.com182+1i 
"m (localhost [127.0.0.1])
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #Reply-to: Konstantin at bsdman.virtualworld.com 
,calhost [127.0.0.1])
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #Reply- 
to:      Lepa at bsdman.virtualworld.com
To: pitman at virtualworld.com
Message-Id: <20090408095351.3B3E11FE at bsdman.virtualworld.com>
Date: Wed,  8 Apr 2009 13:53:51 +0400 (MSD)

Message 1

deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #To: pitman at virtualworld.comalworld.com 
,calhost [127.0.0.1])
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #Message-Id: <20090408095351.3B3E11FE at bsdman.virtualworld.com 
 >.0.1])
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #Date: Wed,  8  
Apr 2009 13:53:51 +0400 (MSD)alworld.com>.0.1])
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: #: Wed,  8 Apr  
2009 13:53:51 +0400 (MSD)alworld.com>.0.1])
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_header_filter_callback is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_get_stream is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
make_header_filter is called
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: msgid=<20090408095351.3B3E11FE at bsdman.virtualworld.com 
 >: saved mail to INBOX
deliver(pitman at virtualworld.com): Apr 08 13:53:51 Info: example: func  
example_plugin_deinit is called



-------------- next part --------------
A non-text attachment was scrubbed...
Name: example.tgz
Type: application/octet-stream
Size: 2439 bytes
Desc: not available
Url : http://dovecot.org/pipermail/dovecot/attachments/20090408/2de762d2/attachment.obj