Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Loop When Authenticating Against LDAP #259

Open
scienssciencia opened this issue Feb 14, 2024 · 11 comments
Open

Loop When Authenticating Against LDAP #259

scienssciencia opened this issue Feb 14, 2024 · 11 comments

Comments

@scienssciencia
Copy link

I am trying to build a DBmail solution to replace my existing Citadel mail server.

OS is Debian 12. DB is Mariadb 10.11.4 DBmail is version 3.4.1 compiled from source for debian using the instructions and adding the --with-ldap flag.

The core issue seems to be that the LDAP query eventually loops from querying for the user ID using mail=user@email.domain and suceeds but then for some reason queries again for mail=. Other odd issues also are present where the LMTP process seems to be continuously crashing.

root@mail01:/home/sysadmin# journalctl -u dbmail-lmtpd.service
Feb 09 05:42:30 mail01 systemd[1]: Starting dbmail-lmtpd.service - DBMail LMTP Server...
Feb 09 05:44:00 mail01 systemd[1]: dbmail-lmtpd.service: start operation timed out. Terminating.
Feb 09 05:44:00 mail01 systemd[1]: dbmail-lmtpd.service: Failed with result 'timeout'.
Feb 09 05:44:00 mail01 systemd[1]: Failed to start dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:44:03 mail01 systemd[1]: dbmail-lmtpd.service: Scheduled restart job, restart counter is at 1.
Feb 09 05:44:03 mail01 systemd[1]: Stopped dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:44:03 mail01 systemd[1]: Starting dbmail-lmtpd.service - DBMail LMTP Server...
Feb 09 05:45:33 mail01 systemd[1]: dbmail-lmtpd.service: start operation timed out. Terminating.
Feb 09 05:45:33 mail01 systemd[1]: dbmail-lmtpd.service: Failed with result 'timeout'.
Feb 09 05:45:33 mail01 systemd[1]: Failed to start dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:45:37 mail01 systemd[1]: dbmail-lmtpd.service: Scheduled restart job, restart counter is at 2.
Feb 09 05:45:37 mail01 systemd[1]: Stopped dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:45:37 mail01 systemd[1]: Starting dbmail-lmtpd.service - DBMail LMTP Server...
Feb 09 05:47:07 mail01 systemd[1]: dbmail-lmtpd.service: start operation timed out. Terminating.
Feb 09 05:47:07 mail01 systemd[1]: dbmail-lmtpd.service: Failed with result 'timeout'.
Feb 09 05:47:07 mail01 systemd[1]: Failed to start dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:47:10 mail01 systemd[1]: dbmail-lmtpd.service: Scheduled restart job, restart counter is at 3.
Feb 09 05:47:10 mail01 systemd[1]: Stopped dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:47:10 mail01 systemd[1]: Starting dbmail-lmtpd.service - DBMail LMTP Server...
Feb 09 05:48:40 mail01 systemd[1]: dbmail-lmtpd.service: start operation timed out. Terminating.
Feb 09 05:48:40 mail01 systemd[1]: dbmail-lmtpd.service: Failed with result 'timeout'.
Feb 09 05:48:40 mail01 systemd[1]: Failed to start dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:48:44 mail01 systemd[1]: dbmail-lmtpd.service: Scheduled restart job, restart counter is at 4.
Feb 09 05:48:44 mail01 systemd[1]: Stopped dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:48:44 mail01 systemd[1]: Starting dbmail-lmtpd.service - DBMail LMTP Server...
Feb 09 05:50:14 mail01 systemd[1]: dbmail-lmtpd.service: start operation timed out. Terminating.
Feb 09 05:50:14 mail01 systemd[1]: dbmail-lmtpd.service: Failed with result 'timeout'.
Feb 09 05:50:14 mail01 systemd[1]: Failed to start dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:50:17 mail01 systemd[1]: dbmail-lmtpd.service: Scheduled restart job, restart counter is at 5.
Feb 09 05:50:17 mail01 systemd[1]: Stopped dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:50:17 mail01 systemd[1]: Starting dbmail-lmtpd.service - DBMail LMTP Server...
Feb 09 05:51:47 mail01 systemd[1]: dbmail-lmtpd.service: start operation timed out. Terminating.
Feb 09 05:51:47 mail01 systemd[1]: dbmail-lmtpd.service: Failed with result 'timeout'.
Feb 09 05:51:47 mail01 systemd[1]: Failed to start dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:51:51 mail01 systemd[1]: dbmail-lmtpd.service: Scheduled restart job, restart counter is at 6.
Feb 09 05:51:51 mail01 systemd[1]: Stopped dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:51:51 mail01 systemd[1]: Starting dbmail-lmtpd.service - DBMail LMTP Server...
Feb 09 05:53:21 mail01 systemd[1]: dbmail-lmtpd.service: start operation timed out. Terminating.
Feb 09 05:53:21 mail01 systemd[1]: dbmail-lmtpd.service: Failed with result 'timeout'.
Feb 09 05:53:21 mail01 systemd[1]: Failed to start dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:53:24 mail01 systemd[1]: dbmail-lmtpd.service: Scheduled restart job, restart counter is at 7.
Feb 09 05:53:24 mail01 systemd[1]: Stopped dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:53:24 mail01 systemd[1]: Starting dbmail-lmtpd.service - DBMail LMTP Server...
Feb 09 05:54:35 mail01 systemd[1]: dbmail-lmtpd.service: Deactivated successfully.
Feb 09 05:54:35 mail01 systemd[1]: Stopped dbmail-lmtpd.service - DBMail LMTP Server.
-- Boot 83cc804fba384af7bf8974e2232d3e4e --
Feb 09 05:54:58 mail01 systemd[1]: Starting dbmail-lmtpd.service - DBMail LMTP Server...
Feb 09 05:54:58 mail01 dbmail/lmtpd[734]: Error:[db] check_upgrade_step(+964): SQLException: Table 'dbmail.dbmail_upgrade_steps' doesn't exist
Feb 09 05:56:28 mail01 systemd[1]: dbmail-lmtpd.service: start operation timed out. Terminating.
Feb 09 05:56:28 mail01 systemd[1]: dbmail-lmtpd.service: Failed with result 'timeout'.
Feb 09 05:56:28 mail01 systemd[1]: Failed to start dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:56:31 mail01 systemd[1]: dbmail-lmtpd.service: Scheduled restart job, restart counter is at 1.
Feb 09 05:56:31 mail01 systemd[1]: Stopped dbmail-lmtpd.service - DBMail LMTP Server.
Feb 09 05:56:31 mail01 systemd[1]: Starting dbmail-lmtpd.service - DBMail LMTP Server...

I am not certain if this is because my alias table is incorrect. When LDAP populates users in the MySQL database it correctly creates the user but no aliases. I attempted to populate the aliases manually in leiu of determining how to ensure they populate as expected. I can log in with a mail client and send an email from my test user to itself but the email never comes back to the inbox.

MariaDB [dbmail]> select user_idnr,userid,client_idnr,active from dbmail_users;
+-----------+--------------------------------+-------------+--------+
| user_idnr | userid                         | client_idnr | active |
+-----------+--------------------------------+-------------+--------+
|         1 | __@!internal_delivery_user!@__ |           0 |      1 |
|         2 | anyone                         |           0 |      1 |
|         3 | __public__                     |           0 |      1 |
|     10001 | user                         |       10001 |      1 |
+-----------+--------------------------------+-------------+--------+
4 rows in set (0.001 sec)

MariaDB [dbmail]> select * from dbmail_aliases;
+------------+---------------------+------------+-------------+
| alias_idnr | alias               | deliver_to | client_idnr |
+------------+---------------------+------------+-------------+
|          1 | user@test.domain | user     |       65535 |
+------------+---------------------+------------+-------------+
1 row in set (0.001 sec)

Logs attached for postfix and DBMail debug outputs when attempting to send an email from user@test.domain to user@test.domain.

postfix.log
dbmail.log

Below is the conf files and other outputs.

dbmail.conf

# Configuration file for DBMAIL
#
# Copyright (c) 2000-2006 IC&S, The Netherlands
# Copyright (c) 2004-2013 NFG Net Facilities Group BV support@nfg.nl
# Copyright (c) 2014-2019 Paul J Stevens, The Netherlands, support@nfg.nl
# Copyright (c) 2020-2023 Alan Hicks, Persistent Objects Ltd support@p-o.co.uk
#

[DBMAIL] 
# 
# Database settings
#
# database connection URI
# https://www.tildeslash.com/libzdb/#api

dburi                = mysql://dbmail:test@10.1.10.3:3306/dbmail

# 
# Supported drivers are sql, ldap.
#
authdriver           = ldap

# 
# 
# following fields are now DEPRECATED!
#driver               =
#host                 =
#sqlport              =
#sqlsocket            =              
#user                 =
#pass                 =                   
#db                   =

#
# Number of database connections per threaded daemon
# This also determines the size of the worker threadpool
#
# Do NOT increase this without proper consideration. A
# very large database/worker pool will not only increase
# the connection pressure on the database, but will more
# significantly cause unnecessary context-switching in 
# your CPUs.
#
#max_db_connections   = 10

# 
# Table prefix. Defaults to "dbmail_" if not specified.
#
table_prefix         = dbmail_   

# 
# encoding must match the database/table encoding.
# i.e. latin1, utf8
encoding             = utf8

#
# messages with unknown encoding will be assumed to have 
# default_msg_encoding
# i.e. iso8859-1, utf8
default_msg_encoding = utf8

# 
# Postmaster's email address for use in bounce messages.
#
#postmaster           = DBMAIL-MAILER       

# 
# Sendmail executable for forwards, replies, notifies, vacations.
# You may use pipes (|) in this command, for example:
# dos2unix|/usr/sbin/sendmail  works well with Qmail.
# You may use quotes (") for executables with unusual names.
#
sendmail              = /usr/sbin/sendmail     

#
#
# The following items can be overridden in the service-specific sections.
#
#

#
# Logging via stderr/log file and syslog
#
# Logging is broken up into 8 logging levels and each level can be
# individually turned on or off.
# The Stderr/log file logs all entries to stderr or the log file.
# Syslog logging uses the facility mail and the logging level of the event for
# logging.
# Syslog can then be configured to log data according to the levels.
#
# Set the log level to the sum of the values next to the levels you want to record.
#   1 = Emergency 
#   2 = Alert
#   4 = Critical
#   8 = Error
#  16 = Warning
#  32 = Notice
#  64 = Info
# 128 = Debug
# 256 = Database -> Logs at debug level
#
# Examples:   0 = Nothing
#            31 = Emergency + Alert + Critical + Error + Warning
#           511 = Everything
#
file_logging_levels       = 511
#
syslog_logging_levels     = 511

#
# Generate a log entry for database queries for the log level at number of
# seconds of query execution time.
#
query_time_info       = 10
query_time_notice     = 20
query_time_warning    = 30

#
# Throw an exception is the query takes longer than query_timeout seconds
query_timeout         = 300 

# 
# Root privileges are used to open a port, then privileges
# are dropped down to the user/group specified here.
#
effective_user        = dbmail
effective_group       = dbmail

# 
# The IPv4 and/or IPv6 addresses the services will bind to.
# Use * for all local interfaces.
# Use 127.0.0.1 for localhost only.
# Separate multiple entries with spaces ( ) or commas (,).
#
bindip                = 0.0.0.0         # IPv4 only - all IP's
#bindip                = ::             # IPv4 and IPv6 - all IP's (linux)
#bindip                = ::             # IPv6 only - all IP's (BSD)
#bindip                = 0.0.0.0,::     # IPv4 and IPv6 - all IP's (BSD)


