Thunderbird unable to save outgoing mails to sent folder

Sers, it's that time of the year again, I am back.

Running Ubuntu 20.04.6 LTS (Focal Fossa)
And ISPConfig 3.2.10p1 (I just ran the ispconfig_update.sh command)
Thunderbird version is unknown but it's at least close to 102.12.

My clients (a small company) angrily report their thunderbird sometimes modals a "Could not save a copy of this (outgoing) mail to the sent folder". Which leads to them retrying and retrying and that way they send the mails thrice.
They have several accounts running on multiple computers (Mr. A has [email protected] in his thunderbird - and so has Mrs. B on another machine). I don't think that's the issue but it's a detail.

My mail.err is empty. mail.err.1 is six days old and displays a connection issue to mariadb:

Code:

Jun  8 09:37:16 web dovecot: auth-worker(1112): Error: mysql(localhost): Connect failed to database (dbispconfig): Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2) - waiting for 1 seconds before retry
Jun  8 09:37:17 web dovecot: auth: Error: auth worker: Aborted PASSV request for [email protected]: Worker process died unexpectedly
Jun  8 09:37:17 web dovecot: auth-worker(1112): Fatal: master: service(auth-worker): child 1112 killed with signal 11 (core dumped)

syslog as well as mail.log show the outgoing mails but no warning or error regarding their saving.

checking the status of postfix, dovecot and mariadb, all show active/running.
When sending out mails myself (different domain, same server), I don't have the issue. Neither do my other clients/users report anything like that ("the absence of evidence is not evidence of absence"!).

I have no idea how to troubleshoot this. Do you have any advise for me?

Of course I am aware this could as well be an issue with the clients mail settings, their thunderbird, their computer, their network, their ISP/cables... I just wanna make sure I can do everything in my limited power to solve this.

 

Is disk quota exceeded for those mail boxes?
Can the clients tell what is the setting for the Sent folcer, i.e. where exactly are sent e-mails copied?

 

This recent thread has related info: https://forum.howtoforge.com/threads/saving-storing-sent-e-mails.90747/#post-447112

 

While the mailbox size is over 4GB (which is huge compared to my personal storage), they are set to "unlimited". I had to increase disk size for the system because of this client.

The setting folder was set to "Sent in [email protected]" last time I checked. A recent Thunderbird update changed this location, so I check for that. Got a remote-connection-date on friday and I presume this is the issue - but I was wrong before.
The issue here is that the mail can't be saved onto the server but triggers a modal. This issue appears for some (random?) mail accounts on this clients domain. It doesn't appear for me personally and last time they had the problem, the sent dir was chosen correctly and an apt-get update/upgrade => reboot solved it. It's just not very practical for me to stand ready to reboot the server everytime they message me their error.

Thanks for the link but I consider my issue different from trying to set up a PHPmailer which seems to generally require some syntax to save outgoing mails (I am interested in that on the side, though) - while outgoing mails usually works in my case, there's just "Hiccups" I can't comprehend/retrace.

 

So I connected to their machines, fixed a few locations and everything seemed to go fine for the whole last week. Just now I got another mail. I restarted the server but that can't be the long term solution.

So I checked mail.err.1 which has a logtime shortly before me opening this thread 13 days ago.

Code:

Jun 14 10:49:44 web dovecot: auth-worker(1207): Error: sql([email protected],80.94.95.242): Password query failed: Lost connection to MySQL server during query (idled for 2 secs)
Jun 14 10:49:50 web dovecot: imap: Error: net_connect_unix(/var/run/dovecot/stats-writer) failed: Connection refused
Jun 14 10:49:50 web dovecot: imap: Error: net_connect_unix(/var/run/dovecot/stats-writer) failed: Connection refused
Jun 14 10:49:50 web dovecot: imap: Error: net_connect_unix(/var/run/dovecot/stats-writer) failed: Connection refused
Jun 14 10:49:50 web dovecot: imap: Error: net_connect_unix(/var/run/dovecot/stats-writer) failed: Connection refused
Jun 14 10:49:50 web dovecot: imap-login: Error: read(anvil) failed: EOF
Jun 14 10:49:50 web dovecot: imap-login: Error: net_connect_unix(/var/run/dovecot/stats-writer) failed: No such file or directory

