Dec 29, 2023: iRedMail-1.6.8 has been released.

3m · 2014-10-07 21:59:26

3m
Member
Offline

Registered: 2013-12-23
Posts: 149

Topic: mail is not sent

- iRedMail version: 0.9.0 b3
- Store mail accounts in which backend MySQL
- Linux/BSD distribution name and version: FreeBSD 9.3
- Related log if you're reporting an issue: installation was successful but the mail is not sent
dovecot.log
Oct 07 16:47:13 imap-login: Info: Login: user=<222@test.ua>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=1263, secured, session=<pk67b9UE1wB/AAAB>
Oct 07 16:47:13 imap(222@test.ua): Info: Disconnected: Logged out in=44 out=562
Oct 07 16:47:26 imap-login: Info: Login: user=<222@test.ua>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=1265, secured, session=<HVmBcNUESgB/AAAB>
Oct 07 16:47:26 imap(222@test.ua): Info: Disconnected: Logged out in=70 out=582
Oct 07 16:47:27 imap-login: Info: Login: user=<222@test.ua>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=1271, secured, session=<AkmScNUEDAB/AAAB>
Oct 07 16:47:27 imap(222@test.ua): Info: Disconnected: Logged out in=50 out=475
Oct 07 16:47:28 imap-login: Info: Login: user=<222@test.ua>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=1272, secured, session=<Kl+ScNUEigB/AAAB>
Oct 07 16:47:28 imap(222@test.ua): Info: Disconnected: Logged out in=233 out=891
Oct 07 16:47:30 imap-login: Info: Login: user=<222@test.ua>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=1274, secured, session=<m6C7cNUEJgB/AAAB>
Oct 07 16:47:30 imap(222@test.ua): Info: Disconnected: Logged out in=49 out=474
Oct 07 16:47:32 imap-login: Info: Login: user=<222@test.ua>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=1276, secured, session=<sw7ccNUELQB/AAAB>
Oct 07 16:47:32 imap(222@test.ua): Info: Disconnected: Logged out in=50 out=475
Oct 07 16:47:38 imap-login: Info: Login: user=<222@test.ua>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=1278, secured, session=<cdk5cdUE1AB/AAAB>
Oct 07 16:47:38 imap(222@test.ua): Info: Disconnected: Logged out in=32 out=460
Oct 07 16:47:39 imap-login: Info: Login: user=<222@test.ua>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=1280, secured, session=<sRlHcdUEUgB/AAAB>
Oct 07 16:47:39 imap(222@test.ua): Info: Disconnected: Logged out in=44 out=562
Oct 07 16:52:00 imap-login: Info: Login: user=<222@test.ua>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=1295, secured, session=<LuzdgNUEyQB/AAAB>
Oct 07 16:52:00 imap(222@test.ua): Info: Disconnected: Logged out in=44 out=562

Disconnected: Logged out ...why?

----

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

**ZhangHuangbin** · 2014-10-07 22:10:57

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 30,787

Re: mail is not sent

Dovecot provides POP3/IMAP/SIEVE services, Postfix provides SMTP service. You're checking wrong log file. Please check /var/log/maillog to figure it out.

3m · 2014-10-08 01:52:06

3m
Member
Offline

Registered: 2013-12-23
Posts: 149

Re: mail is not sent

