search

postalserver / postal

📮 A fully featured open source mail delivery platform for incoming & outgoing e-mail
https://postalserver.io
MIT License
14.89k stars 1.06k forks source link

Can't receive mail #308

Closed paris-ci closed 4 years ago

paris-ci commented 7 years ago

There seems to be nothing listening on external interfaces for port 25, here is some debug info, hope you can help

postal run

11:40:42 system          | Procodile supervisor started with PID 1048
11:40:42 system          | Application root is /opt/postal/app
11:40:42 system          | Automatic respawning is disabled
11:40:42 system          | Reloading configuration
11:40:42 control         | Listening at /tmp/postal/pids/procodile.sock
11:40:42 web.1           | Started with PID 1052
11:40:42 worker.1        | Started with PID 1054
11:40:42 cron.1          | Started with PID 1056
11:40:42 smtp.1          | Started with PID 1058
11:40:42 requeuer.1      | Started with PID 1060
11:40:43 web.1           | => Puma starting in single mode...
11:40:43 web.1           | => * Version 3.8.2 (ruby 2.3.4-p301), codename: Sassy Salamander
11:40:43 web.1           | => * Min threads: 5, max threads: 5
11:40:43 web.1           | => * Environment: production
11:40:44 requeuer.1      | => [requeuer.1:1060] [2017-08-11T11:40:44.827] INFO -- : ** [Raven] Raven 2.1.0 configured not to capture errors.
11:40:44 requeuer.1      | => [requeuer.1:1060] [2017-08-11T11:40:44.925] INFO -- : Running message requeuer...
11:40:45 cron.1          | => [cron.1:1056] [2017-08-11T11:40:45.372] INFO -- : ** [Raven] Raven 2.1.0 configured not to capture errors.
11:40:45 smtp.1          | => [smtp.1:1058] [2017-08-11T11:40:45.465] INFO -- : ** [Raven] Raven 2.1.0 configured not to capture errors.
11:40:45 cron.1          | => [cron.1:1056] [2017-08-11T11:40:45.469] INFO -- : Starting clock for 8 events: [ every-1-minutes every-15-minutes every-15-minutes every-15-minutes every-15-minutes every-hour every-hour every-day ]
11:40:45 cron.1          | => [cron.1:1056] [2017-08-11T11:40:45.469] INFO -- : Triggering 'every-1-minutes'
11:40:45 smtp.1          | => [smtp.1:1058] [2017-08-11T11:40:45.565] INFO -- : Listening on port 25
11:40:45 web.1           | => [web.1:1052] [2017-08-11T11:40:45.767] INFO -- : ** [Raven] Raven 2.1.0 configured not to capture errors.
11:40:45 web.1           | => * Listening on tcp://127.0.0.1:5000
11:40:45 web.1           | => Use Ctrl-C to stop
11:40:45 worker.1        | => [worker.1:1054] [2017-08-11T11:40:45.947] INFO -- : ** [Raven] Raven 2.1.0 configured not to capture errors.
11:40:46 worker.1        | => [worker.1:1054] [2017-08-11T11:40:46.033] INFO -- : Worker running with 4 threads
11:40:46 worker.1        | => [worker.1:1054] [2017-08-11T11:40:46.037] INFO -- : [HEQV2FHP3P] Started processing RequeueWebhooksJob job
11:40:46 worker.1        | => [worker.1:1054] [2017-08-11T11:40:46.037] INFO -- : Joined main queue
11:40:46 worker.1        | => [worker.1:1054] [2017-08-11T11:40:46.038] INFO -- : [NX1CWFKPNO] Started processing SendNotificationsJob job
11:40:46 worker.1        | => [worker.1:1054] [2017-08-11T11:40:46.084] INFO -- : [HEQV2FHP3P] Finished processing RequeueWebhooksJob job in 0.046265129s
11:40:46 worker.1        | => [worker.1:1054] [2017-08-11T11:40:46.114] INFO -- : [NX1CWFKPNO] Finished processing SendNotificationsJob job in 0.076784686s
11:41:45 cron.1          | => [cron.1:1056] [2017-08-11T11:41:45.524] INFO -- : Triggering 'every-1-minutes'
11:41:45 worker.1        | => [worker.1:1054] [2017-08-11T11:41:45.525] INFO -- : [W6KISGVGCU] Started processing RequeueWebhooksJob job
11:41:45 worker.1        | => [worker.1:1054] [2017-08-11T11:41:45.526] INFO -- : [SHIWKT2ZDD] Started processing SendNotificationsJob job
11:41:45 worker.1        | => [worker.1:1054] [2017-08-11T11:41:45.559] INFO -- : [W6KISGVGCU] Finished processing RequeueWebhooksJob job in 0.033811669s
11:41:45 worker.1        | => [worker.1:1054] [2017-08-11T11:41:45.590] INFO -- : [SHIWKT2ZDD] Finished processing SendNotificationsJob job in 0.064328724s
11:42:45 smtp.1          | => [smtp.1:1058] [2017-08-11T11:42:45.280] DEBUG -- : [Z2NLYD]    Connection opened from ::ffff:148.244.209.99
11:42:45 smtp.1          | => [smtp.1:1058] [2017-08-11T11:42:45.280] DEBUG -- : [Z2NLYD]    Client identified as ::ffff:148.244.209.99
11:42:45 smtp.1          | => [smtp.1:1058] [2017-08-11T11:42:45.437] DEBUG -- : [Z2NLYD] <= EHLO User
11:42:45 cron.1          | => [cron.1:1056] [2017-08-11T11:42:45.562] INFO -- : Triggering 'every-1-minutes'
11:42:45 worker.1        | => [worker.1:1054] [2017-08-11T11:42:45.563] INFO -- : [CB46JUGBAL] Started processing RequeueWebhooksJob job
11:42:45 worker.1        | => [worker.1:1054] [2017-08-11T11:42:45.564] INFO -- : [RING4EF1RG] Started processing SendNotificationsJob job
11:42:45 worker.1        | => [worker.1:1054] [2017-08-11T11:42:45.596] INFO -- : [CB46JUGBAL] Finished processing RequeueWebhooksJob job in 0.03290253s
11:42:45 worker.1        | => [worker.1:1054] [2017-08-11T11:42:45.627] INFO -- : [RING4EF1RG] Finished processing SendNotificationsJob job in 0.063509057s
11:42:50 smtp.1          | => [smtp.1:1058] [2017-08-11T11:42:50.455] DEBUG -- : [Z2NLYD] => 250-My capabilities are
11:42:50 smtp.1          | => [smtp.1:1058] [2017-08-11T11:42:50.455] DEBUG -- : [Z2NLYD] => 250 AUTH CRAM-MD5 PLAIN LOGIN
11:42:50 smtp.1          | => [smtp.1:1058] [2017-08-11T11:42:50.455] DEBUG -- : [Z2NLYD] <= QUIT
11:42:50 smtp.1          | => [smtp.1:1058] [2017-08-11T11:42:50.455] DEBUG -- : [Z2NLYD] => 221 Closing Connection
11:42:50 smtp.1          | => [smtp.1:1058] [2017-08-11T11:42:50.455] DEBUG -- : [Z2NLYD]    Connection closed
11:43:45 cron.1          | => [cron.1:1056] [2017-08-11T11:43:45.599] INFO -- : Triggering 'every-1-minutes'
11:43:45 worker.1        | => [worker.1:1054] [2017-08-11T11:43:45.600] INFO -- : [UATBYBO0AG] Started processing RequeueWebhooksJob job
11:43:45 worker.1        | => [worker.1:1054] [2017-08-11T11:43:45.601] INFO -- : [QBIXVOPZZB] Started processing SendNotificationsJob job
11:43:45 worker.1        | => [worker.1:1054] [2017-08-11T11:43:45.634] INFO -- : [UATBYBO0AG] Finished processing RequeueWebhooksJob job in 0.034012678s
11:43:45 worker.1        | => [worker.1:1054] [2017-08-11T11:43:45.666] INFO -- : [QBIXVOPZZB] Finished processing SendNotificationsJob job in 0.064343991s
^X^C11:43:51 system          | Supervisor received INT signal
11:43:51 system          | Reloading configuration
11:43:51 system          | Stopping all Postal processes
11:43:51 web.1           | Sending TERM to 1052
11:43:51 worker.1        | Sending TERM to 1054
11:43:51 cron.1          | Sending TERM to 1056
11:43:51 smtp.1          | Sending TERM to 1058
11:43:51 requeuer.1      | Sending TERM to 1060
11:43:51 cron.1          | => Exiting...
11:43:51 web.1           | => - Gracefully stopping, waiting for requests to finish
11:43:51 smtp.1          | => Received TERM signal, shutting down.
11:43:51 web.1           | => === puma shutdown: 2017-08-11 11:43:51 +0000 ===
11:43:51 web.1           | => - Goodbye!
11:43:52 worker.1        | => [worker.1:1054] [2017-08-11T11:43:52.168] INFO -- : Exiting immediately because no jobs running
11:43:54 web.1           | Removed PID file
11:43:54 worker.1        | Removed PID file
11:43:54 cron.1          | Removed PID file
11:43:54 smtp.1          | Removed PID file
11:43:54 requeuer.1      | Removed PID file
11:43:54 system          | All processes have stopped
11:43:54 system          | Stopping Procodile supervisor

