3CX V18 FTP Backup Errors

[bigdessert]

Since upgrading from 16 to 18 all of our customers fail FTP/FTPS backups.

• 3CX Version, 18.0.237
• Server OS, Debian 10
• Is the 3CX Server Hosted and where? Hosted in Vultr
• IP Phone Make/Model/Firmware version, Yealink T54W
• Provisioning Method: SBC
• Trunk Provider or VoIP Gateway Make/Model, Thinq
• Has the Firewall Checker passed: YES
• Are custom Phone Templates being used: NO

We get errors like the one below. I have cleared out the backup folder completely but still get the errors on next backup.

CAUTION: This email originated from outside of the organization. Do not click links or open attachments unless you recognize the sender and know the content is safe.

Your 3CX backup failed due to the following reason(s):
FluentFTP.FtpCommandException: /3cx/3CXScheduledBackup.zip.tmp: No such file or directory
   at FluentFTP.FtpClient.Rename(String path, String dest)
   at _3cxFilesystemImplementations.FTP.FtpFilesystem.Move(String filename1, String filename2)
   at BackupRestoreSchedule.BackupJob.Execute(IJobExecutionContext context)

Any advice as to what the issue could be?

 

[NickD_3CX]

This sounds like a "read" permission problem because of the "No such file or directory" error.
What the system tries to do, because it's a scheduled job, is rename the .tmp file to .zip. It obviously has "write" permissions as the file seems to have been uploaded.

If you go to the "Backup and Restore" node in the Management Console, does it list the backups?

Regardless, check permissions to be sure.
Also check in case you are somehow limiting the "simultaneous connections" of the FTP. Even if you think they are enough, increase them significantly, at least as a test.

 

[bigdessert]

So I have schedule backups to make sure nothing else is happening on the FTP server when the backup happens. I continue to get this same message but if I go look at the backups and FTP directory it shows the correctly renamed tmp file. Here below shows the backup error I received today at 11:22AM but if I go look at the backups and the FTP server it was successful but I received a failed message. Any other ideas?

 

[cobaltit]

And what do the logs on the FTP server show?

 

[bigdessert]

Here is a log from a backup. It appears to upload the zip.tmp file but then when renaming it renames .zip to 1.zip but then it tries to rename .zip again instead of renaming the zip.tmp. Other thing that throws me off here is it appears the FTP client logs in and quits multiple times(one for each transaction) instead of handling them all in one connection. I am not sure if that is normal or not but it happens to all my users.

216.128.149.9 UNKNOWN - [28/Dec/2021:00:30:00 +0000] "USER aitkinhra" 331 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:00 +0000] "PASS (hidden)" 230 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:00 +0000] "PBSZ 0" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:00 +0000] "PROT P" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:00 +0000] "FEAT" 211 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:00 +0000] "SYST" 215 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:01 +0000] "DELE /3cx/3CXScheduledBackup.zip.tmp" 550 0
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:01 +0000] "QUIT" 221 -
216.128.149.9 UNKNOWN - [28/Dec/2021:00:30:01 +0000] "USER aitkinhra" 331 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:01 +0000] "PASS (hidden)" 230 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:01 +0000] "PBSZ 0" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:01 +0000] "PROT P" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:01 +0000] "FEAT" 211 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:01 +0000] "SYST" 215 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:01 +0000] "TYPE I" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:01 +0000] "EPSV" 229 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:18 +0000] "STOR /3cx/3CXScheduledBackup.zip.tmp" 426 0
216.128.149.9 UNKNOWN - [28/Dec/2021:00:30:35 +0000] "USER aitkinhra" 331 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:35 +0000] "PASS (hidden)" 230 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:35 +0000] "PBSZ 0" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:35 +0000] "PROT P" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:35 +0000] "FEAT" 211 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:35 +0000] "SYST" 215 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:35 +0000] "TYPE I" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:35 +0000] "EPSV" 229 -
216.128.149.9 UNKNOWN - [28/Dec/2021:00:30:49 +0000] "USER aitkinhra" 331 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:49 +0000] "PASS (hidden)" 230 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:49 +0000] "PBSZ 0" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:49 +0000] "PROT P" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:49 +0000] "FEAT" 211 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:49 +0000] "SYST" 215 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:49 +0000] "TYPE I" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:49 +0000] "EPSV" 229 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:52 +0000] "STOR /3cx/3CXScheduledBackup.zip.tmp" 226 598074899
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:52 +0000] "NLST /3cx" 226 62
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:52 +0000] "QUIT" 221 -
216.128.149.9 UNKNOWN - [28/Dec/2021:00:30:52 +0000] "USER aitkinhra" 331 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:52 +0000] "PASS (hidden)" 230 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:52 +0000] "PBSZ 0" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:52 +0000] "PROT P" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:52 +0000] "FEAT" 211 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:52 +0000] "SYST" 215 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:52 +0000] "TYPE I" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:52 +0000] "EPSV" 229 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:53 +0000] "LIST /3cx" 226 168
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:53 +0000] "QUIT" 221 -
216.128.149.9 UNKNOWN - [28/Dec/2021:00:30:53 +0000] "USER aitkinhra" 331 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:53 +0000] "PASS (hidden)" 230 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:53 +0000] "PBSZ 0" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:54 +0000] "PROT P" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:54 +0000] "FEAT" 211 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:54 +0000] "SYST" 215 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:54 +0000] "DELE /3cx/3CXScheduledBackup.1.zip" 550 0
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:54 +0000] "QUIT" 221 -
216.128.149.9 UNKNOWN - [28/Dec/2021:00:30:54 +0000] "USER aitkinhra" 331 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:54 +0000] "PASS (hidden)" 230 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:54 +0000] "PBSZ 0" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:55 +0000] "PROT P" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:55 +0000] "FEAT" 211 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:55 +0000] "SYST" 215 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:30:55 +0000] "RNFR /3cx/3CXScheduledBackup.zip" 350 0
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:31:27 +0000] "RNTO /3cx/3CXScheduledBackup.1.zip" 250 0
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:31:27 +0000] "RNFR /3cx/3CXScheduledBackup.zip" 550 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:31:27 +0000] "RNTO /3cx/3CXScheduledBackup.1.zip" 503 -
216.128.149.9 UNKNOWN - [28/Dec/2021:00:31:37 +0000] "USER aitkinhra" 331 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:31:38 +0000] "PASS (hidden)" 230 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:31:38 +0000] "PBSZ 0" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:31:38 +0000] "PROT P" 200 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:31:38 +0000] "FEAT" 211 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:31:38 +0000] "SYST" 215 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:31:38 +0000] "RNFR /3cx/3CXScheduledBackup.zip" 550 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:31:48 +0000] "RNFR /3cx/3CXScheduledBackup.zip" 550 -
216.128.149.9 UNKNOWN aitkinhra [28/Dec/2021:00:31:48 +0000] "QUIT" 221 -

 

[NickD_3CX]

Other thing that throws me off here is it appears the FTP client logs in and quits multiple times(one for each transaction) instead of handling them all in one connection. I am not sure if that is normal or not but it happens to all my users.

Yes, this is normal behavior, it makes a new connection for each operation, but just to be clear, it never uses more than 1 sim connection to your FTP, it waits to close the previous to start the next.