Oct 7 20:36:38 mx amavis[940]: Using primary internal av scanner code for ClamAV-clamd
Oct 7 20:36:38 mx amavis[940]: Found secondary av scanner ClamAV-clamscan at /usr/local/bin/clamscan
Oct 7 20:36:38 mx amavis[940]: Deleting db files __db.001,__db.002,__db.003,snmp.db,nanny.db in /var/amavis/db
Oct 7 20:36:38 mx amavis[940]: Creating db in /var/amavis/db/; BerkeleyDB 0.54, libdb 5.3
Oct 7 20:37:08 mx postfix/postfix-script[1050]: warning: /var/spool/postfix/etc/hosts and /etc/hosts differ
Oct 7 20:37:08 mx postfix/postfix-script[1056]: starting the Postfix mail system
Oct 7 20:37:08 mx postfix/master[1058]: daemon started -- version 2.11.1, configuration /usr/local/etc/postfix
Oct 7 20:37:42 mx postfix/smtpd[1162]: connect from mx[127.0.0.1]
Oct 7 20:37:43 mx postfix/trivial-rewrite[1166]: warning: do not list domain test.ua in BOTH mydestination and virtual_mailbox_domains
Oct 7 20:37:43 mx postfix/trivial-rewrite[1166]: warning: do not list domain test.ua in BOTH mydestination and virtual_mailbox_domains
Oct 7 20:37:44 mx postfix/smtpd[1162]: 1BE4E9CE58: client=mx[127.0.0.1], sasl_method=LOGIN, sasl_username=222@test.ua
Oct 7 20:38:44 mx roundcube: SMTP Error: SMTP error: Failed to send data in /usr/local/www/roundcube/program/lib/Roundcube/rcube.php on line 1505 (POST /mail/?_task=mail&_unlock=loading1412703461540&_lang=ru&_framed=1?_task=mail&_action=send)
Oct 7 20:38:44 mx postfix/smtpd[1162]: lost connection after DATA (12 bytes) from mx[127.0.0.1]
Oct 7 20:38:44 mx postfix/cleanup[1168]: 1BE4E9CE58: message-id=<20141007173744.1BE4E9CE58@test.ua>
Oct 7 20:38:44 mx postfix/smtpd[1162]: disconnect from mx[127.0.0.1]
Oct 7 20:39:58 mx postfix/smtpd[1162]: connect from mx[127.0.0.1]
Oct 7 20:40:58 mx roundcube: SMTP server does not support authentication ():
Oct 7 20:40:58 mx roundcube: SMTP Error: SMTP error: Authentication failure: SMTP server does not support authentication (Code: ) in /usr/local/www/roundcube/program/lib/Roundcube/rcube.php on line 1505 (POST /mail/?_task=mail&_unlock=loading1412703598114&_lang=ru&_framed=1?_task=mail&_action=send)
Oct 7 20:40:58 mx postfix/smtpd[1162]: disconnect from mx[127.0.0.1]
Oct 7 20:42:07 mx postfix/smtpd[1162]: connect from mx[127.0.0.1]
Oct 7 20:43:07 mx roundcube: SMTP server does not support authentication ():
Oct 7 20:43:07 mx roundcube: SMTP Error: SMTP error: Authentication failure: SMTP server does not support authentication (Code: ) in /usr/local/www/roundcube/program/lib/Roundcube/rcube.php on line 1505 (POST /mail/?_task=mail&_unlock=loading1412703726477&_lang=ru&_framed=1?_task=mail&_action=send)
Oct 7 20:43:07 mx postfix/smtpd[1162]: disconnect from mx[127.0.0.1]

Awstats ...404 Not Found nginx

where disappeared phpMyAdmin??? I beg you to return!!!

**ZhangHuangbin** · 2014-10-08 11:04:00

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 30,787

Re: mail is not sent

3m wrote:

Oct 7 20:37:43 mx postfix/trivial-rewrite[1166]: warning: do not list domain test.ua in BOTH mydestination and virtual_mailbox_domains

Is your server hostname same as your mail domain name? Please fix it first.

3m wrote:

Oct 7 20:40:58 mx roundcube: SMTP Error: SMTP error: Authentication failure: SMTP server does not support authentication (Code: ) in /usr/local/www/roundcube/program/lib/Roundcube/rcube.php on line 1505 (POST /mail/?_task=mail&_unlock=loading1412703598114&_lang=ru&_framed=1?_task=mail&_action=send)

SMTP authentication is enabled by default, not sure why it doesn't work on your server. Please show us output of command "postconf -n" here for troubleshooting.

3m wrote:

where disappeared phpMyAdmin??? I beg you to return!!!

it won't return.
Check our discussion here: https://groups.google.com/d/msg/iredmai … RzR_DiKR8J

3m · 2014-10-08 15:33:17

3m
Member
Offline

Registered: 2013-12-23
Posts: 149

Re: mail is not sent

Hi Zhang! Created a new domain, the error persists

Oct 8 10:23:49 mx postfix/postfix-script[1053]: starting the Postfix mail system
Oct 8 10:23:49 mx postfix/master[1055]: daemon started -- version 2.11.1, configuration /usr/local/etc/postfix
Oct 8 10:24:10 mx postfix/smtpd[1159]: connect from mx[127.0.0.1]
Oct 8 10:24:11 mx postfix/smtpd[1159]: F3A569CEB4: client=mx[127.0.0.1], sasl_method=LOGIN, sasl_username=111@mmm.ua
Oct 8 10:25:12 mx roundcube: SMTP Error: SMTP error: Failed to send data in /usr/local/www/roundcube/program/lib/Roundcube/rcube.php on line 1505 (POST /mail/?_task=mail&_unlock=loading1412753048014&_lang=ru&_framed=1?_task=mail&_action=send)
Oct 8 10:25:12 mx postfix/smtpd[1159]: lost connection after DATA (12 bytes) from mx[127.0.0.1]
Oct 8 10:25:12 mx postfix/cleanup[1165]: F3A569CEB4: message-id=<20141008072411.F3A569CEB4@test.ua>
Oct 8 10:25:12 mx postfix/smtpd[1159]: disconnect from mx[127.0.0.1]