The first message seems to be a failed login attempt - there is no "tx" account/user.
Dunno what the rest is about.

mail.err - seems to take on directly after the reboot:

Code:

Jun 27 12:08:07 web dovecot: master: Error: service(auth-worker): Initial status notification not received in 30 seconds, killing the process
Jun 27 12:08:07 web dovecot: auth-worker: Fatal: master: service(auth-worker): child 1822 killed with signal 9
Jun 27 12:11:13 web dovecot: doveadm: Error: This is Dovecot's error log (1687867873)
Jun 27 12:11:13 web dovecot: doveadm: Fatal: This is Dovecot's fatal log (1687867873)

The last two messages was me doing an "doveadm log find", I guess. But what's the rest?

As I read something about mysql in the mail.errs, I checked /var/log/mysql/error.log, which displays this:

Code:

2023-06-27  3:25:38 140539387889408 [Warning] IP address '185.233.19.83' could not be resolved: Name or service not known
2023-06-27  5:45:29 140539388708608 [Warning] IP address '35.216.229.26' has been resolved to the host name '26.229.216.35.bc.googleusercontent.com', which resembles IPv4-address itself.
2023-06-27  5:45:29 140539387889408 [Warning] IP address '35.216.229.26' has been resolved to the host name '26.229.216.35.bc.googleusercontent.com', which resembles IPv4-address itself.
2023-06-27  5:45:29 140539426715392 [Warning] IP address '35.216.229.26' has been resolved to the host name '26.229.216.35.bc.googleusercontent.com', which resembles IPv4-address itself.
2023-06-27  5:45:29 140539074291456 [Warning] IP address '35.216.229.26' has been resolved to the host name '26.229.216.35.bc.googleusercontent.com', which resembles IPv4-address itself.
2023-06-27  5:45:29 140539390347008 [Warning] IP address '35.216.229.26' has been resolved to the host name '26.229.216.35.bc.googleusercontent.com', which resembles IPv4-address itself.
2023-06-27  5:45:29 140539390551808 [Warning] IP address '35.216.229.26' has been resolved to the host name '26.229.216.35.bc.googleusercontent.com', which resembles IPv4-address itself.
2023-06-27  5:45:29 140539389323008 [Warning] IP address '35.216.229.26' has been resolved to the host name '26.229.216.35.bc.googleusercontent.com', which resembles IPv4-address itself.
2023-06-27  5:45:29 140539390756608 [Warning] IP address '35.216.229.26' has been resolved to the host name '26.229.216.35.bc.googleusercontent.com', which resembles IPv4-address itself.
2023-06-27  5:45:29 140539388708608 [Warning] IP address '35.216.229.26' has been resolved to the host name '26.229.216.35.bc.googleusercontent.com', which resembles IPv4-address itself.
2023-06-27  5:45:29 140539387889408 [Warning] IP address '35.216.229.26' has been resolved to the host name '26.229.216.35.bc.googleusercontent.com', which resembles IPv4-address itself.
2023-06-27  5:45:29 140539426715392 [Warning] IP address '35.216.229.26' has been resolved to the host name '26.229.216.35.bc.googleusercontent.com', which resembles IPv4-address itself.
2023-06-27  5:45:29 140539074291456 [Warning] IP address '35.216.229.26' has been resolved to the host name '26.229.216.35.bc.googleusercontent.com', which resembles IPv4-address itself.
2023-06-27  5:45:29 140539390347008 [Warning] IP address '35.216.229.26' has been resolved to the host name '26.229.216.35.bc.googleusercontent.com', which resembles IPv4-address itself.
2023-06-27 12:03:43 140539074291456 [Warning] IP address '38.166.44.146' could not be resolved: Name or service not known
2023-06-27 12:07:05 140539425490688 [Note] /usr/sbin/mysqld: Normal shutdown
2023-06-27 12:07:05 140539425490688 [Note] Event Scheduler: Purging the queue. 0 events
2023-06-27 12:07:06 140538888034048 [Note] InnoDB: FTS optimize thread exiting.
2023-06-27 12:07:06 140539425490688 [Note] InnoDB: Starting shutdown...
2023-06-27 12:07:06 140539425490688 [Note] InnoDB: Waiting for page_cleaner to finish flushing of buffer pool
2023-06-27 12:07:08 140539425490688 [Note] InnoDB: Shutdown completed; log sequence number 60310803312
2023-06-27 12:07:08 140539425490688 [Note] /usr/sbin/mysqld: Shutdown complete

