Notification e-mail from FreeNAS stopped working since the middle of December

[zephyrus00jp]

Hi,

I have been using FreeNAS server for file storage about a year.

Since the middle of December, the notification e-mail from FreeNAS box has stopped working.

Today I checked the E-mail setting, and when I invoke "send test mail", I saw an error.
That explains the missing notification e-mails.

But the error message is disturbing.
It said "Your test email could not be sent: {u'gazonk@example.com': (550, '5.1.0 : Sender address rejected: User unknown')}
The string 'gazonk@example.com' is a replacement of a real e-mail address to avoid spam.
Note the 'u' prefix to the string: u'gazonk@example.com'.
Please also note the error message from the server included in the error message printed for "send test mail" is
'5.1.0 : Sender address rejected: User unknown'
and it is NOT prefixed with 'u'.

Background:
I have not changed the notification mail configuration on FreeNAS. But I have updated the FreeNAS images in December.
The mail server is used for my regular e-mail and
I have been using the SMTP server to post e-mails without any issue. Actually, basically the setup for the mail for noticiation
was copiedfrom my local mozilla thunderbird and has worked for the last 12 months without issues.
I am very puzzled why the notification e-mail stopped working.
Since the configuration has remained the same, I can only think of incompatible change in FreeNAS itself.

I suspect something changed with the FreeNAS update(s) which I applied in December and since.

One suspicious thing in the error message is the prefix 'u' to the e-mail address.
I have a nagging suspicion that FreeNAS is sending the user name as
u'gazonk@example.com' with the "u" prefix instead of plain 'gazonk@example.com' without quotes.
It seems to me the interpreter/compiler that handles e-mail notification (maybe Python?)
seems to think the e-mail address is UNICODE string and handles it as such and when it "prins" to the SMTP server, it adds 'u' prefix???
Pure conjecture.

Has anyone noticed such missing notification e-mails from FreeNAS in the last four weeks or so?

TIA

 

[Spearfoot]

Hi,

I have been using FreeNAS server for file storage about a year.

Since the middle of December, the notification e-mail from FreeNAS box has stopped working.

Today I checked the E-mail setting, and when I invoke "send test mail", I saw an error.
That explains the missing notification e-mails.

But the error message is disturbing.
It said "Your test email could not be sent: {u'gazonk@example.com': (550, '5.1.0 : Sender address rejected: User unknown')}
The string 'gazonk@example.com' is a replacement of a real e-mail address to avoid spam.
Note the 'u' prefix to the string: u'gazonk@example.com'.
Please also note the error message from the server included in the error message printed for "send test mail" is
'5.1.0 : Sender address rejected: User unknown'
and it is NOT prefixed with 'u'.

Background:
I have not changed the notification mail configuration on FreeNAS. But I have updated the FreeNAS images in December.
The mail server is used for my regular e-mail and
I have been using the SMTP server to post e-mails without any issue. Actually, basically the setup for the mail for noticiation
was copiedfrom my local mozilla thunderbird and has worked for the last 12 months without issues.
I am very puzzled why the notification e-mail stopped working.
Since the configuration has remained the same, I can only think of incompatible change in FreeNAS itself.

I suspect something changed with the FreeNAS update(s) which I applied in December and since.

One suspicious thing in the error message is the prefix 'u' to the e-mail address.
I have a nagging suspicion that FreeNAS is sending the user name as
u'gazonk@example.com' with the "u" prefix instead of plain 'gazonk@example.com' without quotes.
It seems to me the interpreter/compiler that handles e-mail notification (maybe Python?)
seems to think the e-mail address is UNICODE string and handles it as such and when it "prins" to the SMTP server, it adds 'u' prefix???
Pure conjecture.

Has anyone noticed such missing notification e-mails from FreeNAS in the last four weeks or so?

TIA

Odd! Did you try simply re-entering your email settings?

If you have another email account, you might try using it on FreeNAS to see if the problem persists.

Also, what version of FreeNAS are you using?

 

[zephyrus00jp]

Thank you for your comment.

The version of FreeNAS I use: (Sorry I forgot to attach it.)
Build FreeNAS-9.10.2-U1 (86c7ef5)