# postconf -n
alias_database = hash:/usr/local/etc/postfix/aliases
alias_maps = hash:/usr/local/etc/postfix/aliases
allow_min_user = no
allow_percent_hack = no
biff = no
bounce_queue_lifetime = 4h
broken_sasl_auth_clients = yes
command_directory = /usr/local/sbin
config_directory = /usr/local/etc/postfix
content_filter = smtp-amavis:[127.0.0.1]:10024
daemon_directory = /usr/local/libexec/postfix
data_directory = /var/db/postfix
debug_peer_level = 2
debugger_command = PATH=/bin:/usr/bin:/usr/local/bin:/usr/X11R6/bin ddd $daemon_directory/$process_name $process_id & sleep 5
delay_warning_time = 0h
disable_vrfy_command = yes
dovecot_destination_recipient_limit = 1
enable_original_recipient = no
home_mailbox = Maildir/
html_directory = /usr/local/share/doc/postfix
inet_interfaces = all
inet_protocols = all
mail_owner = postfix
mailbox_command = /usr/local/libexec/dovecot/deliver
mailq_path = /usr/local/bin/mailq
manpage_directory = /usr/local/man
maximal_backoff_time = 4000s
maximal_queue_lifetime = 4h
message_size_limit = 15728640
minimal_backoff_time = 300s
mydestination = $myhostname, localhost, localhost.localdomain, localhost.$myhostname
mydomain = test.ua
myhostname = test.ua
mynetworks = 127.0.0.0/8
mynetworks_style = host
myorigin = test.ua
newaliases_path = /usr/local/bin/newaliases
proxy_read_maps = $canonical_maps $lmtp_generic_maps $local_recipient_maps $mydestination $mynetworks $recipient_bcc_maps $recipient_canonical_maps $relay_domains $relay_recipient_maps $relocated_maps $sender_bcc_maps $sender_canonical_maps $smtp_generic_maps $smtpd_sender_login_maps $transport_maps $virtual_alias_domains $virtual_alias_maps $virtual_mailbox_domains $virtual_mailbox_maps $smtpd_sender_restrictions
queue_directory = /var/spool/postfix
queue_run_delay = 300s
readme_directory = /usr/local/share/doc/postfix
receive_override_options = no_address_mappings
recipient_bcc_maps = proxy:mysql:/usr/local/etc/postfix/mysql/recipient_bcc_maps_user.cf, proxy:mysql:/usr/local/etc/postfix/mysql/recipient_bcc_maps_domain.cf
recipient_delimiter = +
relay_domains = $mydestination, proxy:mysql:/usr/local/etc/postfix/mysql/relay_domains.cf
sample_directory = /usr/local/etc/postfix
sender_bcc_maps = proxy:mysql:/usr/local/etc/postfix/mysql/sender_bcc_maps_user.cf, proxy:mysql:/usr/local/etc/postfix/mysql/sender_bcc_maps_domain.cf
sendmail_path = /usr/local/sbin/sendmail
setgid_group = maildrop
smtp-amavis_destination_recipient_limit = 1
smtp_data_init_timeout = 240s
smtp_data_xfer_timeout = 600s
smtp_tls_CAfile = $smtpd_tls_CAfile
smtp_tls_loglevel = 0
smtp_tls_note_starttls_offer = yes
smtp_tls_security_level = may
smtpd_data_restrictions = reject_unauth_pipelining
smtpd_end_of_data_restrictions = check_policy_service inet:127.0.0.1:10031
smtpd_helo_required = yes
smtpd_helo_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_non_fqdn_helo_hostname, reject_invalid_helo_hostname, check_helo_access pcre:/usr/local/etc/postfix/helo_access.pcre
smtpd_recipient_restrictions = reject_unknown_sender_domain, reject_unknown_recipient_domain, reject_non_fqdn_sender, reject_non_fqdn_recipient, reject_unlisted_recipient, check_policy_service inet:127.0.0.1:7777, check_policy_service inet:127.0.0.1:10031, permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination
smtpd_reject_unlisted_recipient = yes
smtpd_reject_unlisted_sender = yes
smtpd_sasl_auth_enable = yes
smtpd_sasl_local_domain =
smtpd_sasl_path = private/dovecot-auth
smtpd_sasl_security_options = noanonymous
smtpd_sasl_type = dovecot
smtpd_sender_login_maps = proxy:mysql:/usr/local/etc/postfix/mysql/sender_login_maps.cf
smtpd_sender_restrictions = permit_mynetworks, reject_sender_login_mismatch, permit_sasl_authenticated
smtpd_tls_CAfile = /etc/ssl/certs/iRedMail_CA.pem
smtpd_tls_auth_only = yes
smtpd_tls_cert_file = /etc/ssl/certs/iRedMail_CA.pem
smtpd_tls_key_file = /etc/ssl/private/iRedMail.key
smtpd_tls_loglevel = 0
smtpd_tls_security_level = may
swap_bangpath = no
tls_random_source = dev:/dev/urandom
transport_maps = proxy:mysql:/usr/local/etc/postfix/mysql/transport_maps_user.cf, proxy:mysql:/usr/local/etc/postfix/mysql/transport_maps_domain.cf
unknown_local_recipient_reject_code = 550
virtual_alias_domains =
virtual_alias_maps = proxy:mysql:/usr/local/etc/postfix/mysql/virtual_alias_maps.cf, proxy:mysql:/usr/local/etc/postfix/mysql/domain_alias_maps.cf, proxy:mysql:/usr/local/etc/postfix/mysql/catchall_maps.cf, proxy:mysql:/usr/local/etc/postfix/mysql/domain_alias_catchall_maps.cf
virtual_gid_maps = static:2000
virtual_mailbox_base = /var/vmail
virtual_mailbox_domains = proxy:mysql:/usr/local/etc/postfix/mysql/virtual_mailbox_domains.cf
virtual_mailbox_maps = proxy:mysql:/usr/local/etc/postfix/mysql/virtual_mailbox_maps.cf
virtual_minimum_uid = 2000
virtual_transport = dovecot
virtual_uid_maps = static:2000

