SMTP Send Email action seems to have broken in FinalBuilder 8.0.0.2508 (and all subsequent versions)

Hi,

We have been trying to update FinalBuilder on our build server so that we can use Visual Studio 2019.

However, our Send Email actions seem to have stopped working. In builds with FinalBuilder version 8.0.0.2468 we usually get the following sort of thing in the logs:

2019-11-14T18:23:16.7008212Z [Send email about packages]
2019-11-14T18:23:16.7008212Z Unable to Send Message (Connect)
2019-11-14T18:23:16.7008212Z Socket Error # 10061
2019-11-14T18:23:16.7008212Z Connection refused.
2019-11-14T18:23:19.8792435Z Retrying action (1 of 2)…
2019-11-14T18:23:19.8792435Z Sent: 11/14/2019 6:23:19 PM : 11/14/2019 6:23:19 PM Data: STARTTLS
2019-11-14T18:23:19.8892457Z Received: 11/14/2019 6:23:19 PM : 11/14/2019 6:23:19 PM Data: 220 2.0.0 SMTP server ready

However, after updating to FinalBuilder version 8.0.0.2508 or later we always get this instead:

2019-11-14T19:07:55.6227859Z [Send email about packages]
2019-11-14T19:07:57.6290578Z Status: Disconnected. : Disconnected.
2019-11-14T19:07:57.6290578Z Unable to Send Message (Connect)
2019-11-14T19:07:57.6290578Z Socket Error # 10061
2019-11-14T19:07:57.6300565Z Connection refused.
2019-11-14T19:07:57.6300565Z Retrying action (1 of 2)…
2019-11-14T19:07:57.6300565Z Status: Disconnected. : Disconnected.
2019-11-14T19:07:57.6300565Z Unable to Send Message (Connect)
2019-11-14T19:07:57.6310567Z Socket Error # 10061
2019-11-14T19:07:57.6310567Z Connection refused.
2019-11-14T19:07:59.6363261Z Retrying action (2 of 2)…
2019-11-14T19:07:59.6363261Z Status: Disconnected. : Disconnected.
2019-11-14T19:07:59.6363261Z Unable to Send Message (Connect)
2019-11-14T19:07:59.6363261Z Socket Error # 10061
2019-11-14T19:07:59.6373263Z Connection refused.

I would guess this is related to the bug fix from the release notes:

Bug Fix - Send Email Action - Fixed reconnection issue when using SSL

The settings we use are as follows:

image

Any help would be appreciated, I can provide more information if needed.

Thanks

Also, I can confirm that if the Send Email action properties are logged, they are identical with both versions of Final Builder. So it would seem that what is causing the failure is purely internal to the Send Email action in the new FinalBuilder versions.

For information, the full log of our action properties are as follows:

Action Properties
ActionComment =
AttachmentsObject =
Authenticate = True
BccSource = asSpecify
BccVariable =
BodyObject =
CopyToSource = asSpecify
CopyToVariable =
Description = Send email about packages
Enabled = True
EnableTimeout = False
Encoding =
ExpandActionLogTitle = True
HideActionFromLog = False
Host = smtpmail
HTMLMessage = True
IgnoreFailure = False
IgnoreIndivualFailures = False
IgnoreMissingAttachments = False
Locked = False
LogActionProperties = True
LogReceived = True
LogSent = True
LogSSLNegotiation = True
LogToVariable =
MaxRetryAttempts = 2
Mode = 0
PathOfBccFile =
PathOfCopyToFile =
PathOfRecipientFile = %EmailRecipientsFile%
PathOfReplyToFile =
PauseInterval = 0
PlainBodyObject =
PopBeforeSMTP = False
POPHost =
POPPort = 110
Port = 25
Priority = 2
RecipientsSource = asFromVariable
RecipientVariable = EmailRecipients
ReplyToSource = asSpecify
ReplyToVariable =
RetryPauseInterval = 1000
Subject = %SystemName% %ProductVersion% (%AssemblyVersion%) …
SuppressStatusMessages = False
TimeoutLength = 1
UseEhlo = True
UseGlobalOptions = True
UserId = software
UseSSL = True
UseTLS = utUseExplicitTLS

Not much has changed in the email action recently, we did fix a bug with ssl reconnection but I don’t think that is the issue here. More likely is your smtp server is not running on the port you are trying to connect to. Connection refused means just that, the server did not accept the connection.

What are your global email settings, the port number?

After some thought, I suspect you are using the incorrect port, most mail servers do not support Explicit TLS on port 25. Check with your mail admin, perhaps something has changed recently.

Hi Vincent, thanks for the response.

I’m waiting for the answer from our admin to see if there’s anything we should be changing configuration-wise. I wouldn’t be surprised if that’s the case.

However, I raised the issue on these forums because I can definitely confirm (after multiple upgrades/downgrades of FinalBuilder) that when we move from FinalBuilder 8.0.0.2468 to 8.0.0.2508 (or later) we go from sending emails successfully to not being able to send them.

But, as you probably noticed, even when things were working with version 8.0.0.2468 for us, we would still consistently start off with a single connection refused error before the first retry would then succeed. So I agree that does suggest something is off with our configuration.

For now I’ll see if there’s anything we can reconfigure on our side, but I may have to come back to ask for some more clues about what changed in that SSL reconnection bug fix. It may be that we had something incorrect, and working by chance before that bug fix, but I will get back to you either way.

Thanks,

Adam

Hi again,

So I have confirmed with our admin that the settings we are using are as expected (and we know they work with earlier versions of FinalBuilder, as well as other software that sends emails).

At this point I have to say it definitely seems that the change in FinalBuilder 8.0.0.2508 is what is making the difference.

To confirm:

FinalBuilder 8.0.0.2468 works with our SMTP settings to send emails
FinalBuilder 8.0.0.2496 works with our SMTP settings to send emails
FinalBuilder 8.0.0.2508 is the point at which we can no longer send emails from FinalBuilder

Rolling back to the previous versions works immediately again with no other changes required.

Could you please give us a bit more information about what the change in that version entailed? Maybe the library being used for sending emails was also updated in that version, or something like that, and we can investigate if there is a bug in that library version?

Thanks

I’ve been investigating this all day without coming up with any real answers. We did take a library update after 2496, however there were no changes to the smtp part of the library. The only minor change we made in the action code itself was to fix a random access violation (by nil’ing a variable when the action was done).

I’ve been testing on multiple machines, with multiple mail servers (gmail, smartermail and office365) and each one works as expected. The only failure I got were when I did something wrong.

Now one thing that I did think of, is client side firewalls and anti malware etc - I’ve lost count of the number of times this has turned out to be the cause of issues. I have seen these tools block one version of FinalBuilder and not another, for no apparent reason.

I know I’m grasping a straws here, but the you are seeing Socket Error # 10061 strongly suggests this. We have not had any other (recent or unresolved) reports of this issue, and have FinalBuilder (and Automise) running tasks on multiple machines here that send mail without issue multiple times per day.

Are you able to test on another machine?

More grasping at straws, I have uploaded a build with another update to the smtp library (Indy), this behaves the same as the previous update here but worth trying

https://downloads.finalbuilder.com/downloads/finalbuilder/800/FB800_2645.exe

This build is identical to the 2629 build from last week apart from the library update.

Hi Vincent,

Thanks for taking a look. To answer your question about other machines, yes, this was happening on multiple machines.

Something interesting I have just noticed though, is that if I go back to the latest version 8.0.0.2629 (or the 2645 version you sent) then I actually see this in the UI:

image

So there it’s saying port 587 is being used. I wasn’t seeing that in the output logs I copy/pasted in my original post, so maybe it’s a UI message only?

It does seem that no matter what I do, if I try to specify port 25 in either the global or local SMTP settings, it is ignored and instead port 587 is used. That would certainly explain things not working. If I choose other port numbers, they are respected and the message in the UI reflects what has been set in the settings (but of course I still get the same error because our server is only set up for port 25).

When I go back to version 8.0.0.2508 (the earliest version we’re having problems with) I don’t see that line in the UI about port 587, but maybe that remapping of 25 to 587 is still happening invisibly in that case.

Anyway, hopefully that’s enough information. If there’s a strong reason why the configuration is forced to 587 when port 25 is specified, then I have no real issue with that and we’ll just have to reconfigure at our end.

Thanks

I can reproduce this here now, not sure why I didn’t see it before. I’m investigating, it shouldn’t be forcing the port to change, and I can’t see where it’s happening in our code, so now to dig into the library.

BTW, the logging of the port was added recently to help diagnose this issue, it’s logged right before connecting (and after we set the port to the value specified in the action or the options). I suspect the library is setting the port when we set the TLS options, which happens after the port is set. I’ll do some more testing but I think I may have a solution.

Ok, I’m embarrassed that it took me so long to figure this one out, especially considering the fix was literally to change the order of two lines of code! I obviously didn’t test the TLS setting using non default ports recently or I would have seen it immediately.

The cause was that we were setting the TLS options after setting the Port, and the update to the library introduced a new behavior, setting the port to the default for the TLS setting.

This build has the fix.

https://downloads.finalbuilder.com/downloads/finalbuilder/800/FB800_2653.exe

Excellent, thanks for the help Vincent. I’ve tried that build and its working straight away, so this issue is resolved for us.

Thanks again for the quick response.