530 Must issue a STARTTLS Command First

boyzoid · January 5, 2022, 2:01pm

I am not trying to connect to GMail

Terry_Whitney · January 5, 2022, 2:04pm

In your sample, You have from something something gmail.com

can you (minus the password) post your code here as so far you have lead everyone down a rabbit hole.

boyzoid · January 5, 2022, 3:04pm

Ahh…I did have the to and from conflated in the example, but fixed it after I posted the screen cap.

I am not trying to send email through GMail.

joe.gooch · January 5, 2022, 3:05pm

STARTTLS capable connections require EHLO instead of HELO - and for whatever reason javamail is sending HELO.

How it should be

$ telnet smtp.email.us-ashburn-1.oci.oraclecloud.com 25
Trying 130.35.96.103...
Connected to smtp.email.us-ashburn-1.oci.oraclecloud.com.
Escape character is '^]'.
220 smtp.email.us-ashburn-1.oci.oraclecloud.com ESMTP smtp-in
EHLO me
250-smtp.email.us-ashburn-1.oci.oraclecloud.com
250-STARTTLS
250 Ok
quit
221 Bye <id: bb655b03-a967-4ca7-bac9-41d62f65639d>
Connection closed by foreign host.

How it is

$ telnet smtp.email.us-ashburn-1.oci.oraclecloud.com 25
Trying 130.35.96.103...
Connected to smtp.email.us-ashburn-1.oci.oraclecloud.com.
Escape character is '^]'.
220 smtp.email.us-ashburn-1.oci.oraclecloud.com ESMTP smtp-in
HELO me
530 Must issue a STARTTLS command first
quit
221 Bye <id: 646d1f86-418e-4c9d-b4f3-5d911ec8f8a9>
Connection closed by foreign host.

Digging into it, javamail recognizes the property “mail.smtp.ehlo=false” on the SmTP Session properties, which is likely causing this. You’d need to turn up logging on the com.sun.mail.smtp.* loggers to FINE or better.

boyzoid · January 5, 2022, 3:13pm

I am not sure how to do either of these in Lucee.

joe.gooch · January 5, 2022, 3:13pm

Also just to be clear there’s some red herrings here.

SSL protocols isn’t the issue. It can’t be, because it’s talking plain text. STARTTLS tells the SERVER to start SSL negotiations, lucee hasn’t done anything SSL yet at this point.
Keystores are not the issue. This is a SMTP client. It doesn’t need a cert. It DOES need to TRUST the server’s cert, but a) we haven’t gotten there yet (see #1) and b) it’d be a PKIX exception if that were the issue.

From here https://lucee.daemonite.io/t/smtp-mail-server-tls-enabled-still-shows-must-issue-starttls-command-first/1251 Lucee doesn’t enable starttls if the username is empty.

boyzoid · January 5, 2022, 3:16pm

Username is not empty. it is being passed when I call new Mail().

Also, if this was the case, it would not work locally as I use the same code, same credentials and same SMTP server.

Terry_Whitney · January 5, 2022, 3:17pm

Without knowing which host you are trying to send at this point

Its a code error with your code
its a configuration error

Lucee does work with Gmail, Azure, Oracle, AWS, AEM, Exchange and multiple other email platforms without issue.

Read the TLS manual on your OS / BOX you are trying to send from and then manually from whatever box you are trying to send email, connect and send the email. You will find you have an “AH HAH” moment, where its something simple you missed.

boyzoid · January 5, 2022, 3:22pm

Once again…both prod and dev machines use the same exact code and same exact config - neither of which has changed in about 4 years. So, it’s not likely a code or config issue.

This worked for years in production and only started having issues when I moved to an Arm instance on Oracle Cloud.

joe.gooch · January 5, 2022, 3:27pm

But your system properties might be different.

Post results of this:

<cfset obj = createobject("java", "java.lang.System").getProperties() />
<cfdump var="#obj#"/>

And/or look in that for mail.smtp.* properties

joe.gooch · January 5, 2022, 3:30pm

I confirm this works for me

<cfmail
  from="(myemail)"
  to="(myemail)"
  subject="Test"
  useTLS="true"
  server="smtp.email.us-ashburn-1.oci.oraclecloud.com"
  port="587"
  username="user" password="pass">test</cfmail>

Except the auth fails - but auth happens after STARTTLS. Verified against the lucee web-context mail.log.

"ERROR","Thread-194","01/05/2022","10:27:33","mail","535 Authentication credentials invalid
;535 Authentication credentials invalid
;lucee.runtime.exp.NativeException: 535 Authentication credentials invalid

	at com.sun.mail.smtp.SMTPTransport$Authenticator.authenticate(SMTPTransport.java:965)
	at com.sun.mail.smtp.SMTPTransport.authenticate(SMTPTransport.java:876)
	at com.sun.mail.smtp.SMTPTransport.protocolConnect(SMTPTransport.java:780)
	at javax.mail.Service.connect(Service.java:388)
	at lucee.runtime.net.smtp.SMTPSender.run(SMTPSender.java:60)
Caused by: javax.mail.AuthenticationFailedException: 535 Authentication credentials invalid

	... 5 more
"

My bet is the instance has a system property or an environment-specific config on the Arm instance that isn’t present on your others.

boyzoid · January 5, 2022, 3:40pm

The only property locally that has any mention of SMTP is

This value is the same in production

I have tried a simple example using <cfmail> and still get the 530 error.

joe.gooch · January 5, 2022, 3:42pm

Turn up logging

<cfset obj2 = createobject("java", "java.util.logging.ConsoleHandler").init() />
<cfset obj2.setFormatter(createobject("java", "java.util.logging.SimpleFormatter").init()) />
<cfset obj2.setLevel(createobject("java","java.util.logging.Level").FINE) />

<cfset obj = createobject("java", "java.util.logging.Logger").getLogger("com.sun.mail.smtp") />
<cfset obj.setLevel(createobject("java","java.util.logging.Level").FINE) />
<cfset obj.addHandler(obj2) />
<cfset obj = createobject("java", "java.util.logging.Logger").getLogger("javax.mail") />
<cfset obj.setLevel(createobject("java","java.util.logging.Level").FINE) />
<cfset obj.addHandler(obj2) />

Dump that in a CFM and run it, then go back and run your cfmail again

You should see lines like this in your console log box server log follow=true

[ERROR] Jan 05, 2022 10:39:46 AM com.sun.mail.smtp.SMTPTransport protocolConnect
FINE: protocolConnect login, host=smtp.email.us-ashburn-1.oci.oraclecloud.com, user=user, password=<non-null>
[ERROR] Jan 05, 2022 10:39:46 AM com.sun.mail.smtp.SMTPTransport authenticate
FINE: Attempt to authenticate using mechanisms: LOGIN PLAIN DIGEST-MD5 NTLM XOAUTH2
[ERROR] Jan 05, 2022 10:39:46 AM com.sun.mail.smtp.SMTPTransport authenticate
FINE: mechanism LOGIN not supported by server
[ERROR] Jan 05, 2022 10:39:46 AM com.sun.mail.smtp.SMTPTransport authenticate
FINE: Using mechanism PLAIN
[ERROR] Jan 05, 2022 10:39:46 AM com.sun.mail.smtp.SMTPTransport protocolConnect
FINE: useEhlo true, useAuth true
[ERROR] Jan 05, 2022 10:39:46 AM com.sun.mail.smtp.SMTPTransport openServer
FINE: trying to connect to host "smtp.email.us-ashburn-1.oci.oraclecloud.com", port 587, isSSL false
[ERROR] Jan 05, 2022 10:39:46 AM com.sun.mail.smtp.SMTPTransport openServer
FINE: connected to host "smtp.email.us-ashburn-1.oci.oraclecloud.com", port: 587
[ERROR] Jan 05, 2022 10:39:46 AM com.sun.mail.smtp.SMTPTransport ehlo
FINE: Found extension "STARTTLS", arg ""
[ERROR] Jan 05, 2022 10:39:46 AM com.sun.mail.smtp.SMTPTransport ehlo
FINE: Found extension "Ok", arg ""
[ERROR] Jan 05, 2022 10:39:46 AM com.sun.mail.smtp.SMTPTransport ehlo
FINE: Found extension "PIPELINING", arg ""
[ERROR] Jan 05, 2022 10:39:46 AM com.sun.mail.smtp.SMTPTransport ehlo
FINE: Found extension "8BITMIME", arg ""
[ERROR] Jan 05, 2022 10:39:46 AM com.sun.mail.smtp.SMTPTransport ehlo
FINE: Found extension "AUTH", arg "PLAIN"
[ERROR] Jan 05, 2022 10:39:46 AM com.sun.mail.smtp.SMTPTransport ehlo
FINE: Found extension "Ok", arg ""

Terry_Whitney · January 5, 2022, 4:00pm

Nothing in the world is static

Update everything on your os
Restart your services / and server (Yes you can hotpatch, but its not recommended long term)
Try again
Both windows and *NIX have made changes recently in crytogpraghy that effects the way the network connections are handled

Next read up

Oracle has some additional requirements that require even your “DEV” machine to potentially be properly setup for email sending, or additional configuration such as using a smart relay

boyzoid · January 5, 2022, 4:27pm

I appreciate you trying to help, I really do.

But, if it was a config issue with Oracle, I would be getting the same errors in both places. I have made no config changes locally, but I can send email without issue. I am only running into this issue trying to send email from the production server.

I have been over the docs for Oracle Email - and have even had a Dev Advocate for Cloud Services trying to help me on that end - including updating the version of Java on the server to match what I have locally. It does not seem to be an issue on the Oracle Email end.

joe.gooch · January 5, 2022, 4:44pm

Try doing the logging i suggested - I’m going to bet you’ll see useEhlo false - and if so, we just need to figure out why.

If you see useEhlo true, then we need to see what else shows in the logs.

kabutotx · January 5, 2022, 5:24pm

My scripts show TLS is loaded. I would follow @joe.gooch and up logging and see.
Your DEV is commandbox on Win 10? Can your set an ARM DEV?
Did you just upgrade to the Oracle Linux 7.9 from something else?
I looked at the newer Jakarta Mail and don’t see any bug fixes that might affect this.

boyzoid · January 5, 2022, 5:27pm

I do not see anything related to the email when I tail the server log

boyzoid · January 5, 2022, 8:54pm

The plot thickens. I friend who works for Oracle has bene helping me and he whipped up a small java app to test this.

It fails on the app server, but it works on my DB server, which is also on Arm architecture.

So, me fear that this issue is Arm related seems unfounded at this point.

If we can figure out the issue, I will report back.

boyzoid · January 6, 2022, 12:58am

So, it seems to have been a hardware issue and/or a config issue with the Arm instance

I spun up another Arm instance and the test java app ran successfully.

Now I get to spend tomorrow getting everything configured again…