2023-06-27 12:07:25 140307389755328 [Note] InnoDB: innodb_empty_free_list_algorithm has been changed to legacy because of small buffer pool size. In order to use backoff, increase buffer pool at least up to 20MB.

2023-06-27 12:07:25 140307389755328 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2023-06-27 12:07:25 140307389755328 [Note] InnoDB: The InnoDB memory heap is disabled
2023-06-27 12:07:25 140307389755328 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2023-06-27 12:07:25 140307389755328 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2023-06-27 12:07:25 140307389755328 [Note] InnoDB: Compressed tables use zlib 1.2.11
2023-06-27 12:07:25 140307389755328 [Note] InnoDB: Using Linux native AIO
2023-06-27 12:07:25 140307389755328 [Note] InnoDB: Using SSE crc32 instructions
2023-06-27 12:07:25 140307389755328 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2023-06-27 12:07:25 140307389755328 [Note] InnoDB: Completed initialization of buffer pool
2023-06-27 12:07:25 140307389755328 [Note] InnoDB: Highest supported file format is Barracuda.
2023-06-27 12:07:26 140307389755328 [Note] InnoDB: 128 rollback segment(s) are active.
2023-06-27 12:07:26 140307389755328 [Note] InnoDB: Waiting for purge to start
2023-06-27 12:07:26 140307389755328 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.49-89.0 started; log sequence number 60310803312
2023-06-27 12:07:26 140306825570048 [Note] InnoDB: Dumping buffer pool(s) not yet started
2023-06-27 12:07:26 140307389755328 [Note] Plugin 'FEEDBACK' is disabled.
2023-06-27 12:07:26 140307389755328 [Note] Server socket created on IP: '::'.
2023-06-27 12:07:26 140307389755328 [Note] /usr/sbin/mysqld: ready for connections.
Version: '10.1.48-MariaDB-0ubuntu0.18.04.1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  Ubuntu 18.04

I really could use some help finding the cause of the issue (and then maybe fixing it).

Of course, I still can't exclude that the issue is their thunderbird (maybe the settings are back to crap again) but as I set it up correctly and it was working for a week this is really strange and upsetting.

 

Sorry, I gotta URGENTLY bump this.

I temporarily solved the issue by adding a cronjob task thingy that reboots the server every day at 4 am. This solved most issues.

Until last week. Somehow, no email got delivered anymore. All got stuck in the queue. The server seemed reeeeeally slow, so I increased its RAM.
An `apt-get update && apt-get upgrade` triggered some issues which I was able to solve.
Then I updated isp_config.
This seemed to have solved the mailstuck issue and the server was quicker again.

But since this monday, my clients are on edge again: The outgoing emails of some accounts can't be saved. This seems to be an issue with the email accounts of only one client (a couple domains) and I can't reproduce the issue.
This issue spans several accounts on several machines in different locations of the country, so I am deducting this is a server issue.
Would an ispc-update get rid of my reboot-cronjob?

The client has no mailbox quota and there is several GB of free disk space available.

There is no related errors logged in mail.log nor is there anything in syslog - mails of those accounts do appear normally - but no log about "saved in outbox" (there is "saved to inbox"). Is there ANY way I can log this specific issue?

 

Are you doing apt-get upgrade and ispconfig_update.sh only when there are some problems on the host? You should keep the system updated, maybe then there would be less problems.
Where are the sent e-mails stored? If it is a network drive, is it mounted and available? The old messages seemed to show network problems.

 

No, I update it once in a while. I just don't check the server too often when everything is running as intended, so the updates are a bit irregular.

The whole setup is a windows root server with a
Hyper-V Ubuntu 18.04 VM (the web+mailserver, currently 4224MB RAM)
on it (there are other VMs with their own IP each).
The drive is a virtual drive (.vhdx) and available when the VM is running. At least I don't see a reason why it wouldn't be.

 

See my signature for link to Automatic updates -tutorial.

 

Will do, thanks! But solving my issue currently has priority. Or finding out what exactly my issue is. With no logs of the error, I am at my wits end.
I will keep an eye on the reboots (I rechecked and I am using crontab - the reboot line is still there) but those were just a temporary solution.

 

Hurrrmmm... Personally I won't use Windows base root server and prefer Linux based root server but, though in my mind the latter is better, I guess that is only a matter of preference. Depending on the server's usages, heavy or otherwise not, I will determine the needed dedicated cpus (rather than sharing them) and may be separating the web and the mail server. ISPConfig has tools for that, so it should be easy enough, though experienced Linux admin may be able to do it on their own.

 

I don't think the issue is rootserver related and the discussion why I am using windows as root would derail this topic which is aimed towards me finding the issue so I can solve this.
The root server has a Ryzen 7 1700X and one processor seems to be sufficient (0% usage). I don't think that's a possible reason why outgoing mails can't be saved and why there's no error message anywhere I looked. Or issit?

 

I was responding to this. And no, I my suggestion is not, in any way, intended to solve your main problems, obviously.

 

Net_connect errors in #5.

 

Those are gone since.

None of those are in mail.err.1 (last entry on the 10th of january, shortly before the updates in #6) nor mail.log and
mail.err is empty.
Also none in syslog.

Searching "error" in syslog gives me:

- some cert renewal errors unrelated to the clients domains (will fix later).
- Some failed SASL PLAIN authentications (lets call it "failed hacks").
- Some SSL_accept error ("failed hack")
- An unsynchronized clock (fixed, I think.)
- This, dunno what it is there for but might error because VM:

Code:

Jan 16 12:02:13 web NetworkManager[707]: <warn>  [1705406533.6249] Error: failed to open /run/network/ifstate
Jan 16 12:02:13 web NetworkManager[707]: <info>  [1705406533.6475] modem-manager: ModemManager available
Jan 16 12:02:13 web NetworkManager[707]: <info>  [1705406533.6631] manager: startup complete

- a ClamAV error that seems to have solved and isn't in todays log:

Code:

Jan 16 12:27:34 web amavis[2219]: (02219-01) (!)ClamAV-clamd av-scanner FAILED: run_av error: Too many retries to talk to /var/run/clamav/clamd.ctl (All attempts (1) failed connecting to /var/run/clamav/clamd.ctl) at (eval 113) line 659>

- More SSL_accept errors with a TLS library problem ("failed hack"):

Code:

Jan 16 04:56:51 web postfix/smtps/smtpd[2435]: connect from unknown[104.156.155.26]
Jan 16 04:56:51 web postfix/smtps/smtpd[2468]: SSL_accept error from unknown[104.156.155.26]: -1
Jan 16 04:56:51 web postfix/smtps/smtpd[2468]: warning: TLS library problem: error:142090FC:SSL routines:tls_early_post_process_client_hello:unknown protocol:../ssl/statem/statem_srvr.c:1659:
Jan 16 04:56:51 web postfix/smtps/smtpd[2468]: lost connection after CONNECT from unknown[104.156.155.26]
Jan 16 04:56:51 web postfix/smtps/smtpd[2468]: disconnect from unknown[104.156.155.26] commands=0/0

- Some "guy" unsuccesfully trying unrecognized commands:

Code:

Jan 16 23:37:29 web postfix/submission/smtpd[82953]: > unknown[183.136.225.29]: 502 5.5.2 Error: command not recognized
Jan 16 23:37:29 web postfix/submission/smtpd[82953]: < unknown[183.136.225.29]:
Jan 16 23:37:29 web postfix/submission/smtpd[82953]: > unknown[183.136.225.29]: 500 5.5.2 Error: bad syntax
Jan 16 23:37:29 web postfix/submission/smtpd[82953]: < unknown[183.136.225.29]:

- Whatever this is:

Code:

Jan 16 23:18:46 web apt-helper[80050]: E: Sub-process nm-online returned an error code (1)

I guess that's extended ubuntu/linux knowledge: Is there a way to search every file from between January 13th to 16th for "error" and copy the complete line, prefixed by filename, into one file?

 

Find which files are between those dates:

Code:

ls -lht /var/log

Make a list of those files, one filename per line, cut lines from start and end according to knowledge gained with previous command:

Code:

ls -t /var/log > /tmp/list-of-files.txt

Grep that modified file, and get output with filename at beginning of line:

Code:

cd /var/log 
for f in $(cat /tmp/modified-list-of-files.txt) ; do grep -i --with-filename error $f ; done