#
# The maximum length of the queue of pending connections. See
# listen(2) for more information
#
# backlog              = 128

# 
# Idle time allowed before a connection is shut off.
#
timeout               = 300             

# 
# Idle time allowed before a connection is shut off if you have not logged in yet.
#
login_timeout         = 60

# 
# If yes, resolves IP addresses to DNS names when logging.
#
resolve_ip            = no

#
# If yes, keep statistics in the authlog table for connecting users
#
authlog               = yes

# 
# logfile for stdout messages
#
logfile               = /var/log/dbmail/dbmail.log

# 
# logfile for stderr messages
#
errorlog              = /var/log/dbmail/dbmail.err

# 
# directory for storing PID files
#
pid_directory         = /var/run/dbmail

#
# directory for locating libraries (normally has a sane default compiled-in)
#
#library_directory       = /usr/lib/dbmail

#
# SSL/TLS certificates
#
# A file containing a list of CAs in PEM format
tls_cafile            =

# A file containing a PEM format certificate
tls_cert              =

# A file containing a PEM format RSA or DSA key
tls_key               =

# A cipher list string in the format given in ciphers(1)
tls_ciphers           =


# hashing algorithm. You can select your favorite hash type
# for generating unique ids for message parts. 
#
# for valid values check mhash(3) but minus the MHASH_ prefix.
#  
# if you ever change this value run 'dbmail-util --rehash' to 
# update the hash for all mimeparts.
#
# examples: MD5, SHA1, SHA256, SHA512, TIGER, WHIRLPOOL
#
# hash_algorithm = SHA1


# header_cache tuning
#
# set header_cache_readonly to 'yes' to prevent new
# unknown header-names from being cached.
#
# header_cache_readonly = yes



[LMTP]
port                  = 24                 
#tls_port              =


[POP]
port                  = 110
#tls_port              = 995

# You can set an alternate banner to display when connecting to the service
# banner = DBMAIL pop3 server ready to rock

# If TLS is enabled, login before starttls is normally
# allowed. Use login_disabled=yes to change this
#
# login_disabled        = no

# 
# If yes, allows SMTP access from the host IP connecting by POP3.
# This requires addition configuration of your MTA
#
pop_before_smtp       = no      

[HTTP]
port                  = 41380
#
# the httpd daemon provides full access to all users, mailboxes
# and messages. Be very careful with this one!
bindip                = 127.0.0.1
admin                 = admin:secret

[IMAP]

# IMAP State Reload Strategy. Internally DBMail is loading various information
# about the selected folders (flags, message ids, etc)
# 1 = full reload (default)
# 2 = diff reload (experimental)
#   In some setups it might be beneficial to use it, due to the fact that
#   reloading is done in differential mode, which may result in lower DB usage

# mailbox_update_strategy = 1

# IMAP Search strategy.
# 1 = full sql search (default). All searches performed on the current folder
#   are made via sql queries.
# 2 = optimized search, use partial sql search  (experimental). Some searches
#   will be made via loaded state of the current folder.
#   In some setups it might be beneficial to use it, due to lower DB usage.

# mailbox_search_strategy = 1

# Only for IMAP Reload Strategy (mailbox_search_strategy = 2)
# Might be beneficial to do a full reload after n iterations. Sometimes might
# be beneficial to reload the full state reload.
# -1 = no expiration 
#  x = number of iterations. If no mails are received (IDLE Server) those
#    iterations can be transform in seconds
#    mailbox_update_strategy_2_max_iterations * idle_timeout * idle_interval = s
#

# mailbox_update_strategy_2_max_iterations = 64

# Allow reporting UNSEEN in SELECT command. 
# Although RFC 3501 does state it that is mandatory, missing it means that the
# client need to issue a search for the unseen messages
# 1 = allow UNSEEN in SELECT Command (default)
# 0 = Do not Allow UNSEEN in SELECT Command

# command_select_allow_unseen = 1

# Mailbox Sequence update strategy.
# 1 = normal behaviour, transactional safe
# 2 = non transaction, still safe, might be better in clustered environments 

# mailbox_update_seq_strategy = 1


# Mailbox DELETE and message status synchronization.
# In some instances messages marked as deleted are not having the status as deleted
# 1 = normal do not sync
# 2 = sync

# mailbox_sync_deleted = 1

# If mailbox_sync_deleted=2, size of the batch. 
# Due to the fact that this flag is making correction live, protection should
# be put in place

# mailbox_sync_batch_size = 64


# You can set an alternate banner to display when connecting to the service
# banner = imap 4r1 server (dbmail 3.4.x)

# 
# Port to bind to.
#
port                  = 143                
#tls_port              = 993

# 
# IMAP prefers a longer timeout than other services.
#
timeout               = 4000            

# 
# If yes, allows SMTP access from the host IP connecting by IMAP.
# This requires addition configuration of your MTA
#
imap_before_smtp      = no     

#
# during IDLE, how many seconds between checking the mailbox
# status (default: 30)
#
# idle_timeout          = 30

# during IDLE, how often should the server send an '* OK' still
# here message (default: 10)
#
# the time between such a message is idle_timeout * idle_interval
# seconds
#
# idle_interval         = 10

#
# If TLS is enabled, login before starttls is normally
# not allowed. Use login_disabled=no to change this
#
# login_disabled        = yes

#
# Provide a CAPABILITY to override the default
#
# capability            = IMAP4 IMAP4rev1 AUTH=LOGIN ACL RIGHTS=texk NAMESPACE CHILDREN SORT QUOTA THREAD=ORDEREDSUBJECT UNSELECT IDLE

# max message size. You can specify the maximum message size
# accepted by the IMAP daemon during APPEND commands.
#
# Supported formats:
#  decimal: 1000000    
#  octal:   03777777
#  hex:     0xfffff
#
# max_message_size      =


[SIEVE]
# 
# Port to bind to.
#
port                  = 4090


[LDAP]
#port                  = 389
version               = 3
#hostname              = 10.1.10.5
base_dn               = dc=corp,dc=test,dc=domain

# 
# If your LDAP library supports ldap_initialize(), then you can use the
# alternative LDAP server DSN like following.
#
URI                = ldap://10.1.10.5:389
# URI                = ldapi://%2fvar%2frun%2fopenldap%2fldapi/

# 
# Leave blank for anonymous bind.
# example: cn=admin,dc=mydomain,dc=com     
#
bind_dn               = uid=dbmail,ou=Services,dc=corp,dc=test,dc=domain

# 
# Leave blank for anonymous bind.
#
bind_pw               = ELhKf3wsgq6b41X4dhNPwgnk
scope                 = SubTree

# AD users may want to set this to 'no' to disable
# ldap referrals if you are seeing 'Operations errors' 
# in your logs
#
referrals             = yes

user_objectclass      = top,inetOrgPerson,posixAccount
forw_objectclass      = top,dbmailForwardingAddress
cn_string             = uid
field_passwd          = userPassword
field_uid             = uid
field_nid             = uidNumber
min_nid               = 10000
max_nid               = 15000
field_cid             = gidNumber
min_cid               = 10000
max_cid               = 15000

# a comma-separated list of attributes to match when searching
# for users or forwards that match a delivery address. A match
# on any of them is a hit.
field_mail            = mail

# field that holds the mail-quota size for a user.
field_quota           = mailQuota

# field that holds the forwarding address. 
#field_fwdtarget       = mailForwardingAddress
field_fwdtarget       = mail

# override the query string used to search for users 
# or forwards with a delivery address.
query_string          = (mail=%s)

[DELIVERY]
# 
# Run Sieve scripts as messages are delivered.
#
SIEVE                 = yes               

# 
# Use 'user+mailbox@domain' format to deliver to a mailbox.
#
SUBADDRESS            = yes          

# 
# Turn on/off the Sieve Vacation extension.
#
SIEVE_VACATION        = yes      

# 
# Turn on/off the Sieve Notify extension
#
SIEVE_NOTIFY          = yes

# 
# Turn on/off additional Sieve debugging.
#
SIEVE_DEBUG           = no          


# Use the auto_notify table to send email notifications.
#
AUTO_NOTIFY           = no
 
# 
# Use the auto_reply table to send away messages.
#
AUTO_REPLY            = no

# 
# Defaults to "NEW MAIL NOTIFICATION"
#
#AUTO_NOTIFY_SUBJECT        =    

# 
# Defaults to POSTMASTER from the DBMAIL section.
#
#AUTO_NOTIFY_SENDER        =   


# If you set this to 'yes' dbmail will check for duplicate
# messages in the relevant mailbox during delivery using 
# the Message-ID header
#
suppress_duplicates     = no

#
# Soft or hard bounce on over-quota delivery
#
quota_failure           = hard


# end of configuration file

Systemd files

root@mail01:/home/sysadmin# cat /etc/systemd/system/dbmail-*
[Unit]
Description=DBMail Imap Server
After=network.target network-online.target mysqld.service postgresql.service

[Service]
Type=notify
ExecStart=/usr/local/sbin/dbmail-imapd -D -f /etc/dbmail/dbmail.conf
Restart=always
RestartSec=3s

[Install]
WantedBy=multi-user.target
[Unit]
Description=DBMail LMTP Server
After=network.target network-online.target mysqld.service postgresql.service

[Service]
Type=notify
ExecStart=/usr/local/sbin/dbmail-lmtpd -D -f /etc/dbmail/dbmail.conf
Restart=always
RestartSec=3s

[Install]
WantedBy=multi-user.target
[Unit]
Description=DBMail pop3 Server
After=network.target network-online.target mysqld.service postgresql.service

[Service]
Type=notify
ExecStart=/usr/local/sbin/dbmail-pop3d -D -f /etc/dbmail/dbmail.conf
Restart=always
RestartSec=3s

[Install]
WantedBy=multi-user.target
root@mail01:/home/sysadmin# 
/usr/lib/tmpfiles.d/dbmail.conf 

d /run/dbmail 0777 dbmail dbmail -
root@mail01:/home/sysadmin# dbmail-util -V
This is dbmail 3.4.1

Copyright (C) 1999-2004 IC & S, dbmail@ic-s.nl
Copyright (C) 2001-2007 Aaron Stone, aaron@serendipity.cx
Copyright (C) 2004-2013 NFG Net Facilities Group BV, support@nfg.nl
Copyright (c) 2014-2019 Paul J Stevens, The Netherlands, support@nfg.nl
Copyright (c) 2020-2023 Alan Hicks, Persistent Objects Ltd support@p-o.co.uk

Please see the AUTHORS and THANKS files for additional contributors.

This program is free software; you can redistribute it and/or 
modify it under the terms of the GNU General Public License as
published by the Free Software Foundation; either version 2 of
the License, or (at your option) any later version.

This program is distributed in the hope that it will be useful,
but WITHOUT ANY WARRANTY; without even the implied warranty of
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
GNU General Public License for more details.

You should have received a copy of the GNU General Public License
along with this program; if not, write to the Free Software
Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.

Internal Version 34001
@alan-hicks
Copy link
Member

If you turn up the debug level you should be able to discover what's causing the timeout.
DBMail looks up the alias to identify the delivery account. With LDAP it's the mail attribute.
Any clues from the log file where lmtp is crashing would be appreciated.

@alan-hicks
Copy link
Member

Also field_mail and field_fwdtarget are both set to mail.

