1

Topic: Some problem with iRedmail new version

==== Required information ====
- iRedMail version (check /etc/iredmail-release):  0.9.3
- Linux/BSD distribution name and version: Ubuntu 14.04
- Store mail accounts in which backend (LDAP/MySQL/PGSQL):  MySQL
- Web server (Apache or Nginx): Apache
- Manage mail accounts with iRedAdmin-Pro? Yes
- Related log if you're reporting an issue:
====

Today I realize that there are some problem occur with iredmail (right now I'm using new version)

1. When I release a spam message, the message is gone from qurantine list in the dashboard and If I check in Received List the message seems already delivered to the user, but user never received that message. Even I check from webmail no message comes out. How can I trace that message ?
2. In the Quarantine List I also see some message without sender and when I open (click the arrow) that message, the from field is "Mail Delivery Subsystem <root@mydomain.com>" and the message "Your message towas automatically rejected: Quota exceeded (mailbox for user is full)" eventhough the user mailbox is not full , what is this ?
3. In the Quarantine List also I see the message that local user send to outside recipient but it is BANNED with error "BANNED, message contains application/x-msdownload,.pdf,filename.pdf", so everytime user send PDF file it is BANNED, why ? How can I resolve this ?

Need Help. Thanks

----

Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.

2 (edited by bigman 2016-01-15 13:13:15)

Re: Some problem with iRedmail new version

Hi,

For no 1 it seems my problem looks like in this topic http://www.iredmail.org/forum/topic1035 … ntine.html
but I've tried to release using command "amavisd-release ID" but still not delivered to user (although the result of that command is seems success root@mail:/etc/amavis/conf.d# amavisd-release DsOOtU6plTeb
250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as B6E1E42445 )
Update : When I check in the dashboard, the message still remain in Quarantine List with same ID, but if I use WebGui to release, the message will move to Received List.