postal test-app-smtp MYGMAILADDRESS@gmail.com

Message has been sent successfully.

netstat -lnp

Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 0.0.0.0:443             0.0.0.0:*               LISTEN      322/nginx: master p
tcp        0      0 127.0.0.1:5000          0.0.0.0:*               LISTEN      1160/[postal] web.1
tcp        0      0 0.0.0.0:25672           0.0.0.0:*               LISTEN      278/beam.smp
tcp        0      0 127.0.0.1:3306          0.0.0.0:*               LISTEN      589/mysqld
tcp        0      0 0.0.0.0:5355            0.0.0.0:*               LISTEN      274/systemd-resolve
tcp        0      0 0.0.0.0:80              0.0.0.0:*               LISTEN      322/nginx: master p
tcp        0      0 0.0.0.0:4369            0.0.0.0:*               LISTEN      410/epmd
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      272/sshd
tcp6       0      0 :::25                   :::*                    LISTEN      1168/[postal] smtp.
tcp6       0      0 :::443                  :::*                    LISTEN      322/nginx: master p
tcp6       0      0 :::5672                 :::*                    LISTEN      278/beam.smp
tcp6       0      0 :::5355                 :::*                    LISTEN      274/systemd-resolve
tcp6       0      0 :::80                   :::*                    LISTEN      322/nginx: master p
tcp6       0      0 :::4369                 :::*                    LISTEN      410/epmd
tcp6       0      0 :::22                   :::*                    LISTEN      272/sshd
udp        0      0 0.0.0.0:5355            0.0.0.0:*                           274/systemd-resolve
udp        0      0 127.0.0.53:53           0.0.0.0:*                           274/systemd-resolve
udp6       0      0 :::5355                 :::*                                274/systemd-resolve
Active UNIX domain sockets (only servers)
Proto RefCnt Flags       Type       State         I-Node   PID/Program name     Path
unix  2      [ ACC ]     STREAM     LISTENING     2791337338 626/systemd          /run/user/0/systemd/private
unix  2      [ ACC ]     STREAM     LISTENING     2791334006 1/init               /run/systemd/private
unix  2      [ ACC ]     STREAM     LISTENING     2791334010 1/init               /run/systemd/journal/stdout
unix  2      [ ACC ]     STREAM     LISTENING     2791334183 1/init               /run/uuidd/request
unix  2      [ ACC ]     STREAM     LISTENING     2791334184 1/init               /var/run/dbus/system_bus_socket
unix  2      [ ACC ]     STREAM     LISTENING     2791338166 589/mysqld           /var/run/mysqld/mysqld.sock
unix  2      [ ACC ]     STREAM     LISTENING     2791401017 1154/[procodile] Po  /tmp/postal/pids/procodile.sock