I tried re-entering my email settings, and I still got the error.
For example, I have changed the e-mail address for the root user using
Account -> Users -> View Users -> root -> Change E-mail
Then I get a different error message that contains the modified e-mail address. So I think the configuration data is reflected to the operation.

I don't have a working second ISP address handy. Maybe I should test against gmail after registering into it.

TIA

 

[zephyrus00jp]

From the webGUI and invoking the shell from it, I looked at /var/log/debug.log, and found the following.
Again, the e-mail address was changed to avoid spam.

Code:

Jan 25 07:50:01 freenas mailqueue.py: [common.system:317] Sending message from queue failed																	
Traceback (most recent call last):											
  File "/usr/local/www/freenasUI/tools/../../freenasUI/common/system.py", line 314, in send_mail_queue														
	server.sendmail(queue.message['From'], queue.message['To'].split(', '), queue.message.as_string())														
  File "/usr/local/lib/python2.7/smtplib.py", line 747, in sendmail			
	raise SMTPRecipientsRefused(senderrs)									  
SMTPRecipientsRefused: {u'gazonk@example.com': (550, '5.1.0 <address-for-root@example.com>: Sender address rejected: User unknown')}

Sure it looks to me something is wrong with the Python code that prints 'u' prefix for the sender address...
I suspect that, in the above code, queue.message['To'].split(', ') may contain data that is recognized/interpreted as containing UNICODE string.
But then why this happens is not quite clear. Maybe unintended locale setting somewhere?

TIA

 

[zephyrus00jp]

I checked my language setting in the Wizard menu. It is English. I only set the timezone to Asia/Tokyo.
I think once I see a problem with other ISP smtp server such as gmail, I can confirm this is a bug. But I have no idea why this box seems to the only one seeing this issue...

TIA

 

[Spearfoot]

Maybe unintended locale setting somewhere?

Good idea! What browser did you use when you entered the email settings? And how was it configured regarding language and locale? Also, what operating system were you using to load the browser, and how was it configured with respect to language and locale?

But I have no idea why this box seems to the only one seeing this issue...

Do you have more than one FreeNAS server?

 

[Spearfoot]

The u' prefix probably doesn't have any significance, as it's the standard prefix for Python unicode strings.

 

[Spearfoot]

I can't duplicate your error.

When I use a valid email address with an invalid Username in System->Email, the system returns

Code:

SMTPAuthenticationError: (535, '5.7.0 (#AUTH012) Incorrect username or password.')

When I use an invalid email address with a valid Username in System->Email, the system returns

Code:

SMTPSenderRefused: (553, 'From address not verified - see http://help.yahoo.com/l/us/yahoo/mail/original/manage/sendfrom-07.html', u'aknash@sbcglobal.net')

When both email address and Username are valid, the 'Send Test Mail' button works -- I see 'Your test email has been sent!' on the System-Email form -- and the test message appears at root's mail account shortly afterwards.

So I can't get past the System->Email setup without getting either a successful test or messages indicating problems with the account.

QUESTION: Are you using a different email address for the root account? I happen to use the same account for root that I use as the 'notification' account, which is the account defined in System->Email.

It appears that your notification settings are okay and you are able to connect to the mail server successfully, but it's returning a 550 error when you submit mail for the root email address.

I would try setting the root account email address the same as your notification account and see if that works. If these already are the same, then I'm all out of ideas.

 

[zephyrus00jp]

Sorry I could not earlier. Got a bad bout of cold/flu-like syndrome...

Anyway here is what I found out and am puzzled more.

I created a gmail account and tried to send the daily security notice, etc. to GMAIL e-mail address.
Now that WORKS (!) Heaven knows why (?)


Back to a few questions raised before in reverse chronological order.

> I would try setting the root account email address the same as your notification account and see if that works. > If these already are the same, then I'm all out of ideas.
The WERE the same.

> The u' prefix probably doesn't have any significance, as it's the standard prefix for Python unicode strings.
Yes, possibly.
But please note the subtle but important issue in the warning/error message below:

SMTPRecipientsRefused: {u'gazonk@example.com': (550, '5.1.0 <address-for-root@example.com>: Sender address rejected: User unknown')}

The e-mail address is prefixed with "u".
But the error message itself '5.1.0 <....>' is NOT prefixed by "u" meaning that the error message is probably handled as plain ASCII text. But somehow the e-mail address handled as unicode strings. Why is the discrepancy?