I've tried to turn on debug the amavis and here is the result in log (I use command line)
Jan 15 10:14:24 mail amavis[31134]: (31134-02) Net::Server: 2016/01/15-10:14:24 CONNECT UNIX Socket: ""
Jan 15 10:14:24 mail amavis[31134]: () idle_proc, hi : was idle, 29799.1 ms, total idle 40.395 s, busy 1.227 s
Jan 15 10:14:24 mail amavis[31134]: () loaded base policy bank
Jan 15 10:14:24 mail amavis[31134]: () loaded policy bank "AM.PDP-SOCK"
Jan 15 10:14:24 mail amavis[31134]: () process_request: fileno sock=14, STDIN=0, STDOUT=1
Jan 15 10:14:24 mail amavis[31134]: () get_deadline switch_to_my_time(new request) - deadline in 480.0 s, set to 336.000 s
Jan 15 10:14:24 mail amavis[31134]: () prolong_timer switch_to_my_time(new request): timer 336, was 0, deadline in 480.0 s
Jan 15 10:14:24 mail amavis[31134]: () process_request: suggested_protocol="AM.PDP" on a UNIX socket
Jan 15 10:14:24 mail amavis[31134]: () process_policy_request: 0, /usr/sbin/amavisd-new, fileno=14
Jan 15 10:14:24 mail amavis[31134]: () switch_to_client_time 480 s, start receiving AM.PDP data
Jan 15 10:14:24 mail amavis[31134]: () get_deadline switch_to_my_time(rx AM.PDP line) - deadline in 480.0 s, set to 336.000 s
Jan 15 10:14:24 mail amavis[31134]: () prolong_timer switch_to_my_time(rx AM.PDP line): timer 336, was 480, deadline in 480.0 s
Jan 15 10:14:24 mail amavis[31134]: () policy protocol: request=release
Jan 15 10:14:24 mail amavis[31134]: () switch_to_client_time 480 s, receiving AM.PDP data
Jan 15 10:14:24 mail amavis[31134]: () get_deadline switch_to_my_time(rx AM.PDP line) - deadline in 480.0 s, set to 336.000 s
Jan 15 10:14:24 mail amavis[31134]: () prolong_timer switch_to_my_time(rx AM.PDP line): timer 336, was 480, deadline in 480.0 s
Jan 15 10:14:24 mail amavis[31134]: () policy protocol: mail_id=DsOOtU6plTeb
Jan 15 10:14:24 mail amavis[31134]: () switch_to_client_time 480 s, receiving AM.PDP data
Jan 15 10:14:24 mail amavis[31134]: () get_deadline switch_to_my_time(rx AM.PDP line) - deadline in 480.0 s, set to 336.000 s
Jan 15 10:14:24 mail amavis[31134]: () prolong_timer switch_to_my_time(rx AM.PDP line): timer 336, was 480, deadline in 480.0 s
Jan 15 10:14:24 mail amavis[31134]: () policy protocol: mail_file=DsOOtU6plTeb
Jan 15 10:14:24 mail amavis[31134]: () switch_to_client_time 480 s, receiving AM.PDP data
Jan 15 10:14:24 mail amavis[31134]: () get_deadline switch_to_my_time(rx entire AM.PDP request) - deadline in 480.0 s, set to 336.000 s
Jan 15 10:14:24 mail amavis[31134]: () prolong_timer switch_to_my_time(rx entire AM.PDP request): timer 336, was 480, deadline in 480.0 s
Jan 15 10:14:24 mail amavis[31134]: () TempDir::prepare_dir: created directory /var/lib/amavis/tmp/amavis-20160115T101424-31134-iKHFDPk6
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) preprocess_policy_query: opening in sql: DsOOtU6plTeb
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) preprocess_policy_query: missing partition_tag in request, fetching msgs record for mail_id=DsOOtU6plTeb
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) sql begin, nontransaction
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) sql: preparing and executing: SELECT partition_tag FROM msgs WHERE mail_id=?
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) release: got msgs record for mail_id=DsOOtU6plTeb: 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) release: opening mail_id=DsOOtU6plTeb, partition_tag=0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) sql begin, nontransaction
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) sql: preparing and executing: SELECT mail_text FROM quarantine WHERE partition_tag=? AND mail_id=? ORDER BY chunk_ind
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::open r drv=mysql (SELECT mail_text FROM quarantine WHERE partition_tag=? AND mail_id=? ORDER BY chunk_ind); key=DsOOtU6plTeb, p_tag=0, s:
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Request: release DsOOtU6plTeb /var/lib/amavis/tmp/amavis-20160115T101424-31134-iKHFDPk6:  ->
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::seek mode=r, pos=0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) msg_from_quarantine: releasing DsOOtU6plTeb
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 54
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 116
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 148
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 165
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 185
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 207
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 259
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 323
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 379
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 412
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 467
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 563
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 635
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 674
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Quarantined message release (miscategorized): DsOOtU6plTeb <> -> <user@mydomain.com>
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Quarantine release DsOOtU6plTeb: missing X-Envelope-From or Return-Path
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) header: Resent-From: "Content-filter at mail.mydomain.com"\n\t<root@mail.mydomain.com>\n
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) header: Resent-To: <user@mydomain.com>\n
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) header: Resent-Date: Fri, 15 Jan 2016 10:14:24 +0700 (WIB)\n
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) header: Resent-Message-ID: <QRRDsOOtU6plTeb@mail.mydomain.com>\n
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) header: Received: from unknown by mail.mydomain.com (amavisd-new, unix socket)\n\tid DsOOtU6plTeb for <user@mydomain.com>;\n\tFri, 15 Jan 2016 10:14:24 +0700 (WIB)\n
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) dkim: not signing mail which is not originating from our site
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) about to connect to smtp:[127.0.0.1]:10025, FWD from <> -> <user@mydomain.com>
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) get_deadline fwd_init - deadline in 480.0 s, set to 480.000 s
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) smtp session: setting up a new session
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) establish_or_refresh, state: down
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) new socket by IO::Socket::INET to [127.0.0.1]:10025, timeout 35, blocking
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) connected to [127.0.0.1]:10025 successfully
Jan 15 10:14:24 mail postfix/smtpd[30765]: connect from mail.mydomain.com[127.0.0.1]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=1, flush=0, wr=0, timeout=35
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: receiving
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop read 54 chars< 220 mail.mydomain.com ESMTP Postfix (Ubuntu)\r\n
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) smtp greeting: 220 mail.mydomain.com ESMTP Postfix (Ubuntu)
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) smtp cmd> EHLO mail.mydomain.com
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=300
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 32> EHLO mail.mydomain.com\r\n
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=1, flush=0, wr=0, timeout=300
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: receiving
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop read 168 chars< 250-mail.mydomain.com\r\n250-PIPELINING\r\n250-SIZE 15728640\r\n250-ETRN\r\n250-AUTH PLAIN LOGIN\r\n250-AUTH=PLAIN LOGIN\r\n250-ENHANCEDSTATUSCODES\r\n250-8BITMIME\r\n250 DSN\r\n
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) smtp resp to EHLO: 250 mail.mydomain.com\nPIPELINING\nSIZE 15728640\nETRN\nAUTH PLAIN LOGIN\nAUTH=PLAIN LOGIN\nENHANCEDSTATUSCODES\n8BITMIME\nDSN
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) tls active=0, capable=, sec_level=0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Remote host presents itself as: mail.mydomain.com, handles DSN, handles PIPELINING
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) AUTH not needed, user='', MTA offers 'PLAIN LOGIN'
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) smtp cmd> MAIL FROM:<>
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) smtp cmd> RCPT TO:<user@mydomain.com>
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) smtp cmd> DATA
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=120
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 68> MAIL FROM:<>\r\nRCPT TO:<user@mydomain.com>\r\nDATA\r\n
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=1, flush=0, wr=0, timeout=300
Jan 15 10:14:24 mail postfix/smtpd[30765]: B6E1E42445: client=mail.mydomain.com[127.0.0.1]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: receiving
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) 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 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) smtp resp to MAIL (pip): 250 2.1.0 Ok
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) smtp resp to RCPT (pip) (<user@mydomain.com>): 250 2.1.5 Ok
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) smtp resp to DATA: 354 End data with <CR><LF>.<CR><LF>
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::seek mode=r, pos=412
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 1, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) write_header: 0, Amavis::Out::SMTP::Protocol=HASH(0x82e8e58)
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 412
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 467
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 563
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 635
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 674
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 742
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 806
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 889
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 969
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 999
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 1034
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 1119
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 1204
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 1287
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 1633
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 1725
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 1810
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 1893
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 1969
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2048
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2127
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2175
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2233
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2305
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2381
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2402
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2477
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2556
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2609
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2687
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2720
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2779
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2843
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2890
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2907
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2921
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 2959
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 3026
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 3049
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 3073
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 3094
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 3116
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 3149
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 3180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 3248
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::getline, chunk 1, pos 3266
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 1, 3267
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 19651 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 2, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 3, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail postfix/cleanup[29185]: B6E1E42445: resent-message-id=<QRRDsOOtU6plTeb@mail.mydomain.com>
Jan 15 10:14:24 mail postfix/cleanup[29185]: B6E1E42445: message-id=<bb8991892fab46a5b8c78f53441e4a12@GCSGEXCH01.sg.local>
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 53143> Resent-From: "Content-filter at mail.mydomain.com"\r\n\t<root@mail.mydomain.com>\r\nResent-To: <user@mydomain.com>\r\nResent-Date: Fri, 15 Jan 2016 10:14:24 +0700 (WIB)\r\nRe [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 4, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 5, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 6, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49791> UUUUAFFFFABRRRQAUUUUAFFF\r\nFABRRRQAUUUUAFFFFABRRRQAUUUUAFFFFABRRRQAUUUUAFFFFABRRRQAUUUUAFFFFABRRRQAUUUU\r\nAec/B7/jw1Pgcyxnp7GvRq85+D4xY6n/ANdIx+hr0agEFFFFABRRRQAUlLSUALRRRQAUUUUAFFFF\r\nABRRRQAUUUUAFFFFAB [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 7, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 8, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 9, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49790> x4Ph1dQ+Nn1walCtt9sN0sQhJdixJKk7sDk9ec5PArrNf0xta0G901JhC1zEUEhXcFP0oA4P4Q2\r\nyGXWZ2RGI8qNWK/MBhiwz6H5TisHwHAF+IlogYKIDPtC/wAQCsuP1z+Feh+CfCVx4Vgu1uL9bprp\r\nkbakZRUwMHGSc5z146Cszw/8OptH8UrrU2pxTrHJM0cQt [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 10, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 11, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 12, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49790> s4ziqek22tWXxRsI/EV9FeXklmzRyxEBduGGMbRjkMeB757VP\r\nFonjTwlqN5D4bgs7+wu5vNVrphlCeu75lOfpuyAOh4q5o/hzxbJ4yttf1+401xHEUKW7N8ilWwqg\r\nr2LdST+NAHF6udWF54tNmWWwF3/p7K4V9vmOFA9jk59gM16not9o9p4OhvtNO3TLa1MgAwS [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 13, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 14, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 15, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49791> TzjoKZooJ+LniM5OFtYBz05\r\nVP8ACtXTPAHhXSLpbqz0aFZkIKPKzSlCDkEbycHI6jmtiLTLGHUZtRitIUvLhVSWdUAdwOgJ7/8A\r\n1h6UDOT+JV0unLoGoTK5gtdUjkkKDJwATjHfgH8queM/EWjReFL2I6lbPJe2rpbokiu0u5cAgA8j\r\nkc9MGuh1DT7TVbGWxv4 [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 16, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 17, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 18, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49790> x7UAb/AIb8Sapf+A9U1a7ljlvLXzzGyxgD5U3LkCovhx4n1fxE+pJqk8Mv2dYTEUjCH5t+7IH+\r\n6K5zwz4i0mw8Ba1pd3fLBdyibyo2B3PvjCrtx1+b8u9Q/DzUpNI0rxTexRh5baxilQYyMqJevTjP\r\n9aANNrL4qXMX2m51O3slUb3QyxIFwM44Q8duW+tSeC/Hup [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 19, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 20, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 21, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49790> ysGH8sfjQB514A8F6X4hsbq91AyPFDKbeKCKQoFIVW3EjnPz\r\ncDOPUHtU0O5l8IfEMabBczTWrXa2coZseaHIClhjG5SwOR79MmjRvEWueAZbuxu9K3RM5LpJuVRJ\r\ngDckmCGBCjjHPHI6Vb8G6LqviTxWniLUrQLbRzmd2dCgeTGV8tSCSASpBz26k0xFNZHtfixn [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 22, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 23, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 24, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49791> geIftEtgGuYACksccESwjI\r\n5UbzknHYEnnmm/C5h/wliheVNlJg+2UoC57DRXk+tfEjWdS1T7L4dV4YN5jjKwiSacgnkA5AB7DG\r\ne59A7T/HniLw9qYsvE0Mk0eAZBLGqzIp/iUr8rD29uoIxQFz1asTxL4psfC8EEl3FPM1w5VI4ApY\r\n4GSfmIGBx37itiKRJokl [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 25, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 26, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 27, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49790> 61zN14z8daDcwtrNlAiSE7Y5I1xIAecMjHB+v5GrXxF8Y6rYapLo9hL9khSFWedTiRmPOA2fl\r\nAGOetc74m8M69pGnwanrupi5lnuPJWIzvMUyrNnc3T7p4AwOKAPSZfGMc3gaXxLYW+8op/cTNtww\r\nbaQSPf8APj1rko/inrl1HLb2ugJPduD5X2bzJSn+0yBckfi [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 28, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 29, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 30, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49790> +buxt33x2nnhUO08BsHJAIBCnjjpitHW77w3fapbaxY+LLO\r\nx1C1G0SK6ypIn91lyM9T0I6+wwAPMTaX8U4ItPQxwajamS7jQYQkb8OR2OQvP+0fWuzZQylWAIIw\r\nQe9cjpWreHotQm1fUPFGl3V/MghDq6wJHGOdoRnJGTkkknP6VJpWu6PZXl/Pd+NtPvEupd8MU [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 31, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 32, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 33, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49791> OSf4fu8/Tmiwi98PNVvtW\r\ng1p7y5edYtUmSESfejXOdv0GeBnjp0xXYVwHwoX/AEfXmCttOqOFbHB4HQ/56iu/oYI8w0PxFpmg\r\neKvGeo30wjjEwCJkeZKyNICqAn5jn/IrofCVx4l1u7m1vVJnstNlObLTwiAshBwz8FuhH8Qyc8AY\r\nzxEPhf8A4SrXvFyRSyLc2 [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 34, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 35, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 36, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49790> 91hjdI5VNvIXjZgSoKhSecEZ6ZHWtXRtd03xBaPdaXcGeFH8tmMbJhsA4wwB6EVyml2XhjxT\r\n4V1aDw/ZR2M12B59vwjpIpJjJAJAXIyMcde+ccF4b8SS6BBqkeJSb20MaKhyEm6Bj9MnJ9hQB67p\r\nnjHw/rN6tnp+orPOwYqgjcZA6nJGMVlN8UPDC3LRedcsg/5b [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 37, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 38, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 39, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49790> n2qeeuGBx9Bge1dPp+qafq0Bn069t7uIHBeCQOAcZwcdDg\r\njg1boA5+x8EaBp+iXOkQ2ZNvd4NyxkbzJiOcswIPX0wK0LrRbK60B9EKtFZtALcLG2GRAMDBOeRg\r\nVoUUAZF14a0688NR+H5lc2kUKRRtkb02ABWBxjcMDtVDQfBFro0FzbXGo3urW06LGLe/cSRIg7 [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 40, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 41, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 42, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49791> IyDQB6LVHVtY0/QrE3up\r\nXK28AYKCQSWY9AAOSfYehParoIYAg5B5FcN8TIVi/sbVrqy+26bYXRN3Bt3ja23DFehxgjk45x3o\r\nALf4veHJ7hI5IL+2id9ouZYk8vHPOQxOOPTj88dgdTsFltomvrcSXY3W6GVd0wxnKjPzcHtWVDrX\r\nhLxRapZC706+SXAFpMVLZ7 [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 43, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 44, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 45, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49790> isODw3r+ueGhq2ueMryGKe3a5NvbqI40VlLYYjG5duPlPA5GT1qhYnHwKunJYB5TjA5GZwM\r\nUkB6fYTLc6dbTpGIllhRwg6KCAcfhXF/FJI5YvD8U3l+VJqqI4lYqhBVgdxHIGCckdq67RDnQdPP\r\nHNrF0/3RXG/FyEXGm6NCXCiXURGcjOAyOM/hTQEPxH8OeHdJ8 [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 46, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 47, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 48, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49790> 5YNK8khYsQMDr9T+dAGzRRRQAUUUUAFFFFABRRRQAUUUU\r\nAFFFFABRRRQAUUUUAFFFFABRRRQAUUUUAFFFFABRRRQAUUUUAFFFFABRRRQAUUUUAFFFFABRRRQA\r\nUUUUAFFFFABRRRQAUUUUAFFFFABRRRQAUUUUAFFFFABRRRQAUUUUAFFFFABRRRQAUUUUAFFFFAB [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 49, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 50, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 51, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 16384 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=180
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 49791> 9omk6nKJb/TLS6kC7A8\r\n0CuwXOcZIzjJP50+LStOgsTYRWFsloesCxKIz/wHGKAOe+G5B8Ny5wHF3LvUNna3HGP4fp+Petfx\r\nPaT33hjUra2j8yeS3fy0HVmxkD8TxVqy0rTtNLmwsLW0MmN5ghVN2OmcDnqat0Act8O7xJvB8ELM\r\nqzWryRzJ0KHeSAR1HBHWptI [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 52, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) read: moving on by 12807 chars
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::IO::SQL::read, 52, 0
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) smtp connection_cache disabled, sending QUIT
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) smtp cmd> QUIT
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=0, flush=1, wr=1, timeout=479.933
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: sending
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop sent 12986> AAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA\r\nAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA\r\nAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA [...]
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: needline=1, flush=0, wr=0, timeout=479.933
Jan 15 10:14:24 mail postfix/smtpd[30765]: disconnect from mail.mydomain.com[127.0.0.1]
Jan 15 10:14:24 mail postfix/qmgr[3642]: B6E1E42445: from=<>, size=862999, nrcpt=1 (queue active)
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop: receiving
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rw_loop read 51 chars< 250 2.0.0 Ok: queued as B6E1E42445\r\n221 2.0.0 Bye\r\n
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) smtp resp to data-dot (<user@mydomain.com>): 250 2.0.0 Ok: queued as B6E1E42445
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) Amavis::Out::SMTP::Session close, disconnecting
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) get_deadline fwd-end-chkpnt - deadline in 479.9 s, set to 336.000 s
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) prolong_timer fwd-end-chkpnt: timer 336, was 0, deadline in 479.9 s
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) FWD from <> -> <user@mydomain.com>, 250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as B6E1E42445
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) TempDir::DESTROY called
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) TempDir removal: empty tempdir is being removed: /var/lib/amavis/tmp/amavis-20160115T101424-31134-iKHFDPk6
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) rmdir_recursively: /var/lib/amavis/tmp/amavis-20160115T101424-31134-iKHFDPk6, excl=
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) TIMING [total 139 ms] - got data: 0 (0%)0, mkdir tempdir: 1 (1%)1, fwd-connect: 26 (18%)19, fwd-mail-pip: 5 (4%)23, fwd-rcpt-pip: 0 (0%)23, fwd-data-chkpnt: 0 (0%)24, write-header: 10 (7%)31, fwd-data-contents: 46 (33%)64, fwd-end-chkpnt: 47 (33%)98, rmdir: 1 (1%)98, rundown: 2 (2%)100
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) switch_to_client_time 480 s, receiving AM.PDP data
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) get_deadline switch_to_my_time(end of AM.PDP session) - deadline in 480.0 s, set to 336.000 s
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) prolong_timer switch_to_my_time(end of AM.PDP session): timer 336, was 480, deadline in 480.0 s
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) exiting process_request
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) idle_proc, bye: was busy, 148.1 ms, total idle 40.395 s, busy 1.375 s
Jan 15 10:14:24 mail amavis[31134]: (rel-DsOOtU6plTeb) load: 3 %, total idle 40.395 s, busy 1.375 s
Jan 15 10:14:24 mail postfix/pipe[28510]: B6E1E42445: to=<user@mydomain.com>, relay=dovecot, delay=0.17, delays=0.11/0/0/0.06, dsn=2.0.0, status=sent (delivered via dovecot service)
Jan 15 10:14:24 mail postfix/qmgr[3642]: B6E1E42445: removed

