Port 587 blocked on Ubuntu VPS... can't unblock it...what to do?

Question

My app can't send order invoices and gives this error in the production.log:

I, [2017-05-21T17:17:19.539388 #9385]  INFO -- : Completed 500 Internal Server Error in 26ms (ActiveRecord: 3.1ms)
F, [2017-05-21T17:17:19.540462 #9385] FATAL -- :
Errno::ECONNREFUSED (Connection refused - connect(2) for nil port 587):
  app/admin/order.rb:6:in `block (2 levels) in <top (required)>'

My cloud services support sent me this answer : I ran an NMAP on your IP address and port 587 appears to be blocked locally on your Droplet. Usually this is caused by IPtables or UFW trying to be helpful, but actually blocking a needed port.

So I did sudo iptables -A OUTPUT -p tcp --dport 587 -j ACCEPT and sudo ufw allow out 587

That didn't do the trick and I'm still getting this error. Can someone please advise me?

here is the action mailersettings in the production.rb

  config.action_mailer.default_url_options = { host: 'mypage.com'}
  config.action_mailer.perform_deliveries = true
  config.action_mailer.raise_delivery_errors = true
  config.action_mailer.delivery_method = :smtp
  config.action_mailer.smtp_settings = {
    address: ENV["SMTP_ADDRESS"],
    user_name: ENV["SMTP_USER"],
    password: ENV["SMTP_PASSWORD"],
    domain: "mypage.com",
    port: 587,
    authentication: :login,
    enable_starttls_auto: true
  }

In the deploy.rb I have this line to to trigger a copy of figaros application.yml to the server.

set :linked_files, %w{config/database.yml config/secrets.yml config/application.yml}

I'm using figaro gem in the application.yml there is this lines:

    SMTP_ADDRESS: "smtp.gmail.com"
SMTP_USER: "xxx@xxxx.com"
SMTP_PASSWORD: "xxxxxx"

** UPdate-3**

        I, [2017-05-23T11:01:33.056948 #1060]  INFO -- : Started GET "/admin/orders/10/edit" for 89.160.235.185 at 2017-05-23 11:01:33 +0000
    I, [2017-05-23T11:01:33.063914 #1060]  INFO -- : Processing by Admin::OrdersController#edit as HTML
    I, [2017-05-23T11:01:33.064026 #1060]  INFO -- :   Parameters: {"id"=>"10"}
    D, [2017-05-23T11:01:33.067956 #1060] DEBUG -- :   ^[[1m^[[36mCart Load (0.5ms)^[[0m  ^[[1mSELECT  "carts".* FROM "carts" WHERE "carts"."id" = $1 LIMIT 1^[[0m  [["$
    D, [2017-05-23T11:01:33.072547 #1060] DEBUG -- :   ^[[1m^[[35mAdminUser Load (0.4ms)^[[0m  SELECT  "admin_users".* FROM "admin_users" WHERE "admin_users"."id" = $1$
    D, [2017-05-23T11:01:33.075089 #1060] DEBUG -- :   ^[[1m^[[36mOrder Load (0.3ms)^[[0m  ^[[1mSELECT  "orders".* FROM "orders" WHERE "orders"."id" = $1 LIMIT 1^[[0m $
    D, [2017-05-23T11:01:33.119522 #1060] DEBUG -- :   ^[[1m^[[35mCACHE (0.0ms)^[[0m  SELECT  "orders".* FROM "orders" WHERE "orders"."id" = $1 LIMIT 1  [["id", "10"]]
    I, [2017-05-23T11:01:33.235247 #1060]  INFO -- :   Rendered /home/deploy/hlinreykdal/shared/bundle/ruby/2.3.0/bundler/gems/activeadmin-0a5a15b88bff/app/views/activ$
    I, [2017-05-23T11:01:33.235589 #1060]  INFO -- : Completed 200 OK in 171ms (Views: 157.9ms | ActiveRecord: 1.2ms)
    I, [2017-05-23T11:01:36.922087 #1060]  INFO -- : Started PATCH "/admin/orders/10" for 89.160.235.185 at 2017-05-23 11:01:36 +0000
    I, [2017-05-23T11:01:36.924303 #1060]  INFO -- : Processing by Admin::OrdersController#update as HTML
    I, [2017-05-23T11:01:36.924405 #1060]  INFO -- :   Parameters: {"utf8"=>" ^ ^ ", "authenticity_token"=>"f8ApZNwgnz1TpSUFfXOkVb2/QnTZaz2p0j3cWIcmdBxRzZpmmWJLQmuDx+n$
    D, [2017-05-23T11:01:36.925594 #1060] DEBUG -- :   ^[[1m^[[36mCart Load (0.2ms)^[[0m  ^[[1mSELECT  "carts".* FROM "carts" WHERE "carts"."id" = $1 LIMIT 1^[[0m  [["$
    D, [2017-05-23T11:01:36.926750 #1060] DEBUG -- :   ^[[1m^[[35mAdminUser Load (0.2ms)^[[0m  SELECT  "admin_users".* FROM "admin_users" WHERE "admin_users"."id" = $1$
    D, [2017-05-23T11:01:36.957134 #1060] DEBUG -- :   ^[[1m^[[36mOrder Load (0.3ms)^[[0m  ^[[1mSELECT  "orders".* FROM "orders" WHERE "orders"."id" = $1 LIMIT 1^[[0m $
    D, [2017-05-23T11:01:36.958757 #1060] DEBUG -- :   ^[[1m^[[35m (0.1ms)^[[0m  BEGIN
    D, [2017-05-23T11:01:36.961249 #1060] DEBUG -- :   ^[[1m^[[36mSQL (0.6ms)^[[0m  ^[[1mUPDATE "orders" SET "shipped" = $1, "updated_at" = $2 WHERE "orders"."id" = $3$
    D, [2017-05-23T11:01:36.962569 #1060] DEBUG -- :   ^[[1m^[[35m (0.8ms)^[[0m  COMMIT
    I, [2017-05-23T11:01:36.965057 #1060]  INFO -- : Redirected to http://hlinreykdal.com/admin/orders/10
    I, [2017-05-23T11:01:36.965267 #1060]  INFO -- : Completed 302 Found in 41ms (ActiveRecord: 2.3ms)
    I, [2017-05-23T11:01:37.013697 #1060]  INFO -- : Started GET "/admin/orders/10" for 89.160.235.185 at 2017-05-23 11:01:37 +0000
    I, [2017-05-23T11:01:37.014844 #1060]  INFO -- : Processing by Admin::OrdersController#show as HTML
    I, [2017-05-23T11:01:37.014925 #1060]  INFO -- :   Parameters: {"id"=>"10"}
    D, [2017-05-23T11:01:37.015893 #1060] DEBUG -- :   ^[[1m^[[36mCart Load (0.2ms)^[[0m  ^[[1mSELECT  "carts".* FROM "carts" WHERE "carts"."id" = $1 LIMIT 1^[[0m  [["$
    D, [2017-05-23T11:01:37.017087 #1060] DEBUG -- :   ^[[1m^[[35mAdminUser Load (0.2ms)^[[0m  SELECT  "admin_users".* FROM "admin_users" WHERE "admin_users"."id" = $1$
    D, [2017-05-23T11:01:37.017985 #1060] DEBUG -- :   ^[[1m^[[36mOrder Load (0.2ms)^[[0m  ^[[1mSELECT  "orders".* FROM "orders" WHERE "orders"."id" = $1 LIMIT 1^[[0m $
    D, [2017-05-23T11:01:37.046277 #1060] DEBUG -- :   ^[[1m^[[35mProductItem Load (0.9ms)^[[0m  SELECT "product_items".* FROM "product_items" WHERE "product_items"."o$
    D, [2017-05-23T11:01:37.048060 #1060] DEBUG -- :   ^[[1m^[[36mProduct Load (0.3ms)^[[0m  ^[[1mSELECT  "products".* FROM "products" WHERE "products"."id" = $1 LIMIT$
    I, [2017-05-23T11:01:37.055910 #1060]  INFO -- :   Rendered /home/deploy/hlinreykdal/shared/bundle/ruby/2.3.0/bundler/gems/activeadmin-0a5a15b88bff/app/views/activ$
    I, [2017-05-23T11:01:37.056193 #1060]  INFO -- : Completed 200 OK in 41ms (Views: 36.4ms | ActiveRecord: 1.7ms)
    I, [2017-05-23T11:01:39.569747 #1060]  INFO -- : Started GET "/admin/orders" for 89.160.235.185 at 2017-05-23 11:01:39 +0000
    I, [2017-05-23T11:01:39.571136 #1060]  INFO -- : Processing by Admin::OrdersController#index as HTML
    D, [2017-05-23T11:01:39.572365 #1060] DEBUG -- :   ^[[1m^[[35mCart Load (0.2ms)^[[0m  SELECT  "carts".* FROM "carts" WHERE "carts"."id" = $1 LIMIT 1  [["id", 45856$
    D, [2017-05-23T11:01:39.573735 #1060] DEBUG -- :   ^[[1m^[[36mAdminUser Load (0.2ms)^[[0m  ^[[1mSELECT  "admin_users".* FROM "admin_users" WHERE "admin_users"."id"$
    D, [2017-05-23T11:01:39.601594 #1060] DEBUG -- :   ^[[1m^[[35m (0.6ms)^[[0m  SELECT COUNT(count_column) FROM (SELECT  1 AS count_column FROM "orders" LIMIT 30 OFFS$
    D, [2017-05-23T11:01:39.602587 #1060] DEBUG -- :   ^[[1m^[[36mCACHE (0.0ms)^[[0m  ^[[1mSELECT COUNT(count_column) FROM (SELECT  1 AS count_column FROM "orders" LIM$
    D, [2017-05-23T11:01:39.603970 #1060] DEBUG -- :   ^[[1m^[[35m (0.3ms)^[[0m  SELECT COUNT(*) FROM "orders"
    D, [2017-05-23T11:01:39.605077 #1060] DEBUG -- :   ^[[1m^[[36mCACHE (0.0ms)^[[0m  ^[[1mSELECT COUNT(count_column) FROM (SELECT  1 AS count_column FROM "orders" LIM$
    D, [2017-05-23T11:01:39.607023 #1060] DEBUG -- :   ^[[1m^[[35mOrder Load (0.4ms)^[[0m  SELECT  "orders".* FROM "orders"  ORDER BY "orders"."id" desc LIMIT 30 OFFSE$
    D, [2017-05-23T11:01:39.630054 #1060] DEBUG -- :   ^[[1m^[[36mProductItem Load (0.4ms)^[[0m  ^[[1mSELECT "product_items".* FROM "product_items"^[[0m
I, [2017-05-23T11:01:39.675343 #1060]  INFO -- :   Rendered /home/deploy/hlinreykdal/shared/bundle/ruby/2.3.0/bundler/gems/activeadmin-0a5a15b88bff/app/views/activ$
I, [2017-05-23T11:01:39.675662 #1060]  INFO -- : Completed 200 OK in 104ms (Views: 98.1ms | ActiveRecord: 2.2ms)
I, [2017-05-23T11:01:42.003418 #1060]  INFO -- : Started GET "/admin/orders/10/edit" for 89.160.235.185 at 2017-05-23 11:01:42 +0000
I, [2017-05-23T11:01:42.005829 #1060]  INFO -- : Processing by Admin::OrdersController#edit as HTML
I, [2017-05-23T11:01:42.005923 #1060]  INFO -- :   Parameters: {"id"=>"10"}
D, [2017-05-23T11:01:42.007115 #1060] DEBUG -- :   ^[[1m^[[35mCart Load (0.2ms)^[[0m  SELECT  "carts".* FROM "carts" WHERE "carts"."id" = $1 LIMIT 1  [["id", 45856$
D, [2017-05-23T11:01:42.008543 #1060] DEBUG -- :   ^[[1m^[[36mAdminUser Load (0.2ms)^[[0m  ^[[1mSELECT  "admin_users".* FROM "admin_users" WHERE "admin_users"."id"$
D, [2017-05-23T11:01:42.009473 #1060] DEBUG -- :   ^[[1m^[[35mOrder Load (0.2ms)^[[0m  SELECT  "orders".* FROM "orders" WHERE "orders"."id" = $1 LIMIT 1  [["id", 1$
D, [2017-05-23T11:01:42.030642 #1060] DEBUG -- :   ^[[1m^[[36mCACHE (0.0ms)^[[0m  ^[[1mSELECT  "orders".* FROM "orders" WHERE "orders"."id" = $1 LIMIT 1^[[0m  [["i$
I, [2017-05-23T11:01:42.096028 #1060]  INFO -- :   Rendered /home/deploy/hlinreykdal/shared/bundle/ruby/2.3.0/bundler/gems/activeadmin-0a5a15b88bff/app/views/activ$
I, [2017-05-23T11:01:42.096369 #1060]  INFO -- : Completed 200 OK in 90ms (Views: 86.2ms | ActiveRecord: 0.6ms)
I, [2017-05-23T11:01:44.668194 #1060]  INFO -- : Started PATCH "/admin/orders/10" for 89.160.235.185 at 2017-05-23 11:01:44 +0000
I, [2017-05-23T11:01:44.674148 #1060]  INFO -- : Processing by Admin::OrdersController#update as HTML
I, [2017-05-23T11:01:44.674417 #1060]  INFO -- :   Parameters: {"utf8"=>" ^ ^ ", "authenticity_token"=>"NcVZXJWZ1pcKMTEmFFZmtY3HvY7oJH2G+WOxTpVXu6UbyOpe0NsC6DIX08q$
D, [2017-05-23T11:01:44.681838 #1060] DEBUG -- :   ^[[1m^[[35mCart Load (1.6ms)^[[0m  SELECT  "carts".* FROM "carts" WHERE "carts"."id" = $1 LIMIT 1  [["id", 45856$
D, [2017-05-23T11:01:44.687054 #1060] DEBUG -- :   ^[[1m^[[36mAdminUser Load (0.4ms)^[[0m  ^[[1mSELECT  "admin_users".* FROM "admin_users" WHERE "admin_users"."id"$
D, [2017-05-23T11:01:44.690370 #1060] DEBUG -- :   ^[[1m^[[35mOrder Load (0.4ms)^[[0m  SELECT  "orders".* FROM "orders" WHERE "orders"."id" = $1 LIMIT 1  [["id", 1$
D, [2017-05-23T11:01:44.694556 #1060] DEBUG -- :   ^[[1m^[[36m (0.1ms)^[[0m  ^[[1mBEGIN^[[0m
D, [2017-05-23T11:01:44.699039 #1060] DEBUG -- :   ^[[1m^[[35mSQL (0.4ms)^[[0m  UPDATE "orders" SET "shipped" = $1, "updated_at" = $2 WHERE "orders"."id" = $3  [["$
D, [2017-05-23T11:01:44.700660 #1060] DEBUG -- :   ^[[1m^[[36m (0.7ms)^[[0m  ^[[1mCOMMIT^[[0m
I, [2017-05-23T11:01:44.703571 #1060]  INFO -- : SMTP_ADDR: "smtp.gmail.com"
D, [2017-05-23T11:01:44.707271 #1060] DEBUG -- :   ^[[1m^[[35mProductItem Load (0.3ms)^[[0m  SELECT "product_items".* FROM "product_items" WHERE "product_items"."o$
D, [2017-05-23T11:01:44.708898 #1060] DEBUG -- :   ^[[1m^[[36mProduct Load (0.3ms)^[[0m  ^[[1mSELECT  "products".* FROM "products" WHERE "products"."id" = $1 LIMIT$
I, [2017-05-23T11:01:44.709746 #1060]  INFO -- :   Rendered order_notifier/shipped.html.erb within layouts/mailer (4.5ms)
D, [2017-05-23T11:01:44.711077 #1060] DEBUG -- :
OrderNotifier#shipped: processed outbound mail in 8.1ms
I, [2017-05-23T11:01:44.739622 #1060]  INFO -- :
Sent mail to dadih32@gmail.com (28.3ms)
D, [2017-05-23T11:01:44.739727 #1060] DEBUG -- : Date: Tue, 23 May 2017 11:01:44 +0000
From: =?UTF-8?B?SGzDrW4=?= Reykdal Concept Store <hlin@hlinreykdal.com>
To: dadih32@gmail.com
Message-ID: <59241698ae5b8_4242ad89726e92861420@hlinreykdal.mail>
Subject: Order Shipped
Mime-Version: 1.0
Content-Type: text/html;
 charset=UTF-8
Content-Transfer-Encoding: 7bit

<html>
  <body>
    <h1>Your Order has been shipped</h1>

<h3>Dear dadi </h3>


<p>
 Your order has been shipped to your address, please contact store@hlinreykdal.com for further information.
</p>

<p> Thank You </p>

        <ul>
                <li>
                        FOLLY MATCHBOOK NAIL FILES&times;1
                </li>


        </ul>

<p> Thank You </p>





  </body>
</html>

I, [2017-05-23T11:01:44.741054 #1060]  INFO -- : Completed 500 Internal Server Error in 66ms (ActiveRecord: 4.2ms)
F, [2017-05-23T11:01:44.743481 #1060] FATAL -- :
SocketError (getaddrinfo: Name or service not known):
  app/admin/order.rb:6:in `block (2 levels) in <top (required)>'

I, [2017-05-23T11:10:08.863192 #1060]  INFO -- : Started GET "/products/41" for 164.132.161.46 at 2017-05-23 11:10:08 +0000
I, [2017-05-23T11:10:08.876373 #1060]  INFO -- : Processing by ProductsController#show as */*
I, [2017-05-23T11:10:08.876536 #1060]  INFO -- :   Parameters: {"id"=>"41"}
D, [2017-05-23T11:10:08.881123 #1060] DEBUG -- :   ^[[1m^[[35mCart Load (0.7ms)^[[0m  SELECT  "carts".* FROM "carts" WHERE "carts"."id" = $1 LIMIT 1  [["id", nil]]
D, [2017-05-23T11:10:08.882685 #1060] DEBUG -- :   ^[[1m^[[36m (0.2ms)^[[0m  ^[[1mBEGIN^[[0m
D, [2017-05-23T11:10:08.887770 #1060] DEBUG -- :   ^[[1m^[[35mSQL (1.3ms)^[[0m  INSERT INTO "carts" ("created_at", "updated_at") VALUES ($1, $2) RETURNING "id"  [[$
D, [2017-05-23T11:10:08.890018 #1060] DEBUG -- :   ^[[1m^[[36m (0.7ms)^[[0m  ^[[1mCOMMIT^[[0m
D, [2017-05-23T11:10:08.893274 #1060] DEBUG -- :   ^[[1m^[[35mProduct Load (1.2ms)^[[0m  SELECT  "products".* FROM "products" WHERE "products"."slug" = $1  ORDER B$
D, [2017-05-23T11:10:08.894865 #1060] DEBUG -- :   ^[[1m^[[36mProduct Load (0.4ms)^[[0m  ^[[1mSELECT  "products".* FROM "products" WHERE "products"."id" = $1 LIMIT$
D, [2017-05-23T11:10:08.900733 #1060] DEBUG -- :   ^[[1m^[[35mLabel Load (1.2ms)^[[0m  SELECT  "labels".* FROM "labels" WHERE "labels"."id" = $1 LIMIT 1  [["id", 8$
D, [2017-05-23T11:10:08.907954 #1060] DEBUG -- :   ^[[1m^[[36mProduct Load (0.6ms)^[[0m  ^[[1mSELECT  "products".* FROM "products" WHERE "products"."category_id" =$
I, [2017-05-23T11:10:08.916955 #1060]  INFO -- :   Rendered products/show.html.erb within layouts/application (18.7ms)
D, [2017-05-23T11:10:08.920965 #1060] DEBUG -- :   ^[[1m^[[35mCategory Load (0.8ms)^[[0m  SELECT "categories".* FROM "categories"
D, [2017-05-23T11:10:08.924524 #1060] DEBUG -- :   ^[[1m^[[36mLabel Load (0.3ms)^[[0m  ^[[1mSELECT "labels".* FROM "labels"^[[0m
D, [2017-05-23T11:10:08.929926 #1060] DEBUG -- :   ^[[1m^[[35m (0.3ms)^[[0m  SELECT COUNT(*) FROM "product_items" WHERE "product_items"."cart_id" = $1  [["cart_id"$
I, [2017-05-23T11:10:08.930159 #1060]  INFO -- :   Rendered application/_navbar.html.erb (10.7ms)
I, [2017-05-23T11:10:08.931046 #1060]  INFO -- :   Rendered application/_message.html.erb (0.2ms)
I, [2017-05-23T11:10:08.932261 #1060]  INFO -- :   Rendered emaillist/_email.html.erb (0.6ms)
I, [2017-05-23T11:10:08.932381 #1060]  INFO -- :   Rendered application/_notifications.html.erb (0.9ms)
I, [2017-05-23T11:10:08.936424 #1060]  INFO -- :   Rendered application/_footer.html.erb (3.5ms)
I, [2017-05-23T11:10:08.936826 #1060]  INFO -- : Completed 200 OK in 60ms (Views: 36.7ms | ActiveRecord: 7.6ms)
I, [2017-05-23T11:12:35.005157 #1060]  INFO -- : Started GET "/labels/10" for 66.249.65.74 at 2017-05-23 11:12:35 +0000
I, [2017-05-23T11:12:35.040137 #1060]  INFO -- : Processing by LabelsController#show as HTML
I, [2017-05-23T11:12:35.040544 #1060]  INFO -- :   Parameters: {"id"=>"10"}
D, [2017-05-23T11:12:35.049755 #1060] DEBUG -- :   ^[[1m^[[36mCart Load (0.8ms)^[[0m  ^[[1mSELECT  "carts".* FROM "carts" WHERE "carts"."id" = $1 LIMIT 1^[[0m  [["$
D, [2017-05-23T11:12:35.052776 #1060] DEBUG -- :   ^[[1m^[[35m (0.2ms)^[[0m  BEGIN
D, [2017-05-23T11:12:35.060048 #1060] DEBUG -- :   ^[[1m^[[36mSQL (0.9ms)^[[0m  ^[[1mINSERT INTO "carts" ("created_at", "updated_at") VALUES ($1, $2) RETURNING "id$
D, [2017-05-23T11:12:35.061486 #1060] DEBUG -- :   ^[[1m^[[35m (0.6ms)^[[0m  COMMIT
D, [2017-05-23T11:12:35.065373 #1060] DEBUG -- :   ^[[1m^[[36mLabel Load (0.4ms)^[[0m  ^[[1mSELECT  "labels".* FROM "labels" WHERE "labels"."id" = $1 LIMIT 1^[[0m $
I, [2017-05-23T11:12:35.067624 #1060]  INFO -- : Completed 404 Not Found in 27ms (ActiveRecord: 3.0ms)
F, [2017-05-23T11:12:35.069957 #1060] FATAL -- :
ActiveRecord::RecordNotFound (Couldn't find Label with 'id'=10):
  app/controllers/labels_controller.rb:21:in `set_label'

Are you sure that `ENV["SMTP_ADDRESS"]` is not `nil`? See also [this issue](http://stackoverflow.com/questions/38677793/errnoeconnrefused-connection-refused-connect2-for-nil-port-587-for-rail) (with the same error). — Matouš Borák, May 21 '17 at 19:03
I'm pretty sure it is not nil... in my `application.yml` it is set as `SMTP_ADDRESS: "smtp.gmail.com"` — DaudiHell, May 21 '17 at 21:25
OK and how do you convert the `application.yml` to `ENV` variables? Are you using the [figaro gem](https://github.com/laserlemon/figaro) or something like that? Can you pls confirm that the variable is indeed set by showing `puts ENV["SMTP_ADDRESS"].inspect` just before sending the mail? — Matouš Borák, May 22 '17 at 04:44
I'm using `figaro gem`.... this is the output `irb(main):001:0> puts ENV["SMTP_ADDRESS"].inspect "smtp.gmail.com" => nil irb(main):002:0> ` — DaudiHell, May 22 '17 at 05:11
OK and can you put the same inspect inside the `production.rb` file, please? I suspect that the Figaro gem is initialized / or the `application.yml` file read _after_ running through the `production.rb` file. — Matouš Borák, May 22 '17 at 05:35
ok if I do that I get this error now form the `production.log` : `SocketError (getaddrinfo: Name or service not known): app/admin/order.rb:6:in `block (2 levels) in '` — DaudiHell, May 22 '17 at 15:12
Either read the output from the console (`puts` prints to console), or please change the `production.log` debug line to: `Rails.logger.info "SMTP_ADDR: #{ENV["SMTP_ADDRESS"].inspect}"` and paste here the output from the log. I expect that it will be blank (`nil`). Thanks. — Matouš Borák, May 22 '17 at 15:28
here it is `irb(main):002:0> Rails.logger.info "SMTP_ADDR: #{ENV["SMTP_ADDRESS"].inspect}" SMTP_ADDR: "smtp.gmail.com" => true ` — DaudiHell, May 22 '17 at 16:03
Sorry, I did not mean 'rails c' console but stdout console. If you don't know what I mean, please use the line in priduction.rb and read the result from the production.logm thanks, — Matouš Borák, May 22 '17 at 16:15
If I add the line to production.rb the deploy breaks with `undefined method info` — DaudiHell, May 22 '17 at 16:36
OK I have to say I did not know that logger is not available yet in the environment files. I tested it and indeed it's not. However you can easily configure one right away: in the `production.log`, replace the log line with two lines: `config.logger = ActiveSupport::Logger.new('/tmp/foo.log')` and `config.logger.info "SMTP_ADDR: #{ENV["SMTP_ADDRESS"].inspect}"`, deploy and inspect the `/tmp/foo.log` file content. — Matouš Borák, May 23 '17 at 05:06
I don´t see any `foo.log` though in the `deploy@superapp:~/superapp/current/tmp$` — DaudiHell, May 23 '17 at 11:29
It should be present in `/tmp`, the server-wide tmp directory. Try `cat /tmp/foo.log`. — Matouš Borák, May 23 '17 at 11:52
thank you, please see my update....I added the ` foo.log`output to my question. I had to shorten it due to length.... — DaudiHell, May 23 '17 at 14:07
OK, thanks, but I'm sorry, my original assumption was wrong and the config variable is indeed set properly. Now, when you log on the server, can you do `host smtp.gmail.com` and get the IP address properly without errors? Can you also pls paste the content of `order.rb`, especially around line 6? — Matouš Borák, May 23 '17 at 14:13
thanks man... here isn the output of `host smtp.gmail.com` `smtp.gmail.com is an alias for gmail-smtp-msa.l.google.com. gmail-smtp-msa.l.google.com has address 74.125.71.108 gmail-smtp-msa.l.google.com has address 74.125.71.109 gmail-smtp-msa.l.google.com has IPv6 address 2a00:1450:400c:c02::6d` The order.rb has been added to the question — DaudiHell, May 23 '17 at 21:09
Thank you, so DNS also works ok. Now, can you do `telnet smtp.gmail.com 587` without connection errors (run this on the production server, of course)? — Matouš Borák, May 23 '17 at 21:16
It works `Trying 74.125.71.108... Connected to gmail-smtp-msa.l.google.com. Escape character is '^]'. 220 smtp.gmail.com ESMTP k22sm2411466wrc.12 - gsmtp` — DaudiHell, May 23 '17 at 21:31
Hmmm, then I guess it must be something else... Could you pls edit `config/initializers/backtrace_silencers.rb` and uncomment the `remove_silencers!` line, deploy and paste here the full stack trace fo the error? Thanks. — Matouš Borák, May 24 '17 at 05:16
Are you sure you ran the project with the silencers removed? The output from update3 has no new information, there should be many more lines with the stack trace... — Matouš Borák, May 24 '17 at 09:25
Yes I uncommented this line `Rails.backtrace_cleaner.remove_silencers!` I've restarted the server please see update-3 again — DaudiHell, May 24 '17 at 09:49
I added another question about this: https://stackoverflow.com/questions/44155659/serious-problems-sending-mails-via-actionmailer-in-production-ror — DaudiHell, May 24 '17 at 10:25
thank you for all your help and time... this problem has been solved https://stackoverflow.com/questions/44155659/serious-problems-sending-mails-via-actionmailer-in-production-ror/44156539#44156539 — DaudiHell, May 24 '17 at 12:42
That's great news! I have to say I was slowly getting a bit desperate as nothung made sense to me... So, in the end, was it all about the `.inspect` that you somehow did not include in this original question? ;-) Even if so, never mind and I'm glad that you've resolved the issue! — Matouš Borák, May 24 '17 at 17:26

Port 587 blocked on Ubuntu VPS... can't unblock it...what to do?

0 Answers0