Client is always localhost

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
12 messages Options
Reply | Threaded
Open this post in threaded view
|

Client is always localhost

chaouche yacine
o/

I was doing some log processing today for a supposedly sent mail I didn't recieve. It turns out that while I was playing with the log file I suddenly realized that every connection is made from localhost...





root@messagerie[10.10.10.19] ~/SCRIPTS/MAIL # zgrep client= /var/log/mail.*  | grep -v localhost
root@messagerie[10.10.10.19] ~/SCRIPTS/MAIL #

that command was supposed to spit all the client connections that weren't made by localhost, and it had 0 results...






On another machine (with an old setup) this  is definitely not the case (had 923 unique clients/IPs) :


root@messagerie-secours[10.10.10.20] /var/log # zgrep -o 'client=.*]' /var/log/mail.* | grep -v localhost | cut -f 2 -d : | sort | uniq -c | sort -n
      1 client=118-163-37-8.HINET-IP.hinet.net[118.163.37.8]
      1 client=131.red-80-35-249.staticip.rima-tde.net[80.35.249.131]
      1 client=179-191-149-46.dynamic.starweb.net.br[179.191.149.46]
      1 client=a95-93-181-252.cpe.netcabo.pt[95.93.181.252]
   [...snip...]

   1713 client=mta-gw11.infomaniak.ch[84.16.68.70]
   1715 client=mta-gw16.infomaniak.ch[84.16.68.77]
   1943 client=messagerie.algerian-radio.dz[10.10.10.19]
   4499 client=wsus.eprs.dz[10.10.10.1]
root@messagerie-secours[10.10.10.20] /var/log #




This is a little embarassing since I can not know if any other server has attempted to connect to my posftix or not. Any idea on what could be wrong ?


Config follows :