telnet mail.api-d.com 25 [my mail server, from my local computer]

Trying 5.196.41.99...
telnet: connect to address 5.196.41.99: Operation timed out
telnet: Unable to connect to remote host

telnet mail.api-d.com 25 [from the mail server itself]

Trying 5.196.41.99...
Connected to mail.api-d.com.
Escape character is '^]'.
220 mail.api-d.com ESMTP Postal/CJWFDT
^]quit

telnet> quit

iptables -L

Chain INPUT (policy ACCEPT)
target     prot opt source               destination

Chain FORWARD (policy ACCEPT)
target     prot opt source               destination

Chain OUTPUT (policy ACCEPT)
target     prot opt source               destination

iptables -vL -t nat

Chain PREROUTING (policy ACCEPT 2212 packets, 101K bytes)
 pkts bytes target     prot opt in     out     source               destination

Chain INPUT (policy ACCEPT 508 packets, 20402 bytes)
 pkts bytes target     prot opt in     out     source               destination

Chain OUTPUT (policy ACCEPT 171 packets, 10787 bytes)
 pkts bytes target     prot opt in     out     source               destination

Chain POSTROUTING (policy ACCEPT 171 packets, 10787 bytes)
 pkts bytes target     prot opt in     out     source               destination

ufw status verbose

