Wallace rejecting email

Sruli Saurymper sruli at saurymper.com
Thu Jan 8 18:25:04 CET 2015


Hi all,
Can anyone please help me with regards to below?

I setup kolab 3.3 on centos7 for testing I created a postmaster email, 
it worked fine, I then changed it to a multidomain system and also 
changed the recipient policy (in kolab.conf i added "daemon_rcpt_policy 
= False") since then I get a bounce when sending an email to the 
postmaster address, I deleted the user from webadmin and re-added it but 
it did not solve the issue. I created another email address and that 
email works fine, see the bounce message below and I attach the maillog 
file for the session of the failed email.

If anyone can help will be appreciated

Thanks
Sruli

This is the email system Wallace at localhost.localdomain.

I'm sorry to inform you we could not deliver the attached message
to the following recipients:

- master, post<postmaster at twsinternet.co.uk>
-postmaster at twsinternet.co.uk

Your message is being delivered to any other recipients you may have
sent your message to. There is no need to resend the message to those
recipients.



X-Module: resources
X-Wallace-Result: REJECT


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kolab.org/pipermail/users/attachments/20150108/463e0815/attachment-0001.html>
-------------- next part --------------
Jan  6 13:22:18 mail postfix/smtpd[2699]: connect from unknown[213.171.197.242]
Jan  6 13:22:30 mail postfix/smtpd[2699]: 66D2D18004C1D: client=unknown[213.171.197.242]
Jan  6 13:22:30 mail postfix/cleanup[2711]: 66D2D18004C1D: message-id=<54ABE16C.4060009 at saurymper.com>
Jan  6 13:22:30 mail postfix/qmgr[1825]: 66D2D18004C1D: from=<sruli at saurymper.com>, size=1136, nrcpt=1 (queue active)
Jan  6 13:22:30 mail postfix/smtpd[2699]: disconnect from unknown[213.171.197.242]
Jan  6 13:22:30 mail amavis[2683]: Net::Server: 2015/01/06-13:22:30 CONNECT TCP Peer: "[127.0.0.1]:53944" Local: "[127.0.0.1]:10024"
Jan  6 13:22:30 mail amavis[2683]: loaded base policy bank
Jan  6 13:22:30 mail amavis[2683]: lookup_ip_acl (inet_acl) arr.obj: key="127.0.0.1" matches "127.0.0.1", result=1
Jan  6 13:22:30 mail amavis[2683]: process_request: fileno sock=14, STDIN=0, STDOUT=1
Jan  6 13:22:30 mail amavis[2683]: get_deadline switch_to_my_time(new request) - deadline in 480.0 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: prolong_timer switch_to_my_time(new request): timer 336, was 0, deadline in 480.0 s
Jan  6 13:22:30 mail amavis[2683]: process_request: suggested_protocol="" on a TCP socket
Jan  6 13:22:30 mail amavis[2683]: (02683-01) SMTP> 220 [127.0.0.1] ESMTP amavisd-new service ready
Jan  6 13:22:30 mail amavis[2683]: (02683-01) switch_to_client_time 480 s, smtp response sent
Jan  6 13:22:30 mail amavis[2683]: (02683-01) idle_proc, 4: was busy, 34.3 ms, total idle 0.000 s, busy 0.034 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) smtp readline: read 29 bytes, new size: 29
Jan  6 13:22:30 mail amavis[2683]: (02683-01) idle_proc, 5: was idle, 1.0 ms, total idle 0.001 s, busy 0.034 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) SMTP< EHLO mail.twsinternet.co.uk\r\n
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline switch_to_my_time(rx SMTP EHLO) - deadline in 480.0 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer switch_to_my_time(rx SMTP EHLO): timer 336, was 480, deadline in 480.0 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP> 250-[127.0.0.1]
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP> 250-VRFY
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP> 250-PIPELINING
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP> 250-SIZE
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP> 250-ENHANCEDSTATUSCODES
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP> 250-8BITMIME
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP> 250-DSN
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP> 250 XFORWARD NAME ADDR PORT PROTO HELO IDENT SOURCE
Jan  6 13:22:30 mail amavis[2683]: (02683-01) switch_to_client_time 480 s, smtp response sent
Jan  6 13:22:30 mail amavis[2683]: (02683-01) idle_proc, 6: was busy, 3.9 ms, total idle 0.001 s, busy 0.038 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) smtp readline: read 250 bytes, new size: 250
Jan  6 13:22:30 mail amavis[2683]: (02683-01) idle_proc, 5: was idle, 0.5 ms, total idle 0.002 s, busy 0.038 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP< XFORWARD ADDR=213.171.197.242 PORT=52806\r\n
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline switch_to_my_time(rx SMTP XFORWARD) - deadline in 480.0 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer switch_to_my_time(rx SMTP XFORWARD): timer 336, was 480, deadline in 480.0 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP> 250 2.5.0 Ok XFORWARD
Jan  6 13:22:30 mail amavis[2683]: (02683-01) switch_to_client_time 480 s, smtp response sent
Jan  6 13:22:30 mail amavis[2683]: (02683-01) idle_proc, 6: was busy, 4.3 ms, total idle 0.002 s, busy 0.043 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) idle_proc, 5: was idle, 0.7 ms, total idle 0.002 s, busy 0.043 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP< XFORWARD PROTO=ESMTP HELO=twsinternet.com IDENT=66D2D18004C1D SOURCE=REMOTE\r\n
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline switch_to_my_time(rx SMTP XFORWARD) - deadline in 480.0 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer switch_to_my_time(rx SMTP XFORWARD): timer 336, was 480, deadline in 480.0 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP> 250 2.5.0 Ok XFORWARD
Jan  6 13:22:30 mail amavis[2683]: (02683-01) switch_to_client_time 480 s, smtp response sent
Jan  6 13:22:30 mail amavis[2683]: (02683-01) idle_proc, 6: was busy, 4.3 ms, total idle 0.002 s, busy 0.047 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) idle_proc, 5: was idle, 0.7 ms, total idle 0.003 s, busy 0.047 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP< MAIL FROM:<sruli at saurymper.com> SIZE=1136\r\n
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline switch_to_my_time(rx SMTP MAIL) - deadline in 480.0 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer switch_to_my_time(rx SMTP MAIL): timer 336, was 480, deadline in 480.0 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) check_mail_begin_task: task_count=1
Jan  6 13:22:30 mail amavis[2683]: (02683-01) TempDir::prepare_dir: created directory /var/spool/amavisd/tmp/amavis-20150106T132230-02683-xVYaZk0y
Jan  6 13:22:30 mail amavis[2683]: (02683-01) TempDir::prepare_file: creating file /var/spool/amavisd/tmp/amavis-20150106T132230-02683-xVYaZk0y/email.txt
Jan  6 13:22:30 mail amavis[2683]: (02683-01) TempDir::prepare_file: layers: unix,perlio
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ip_acl (client_ipaddr_policy) arr.obj: key="213.171.197.242", no match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [debug_sender] => undef, "sruli at saurymper.com" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) mesage size set to a declared size 1136
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP> 250 2.1.0 Sender <sruli at saurymper.com> OK
Jan  6 13:22:30 mail amavis[2683]: (02683-01) switch_to_client_time 480 s, smtp response sent
Jan  6 13:22:30 mail amavis[2683]: (02683-01) idle_proc, 6: was busy, 17.7 ms, total idle 0.003 s, busy 0.065 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) idle_proc, 5: was idle, 0.1 ms, total idle 0.003 s, busy 0.065 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP< RCPT TO:<postmaster at twsinternet.co.uk> ORCPT=rfc822;postmaster at twsinternet.co.uk\r\n
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline switch_to_my_time(rx SMTP RCPT) - deadline in 480.0 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer switch_to_my_time(rx SMTP RCPT): timer 336, was 480, deadline in 480.0 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup => undef, "postmaster at twsinternet.co.uk", no lookup tables
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_re("postmaster at twsinternet.co.uk") matches key "(?^:.*)", result="1"
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [local_domains] => true,  "postmaster at twsinternet.co.uk" matches, result="1", matching_key="(?^:.*)"
Jan  6 13:22:30 mail amavis[2683]: (02683-01) query_keys: postmaster at twsinternet.co.uk, postmaster, @twsinternet.co.uk, @.twsinternet.co.uk, @.co.uk, @.uk, @.
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap "postmaster at twsinternet.co.uk", query keys: "postmaster at twsinternet.co.uk", "postmaster", "@twsinternet.co.uk", "@.twsinternet.co.uk", "@.co.uk", "@.uk", "@.", base: dc=twsinternet,dc=co,dc=uk, filter: (|(mail=%m)(alias=%m))
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ldap begin_work
Jan  6 13:22:30 mail amavis[2683]: (02683-01) Connecting to LDAP server
Jan  6 13:22:30 mail amavis[2683]: (02683-01) connect_to_ldap: trying localhost
Jan  6 13:22:30 mail amavis[2683]: (02683-01) connect_to_ldap: connected to localhost
Jan  6 13:22:30 mail amavis[2683]: (02683-01) connect_to_ldap: bind uid=kolab-service,ou=Special Users,dc=twsinternet,dc=co,dc=uk succeeded
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: searching base="dc=twsinternet,dc=co,dc=uk", scope="sub", filter="(|(|(mail=postmaster at twsinternet.co.uk)(mail=postmaster)(mail=@twsinternet.co.uk)(mail=@.twsinternet.co.uk)(mail=@.co.uk)(mail=@.uk)(mail=@.))(|(alias=postmaster at twsinternet.co.uk)(alias=postmaster)(alias=@twsinternet.co.uk)(alias=@.twsinternet.co.uk)(alias=@.co.uk)(alias=@.uk)(alias=@.)))"
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisLocal" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisMessageSizeLimit" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisVirusLover" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisSpamLover" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisUncheckedLover" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisBannedFilesLover" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisBadHeaderLover" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisBypassVirusChecks" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisBypassSpamChecks" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisBypassBannedChecks" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisBypassHeaderChecks" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisSpamTagLevel" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisSpamTag2Level" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisSpamKillLevel" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisSpamDsnCutoffLevel" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisSpamQuarantineCutoffLevel" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisSpamSubjectTag" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisSpamSubjectTag2" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisSpamModifiesSubj" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisVirusQuarantineTo" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisSpamQuarantineTo" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisBannedQuarantineTo" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisUncheckedQuarantineTo" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisBadHeaderQuarantineTo" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisCleanQuarantineTo" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisArchiveQuarantineTo" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisAddrExtensionVirus" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisAddrExtensionSpam" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisAddrExtensionBanned" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisAddrExtensionBadHeader" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisWarnVirusRecip" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisWarnBannedRecip" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisWarnBadHeaderRecip" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisVirusAdmin" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisNewVirusAdmin" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisSpamAdmin" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisBannedAdmin" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisBadHeaderAdmin" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisBannedRuleNames" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisDisclaimerOptions" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisForwardMethod" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisSaUserConf" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisSaUserName" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisBlacklistSender" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisWhitelistSender" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavislocal" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavismessagesizelimit" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisviruslover" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisspamlover" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisuncheckedlover" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisbannedfileslover" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisbadheaderlover" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisbypassviruschecks" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisbypassspamchecks" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisbypassbannedchecks" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisbypassheaderchecks" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisspamtaglevel" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisspamtag2level" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisspamkilllevel" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisspamdsncutofflevel" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisspamquarantinecutofflevel" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisspamsubjecttag" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisspamsubjecttag2" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisspammodifiessubj" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisvirusquarantineto" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisspamquarantineto" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisbannedquarantineto" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisuncheckedquarantineto" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisbadheaderquarantineto" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amaviscleanquarantineto" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisarchivequarantineto" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisaddrextensionvirus" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisaddrextensionspam" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisaddrextensionbanned" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisaddrextensionbadheader" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amaviswarnvirusrecip" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amaviswarnbannedrecip" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amaviswarnbadheaderrecip" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisvirusadmin" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisnewvirusadmin" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisspamadmin" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisbannedadmin" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisbadheaderadmin" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisbannedrulenames" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisdisclaimeroptions" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisforwardmethod" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavissauserconf" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavissausername" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amavisblacklistsender" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap: reading attribute "amaviswhitelistsender" from object
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap(postmaster at twsinternet.co.uk) matches, result=(dn=>"cn=share2,ou=Shared Folders,dc=twsinternet,dc=co,dc=uk")
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap(postmaster at twsinternet.co.uk) matches, result=(dn=>"uid=postmaster,ou=People,dc=twsinternet,dc=co,dc=uk")
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisMessageSizeLimit) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisMessageSizeLimit) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisMessageSizeLimit
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [message_size_limit] => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP> 250 2.1.5 Recipient <postmaster at twsinternet.co.uk> OK
Jan  6 13:22:30 mail amavis[2683]: (02683-01) switch_to_client_time 480 s, smtp response sent
Jan  6 13:22:30 mail amavis[2683]: (02683-01) idle_proc, 6: was busy, 99.9 ms, total idle 0.003 s, busy 0.164 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) idle_proc, 5: was idle, 0.7 ms, total idle 0.004 s, busy 0.164 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP< DATA\r\n
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline switch_to_my_time(rx SMTP DATA) - deadline in 480.0 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer switch_to_my_time(rx SMTP DATA): timer 336, was 480, deadline in 480.0 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP:[127.0.0.1]:10024 /var/spool/amavisd/tmp/amavis-20150106T132230-02683-xVYaZk0y: <sruli at saurymper.com> -> <postmaster at twsinternet.co.uk> SIZE=1136 Received: from mail.twsinternet.co.uk ([127.0.0.1]) by localhost (mail.twsinternet.co.uk [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for <postmaster at twsinternet.co.uk>; Tue,  6 Jan 2015 13:22:30 +0000 (GMT)
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP> 354 End data with <CR><LF>.<CR><LF>
Jan  6 13:22:30 mail amavis[2683]: (02683-01) switch_to_client_time 480 s, smtp response sent
Jan  6 13:22:30 mail amavis[2683]: (02683-01) switch_to_client_time 480 s, receiving data
Jan  6 13:22:30 mail amavis[2683]: (02683-01) smtp copy: read 1145 bytes into buffer, new size: 1145
Jan  6 13:22:30 mail amavis[2683]: (02683-01) smtp copy: 6 bytes still buffered at end
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline switch_to_my_time(rx data-end) - deadline in 480.0 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer switch_to_my_time(rx data-end): timer 336, was 480, deadline in 480.0 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ESMTP< .<CR><LF>
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline get_body_digest - deadline in 480.0 s, set to 30.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline digest_pre - deadline in 480.0 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer digest_pre: timer 336, was 336, deadline in 480.0 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_body_digest: reading header section from memory
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_body_digest: sending h/b separator to DKIM
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline digest_hdr - deadline in 480.0 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer digest_hdr: timer 336, was 336, deadline in 480.0 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_body_digest: reading mail body from memory
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline digest_body - deadline in 480.0 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer digest_body: timer 336, was 336, deadline in 480.0 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_body_digest: message size 1136, header+sep 1132, body 4
Jan  6 13:22:30 mail amavis[2683]: (02683-01) body type (ESMTP BODY): unlabeled, good (h=0, b=0)
Jan  6 13:22:30 mail amavis[2683]: (02683-01) body hash: e1c06d85ae7b8b032bef47e42e4c08f9
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ip_from_received: 213.171.197.242
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ip_from_received: 192.168.235.104
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ip_trace: 213.171.197.242 < 192.168.235.104
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ip_acl (public_nets) arr.obj: key="213.171.197.242" matches "::ffff:0:0/96", result=1
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ip_acl (public_nets) arr.obj: key="192.168.235.104" matches "!192.168.0.0/16", result=0
Jan  6 13:22:30 mail amavis[2683]: (02683-01) Original mail size: 1136; quota set to: 568000 bytes (fmin=5, fmax=500, qmin=102400, qmax=314572800)
Jan  6 13:22:30 mail amavis[2683]: (02683-01) Checking: lOraVyOhrXnm [213.171.197.242] <sruli at saurymper.com> -> <postmaster at twsinternet.co.uk>
Jan  6 13:22:30 mail amavis[2683]: (02683-01) 2822.From: <sruli at saurymper.com>
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisLocal) rec=0, "postmaster at twsinternet.co.uk" result: "1"
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisLocal
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [local_domains] => true,  "postmaster at twsinternet.co.uk" matches, result="1", matching_key="/cached/"
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBypassVirusChecks) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBypassVirusChecks) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisBypassVirusChecks
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [bypass_virus_checks] => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBypassBannedChecks) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBypassBannedChecks) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisBypassBannedChecks
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [bypass_banned_checks] => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBypassSpamChecks) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBypassSpamChecks) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisBypassSpamChecks
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [bypass_spam_checks] => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) Extracting mime components from a string
Jan  6 13:22:30 mail amavis[2683]: (02683-01) Issued a new file name: p001
Jan  6 13:22:30 mail amavis[2683]: (02683-01) Charging 2 bytes to remaining quota 568000 (out of 568000, (0%)) - by mime_decode
Jan  6 13:22:30 mail amavis[2683]: (02683-01) p001 1 Content-Type: text/plain, size: 2 B, name:
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline mime_decode - deadline in 479.9 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer mime_decode: timer 336, was 336, deadline in 479.9 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline mime_decode-1 - deadline in 479.9 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer mime_decode-1: timer 336, was 336, deadline in 479.9 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) inspect_dsn: parts: text/plain
Jan  6 13:22:30 mail amavis[2683]: (02683-01) inspect_dsn: not a bounce
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline dsn_parse - deadline in 479.9 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer dsn_parse: timer 336, was 336, deadline in 479.9 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) decode_parts: level=1, #parts=1 : p001
Jan  6 13:22:30 mail amavis[2683]: (02683-01) running file(1) on 1 files, arglist size 18
Jan  6 13:22:30 mail amavis[2683]: (02683-01) run_command: [2713] /usr/bin/file p001 </dev/null 2>&1
Jan  6 13:22:30 mail amavis[2713]: (02683-01) open_on_specific_fd: target fd0 closing, to become < /dev/null
Jan  6 13:22:30 mail amavis[2713]: (02683-01) open_on_specific_fd: target fd1 closing, to become (65) &=18
Jan  6 13:22:30 mail amavis[2713]: (02683-01) open_on_specific_fd: target fd1 dup2 from fd18 (65) &=18
Jan  6 13:22:30 mail amavis[2713]: (02683-01) open_on_specific_fd: source fd18 closed
Jan  6 13:22:30 mail amavis[2713]: (02683-01) open_on_specific_fd: target fd2 closing, to become (65) &1
Jan  6 13:22:30 mail amavis[2713]: (02683-01) open_on_specific_fd: target fd2 dup2 from fd1 (65) &1
Jan  6 13:22:30 mail amavis[2683]: (02683-01) result line from file(1): p001: ASCII text\n
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_re("ASCII text") matches key "(?^i:^(ASCII|text)\b)", result="asc"
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [map_full_type_to_short_type] => true,  "ASCII text" matches, result="asc", matching_key="(?^i:^(ASCII|text)\134b)"
Jan  6 13:22:30 mail amavis[2683]: (02683-01) File-type of p001: ASCII text; (asc)
Jan  6 13:22:30 mail amavis[2683]: (02683-01) do_ascii: Decoding part p001
Jan  6 13:22:30 mail amavis[2683]: (02683-01) do_ascii: Setting sigaction handler, was 0
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline do_ascii_pre - deadline in 479.9 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer do_ascii_pre: timer 336, was 0, deadline in 479.9 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) do_ascii: Decoding part p001 (0 items), uulib V0.5pl20
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline do_ascii - deadline in 479.9 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer do_ascii: timer 336, was 336, deadline in 479.9 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) decompose_part: p001 - atomic
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline parts_decode - deadline in 479.9 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer parts_decode: timer 336, was 336, deadline in 479.9 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBypassHeaderChecks) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBypassHeaderChecks) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisBypassHeaderChecks
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [bypass_header_checks] => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) check_header: 0, OK
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBypassHeaderChecks) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBypassHeaderChecks) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisBypassHeaderChecks
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [bypass_header_checks] => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) Checking for banned types and filenames
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBannedRuleNames) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBannedRuleNames) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisBannedRuleNames
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup: (scalar) matches, result="DEFAULT"
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [banned_filename], 1 matches for "postmaster at twsinternet.co.uk", results: "(constant:DEFAULT)"=>"DEFAULT"
Jan  6 13:22:30 mail amavis[2683]: (02683-01) collect banned table[0]: postmaster at twsinternet.co.uk, tables: DEFAULT=>Amavis::Lookup::RE=ARRAY(0x2b46188)
Jan  6 13:22:30 mail amavis[2683]: (02683-01) starting banned checks - traversing message structure tree
Jan  6 13:22:30 mail amavis[2683]: (02683-01) check_for_banned (p001) text/plain,.asc
Jan  6 13:22:30 mail amavis[2683]: (02683-01) doing banned check for postmaster at twsinternet.co.uk on text/plain,.asc
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_re(["text/plain",".asc"]), no matches
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [check_bann:postmaster at twsinternet.co.uk] => undef, ["text/plain",".asc"] does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [banned_namepath_re] => undef, "P=p001\tL=1\tM=text/plain\tT=asc" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) p.path postmaster at twsinternet.co.uk: "P=p001,L=1,M=text/plain,T=asc"
Jan  6 13:22:30 mail amavis[2683]: (02683-01) banned check: any=0, all=N (1)
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_re("MAIL") matches key "(?^:^MAIL$)", result="1"
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [keep_decoded_original] => true,  "MAIL" matches, result="1", matching_key="(?^:^MAIL$)"
Jan  6 13:22:30 mail amavis[2683]: (02683-01) Issued a new file name: p002
Jan  6 13:22:30 mail amavis[2683]: (02683-01) presenting full original message to scanners as /var/spool/amavisd/tmp/amavis-20150106T132230-02683-xVYaZk0y/parts/p002
Jan  6 13:22:30 mail amavis[2683]: (02683-01) Calling virus scanners, 2 files to scan in /var/spool/amavisd/tmp/amavis-20150106T132230-02683-xVYaZk0y/parts
Jan  6 13:22:30 mail amavis[2683]: (02683-01) invoking av-scanner ClamAV-clamd
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ask_daemon: proto=DFLT, spawn=0, (ClamAV-clamd) /var/run/clamd.amavisd/clamd.sock
Jan  6 13:22:30 mail amavis[2683]: (02683-01) run_av (ClamAV-clamd): query template(1,1): CONTSCAN {}\n
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline run_av_pre - deadline in 479.8 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer run_av_pre: timer 336, was 336, deadline in 479.8 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline run_av_scan - deadline in 479.8 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer run_av_scan: timer 336, was 336, deadline in 479.8 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) run_av Using (ClamAV-clamd): (code) CONTSCAN /var/spool/amavisd/tmp/amavis-20150106T132230-02683-xVYaZk0y/parts\n
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline ask_daemon_internal_connect_pre - deadline in 479.8 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline ask_daemon_internal_connect - deadline in 479.8 s, set to 10.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer ask_daemon_internal_connect: timer 10, was 336, deadline in 479.8 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ClamAV-clamd: Connecting to socket  /var/run/clamd.amavisd/clamd.sock
Jan  6 13:22:30 mail amavis[2683]: (02683-01) new socket by IO::Socket::UNIX to /var/run/clamd.amavisd/clamd.sock, timeout 10
Jan  6 13:22:30 mail amavis[2683]: (02683-01) connected to /var/run/clamd.amavisd/clamd.sock successfully
Jan  6 13:22:30 mail amavis[2683]: (02683-01) ClamAV-clamd: Sending CONTSCAN /var/spool/amavisd/tmp/amavis-20150106T132230-02683-xVYaZk0y/parts\n to socket /var/run/clamd.amavisd/clamd.sock
Jan  6 13:22:30 mail amavis[2683]: (02683-01) rw_loop: needline=0, flush=1, wr=1, timeout=10
Jan  6 13:22:30 mail amavis[2683]: (02683-01) rw_loop: sending 76 chars
Jan  6 13:22:30 mail amavis[2683]: (02683-01) rw_loop sent 76> CONTSCAN /var/spool/amavisd/tmp/amavis-20150106T132230-02683-xVYaZk0y/parts\n
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline ask_daemon_internal_scan - deadline in 479.8 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer ask_daemon_internal_scan: timer 336, was 10, deadline in 479.8 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) rw_loop: needline=0, flush=0, wr=0, timeout=335.990
Jan  6 13:22:30 mail amavis[2683]: (02683-01) rw_loop: receiving
Jan  6 13:22:30 mail amavis[2683]: (02683-01) rw_loop read 71 chars< /var/spool/amavisd/tmp/amavis-20150106T132230-02683-xVYaZk0y/parts: OK\n
Jan  6 13:22:30 mail amavis[2683]: (02683-01) rw_loop: needline=0, flush=0, wr=0, timeout=335.990
Jan  6 13:22:30 mail amavis[2683]: (02683-01) rw_loop: receiving
Jan  6 13:22:30 mail amavis[2683]: (02683-01) rw_loop read: got eof
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline ask_daemon_internal - deadline in 479.8 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer ask_daemon_internal: timer 336, was 336, deadline in 479.8 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) get_deadline run_av_3 - deadline in 479.8 s, set to 336.000 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) prolong_timer run_av_3: timer 336, was 336, deadline in 479.8 s
Jan  6 13:22:30 mail amavis[2683]: (02683-01) run_av (ClamAV-clamd) result: /var/spool/amavisd/tmp/amavis-20150106T132230-02683-xVYaZk0y/parts: OK\n
Jan  6 13:22:30 mail amavis[2683]: (02683-01) run_av (ClamAV-clamd): CLEAN
Jan  6 13:22:30 mail amavis[2683]: (02683-01) run_av (ClamAV-clamd) result: clean
Jan  6 13:22:30 mail amavis[2683]: (02683-01) wbl: checking sender <sruli at saurymper.com>
Jan  6 13:22:30 mail amavis[2683]: (02683-01) query_keys: sruli at saurymper.com, @saurymper.com, @.saurymper.com, @.com, @.
Jan  6 13:22:30 mail amavis[2683]: (02683-01) wbl: (LDAP) query keys: "sruli at saurymper.com", "@saurymper.com", "@.saurymper.com", "@.com", "@."
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBlacklistSender) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisBlacklistSender) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisBlacklistSender
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisWhitelistSender) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisWhitelistSender) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisWhitelistSender
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [blacklist_recip<postmaster at twsinternet.co.uk>] => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [blacklist_sender<sruli at saurymper.com>,blacklist_sender] => undef, "sruli at saurymper.com" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [whitelist_recip<postmaster at twsinternet.co.uk>] => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [whitelist_sender<sruli at saurymper.com>,whitelist_sender] => undef, "sruli at saurymper.com" does not match
Jan  6 13:22:30 mail amavis[2683]: (02683-01) query_keys: postmaster at twsinternet.co.uk, postmaster@, twsinternet.co.uk, .twsinternet.co.uk, .co.uk, .uk, .
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup_hash(postmaster at twsinternet.co.uk) matches keys: "."=>ARRAY(0x2b4c068)
Jan  6 13:22:30 mail amavis[2683]: (02683-01) lookup [score_recip<postmaster at twsinternet.co.uk>,score_sender], 1 matches for "postmaster at twsinternet.co.uk", results: "."=>[Amavis::Lookup::RE=ARRAY(0x2b462f0),{amavis-user-admin at lists.sourceforge.net=>"-3",owner-postfix-announce at postfix.org=>"-3",ntbugtraq at listserv.ntbugtraq.com=>"-3",donotreply at sendmail.org=>"-3",slashdot at slashdot.org=>"-3",clp-request at comp.nus.edu.sg=>"-3",nobody at cert.org=>"-3",security-alerts at linuxsecurity.com=>"-3",cvs-commits-list-admin at gnome.org=>"-3",amavis-user-bounces at lists.sourceforge.net=>"-3",notification-return at lists.sophos.com=>"-3",mailman-announce-admin at python.org=>"-3",emailnews at genomeweb.com=>"-5",owner-textbreakingnews at cnnimail12.cnn.com=>"-5",ca+envelope at sendmail.org=>"-3",cert-advisory at us-cert.gov=>"-3",returns.groups.yahoo.com=>"-3",owner-postfix-users at postfix.org=>"-3",.example.net=>"1",securityfocus.com=>"-3",yahoo-dev-null at yahoo-inc.com=>"-3",owner-alert at iss.net=>"-3",sendmail-announce-request at lists.sendmail...
Jan  6 13:22:31 mail amavis[2683]: (02683-01) ....org=>"-3",surveys-errors at lists.nua.ie=>"-3",spamassassin.apache.org=>"-3",lvs-users-admin at linuxvirtualserver.org=>"-3",sender at example.net=>"3",owner-sendmail-announce at lists.sendmail.org=>"-3",noreply at freshmeat.net=>"-3",ietf-123-owner at loki.ietf.org=>"-3",clusternews at linuxnetworx.com=>"-3",owner-technews at postel.acm.org=>"-3",rt-users-admin at lists.fsck.com=>"-3"}]
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_re("sruli at saurymper.com"), no matches
Jan  6 13:22:31 mail amavis[2683]: (02683-01) query_keys: sruli at saurymper.com, sruli@, saurymper.com, .saurymper.com, .com, .
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_hash(sruli at saurymper.com), no matches
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup [score_sender<sruli at saurymper.com>] => undef, "sruli at saurymper.com" does not match
Jan  6 13:22:31 mail amavis[2683]: (02683-01) SpamControl: calling spam scanner SpamAssassin
Jan  6 13:22:31 mail amavis[2683]: (02683-01) get_deadline spam_scan_sa_pre - deadline in 479.8 s, set to 476.000 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) prolong_timer spam_scan_sa_pre: timer 476, was 336, deadline in 479.8 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSaUserConf) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSaUserConf) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisSaUserConf
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup [sa_userconf] => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSaUserName) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSaUserName) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisSaUserName
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup [sa_username] => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:31 mail amavis[2683]: (02683-01) SA user config: "", username: "amavis", 0, (0)postmaster at twsinternet.co.uk
Jan  6 13:22:31 mail amavis[2683]: (02683-01) calling SA parse (0), SA vers 3.3.2, 3.003002, data as STRING, recips_ind [0], user: "amavis"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) get_deadline SA check - deadline in 479.7 s, set to 475.000 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) CALLING SA check (0)
Jan  6 13:22:31 mail amavis[2683]: (02683-01) DONE SA check (0)
Jan  6 13:22:31 mail amavis[2683]: (02683-01) get_deadline spam_scan_sa - deadline in 479.1 s, set to 336.000 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) prolong_timer spam_scan_sa: timer 336, was 476, deadline in 479.1 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) spam_scan: score=1.273 autolearn=no tests=[RDNS_NONE=1.274,SPF_HELO_PASS=-0.001] recips=0
Jan  6 13:22:31 mail amavis[2683]: (02683-01) get_deadline spam_scan - deadline in 479.1 s, set to 336.000 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) prolong_timer spam_scan: timer 336, was 336, deadline in 479.1 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamTagLevel) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamTagLevel) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisSpamTagLevel
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup: (scalar) matches, result="-10"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup [spam_tag_level] => true,  "postmaster at twsinternet.co.uk" matches, result="-10", matching_key="(constant:-10)"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamTag2Level) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamTag2Level) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisSpamTag2Level
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup: (scalar) matches, result="6.2"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup [spam_tag2_level] => true,  "postmaster at twsinternet.co.uk" matches, result="6.2", matching_key="(constant:6.2)"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamTag3Level) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamTag3Level) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisSpamTag3Level
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup [spam_tag3_level] => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamKillLevel) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamKillLevel) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisSpamKillLevel
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup: (scalar) matches, result="6.9"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup [spam_kill_level] => true,  "postmaster at twsinternet.co.uk" matches, result="6.9", matching_key="(constant:6.9)"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisMessageSizeLimit) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisMessageSizeLimit) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisMessageSizeLimit
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup [message_size_limit] => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:31 mail amavis[2683]: (02683-01) final_destiny (ccat=0) is PASS, recip postmaster at twsinternet.co.uk
Jan  6 13:22:31 mail amavis[2683]: (02683-01) final_destiny PASS, recip postmaster at twsinternet.co.uk
Jan  6 13:22:31 mail amavis[2683]: (02683-01) do_notify_and_quar: ccat=CleanTag (1,1) ("1,1":CleanTag, "1":Clean, "0":CatchAll) ccat_block=(), qar_mth=
Jan  6 13:22:31 mail amavis[2683]: (02683-01) do_notify_and_quarantine: not quarantining, q_method off
Jan  6 13:22:31 mail amavis[2683]: (02683-01) skip admin notification, no administrators
Jan  6 13:22:31 mail amavis[2683]: (02683-01) do_notify_and_quarantine - done
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisForwardMethod) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisForwardMethod) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisForwardMethod
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup: (opaque) matches, result="smtp:[127.0.0.1]:10025"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup [forward_method] => true,  "postmaster at twsinternet.co.uk" matches, result="smtp:[127.0.0.1]:10025", matching_key="(opaque:smtp:[127.0.0.1]:10025)"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) delivery method is 1, recips: postmaster at twsinternet.co.uk
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamTagLevel) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamTagLevel) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisSpamTagLevel
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup: (scalar) matches, result="-10"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup [spam_tag_level] => true,  "postmaster at twsinternet.co.uk" matches, result="-10", matching_key="(constant:-10)"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamTag2Level) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamTag2Level) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisSpamTag2Level
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup: (scalar) matches, result="6.2"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup [spam_tag2_level] => true,  "postmaster at twsinternet.co.uk" matches, result="6.2", matching_key="(constant:6.2)"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamSubjectTag) rec=0, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr(amavisSpamSubjectTag) rec=1, "postmaster at twsinternet.co.uk" result: undef
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup_ldap_attr, no such attrs: amavisSpamSubjectTag
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup [spam_subject_tag] => undef, "postmaster at twsinternet.co.uk" does not match
Jan  6 13:22:31 mail amavis[2683]: (02683-01) headers CLUSTERING: NEW CLUSTER <postmaster at twsinternet.co.uk>: score=1.273, tag=1, tag2=0, local=1, bl=, s=, mangle=
Jan  6 13:22:31 mail amavis[2683]: (02683-01) header: X-Virus-Scanned: amavisd-new at twsinternet.co.uk\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) header: X-Spam-Flag: NO\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) header: X-Spam-Score: 1.273\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) header: X-Spam-Level: *\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) header: X-Spam-Status: No, score=1.273 tagged_above=-10 required=6.2\n\ttests=[RDNS_NONE=1.274, SPF_HELO_PASS=-0.001] autolearn=no\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) fwd: scanner provided a header field X-Spam-Checker-Version, inhibited by %allowed_added_header_fields
Jan  6 13:22:31 mail amavis[2683]: (02683-01) fwd: scanner provided a header field X-Spam-Level, but we preferred our own
Jan  6 13:22:31 mail amavis[2683]: (02683-01) fwd: scanner provided a header field X-Spam-Status, but we preferred our own
Jan  6 13:22:31 mail amavis[2683]: (02683-01) header: Received: from mail.twsinternet.co.uk ([127.0.0.1])\n\tby localhost (mail.twsinternet.co.uk [127.0.0.1]) (amavisd-new, port 10024)\n\twith ESMTP id lOraVyOhrXnm for <postmaster at twsinternet.co.uk>;\n\tTue,  6 Jan 2015 13:22:30 +0000 (GMT)\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) headers CLUSTERING: done all 1 recips in one go
Jan  6 13:22:31 mail amavis[2683]: (02683-01) spam-tag, <sruli at saurymper.com> -> <postmaster at twsinternet.co.uk>, No, score=1.273 tagged_above=-10 required=6.2 tests=[RDNS_NONE=1.274, SPF_HELO_PASS=-0.001] autolearn=no
Jan  6 13:22:31 mail amavis[2683]: (02683-01) dkim: not signing mail which is not originating from our site
Jan  6 13:22:31 mail amavis[2683]: (02683-01) about to connect to smtp:[127.0.0.1]:10025, lOraVyOhrXnm FWD from <sruli at saurymper.com> -> <postmaster at twsinternet.co.uk>
Jan  6 13:22:31 mail amavis[2683]: (02683-01) get_deadline fwd_init - deadline in 479.0 s, set to 480.000 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) smtp session: setting up a new session
Jan  6 13:22:31 mail amavis[2683]: (02683-01) establish_or_refresh, state: down
Jan  6 13:22:31 mail amavis[2683]: (02683-01) new socket using IO::Socket::IP to [127.0.0.1]:10025, timeout 35
Jan  6 13:22:31 mail amavis[2683]: (02683-01) connected to [127.0.0.1]:10025 successfully
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: needline=1, flush=0, wr=0, timeout=35
Jan  6 13:22:31 mail postfix/smtpd[2715]: connect from localhost[127.0.0.1]
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: receiving
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop read 42 chars< 220 mail.twsinternet.co.uk ESMTP Postfix\r\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) smtp greeting: 220 mail.twsinternet.co.uk ESMTP Postfix, dt: 63.7 ms
Jan  6 13:22:31 mail amavis[2683]: (02683-01) smtp cmd> EHLO localhost
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: needline=0, flush=1, wr=1, timeout=300
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: sending 16 chars
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop sent 16> EHLO localhost\r\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: needline=1, flush=0, wr=0, timeout=300
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: receiving
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop read 198 chars< 250-mail.twsinternet.co.uk\r\n250-PIPELINING\r\n250-SIZE 10240000\r\n250-VRFY\r\n250-ETRN\r\n250-STARTTLS\r\n250-XFORWARD NAME ADDR PROTO HELO SOURCE PORT IDENT\r\n250-ENHANCEDSTATUSCODES\r\n250-8BITMIME\r\n250 DSN\r\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) smtp resp to EHLO: 250 mail.twsinternet.co.uk\nPIPELINING\nSIZE 10240000\nVRFY\nETRN\nSTARTTLS\nXFORWARD NAME ADDR PROTO HELO SOURCE PORT IDENT\nENHANCEDSTATUSCODES\n8BITMIME\nDSN
Jan  6 13:22:31 mail amavis[2683]: (02683-01) tls active=0, capable=1, sec_level=0
Jan  6 13:22:31 mail amavis[2683]: (02683-01) Remote host presents itself as: mail.twsinternet.co.uk, handles DSN, handles PIPELINING
Jan  6 13:22:31 mail amavis[2683]: (02683-01) smtp cmd> XFORWARD ADDR=213.171.197.242 PORT=52806 PROTO=ESMTP HELO=twsinternet.com SOURCE=REMOTE IDENT=66D2D18004C1D
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: needline=0, flush=1, wr=1, timeout=300
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: sending 109 chars
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop sent 109> XFORWARD ADDR=213.171.197.242 PORT=52806 PROTO=ESMTP HELO=twsinternet.com SOURCE=REMOTE IDENT=66D2D18004C1D\r\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: needline=1, flush=0, wr=0, timeout=300
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: receiving
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop read 14 chars< 250 2.0.0 Ok\r\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) smtp resp to XFORWARD: 250 2.0.0 Ok
Jan  6 13:22:31 mail amavis[2683]: (02683-01) AUTH not needed, user='', MTA offers ''
Jan  6 13:22:31 mail amavis[2683]: (02683-01) smtp cmd> MAIL FROM:<sruli at saurymper.com> BODY=7BIT
Jan  6 13:22:31 mail amavis[2683]: (02683-01) smtp cmd> RCPT TO:<postmaster at twsinternet.co.uk> ORCPT=rfc822;postmaster at twsinternet.co.uk
Jan  6 13:22:31 mail amavis[2683]: (02683-01) smtp cmd> DATA
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: needline=0, flush=1, wr=1, timeout=120
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: sending 131 chars
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop sent 131> MAIL FROM:<sruli at saurymper.com> BODY=7BIT\r\nRCPT TO:<postmaster at twsinternet.co.uk> ORCPT=rfc822;postmaster at twsinternet.co.uk\r\nDATA\r\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: needline=1, flush=0, wr=0, timeout=300
Jan  6 13:22:31 mail postfix/smtpd[2715]: DE64A18004C20: client=localhost[127.0.0.1], orig_queue_id=66D2D18004C1D, orig_client=unknown[213.171.197.242]
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: receiving
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop read 65 chars< 250 2.1.0 Ok\r\n250 2.1.5 Ok\r\n354 End data with <CR><LF>.<CR><LF>\r\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) smtp resp to MAIL (pip): 250 2.1.0 Ok
Jan  6 13:22:31 mail amavis[2683]: (02683-01) smtp resp to RCPT (pip) (<postmaster at twsinternet.co.uk>): 250 2.1.5 Ok
Jan  6 13:22:31 mail amavis[2683]: (02683-01) smtp resp to DATA: 354 End data with <CR><LF>.<CR><LF>
Jan  6 13:22:31 mail amavis[2683]: (02683-01) write_header: 1, Amavis::Out::SMTP::Protocol=HASH(0x6b845e0)
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: needline=1, flush=0, wr=1, timeout=479.808
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: sending 1604 chars
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop sent 1604> X-Virus-Scanned: amavisd-new at twsinternet.co.uk\r\nX-Spam-Flag: NO\r\nX-Spam-Score: 1.273\r\nX-Spam-Level: *\r\nX-Spam-Status: No, score=1.273 tagged_above=-10 required=6.2\r\n\ttests=[RDNS_NONE=1.274, SPF_HEL [...]
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: needline=1, flush=0, wr=0, timeout=479.808
Jan  6 13:22:31 mail postfix/cleanup[2716]: DE64A18004C20: message-id=<54ABE16C.4060009 at saurymper.com>
Jan  6 13:22:31 mail postfix/qmgr[1825]: DE64A18004C20: from=<sruli at saurymper.com>, size=1365, nrcpt=1 (queue active)
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop: receiving
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rw_loop read 39 chars< 250 2.0.0 Ok: queued as DE64A18004C20\r\n
Jan  6 13:22:31 mail amavis[2683]: (02683-01) smtp resp to data-dot (<postmaster at twsinternet.co.uk>): 250 2.0.0 Ok: queued as DE64A18004C20, dt: 32.0 ms
Jan  6 13:22:31 mail amavis[2683]: (02683-01) Amavis::Out::SMTP::Session close, keeping connection
Jan  6 13:22:31 mail amavis[2683]: (02683-01) get_deadline fwd-end-chkpnt - deadline in 478.8 s, set to 336.000 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) prolong_timer fwd-end-chkpnt: timer 336, was 0, deadline in 478.8 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lOraVyOhrXnm FWD from <sruli at saurymper.com> -> <postmaster at twsinternet.co.uk>, BODY=7BIT 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as DE64A18004C20
Jan  6 13:22:31 mail amavis[2683]: (02683-01) get_deadline forwarding - deadline in 478.8 s, set to 336.000 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) prolong_timer forwarding: timer 336, was 336, deadline in 478.8 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) DSN: sender NOT credible, SA: 1.273, <sruli at saurymper.com>
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup: (scalar) matches, result="10"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) lookup [spam_dsn_cutoff_level_bysender] => true,  "sruli at saurymper.com" matches, result="10", matching_key="(constant:10)"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) dsn: from MTA 250 NonBlocking:CleanTag <sruli at saurymper.com> -> <postmaster at twsinternet.co.uk>: on_succ=0, on_dly=1, on_fail=1, never=0, warn_sender=, DSN_passed_on=1, destiny=1, mta_resp: "250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as DE64A18004C20"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) DSN: SUCC from MTA 250 NonBlocking:CleanTag, no DSN requested: <sruli at saurymper.com> -> <postmaster at twsinternet.co.uk>
Jan  6 13:22:31 mail amavis[2683]: (02683-01) delivery_status_notification: notif 0 bytes, suppressed: no
Jan  6 13:22:31 mail amavis[2683]: (02683-01) one_response_for_all, per_recip_capable: N, suppressed: N
Jan  6 13:22:31 mail amavis[2683]: (02683-01) one_response_for_all <sruli at saurymper.com>: success, r=0,b=0,d=0, ndn_needed=0, '250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as DE64A18004C20'
Jan  6 13:22:31 mail amavis[2683]: (02683-01) notif=N, suppressed=0, ndn_needed=0, exit=0, 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as DE64A18004C20
Jan  6 13:22:31 mail amavis[2683]: (02683-01) get_deadline delivery-notification - deadline in 478.8 s, set to 336.000 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) prolong_timer delivery-notification: timer 336, was 336, deadline in 478.8 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) status counters: InMsgsStatus{Relayed,RelayedUntagged,RelayedUntaggedInbound}
Jan  6 13:22:31 mail amavis[2683]: (02683-01) get_deadline snmp-counters - deadline in 478.8 s, set to 336.000 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) prolong_timer snmp-counters: timer 336, was 336, deadline in 478.8 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) oldest_public_ip_addr_from_received: 213.171.197.242
Jan  6 13:22:31 mail amavis[2683]: (02683-01) Passed CLEAN {RelayedInbound}, [213.171.197.242]:52806 [213.171.197.242] <sruli at saurymper.com> -> <postmaster at twsinternet.co.uk>, Queue-ID: 66D2D18004C1D, Message-ID: <54ABE16C.4060009 at saurymper.com>, mail_id: lOraVyOhrXnm, Hits: 1.273, size: 1136, queued_as: DE64A18004C20, 1393 ms
Jan  6 13:22:31 mail amavis[2683]: (02683-01) get_deadline main_log_entry - deadline in 478.8 s, set to 336.000 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) prolong_timer main_log_entry: timer 336, was 336, deadline in 478.8 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) TIMING-SA total 657 ms - parse: 5 (0.7%), extract_message_metadata: 11 (1.7%), get_uri_detail_list: 0.77 (0.1%), tests_pri_-1000: 9 (1.3%), tests_pri_-950: 1.66 (0.3%), tests_pri_-900: 1.70 (0.3%), tests_pri_-400: 1.12 (0.2%), tests_pri_0: 571 (86.9%), check_dkim_adsp: 80 (12.2%), check_spf: 214 (32.6%), poll_dns_idle: 178 (27.1%), check_razor2: 212 (32.2%), check_pyzor: 0.38 (0.1%), tests_pri_500: 9 (1.3%), get_report: 1.04 (0.2%)
Jan  6 13:22:31 mail amavis[2683]: (02683-01) updating snmp variables in BDB
Jan  6 13:22:31 mail amavis[2683]: (02683-01) get_deadline check done - deadline in 478.8 s, set to 336.000 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) prolong_timer check done: timer 336, was 336, deadline in 478.8 s
Jan  6 13:22:31 mail amavis[2683]: (02683-01) sending SMTP response: "250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as DE64A18004C20"
Jan  6 13:22:31 mail amavis[2683]: (02683-01) ESMTP> 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as DE64A18004C20
Jan  6 13:22:31 mail amavis[2683]: (02683-01) switch_to_client_time 480 s, smtp response sent
Jan  6 13:22:31 mail postfix/smtp[2712]: 66D2D18004C1D: to=<postmaster at twsinternet.co.uk>, relay=127.0.0.1[127.0.0.1]:10024, delay=13, delays=11/0.07/0.05/1.4, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as DE64A18004C20)
Jan  6 13:22:31 mail amavis[2683]: (02683-01) TempDir::strip: /var/spool/amavisd/tmp/amavis-20150106T132230-02683-xVYaZk0y
Jan  6 13:22:31 mail amavis[2683]: (02683-01) rmdir_recursively: /var/spool/amavisd/tmp/amavis-20150106T132230-02683-xVYaZk0y/parts, excl=1
Jan  6 13:22:31 mail postfix/qmgr[1825]: 66D2D18004C1D: removed
Jan  6 13:22:31 mail amavis[2683]: (02683-01) size: 1136, TIMING [total 1402 ms] - ldap-prepare: 24 (2%)2, SMTP greeting: 10 (1%)2, SMTP EHLO: 4.7 (0%)3, SMTP pre-MAIL: 14 (1%)4, mkdir tempdir: 8 (1%)4, create email.txt: 1.2 (0%)4, ldap-connect: 28 (2%)6, lookup_ldap: 73 (5%)12, SMTP pre-DATA-flush: 10 (1%)12, SMTP DATA: 4.2 (0%)13, check_init: 2.0 (0%)13, digest_hdr: 7 (0%)13, digest_body_dkim: 1.4 (0%)13, collect_info: 6 (0%)14, mkdir parts: 12 (1%)15, mime_decode: 22 (2%)16, get-file-type1: 63 (4%)21, decompose_part: 18 (1%)22, parts_decode: 0.2 (0%)22, check_header: 3.1 (0%)22, AV-scan-1: 40 (3%)25, spam-wb-list: 16 (1%)26, SA msg read: 2.4 (0%)26, SA parse: 78 (6%)32, SA check: 643 (46%)78, decide_mail_destiny: 25 (2%)80, notif-quar: 1.7 (0%)80, fwd-connect: 98 (7%)87, fwd-xforward: 3.1 (0%)87, fwd-mail-pip: 117 (8%)95, fwd-rcpt-pip: 0.5 (0%)95, fwd-data-chkpnt: 0.1 (0%)95, write-header: 1.2 (0%)95, fwd-data-contents: 0.1 (0%)95, fwd-end-chkpnt: 34 (2%)98, prepare-dsn: 4.0 (0%)98, report: 9 (...
Jan  6 13:22:32 mail amavis[2683]: (02683-01) ...1%)99, main_log_entry: 10 (1%)99, update_snmp: 3.2 (0%)100, SMTP pre-response: 1.3 (0%)100, SMTP response: 0.6 (0%)100, unlink-2-files: 1.0 (0%)100, rundown: 1.6 (0%)100
Jan  6 13:22:32 mail amavis[2683]: (02683-01) idle_proc, 6: was busy, 1234.5 ms, total idle 0.004 s, busy 1.399 s
Jan  6 13:22:32 mail amavis[2683]: (02683-01) idle_proc, 5: was idle, 0.2 ms, total idle 0.004 s, busy 1.399 s
Jan  6 13:22:32 mail amavis[2683]: (02683-01) ESMTP< QUIT\r\n
Jan  6 13:22:32 mail amavis[2683]: (02683-01) get_deadline switch_to_my_time(rx SMTP QUIT) - deadline in 480.0 s, set to 336.000 s
Jan  6 13:22:32 mail amavis[2683]: (02683-01) prolong_timer switch_to_my_time(rx SMTP QUIT): timer 336, was 480, deadline in 480.0 s
Jan  6 13:22:32 mail amavis[2683]: (02683-01) ESMTP> 221 2.0.0 [127.0.0.1] amavisd-new closing transmission channel
Jan  6 13:22:32 mail amavis[2683]: (02683-01) switch_to_client_time 480 s, smtp response sent
Jan  6 13:22:32 mail amavis[2683]: (02683-01) SMTP session over, timer stopped
Jan  6 13:22:32 mail amavis[2683]: (02683-01) extra modules loaded: Convert/UUlib.pm, unicore/lib/Gc/Nd.pl
Jan  6 13:22:32 mail amavis[2683]: (02683-01) exiting process_request
Jan  6 13:22:32 mail amavis[2683]: (02683-01) idle_proc, bye: was busy, 19.0 ms, total idle 0.004 s, busy 1.418 s
Jan  6 13:22:32 mail amavis[2683]: (02683-01) load: 100 %, total idle 0.004 s, busy 1.418 s
Jan  6 13:22:32 mail postfix/smtp[2717]: DE64A18004C20: to=<postmaster at twsinternet.co.uk>, relay=127.0.0.1[127.0.0.1]:10026, delay=0.32, delays=0.14/0.05/0.12/0, dsn=2.0.0, status=sent (250 Ok)
Jan  6 13:22:32 mail postfix/qmgr[1825]: DE64A18004C20: removed
Jan  6 13:22:32 mail postfix/smtpd[2718]: connect from localhost[127.0.0.1]
Jan  6 13:22:32 mail postfix/smtpd[2718]: A02FC18004C1D: client=localhost[127.0.0.1]
Jan  6 13:22:32 mail postfix/cleanup[2716]: A02FC18004C1D: message-id=<20150106132232.A02FC18004C1D at mail.twsinternet.co.uk>
Jan  6 13:22:32 mail postfix/qmgr[1825]: A02FC18004C1D: from=<MAILER-DAEMON at localhost.localdomain>, size=2688, nrcpt=1 (queue active)
Jan  6 13:22:32 mail postfix/smtpd[2718]: disconnect from localhost[127.0.0.1]
Jan  6 13:22:33 mail postfix/smtp[2719]: A02FC18004C1D: to=<sruli at saurymper.com>, relay=mail.saurymper.com[213.171.197.242]:25, delay=0.67, delays=0.05/0.1/0.24/0.28, dsn=2.0.0, status=sent (250 Ok, message saved <Message-ID: 20150106132232.A02FC18004C1D at mail.twsinternet.co.uk>)
Jan  6 13:22:33 mail postfix/qmgr[1825]: A02FC18004C1D: removed


More information about the users mailing list