postfinger - postfix configuration on Thu Mar  2 14:16:09 CET 2017
version: 1.30 Warning: postfinger output may show private configuration information,
such as ip addresses and/or domain names which you do not want to show
to the public.  If this is the case it is your responsibility to modify
the output to hide this private information.  [Remove this warning with
the --nowarn option.] --System Parameters--
mail_version = 2.11.3
hostname = messagerie
uname = Linux messagerie 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u2 (2016-01-02) x86_64 GNU/Linux --Packaging information--
looks like this postfix comes from deb package: postfix-2.11.3-1 --main.cf non-default parameters--
alias_maps = hash:/etc/aliases
append_dot_mydomain = no
biff = no
content_filter = amavis:[127.0.0.1]:10024
enable_original_recipient = no
inet_protocols = ipv4
mailbox_command = procmail -a "$EXTENSION"
mailbox_size_limit = 0
maildrop_destination_recipient_limit = 1
message_size_limit = 20971520
mydestination = messagerie.domain.tld, messagerie, localhost.localdomain, localhost
myhostname = messagerie.domain.tld
mynetworks = 127.0.0.0/8 [::ffff:127.0.0.0]/104 [::1]/128
myorigin = /etc/mailname
readme_directory = no
recipient_delimiter = +
smtpd_banner = $myhostname ESMTP $mail_name (Debian/GNU)
smtpd_client_message_rate_limit = 100
smtpd_relay_restrictions = permit_mynetworks, permit_sasl_authenticated, reject_unauth_destination
smtpd_sasl_auth_enable = yes
smtpd_sasl_authenticated_header = yes
smtpd_sender_restrictions = check_sender_access hash:/etc/postfix/maps/reject_senders
smtpd_tls_cert_file = /etc/ssl/private/LETSENCRYPT/nouveau_complet.cert
smtpd_tls_key_file = /etc/ssl/private/LETSENCRYPT/server.private_key
smtpd_tls_loglevel = 1
smtpd_tls_security_level = may
smtpd_tls_session_cache_database = btree:${data_directory}/smtpd_scache
smtpd_use_tls = yes
smtp_tls_security_level = may
smtp_tls_session_cache_database = btree:${data_directory}/smtp_scache
virtual_alias_maps = hash:/etc/postfix/maps/alias
virtual_gid_maps = static:1002
virtual_mailbox_base = /var/vmail/
virtual_mailbox_domains = backup.domain.tld, domain.tld
virtual_mailbox_maps = mysql:/etc/postfix/maps/mailboxes.cf
virtual_transport = lmtp:unix:private/dovecot-lmtp
virtual_uid_maps = static:113 --master.cf--
smtp    inet  n     -     n     -     -     smtpd -o content_filter=spamassassin
pickup   unix  n     -     -     60    1     pickup
cleanup  unix  n     -     -     -     0     cleanup
qmgr    unix  n     -     n     300    1     qmgr
tlsmgr   unix  -     -     -     1000?  1     tlsmgr
rewrite  unix  -     -     -     -     -     trivial-rewrite
bounce   unix  -     -     -     -     0     bounce
defer    unix  -     -     -     -     0     bounce
trace    unix  -     -     -     -     0     bounce
verify   unix  -     -     -     -     1     verify
flush    unix  n     -     -     1000?  0     flush
proxymap  unix  -     -     n     -     -     proxymap
proxywrite unix -     -     n     -     1     proxymap
smtp    unix  -     -     -     -     -     smtp
relay    unix  -     -     -     -     -     smtp
showq    unix  n     -     -     -     -     showq
error    unix  -     -     -     -     -     error
retry    unix  -     -     -     -     -     error
discard  unix  -     -     -     -     -     discard
local    unix  -     n     n     -     -     local
virtual  unix  -     n     n     -     -     virtual
lmtp    unix  -     -     -     -     -     lmtp
anvil    unix  -     -     -     -     1     anvil
scache   unix  -     -     -     -     1     scache # flags=DRhu user=vmail argv=/usr/bin/maildrop -d vmail ${extension} ${recipient} ${user} ${nexthop} ${sender}
maildrop  unix  -     n     n     -     -     pipe  # flags=DRhu user=vmail argv=/usr/bin/maildrop -V9 -d ${recipient} -w 80 flags=DRhu user=vmail argv=/var/vmail/maildropwrapper -V9 -d ${recipient}  # flags=DRhu user=vmail argv=/var/vmail/maildropwrapper -V9 -d vmail ${extension} ${recipient} ${user} ${nexthop} ${sender}
uucp    unix  -     n     n     -     -     pipe flags=Fqhu user=uucp argv=uux -r -n -z -a$sender - $nexthop!rmail ($recipient)
ifmail   unix  -     n     n     -     -     pipe flags=F user=ftn argv=/usr/lib/ifmail/ifmail -r $nexthop ($recipient)
bsmtp    unix  -     n     n     -     -     pipe flags=Fq. user=bsmtp argv=/usr/lib/bsmtp/bsmtp -t$nexthop -f$sender $recipient
scalemail-backend unix    -    n    n    -    2    pipe flags=R user=scalemail argv=/usr/lib/scalemail/bin/scalemail-store ${nexthop} ${user} ${extension}
mailman  unix  -     n     n     -     -     pipe flags=FR user=list argv=/usr/lib/mailman/bin/postfix-to-mailman.py ${nexthop} ${user}
amavis unix - - - - 2 smtp -o smtp_data_done_timeout=1200 -o smtp_send_xforward_command=yes
127.0.0.1:10025 inet n - - - - smtpd -o content_filter= -o local_recipient_maps= -o relay_recipient_maps= -o smtpd_restriction_classes= -o smtpd_client_restrictions= -o smtpd_helo_restrictions= #-o smtpd_sender_restrictions= -o smtpd_recipient_restrictions=permit_mynetworks,reject -o mynetworks=127.0.0.0/8 -o strict_rfc821_envelopes=yes -o receive_override_options=no_unknown_recipient_checks,no_header_body_checks # yassine 27/03/2016 # me donne un warning au démarrage # /usr/sbin/postconf: warning: /etc/postfix/master.cf: unused parameter: smtpd_bind_address=127.0.0.1 #-o smtpd_bind_address=127.0.0.1
spamassassin  unix  -  n    n    -  -  pipe user=spamd   argv=/usr/bin/spamc -f  -e /usr/sbin/sendmail -oi -f ${sender} ${recipient}  -- end of postfinger output --







-- Yassine
Reply | Threaded
Open this post in threaded view
|

Re: Client is always localhost

Viktor Dukhovni

> On Mar 2, 2017, at 9:04 AM, chaouche yacine <[hidden email]> wrote:
>
> I was doing some log processing today for a supposedly sent mail I didn't recieve. It turns out that while I was playing with the log file I suddenly realized that every connection is made from localhost...
>
> root@messagerie[10.10.10.19] ~/SCRIPTS/MAIL # zgrep client= /var/log/mail.*  | grep -v localhost

