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

Meteor email keeps SMTP connection opened and causes error with some email providers #8591

Closed
HoptimizeME opened this issue Apr 13, 2017 · 39 comments
Assignees

Comments

@HoptimizeME
Copy link

HoptimizeME commented Apr 13, 2017

RE: #8425 #8495

@edemaine @abernix

Since the "Upgrade to mailcomposer@4 and smtp-connection@2." I have issues with SMTP connections.

The MDG-email package keeps the SMTP connection opened. It never send a SMTP "QUIT" command.

Some email providers, for instance Amazon SES, don't like people to keep their connections opened. Amazon SES close the SMTP connection after 10 seconds with a timeout message and when it happens I get this error:

Error: Unexpected Response: 421 Timeout waiting for data from client.

This error wouldn't happen if you would close the SMTP connection after having sent the email.

Also, this error message is very hard to process in a try/catch because it's impossible to know if the mail has been sent correctly prior the timeout. In my particular case, the "421 Timeout" happens after the "250 Ok" (that follows the email being sent). So I could probably ignore the error ... but if the "421 Timeout" was real, I would miss the chance to retry sending the email.

(edit: I am not sure if the previous package also kept the SMTP connection opened and simply ignored the resulting error)

@rodrigok
Copy link

We are experiencing the same problem here at Rocket.Chat

@HoptimizeME
Copy link
Author

Downgrading to meteor add email@=1.1.18 helps in the meantime.

@engelgabriel
Copy link
Contributor

Thanks @HoptimizeME we used your temporary fix on RocketChat/Rocket.Chat#6678

@edemaine
Copy link
Contributor

I think I've figured out why things have behaved differently from old, in my changes in #8495. Namely, the old way used simplesmtp's pool functionality to keep SMTP connections open, but the smtp-connection package I switched to does not have this built in. Nodemailer offers alternative pool mechanisms, which I will explore. Hopefully can get back to full old functionality again with modern packages -- meanwhile, sorry about this!

@edemaine
Copy link
Contributor