> Do you have more than one FreeNAS server?
I have only one FreeNAS server and so can't compare the operation on another box.

Re locale
> Good idea! What browser did you use when you entered the email settings? And how was it configured
> regarding language and locale? Also, what operating system were you using to load the browser, and how was > it configured with respect to language and locale?
I used Firefox web browser 4x.y or 5x.y (not sure what it was.).
It is a Japanese version, I think since the menus are shown in Japanese, and the host OS is Windows 10, again a Japanese version.
So naturally, I get a little suspicous about the data type that is put into the mail address field. (Instead of plain ASCII character, what I thought were typing, could it be that unicode equivalent somehow sneaqued in?)
*BUT* please recall the same browser from the same Windows PC was used to set up the new GMAIL account, and for that GMAIL account, the sending of e-mails works.

I am so confused and right now, all my daily security warning reach my local ISP mailbox by way of GMAIL account and presumaby NSA is reading the content

Of course, there *IS* a chance of my local ISP changing SMTP server, but as far as I know the mozilla thunderbird mail client which I use to receive and send e-mails from/to the SMTP server had no change of account and it has worked without any issues.

I suspect I need to run Wireshark or something to check what is on wire in the place for e-mail address (a plain ASCII character string or something else???).

Thank you again for your tips and I am sorry that I could not follow up in a timely manner.


That *COULD* mean

 

[Stux]

I'm guessing your isp has changed the way their smtp server is configured to make it harder to be used as a reflector for spam. Are you using authenticated smtp?

 

[zephyrus00jp]

Hi,

Thank you for everybody who chimed in with ideas.

Anyway, just as I was thinking about installing Wireshark on FreeNas which I had never done before (I have run it under Windows and linux before), I tweaked the setting back of e-mail to the original one, which stopped working in December until late January as far as I could tell.

A REAL SURPRISE: this time it worked !?
That is, I could send the test e-mail again(?!)

> I'm guessing your isp has changed the way their smtp server is configured to make it harder to be used as a >reflector for spam. Are you using authenticated smtp?

Well, yes and no.
YES in the sense I put the authentication on and put the password when I tested it.

However, it seems that today the SMTP server of the ISP does not seem to require the authentication.
That is, I put the password and saw the test succeed. A real surprise.
But then I recall that upgrade occasionally left password empty, I tested to see if removing password
could cause the test to fail.
But when I checked mozilla thunderbird mail client, it did not have the password set up there.
In mozilla's case, if the server requires authentication and password is missing a pop-up appears where I am requested to type in the password.
I got curious and erased the password field. Thus empty password.
I tried sending test e-mail. It worked again (!?)

(Hmm... There can be a grace period in the sense that if I READ e-mails from the Windows PC at home
using pop3 authentication and it MAY BE THAT the ISP server REMEMBERS that there was an authenticated
access for a registered user from my home's gateway and the next time I try to send e-mail from my home's gateway address, it will allow it in a grace period (?).
Actually, I tested this scenario back in January by receiving and sending e-mails from Windows 10 mail client Mozilla Thunderbird WITH EXACTLY THE SAME mail setup as FreeNAS's. The only difference, of course, is that Thunderbird is set up additionally for POP3 access to read e-mails. And the configuration of TB and FreeNAS worked like a charm for about 12 months until the middle of last December.

Anyway, I am dumbfounded.

It could be a subtle change of server setup on the side of my ISP: so subtle, they never bothered to tell its users, and they may revert it back silently again...
(As a matter of fact, I tested the interaction of ISP's SMTP by means of manual telnet session into the port (578) and typed the initial command but did not see anything untowed about the interaction.)

The only difference I can think of on my side is that Firefox has changed to 51.0.1.
(But again my point was that the configuration of e-mail that worked for 12 months stopped working in December, and the similar setup up in mozilla thunderbird mail client worked without an issue during the December and January. Only yesterday, I was about to see what was going on by capturing the packet and reverted the setup from the hastily created GMAIL account to local ISP's, it began working again.

I will report back with packet trace when the problem recurs. [I suspected the incompatible Python update, but I think I was wrong. The version of the FreeNAS remains the same "FreeNAS-9.10.2-U1 (86c7ef5)" and so the only culrpit would be the local ISP for now.]

Thank you again for the ideas.