This would be a good time to look at the actual log entries and
determine whether (most likely) all the mail is originating locally,
or whether some proxy or other is making your system an open relay.

Just "grep -v localhost" is not terribly informative.

--
        Viktor.

Reply | Threaded
Open this post in threaded view
|

Re: Client is always localhost

chaouche yacine
Hello Viktor,

I did my best at making most sense of the lines in the log file and made assumptions on timestamps to collect these lines where there should be an email from [hidden email] to me ([hidden email]), although their SMTP client doesn't seem to appear here :




Mar  2 09:50:09 messagerie postfix/cleanup[26917]: B819A162007E: message-id=<[hidden email]>
Mar  2 09:50:09 messagerie postfix/smtpd[25491]: disconnect from localhost[127.0.0.1]
Mar  2 09:50:09 messagerie postfix/smtp[26927]: A06681620081: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.18, delays=0.06/0/0/0.12, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as B819A162007E)
Mar  2 09:50:48 messagerie postfix/scache[26273]: statistics: start interval Mar  2 09:43:08
Mar  2 09:50:48 messagerie postfix/scache[26273]: statistics: domain lookup hits=3 miss=28 success=9%
Mar  2 09:50:48 messagerie postfix/scache[26273]: statistics: max simultaneous domains=1 addresses=2 connection=8
#----------------------------------- seems to be starting to process something (also from timestamps this is roughly 2 minutes later
Mar  2 09:51:37 messagerie postfix/cleanup[26917]: A4C09162007E: message-id=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/pickup[26438]: 2D3361620085: uid=0 from=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/cleanup[26917]: 2D3361620085: message-id=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/pickup[26438]: 337A01620081: uid=0 from=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/cleanup[26917]: 337A01620081: message-id=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/smtpd[26937]: 46019162007E: client=localhost[127.0.0.1]
Mar  2 09:51:40 messagerie postfix/cleanup[26917]: 46019162007E: message-id=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/smtpd[25491]: connect from localhost[127.0.0.1]
Mar  2 09:51:40 messagerie postfix/smtpd[26937]: disconnect from localhost[127.0.0.1]
Mar  2 09:51:40 messagerie postfix/smtpd[25491]: 4EC8B1620083: client=localhost[127.0.0.1]
Mar  2 09:51:40 messagerie postfix/cleanup[26917]: 4EC8B1620083: message-id=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/smtp[26927]: 2D3361620085: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.18, delays=0.06/0/0/0.12, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 46019162007E)
Mar  2 09:51:40 messagerie postfix/smtpd[25491]: disconnect from localhost[127.0.0.1]
Mar  2 09:51:40 messagerie postfix/smtp[27113]: 337A01620081: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.22, delays=0.08/0.01/0/0.13, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4EC8B1620083)
Mar  2 09:51:40 messagerie postfix/smtp[27113]: 337A01620081: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.22, delays=0.08/0.01/0/0.13, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4EC8B1620083)
Mar  2 09:51:40 messagerie postfix/smtp[27113]: 337A01620081: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.22, delays=0.08/0.01/0/0.13, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4EC8B1620083)
Mar  2 09:51:40 messagerie postfix/smtp[27113]: 337A01620081: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.22, delays=0.08/0.01/0/0.13, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4EC8B1620083)
Mar  2 09:51:40 messagerie postfix/smtp[27113]: 337A01620081: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.22, delays=0.08/0.01/0/0.13, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4EC8B1620083)
Mar  2 09:51:40 messagerie postfix/smtp[27113]: 337A01620081: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.22, delays=0.08/0.01/0/0.13, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 4EC8B1620083)
Mar  2 09:51:40 messagerie postfix/pickup[26438]: 637F21620085: uid=0 from=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/cleanup[26917]: 637F21620085: message-id=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/lmtp[27117]: 4EC8B1620083: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.17, delays=0.04/0/0/0.12, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> yb8gFhzdt1juaQAA4gj4ZQ Saved)
Mar  2 09:51:40 messagerie postfix/smtpd[26937]: connect from localhost[127.0.0.1]
Mar  2 09:51:40 messagerie postfix/smtpd[26937]: 82D8E1620086: client=localhost[127.0.0.1]
Mar  2 09:51:40 messagerie postfix/cleanup[26917]: 82D8E1620086: message-id=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/pickup[26438]: 860B91620088: uid=0 from=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/cleanup[27124]: 860B91620088: message-id=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/smtp[26927]: 637F21620085: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.2, delays=0.07/0/0/0.13, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 82D8E1620086)
Mar  2 09:51:40 messagerie postfix/lmtp[27117]: 4EC8B1620083: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.32, delays=0.04/0/0/0.27, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> yb8gFhzdt1juaQAA4gj4ZQ Saved)
Mar  2 09:51:40 messagerie postfix/smtpd[25491]: connect from localhost[127.0.0.1]
Mar  2 09:51:40 messagerie postfix/lmtp[27125]: 82D8E1620086: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.16, delays=0.06/0.01/0/0.09, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> D6aUIxzdt1j2aQAA4gj4ZQ Saved)
Mar  2 09:51:40 messagerie postfix/smtpd[25491]: A72791620086: client=localhost[127.0.0.1]
Mar  2 09:51:40 messagerie postfix/cleanup[26917]: A72791620086: message-id=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/pickup[26438]: AB3D61620081: uid=0 from=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/cleanup[27124]: AB3D61620081: message-id=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/smtp[27113]: 860B91620088: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.25, delays=0.08/0.01/0/0.16, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as A72791620086)
Mar  2 09:51:40 messagerie postfix/lmtp[27117]: 4EC8B1620083: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.47, delays=0.04/0/0/0.42, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> yb8gFhzdt1juaQAA4gj4ZQ Saved)
Mar  2 09:51:40 messagerie postfix/smtpd[26937]: CC5291620088: client=localhost[127.0.0.1]
Mar  2 09:51:40 messagerie postfix/cleanup[27124]: CC5291620088: message-id=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/lmtp[27125]: A72791620086: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.23, delays=0.02/0/0/0.2, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> E6aUIxzdt1j2aQAA4gj4ZQ Saved)
Mar  2 09:51:40 messagerie postfix/smtp[26927]: AB3D61620081: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.27, delays=0.1/0/0/0.17, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as CC5291620088)
Mar  2 09:51:40 messagerie postfix/pickup[26438]: E0D911620081: uid=0 from=<[hidden email]>
Mar  2 09:51:40 messagerie postfix/cleanup[26917]: E0D911620081: message-id=<[hidden email]>
Mar  2 09:51:41 messagerie postfix/lmtp[27117]: 4EC8B1620083: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.69, delays=0.04/0/0/0.64, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> yb8gFhzdt1juaQAA4gj4ZQ Saved)
Mar  2 09:51:41 messagerie postfix/smtpd[25491]: 0AD8C1620086: client=localhost[127.0.0.1]
Mar  2 09:51:41 messagerie postfix/lmtp[27125]: CC5291620088: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.21, delays=0.07/0/0/0.13, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> kZmENhzdt1j/aQAA4gj4ZQ Saved)
Mar  2 09:51:41 messagerie postfix/cleanup[27124]: 0AD8C1620086: message-id=<[hidden email]>
Mar  2 09:51:41 messagerie postfix/smtp[27113]: E0D911620081: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.28, delays=0.15/0/0/0.12, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 0AD8C1620086)
Mar  2 09:51:41 messagerie postfix/pickup[26438]: 1781E1620081: uid=0 from=<[hidden email]>
Mar  2 09:51:41 messagerie postfix/cleanup[26917]: 1781E1620081: message-id=<[hidden email]>
Mar  2 09:51:41 messagerie postfix/lmtp[27117]: 4EC8B1620083: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.84, delays=0.04/0/0/0.79, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> yb8gFhzdt1juaQAA4gj4ZQ Saved)
Mar  2 09:51:41 messagerie postfix/pickup[26438]: 310FC1620088: uid=0 from=<[hidden email]>
Mar  2 09:51:41 messagerie postfix/cleanup[27124]: 310FC1620088: message-id=<[hidden email]>
Mar  2 09:51:41 messagerie postfix/smtpd[25491]: 32B511620089: client=localhost[127.0.0.1]
Mar  2 09:51:41 messagerie postfix/cleanup[26917]: 32B511620089: message-id=<[hidden email]>
Mar  2 09:51:41 messagerie postfix/smtp[26927]: 1781E1620081: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.27, delays=0.1/0/0/0.16, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 32B511620089)
Mar  2 09:51:41 messagerie postfix/lmtp[27134]: 0AD8C1620086: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.26, delays=0.03/0/0/0.23, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> Iu+JBB3dt1gDagAA4gj4ZQ Saved)
Mar  2 09:51:41 messagerie postfix/smtp[27116]: 46019162007E: to=<[hidden email]>, relay=mta-gw.infomaniak.ch[83.166.132.48]:25, delay=1, delays=0.04/0.01/0.57/0.42, dsn=2.0.0, status=sent (250 2.0.0 v228peKp126954 Message accepted for delivery)
Mar  2 09:51:41 messagerie postfix/lmtp[27117]: 4EC8B1620083: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=1, delays=0.04/0/0/0.96, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> yb8gFhzdt1juaQAA4gj4ZQ Saved)
Mar  2 09:51:41 messagerie postfix/smtpd[25491]: 5F2E3162007E: client=localhost[127.0.0.1]
Mar  2 09:51:41 messagerie postfix/cleanup[26917]: 5F2E3162007E: message-id=<[hidden email]>
Mar  2 09:51:41 messagerie postfix/lmtp[27125]: 32B511620089: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.22, delays=0.09/0/0/0.13, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> cvzVER3dt1gHagAA4gj4ZQ Saved)
Mar  2 09:51:41 messagerie postfix/smtp[27113]: 310FC1620088: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.27, delays=0.11/0.02/0/0.14, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 5F2E3162007E)
Mar  2 09:51:41 messagerie postfix/lmtp[27134]: 5F2E3162007E: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.1, delays=0.03/0/0/0.07, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> zb8gFhzdt1juaQAA4gj4ZQ Saved)
#----------------------------------- seems to have ended processing whatever it was doing (also based on timestamps, this is 17 seconds later)
Mar  2 09:51:58 messagerie postfix/cleanup[27124]: 3DDFF162007E: message-id=<>
Mar  2 09:51:59 messagerie postfix/pickup[26438]: 6DF721620085: uid=0 from=<[hidden email]>
Mar  2 09:51:59 messagerie postfix/cleanup[27124]: 6DF721620085: message-id=<[hidden email]>


  -- Yassine.