**ZhangHuangbin** · 2014-10-08 17:58:12

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 30,787

Re: mail is not sent

Could you please show me below settings in Roundcube config file /usr/local/www/roundcubemail/config/config.inc.php?

$config['smtp_server'] =
$config['smtp_port'] =
$config['smtp_user'] =
$config['smtp_pass'] =
$config['smtp_auth_type'] =

3m · 2014-10-08 18:02:19

3m
Member
Offline

Registered: 2013-12-23
Posts: 149

Re: mail is not sent

Mozilla Thunderbird 31.1.2 it works just fine!!!
a problem in...
SMTP Error: SMTP error: Failed to send data in /usr/local/www/roundcube/program/lib/Roundcube/rcube.php on line 1505 (POST /mail/?_task=mail&_unlock=loading1412753048014&_lang=ru&_framed=1?_task=mail&_action=send)

**ZhangHuangbin** · 2014-10-08 18:32:58

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 30,787

Re: mail is not sent

Check my previous reply. Cannot help without your settings/log.

3m · 2014-10-08 19:01:58

3m
Member
Offline

Registered: 2013-12-23
Posts: 149

Re: mail is not sent

// SMTP
$config['smtp_server'] = 'tls://127.0.0.1';
$config['smtp_port'] = 587;
$config['smtp_user'] = '%u';
$config['smtp_pass'] = '%p';
$config['smtp_auth_type'] = 'LOGIN';

**ZhangHuangbin** · 2014-10-08 19:49:00

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 30,787

Re: mail is not sent

No idea yet. Could you please turn on smtp debug in Roundcube and try again?

$config['smtp_debug'] = true;

Then extract roundcube log from /var/log/maillog and paste here.

3m · 2014-10-08 20:30:33

3m
Member
Offline

Registered: 2013-12-23
Posts: 149

Re: mail is not sent

Oct 8 15:28:13 mx postfix/smtpd[1200]: connect from mx[127.0.0.1]
Oct 8 15:28:13 mx roundcube: Recv: 220 test.ua ESMTP Postfix
Oct 8 15:28:13 mx roundcube: Send: EHLO _
Oct 8 15:28:13 mx roundcube: Recv: 250-test.ua
Oct 8 15:28:13 mx roundcube: Recv: 250-PIPELINING
Oct 8 15:28:13 mx roundcube: Recv: 250-SIZE 15728640
Oct 8 15:28:13 mx roundcube: Recv: 250-ETRN
Oct 8 15:28:13 mx roundcube: Recv: 250-STARTTLS
Oct 8 15:28:13 mx roundcube: Recv: 250-ENHANCEDSTATUSCODES
Oct 8 15:28:13 mx roundcube: Recv: 250-8BITMIME
Oct 8 15:28:13 mx roundcube: Recv: 250 DSN
Oct 8 15:28:13 mx roundcube: Send: STARTTLS
Oct 8 15:28:13 mx roundcube: Recv: 220 2.0.0 Ready to start TLS
Oct 8 15:28:13 mx roundcube: Send: EHLO _
Oct 8 15:28:13 mx roundcube: Recv: 250-test.ua
Oct 8 15:28:13 mx roundcube: Recv: 250-PIPELINING
Oct 8 15:28:13 mx roundcube: Recv: 250-SIZE 15728640
Oct 8 15:28:13 mx roundcube: Recv: 250-ETRN
Oct 8 15:28:13 mx roundcube: Recv: 250-AUTH PLAIN LOGIN
Oct 8 15:28:13 mx roundcube: Recv: 250-AUTH=PLAIN LOGIN
Oct 8 15:28:13 mx roundcube: Recv: 250-ENHANCEDSTATUSCODES
Oct 8 15:28:13 mx roundcube: Recv: 250-8BITMIME
Oct 8 15:28:13 mx roundcube: Recv: 250 DSN
Oct 8 15:28:13 mx roundcube: Send: AUTH LOGIN
Oct 8 15:28:13 mx roundcube: Recv: 334 VXNlcm5hbWU6
Oct 8 15:28:13 mx roundcube: Send: MTExQG1tbS51YQ==
Oct 8 15:28:13 mx roundcube: Recv: 334 UGFzc3dvcmQ6
Oct 8 15:28:13 mx roundcube: Send: ****** [12]
Oct 8 15:28:14 mx roundcube: Recv: 235 2.7.0 Authentication successful
Oct 8 15:28:14 mx roundcube: Send: MAIL FROM:<111@mmm.ua>
Oct 8 15:28:14 mx roundcube: Recv: 250 2.1.0 Ok
Oct 8 15:28:14 mx roundcube: Send: RCPT TO:<222@mmm.ua>
Oct 8 15:28:14 mx postfix/smtpd[1200]: 28C049CDBB: client=mx[127.0.0.1], sasl_method=LOGIN, sasl_username=111@mmm.ua
Oct 8 15:28:14 mx roundcube: Recv: 250 2.1.5 Ok
Oct 8 15:28:14 mx roundcube: Send: DATA
Oct 8 15:29:14 mx roundcube: Send: RSET
Oct 8 15:29:14 mx roundcube: SMTP Error: SMTP error: Failed to send data in /usr/local/www/roundcube/program/lib/Roundcube/rcube.php on line 1505 (POST /mail/?_task=mail&_unlock=loading1412771292229&_lang=ru&_framed=1?_task=mail&_action=send)
Oct 8 15:29:14 mx roundcube: Send: QUIT
Oct 8 15:29:14 mx postfix/smtpd[1200]: lost connection after DATA (12 bytes) from mx[127.0.0.1]
Oct 8 15:29:14 mx postfix/cleanup[1205]: 28C049CDBB: message-id=<20141008122814.28C049CDBB@test.ua>
Oct 8 15:29:14 mx postfix/smtpd[1200]: disconnect from mx[127.0.0.1]

**ZhangHuangbin** · 2014-10-09 21:09:21

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 30,787

Re: mail is not sent

3m wrote:

Oct 8 15:28:13 mx roundcube: Send: EHLO _

*) Excuse me, is '_' the real EHLO identity sent by Roundcube or you replaced it?
*) Any related log in Cluebringer? You have to turn on debug mode in Cluebringer to track this. See also: http://www.iredmail.org/docs/turn.on.de … inger.html

3m · 2014-10-10 20:04:59

3m
Member
Offline

Registered: 2013-12-23
Posts: 149

Re: mail is not sent

/var/log/cbpolicyd.log

[2014/10/10-14:58:17 - 1061] [CORE] INFO: Starting "1" children
[2014/10/10-14:58:17 - 1065] [CORE] INFO: 2014/10/10-14:58:17 CONNECT TCP Peer: "[127.0.0.1]:23119" Local: "[127.0.0.1]:10031"
[2014/10/10-14:58:17 - 1208] [CORE] DEBUG: Child Preforked (1208)
[2014/10/10-14:58:17 - 1208] [CBPOLICYD] DEBUG: Starting up caching engine
[2014/10/10-14:58:17 - 1065] [TRACKING] DEBUG: No session tracking data exists for request: $VAR1 = {
'ccert_fingerprint' => '',
'sasl_method' => 'LOGIN',
'sasl_sender' => '',
'size' => 0,
'_timestamp' => 1412942297,
'helo_name' => '_',
'reverse_client_name' => 'mx',
'queue_id' => '',
'encryption_cipher' => 'DHE-RSA-AES256-SHA',
'encryption_protocol' => 'TLSv1',
'etrn_domain' => '',
'ccert_subject' => '',
'request' => 'smtpd_access_policy',
'protocol_state' => 'RCPT',
'stress' => '',
'sasl_username' => '111@mmm.ua',
'recipient' => '222@mmm.ua',
'ccert_pubkey_fingerprint' => '',
'instance' => '4b4.5437c9d9.7df90.0',
'protocol_name' => 'ESMTP',
'encryption_keysize' => '256',
'recipient_count' => '0',
'ccert_issuer' => '',
'sender' => '111@mmm.ua',
'client_name' => 'mx',
'client_address' => '127.0.0.1',
'_protocol_transport' => 'Postfix'
};
[2014/10/10-14:58:17 - 1065] [TRACKING] DEBUG: Added session tracking information for: $VAR1 = {
'ccert_fingerprint' => '',
'sasl_method' => 'LOGIN',
'sasl_sender' => '',
'size' => 0,
'_timestamp' => 1412942297,
'helo_name' => '_',
'reverse_client_name' => 'mx',
'queue_id' => '',
'encryption_cipher' => 'DHE-RSA-AES256-SHA',
'encryption_protocol' => 'TLSv1',
'etrn_domain' => '',
'ccert_subject' => '',
'request' => 'smtpd_access_policy',
'protocol_state' => 'RCPT',
'stress' => '',
'sasl_username' => '111@mmm.ua',
'recipient' => '222@mmm.ua',
'ccert_pubkey_fingerprint' => '',
'instance' => '4b4.5437c9d9.7df90.0',
'protocol_name' => 'ESMTP',
'encryption_keysize' => '256',
'recipient_count' => '0',
'ccert_issuer' => '',
'sender' => '111@mmm.ua',
'client_name' => 'mx',
'client_address' => '127.0.0.1',
'_protocol_transport' => 'Postfix'
};
[2014/10/10-14:58:17 - 1065] [TRACKING] DEBUG: Protocol state is 'RCPT', resolving policy...
[2014/10/10-14:58:17 - 1065] [POLICIES] DEBUG: Going to resolve session data into policy: $VAR1 = {
'Recipient' => '222@mmm.ua',
'SASLUsername' => '111@mmm.ua',
'QueueID' => '',
'RecipientData' => '',
'Instance' => '4b4.5437c9d9.7df90.0',
'EncryptionCipher' => 'DHE-RSA-AES256-SHA',
'Size' => '0',
'EncryptionKeySize' => '256',
'EncryptionProtocol' => 'TLSv1',
'Helo' => '_',
'ClientAddress' => '127.0.0.1',
'ClientName' => 'mx',
'Sender' => '111@mmm.ua',
'SASLSender' => '',
'Protocol' => 'ESMTP',
'ClientReverseName' => 'mx',
'SASLMethod' => 'LOGIN'
};
[2014/10/10-14:58:17 - 1065] [POLICIES] DEBUG: Found policy member with ID '2' in policy 'Default Outbound'
[2014/10/10-14:58:17 - 1065] [POLICIES] DEBUG: Found policy member with ID '3' in policy 'Default Inbound'
[2014/10/10-14:58:17 - 1065] [POLICIES] DEBUG: Found policy member with ID '4' in policy 'Default Internal'
[2014/10/10-14:58:17 - 1065] [POLICIES] DEBUG: Found policy member with ID '6' in policy 'whitelists'
[2014/10/10-14:58:17 - 1065] [POLICIES] DEBUG: Found policy member with ID '7' in policy 'blacklists'
[2014/10/10-14:58:17 - 1065] [POLICIES] DEBUG: Found policy member with ID '8' in policy 'no_greylisting'
[2014/10/10-14:58:17 - 1065] [POLICIES] DEBUG: Found policy member with ID '9' in policy 'no_greylisting'
[2014/10/10-14:58:17 - 1065] [POLICIES] DEBUG: [ID:2/Name:Default Outbound]: Main policy sources '%internal_domains'
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:2/Name:Default Outbound]: Group 'internal_domains' has 1 source(s) => @test.km
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:2/Name:Default Outbound]=>(group:internal_domains): - Resolved source '@test.km' to a email address specification, match = 0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:2/Name:Default Outbound]=>(group:internal_domains): Source group result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] INFO: [ID:2/Name:Default Outbound]: Source matching result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:3/Name:Default Inbound]: Main policy sources '!%internal_ips,!%internal_domains'
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:3/Name:Default Inbound]: Group 'internal_ips' has 1 source(s) => 10.0.0.0/8
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:3/Name:Default Inbound]=>(group:internal_ips): - Resolved source '10.0.0.0/8' to a IP/CIDR specification, match = 0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:3/Name:Default Inbound]=>(group:internal_ips): Source group result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:3/Name:Default Inbound]: Group 'internal_domains' has 1 source(s) => @test.km
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:3/Name:Default Inbound]=>(group:internal_domains): - Resolved source '@test.km' to a email address specification, match = 0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:3/Name:Default Inbound]=>(group:internal_domains): Source group result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] INFO: [ID:3/Name:Default Inbound]: Source matching result: matched=1
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:3/Name:Default Inbound]: Main policy destinations '%internal_domains'
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:3/Name:Default Inbound]: Group 'internal_domains' has 1 destination(s) => @test.km
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:3/Name:Default Inbound]=>(group:internal_domains): - Resolved destination '@test.km' to a email address specification, match = 0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:3/Name:Default Inbound]=>(group:internal_domains): Destination group result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] INFO: [ID:3/Name:Default Inbound]: Destination matching result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:4/Name:Default Internal]: Main policy sources '%internal_ips,%internal_domains'
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:4/Name:Default Internal]: Group 'internal_ips' has 1 source(s) => 10.0.0.0/8
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:4/Name:Default Internal]=>(group:internal_ips): - Resolved source '10.0.0.0/8' to a IP/CIDR specification, match = 0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:4/Name:Default Internal]=>(group:internal_ips): Source group result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] INFO: [ID:4/Name:Default Internal]: Source matching result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:6/Name:whitelists]: Main policy sources '%whitelists'
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:6/Name:whitelists]: Group 'whitelists' has 0 source(s) =>
[2014/10/10-14:58:18 - 1065] [POLICIES] WARNING: [ID:6/Name:whitelists]: No group members for source group 'whitelists'
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:6/Name:whitelists]=>(group:whitelists): Source group result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] INFO: [ID:6/Name:whitelists]: Source matching result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:7/Name:blacklists]: Main policy sources '%blacklists'
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:7/Name:blacklists]: Group 'blacklists' has 0 source(s) =>
[2014/10/10-14:58:18 - 1065] [POLICIES] WARNING: [ID:7/Name:blacklists]: No group members for source group 'blacklists'
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:7/Name:blacklists]=>(group:blacklists): Source group result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] INFO: [ID:7/Name:blacklists]: Source matching result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:8/Name:no_greylisting]: Main policy sources '!%internal_ips,!%internal_domains'
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:8/Name:no_greylisting]: Group 'internal_ips' has 1 source(s) => 10.0.0.0/8
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:8/Name:no_greylisting]=>(group:internal_ips): - Resolved source '10.0.0.0/8' to a IP/CIDR specification, match = 0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:8/Name:no_greylisting]=>(group:internal_ips): Source group result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:8/Name:no_greylisting]: Group 'internal_domains' has 1 source(s) => @test.km
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:8/Name:no_greylisting]=>(group:internal_domains): - Resolved source '@test.km' to a email address specification, match = 0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:8/Name:no_greylisting]=>(group:internal_domains): Source group result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] INFO: [ID:8/Name:no_greylisting]: Source matching result: matched=1
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:8/Name:no_greylisting]: Main policy destinations '%no_greylisting_for_internal'
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:8/Name:no_greylisting]: Group 'no_greylisting_for_internal' has 0 destination(s) =>
[2014/10/10-14:58:18 - 1065] [POLICIES] WARNING: [ID:8/Name:no_greylisting]: No group members for destination group 'no_greylisting_for_internal'
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:8/Name:no_greylisting]=>(group:no_greylisting_for_internal): Destination group result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] INFO: [ID:8/Name:no_greylisting]: Destination matching result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:9/Name:no_greylisting]: Main policy sources '%no_greylisting_for_external'
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:9/Name:no_greylisting]: Group 'no_greylisting_for_external' has 0 source(s) =>
[2014/10/10-14:58:18 - 1065] [POLICIES] WARNING: [ID:9/Name:no_greylisting]: No group members for source group 'no_greylisting_for_external'
[2014/10/10-14:58:18 - 1065] [POLICIES] DEBUG: [ID:9/Name:no_greylisting]=>(group:no_greylisting_for_external): Source group result: matched=0
[2014/10/10-14:58:18 - 1065] [POLICIES] INFO: [ID:9/Name:no_greylisting]: Source matching result: matched=0
[2014/10/10-14:58:18 - 1065] [TRACKING] DEBUG: Policy resolved into: $VAR1 = {};
[2014/10/10-14:58:18 - 1065] [TRACKING] DEBUG: Request translated into session data: $VAR1 = {
'Recipient' => '222@mmm.ua',
'SASLUsername' => '111@mmm.ua',
'QueueID' => '',
'RecipientData' => '',
'Instance' => '4b4.5437c9d9.7df90.0',
'EncryptionCipher' => 'DHE-RSA-AES256-SHA',
'Size' => '0',
'EncryptionKeySize' => '256',
'ParsedClientAddress' => {
'Broadcast_Long' => 2130706433,
'Network' => '127.0.0.1',
'IP_Long' => 2130706433,
'Broadcast' => '127.0.0.1',
'IP' => '127.0.0.1',
'Mask_Long' => 4294967295,
'Network_Long' => 2130706433
},
'ProtocolTransport' => 'Postfix',
'EncryptionProtocol' => 'TLSv1',
'Helo' => '_',
'ClientAddress' => '127.0.0.1',
'ClientName' => 'mx',
'Sender' => '111@mmm.ua',
'SASLSender' => '',
'Timestamp' => 1412942297,
'ProtocolState' => 'RCPT',
'Policy' => {},
'Protocol' => 'ESMTP',
'ClientReverseName' => 'mx',
'SASLMethod' => 'LOGIN'
};
[2014/10/10-14:58:18 - 1065] [CBPOLICYD] DEBUG: Got request, running modules...
[2014/10/10-14:58:18 - 1065] [CBPOLICYD] DEBUG: Running module: Access Control Plugin
[2014/10/10-14:58:18 - 1065] [CBPOLICYD] DEBUG: Running module: HELO/EHLO Check Plugin
[2014/10/10-14:58:18 - 1065] [CBPOLICYD] DEBUG: Running module: Greylisting Plugin
[2014/10/10-14:58:18 - 1065] [CBPOLICYD] DEBUG: Running module: Quotas Plugin
[2014/10/10-14:58:18 - 1065] [CBPOLICYD] DEBUG: Done with modules
[2014/10/10-14:58:48 - 1061] [CORE] INFO: Killing "1" children
[2014/10/10-14:58:48 - 1208] [CBPOLICYD] DEBUG: Shutting down caching engine (1208)