In other good news, the latest Nodemailer also just switched back to MIT license, so this will hopefully simplify everything... (see #8425 for the messy old story)

@etyp
Copy link

etyp commented Apr 14, 2017

Experiencing the same issue here. Having issues running the meteor add email@=1.1.18 command. We're getting constraints issues:

While selecting package versions:
error: No version of email satisfies all constraints: @=1.1.18, @1.2.0
Constraints on package "email":
* email@=1.1.18 <- top level
* email@1.2.0 <- top level
* email@1.2.0 <- accounts-password 1.3.5
* email@1.0.2 <- meteorhacks:kadira 2.5.0

Tried modifying the other package versions like in the RocketChat commit (moving accounts-password down to 1.3.4), but still experiencing issues.

Anybody know how to resolve this?

Had to step down from Meteor 1.4.4 to resolve.

This is really horrible for us as it caused all mail services to break/time out and eventually have keys revoked. Have patched in the meantime, but @abernix I think this could turn out to be a pretty serious issue as people upgrade to 1.4.4

@edemaine
Copy link
Contributor

Might be worth a Meteor release that points back to email@1.1.18... meanwhile, I'm hoping to have the bug-fixed email@1.2.1 by end of weekend. (complications in #8597)

@etyp
Copy link

etyp commented Apr 15, 2017

@edemaine any luck with the email package updates?

@edemaine
Copy link
Contributor

Yes, I've finished a draft here: https://github.com/edemaine/meteor
The test suite passes, but I need to test actual SMTP server usage. If anyone gets a chance to test as well, that'd be nice!

@edemaine
Copy link
Contributor

Specifically, you can copy the packages/email directory into your project's packages directory, then meteor add email@1.2.1, to try the updated version. So far so good on my end, but please test in a noncritical environment!

@etyp
Copy link

etyp commented Apr 16, 2017

Awesome, will give this a try in the morning on my side. Thanks @edemaine

edemaine added a commit to edemaine/meteor that referenced this issue Apr 16, 2017
* Most critically, use a pool instead of direct SMTP connection,
  to handle dropped connections and increase throughput,
  like mail module 1.1.  (meteor#8591)
* New nodemailer's sendMail wants an options object, not a MailComposer
  object.  Luckily, a MailComposer object has a "mail" field that
  remembers the original options, so we can keep original behavior.
* However, we no longer support the mailComposer option set to a compiled
  MailComposer object (functionality that was briefly added in 1.2.0).
* nodemailer does SMTP URL parsing now automatically for us, simplifying code.
* Tests' outputs now end with additional "\r\n"
* Drop underscore package dependency (no longer needed)
@HoptimizeME
Copy link
Author

Good morning Erik! I tried your devel package and it seems to work well.

I did my tests using Amazon SES.

When the email is sent, I see the connection to the mail server staying established for about 10 seconds. I understand this package doesn't QUIT the SMTP connection and Amazon times out after 10 seconds. At least the connection closing is handled properly because it doesn't throw an error as smtp-connection was doing.

I also tried to send 3 emails in the same connection and it worked well.

Thanks!!

@etyp
Copy link

etyp commented Apr 16, 2017

I've also just tried and unfortunately it seems that I still have issues sending through the Sendgrid STMP API.

My question is, like @HoptimizeME mentioned above, if this doesn't QUIT the SMTP connection, is that the likely reason for Sendgrid smtp failing?

If so, I'm assuming the switch to modern nodemailer in this case mainly helps by handling the timeout error, correct?

@HoptimizeME
Copy link
Author

@etyp do you also have issues sending emails with email@1.1.18 ?

I'm asking that because I'm mostly convinced email@1.1.18 had the same behaviour:

don't send QUIT and wait for the mail server to drop the connection (if it ever does)

When I send email with email@1.1.18 the connection stays opened for 10 seconds after the email has been sent. So even though I didn't add debug prints in the code to confirm, I assume it's dropping the connection when the Amazon SES 10 seconds timeout kicks in.

p.s. *rant* I hate encrypted connection, so hard to debug with tcpdump ...

@etyp
Copy link

etyp commented Apr 16, 2017

@HoptimizeME nope, didn't have the same issues with email@1.1.18 ---- if that version had the same behavior, then I'm curious what the jump 1.2.0 changed to cause this 🤔

Sendgrid also has unreliable documentation/error verbosity, so I'll have to poke around a bit more to see.

@edemaine
Copy link
Contributor

Indeed, 1.1.18 also maintained a pool of connections (up to 5, I think), and 1.2.1 should restore this behavior. Please ignore 1.2.0, which didn't use a pool, and instead maintained a single connection. But 1.2.1 should restore the behavior of 1.1.18, except that now it's using a much newer version of Nodemailer.

@HoptimizeME, I'm glad 1.2.1 is working for you. I've also done a bunch of tests, with several minutes or even an hour between sending messages, and 1.2.1 seems to have had no problem with reconnecting as needed.

@etyp, could you elaborate on the problem you're having with Sendgrid SMTP? Do you get an error, or hanging behavior, or something else?

@etyp
Copy link

etyp commented Apr 16, 2017

@edemaine sure - so with Sendgrid SMTP, no errors are thrown in the Meteor app, but once the email comes through, the subject, body, etc. is completely blank.

I've replaced our Sendgrid SMTP API usage throughout the app withe the HTTP API as a stop gap, and would suggest anybody who has this same issue do the same until we can get to the bottom of this.

Unfortunately, I don't have enough time today to dig into the issue with Sendgrid any further, but will open a ticket with them first thing tomorrow to help diagnose what they might be receiving on their end that causes the empty subject line and email.

Sorry, I wish I had more time today - I'll provide updates as soon as possible.

@edemaine
Copy link
Contributor

@etyp Interesting. The generated email format in the new Nodemailer is different from the old one, though my reading of the spec was that this format was more correct than old. But perhaps there's an incompatibility... Can you paste the exact message that came through? Were From and To headers also blank?

@engelgabriel
Copy link
Contributor

We are waiting on this to close:
RocketChat/Rocket.Chat#6705

@edemaine
Copy link
Contributor

@engelgabriel Would you be able to test the email package from https://github.com/edemaine/meteor/tree/devel/packages/email to see if it works in your scenario(s)?

@engelgabriel
Copy link
Contributor

I've asked @rodrigok to test it and will get back to you. Would that fix be released soon?

@abernix
Copy link
Contributor

abernix commented Apr 17, 2017

@engelgabriel We can release the email package separate from entire Meteor releases. Your (or @rodrigok's) help confirming that the update works will certainly make that process go quicker.

@edemaine
Copy link
Contributor

Oh, right, forgot that was possible. That might be worth doing now; my tests and @HoptimizeME's suggest that 1.2.1 is reasonably functional -- definitely a major improvement over 1.2.0. If we end up needing to make more changes, or revert all the way back to 1.1.18, we can just increment the version number again...

@rodrigok
Copy link

@edemaine It's working for us using your version 1.2.1

@abernix abernix self-assigned this Apr 17, 2017
abernix pushed a commit that referenced this issue Apr 17, 2017
* Switch to modern nodemailer 4, Node 4 version. Fix #8591

* Most critically, use a pool instead of direct SMTP connection,
  to handle dropped connections and increase throughput,
  like mail module 1.1.  (#8591)
* New nodemailer's sendMail wants an options object, not a MailComposer
  object.  Luckily, a MailComposer object has a "mail" field that
  remembers the original options, so we can keep original behavior.
* However, we no longer support the mailComposer option set to a compiled
  MailComposer object (functionality that was briefly added in 1.2.0).
* nodemailer does SMTP URL parsing now automatically for us, simplifying code.
* Tests' outputs now end with additional "\r\n"
* Drop underscore package dependency (no longer needed)

* General formatting/style cleanup for `packages/email`.

* snake_cased => camelCased for some local variables.
* Added curly-brackets to `if`s.
* Removed trailing spaces.
* Removed commented-out code.
* Removed older doc text and changed some links.

* Get rid of back-and-forth assigning of `mailUrlString`.
@abernix abernix mentioned this issue Apr 17, 2017
@abernix
Copy link
Contributor

abernix commented Apr 17, 2017

Thanks to the great work by @edemaine in #8605, this should be fixed with email@1.2.1. If those experiencing a problem have a minute to test it (after removing the copied version from your packages directory), please do and report back if it's working properly. Getting the update should be as simple as:

meteor update

Closing, but happy to reopen if this persists.

/cc @rodrigok

@HoptimizeME
Copy link
Author

The real published package (email@1.2.1) works well for me.

Thanks @edemaine for the quick fix :)

@YannLeBihan
Copy link

Updating Meteor has fixed the issue on all my sites, many thanks !

@michaelcbrook
Copy link

I'm going to jump in here. I'm still having issues with email@1.2.1. I'm getting Greeting never received after the connection times out around 15-20 seconds. Here is my console.log and a stack trace:

{ [Error: Greeting never received] code: 'ETIMEDOUT', command: 'CONN' }

Exception while invoking method 'account.signup' Error: Greeting never received
    at Object.Future.wait (/home/michael/.meteor/packages/meteor-tool/.1.4.4_1.z6ks5d++os.linux.x86_64+web.browser+web.cordova/mt-os.linux.x86_64/dev_bundle/server-lib/node_modules/fibers/future.js:449:15)
    at Mail._syncSendMail (packages/meteor.js:213:24)
    at smtpSend (packages/email.js:110:13)
    at Object.Email.send (packages/email.js:168:5)
    at sendEmail (imports/startup/server/common.js:45:9)
    at AccountsServer.accountsOnCreateUser [as _onCreateUserHook] (imports/startup/server/accounts.js:137:3)
    at AccountsServer.Ap.insertUserDoc (packages/accounts-base/accounts_server.js:1310:21)
    at createUser (packages/accounts-password/password_server.js:1050:25)
    at AccountsServer.Accounts.createUser (packages/accounts-password/password_server.js:1119:10)
    at [object Object].Meteor.methods.account.signup (imports/api/server/methods.js:40:12)
    - - - - -
    at SMTPConnection._formatError (/home/michael/.meteor/packages/email/.1.2.1.mj8x0++os+web.browser+web.cordova/npm/node_modules/node4mailer/lib/smtp-connection/index.js:558:19)
    at SMTPConnection._onError (/home/michael/.meteor/packages/email/.1.2.1.mj8x0++os+web.browser+web.cordova/npm/node_modules/node4mailer/lib/smtp-connection/index.js:531:20)
    at [object Object].<anonymous> (/home/michael/.meteor/packages/email/.1.2.1.mj8x0++os+web.browser+web.cordova/npm/node_modules/node4mailer/lib/smtp-connection/index.js:472:22)
    at Timer.listOnTimeout (timers.js:92:15)

This all started when I upgraded to Meteor 1.4.4.1 and was having the issue you all mentioned here with email@1.2.0. But upgrading to email@1.2.1 then produced this error instead. Also worth noting I'm using Amazon SES SMTP.

I didn't have this issue in earlier versions, but now after upgrading Meteor, package constraints make it impossible for me to downgrade the email package in isolation (like @etyp mentioned). Without a fix, I'm going to have to recreate my entire project in a previous Meteor version.

@HoptimizeME
Copy link
Author

HoptimizeME commented Apr 18, 2017

Using Amazon SES SMTP here and it works well with email@1.2.1

@michaelcbrook Which SMTP zone? smtp or smtps? Which port? What does your MAIL_URL look like? Mine looks like this:

smtp://my_username:my_password@email-smtp.us-west-2.amazonaws.com:587/

Try to add debug to the MAIL_URL. The debug will appear in your server's console. You might be able to better see what is happening.

smtp://my_username:my_password@email-smtp.us-west-2.amazonaws.com:587/?logger=true&debug=true

@HoptimizeME
Copy link
Author

Side note: I have just realized that the pool option may now be selectively disabled (it is activated by default in the email@1.2.1 package) and, when disabled, the SMTP connection is QUIT right after sending the email.

smtp://my_username:my_password@email-smtp.us-west-2.amazonaws.com:587/?pool=false

Personally, I will keep it activated on Amazon SES SMTP even though Amazon times out and closes the pool after 10 seconds. At least, if I have bursts of emails, they will enjoy using the SMTP channel that is already opened.

Thanks @edemaine for the complete handling of the mailUrl string. That's a very nice addition to email@1.2.1!

@michaelcbrook
Copy link

@HoptimizeME Here is my MAIL_URL format:

smtp://<username>:<password>@email-smtp.us-east-1.amazonaws.com:465

And after enabling debugging, this is the result:

DEBUG Creating transport: node4mailer (4.0.2; +https://github.com/edemaine/node4mailer; SMTP/4.0.2[client:4.0.2])
DEBUG Sending mail using SMTP/4.0.2[client:4.0.2]
INFO  [PVnXOXMIl9w] Connection established to 23.21.91.54:465
ERROR [PVnXOXMIl9w] Greeting never received
DEBUG [PVnXOXMIl9w] Closing connection to the server using "end"
ERROR Send Error: Greeting never received
	<error thrown here>
INFO  [PVnXOXMIl9w] Connection closed

@edemaine
Copy link
Contributor

edemaine commented Apr 18, 2017

Aha! I'm 90% certain that should be smtps://<username>:<password>@email-smtp.us-east-1.amazonaws.com:465 (changing smtp: to smtps:).

email@1.1.18 automatically switched from smtp: to smtps: when the port number was 465. I viewed that as a bug, but it's clearly affecting users -- hopefully the only issue? Anyway, for now, change smtp: to smtps: as it should be and see if that works.

@michaelcbrook
Copy link

That worked flawlessly! Thanks @edemaine!

abernix pushed a commit that referenced this issue Apr 25, 2017
* Switch to modern nodemailer 4, Node 4 version. Fix #8591

* Most critically, use a pool instead of direct SMTP connection,
  to handle dropped connections and increase throughput,
  like mail module 1.1.  (#8591)
* New nodemailer's sendMail wants an options object, not a MailComposer
  object.  Luckily, a MailComposer object has a "mail" field that
  remembers the original options, so we can keep original behavior.
* However, we no longer support the mailComposer option set to a compiled
  MailComposer object (functionality that was briefly added in 1.2.0).
* nodemailer does SMTP URL parsing now automatically for us, simplifying code.
* Tests' outputs now end with additional "\r\n"
* Drop underscore package dependency (no longer needed)

* General formatting/style cleanup for `packages/email`.

* snake_cased => camelCased for some local variables.
* Added curly-brackets to `if`s.
* Removed trailing spaces.
* Removed commented-out code.
* Removed older doc text and changed some links.

* Get rid of back-and-forth assigning of `mailUrlString`.
abernix pushed a commit that referenced this issue Apr 25, 2017
* Switch to modern nodemailer 4, Node 4 version. Fix #8591

* Most critically, use a pool instead of direct SMTP connection,
  to handle dropped connections and increase throughput,
  like mail module 1.1.  (#8591)
* New nodemailer's sendMail wants an options object, not a MailComposer
  object.  Luckily, a MailComposer object has a "mail" field that
  remembers the original options, so we can keep original behavior.
* However, we no longer support the mailComposer option set to a compiled
  MailComposer object (functionality that was briefly added in 1.2.0).
* nodemailer does SMTP URL parsing now automatically for us, simplifying code.
* Tests' outputs now end with additional "\r\n"
* Drop underscore package dependency (no longer needed)

* General formatting/style cleanup for `packages/email`.

* snake_cased => camelCased for some local variables.
* Added curly-brackets to `if`s.
* Removed trailing spaces.
* Removed commented-out code.
* Removed older doc text and changed some links.

* Get rid of back-and-forth assigning of `mailUrlString`.
dandv pushed a commit to Wylio/meteor-mandrill that referenced this issue May 8, 2017
Please change the readme to uncomment the port and host and to use smtps.

meteor/meteor#8591

This is the solution that worked for me in regards to this bug.
@ianpogi5
Copy link

Hi I upgraded my meteor version from 1.4.2.* to 1.4.4.2 now I'm having the same error.

Here's the debug logs:

[2017-05-24 12:29:06] DEBUG Creating transport: node4mailer (4.0.2; +https://github.com/edemaine/node4mailer; SMTP/4.0.2[client:4.0.2])
[2017-05-24 12:29:06] DEBUG Sending mail using SMTP/4.0.2[client:4.0.2]
[2017-05-24 12:29:06] INFO  [qmILpsjqcXM] Connection established to 23.23.104.248:587
[2017-05-24 12:29:07] DEBUG [qmILpsjqcXM] S: 220 email-smtp.amazonaws.com ESMTP SimpleEmailService-2110753669 vT7azsvDxzZWxy1Cqt0e
[2017-05-24 12:29:07] DEBUG [qmILpsjqcXM] C: EHLO mydomain.com
[2017-05-24 12:29:07] DEBUG [qmILpsjqcXM] S: 250-email-smtp.amazonaws.com
[2017-05-24 12:29:07] DEBUG [qmILpsjqcXM] S: 250-8BITMIME
[2017-05-24 12:29:07] DEBUG [qmILpsjqcXM] S: 250-SIZE 10485760
[2017-05-24 12:29:07] DEBUG [qmILpsjqcXM] S: 250-STARTTLS
[2017-05-24 12:29:07] DEBUG [qmILpsjqcXM] S: 250-AUTH PLAIN LOGIN
[2017-05-24 12:29:07] DEBUG [qmILpsjqcXM] S: 250 Ok
[2017-05-24 12:29:07] DEBUG [qmILpsjqcXM] C: STARTTLS
[2017-05-24 12:29:07] DEBUG [qmILpsjqcXM] S: 220 Ready to start TLS
[2017-05-24 12:29:08] INFO  [qmILpsjqcXM] Connection upgraded with STARTTLS
[2017-05-24 12:29:08] DEBUG [qmILpsjqcXM] C: EHLO mydomain.com
[2017-05-24 12:29:08] DEBUG [qmILpsjqcXM] S: 250-email-smtp.amazonaws.com
[2017-05-24 12:29:08] DEBUG [qmILpsjqcXM] S: 250-8BITMIME
[2017-05-24 12:29:08] DEBUG [qmILpsjqcXM] S: 250-SIZE 10485760
[2017-05-24 12:29:08] DEBUG [qmILpsjqcXM] S: 250-STARTTLS
[2017-05-24 12:29:08] DEBUG [qmILpsjqcXM] S: 250-AUTH PLAIN LOGIN
[2017-05-24 12:29:08] DEBUG [qmILpsjqcXM] S: 250 Ok
[2017-05-24 12:29:08] DEBUG [qmILpsjqcXM] SMTP handshake finished
[2017-05-24 12:29:08] DEBUG [qmILpsjqcXM] C: AUTH PLAIN ******************
[2017-05-24 12:29:08] DEBUG [qmILpsjqcXM] S: 235 Authentication successful.
[2017-05-24 12:29:08] INFO  [qmILpsjqcXM] User "**************" authenticated
[2017-05-24 12:29:08] INFO  Sending message <8348bdf4-61ad-a120-6371-60f622beb79d@mydomain.com> to <ian@mydomain.com>
[2017-05-24 12:29:08] DEBUG [qmILpsjqcXM] C: MAIL FROM:<sender@mydomain.com>
/home/ubuntu/app/programs/server/npm/node_modules/meteor/email/node_modules/node4mailer/lib/mime-node/last-newline.js:28
        this.push(Buffer.from('\r\n'));
                         ^
TypeError: this is not a typed array.
    at Function.from (native)

My MAIL_URL is smtp://user:password@email-smtp.us-east-1.amazonaws.com:587

email version 1.2.1

Any ideas?

@ianpogi5
Copy link

ok found the issue. I was using nodejs 4.2.6 which comes with the official ubuntu repository. I updated to nodejs 4.8.3 and the error was gone.

@edemaine
Copy link
Contributor

@ianpogi5 FWIW, email@1.2.2 should work on older Nodes.

@juvyc
Copy link

juvyc commented Jun 21, 2017

Not sure what things need to do with this error, I cant send email.

I20170621-01:05:33.600(0)? Exception while invoking method '_addEmails' Error: Connection timeout
I20170621-01:05:33.602(0)?     at Object.Future.wait (/home/ubuntu/.meteor/packages/meteor-tool/.1.5.0.18smhjv++os.linux.x86_64+web.browser+web.cordova/mt-os.linux.x86_64/dev_bundle/server-lib/node_modules/fibers/future.js:449:15)
I20170621-01:05:33.603(0)?     at Mail._syncSendMail (packages/meteor.js:213:24)
I20170621-01:05:33.603(0)?     at smtpSend (packages/email.js:116:13)
I20170621-01:05:33.604(0)?     at Object.Email.send (packages/email.js:174:5)
I20170621-01:05:33.605(0)?     at [object Object].Meteor.methods._addEmails (server/global/email.js:64:19)
I20170621-01:05:33.606(0)?     at maybeAuditArgumentChecks (packages/ddp-server/livedata_server.js:1737:12)
I20170621-01:05:33.606(0)?     at packages/ddp-server/livedata_server.js:719:19
I20170621-01:05:33.606(0)?     at [object Object]._.extend.withValue (packages/meteor.js:1122:17)
I20170621-01:05:33.607(0)?     at packages/ddp-server/livedata_server.js:717:40
I20170621-01:05:33.608(0)?     at [object Object]._.extend.withValue (packages/meteor.js:1122:17)
I20170621-01:05:33.608(0)?     - - - - -
I20170621-01:05:33.609(0)?     at SMTPConnection._formatError (/home/ubuntu/.meteor/packages/email/.1.2.3.1as4pux++os+web.browser+web.cordova/npm/node_modules/node4mailer/lib/smtp-connection/index.js:558:19)
I20170621-01:05:33.612(0)?     at SMTPConnection._onError (/home/ubuntu/.meteor/packages/email/.1.2.3.1as4pux++os+web.browser+web.cordova/npm/node_modules/node4mailer/lib/smtp-connection/index.js:531:20)
I20170621-01:05:33.613(0)?     at [object Object].<anonymous> (/home/ubuntu/.meteor/packages/email/.1.2.3.1as4pux++os+web.browser+web.cordova/npm/node_modules/node4mailer/lib/smtp-connection/index.js:249:18)
I20170621-01:05:33.613(0)?     at Timer.listOnTimeout (timers.js:92:15)
I20170621-01:05:34.111(0)? test1@jobtracking.com.au

@abernix
Copy link
Contributor

abernix commented Jun 21, 2017

@juvyc Do you have a correct MAIL_URL? Can you give an example (without credentials)? What version of email are you using?

@mohamedabbas1992
Copy link

please explain MAIL_URL format in gmail err for MAIL_URL\error greeting never received code 'etimedout'

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