Reply | Threaded
Open this post in threaded view
|

Re: Client is always localhost

Viktor Dukhovni

> On Mar 6, 2017, at 10:02 AM, chaouche yacine <[hidden email]> wrote:
>
> I did my best at making most sense of the lines in the log file and made assumptions on timestamps to collect these lines where there should be an email from [hidden email] to me ([hidden email]), although their SMTP client doesn't seem to appear here :

You likely have most of the entries in master.cf chrooted,
and no log socket in chroot jail ($queue_directory/dev/log or similar).

I see no logging from qmgr(8) or smtpd(8) other than the re-injection
service receiving amavis filtered email.

Fix your master.cf file (turn off chroot).

--
        Viktor.

Reply | Threaded
Open this post in threaded view
|

Re: Client is always localhost

chaouche yacine





On Monday, March 6, 2017 4:10 PM, Viktor Dukhovni <[hidden email]> wrote:


>You likely have most of the entries in master.cf chrooted,

>and no log socket in chroot jail ($queue_directory/dev/log or similar).

I have no smtpd line in my master.cf file, and since my postfix version is 2.X the default is to run chrooted. My queue_directory is /var/spool/postfix




root@messagerie[10.10.10.19] /var/spool/postfix # postconf queue_directory
queue_directory = /var/spool/postfix
root@messagerie[10.10.10.19] /var/spool/postfix #