@alan-hicks
Copy link
Member

Also you need to change your password!

@scienssciencia
Copy link
Author

scienssciencia commented Feb 14, 2024

If you turn up the debug level you should be able to discover what's causing the timeout.

Any clues from the log file where lmtp is crashing would be appreciated.

Postfix log shows the email being transferred to LMTPD but the process sends a reset to the postfix process while receiving the data mid-session (according to PCAP output). Relevant log below for Postfix:

Feb 14 02:03:04 mail01 postfix/qmgr[1102]: AC69E7A05B0: from=<user@test.domain>, size=565, nrcpt=1 (queue active)
Feb 14 02:03:04 mail01 postfix/qmgr[1102]: B8CA07A05AE: from=<user@test.domain>, size=562, nrcpt=1 (queue active)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: name_mask: all
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: inet_addr_local: configured 2 IPv4 addresses
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: inet_addr_local: configured 2 IPv6 addresses
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: process generation: 2102 (2102)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: match_string: parent_domain_matches_subdomains: fast_flush_domains ~? debug_peer_list
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: match_string: parent_domain_matches_subdomains: fast_flush_domains ~? fast_flush_domains
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: name_mask: canonical
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: name_mask: virtual
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: host name lookup methods: native
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: auto_clnt_create: transport=local endpoint=private/scache
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: connection established
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: master_notify: status 0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: deliver_request_initial: send initial response
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr protocol = delivery_request_protocol
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: flags
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: flags
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: 3
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: queue_name
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: queue_name
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: active
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: queue_id
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: queue_id
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: AC69E7A05B0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: offset
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: offset
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: 682
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: size
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: size
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: 565
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: nexthop
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: nexthop
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: 127.0.0.1:24
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: encoding
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: encoding
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: 8bit
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: smtputf8
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: smtputf8
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: 0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: sender
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: sender
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: envelope_id
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: envelope_id
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: ret_flags
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: ret_flags
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: 0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: time
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: time
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: tYvMZQAAAACqkgoAAAAAANiPzGUAAAAAUMAFAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: log_client_name
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: log_client_name
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: unknown
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: log_client_address
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: log_client_address
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: 10.1.10.8
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: log_client_port
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: log_client_port
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: 42380
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: log_protocol_name
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: log_protocol_name
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: ESMTP
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: log_helo_name
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: log_helo_name
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: [10.1.10.8]
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: sasl_method
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: sasl_method
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: sasl_username
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: sasl_username
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: sasl_sender
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: sasl_sender
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: log_ident
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: log_ident
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: AC69E7A05B0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: rewrite_context
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: rewrite_context
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: remote
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: recipient_count
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: recipient_count
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: 1
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: (list terminator)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: original_recipient
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: original_recipient
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: recipient
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: recipient
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: offset
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: offset
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: 659
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: dsn_orig_rcpt
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: dsn_orig_rcpt
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: rfc822;user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: notify_flags
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: notify_flags
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: 0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: (list terminator)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: deliver_request_get: file active/AC69E7A05B0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: deliver_message: from user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: smtp_parse_destination: 127.0.0.1:24 24
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: connecting to 127.0.0.1 port 24
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: smtp_addr_one: host 127.0.0.1
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: smtp_addr_one: using numerical host 127.0.0.1
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: begin 127.0.0.1 address list
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: pref    0 host 127.0.0.1/127.0.0.1
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: end 127.0.0.1 address list
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: global TLS level: none
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: ctable_locate: install entry key MTI3LjAuMC4xOjI0:127.0.0.1:24:
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: smtp_connect_addr: trying: 127.0.0.1[127.0.0.1] port 24...
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: vstream_tweak_tcp: TCP_MAXSEG 32741
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: fd=14: stream buffer size old=0 new=130964
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: < 127.0.0.1[127.0.0.1]:24: 220 mail01 LMTP
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: > 127.0.0.1[127.0.0.1]:24: LHLO mail01.corp.test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: < 127.0.0.1[127.0.0.1]:24: 250-mail01
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: < 127.0.0.1[127.0.0.1]:24: 250-PIPELINING
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: < 127.0.0.1[127.0.0.1]:24: 250-ENHANCEDSTATUSCODES
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: < 127.0.0.1[127.0.0.1]:24: 250 SIZE
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: server features: 0x100d size 0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: Using LMTP PIPELINING, TCP send buffer size is 2626560, PIPELINING buffer size is 4096
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: > 127.0.0.1[127.0.0.1]:24: MAIL FROM:<user@test.domain>
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: > 127.0.0.1[127.0.0.1]:24: RCPT TO:<user@test.domain>
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: > 127.0.0.1[127.0.0.1]:24: DATA
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: < 127.0.0.1[127.0.0.1]:24: 250 Sender <user@test.domain> OK
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: name_mask: all
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: inet_addr_local: configured 2 IPv4 addresses
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: inet_addr_local: configured 2 IPv6 addresses
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: process generation: 2103 (2103)
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: match_string: parent_domain_matches_subdomains: fast_flush_domains ~? debug_peer_list
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: match_string: parent_domain_matches_subdomains: fast_flush_domains ~? fast_flush_domains
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: name_mask: canonical
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: name_mask: virtual
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: host name lookup methods: native
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: auto_clnt_create: transport=local endpoint=private/scache
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: connection established
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: master_notify: status 0
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: deliver_request_initial: send initial response
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr protocol = delivery_request_protocol
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: flags
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: flags
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: 3
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: queue_name
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: queue_name
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: active
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: queue_id
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: queue_id
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: B8CA07A05AE
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: offset
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: offset
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: 682
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: size
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: size
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: 562
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: nexthop
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: nexthop
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: 127.0.0.1:24
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: encoding
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: encoding
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: 8bit
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: smtputf8
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: smtputf8
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: 0
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: sender
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: sender
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: envelope_id
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: envelope_id
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: ret_flags
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: ret_flags
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: 0
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: time
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: time
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: cIvMZQAAAAAfMgsAAAAAANiPzGUAAAAAkCMGAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: log_client_name
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: log_client_name
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: unknown
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: log_client_address
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: log_client_address
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: 10.1.10.8
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: log_client_port
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: log_client_port
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: 42380
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: log_protocol_name
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: log_protocol_name
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: ESMTP
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: log_helo_name
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: log_helo_name
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: [10.1.10.8]
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: sasl_method
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: sasl_method
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: sasl_username
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: sasl_username
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: sasl_sender
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: sasl_sender
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: log_ident
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: log_ident
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: B8CA07A05AE
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: rewrite_context
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: rewrite_context
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: remote
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: recipient_count
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: recipient_count
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: 1
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: (list terminator)
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: original_recipient
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: original_recipient
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: recipient
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: recipient
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: offset
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: offset
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: 659
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: dsn_orig_rcpt
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: dsn_orig_rcpt
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: rfc822;user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: notify_flags
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: notify_flags
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: 0
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: dbmail-lmtp socket: wanted attribute: (list terminator)
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: deliver_request_get: file active/B8CA07A05AE
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: deliver_message: from user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: smtp_parse_destination: 127.0.0.1:24 24
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: connecting to 127.0.0.1 port 24
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: smtp_addr_one: host 127.0.0.1
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: smtp_addr_one: using numerical host 127.0.0.1
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: begin 127.0.0.1 address list
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: pref    0 host 127.0.0.1/127.0.0.1
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: end 127.0.0.1 address list
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: global TLS level: none
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: ctable_locate: install entry key MTI3LjAuMC4xOjI0:127.0.0.1:24:
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: smtp_connect_addr: trying: 127.0.0.1[127.0.0.1] port 24...
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: vstream_tweak_tcp: TCP_MAXSEG 32741
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: fd=14: stream buffer size old=0 new=130964
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: smtp_get: EOF
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: smtp_get: EOF
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: connect to subsystem private/defer
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: connect to subsystem private/defer
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: private/defer socket: wanted attribute: protocol
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: protocol
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: delivery_status_protocol
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: private/defer socket: wanted attribute: (list terminator)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr nrequest = 0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr flags = 0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr queue_id = AC69E7A05B0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr original_recipient = user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr recipient = user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr offset = 659
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr dsn_orig_rcpt = rfc822;user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr notify_flags = 0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr status = 4.4.2
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr diag_type =
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr diag_text =
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr mta_type =
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr mta_mname =
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr action = delayed
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr reason = lost connection with 127.0.0.1[127.0.0.1] while sending RCPT TO
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: private/defer socket: wanted attribute: status
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: status
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute value: 0
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: private/defer socket: wanted attribute: protocol
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: private/defer socket: wanted attribute: (list terminator)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: input attribute name: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: AC69E7A05B0: to=<user@test.domain>, relay=127.0.0.1[127.0.0.1]:24, delay=1059, delays=1059/0.04/0/0.06, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while sending RCPT TO)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: flush_add: site test.domain id AC69E7A05B0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: match_list_match: test.domain: no match
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: flush_add: site test.domain id AC69E7A05B0 status 4
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: name_mask: resource
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: protocol
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: name_mask: software
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: deliver_request_final: send: "lost connection with 127.0.0.1[127.0.0.1] while sending RCPT TO" -1
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: delivery_status_protocol
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr status = 4.4.2
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: private/defer socket: wanted attribute: (list terminator)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr diag_type =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr diag_text =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr nrequest = 0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr mta_type =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr flags = 0
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr mta_mname =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr queue_id = B8CA07A05AE
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr action =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr original_recipient = user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr reason = lost connection with 127.0.0.1[127.0.0.1] while sending RCPT TO
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr recipient = user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: send attr status = 4294967295
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr offset = 659
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr dsn_orig_rcpt = rfc822;user@test.domain
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr notify_flags = 0
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr status = 4.4.2
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr diag_type =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr diag_text =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr mta_type =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr mta_mname =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr action = delayed
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr reason = lost connection with 127.0.0.1[127.0.0.1] while receiving the initial server greeting
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: master_notify: status 1
Feb 14 02:03:04 mail01 postfix/lmtp[20160]: connection closed
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: private/defer socket: wanted attribute: status
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: status
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute value: 0
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: private/defer socket: wanted attribute: (list terminator)
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: input attribute name: (end)
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: B8CA07A05AE: to=<user@test.domain>, relay=127.0.0.1[127.0.0.1]:24, delay=1128, delays=1128/0.03/0.05/0, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while receiving the initial server greeting)
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: flush_add: site test.domain id B8CA07A05AE
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: match_list_match: test.domain: no match
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: flush_add: site test.domain id B8CA07A05AE status 4
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: deliver_request_final: send: "lost connection with 127.0.0.1[127.0.0.1] while receiving the initial server greeting" -1
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr status = 4.4.2
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr diag_type =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr diag_text =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr mta_type =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr mta_mname =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr action =
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr reason = lost connection with 127.0.0.1[127.0.0.1] while receiving the initial server greeting
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: send attr status = 4294967295
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: master_notify: status 1
Feb 14 02:03:04 mail01 postfix/lmtp[20161]: connection closed
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: name_mask: all
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: inet_addr_local: configured 2 IPv4 addresses
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: inet_addr_local: configured 2 IPv6 addresses
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: process generation: 2106 (2106)
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: dict_open: regexp:{{/^[^A-Z]/ Bogus}}
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? debug_peer_list
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? fast_flush_domains
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? mynetworks
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? permit_mx_backup_networks
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? qmqpd_authorized_clients
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? relay_domains
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_client_event_limit_exceptions ~? smtpd_access_maps
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_list_match: smtpd_client_event_limit_exceptions: no match
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: mynetworks ~? debug_peer_list
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: mynetworks ~? fast_flush_domains
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: mynetworks ~? mynetworks
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: mynetworks ~? debug_peer_list
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: mynetworks ~? fast_flush_domains
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: mynetworks ~? mynetworks
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: name_mask: host
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: been_here: 127.0.0.1/32: 0
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: been_here: 10.1.10.3/32: 0
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: been_here: [::1]/128: 0
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: been_here: [fe80::20c:29ff:fee5:1ad]/128: 0
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: mynetworks_core: 127.0.0.1/32 10.1.10.3/32 [::1]/128 [fe80::20c:29ff:fee5:1ad]/128
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: mynetworks ~? debug_peer_list
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: mynetworks ~? fast_flush_domains
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: mynetworks ~? mynetworks
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: relay_domains ~? debug_peer_list
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: relay_domains ~? fast_flush_domains
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: relay_domains ~? mynetworks
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: relay_domains ~? permit_mx_backup_networks
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: relay_domains ~? qmqpd_authorized_clients
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: relay_domains ~? relay_domains
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: permit_mx_backup_networks ~? debug_peer_list
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: permit_mx_backup_networks ~? fast_flush_domains
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: permit_mx_backup_networks ~? mynetworks
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: permit_mx_backup_networks ~? permit_mx_backup_networks
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: connect to subsystem private/proxymap
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/proxymap socket: wanted attribute: protocol
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: protocol
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute value: proxymap_protocol
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/proxymap socket: wanted attribute: (list terminator)
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: send attr request = open
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: send attr table = unix:passwd.byname
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: send attr flags = 0
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/proxymap socket: wanted attribute: status
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: status
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute value: 0
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/proxymap socket: wanted attribute: flags
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: flags
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute value: 16
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/proxymap socket: wanted attribute: (list terminator)
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: dict_proxy_open: connect to map=unix:passwd.byname status=0 server_flags=fixed
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: dict_open: proxy:unix:passwd.byname
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: Compiled against Berkeley DB: 5.3.28?
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: Run-time linked against Berkeley DB: 5.3.28?
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: dict_open: hash:/etc/aliases
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: user = dbmail
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: password = test
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: dbname = dbmail
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: result_format = %s
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: option_file = <NULL>
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: option_group = client
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: tls_key_file = <NULL>
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: tls_cert_file = <NULL>
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: tls_CAfile = <NULL>
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: tls_CApath = <NULL>
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: tls_ciphers = <NULL>
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_bool: /etc/postfix/sql-virtual_mailbox_maps.cf: tls_verify_cert = on
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_bool: /etc/postfix/sql-virtual_mailbox_maps.cf: require_result_set = on
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_int: /etc/postfix/sql-virtual_mailbox_maps.cf: expansion_limit = 0
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: query = SELECT 1 FROM dbmail_aliases WHERE alias='%s';
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: domain =
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: cfg_get_str: /etc/postfix/sql-virtual_mailbox_maps.cf: hosts = 127.0.0.1
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: dict_open: mysql:/etc/postfix/sql-virtual_mailbox_maps.cf
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? debug_peer_list
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? fast_flush_domains
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? mynetworks
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? permit_mx_backup_networks
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? qmqpd_authorized_clients
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? relay_domains
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: smtpd_access_maps ~? smtpd_access_maps
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: unknown_helo_hostname_tempfail_action = defer_if_permit
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: unknown_address_tempfail_action = defer_if_permit
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: unverified_recipient_tempfail_action = defer_if_permit
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: unverified_sender_tempfail_action = defer_if_permit
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: name_mask: 0
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: tls_library_init: using backwards-compatible defaults
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: auto_clnt_create: transport=local endpoint=private/tlsmgr
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: auto_clnt_open: connected to private/tlsmgr
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/tlsmgr: wanted attribute: protocol
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: protocol
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute value: tlsmgr_protocol
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/tlsmgr: wanted attribute: (list terminator)
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: send attr request = seed
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: send attr size = 32
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/tlsmgr: wanted attribute: status
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: status
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute value: 0
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/tlsmgr: wanted attribute: seed
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: seed
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute value: jH/EAZFetfeDr00ZavAzAoIWKcP4YrpvPwQi8SMJDYo=
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/tlsmgr: wanted attribute: (list terminator)
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: send attr request = policy
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: send attr cache_type = smtpd
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/tlsmgr: wanted attribute: status
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: status
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute value: 0
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/tlsmgr: wanted attribute: cachable
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: cachable
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute value: 0
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/tlsmgr: wanted attribute: timeout
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: timeout
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute value: 3600
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: private/tlsmgr: wanted attribute: (list terminator)
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: fast_flush_domains ~? debug_peer_list
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: match_string: parent_domain_matches_subdomains: fast_flush_domains ~? fast_flush_domains
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: auto_clnt_create: transport=local endpoint=private/anvil
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: connection established
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: master_notify: status 0
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: name_mask: resource
Feb 14 02:03:06 mail01 postfix/smtpd[20167]: name_mask: software
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: connect from unknown[10.1.10.8]
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_list_match: unknown: no match
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_list_match: 10.1.10.8: no match
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_list_match: unknown: no match
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_list_match: 10.1.10.8: no match
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? 127.0.0.0/8
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_hostaddr: smtpd_client_event_limit_exceptions: 10.1.10.8 ~? 127.0.0.0/8
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? [::ffff:127.0.0.0]/104
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_hostaddr: smtpd_client_event_limit_exceptions: 10.1.10.8 ~? [::ffff:127.0.0.0]/104
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_hostname: smtpd_client_event_limit_exceptions: unknown ~? [::1]/128
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_hostaddr: smtpd_client_event_limit_exceptions: 10.1.10.8 ~? [::1]/128
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_list_match: unknown: no match
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_list_match: 10.1.10.8: no match
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: auto_clnt_open: connected to private/anvil
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/anvil: wanted attribute: protocol
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: protocol
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: anvil_protocol
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/anvil: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr request = connect
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr ident = smtp:10.1.10.8
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/anvil: wanted attribute: status
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: status
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/anvil: wanted attribute: count
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: count
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 1
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/anvil: wanted attribute: rate
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: rate
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 1
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/anvil: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 220 mail01.corp.test.domain ESMTP Postfix (Debian/GNU)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: < unknown[10.1.10.8]: EHLO [10.1.10.8]
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_list_match: unknown: no match
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_list_match: 10.1.10.8: no match
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250-mail01.corp.test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250-PIPELINING
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250-SIZE 10240000
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250-VRFY
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250-ETRN
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250-STARTTLS
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250-ENHANCEDSTATUSCODES
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250-8BITMIME
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250-DSN
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250-SMTPUTF8
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250 CHUNKING
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: < unknown[10.1.10.8]: MAIL FROM:<user@test.domain> BODY=8BITMIME SIZE=367
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: extract_addr: input: <user@test.domain>
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: smtpd_check_addr: addr=user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: connect to subsystem private/rewrite
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: protocol
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: protocol
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: trivial_rewrite_protocol
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr request = rewrite
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr rule = local
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr address = ""
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: address
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: address
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: ""
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: rewrite_clnt: local: "" -> ""
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr request = rewrite
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr rule = local
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr address = user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: address
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: address
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: rewrite_clnt: local: user@test.domain -> user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr request = resolve
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr sender =
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr address = user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: transport
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: transport
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: dbmail-lmtp
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: nexthop
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: nexthop
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 127.0.0.1:24
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: recipient
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: recipient
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 1024
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: resolve_clnt: `' -> `user@test.domain' -> transp=`dbmail-lmtp' host=`127.0.0.1:24' rcpt=`user@test.domain' flags= class=virtual
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: ctable_locate: install entry key ?user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: extract_addr: in: <user@test.domain>, result: user@test.domain
Feb 14 02:03:07 mail01 post dispatching event loop...fix/smtpd[20167]: send attr request = rewrite
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr rule = local
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr address = double-bounce
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: address
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: address
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: double-bounce@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: rewrite_clnt: local: double-bounce -> double-bounce@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: smtpd_check_rewrite: trying: permit_inet_interfaces
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: permit_inet_interfaces: unknown 10.1.10.8
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: fsspace: .: block size 4096, blocks free 47672522
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: smtpd_check_queue: blocks 4096 avail 47672522 min_free 0 msg_size_limit 10240000
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250 2.1.0 Ok
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: < unknown[10.1.10.8]: RCPT TO:<user@test.domain>
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: extract_addr: input: <user@test.domain>
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: smtpd_check_addr: addr=user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr request = rewrite
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr rule = local
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr address = user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: address
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: address
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: rewrite_clnt: local: user@test.domain -> user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: rewrite_clnt: cached: local: user@test.domain -> user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr request = resolve
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr sender = user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr address = user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: transport
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: transport
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: dbmail-lmtp
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: nexthop
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: nexthop
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 127.0.0.1:24
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: recipient
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: recipient
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: flags
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 1024
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: private/rewrite socket: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: resolve_clnt: `user@test.domain' -> `user@test.domain' -> transp=`dbmail-lmtp' host=`127.0.0.1:24' rcpt=`user@test.domain' flags= class=virtual
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: ctable_locate: install entry key user@test.domain?user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: extract_addr: in: <user@test.domain>, result: user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: >>> START Recipient address RESTRICTIONS <<<
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: generic_checks: name=permit_mynetworks
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: permit_mynetworks: unknown 10.1.10.8
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_hostname: mynetworks: unknown ~? 127.0.0.0/8
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_hostaddr: mynetworks: 10.1.10.8 ~? 127.0.0.0/8
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_hostname: mynetworks: unknown ~? [::ffff:127.0.0.0]/104
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_hostaddr: mynetworks: 10.1.10.8 ~? [::ffff:127.0.0.0]/104
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_hostname: mynetworks: unknown ~? [::1]/128
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_hostaddr: mynetworks: 10.1.10.8 ~? [::1]/128
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_list_match: unknown: no match
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: match_list_match: 10.1.10.8: no match
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: generic_checks: name=permit_mynetworks status=0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: generic_checks: name=permit_sasl_authenticated
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: generic_checks: name=permit_sasl_authenticated status=0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: generic_checks: name=defer_unauth_destination
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: reject_unauth_destination: user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: permit_auth_destination: user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: ctable_locate: leave existing entry key user@test.domain?user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: generic_checks: name=defer_unauth_destination status=0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: >>> END Recipient address RESTRICTIONS <<<
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: >>> CHECKING Recipient address VALIDATION MAPS <<<
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: ctable_locate: leave existing entry key user@test.domain?user@test.domain
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: maps_find: recipient_canonical_maps: user@test.domain: not found
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: maps_find: recipient_canonical_maps: user: not found
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: maps_find: recipient_canonical_maps: @test.domain: not found
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: mail_addr_find: user@test.domain -> (not found)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: maps_find: canonical_maps: user@test.domain: not found
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: maps_find: canonical_maps: user: not found
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: maps_find: canonical_maps: @test.domain: not found
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: mail_addr_find: user@test.domain -> (not found)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: maps_find: virtual_alias_maps: user@test.domain: not found
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: maps_find: virtual_alias_maps: user: not found
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: maps_find: virtual_alias_maps: @test.domain: not found
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: mail_addr_find: user@test.domain -> (not found)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: dict_mysql_get_active: attempting to connect to host 127.0.0.1
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: dict_mysql: successful connection to host 127.0.0.1
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: mysql:/etc/postfix/sql-virtual_mailbox_maps.cf: successful query result from host 127.0.0.1
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: dict_mysql_lookup: retrieved 1 rows
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: maps_find: virtual_mailbox_maps: mysql:/etc/postfix/sql-virtual_mailbox_maps.cf(0,lock|fold_fix|utf8_request): user@test.domain = 1
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: mail_addr_find: user@test.domain -> 1
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: before input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping enable_milters
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: after input_transp_cleanup: cleanup flags = enable_header_body_filter enable_automatic_bcc enable_address_mapping
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: name_mask: sendmail
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: name_mask: verify
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: connect to subsystem public/cleanup
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: public/cleanup socket: wanted attribute: protocol
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: protocol
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: cleanup_protocol
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: public/cleanup socket: wanted attribute: queue_id
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: queue_id
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 193C37A05B2
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: public/cleanup socket: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: send attr flags = 178
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: 193C37A05B2: client=unknown[10.1.10.8]
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250 2.1.5 Ok
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: < unknown[10.1.10.8]: DATA
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 354 End data with <CR><LF>.<CR><LF>
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=500
Feb 14 02:03:07 mail01 postfix/cleanup[20170]: 193C37A05B2: message-id=<d64e4799-32cd-4789-a8fb-3b55fd5b67ef@test.domain>
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: public/cleanup socket: wanted attribute: status
Feb 14 02:03:07 mail01 postfix/qmgr[1102]: 193C37A05B2: from=<user@test.domain>, size=565, nrcpt=1 (queue active)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: status
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: 0
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: public/cleanup socket: wanted attribute: reason
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: reason
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute value: (end)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: public/cleanup socket: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: > unknown[10.1.10.8]: 250 2.0.0 Ok: queued as 193C37A05B2
Feb 14 02:03:07 mail01 postfix/smtpd[20167]: smtp_stream_setup: maxtime=300 enable_deadline=0 min_data_rate=0
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: connection established
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: master_notify: status 0
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: deliver_request_initial: send initial response
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr protocol = delivery_request_protocol
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: flags
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: flags
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 3
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: queue_name
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: queue_name
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: active
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: queue_id
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: queue_id
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 193C37A05B2
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: offset
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: offset
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 681
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: size
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: size
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 565
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: nexthop
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: nexthop
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 127.0.0.1:24
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: encoding
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: encoding
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 8bit
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: smtputf8
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: smtputf8
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 0
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: sender
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: sender
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: user@test.domain
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: envelope_id
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: envelope_id
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: (end)
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: ret_flags
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: ret_flags
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 0
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: time
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: time
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 24/MZQAAAAAWEQEAAAAAANuPzGUAAAAAPrMBAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA==
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: log_client_name
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: log_client_name
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: unknown
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: log_client_address
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: log_client_address
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 10.1.10.8
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: log_client_port
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: log_client_port
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 53124
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: log_protocol_name
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: log_protocol_name
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: ESMTP
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: log_helo_name
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: log_helo_name
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: [10.1.10.8]
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: sasl_method
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: sasl_method
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: (end)
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: sasl_username
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: sasl_username
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: (end)
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: sasl_sender
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: sasl_sender
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: (end)
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: log_ident
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: log_ident
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 193C37A05B2
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: rewrite_context
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: rewrite_context
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: remote
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: recipient_count
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: recipient_count
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 1
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: original_recipient
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: original_recipient
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: user@test.domain
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: recipient
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: recipient
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: user@test.domain
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: offset
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: offset
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 658
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: dsn_orig_rcpt
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: dsn_orig_rcpt
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: rfc822;user@test.domain
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: notify_flags
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: notify_flags
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 0
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: dbmail-lmtp socket: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: deliver_request_get: file active/193C37A05B2
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: deliver_message: from user@test.domain
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: smtp_parse_destination: 127.0.0.1:24 24
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: connecting to 127.0.0.1 port 24
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: smtp_addr_one: host 127.0.0.1
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: smtp_addr_one: using numerical host 127.0.0.1
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: begin 127.0.0.1 address list
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: pref    0 host 127.0.0.1/127.0.0.1
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: end 127.0.0.1 address list
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: ctable_locate: install entry key MTI3LjAuMC4xOjI0:127.0.0.1:24:
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: smtp_connect_addr: trying: 127.0.0.1[127.0.0.1] port 24...
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: connect to 127.0.0.1[127.0.0.1]:24: Connection refused
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: connect to subsystem private/defer
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: private/defer socket: wanted attribute: protocol
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: protocol
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: delivery_status_protocol
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: private/defer socket: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr nrequest = 0
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr flags = 0
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr queue_id = 193C37A05B2
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr original_recipient = user@test.domain
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr recipient = user@test.domain
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr offset = 658
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr dsn_orig_rcpt = rfc822;user@test.domain
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr notify_flags = 0
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr status = 4.4.1
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr diag_type =
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr diag_text =
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr mta_type =
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr mta_mname =
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr action = delayed
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr reason = connect to 127.0.0.1[127.0.0.1]:24: Connection refused
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: private/defer socket: wanted attribute: status
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: status
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute value: 0
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: private/defer socket: wanted attribute: (list terminator)
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: input attribute name: (end)
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: 193C37A05B2: to=<user@test.domain>, relay=none, delay=0.04, delays=0.04/0/0/0, dsn=4.4.1, status=deferred (connect to 127.0.0.1[127.0.0.1]:24: Connection refused)
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: flush_add: site test.domain id 193C37A05B2
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: match_list_match: test.domain: no match
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: flush_add: site test.domain id 193C37A05B2 status 4
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: deliver_request_final: send: "connect to 127.0.0.1[127.0.0.1]:24: Connection refused" -1
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr status = 4.4.1
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr diag_type =
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr diag_text =
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr mta_type =
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr mta_mname =
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr action =
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr reason = connect to 127.0.0.1[127.0.0.1]:24: Connection refused
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: send attr status = 4294967295
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: master_notify: status 1
Feb 14 02:03:07 mail01 postfix/lmtp[20160]: connection closed