Please Help, because right now I can't release any mail from quarantine neither with WebGUI nor with command.

thanks

3

Re: Some problem with iRedmail new version

Update : evidently, the message can be send with command line : amavisd-release ID
but when I check in dashboard, it is still remain in Quarantine List, so I can run the command line again and again and the message will be delivered to user as much as we run the command.

If I use Webgui to release, the message is not delivered to user, but it is move from Quarantine List to Received List, so after that, I can't run the command line to release because the message has gone (not found)

So the webgui release function is not working. Please help.

thanks

4

Re: Some problem with iRedmail new version

The problem is, I cannot reproduce this issue, so i cannot debug it on my testing machine. sad

Is it possible to let me login to your server (via ssh) for further debug? root privilege is required for updating config files and check log files.

5

Re: Some problem with iRedmail new version

Good news: i reproduced this issue on my testing machine, Ubuntu 15.10. Here's patch to fix it:

diff -r 78dd8d5f03bc libs/amavisd/quarantine.py
--- a/libs/amavisd/quarantine.py    Tue Jan 19 21:44:46 2016 +0800
+++ b/libs/amavisd/quarantine.py    Tue Jan 19 22:35:05 2016 +0800
@@ -266,7 +266,7 @@
             cmd_release += 'quar_type=Q\r\n'
             try:
                 s.send(cmd_release + '\r\n')
-                #s.recv(1024)
+                s.recv(1024)
 
                 releasedMailIDs += [record.get('mail_id', 'NOT-EXIST')]
             except Exception, e:

We must wait for Amavisd's response before deleting SQL record.

6 (edited by bigman 2016-01-20 12:44:28)

Re: Some problem with iRedmail new version

Hi Zhang thanks for the reply,
1. When I run this patch with --dry-run -p1 parameter the output is like below (unexpected ends in middle of line), is it safe to apply?
checking file libs/amavisd/quarantine.py
patch unexpectedly ends in middle of line
Hunk #1 succeeded at 266 with fuzz 1.

Edit : When I run for the second time, it has error like this :
checking file libs/amavisd/quarantine.py
Hunk #1 FAILED at 266.
1 out of 1 hunk FAILED

2. What about my question no 2 and 3 above ?

Waiting for your help
thanks

7

Re: Some problem with iRedmail new version

bigman wrote:

1. When I run this patch with --dry-run -p1 parameter the output is like below (unexpected ends in middle of line), is it safe to apply?

This patch just modifies ONE file, how about open file libs/amavisd/quarantine.py and modify it manually?

bigman wrote:

2. In the Quarantine List I also see some message without sender and when I open (click the arrow) that message, the from field is "Mail Delivery Subsystem <root@mydomain.com>" and the message "Your message towas automatically rejected: Quota exceeded (mailbox for user is full)" eventhough the user mailbox is not full , what is this ?