and there's a /dev/log socket there, but it belongs to root, while the other files belong to postfix :






root@messagerie[10.10.10.19] /var/spool/postfix # ls
total 80K
drwx------  2 postfix postfix   12K Mar  6 16:53 active
drwx------  2 postfix postfix  4.0K Mar  6 15:15 bounce
drwx------  2 postfix postfix  4.0K Mar  7  2016 corrupt
drwx------ 18 postfix postfix  4.0K Nov 14 08:56 defer
drwx------ 18 postfix postfix  4.0K Nov 14 08:56 deferred
drwxr-xr-x  2 postfix postfix  4.0K Sep  8 09:50 dev
drwxr-xr-x  3 postfix postfix  4.0K Feb  5 10:46 etc
drwx------  2 postfix postfix  4.0K Mar 27  2016 flush
drwx------  2 postfix postfix  4.0K Mar  7  2016 hold
drwx------  2 postfix postfix  4.0K Mar  6 16:53 incoming
drwxr-xr-x  3 postfix postfix  4.0K Mar  7  2016 lib
drwx-wx---  2 postfix postdrop 4.0K Mar  6 16:53 maildrop
drwxr-xr-x  2 root    postfix  4.0K Sep 26 10:52 pid
drwx------  2 postfix postfix  4.0K Mar  6 10:27 private
drwx--s---  2 postfix postdrop 4.0K Feb  5 10:46 public
drwx------  2 postfix postfix  4.0K Mar  7  2016 saved
drwx------  2 postfix postfix  4.0K Mar  6 10:47 trace
drwxr-xr-x  3 postfix postfix  4.0K Mar  7  2016 usr
root@messagerie[10.10.10.19] /var/spool/postfix # ls dev/log
srw-rw-rw- 1 root root 0 Sep  8 09:50 dev/log
root@messagerie[10.10.10.19] /var/spool/postfix #