DBMail debug log:

Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Info:[server] _sock_cb(+636): connection accepted
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Notice:[clientbase] client_init(+180): incoming connection on [127.0.0.1:24] from [127.0.0.1:42390]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[misc] create_unique_id(+178): created: beb1d010a0c5e343d009922e3ed5258a
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_cork(+203): [0x7fbeac02c010] [16] [16]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Database:[db] db_con_get(+330): [0x564f0cb7ced0] connection from pool
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Database:[db] db_con_close(+358): [0x564f0cb7ced0] connection to pool
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_write(+382): [0x7fbeac02c010] S > [17/17:220 mail01 LMTP
]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_uncork(+211): [0x7fbeac02c010] [16] [16], [60]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[lmtp] lmtp_cb_write(+130): [0x564f0cbb8c20] state: [0]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[lmtp] lmtp_handle_input(+122): [0x564f0cbb8c20] done
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientsession] socket_write_cb(+293): reset timeout [60]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_read_cb(+434): [0x7fbeac02c010] [46]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_read_cb(+434): [0x7fbeac02c010] [-1]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Info:[clientbase] ci_readln(+525): [0x7fbeac02c010] C < [46:LHLO mail01.corp.test.domain
]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[lmtp] lmtp_tokenizer(+280): [0x564f0cbb8c20] cmd [0], state [1] [LHLO]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_cork(+203): [0x7fbeac02c010] [16] [16]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_write(+382): [0x7fbeac02c010] S > [63/63:250-mail01
250-PIPELINING
250-ENHANCEDSTATUSCODES
250 SIZE
]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_uncork(+211): [0x7fbeac02c010] [16] [16], [300]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[lmtp] lmtp_handle_input(+122): [0x564f0cbb8c20] done
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[lmtp] lmtp_cb_write(+130): [0x564f0cbb8c20] state: [2]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[lmtp] lmtp_handle_input(+122): [0x564f0cbb8c20] done
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientsession] socket_write_cb(+299): reset timeout [300]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_read_cb(+434): [0x7fbeac02c010] [70]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_read_cb(+434): [0x7fbeac02c010] [-1]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Info:[clientbase] ci_readln(+525): [0x7fbeac02c010] C < [33:MAIL FROM:<user@test.domain>
]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[lmtp] lmtp_tokenizer(+280): [0x564f0cbb8c20] cmd [4], state [1] [MAIL]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_cork(+203): [0x7fbeac02c010] [16] [16]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Info:[misc] find_bounded(+367): Found [user@test.domain] of length [19] between '<' and '>' so next skip [25]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_write(+382): [0x7fbeac02c010] S > [37/37:250 Sender <user@test.domain> OK
]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_uncork(+211): [0x7fbeac02c010] [16] [16], [300]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Info:[clientbase] ci_readln(+525): [0x7fbeac02c010] C < [31:RCPT TO:<user@test.domain>
]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[lmtp] lmtp_tokenizer(+280): [0x564f0cbb8c20] cmd [9], state [1] [RCPT]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[clientbase] ci_cork(+203): [0x7fbeac02c010] [16] [16]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Info:[misc] find_bounded(+367): Found [user@test.domain] of length [19] between '<' and '>' so next skip [23]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[dsn] dsnuser_init(+194): dsnuser initialized
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Info:[dsn] dsnuser_resolve(+566): checking if [user@test.domain] is a valid username, alias, or catchall.
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [0]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [1]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [1]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [2]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [2]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [3]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [3]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [4]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [4]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [5]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [5]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [6]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [6]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [7]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [7]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [8]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [8]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [9]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [9]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [10]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [10]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [11]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [11]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [12]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [12]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [13]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [13]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [14]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [14]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [15]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [15]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [16]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [16]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [17]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [17]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [18]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [18]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [19]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [19]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [20]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [20]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Error:[auth] auth_check_user_ext(+887): too many checks. Possible loop detected.
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Error:[auth] auth_check_user_ext(+887): too many checks. Possible loop detected.
free(): invalid pointer
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Debug:[imap] imap_cb_time(+370): [0x55b06a184d80]
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Debug:[clientbase] ci_cork(+203): [0x7f45046c5010] [18] [18]
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Database:[db] db_con_get(+330): [0x55b06a147ed0] connection from pool
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Database:[db] db_stmt_prepare(+493): [0x55b06a147ed0] [SELECT name,seq FROM %smailboxes WHERE mailbox_idnr=?]
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Database:[db] db_stmt_set_u64(+513): [0x55b06a189500] 1:[1]
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Debug:[MailboxState] db_getmailbox_seq(+1103): id: [1] name: [INBOX] seq [1]
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Database:[db] db_con_close(+358): [0x55b06a147ed0] connection to pool
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Debug:[imap] dbmail_imap_session_mailbox_status(+1636): seq: [1] -> [1]
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Debug:[clientbase] ci_uncork(+211): [0x7f45046c5010] [18] [18], [30]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Info:[debug] configure_debug(+78): [LMTP] syslog [31 -> 511] stderr [31 -> 511]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1019): max_db_connections [10]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[config] config_get_timeout(+521): timeout [300] seconds
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[config] config_get_timeout(+531): login_timeout [60] seconds
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1028): no value for SOCKET in config file
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1030): socket []
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1051): binding to PORT [24]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1080): binding to IP [0.0.0.0]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1086): no value for BACKLOG in config file. Using default value [128]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1090): LMTP backlog [128]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1097): not resolving client IP
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1104): no value for LMTP_BEFORE_SMTP  in config file
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1106): Disabling LMTP-before-SMTP
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1113): Enabling LMTP Authentication logging
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1122): effective user shall be [dbmail]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1132): effective group shall be [dbmail]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[config] config_get_timeout(+521): timeout [300] seconds
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[config] config_get_timeout(+531): login_timeout [60] seconds
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Notice:[server] server_run(+771): starting main service loop for [LMTP]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[db] db_connect(+212): dburi: mysql://dbmail:test@10.1.10.3:3306/dbmail
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_connect(+260): db at dburi: [mysql://dbmail:test@10.1.10.3:3306/dbmail]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Info:[db] db_connect(+270): database connection pool created with maximum connections of [10]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_connect(+274): run a database connection reaper thread every [60] seconds
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_connect(+278): database connection pool started with [5] connections, max [10]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_close(+358): [0x5567be52ced0] connection to pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_get(+330): [0x5567be52ced0] connection from pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_query(+430): [0x5567be52ced0] [SELECT 1=1 FROM dbmail_users LIMIT 1 OFFSET 0]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] log_query_time(+374): last query took [0] seconds
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_clear(+365): [0x5567be52ced0] connection cleared
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_clear(+365): [0x5567be52ced0] connection cleared
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_clear(+365): [0x5567be52ced0] connection cleared
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_query(+430): [0x5567be52ced0] [SELECT 1=1 FROM dbmail_mimeparts LIMIT 1 OFFSET 0]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] log_query_time(+374): last query took [0] seconds
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_clear(+365): [0x5567be52ced0] connection cleared
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_query(+430): [0x5567be52ced0] [SELECT 1=1 FROM dbmail_header LIMIT 1 OFFSET 0]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] log_query_time(+374): last query took [0] seconds
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_clear(+365): [0x5567be52ced0] connection cleared
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_get(+330): [0x5567be52d980] connection from pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_prepare(+493): [0x5567be52d980] [SELECT 1=1 FROM %supgrade_steps WHERE from_version = ? AND to_version = ?]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_set_int(+507): [0x5567be5599c0] 1:[0]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_set_int(+507): [0x5567be5599c0] 2:[32001]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_clear(+365): [0x5567be52d980] connection cleared
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_close(+358): [0x5567be52d980] connection to pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_get(+330): [0x5567be52d980] connection from pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_prepare(+493): [0x5567be52d980] [SELECT 1=1 FROM %supgrade_steps WHERE from_version = ? AND to_version = ?]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_set_int(+507): [0x5567be559d00] 1:[32001]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_set_int(+507): [0x5567be559d00] 2:[32002]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_clear(+365): [0x5567be52d980] connection cleared
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_close(+358): [0x5567be52d980] connection to pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_get(+330): [0x5567be52d980] connection from pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_prepare(+493): [0x5567be52d980] [SELECT 1=1 FROM %supgrade_steps WHERE from_version = ? AND to_version = ?]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_set_int(+507): [0x5567be559be0] 1:[32001]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_set_int(+507): [0x5567be559be0] 2:[32003]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_clear(+365): [0x5567be52d980] connection cleared
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_close(+358): [0x5567be52d980] connection to pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_get(+330): [0x5567be52d980] connection from pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_prepare(+493): [0x5567be52d980] [SELECT 1=1 FROM %supgrade_steps WHERE from_version = ? AND to_version = ?]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_set_int(+507): [0x5567be559d00] 1:[32001]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_set_int(+507): [0x5567be559d00] 2:[32004]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_clear(+365): [0x5567be52d980] connection cleared
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_close(+358): [0x5567be52d980] connection to pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_get(+330): [0x5567be52d980] connection from pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_prepare(+493): [0x5567be52d980] [SELECT 1=1 FROM %supgrade_steps WHERE from_version = ? AND to_version = ?]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_set_int(+507): [0x5567be559be0] 1:[32001]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_set_int(+507): [0x5567be559be0] 2:[32005]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_clear(+365): [0x5567be52d980] connection cleared
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_close(+358): [0x5567be52d980] connection to pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_get(+330): [0x5567be52d980] connection from pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_prepare(+493): [0x5567be52d980] [SELECT 1=1 FROM %supgrade_steps WHERE from_version = ? AND to_version = ?]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_set_int(+507): [0x5567be559d00] 1:[32001]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_stmt_set_int(+507): [0x5567be559d00] 2:[32006]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_clear(+365): [0x5567be52d980] connection cleared
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_close(+358): [0x5567be52d980] connection to pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Database:[db] db_con_close(+358): [0x5567be52ced0] connection to pool
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[db] db_check_version(+1092): Schema check successful
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] auth_load_driver(+47): no value for library_directory, using default [/usr/local/lib/dbmail]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] auth_load_driver(+72): looking for auth_ldap as /tmp/dbmail/src/modules/.libs/libauth_ldap.so
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] auth_load_driver(+76): cannot load /tmp/dbmail/src/modules/.libs/libauth_ldap.so: cannot open shared object file: No such file or directory
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] auth_load_driver(+72): looking for auth_ldap as /usr/local/lib/dbmail/libauth_ldap.so
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+58): key "BIND_DN" section "LDAP" var _ldap_cfg.bind_dn value [uid=dbmail,ou=Services,dc=corp,dc=test,dc=domain]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+59): key "BIND_PW" section "LDAP" var _ldap_cfg.bind_pw value [ELhKf3wsgq6b41X4dhNPwgnk]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+60): key "BASE_DN" section "LDAP" var _ldap_cfg.base_dn value [dc=corp,dc=test,dc=domain]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+62): key "URI" section "LDAP" var _ldap_cfg.uri value [ldap://10.1.10.5:389]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+63): key "VERSION" section "LDAP" var _ldap_cfg.version value [3]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+65): key "USER_OBJECTCLASS" section "LDAP" var _ldap_cfg.user_objectclass value [top,inetOrgPerson,posixAccount]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+66): key "FORW_OBJECTCLASS" section "LDAP" var _ldap_cfg.forw_objectclass value [top,dbmailForwardingAddress]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+67): key "CN_STRING" section "LDAP" var _ldap_cfg.cn_string value [uid]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+68): key "FIELD_UID" section "LDAP" var _ldap_cfg.field_uid value [uid]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+69): key "FIELD_CID" section "LDAP" var _ldap_cfg.field_cid value [gidNumber]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+70): key "MIN_CID" section "LDAP" var _ldap_cfg.min_cid value [10000]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+71): key "MAX_CID" section "LDAP" var _ldap_cfg.max_cid value [15000]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+72): key "FIELD_NID" section "LDAP" var _ldap_cfg.field_nid value [uidNumber]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+73): key "MIN_NID" section "LDAP" var _ldap_cfg.min_nid value [10000]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+74): key "MAX_NID" section "LDAP" var _ldap_cfg.max_nid value [15000]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+75): key "FIELD_MAIL" section "LDAP" var _ldap_cfg.field_mail value [mail]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+76): key "FIELD_QUOTA" section "LDAP" var _ldap_cfg.field_maxmail value [mailQuota]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+77): key "FIELD_PASSWD" section "LDAP" var _ldap_cfg.field_passwd value [userPassword]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+78): key "FIELD_FWDTARGET" section "LDAP" var _ldap_cfg.field_fwdtarget value [mail]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+79): key "QUERY_STRING" section "LDAP" var _ldap_cfg.query_string value [(mail=%s)]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+80): key "SCOPE" section "LDAP" var _ldap_cfg.scope value [SubTree]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+81): key "REFERRALS" section "LDAP" var _ldap_cfg.referrals value [yes]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+82): key "QUERY_TIMEOUT" section "LDAP" var _ldap_cfg.query_timeout value [300]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] __auth_get_config(+108): integer ldap scope is [2]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] authldap_connect(+224): connecting to ldap server on [ldap://10.1.10.5:389] version [3]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] auth_ldap_bind(+194): binddn [uid=dbmail,ou=Services,dc=corp,dc=test,dc=domain]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[auth] ldap_con_get(+132): connection [0x5567be564210]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Notice:[server] server_run(+785): starting main service loop for [LMTP]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Info:[server] server_set_sighandler(+697): signal handler placed
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] dm_bind_and_listen(+404): creating plain socket [14] on [0.0.0.0:24]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_run(+830): Adding event for plain socket [14] [1/1]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_run(+856): dispatching event loop...

