Errors while sending out _notify()

(Bug, Closed -> Fixed, Priority: Critical, Test Status: Needs Testing , Reported By Bad Link: Thing 3y284oe not found, )

Notifications

Summary: Eric is trying to send mass emails from the Spirit Island Space. He's seeing erratic behavior, and I'm seeing errors in the Splunk logs.

Relevant-looking log errors

My guess is that we aren't throttling properly, so AWS is slamming us down. No, that doesn't seem to make sense -- our limits are much higher than this, and we don't show any rejects in the SES monitor.

Whatever it is, it's erratic: I'm able to send _notify() from a scratch Space to a single recipient with no problem.

Current theory:

AWS explicitly says that this stuff is unreliable, so we should have retry logic.
We might be sending too fast: while they don't explicitly limit number-per-second, they don't not say that either.

So we should probably:

Make the test and real sides of RealEmailSender more similar. (Actually, doesn't matter -- I'm using TLS even in development these days.)
Wrap the phases of email sending in Future-ized functions, with pauses and retries.
Build a throttle of about one email per second into EmailSendingActor.

<14>1 2018-10-27T17:19:09.331Z ae-prod-querki-app08.querki.net ConductR - - [mdc bundleId="18ce7cd926bab888cb7fda3c67662b65"][akka system-name="conductr" thread="conductr-bundle-execution-dispatcher-469"] [[31merror[0m] application - Exception while sending email EmailMsg(EmailAddress(userEmails@querki.net),EmailAddress(geepope@gmail.com),gpope,Spirit Island Playtesting,QWikitext([Spirit Island Playtesting] Release 2018-10-24 (from Spirit Island Playtesting)),CompositeWikitext(Vector(QWikitext(Large release posted a few days ago - changes-only files are now up too. (Thanks Anthony!)
Some people got the last notification via email, others via the bell in the top-nav, but Querki was having some odd up-and-down issues at the time. Comment here if you did *not* get this as an email by mid-afternoon Saturday 10-27 (I'm sending this notification at about 12:40 PM Eastern time).), HtmlWikitextImpl(<hr/>), QWikitext(<a href="https://www.querki.net/u/darker/spirit-island-playtesting/.bu6odtf"><i>Click here to go to Spirit Island Playtesting.</i></a>))),QWikitext(You received this email as a member of Spirit Island Playtesting.
If you don't want to receive emails like these, click [Unsubscribe](https://www.querki.net/unsub?unsubInfo=0d91f656843e1fd9ea459662c1991e602b99652d%3B4joa3uw175j5o%3B4849665%3Ageepope%40gmail.com%3Abu6odr4%3A7w4g8ts%3ASpirit+Island+Playtesting%3ARelease)))
com.sun.mail.util.MailConnectException: Couldn't connect to host, port: email-smtp.us-east-1.amazonaws.com, 25; timeout -1
	at com.sun.mail.smtp.SMTPTransport.openServer(SMTPTransport.java:1961)
	at com.sun.mail.smtp.SMTPTransport.protocolConnect(SMTPTransport.java:654)
	at javax.mail.Service.connect(Service.java:345)
	at javax.mail.Service.connect(Service.java:226)
	at javax.mail.Service.connect(Service.java:246)
	at querki.email.RealEmailSender.sendEmail(RealEmailSender.scala:178)
	at querki.email.EmailSendingActor$$anonfun$doReceive$1.applyOrElse(EmailSendingActor.scala:25)
	at scala.PartialFunction$OrElse.applyOrElse(PartialFunction.scala:171)
	at akka.actor.Actor$class.aroundReceive(Actor.scala:484)
	at querki.util.QuerkiActor.aroundReceive(QuerkiActor.scala:16)
Caused by: java.net.ConnectException: Connection timed out
	at java.net.PlainSocketImpl.socketConnect(Native Method)
	at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350)
	at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
	at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
	at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
	at java.net.Socket.connect(Socket.java:589)
	at java.net.Socket.connect(Socket.java:538)
	at com.sun.mail.util.SocketFetcher.createSocket(SocketFetcher.java:297)
	at com.sun.mail.util.SocketFetcher.getSocket(SocketFetcher.java:229)
	at com.sun.mail.smtp.SMTPTransport.openServer(SMTPTransport.java:1927)

Possibly Irrelevant

(In retrospect, these errors suggest a problem with comment notifications.)

In chronological order, to make it a little easier:

<14>1 2018-10-27T16:45:11.647Z ae-prod-querki-app06.querki.net ConductR - - [mdc bundleId="18ce7cd926bab888cb7fda3c67662b65"][akka system-name="conductr" thread="conductr-bundle-execution-dispatcher-1009"] Full error trace:

[[31merror[0m] application - Non-Exception Error: CommentNotifier got a commentNotifyPref that isn't a YesNo: OneUserValue(FullIdentity(9v5kang,EmailAddress(Speedyolrac@yahoo.com),SpeedyOlrac,SpeedyOlrac,bu6ocli,2),7w4g8ts,1y8ed,Optional TrueOrFalse Type: List(),2018-05-18T12:52:35.000Z)
java.lang.Exception: Debugging Stack Trace requested
	at querki.util.QLog$.stackTrace(QLog.scala:23)
	at querki.util.QLog$.error(QLog.scala:47)
	at querki.conversations.CommentNotifierEcot$$anonfun$notifyComment$2$$anonfun$7.apply(CommentNotifier.scala:118)
	at querki.conversations.CommentNotifierEcot$$anonfun$notifyComment$2$$anonfun$7.apply(CommentNotifier.scala:107)
	at scala.collection.LinearSeqOptimized$class.foldLeft(LinearSeqOptimized.scala:124)
	at scala.collection.immutable.List.foldLeft(List.scala:84)
	at scala.collection.TraversableOnce$class.$div$colon(TraversableOnce.scala:151)
	at scala.collection.AbstractTraversable.$div$colon(Traversable.scala:104)
	at querki.conversations.CommentNotifierEcot$$anonfun$notifyComment$2.apply(CommentNotifier.scala:107)
	at querki.conversations.CommentNotifierEcot$$anonfun$notifyComment$2.apply(CommentNotifier.scala:77)

<12>1 2018-10-27T16:45:11.647Z ae-prod-querki-app06.querki.net ConductR - - [mdc bundleId="18ce7cd926bab888cb7fda3c67662b65"][akka system-name="conductr" thread="conductr-bundle-execution-dispatcher-1009"] java.lang.Exception: Debugging Stack Trace requested
	at querki.util.QLog$.stackTrace(QLog.scala:23)
	at querki.util.QLog$.error(QLog.scala:47)
	at querki.conversations.CommentNotifierEcot$$anonfun$notifyComment$2$$anonfun$7.apply(CommentNotifier.scala:118)
	at querki.conversations.CommentNotifierEcot$$anonfun$notifyComment$2$$anonfun$7.apply(CommentNotifier.scala:107)
	at scala.collection.LinearSeqOptimized$class.foldLeft(LinearSeqOptimized.scala:124)
	at scala.collection.immutable.List.foldLeft(List.scala:84)
	at scala.collection.TraversableOnce$class.$div$colon(TraversableOnce.scala:151)
	at scala.collection.AbstractTraversable.$div$colon(Traversable.scala:104)
	at querki.conversations.CommentNotifierEcot$$anonfun$notifyComment$2.apply(CommentNotifier.scala:107)
	at querki.conversations.CommentNotifierEcot$$anonfun$notifyComment$2.apply(CommentNotifier.scala:77)
	at scala.util.Success$$anonfun$map$1.apply(Try.scala:237)
	at scala.util.Try$.apply(Try.scala:192)
	at scala.util.Success.map(Try.scala:237)
	at scala.concurrent.Future$$anonfun$map$1.apply(Future.scala:237)
	at scala.concurrent.Future$$anonfun$map$1.apply(Future.scala:237)
	at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:36)

<12>1 2018-10-27T16:45:11.647Z ae-prod-querki-app06.querki.net ConductR - - [mdc bundleId="18ce7cd926bab888cb7fda3c67662b65"][akka system-name="conductr" thread="conductr-bundle-execution-dispatcher-1009"] 	at scala.concurrent.impl.ExecutionContextImpl$AdaptedForkJoinTask.exec(ExecutionContextImpl.scala:121)
	at scala.concurrent.forkjoin.ForkJoinTask.doExec(ForkJoinTask.java:260)
	at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.pollAndExecAll(ForkJoinPool.java:1253)
	at scala.concurrent.forkjoin.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1346)
	at scala.concurrent.forkjoin.ForkJoinPool.runWorker(ForkJoinPool.java:1979)
	at scala.concurrent.forkjoin.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:107)

A better version of that, later:

<14>1 2018-10-27T18:08:44.99Z ae-prod-querki-app06.querki.net ConductR - - [mdc bundleId="18ce7cd926bab888cb7fda3c67662b65"][akka system-name="conductr" thread="conductr-bundle-execution-dispatcher-1140"] [[31merror[0m] application - Non-Exception Error: CommentNotifier got a commentNotifyPref that isn't a YesNo: OneUserValue(FullIdentity(9v5kang,EmailAddress(Speedyolrac@yahoo.com),SpeedyOlrac,SpeedyOlrac,bu6ocli,2),7w4g8ts,1y8ed,Optional TrueOrFalse Type: List(),2018-05-18T12:52:35.000Z)
java.lang.Exception: Debugging Stack Trace requested
	at querki.util.QLog$.stackTrace(QLog.scala:23)
	at querki.util.QLog$.error(QLog.scala:47)
	at querki.conversations.CommentNotifierEcot$$anonfun$notifyComment$2$$anonfun$7.apply(CommentNotifier.scala:118)
	at querki.conversations.CommentNotifierEcot$$anonfun$notifyComment$2$$anonfun$7.apply(CommentNotifier.scala:107)
	at scala.collection.LinearSeqOptimized$class.foldLeft(LinearSeqOptimized.scala:124)
	at scala.collection.immutable.List.foldLeft(List.scala:84)
	at scala.collection.TraversableOnce$class.$div$colon(TraversableOnce.scala:151)
	at scala.collection.AbstractTraversable.$div$colon(Traversable.scala:104)
	at querki.conversations.CommentNotifierEcot$$anonfun$notifyComment$2.apply(CommentNotifier.scala:107)
	at querki.conversations.CommentNotifierEcot$$anonfun$notifyComment$2.apply(CommentNotifier.scala:77)