> I see no logging from qmgr(8) or smtpd(8) other than the re-injection

>service receiving amavis filtered email.

Correct.


> Fix your master.cf file (turn off chroot).
I would like to make sure I understand the docs correctly before I do this. I have highlighted here some passages of the postfix documentation that says that


"Sites with high security requirements should consider to chroot all daemons that talk to the network: the smtp(8) and smtpd(8) processes"...

(Online annotation : http://genius.it/www.postfix.org/BASIC_CONFIGURATION_README.html#chroot_setup)

Also, I don't have syslog installed, I have rsyslog instead, and it doesn't seem to support the -a option

Its man page says that rsyslogd reads from /dev/log, but I don't have it on my machine.


root@messagerie[10.10.10.19] ~ # ls /dev/log
ls: cannot access /dev/log: No such file or directory
root@messagerie[10.10.10.19] ~ #


But as I was trying to find something in rsyslog's /etc/ files, I found this :


root@messagerie[10.10.10.19] ~ # cat /etc/rsyslog.d/postfix.conf
# Create an additional socket in postfix's chroot in order not to break
# mail logging when rsyslog is restarted.  If the directory is missing,
# rsyslog will silently skip creating the socket.
$AddUnixListenSocket /var/spool/postfix/dev/log
root@messagerie[10.10.10.19] ~ #


So it seems that rsyslog is already configured to read from the chrooted /var/spool/postfix/dev/log socket. Maybe it's just a question of permissions/ownership ? I told myself.

I changed ownership to postfix:postfix, restarted postfix, restarted rsyslogd, but still nothing in the logs. Here's an excerpt after sending myself mail from my yahoo account :





Mar  6 17:25:38 messagerie postfix/cleanup[29757]: 3vcQBV1wdkz3PsZP: message-id=<[hidden email]>
Mar  6 17:25:41 messagerie postfix/pickup[29551]: 3vcQBY22F7z3PsZY: uid=0 from=<[hidden email]>
Mar  6 17:25:41 messagerie postfix/cleanup[29922]: 3vcQBY22F7z3PsZY: message-id=<[hidden email]>
Mar  6 17:25:41 messagerie postfix/smtpd[29766]: 3vcQBY2gDsz3PsZP: client=localhost[127.0.0.1]
Mar  6 17:25:41 messagerie postfix/cleanup[29802]: 3vcQBY2gDsz3PsZP: message-id=<[hidden email]>
Mar  6 17:25:41 messagerie postfix/smtpd[29766]: disconnect from localhost[127.0.0.1]
Mar  6 17:25:41 messagerie postfix/smtp[29805]: 3vcQBY22F7z3PsZY: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.17, delays=0.06/0/0/0.1, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 3vcQBY2gDsz3PsZP)
Mar  6 17:25:41 messagerie postfix/pickup[29551]: 3vcQBY3B5Tz3PsZY: uid=0 from=<[hidden email]>
Mar  6 17:25:41 messagerie postfix/cleanup[29757]: 3vcQBY3B5Tz3PsZY: message-id=<[hidden email]>
Mar  6 17:25:41 messagerie postfix/smtpd[29816]: 3vcQBY3zJVz3PsZS: client=localhost[127.0.0.1]
Mar  6 17:25:41 messagerie postfix/cleanup[29802]: 3vcQBY3zJVz3PsZS: message-id=<[hidden email]>
Mar  6 17:25:41 messagerie postfix/lmtp[29806]: 3vcQBY2gDsz3PsZP: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.19, delays=0.03/0/0/0.16, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> Vl1yGIWNvVgHdQAA4gj4ZQ Saved)
Mar  6 17:25:41 messagerie postfix/smtpd[29816]: disconnect from localhost[127.0.0.1]
Mar  6 17:25:41 messagerie postfix/smtp[29764]: 3vcQBY3B5Tz3PsZY: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.18, delays=0.07/0/0/0.11, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 3vcQBY3zJVz3PsZS)
Mar  6 17:25:41 messagerie postfix/lmtp[29812]: 3vcQBY3zJVz3PsZS: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.2, delays=0.03/0/0/0.16, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> Wl1yGIWNvVgHdQAA4gj4ZQ Saved)


Any tips ?
















--
    Viktor.
Reply | Threaded
Open this post in threaded view
|

Re: Client is always localhost

Viktor Dukhovni

> On Mar 6, 2017, at 11:27 AM, chaouche yacine <[hidden email]> wrote:
>
>> You likely have most of the entries in master.cf chrooted,
>
>> and no log socket in chroot jail ($queue_directory/dev/log or similar).
>
> I have no smtpd line in my master.cf file, and since my postfix version is 2.X the default is to run chrooted. My queue_directory is /var/spool/postfix

Of course you do.  You're just not looking in the correct column.

Disable chroot for all master.cf entries and make sure that logging
works in that configuration.  Once that works, you can if you wish
tackle making logging work with chroot, but that's for experts, and
you'll have to figure that out for yourself.

--
        Viktor.

Reply | Threaded
Open this post in threaded view
|

Re: Client is always localhost

chaouche yacine
Viktor,


Reporting on my progress, I had two smtp lines in my master.cf, one is unix and the other is inet. Changed both of them to not be run in a chrooted environement :




smtp      inet  n       -       n       -       -       smtpd -o content_filter=spamassassin
smtp      unix  -       -       n       -       -       smtp



qmgr appears only once and is also run unchrooted :




qmgr      unix  n       -       n       300     1       qmgr




Then I restarted postfix (postfix stop/start are silently ignored, I had to call through service postfix stop/start/reload) and sent myself an e-mail from my yahoo account, still nothing from smtp/qmgr :



Mar 7 12:02:58 messagerie postfix[12995]: Stopping Postfix Mail Transport Agent: postfix.
Mar 7 12:03:03 messagerie postfix[13047]: Starting Postfix Mail Transport Agent: postfix.
Mar 7 12:05:27 messagerie postfix/cleanup[13638]: 3vcv2b2WQwz3PsZP: message-id=<[hidden email]>
Mar 7 12:05:30 messagerie postfix/pickup[13156]: 3vcv2f0X49z3PsZV: uid=0 from=<[hidden email]>
Mar 7 12:05:30 messagerie postfix/cleanup[13638]: 3vcv2f0X49z3PsZV: message-id=<[hidden email]>
Mar 7 12:05:30 messagerie postfix/smtpd[13651]: connect from localhost[127.0.0.1]
Mar 7 12:05:30 messagerie postfix/smtpd[13651]: 3vcv2f1Lryz3PsZP: client=localhost[127.0.0.1]
Mar 7 12:05:30 messagerie postfix/cleanup[13638]: 3vcv2f1Lryz3PsZP: message-id=<[hidden email]>
Mar 7 12:05:30 messagerie postfix/smtpd[13651]: disconnect from localhost[127.0.0.1]
Mar 7 12:05:30 messagerie postfix/smtp[13648]: 3vcv2f0X49z3PsZV: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.18, delays=0.05/0.01/0/0.12, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 3vcv2f1Lryz3PsZP)
Mar 7 12:05:30 messagerie postfix/pickup[13156]: 3vcv2f1wL4z3PsZV: uid=0 from=<[hidden email]>
Mar 7 12:05:30 messagerie postfix/cleanup[13638]: 3vcv2f1wL4z3PsZV: message-id=<[hidden email]>
Mar 7 12:05:30 messagerie postfix/lmtp[13652]: 3vcv2f1Lryz3PsZP: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.19, delays=0.03/0.01/0/0.16, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> 3z5+DfqTvlhUMAAA4gj4ZQ Saved)
Mar 7 12:05:30 messagerie postfix/smtpd[13651]: connect from localhost[127.0.0.1]
Mar 7 12:05:30 messagerie postfix/smtpd[13651]: 3vcv2f2l3Cz3PsZP: client=localhost[127.0.0.1]
Mar 7 12:05:30 messagerie postfix/cleanup[13638]: 3vcv2f2l3Cz3PsZP: message-id=<[hidden email]>
Mar 7 12:05:30 messagerie postfix/smtpd[13651]: disconnect from localhost[127.0.0.1]
Mar 7 12:05:30 messagerie postfix/smtp[13648]: 3vcv2f1wL4z3PsZV: to=<[hidden email]>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.2, delays=0.07/0/0/0.13, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as 3vcv2f2l3Cz3PsZP)
Mar 7 12:05:30 messagerie postfix/lmtp[13652]: 3vcv2f2l3Cz3PsZP: to=<[hidden email]>, relay=messagerie.mydomain.tld[private/dovecot-lmtp], delay=0.2, delays=0.04/0/0/0.16, dsn=2.0.0, status=sent (250 2.0.0 <[hidden email]> 4z5+DfqTvlhUMAAA4gj4ZQ Saved)


  -- Yassine.