The entries that grabs my attention are these where the LDAP lookup seems logical but then quesries mail=10001

Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Info:[dsn] dsnuser_resolve(+566): checking if [user@test.domain] is a valid username, alias, or catchall.
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [0]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [1]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] ldap_con_get(+132): connection [0x564f0cbb4210]
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 02:42:13 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [1]

It loops this query until checks [20] and LMTP appears to restart....

Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Error:[auth] auth_check_user_ext(+887): too many checks. Possible loop detected.
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Error:[auth] auth_check_user_ext(+887): too many checks. Possible loop detected.
free(): invalid pointer
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Debug:[imap] imap_cb_time(+370): [0x55b06a184d80]
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Debug:[clientbase] ci_cork(+203): [0x7f45046c5010] [18] [18]
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Database:[db] db_con_get(+330): [0x55b06a147ed0] connection from pool
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Database:[db] db_stmt_prepare(+493): [0x55b06a147ed0] [SELECT name,seq FROM %smailboxes WHERE mailbox_idnr=?]
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Database:[db] db_stmt_set_u64(+513): [0x55b06a189500] 1:[1]
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Debug:[MailboxState] db_getmailbox_seq(+1103): id: [1] name: [INBOX] seq [1]
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Database:[db] db_con_close(+358): [0x55b06a147ed0] connection to pool
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Debug:[imap] dbmail_imap_session_mailbox_status(+1636): seq: [1] -> [1]
Feb 14 02:42:15 mail01 dbmail-imapd[20868]: [0x55b06a0e8e00] Debug:[clientbase] ci_uncork(+211): [0x7f45046c5010] [18] [18], [30]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Info:[debug] configure_debug(+78): [LMTP] syslog [31 -> 511] stderr [31 -> 511]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1019): max_db_connections [10]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[config] config_get_timeout(+521): timeout [300] seconds
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[config] config_get_timeout(+531): login_timeout [60] seconds
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1028): no value for SOCKET in config file
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1030): socket []
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1051): binding to PORT [24]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1080): binding to IP [0.0.0.0]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1086): no value for BACKLOG in config file. Using default value [128]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1090): LMTP backlog [128]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1097): not resolving client IP
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1104): no value for LMTP_BEFORE_SMTP  in config file
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1106): Disabling LMTP-before-SMTP
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1113): Enabling LMTP Authentication logging
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1122): effective user shall be [dbmail]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[server] server_config_load(+1132): effective group shall be [dbmail]
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[config] config_get_timeout(+521): timeout [300] seconds
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Debug:[config] config_get_timeout(+531): login_timeout [60] seconds
Feb 14 02:42:17 mail01 dbmail-lmtpd[20892]: [0x5567be4cde00] Notice:[server] server_run(+771): starting main service loop for [LMTP]