Status: inactive

postal config

web:
  # The host that the management interface will be available on
  host: mail.api-d.com
  # The protocol that requests to the management interface should happen on
  protocol: https

fast_server:
  # This can be enabled to enable click & open tracking on emails. It is disabled by
  # default as it requires a separate static IP address on your server.
  enabled: false
  bind_address:

general:
  # This can be changed to allow messages to be sent from multiple IP addresses
  use_ip_pools: false

main_db:
  # Specify the connection details for your MySQL database
  host: 127.0.0.1
  username: postal
  password: HEREISTHEPASSWORD
  database: postal

message_db:
  # Specify the connection details for your MySQL server that will be house the
  # message databases for mail servers.
  host: 127.0.0.1
  username: postal
  password: HEREISTHEPASSWORD
  prefix: postal

rabbitmq:
  # Specify the connection details for your RabbitMQ server.
  host: 127.0.0.1
  username: postal
  password: HEREISTHEPASSWORD
  vhost: /postal

dns:
  # Specifies the DNS record that you have configured. Refer to the documentation at
  # https://github.com/atech/postal/wiki/Domains-&-DNS-Configuration for further
  # information about these.
  mx_records:
    - mx.mail.api-d.com
  smtp_server_hostname: mail.api-d.com
  spf_include: spf.mail.api-d.com
  return_path: rp.mail.api-d.com
  route_domain: routes.mail.api-d.com
  track_domain: track.mail.api-d.com

#smtp_server:
#  port: 2525

smtp:
  # Specify an SMTP server that can be used to send messages from the Postal management
  # system to users. You can configure this to use a Postal mail server once the
  # your installation has been set up.
  host: 127.0.0.1
  port: 25
  username: api-d/api-d
  password: HEREISTHEPASSWORD
  from_name: Postal
  from_address: postal@api-d.com

rails:
  # This is generated automatically by the config initialization. It should be a random
  # string unique to your installation.
  secret_key: 1fdd85c15e2086f149a79bf3fe2b502a701f5fc273df8dd999933e87716712151d6976d8dc865118e22ad108e1cd5cafd12de540f284e3a79aafe2ef9a92bc87fe3e43519a2c39054edcf8cfbdfaee8b6a0435ee6b98b61069227c37f02e89c6406ac105568be34f3623fec671271624c7376a2bdaa8db3288d9e4f0fc06ffff

spamd:
  enabled: true
  host: 127.0.0.1
  port: 783

Screenshot of a sendmail to my server from my server

Screenshot 1 Screenshot 2

paris-ci commented 7 years ago

I can otherwise send mail normally