Reply | Threaded
Open this post in threaded view
|

Re: Client is always localhost

@lbutlr
In reply to this post by chaouche yacine
On 2017-03-06 (09:27 MST), chaouche yacine <[hidden email]> wrote:
>
> since my postfix version is 2.X the default is to run chrooted.

Really? I do not remember chroot ever being the default.

--
Apple broke AppleScripting signatures in Mail.app, so no random signatures.

Reply | Threaded
Open this post in threaded view
|

Re: Client is always localhost

chaouche yacine


On Tuesday, March 7, 2017 12:13 PM, "@lbutlr" <[hidden email]> wrote:
> Really? I do not remember chroot ever being the default.

Yet in master.cf I find this :



# ==========================================================================
# service type private unpriv chroot wakeup maxproc command + args
#                             (yes)   (yes)   (yes)   (never) (100)
# ==========================================================================
Reply | Threaded
Open this post in threaded view
|

Re: Client is always localhost

Wietse Venema
In reply to this post by chaouche yacine
chaouche yacine:

> Viktor,
>
> Reporting on my progress, I had two smtp lines in my master.cf,
> one is unix and the other is inet. Changed both of them to not be
> run in a chrooted environement :
>
> smtp      inet  n       -       n       -       -       smtpd -o content_filter=spamassassin
> smtp      unix  -       -       n       -       -       smtp
>
> qmgr appears only once and is also run unchrooted :
>
> qmgr      unix  n       -       n       300     1       qmgr
>
> Then I restarted postfix (postfix stop/start are silently ignored,
> I had to call through service postfix stop/start/reload) and sent
> myself an e-mail from my yahoo account, still nothing from smtp/qmgr
> :

What Linux distribution is this?

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: Client is always localhost

chaouche yacine
On Tuesday, March 7, 2017 1:12 PM, Wietse Venema <[hidden email]> wrote:

> What Linux distribution is this?


I am running Debian 8.5

root@messagerie[10.10.10.19] ~ # lsb_release -a
No LSB modules are available.
Distributor ID: Debian
Description:    Debian GNU/Linux 8.5 (jessie)
Release:        8.5
Codename:       jessie
root@messagerie[10.10.10.19] ~ #
Reply | Threaded
Open this post in threaded view
|

Re: Client is always localhost

@lbutlr
In reply to this post by chaouche yacine
On 2017-03-07 (05:09 MST), chaouche yacine <[hidden email]> wrote:

>
> On Tuesday, March 7, 2017 12:13 PM, "@lbutlr" <[hidden email]> wrote:
>> Really? I do not remember chroot ever being the default.
>
> Yet in master.cf I find this :
>
>
> # ==========================================================================
> # service type private unpriv chroot wakeup maxproc command + args
> #                             (yes)   (yes)   (yes)   (never) (100)
> # ==========================================================================

The column headers?

That does not indicate that chroot is the default.

You have to look at the non commented lines.

smtpd        pass  -       -       n       -       -       smtpd

(not private, not unprivileged, not chroot…)

--
Apple broke AppleScripting signatures in Mail.app, so no random signatures.