Also field_mail and field_fwdtarget are both set to mail.

I have no use for the mail forwarding since one user will have one email and forwarding is moot. I changed it out of concern that not having a valid value may cause the condition I am seeing. If it can be left at default without concern then I will revert that change.

Also you need to change your password!

This is being tested in an air-gapped virtual environment to prove out a concept to build a live server with security in mind. The basic passwords for database and the random password for LDAP are not on any live systems.

@alan-hicks
Copy link
Member

There are a few issues, there appears to be a loop, possibly due to the duplicate forward, perhaps comment that out. There is also an invalid free that I'll need to fix. I'll look at the code when I'm fresh tomorrow.

I suspect commenting out field_fwdtarget might fix this issue.

Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [mail]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] __auth_get_every_match(+432): got value [user@test.domain]
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Error:[auth] auth_check_user_ext(+887): too many checks. Possible loop detected.
Feb 14 02:42:14 mail01 dbmail-lmtpd[20866]: [0x564f0cb1de00] Error:[auth] auth_check_user_ext(+887): too many checks. Possible loop detected.
free(): invalid pointer

@scienssciencia
Copy link
Author

I attempted to send an email after commenting the field_fwdtarget entry as advised. A similar outcome ocurred. I will omit the postfix log since that cog appears to be working as intended. The only relevant entry is:

Feb 14 19:07:54 mail01 postfix/lmtp[1718]: F382C7A06B0: to=<user@test.domain>, relay=127.0.0.1[127.0.0.1]:24, delay=0.04, delays=0.03/0/0/0.01, dsn=4.4.2, status=deferred (lost connection with 127.0.0.1[127.0.0.1] while sending RCPT TO)

the DBMail log appears to be no longer looping so that is a benefit. The entries that give me pause are as follows:

Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Info:[dsn] dsnuser_resolve(+566): checking if [user@test.domain] is a valid username, alias, or catchall.
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [0]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] ldap_con_get(+132): connection [0x563bcabf9620]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] ldap_con_get(+132): connection [0x563bcabf9620]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [1]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] ldap_con_get(+132): connection [0x563bcabf9620]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] ldap_con_get(+132): connection [0x563bcabf9620]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids

The process checks for the uid from LDAP using the email as a refrence in the specified DN. This makes sense and is expected.

The uid value is correctly ascertained, however the LMTP process then does another LDAP query using mail=10001 which will obviously come up with no entry. At this time the process appears to restart. I am making this observation and deduction based on the output inferring it is loading configuration by setting the debug level:

Feb 14 19:36:23 mail01 dbmail-lmtpd[2132]: [0x55a309d41e00] Info:[debug] configure_debug(+78): [LMTP] syslog [31 -> 511] stderr [31 -> 511]

Full log output for the LMTP process below:

Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Info:[server] _sock_cb(+636): connection accepted
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Notice:[clientbase] client_init(+180): incoming connection on [127.0.0.1:24] from [127.0.0.1:33176]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[misc] create_unique_id(+178): created: c117db57785f8732fa7d2762f1abe061
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_cork(+203): [0x7f521f7ca010] [16] [16]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Database:[db] db_con_get(+330): [0x563bcabc1e90] connection from pool
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Database:[db] db_con_close(+358): [0x563bcabc1e90] connection to pool
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_write(+382): [0x7f521f7ca010] S > [17/17:220 mail01 LMTP
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_uncork(+211): [0x7f521f7ca010] [16] [16], [60]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[lmtp] lmtp_cb_write(+130): [0x563bcabfe030] state: [0]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[lmtp] lmtp_handle_input(+122): [0x563bcabfe030] done
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientsession] socket_write_cb(+293): reset timeout [60]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_read_cb(+434): [0x7f521f7ca010] [46]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_read_cb(+434): [0x7f521f7ca010] [-1]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Info:[clientbase] ci_readln(+525): [0x7f521f7ca010] C < [46:LHLO mail01.corp.test.domain
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[lmtp] lmtp_tokenizer(+280): [0x563bcabfe030] cmd [0], state [1] [LHLO]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_cork(+203): [0x7f521f7ca010] [16] [16]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_write(+382): [0x7f521f7ca010] S > [63/63:250-mail01
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_uncork(+211): [0x7f521f7ca010] [16] [16], [300]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[lmtp] lmtp_handle_input(+122): [0x563bcabfe030] done
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[lmtp] lmtp_cb_write(+130): [0x563bcabfe030] state: [2]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[lmtp] lmtp_handle_input(+122): [0x563bcabfe030] done
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientsession] socket_write_cb(+299): reset timeout [300]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_read_cb(+434): [0x7f521f7ca010] [70]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_read_cb(+434): [0x7f521f7ca010] [-1]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Info:[clientbase] ci_readln(+525): [0x7f521f7ca010] C < [33:MAIL FROM:<user@test.domain>
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[lmtp] lmtp_tokenizer(+280): [0x563bcabfe030] cmd [4], state [1] [MAIL]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_cork(+203): [0x7f521f7ca010] [16] [16]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Info:[misc] find_bounded(+367): Found [user@test.domain] of length [19] between '<' and '>' so next skip [25]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_write(+382): [0x7f521f7ca010] S > [37/37:250 Sender <user@test.domain> OK
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_uncork(+211): [0x7f521f7ca010] [16] [16], [300]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Info:[clientbase] ci_readln(+525): [0x7f521f7ca010] C < [31:RCPT TO:<user@test.domain>
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[lmtp] lmtp_tokenizer(+280): [0x563bcabfe030] cmd [9], state [1] [RCPT]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[clientbase] ci_cork(+203): [0x7f521f7ca010] [16] [16]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Info:[misc] find_bounded(+367): Found [user@test.domain] of length [19] between '<' and '>' so next skip [23]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[dsn] dsnuser_init(+194): dsnuser initialized
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Info:[dsn] dsnuser_resolve(+566): checking if [user@test.domain] is a valid username, alias, or catchall.
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [0]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] ldap_con_get(+132): connection [0x563bcabf9620]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] ldap_con_get(+132): connection [0x563bcabf9620]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [1]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] ldap_con_get(+132): connection [0x563bcabf9620]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] ldap_con_get(+132): connection [0x563bcabf9620]
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Info:[debug] configure_debug(+78): [LMTP] syslog [31 -> 511] stderr [31 -> 511]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_config_load(+1019): max_db_connections [10]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[config] config_get_timeout(+521): timeout [300] seconds
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[config] config_get_timeout(+531): login_timeout [60] seconds
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_config_load(+1028): no value for SOCKET in config file
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_config_load(+1030): socket []
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_config_load(+1051): binding to PORT [24]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_config_load(+1080): binding to IP [0.0.0.0]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_config_load(+1086): no value for BACKLOG in config file. Using default value [128]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_config_load(+1090): LMTP backlog [128]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_config_load(+1097): not resolving client IP
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_config_load(+1104): no value for LMTP_BEFORE_SMTP  in config file
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_config_load(+1106): Disabling LMTP-before-SMTP
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_config_load(+1113): Enabling LMTP Authentication logging
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_config_load(+1122): effective user shall be [dbmail]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_config_load(+1132): effective group shall be [dbmail]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[config] config_get_timeout(+521): timeout [300] seconds
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[config] config_get_timeout(+531): login_timeout [60] seconds
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Notice:[server] server_run(+771): starting main service loop for [LMTP]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[db] db_connect(+212): dburi: mysql://dbmail:test@10.1.10.3:3306/dbmail
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_connect(+260): db at dburi: [mysql://dbmail:test@10.1.10.3:3306/dbmail]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Info:[db] db_connect(+270): database connection pool created with maximum connections of [10]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_connect(+274): run a database connection reaper thread every [60] seconds
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_connect(+278): database connection pool started with [5] connections, max [10]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_close(+358): [0x55c2760c9e90] connection to pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_get(+330): [0x55c2760c9e90] connection from pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_query(+430): [0x55c2760c9e90] [SELECT 1=1 FROM dbmail_users LIMIT 1 OFFSET 0]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] log_query_time(+374): last query took [0] seconds
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_clear(+365): [0x55c2760c9e90] connection cleared
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_clear(+365): [0x55c2760c9e90] connection cleared
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_clear(+365): [0x55c2760c9e90] connection cleared
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_query(+430): [0x55c2760c9e90] [SELECT 1=1 FROM dbmail_mimeparts LIMIT 1 OFFSET 0]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] log_query_time(+374): last query took [0] seconds
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_clear(+365): [0x55c2760c9e90] connection cleared
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_query(+430): [0x55c2760c9e90] [SELECT 1=1 FROM dbmail_header LIMIT 1 OFFSET 0]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] log_query_time(+374): last query took [0] seconds
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_clear(+365): [0x55c2760c9e90] connection cleared
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_get(+330): [0x55c2760ca940] connection from pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_prepare(+493): [0x55c2760ca940] [SELECT 1=1 FROM %supgrade_steps WHERE from_version = ? AND to_version = ?]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_set_int(+507): [0x55c2760f6de0] 1:[0]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_set_int(+507): [0x55c2760f6de0] 2:[32001]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_clear(+365): [0x55c2760ca940] connection cleared
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_close(+358): [0x55c2760ca940] connection to pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_get(+330): [0x55c2760ca940] connection from pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_prepare(+493): [0x55c2760ca940] [SELECT 1=1 FROM %supgrade_steps WHERE from_version = ? AND to_version = ?]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_set_int(+507): [0x55c2760f9750] 1:[32001]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_set_int(+507): [0x55c2760f9750] 2:[32002]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_clear(+365): [0x55c2760ca940] connection cleared
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_close(+358): [0x55c2760ca940] connection to pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_get(+330): [0x55c2760ca940] connection from pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_prepare(+493): [0x55c2760ca940] [SELECT 1=1 FROM %supgrade_steps WHERE from_version = ? AND to_version = ?]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_set_int(+507): [0x55c2760f8f40] 1:[32001]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_set_int(+507): [0x55c2760f8f40] 2:[32003]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_clear(+365): [0x55c2760ca940] connection cleared
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_close(+358): [0x55c2760ca940] connection to pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_get(+330): [0x55c2760ca940] connection from pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_prepare(+493): [0x55c2760ca940] [SELECT 1=1 FROM %supgrade_steps WHERE from_version = ? AND to_version = ?]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_set_int(+507): [0x55c2760f9750] 1:[32001]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_set_int(+507): [0x55c2760f9750] 2:[32004]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_clear(+365): [0x55c2760ca940] connection cleared
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_close(+358): [0x55c2760ca940] connection to pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_get(+330): [0x55c2760ca940] connection from pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_prepare(+493): [0x55c2760ca940] [SELECT 1=1 FROM %supgrade_steps WHERE from_version = ? AND to_version = ?]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_set_int(+507): [0x55c2760f8f40] 1:[32001]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_set_int(+507): [0x55c2760f8f40] 2:[32005]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_clear(+365): [0x55c2760ca940] connection cleared
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_close(+358): [0x55c2760ca940] connection to pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_get(+330): [0x55c2760ca940] connection from pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_prepare(+493): [0x55c2760ca940] [SELECT 1=1 FROM %supgrade_steps WHERE from_version = ? AND to_version = ?]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_set_int(+507): [0x55c2760f9750] 1:[32001]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_stmt_set_int(+507): [0x55c2760f9750] 2:[32006]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_clear(+365): [0x55c2760ca940] connection cleared
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_close(+358): [0x55c2760ca940] connection to pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Database:[db] db_con_close(+358): [0x55c2760c9e90] connection to pool
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[db] db_check_version(+1092): Schema check successful
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] auth_load_driver(+47): no value for library_directory, using default [/usr/local/lib/dbmail]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] auth_load_driver(+72): looking for auth_ldap as /tmp/dbmail/src/modules/.libs/libauth_ldap.so
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] auth_load_driver(+76): cannot load /tmp/dbmail/src/modules/.libs/libauth_ldap.so: cannot open shared object file: No such file or directory
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] auth_load_driver(+72): looking for auth_ldap as /usr/local/lib/dbmail/libauth_ldap.so
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+58): key "BIND_DN" section "LDAP" var _ldap_cfg.bind_dn value [uid=dbmail,ou=Services,dc=corp,dc=test,dc=domain]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+59): key "BIND_PW" section "LDAP" var _ldap_cfg.bind_pw value [ELhKf3wsgq6b41X4dhNPwgnk]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+60): key "BASE_DN" section "LDAP" var _ldap_cfg.base_dn value [dc=corp,dc=test,dc=domain]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+62): key "URI" section "LDAP" var _ldap_cfg.uri value [ldap://10.1.10.5:389]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+63): key "VERSION" section "LDAP" var _ldap_cfg.version value [3]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+65): key "USER_OBJECTCLASS" section "LDAP" var _ldap_cfg.user_objectclass value [top,inetOrgPerson,posixAccount]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+66): key "FORW_OBJECTCLASS" section "LDAP" var _ldap_cfg.forw_objectclass value [top,dbmailForwardingAddress]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+67): key "CN_STRING" section "LDAP" var _ldap_cfg.cn_string value [uid]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+68): key "FIELD_UID" section "LDAP" var _ldap_cfg.field_uid value [uid]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+69): key "FIELD_CID" section "LDAP" var _ldap_cfg.field_cid value [gidNumber]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+70): key "MIN_CID" section "LDAP" var _ldap_cfg.min_cid value [10000]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+71): key "MAX_CID" section "LDAP" var _ldap_cfg.max_cid value [15000]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+72): key "FIELD_NID" section "LDAP" var _ldap_cfg.field_nid value [uidNumber]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+73): key "MIN_NID" section "LDAP" var _ldap_cfg.min_nid value [10000]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+74): key "MAX_NID" section "LDAP" var _ldap_cfg.max_nid value [15000]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+75): key "FIELD_MAIL" section "LDAP" var _ldap_cfg.field_mail value [mail]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+76): key "FIELD_QUOTA" section "LDAP" var _ldap_cfg.field_maxmail value [mailQuota]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+77): key "FIELD_PASSWD" section "LDAP" var _ldap_cfg.field_passwd value [userPassword]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+79): key "QUERY_STRING" section "LDAP" var _ldap_cfg.query_string value [(mail=%s)]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+80): key "SCOPE" section "LDAP" var _ldap_cfg.scope value [SubTree]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+81): key "REFERRALS" section "LDAP" var _ldap_cfg.referrals value [yes]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+82): key "QUERY_TIMEOUT" section "LDAP" var _ldap_cfg.query_timeout value [300]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] __auth_get_config(+108): integer ldap scope is [2]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] authldap_connect(+224): connecting to ldap server on [ldap://10.1.10.5:389] version [3]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] auth_ldap_bind(+194): binddn [uid=dbmail,ou=Services,dc=corp,dc=test,dc=domain]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[auth] ldap_con_get(+132): connection [0x55c276101620]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Notice:[server] server_run(+785): starting main service loop for [LMTP]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Info:[server] server_set_sighandler(+697): signal handler placed
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] dm_bind_and_listen(+404): creating plain socket [14] on [0.0.0.0:24]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_run(+830): Adding event for plain socket [14] [1/1]
Feb 14 19:07:57 mail01 dbmail-lmtpd[1741]: [0x55c27606ae00] Debug:[server] server_run(+856): dispatching event loop...