This doesn't look like sent by Dovecot, because the subject is not same as the one defined in /usr/local/bin/dovecot-quota-warning.sh.

If Amavisd didn't log a sender address in SQL database, then iRedAdmin-Pro doesn't get one. iRedAdmin-Pro just reads the SQL record.

bigman wrote:

3. In the Quarantine List also I see the message that local user send to outside recipient but it is BANNED with error "BANNED, message contains application/x-msdownload,.pdf,filename.pdf", so everytime user send PDF file it is BANNED, why ? How can I resolve this ?

You can find 'pdf' is banned in /etc/amavis/conf.d/20-debian_defaults, setting "$banned_filename_re". Remove it and restart Amavisd, then it should be fine.

8 (edited by bigman 2016-01-20 13:03:24)

Re: Some problem with iRedmail new version

Hi Zhang

thanks for the reply. how to modify it manually ? What should I modify ?
Sorry I don't understand how to read the patch smile
When I open the quarantine.py in line 266 it seems like these :
  cmd_release += 'quar_type=Q\r\n'
            try:
                s.send(cmd_release + '\r\n')
                #s.recv(1024)

                releasedMailIDs += [record.get('mail_id', 'NOT-EXIST')]
            except Exception, e:
                pass


So what should I change ? Just open the remark in s.recv(1024) line ?

thanks

9

Re: Some problem with iRedmail new version

Just REMOVE '#' in this line:

                #s.recv(1024)

Don't forget to restart Apache or uwsgi (if you're running Nginx) service to reload modified files.

10

Re: Some problem with iRedmail new version

Hi Zhang,

Ok it works ! Thanks

about problem no 3 I have check in /etc/amavis/conf.d/20-debian_defaults there is no pdf extension but there is qr '^application/x-msdownload$'i   line.
Can I remark this line ? What is the impact ?

thanks

11

Re: Some problem with iRedmail new version

You can try it.