**javon** · 2015-01-04 06:52:25

javon
Member
Offline

Registered: 2012-05-27
Posts: 37

Re: mail is not sent

Sorry for hijacking an old thread. But did you solve it somehow?
I have completely new installation of iRedMail 0.9.0 on FreeBSD 10.1.
I am facing similar problems:
If I send mail from Roundcube I got error:
SMTP Error (220): Authentication failed.

In maillog is this:
Jan 3 23:49:01 smtpnew postfix/smtpd[14856]: connect from unknown[xx.xx.xx.xx]
Jan 3 23:49:01 smtpnew postfix/smtpd[14856]: SSL_accept error from unknown[xx.xx.xx.xx]: 0
Jan 3 23:49:01 smtpnew postfix/smtpd[14856]: warning: TLS library problem: error:14094418:SSL routines:SSL3_READ_BYTES:tlsv1 alert unknown ca:/usr/src/secure/lib/libssl/../../../crypto/openssl/ssl/s3_pkt.c:1125:SSL alert number 48:
Jan 3 23:49:01 smtpnew postfix/smtpd[14856]: lost connection after STARTTLS from unknown[xx.xx.xx.xx]
Jan 3 23:49:01 smtpnew roundcube: PHP Deprecated: Non-static method PEAR::raiseError() should not be called statically, assuming $this from incompatible context in /usr/local/www/roundcube/program/lib/Net/SMTP.php on line 611
Jan 3 23:49:01 smtpnew postfix/smtpd[14856]: disconnect from unknown[xx.xx.xx.xx]
Jan 3 23:49:01 smtpnew roundcube: STARTTLS failed ():
Jan 3 23:49:01 smtpnew roundcube: PHP Deprecated: Non-static method PEAR::raiseError() should not be called statically, assuming $this from incompatible context in /usr/local/www/roundcube/program/lib/Net/SMTP.php on line 371
Jan 3 23:49:01 smtpnew roundcube: PHP Deprecated: Non-static method PEAR::raiseError() should not be called statically, assuming $this from incompatible context in /usr/local/www/roundcube/program/lib/Net/SMTP.php on line 265
Jan 3 23:49:01 smtpnew roundcube: SMTP Error: SMTP error: Authentication failure: STARTTLS failed (Code: ) in /usr/local/www/roundcube/program/lib/Roundcube/rcube.php on line 1505 (POST /mail/?_task=mail&_unlock=loading1420325349248&_lang=en_US&_framed=1?_task=mail&_action=send)

**ZhangHuangbin** · 2015-01-04 14:55:01

ZhangHuangbin
iRedMail Developers
Offline

Registered: 2009-05-06
Posts: 30,787

Re: mail is not sent

javon wrote:

Jan 3 23:49:01 smtpnew postfix/smtpd[14856]: connect from unknown[xx.xx.xx.xx]

Is xx.xx.xx.xx the IP address of your webmail server?

Can you send mail with other mail clients? e.g. Outlook, Thunderbird. All have the same issue?

Dec 29, 2023: iRedMail-1.6.8 has been released.

mail is not sent

Posts: 15

1 Topic by 3m 2014-10-07 21:59:26 (edited by 3m 2014-10-07 22:02:02)

Topic: mail is not sent

2 Reply by ZhangHuangbin 2014-10-07 22:10:57

Re: mail is not sent

3 Reply by 3m 2014-10-08 01:52:06

Re: mail is not sent

4 Reply by ZhangHuangbin 2014-10-08 11:04:00

Re: mail is not sent

5 Reply by 3m 2014-10-08 15:33:17

Re: mail is not sent

6 Reply by ZhangHuangbin 2014-10-08 17:58:12

Re: mail is not sent

7 Reply by 3m 2014-10-08 18:02:19

Re: mail is not sent

8 Reply by ZhangHuangbin 2014-10-08 18:32:58

Re: mail is not sent

9 Reply by 3m 2014-10-08 19:01:58

Re: mail is not sent

10 Reply by ZhangHuangbin 2014-10-08 19:49:00

Re: mail is not sent

11 Reply by 3m 2014-10-08 20:30:33

Re: mail is not sent

12 Reply by ZhangHuangbin 2014-10-09 21:09:21

Re: mail is not sent

13 Reply by 3m 2014-10-10 20:04:59

Re: mail is not sent

14 Reply by javon 2015-01-04 06:52:25

Re: mail is not sent

15 Reply by ZhangHuangbin 2015-01-04 14:55:01

Re: mail is not sent

Posts: 15