@scienssciencia
Copy link
Author

For further context, even using a telnet client to manually pipe an email causes this issue.

root@wkstn01:~$ telnet 10.1.10.3 24
Trying 10.1.10.3...
Connected to 10.1.10.3.
Escape character is '^]'.
220 mail01 LMTP
LHLO
250-mail01
250-PIPELINING
250-ENHANCEDSTATUSCODES
250 SIZE
RCPT TO:<user@test.domain>
Connection closed by foreign host.
Feb 14 20:22:19 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Info:[server] _sock_cb(+636): connection accepted
Feb 14 20:22:19 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Notice:[clientbase] client_init(+180): incoming connection on [10.1.10.3:24] from [10.1.10.1:48372]
Feb 14 20:22:19 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[misc] create_unique_id(+178): created: 01c19f06c5456e839eac21a379e3dd3a
Feb 14 20:22:19 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[clientbase] ci_cork(+203): [0x7f540435a010] [16] [16]
Feb 14 20:22:19 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Database:[db] db_con_get(+330): [0x5603747eee90] connection from pool
Feb 14 20:22:19 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Database:[db] db_con_close(+358): [0x5603747eee90] connection to pool
Feb 14 20:22:19 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[clientbase] ci_write(+382): [0x7f540435a010] S > [17/17:220 mail01 LMTP
]
Feb 14 20:22:19 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[clientbase] ci_uncork(+211): [0x7f540435a010] [16] [16], [60]
Feb 14 20:22:19 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[lmtp] lmtp_cb_write(+130): [0x56037482b030] state: [0]
Feb 14 20:22:19 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[lmtp] lmtp_handle_input(+122): [0x56037482b030] done
Feb 14 20:22:19 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[clientsession] socket_write_cb(+293): reset timeout [60]
Feb 14 20:22:23 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[clientbase] ci_read_cb(+434): [0x7f540435a010] [6]
Feb 14 20:22:23 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[clientbase] ci_read_cb(+434): [0x7f540435a010] [-1]
Feb 14 20:22:23 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Info:[clientbase] ci_readln(+525): [0x7f540435a010] C < [6:LHLO
]
Feb 14 20:22:23 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[lmtp] lmtp_tokenizer(+280): [0x56037482b030] cmd [0], state [1] [LHLO]
Feb 14 20:22:23 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[clientbase] ci_cork(+203): [0x7f540435a010] [16] [16]
Feb 14 20:22:23 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[clientbase] ci_write(+382): [0x7f540435a010] S > [63/63:250-mail01
250-PIPELINING
250-ENHANCEDSTATUSCODES
250 SIZE
]
Feb 14 20:22:23 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[clientbase] ci_uncork(+211): [0x7f540435a010] [16] [16], [300]
Feb 14 20:22:23 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[lmtp] lmtp_handle_input(+122): [0x56037482b030] done
Feb 14 20:22:23 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[lmtp] lmtp_cb_write(+130): [0x56037482b030] state: [2]
Feb 14 20:22:23 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[lmtp] lmtp_handle_input(+122): [0x56037482b030] done
Feb 14 20:22:23 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[clientsession] socket_write_cb(+299): reset timeout [300]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[clientbase] ci_read_cb(+434): [0x7f540435a010] [31]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[clientbase] ci_read_cb(+434): [0x7f540435a010] [-1]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Info:[clientbase] ci_readln(+525): [0x7f540435a010] C < [31:RCPT TO:<user@test.domain>
]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[lmtp] lmtp_tokenizer(+280): [0x56037482b030] cmd [9], state [1] [RCPT]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[clientbase] ci_cork(+203): [0x7f540435a010] [16] [16]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Info:[misc] find_bounded(+367): Found [user@test.domain] of length [19] between '<' and '>' so next skip [23]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[dsn] dsnuser_init(+194): dsnuser initialized
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Info:[dsn] dsnuser_resolve(+566): checking if [user@test.domain] is a valid username, alias, or catchall.
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] auth_check_user_ext(+891): checking user [user@test.domain] in alias table
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=user@test.domain)], checks [0]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] ldap_con_get(+132): connection [0x560374826620]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] authldap_search(+282):  [(mail=user@test.domain)]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] ldap_con_get(+132): connection [0x560374826620]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] __auth_get_every_match(+426): scan results for DN: [cn=user,ou=Users,dc=corp,dc=test,dc=domain]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] __auth_get_every_match(+428): ldap_get_values [uidNumber]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] __auth_get_every_match(+432): got value [10001]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] auth_check_user_ext(+961): into checking loop
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] auth_check_user_ext(+891): checking user [10001] in alias table
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] auth_check_user_ext(+932): searching with query [(mail=10001)], checks [1]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] ldap_con_get(+132): connection [0x560374826620]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] authldap_search(+282):  [(mail=10001)]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] ldap_con_get(+132): connection [0x560374826620]
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] __auth_get_every_match(+410): nothing found
Feb 14 20:22:25 mail01 dbmail-lmtpd[2767]: [0x56037478fe00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids
free(): invalid pointer
Feb 14 20:22:28 mail01 dbmail-lmtpd[2777]: [0x5650a5229e00] Info:[debug] configure_debug(+78): [LMTP] syslog [31 -> 511] stderr [31 -> 511]

@alan-hicks
Copy link
Member

Subsequenst searches are red herrings, as userids is 10001 and that is where the email will be delivered

Feb 14 19:07:54 mail01 dbmail-lmtpd[1720]: [0x563bcab62e00] Debug:[auth] auth_check_user_ext(+945): adding [10001] to userids

Discovering what caused dbmail-lmtpd[1720] to stop and another to start dbmail-lmtpd[1741] may be key here.

I'm using the following python test script. The need for the except block is smtplib.SMTPDataError is raised when it gets a 215 OK message.

import uuid
import smtplib
import datetime
import time
from email import utils
nowdt = datetime.datetime.now()
nowtuple = nowdt.timetuple()
nowtimestamp = time.mktime(nowtuple)

host = "::1"
port = 1024
domain = 'test.domain'
user_id = 'user'
from_name = "Test user"
from_addr = 'user@test.domain'
to_addr = 'user@test.domain'

msg = """Return-Path: {from_name} <{from_addr}>
Received: from {user_id} by {domain}
with local (Exim 4.96 (FreeBSD)) (envelope-from <{from_addr}>)
id {id} for {to_addr}; {date}
From: {from_name} <{from_addr}>
To: {to_addr}
Subject: =?UTF-8?B?8J+ZjCBIZWxsbyB0ZXN0IHdpdGggdXRmOCDwn5GJ?=
X-Alan-Id: {id}
Message-Id: <{id}@{domain}>
Date: {date}

Test line 1
Test line 2
Test line 3

""".format(
id=uuid.uuid4(),
date=utils.formatdate(nowtimestamp),
from_name=from_name,
from_addr=from_addr,
to_addr=to_addr,
domain=domain,
user_id=user_id,
)

#print(msg)
lmtp = smtplib.LMTP(host, port)

try:
lmtp.sendmail(from_addr, to_addr, msg)
except smtplib.SMTPDataError:
pass

@alan-hicks
Copy link
Member

I've been looking at the code starting at dsnuser_resolve(529), the delivery tries to identify the user.

As delivery->address is an email address it checks if [user@test.domain] is a valid username, alias, or catchall dsnuser_resolve(+566).

It then checks to see if there's an alias address_has_alias() and this calls auth_check_user_ext().

As it successfully found an alias it adds the user it to userids and returns 1
auth_check_user_ext(+945): adding [10001] to userids

But this does not show up in trace address_has_alias(+255) "user [%s] found total of [%d] aliases"

Is there a stack trace or perhaps you could debug?

@alan-hicks
Copy link
Member

Perhaps you might be able to use the ubunto Dockerfile from https://github.com/dbmail/dbmail/tree/main/docker the image is here https://hub.docker.com/r/alanhicks/dbmail
Although I can see you have an error, dbmail-lmtpd is running successfully here, I'm unable to reproduce your error and can find nothing that might cause it in the code.

@scienssciencia
Copy link
Author

I am planning a Kubernetes deployment so I may move to DBMail at that time.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants