Mailinglist not delivered

Franz Skale i.bin at dah.am
Mon Dec 10 16:02:26 CET 2012




I had a similar problem.
Check your mailq: mailq
Check wallace:
Check: /etc/default/wallace
EDIT LINE: "-l debug -d 9"
tail -f /var/log/kolab/pykolab.log
Check, that the works show up.
Check the permissions of: /etc/kolab and /etc/kolab/kolab.conf
Check /etc/init.d/wallace:
group=""   

I changed the group from kolab-n to kolab.
Then it started to work again.

I debugged the problem with strace:
[pid 23721] getresgid([413], [413], [413]) = 0
id 23721] open("/etc/kolab/kolab.conf", O_RDONLY) = -1 EACCES
(Permission denied)


You must see something like: (mail.log)
c 10 15:56:02 mail postfix/lmtp[24518]: CED48801D7B0:
to=<email at address.com>,
relay=server.exmaple.com[/var/lib/imap/socket/lmtp], delay=0.02,
delays=0.01/0.01/0/0, dsn=2.1.5, status=sent (250 2.1.5 Ok
SESSIONID=<server-24318-1355151362-1>)

LMTP delivers the mail to the store.


Rgds.

Franz




Am 10.12.12 12:22, schrieb mailingliste at dreampixel.de:
> Hi at all,
>
> I have a multidomain-setup in my kolab3. My primary domain is  
> 'gehr-edv.de' an my private domain is 'dreampixel.de'
>
> For the mailinglists I use the address 'mailinglist at dreampixel.de'
>
> All adress work find. I can send from my google-mailaccount mails to  
> all my mail-addresses:
>
> - sven_AT_gehr-edv.de
> - sven_AT_dreampixel.de.de
> - mailingliste_AT_dreampixel.de.de
>
> but I get no mail from any mailing list. Perhaps the spam filter problem that?
>
>
> In the /var/log/maillog are some entries that I do not understand
>
>
> Dec 10 12:13:02 kolab imap[8511]: IOERROR: opening  
> /var/lib/imap/user_deny.db: No such file or directory
> [...]
> Dec 10 12:13:33 kolab imap[8495]: ptload(): fetched cache record  
> (sven.gehr at gehr-edv.de)(mark 1355136320, current 1355138013, limit  
> 1355127213)
> [...]
> Dec 10 12:13:38 kolab postfix/smtpd[8517]: warning: Illegal address  
> syntax from localhost[127.0.0.1] in MAIL command: <++SO WERDEN AUCH  
> SIE MILLION??R++ at mail.dreampixel.de>
>
>
>
> Here the complete log while fetchmail fetch the mailboxes:
>
>
>
>
> Dec 10 12:13:02 kolab master[1585]: process 8374 exited, status 0
> Dec 10 12:13:02 kolab master[8511]: about to exec /usr/lib/cyrus-imapd/imapd
> Dec 10 12:13:02 kolab imap[8511]: executed
> Dec 10 12:13:02 kolab imap[8511]: IOERROR: opening  
> /var/lib/imap/user_deny.db: No such file or directory
> Dec 10 12:13:33 kolab imap[8495]: accepted connection
> Dec 10 12:13:33 kolab master[8513]: about to exec /usr/lib/cyrus-imapd/imapd
> Dec 10 12:13:33 kolab imap[8513]: executed
> Dec 10 12:13:33 kolab imap[8513]: IOERROR: opening  
> /var/lib/imap/user_deny.db: No such file or directory
> Dec 10 12:13:33 kolab imap[8495]: imapd:Loading hard-coded DH parameters
> Dec 10 12:13:33 kolab imap[8495]: SSL_accept() incomplete -> wait
> Dec 10 12:13:33 kolab imap[8495]: SSL_accept() succeeded -> done
> Dec 10 12:13:33 kolab imap[8495]: starttls: TLSv1 with cipher  
> DHE-RSA-AES256-SHA (256/256 bits new) no authentication
> Dec 10 12:13:33 kolab imap[8495]: client id: "name" "Roundcube"  
> "version" "0.9-git" "php" "5.3.10" "os" "Linux" "command"  
> "/Microsoft-Server-ActiveSync?Cmd=Sync&User=sven.gehr%40gehr-edv.de&DeviceId=SEC126282DF59245&DeviceType=SAMSUNGGTI9300"
> Dec 10 12:13:33 kolab imap[8495]: ptload(): fetched cache record  
> (sven.gehr at gehr-edv.de)(mark 1355136320, current 1355138013, limit  
> 1355127213)
> Dec 10 12:13:33 kolab imap[8495]: ptload returning data
> Dec 10 12:13:33 kolab imap[8495]: canonified sven.gehr at gehr-edv.de ->  
> sven.gehr at gehr-edv.de
> Dec 10 12:13:33 kolab imap[8495]: login: localhost [127.0.0.1]  
> sven.gehr at gehr-edv.de PLAIN+TLS User logged in  
> SESSIONID=<kolab.local.lan-8495-1355138013-1>
> Dec 10 12:13:34 kolab imap[8495]: open: user sven^gehr at gehr-edv.de  
> opened Tasks
> Dec 10 12:13:34 kolab imap[8495]: open: user sven^gehr at gehr-edv.de  
> opened Adressbuch
> Dec 10 12:13:34 kolab imap[8495]: SQUAT returned 258 messages
> Dec 10 12:13:34 kolab imap[8495]: open: user sven^gehr at gehr-edv.de  
> opened Tasks
> Dec 10 12:13:34 kolab imap[8495]: open: user sven^gehr at gehr-edv.de  
> opened Adressbuch
> Dec 10 12:13:34 kolab imap[8495]: open: user sven^gehr at gehr-edv.de  
> opened Kalender
> Dec 10 12:13:35 kolab imap[8495]: open: user sven^gehr at gehr-edv.de  
> opened INBOX
> Dec 10 12:13:35 kolab imap[8495]: SQUAT returned 79 messages
> Dec 10 12:13:35 kolab imap[8495]: open: user sven^gehr at gehr-edv.de opened Spam
> Dec 10 12:13:35 kolab imap[8495]: SQUAT returned 12 messages
> Dec 10 12:13:35 kolab imap[8495]: open: user sven^gehr at gehr-edv.de  
> opened Trash
> Dec 10 12:13:35 kolab imap[8495]: SQUAT returned 12954 messages
> Dec 10 12:13:35 kolab imap[8495]: open: user sven^gehr at gehr-edv.de  
> opened INBOX
> Dec 10 12:13:36 kolab imap[8495]: USAGE sven^gehr at gehr-edv.de user:  
> 0.105983 sys: 0.021996
> Dec 10 12:13:38 kolab postfix/smtpd[8517]: connect from localhost[127.0.0.1]
> Dec 10 12:13:38 kolab postfix/smtpd[8517]: warning: Illegal address  
> syntax from localhost[127.0.0.1] in MAIL command: <++SO WERDEN AUCH  
> SIE MILLION??R++ at mail.dreampixel.de>
> Dec 10 12:13:38 kolab postfix/smtpd[8518]: connect from localhost[127.0.0.1]
> Dec 10 12:13:38 kolab postfix/smtpd[8518]: warning: Illegal address  
> syntax from localhost[127.0.0.1] in RCPT command: <++SO WERDEN AUCH  
> SIE MILLION??R++ at mail.dreampixel.de>
> Dec 10 12:13:38 kolab postfix/smtpd[8518]: disconnect from  
> localhost[127.0.0.1]
> Dec 10 12:13:38 kolab postfix/smtpd[8517]: warning: Illegal address  
> syntax from localhost[127.0.0.1] in MAIL command: <T??glich entstehen  
> 389 Million??re ... @mail.dreampixel.de>
> Dec 10 12:13:38 kolab postfix/smtpd[8518]: connect from localhost[127.0.0.1]
> Dec 10 12:13:38 kolab postfix/smtpd[8518]: warning: Illegal address  
> syntax from localhost[127.0.0.1] in RCPT command: <T??glich entstehen  
> 389 Million??re ... @mail.dreampixel.de>
> Dec 10 12:13:38 kolab postfix/smtpd[8518]: disconnect from  
> localhost[127.0.0.1]
> Dec 10 12:13:39 kolab postfix/smtpd[8517]: warning: Illegal address  
> syntax from localhost[127.0.0.1] in MAIL command: <54 neue Million??re  
> damit geboren! Alle sind Anf??nger!>
> Dec 10 12:13:39 kolab postfix/smtpd[8518]: connect from localhost[127.0.0.1]
> Dec 10 12:13:39 kolab postfix/smtpd[8518]: warning: Illegal address  
> syntax from localhost[127.0.0.1] in RCPT command: <54 neue Million??re  
> damit geboren! Alle sind Anf??nger!>
> Dec 10 12:13:39 kolab postfix/smtpd[8518]: disconnect from  
> localhost[127.0.0.1]
> Dec 10 12:13:39 kolab postfix/smtpd[8517]: warning: Illegal address  
> syntax from localhost[127.0.0.1] in MAIL command: <++Noch die  
> ver??ffentlichte Dokumente++ at mail.dreampixel.de>
> Dec 10 12:13:39 kolab postfix/smtpd[8518]: connect from localhost[127.0.0.1]
> Dec 10 12:13:39 kolab postfix/smtpd[8518]: warning: Illegal address  
> syntax from localhost[127.0.0.1] in RCPT command: <++Noch die  
> ver??ffentlichte Dokumente++ at mail.dreampixel.de>
> Dec 10 12:13:39 kolab postfix/smtpd[8518]: disconnect from  
> localhost[127.0.0.1]
> Dec 10 12:13:39 kolab postfix/smtpd[8517]: disconnect from  
> localhost[127.0.0.1]
> Dec 10 12:13:39 kolab postfix/smtpd[8518]: connect from localhost[127.0.0.1]
> Dec 10 12:13:39 kolab postfix/smtpd[8518]: 8F0F81207F3:  
> client=localhost[127.0.0.1]
> Dec 10 12:13:39 kolab postfix/cleanup[8520]: 8F0F81207F3:  
> message-id=<201212101112.qBABC7TR006660 at lists2.andrew.cmu.edu>
> Dec 10 12:13:39 kolab postfix/qmgr[1740]: 8F0F81207F3:  
> from=<info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu>,  
> size=4962, nrcpt=1 (queue active)
> Dec 10 12:13:39 kolab postfix/smtpd[8518]: disconnect from  
> localhost[127.0.0.1]
> Dec 10 12:13:39 kolab amavis[7561]: (07561-02) Net::Server:  
> 2012/12/10-12:13:39 CONNECT TCP Peer: "127.0.0.1:45748" Local:  
> "127.0.0.1:10024"
> Dec 10 12:13:39 kolab amavis[7561]: (07561-02) idle_proc, hi : was  
> idle, 1815281.6 ms, total idle 2725.985 s, busy 5.199 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-02) loaded base policy bank
> Dec 10 12:13:39 kolab amavis[7561]: (07561-02) lookup_ip_acl  
> (inet_acl): key="127.0.0.1" matches "127.0.0.1", result=1
> Dec 10 12:13:39 kolab amavis[7561]: (07561-02) process_request: fileno  
> sock=12, STDIN=0, STDOUT=1
> Dec 10 12:13:39 kolab amavis[7561]: (07561-02) switch_to_my_time      
> 480 s, new request
> Dec 10 12:13:39 kolab amavis[7561]: (07561-02) process_request:  
> suggested_protocol="" on TCP
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) SMTP> 220 [127.0.0.1]  
> ESMTP amavisd-new service ready
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_client_time  
> 480 s, smtp response sent
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) idle_proc, 4: was busy,  
> 4.5 ms, total idle 2725.985 s, busy 5.203 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) idle_proc, 5: was idle,  
> 0.2 ms, total idle 2725.986 s, busy 5.203 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) SMTP< EHLO kolab.local.lan\r\n
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_my_time      
> 480 s, SMTP EHLO received
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP> 250-[127.0.0.1]
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP> 250-VRFY
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP> 250-PIPELINING
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP> 250-SIZE
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP> 250-ENHANCEDSTATUSCODES
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP> 250-8BITMIME
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP> 250-DSN
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP> 250 XFORWARD  
> NAME ADDR PORT PROTO HELO SOURCE
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_client_time  
> 480 s, smtp response sent
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) idle_proc, 6: was busy,  
> 2.4 ms, total idle 2725.986 s, busy 5.205 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) idle_proc, 5: was idle,  
> 0.2 ms, total idle 2725.986 s, busy 5.205 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP< XFORWARD  
> NAME=localhost ADDR=127.0.0.1 PORT=40794\r\n
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_my_time      
> 480 s, SMTP XFORWARD received
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP> 250 2.5.0 Ok XFORWARD
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_client_time  
> 480 s, smtp response sent
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) idle_proc, 6: was busy,  
> 1.1 ms, total idle 2725.986 s, busy 5.207 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) idle_proc, 5: was idle,  
> 0.2 ms, total idle 2725.986 s, busy 5.207 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP< XFORWARD  
> PROTO=ESMTP HELO=kolab.local.lan SOURCE=LOCAL\r\n
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_my_time      
> 480 s, SMTP XFORWARD received
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP> 250 2.5.0 Ok XFORWARD
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_client_time  
> 480 s, smtp response sent
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) idle_proc, 6: was busy,  
> 0.8 ms, total idle 2725.986 s, busy 5.207 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) idle_proc, 5: was idle,  
> 0.1 ms, total idle 2725.986 s, busy 5.207 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP< MAIL  
> FROM:<info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu>  
> SIZE=4962 BODY=7BIT\r\n
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_my_time      
> 480 s, SMTP MAIL received
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) check_mail_begin_task:  
> task_count=3
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ip_acl:  
> key="127.0.0.1" matches "127.0.0.0/8", result=1
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) loaded policy bank "MYNETS"
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup [debug_sender]  
> => undef,  
> "info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu"  
> does not match
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP> 250 2.1.0 Sender  
> <info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu> OK
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_client_time  
> 480 s, smtp response sent
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) idle_proc, 6: was busy,  
> 3.2 ms, total idle 2725.986 s, busy 5.211 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) idle_proc, 5: was idle,  
> 0.2 ms, total idle 2725.986 s, busy 5.211 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP< RCPT  
> TO:<sven.gehr at gehr-edv.de> ORCPT=rfc822;sven at dreampixel.de\r\n
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_my_time      
> 480 s, SMTP RCPT received
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_acl(sven.gehr at gehr-edv.de) matches key ".gehr-edv.de", result=1
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup [local_domains]  
> => true,  "sven.gehr at gehr-edv.de" matches, result="1",  
> matching_key=".gehr-edv.de"
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) query_keys:  
> sven.gehr at gehr-edv.de, sven.gehr, @gehr-edv.de, @.gehr-edv.de, @.de, @.
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap  
> "sven.gehr at gehr-edv.de", query keys: "sven.gehr at gehr-edv.de",  
> "sven.gehr", "@gehr-edv.de", "@.gehr-edv.de", "@.de", "@.", base:  
> dc=gehr-edv,dc=de, filter: (|(mail=%m)(alias=%m))
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ldap begin_work
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: searching  
> base="dc=gehr-edv,dc=de", scope="sub",  
> filter="(|(|(mail=sven.gehr at gehr-edv.de)(mail=sven.gehr)(mail=@gehr-edv.de)(mail=@.gehr-edv.de)(mail=@.de)(mail=@.))(|(alias=sven.gehr at gehr-edv.de)(alias=sven.gehr)(alias=@gehr-edv.de)(alias=@.gehr-edv.de)(alias=@.de)(alias=@.)))"
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisviruslover" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisspamlover" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisbannedfileslover" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisbadheaderlover" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisbypassviruschecks" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisbypassspamchecks" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisbypassbannedchecks" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisbypassheaderchecks" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisspamtaglevel" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisspamtag2level" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisspamkilllevel" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisspamdsncutofflevel" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisspamquarantinecutofflevel" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisspamsubjecttag" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisspamsubjecttag2" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisspammodifiessubj" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisvirusquarantineto" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisspamquarantineto" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisbannedquarantineto" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisbadheaderquarantineto" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisarchivequarantineto" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisblacklistsender" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amaviswhitelistsender" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavislocal" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavismessagesizelimit" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amaviswarnvirusrecip" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amaviswarnbannedrecip" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amaviswarnbadheaderrecip" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisvirusadmin" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisnewvirusadmin" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisspamadmin" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisbannedadmin" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisbadheaderadmin" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_ldap: reading  
> attribute "amavisbannedrulenames" from object
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_ldap(sven.gehr at gehr-edv.de) matches,  
> result=(dn=>"uid=gehr,ou=People,dc=gehr-edv,dc=de")
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_ldap_attr(amavismessagesizelimit), no attribute,  
> "sven.gehr at gehr-edv.de" result=undef
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup  
> [message_size_limit] => undef, "sven.gehr at gehr-edv.de" does not match
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP> 250 2.1.5  
> Recipient <sven.gehr at gehr-edv.de> OK
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_client_time  
> 480 s, smtp response sent
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) idle_proc, 6: was busy,  
> 16.4 ms, total idle 2725.986 s, busy 5.227 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) idle_proc, 5: was idle,  
> 0.2 ms, total idle 2725.986 s, busy 5.227 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP< DATA\r\n
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_my_time      
> 480 s, SMTP DATA received
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP::10024  
> /var/spool/amavisd/tmp/amavis-20121210T112808-07561:  
> <info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu>  
> -> <sven.gehr at gehr-edv.de> SIZE=4962 BODY=7BIT Received: from  
> kolab.local.lan ([127.0.0.1]) by localhost (kolab.local.lan  
> [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for  
> <sven.gehr at gehr-edv.de>; Mon, 10 Dec 2012 12:13:39 +0100 (CET)
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP> 354 End data  
> with <CR><LF>.<CR><LF>
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_client_time  
> 480 s, smtp response sent
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_client_time  
> 480 s, receiving data
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) switch_to_my_time      
> 480 s, data-end received
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ESMTP< .<CR><LF>
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) smtp connection cache,  
> dt: 1815.3, state: 0
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) prolong_timer  
> digest_init: timer set to 480 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) get_body_digest:  
> reading header section
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) prolong_timer  
> digest_hdr: timer set to 480 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) get_body_digest:  
> reading mail body
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) prolong_timer  
> digest_body: timer set to 480 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) body type (ESMTP BODY):  
> labeled 7BIT, good (h=0, b=0)
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) body hash:  
> 1f61e9058dc88bf7bd7f29b222820e51
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) Original mail size:  
> 4962; quota set to: 2481000 bytes
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) generate_mail_id retry:  
> MroZIJt+M1y/KO79aSzOMg
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) Checking: JKcEkmyn8ajk  
> MYNETS [127.0.0.1]  
> <info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu>  
> -> <sven.gehr at gehr-edv.de>
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) 2822.From:  
> <anant at isac.gov.in>, 2822.Sender:  
> <info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu>
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_ldap_attr(amavislocal), no attribute, "sven.gehr at gehr-edv.de"  
> result=1
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup [local_domains]  
> => true,  "sven.gehr at gehr-edv.de" matches, result="1",  
> matching_key="/cached/"
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_ldap_attr(amavisbypassviruschecks), no attribute,  
> "sven.gehr at gehr-edv.de" result=undef
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) query_keys:  
> sven.gehr at gehr-edv.de, sven.gehr@, gehr-edv.de, .gehr-edv.de, .de, .
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_hash(sven.gehr at gehr-edv.de), no matches
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup  
> [bypass_virus_checks] => undef, "sven.gehr at gehr-edv.de" does not match
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_ldap_attr(amavisbypassbannedchecks), no attribute,  
> "sven.gehr at gehr-edv.de" result=undef
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) query_keys:  
> sven.gehr at gehr-edv.de, sven.gehr@, gehr-edv.de, .gehr-edv.de, .de, .
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_hash(sven.gehr at gehr-edv.de), no matches
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup  
> [bypass_banned_checks] => undef, "sven.gehr at gehr-edv.de" does not match
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_ldap_attr(amavisbypassspamchecks), no attribute,  
> "sven.gehr at gehr-edv.de" result=undef
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) query_keys:  
> sven.gehr at gehr-edv.de, sven.gehr@, gehr-edv.de, .gehr-edv.de, .de, .
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_hash(sven.gehr at gehr-edv.de), no matches
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup  
> [bypass_spam_checks] => undef, "sven.gehr at gehr-edv.de" does not match
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) Extracting mime components
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) Issued a new file name: p001
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) Charging 1513 bytes to  
> remaining quota 2481000 (out of 2481000, (0%)) - by mime_decode
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) p001 1 Content-Type:  
> text/plain, size: 1513 B, name:
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) prolong_timer  
> mime_decode: remaining time = 480 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) prolong_timer  
> mime_decode-1: remaining time = 480 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) inspect_dsn: parts: text/plain
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) inspect_dsn: not a bounce
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) prolong_timer  
> dsn_parse: remaining time = 480 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) decode_parts: level=1,  
> #parts=1 : p001
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) running file(1) on 1  
> files, arglist size 18
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) run_command: [8522]  
> /usr/bin/file p001 </dev/null 2>&1
> Dec 10 12:13:39 kolab amavis[8522]: (07561-03) open_on_specific_fd:  
> target fd0 closing, to become < /dev/null
> Dec 10 12:13:39 kolab amavis[8522]: (07561-03) open_on_specific_fd:  
> target fd1 closing, to become > &=16
> Dec 10 12:13:39 kolab amavis[8522]: (07561-03) open_on_specific_fd:  
> target fd1 dup2 from fd16 > &=16
> Dec 10 12:13:39 kolab amavis[8522]: (07561-03) open_on_specific_fd:  
> source fd16 closed
> Dec 10 12:13:39 kolab amavis[8522]: (07561-03) open_on_specific_fd:  
> target fd2 closing, to become > &1
> Dec 10 12:13:39 kolab amavis[8522]: (07561-03) open_on_specific_fd:  
> target fd2 dup2 from fd1 > &1
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) result line from  
> file(1): p001: ASCII English text\n
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_re("ASCII  
> English text") matches key "(?i-xsm:^(ASCII|text)\b)", result="asc"
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup  
> [map_full_type_to_short_type] => true,  "ASCII English text" matches,  
> result="asc", matching_key="(?i-xsm:^(ASCII|text)\\b)"
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) File-type of p001:  
> ASCII English text; (asc)
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) do_ascii: Decoding part p001
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) do_ascii: Setting  
> sigaction handler, was 0
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) timer set to 320 s (was 480 s)
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) do_ascii: Decoding part  
> p001 (0 items), uulib V0.5pl20
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) prolong_timer do_ascii:  
> timer set to 480 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) decompose_part: p001 - atomic
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) prolong_timer  
> parts_decode: remaining time = 480 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_ldap_attr(amavisbypassheaderchecks), no attribute,  
> "sven.gehr at gehr-edv.de" result=undef
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) query_keys:  
> sven.gehr at gehr-edv.de, sven.gehr@, gehr-edv.de, .gehr-edv.de, .de, .
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_hash(sven.gehr at gehr-edv.de), no matches
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup  
> [bypass_header_checks] => undef, "sven.gehr at gehr-edv.de" does not match
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) check_header: 0, OK
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_ldap_attr(amavisbypassheaderchecks), no attribute,  
> "sven.gehr at gehr-edv.de" result=undef
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) query_keys:  
> sven.gehr at gehr-edv.de, sven.gehr@, gehr-edv.de, .gehr-edv.de, .de, .
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_hash(sven.gehr at gehr-edv.de), no matches
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup  
> [bypass_header_checks] => undef, "sven.gehr at gehr-edv.de" does not match
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) Checking for banned  
> types and filenames
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_ldap_attr(amavisbannedrulenames), no attribute,  
> "sven.gehr at gehr-edv.de" result=undef
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup: (scalar)  
> matches, result="DEFAULT"
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup  
> [banned_filename], 1 matches for "sven.gehr at gehr-edv.de", results:  
> "(constant:DEFAULT)"=>"DEFAULT"
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) collect banned  
> table[0]: sven.gehr at gehr-edv.de, tables:  
> DEFAULT=>Amavis::Lookup::RE=ARRAY(0x2abe960)
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) starting banned checks  
> - traversing message structure tree
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) check_for_banned (p001)  
> text/plain,.asc
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) doing banned check for  
> sven.gehr at gehr-edv.de on text/plain,.asc
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_re(["text/plain",".asc"]), no matches
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup  
> [check_bann:sven.gehr at gehr-edv.de] => undef, ["text/plain",".asc"]  
> does not match
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup  
> [banned_namepath_re] => undef, "P=p001\tL=1\tM=text/plain\tT=asc" does  
> not match
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) p.path  
> sven.gehr at gehr-edv.de: "P=p001,L=1,M=text/plain,T=asc"
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) banned check: any=0, all=N (1)
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup_re("MAIL")  
> matches key "(?-xism:^MAIL$)", result="1"
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup  
> [keep_decoded_original] => true,  "MAIL" matches, result="1",  
> matching_key="(?-xism:^MAIL$)"
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) Issued a new file name: p002
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) presenting full  
> original message to scanners as  
> /var/spool/amavisd/tmp/amavis-20121210T112808-07561/parts/p002
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) Calling virus scanners,  
> 2 files to scan in  
> /var/spool/amavisd/tmp/amavis-20121210T112808-07561/parts
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) run_av (ClamAV-clamd):  
> query template(1,1): CONTSCAN {}\n
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) prolong_timer run_av:  
> timer set to 480 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) prolong_timer run_av:  
> timer set to 384 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ask_av Using  
> (ClamAV-clamd): CONTSCAN  
> /var/spool/amavisd/tmp/amavis-20121210T112808-07561/parts\n
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ask_daemon_internal:  
> timer set to 10 s (was 384 s)
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ClamAV-clamd:  
> Connecting to socket  /var/spool/amavisd/clamd.sock
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) creating socket by  
> IO::Socket::UNIX to /var/spool/amavisd/clamd.sock
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ClamAV-clamd: Sending  
> CONTSCAN /var/spool/amavisd/tmp/amavis-20121210T112808-07561/parts\n  
> to UNIX socket /var/spool/amavisd/clamd.sock
> Dec 10 12:13:39 kolab clamd[1646]: SelfCheck: Database status OK.
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) prolong_timer  
> ask_daemon_internal: timer set to 307 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) prolong_timer  
> ask_daemon_internal: timer set to 384 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) prolong_timer ask_av:  
> timer set to 480 s
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) ask_av (ClamAV-clamd)  
> result: /var/spool/amavisd/tmp/amavis-20121210T112808-07561/parts: OK\n
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) run_av (ClamAV-clamd): CLEAN
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) run_av (ClamAV-clamd)  
> result: clean
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) wbl: checking sender  
> <info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu>,  
> <anant at isac.gov.in>
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) query_keys:  
> info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu,  
> @lists.andrew.cmu.edu, @.lists.andrew.cmu.edu, @.andrew.cmu.edu,  
> @.cmu.edu, @.edu, @.
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) wbl: (LDAP) query keys:  
> "info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu",  
> "@lists.andrew.cmu.edu", "@.lists.andrew.cmu.edu", "@.andrew.cmu.edu",  
> "@.cmu.edu", "@.edu", "@."
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_ldap_attr(amavisblacklistsender), no attribute,  
> "sven.gehr at gehr-edv.de" result=undef
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup => undef,  
> "sven.gehr at gehr-edv.de" does not match
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03)  
> lookup_ldap_attr(amaviswhitelistsender), no attribute,  
> "sven.gehr at gehr-edv.de" result=undef
> Dec 10 12:13:39 kolab amavis[7561]: (07561-03) lookup => undef,  
> "sven.gehr at gehr-edv.de" does not match
> Dec 10 12:13:44 kolab postfix/smtpd[8524]: connect from localhost[127.0.0.1]
> Dec 10 12:13:44 kolab postfix/smtpd[8524]: C876F1207FD:  
> client=localhost[127.0.0.1]
> Dec 10 12:13:44 kolab postfix/cleanup[8520]: C876F1207FD:  
> message-id=<201212101112.qBABC7TR006660 at lists2.andrew.cmu.edu>
> Dec 10 12:13:45 kolab postfix/smtpd[8524]: disconnect from  
> localhost[127.0.0.1]
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) rw_loop: receiving
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) rw_loop read 52 chars<  
> 250 2.0.0 Ok: queued as C876F1207FD\r\n221 2.0.0 Bye\r\n
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) smtp resp to data-dot  
> (<sven.gehr at gehr-edv.de>): 250 2.0.0 Ok: queued as C876F1207FD
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03)  
> Amavis::Out::SMTP::Session close, disconnecting
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) prolong_timer  
> fwd-end-chkpnt: timer set to 474 s
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) FWD via SMTP:  
> <info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu>  
> -> <sven.gehr at gehr-edv.de>,BODY=7BIT 250 2.0.0 Ok, id=07561-03, from  
> MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as C876F1207FD
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) prolong_timer  
> forwarding: remaining time = 474 s
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) DSN: sender is credible  
> (orig), SA: -2.324,  
> <info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu>
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) lookup: (scalar)  
> matches, result="18"
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) lookup => true,   
> "info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu"  
> matches, result="18", matching_key="(constant:18)"
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) dsn: from MTA 250  
> NonBlocking:CleanTag  
> <info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu>  
> -> <sven.gehr at gehr-edv.de>: on_succ=0, on_dly=1, on_fail=1, never=0,  
> warn_sender=, DSN_passed_on=1, mta_resp: "250 2.0.0 Ok, id=07561-03,  
> from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as C876F1207FD"
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) DSN: SUCC from MTA 250  
> NonBlocking:CleanTag, no DSN requested:  
> <info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu>  
> -> <sven.gehr at gehr-edv.de>
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) one_response_for_all  
> <info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu>:  
> success, r=0,b=0,d=0, ndn_needed=0, '250 2.0.0 Ok, id=07561-03, from  
> MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as C876F1207FD'
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) notif=N, suppressed=0,  
> ndn_needed=0, exit=0, 250 2.0.0 Ok, id=07561-03, from  
> MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as C876F1207FD
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) prolong_timer  
> delivery-notification: remaining time = 474 s
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03)  
> fish_out_ip_from_received: 218.248.39.236
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) lookup_ip_acl  
> (publicnetworks): key="218.248.39.236" matches "::FFFF:0:0/96", result=1
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03)  
> parse_ip_address_from_received: 218.248.39.236
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) Passed CLEAN, MYNETS  
> LOCAL [127.0.0.1] [218.248.39.236]  
> <info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu>  
> -> <sven.gehr at gehr-edv.de>, Message-ID:  
> <201212101112.qBABC7TR006660 at lists2.andrew.cmu.edu>, mail_id:  
> JKcEkmyn8ajk, Hits: -2.324, size: 4962, queued_as: C876F1207FD, 5597 ms
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) prolong_timer  
> main_log_entry: remaining time = 474 s
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) TIMING-SA total 4886 ms  
> - parse: 5 (0.1%), extract_message_metadata: 25 (0.5%), poll_dns_idle:  
> 475 (9.7%), get_uri_detail_list: 5 (0.1%), tests_pri_-1000: 9 (0.2%),  
> tests_pri_-950: 1.84 (0.0%), tests_pri_-900: 2 (0.0%), tests_pri_-400:  
> 1.55 (0.0%), tests_pri_0: 2767 (56.6%), check_dkim_adsp: 1599 (32.7%),  
> check_spf: 449 (9.2%), check_razor2: 503 (10.3%), check_pyzor: 0.79  
> (0.0%), tests_pri_500: 72 (1.5%), learn: 1962 (40.2%), get_report: 4  
> (0.1%)
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) updating snmp variables
> Dec 10 12:13:45 kolab postfix/qmgr[1740]: C876F1207FD:  
> from=<info-cyrus-bounces+mailingliste=dreampixel.de at lists.andrew.cmu.edu>,  
> size=5568, nrcpt=1 (queue active)
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) prolong_timer check  
> done: remaining time = 474 s
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) sending SMTP response:  
> "250 2.0.0 Ok, id=07561-03, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok:  
> queued as C876F1207FD"
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) ESMTP> 250 2.0.0 Ok,  
> id=07561-03, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as  
> C876F1207FD
> Dec 10 12:13:45 kolab postfix/smtp[8521]: 8F0F81207F3:  
> to=<sven.gehr at gehr-edv.de>, orig_to=<sven at dreampixel.de>,  
> relay=127.0.0.1[127.0.0.1]:10024, delay=5.8,  
> delays=0.13/0.02/0.01/5.6, dsn=2.0.0, status=sent (250 2.0.0 Ok,  
> id=07561-03, from MTA([127.0.0.1]:10025): 250 2.0.0 Ok: queued as  
> C876F1207FD)
> Dec 10 12:13:45 kolab postfix/qmgr[1740]: 8F0F81207F3: removed
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) switch_to_client_time  
> 480 s, smtp response sent
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) TempDir::strip:  
> /var/spool/amavisd/tmp/amavis-20121210T112808-07561
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) rmdir_recursively:  
> /var/spool/amavisd/tmp/amavis-20121210T112808-07561/parts, excl=1
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) TIMING [total 5617 ms]  
> - SMTP greeting: 4 (0%)0, SMTP EHLO: 3 (0%)0, SMTP pre-MAIL: 3 (0%)0,  
> lookup_ldap: 18 (0%)1, SMTP pre-DATA-flush: 2 (0%)1, SMTP DATA: 18  
> (0%)1, check_init: 1 (0%)1, digest_hdr: 7 (0%)1, digest_body_dkim: 2  
> (0%)1, gen_mail_id: 2 (0%)1, mime_decode: 16 (0%)1, get-file-type1: 36  
> (1%)2, decompose_part: 3 (0%)2, parts_decode: 0 (0%)2, check_header: 6  
> (0%)2, AV-scan-1: 15 (0%)2, spam-wb-list: 10 (0%)3, SA parse: 8 (0%)3,  
> SA check: 4870 (87%)89, update_cache: 16 (0%)90, decide_mail_destiny:  
> 3 (0%)90, fwd-connect: 35 (1%)90, fwd-xforward: 3 (0%)90,  
> fwd-mail-pip: 30 (1%)91, fwd-rcpt-pip: 1 (0%)91, fwd-data-chkpnt: 0  
> (0%)91, write-header: 4 (0%)91, fwd-data-contents: 0 (0%)91,  
> fwd-end-chkpnt: 466 (8%)99, prepare-dsn: 4 (0%)99, main_log_entry: 11  
> (0%)100, update_snmp: 8 (0%)100, SMTP pre-response: 1 (0%)100, SMTP  
> response: 8 (0%)100, unlink-2-files: 1 (0%)100, rundown: 1 (0%)100
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) idle_proc, 6: was busy,  
> 5588.7 ms, total idle 2725.986 s, busy 10.816 s
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) idle_proc, 5: was idle,  
> 0.4 ms, total idle 2725.987 s, busy 10.816 s
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) ESMTP< QUIT\r\n
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) switch_to_my_time      
> 480 s, SMTP QUIT received
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) ESMTP> 221 2.0.0  
> [127.0.0.1] amavisd-new closing transmission channel
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) switch_to_client_time  
> 480 s, smtp response sent
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) SMTP session over,  
> timer stopped
> Dec 10 12:13:45 kolab postfix/smtp[8525]: C876F1207FD:  
> to=<sven.gehr at gehr-edv.de>, relay=127.0.0.1[127.0.0.1]:10026,  
> delay=0.54, delays=0.51/0.01/0/0.01, dsn=2.0.0, status=sent (250 Ok)
> Dec 10 12:13:45 kolab postfix/qmgr[1740]: C876F1207FD: removed
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) exiting process_request
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03)  
> post_process_request_hook: timer was not running
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) idle_proc, bye: was  
> busy, 11.4 ms, total idle 2725.987 s, busy 10.827 s
> Dec 10 12:13:45 kolab imaps[8480]: accepted connection
> Dec 10 12:13:45 kolab amavis[7561]: (07561-03) load: 0 %, total idle  
> 2725.987 s, busy 10.827 s
> Dec 10 12:13:45 kolab master[8526]: about to exec /usr/lib/cyrus-imapd/imapd
> Dec 10 12:13:45 kolab imaps[8526]: executed
> Dec 10 12:13:45 kolab imaps[8526]: IOERROR: opening  
> /var/lib/imap/user_deny.db: No such file or directory
> Dec 10 12:13:45 kolab imaps[8480]: imapd:Loading hard-coded DH parameters
> Dec 10 12:13:45 kolab imaps[8480]: SSL_accept() incomplete -> wait
> Dec 10 12:13:45 kolab imaps[8480]: SSL_accept() succeeded -> done
> Dec 10 12:13:45 kolab imaps[8480]: starttls: TLSv1 with cipher  
> DHE-RSA-AES256-SHA (256/256 bits new) no authentication
> Dec 10 12:13:45 kolab imaps[8480]: ptload(): fetched cache record  
> (cyrus-admin)(mark 1355137843, current 1355138025, limit 1355127225)
> Dec 10 12:13:45 kolab imaps[8480]: ptload returning data
> Dec 10 12:13:45 kolab imaps[8480]: canonified cyrus-admin -> cyrus-admin
> Dec 10 12:13:45 kolab imaps[8480]: login: localhost [127.0.0.1]  
> cyrus-admin plaintext+TLS User logged in  
> SESSIONID=<kolab.local.lan-8480-1355138025-1>
> Dec 10 12:13:45 kolab postfix/smtpd[8527]: connect from localhost[127.0.0.1]
> Dec 10 12:13:45 kolab postfix/smtpd[8527]: A42B91207FF:  
> client=localhost[127.0.0.1]
> Dec 10 12:13:45 kolab postfix/cleanup[8520]: A42B91207FF:  
> message-id=<201212101112.qBABC7TR006660 at lists2.andrew.cmu.edu>
> Dec 10 12:13:45 kolab postfix/qmgr[1740]: A42B91207FF:  
> from=<anant at isac.gov.in>, size=5763, nrcpt=1 (queue active)
> Dec 10 12:13:45 kolab postfix/smtpd[8527]: disconnect from  
> localhost[127.0.0.1]
> Dec 10 12:13:45 kolab postfix/smtp[8528]: certificate verification  
> failed for mail.gehr-edv.de[62.75.220.38]:25: self-signed certificate
> Dec 10 12:13:46 kolab postfix/smtp[8528]: A42B91207FF:  
> to=<info-cyrus at lists.andrew.cmu.edu>,  
> relay=mail.gehr-edv.de[62.75.220.38]:25, delay=0.42,  
> delays=0.08/0.02/0.19/0.13, dsn=2.0.0, status=sent (250 2.0.0 Ok:  
> queued as 2FAB4CD0165)
> Dec 10 12:13:46 kolab postfix/qmgr[1740]: A42B91207FF: removed
> Dec 10 12:14:58 kolab master[1585]: process 8495 exited, status 0
> Dec 10 12:15:23 kolab master[1585]: process 8480 exited, status 0
> Dec 10 12:15:33 kolab imap[8497]: accepted connection
> Dec 10 12:15:33 kolab master[8534]: about to exec /usr/lib/cyrus-imapd/imapd
> Dec 10 12:15:33 kolab imap[8534]: executed
> Dec 10 12:15:33 kolab imap[8534]: IOERROR: opening  
> /var/lib/imap/user_deny.db: No such file or directory
> Dec 10 12:15:33 kolab imap[8497]: imapd:Loading hard-coded DH parameters
> Dec 10 12:15:33 kolab imap[8497]: SSL_accept() incomplete -> wait
> Dec 10 12:15:33 kolab imap[8497]: SSL_accept() succeeded -> done
> Dec 10 12:15:33 kolab imap[8497]: starttls: TLSv1 with cipher  
> DHE-RSA-AES256-SHA (256/256 bits new) no authentication
> Dec 10 12:15:33 kolab imap[8497]: client id: "name" "Roundcube"  
> "version" "0.9-git" "php" "5.3.10" "os" "Linux" "command"  
> "/roundcubemail/?_task=addressbook&_action=refresh&_remote=1&_unlock=loading1355138134347&_=1355138134352"
> Dec 10 12:15:33 kolab imap[8497]: ptload(): fetched cache record  
> (sven.gehr at gehr-edv.de)(mark 1355136320, current 1355138133, limit  
> 1355127333)
> Dec 10 12:15:33 kolab imap[8497]: ptload returning data
> Dec 10 12:15:33 kolab imap[8497]: canonified sven.gehr at gehr-edv.de ->  
> sven.gehr at gehr-edv.de
> Dec 10 12:15:33 kolab imap[8497]: login: localhost [127.0.0.1]  
> sven.gehr at gehr-edv.de PLAIN+TLS User logged in  
> SESSIONID=<kolab.local.lan-8497-1355138133-1>
> Dec 10 12:15:33 kolab imap[8497]: open: user sven^gehr at gehr-edv.de  
> opened Kalender
> Dec 10 12:15:34 kolab imap[8497]: open: user sven^gehr at gehr-edv.de  
> opened Tasks
> Dec 10 12:15:34 kolab imap[8497]: USAGE sven^gehr at gehr-edv.de user:  
> 0.065989 sys: 0.018997
> Dec 10 12:17:12 kolab master[1585]: process 8497 exited, status 0
>
> _______________________________________________
> Kolab-users mailing list
> Kolab-users at kolab.org
> https://www.intevation.de/mailman/listinfo/kolab-users


-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 4495 bytes
Desc: S/MIME Kryptografische Unterschrift
URL: <http://lists.kolab.org/pipermail/users/attachments/20121210/9d6a4e48/attachment.p7s>


More information about the users mailing list