willpower232 commented 7 years ago

Have you given ruby the privilege to run on system ports?

sudo setcap 'cap_net_bind_service=+ep' /usr/bin/ruby2.3

If you have, can you please postal start and then send us the output of postal status

paris-ci commented 7 years ago

@willpower232 Yeah, I did that, forgot to mention, sorry.

postal start

Started Procodile supervisor with PID 2889

postal status

Procodile Version   1.0.17
Application Root    /opt/postal/app
Supervisor PID      2889
Started             2017-08-11 13:30:01 +0000

|| web
|| Quantity            1
|| Command             bundle exec puma -C config/puma.rb
|| Respawning          5 every 3600 seconds
|| Restart mode        usr1
|| Log path            none specified
|| Address/Port        none
|| => web.1            Running      13:30        pid:2895     respawns:0      port:-        tag:-

|| worker
|| Quantity            1
|| Command             bundle exec ruby script/worker.rb
|| Respawning          5 every 3600 seconds
|| Restart mode        start-term
|| Log path            none specified
|| Address/Port        none
|| => worker.1         Running      13:30        pid:2897     respawns:0      port:-        tag:-

|| cron
|| Quantity            1
|| Command             bundle exec rake postal:cron
|| Respawning          5 every 3600 seconds
|| Restart mode        term-start
|| Log path            none specified
|| Address/Port        none
|| => cron.1           Running      13:30        pid:2899     respawns:0      port:-        tag:-

|| smtp
|| Quantity            1
|| Command             bundle exec rake postal:smtp_server
|| Respawning          5 every 3600 seconds
|| Restart mode        usr1
|| Log path            none specified
|| Address/Port        none
|| => smtp.1           Running      13:30        pid:2901     respawns:0      port:-        tag:-

|| requeuer
|| Quantity            1
|| Command             bundle exec rake postal:requeuer
|| Respawning          5 every 3600 seconds
|| Restart mode        term-start
|| Log path            none specified
|| Address/Port        none
|| => requeuer.1       Running      13:30        pid:2906     respawns:0      port:-        tag:-
willpower232 commented 7 years ago

sorry I managed to not see it in your netstat -lnp but its there!

It must be that something is blocking smtp connection to your server, either your ISP or your server company.

You can try using iptables to use port 2525 instead, see https://github.com/atech/postal/issues/306#issuecomment-321571866

paris-ci commented 7 years ago

@willpower232 No luck starting the server on port 2525 and redirecting with IPTables... So I tried

1) nc -l 0.0.0.0 25 [listen to port 25 on the mail server]

2) telnet mail.api-d.com 25 [from local machine]

\2) > helo \1) < helo

So it's not a connexion problem between me and the mail server... It looks like postal is not listening to 0.0.0.0

willpower232 commented 7 years ago

Postal is supposed to be running on port 25, thats its intended behaviour.

Those iptables rules allow you to access postal port 25 using port 2525, a small sacrifice to get around connection issues.

paris-ci commented 7 years ago

I know, but I set the IPTables rules so that the port 25 will be redirected to port 2525, and setup postal to listen on 2525, but it's still not working. However, if I use netcat to open the port 25, I can telnet into it, so it isn't a connexion problem

catphish commented 7 years ago

I just tried this and it appears Postfix is listening on this host:

charlie@charlie-pc ~ $ telnet 5.196.41.99 25
Trying 5.196.41.99...
Connected to 5.196.41.99.
Escape character is '^]'.
220-mail.api-d.com ESMTP Postfix

With regard to your original question, if you can connect to SMTP locally but not externally, this is most likely a firewall issue. I see you have no INPUT rules in iptables, so maybe an external firewall?

Your screenshots actually show a completely different error unable to resolve mx.mail.api-d.com. I can resolve that name from here. Are you still having trouble with this?

paris-ci commented 7 years ago

@catphish Hey \o Thanks for getting back to me, I reinstalled postfix and everything on another container so I could still receive mail.

I changed nothing on the external firewall, and the two containers have an empty iptables/ufw set of rules.