Toggle sidebar Toggle sidebar

V18 FTP Backup errors

Status
Not open for further replies.

bigdessert

Silver Partner
Advanced Certified
Joined
Apr 3, 2017
Messages
90
Reaction score
31
Since upgrading from 16 to 18 all of our customers fail FTP/FTPS backups.

  • 3CX Version, 18.0.461
  • 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
Here is the error

Code: 
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)

The backup completes and I can see the Zip file there so it is working. What I think is happening is some type of race condition where it tries to rename 3CXScheduledBackup.zip.tmp to 3CXScheduledBackup.zip but either it doesn't happen fast enough or for some strange reason it is trying again and again as shown in the logs below.

3CX Support any thoughts on this?

xxx.xxx.xxx.xxx UNKNOWN datacomm [30/Mar/2022:21:17:44 +0000] "RNFR /3cx/3CXScheduledBackup.zip.tmp" 350 0
xxx.xxx.xxx.xxx UNKNOWN datacomm [30/Mar/2022:21:18:26 +0000] "RNTO /3cx/3CXScheduledBackup.zip" 250 0
xxx.xxx.xxx.xxx UNKNOWN datacomm [30/Mar/2022:21:18:26 +0000] "RNFR /3cx/3CXScheduledBackup.zip.tmp" 550 -


Here are the FTP logs


Code: 
Wed Mar 30 21:15:08 2022 5 xxx.xxx.xxx.xxx 0 /mnt/ftp/datacomm/3cx/3CXScheduledBackup.zip.tmp b _ i r datacomm ftps 0 * i
Wed Mar 30 21:17:32 2022 48 xxx.xxx.xxx.xxx 2216937800 /mnt/ftp/datacomm/3cx/3CXScheduledBackup.zip.tmp b _ i r datacomm ftps 0 * c
Wed Mar 30 21:17:43 2022 0 xxx.xxx.xxx.xxx 2216937809 /mnt/ftp/datacomm/3cx/3CXScheduledBackup.zip a _ d r datacomm ftps 0 * c

Code: 
144.202.51.254 UNKNOWN - [30/Mar/2022:21:15:01 +0000] "USER datacomm" 331 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "PASS (hidden)" 230 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "PBSZ 0" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "PROT P" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "FEAT" 211 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "SYST" 215 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "DELE /3cx/3CXScheduledBackup.zip.tmp" 550 0
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "QUIT" 221 -
144.202.51.254 UNKNOWN - [30/Mar/2022:21:15:02 +0000] "USER datacomm" 331 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "PASS (hidden)" 230 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "PBSZ 0" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "PROT P" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "FEAT" 211 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "SYST" 215 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "TYPE I" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:02 +0000] "EPSV" 229 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:15:18 +0000] "STOR /3cx/3CXScheduledBackup.zip.tmp" 426 0
144.202.51.254 UNKNOWN - [30/Mar/2022:21:16:43 +0000] "USER datacomm" 331 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:16:44 +0000] "PASS (hidden)" 230 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:16:44 +0000] "PBSZ 0" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:16:44 +0000] "PROT P" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:16:44 +0000] "FEAT" 211 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:16:44 +0000] "SYST" 215 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:16:44 +0000] "TYPE I" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:16:44 +0000] "EPSV" 229 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:32 +0000] "STOR /3cx/3CXScheduledBackup.zip.tmp" 226 2216937800
144.202.51.254 UNKNOWN - [30/Mar/2022:21:17:41 +0000] "USER datacomm" 331 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:41 +0000] "PASS (hidden)" 230 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:41 +0000] "PBSZ 0" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:41 +0000] "PROT P" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:41 +0000] "FEAT" 211 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:41 +0000] "SYST" 215 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:41 +0000] "TYPE I" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:41 +0000] "EPSV" 229 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:41 +0000] "NLST /3cx" 226 62
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:41 +0000] "QUIT" 221 -
144.202.51.254 UNKNOWN - [30/Mar/2022:21:17:42 +0000] "USER datacomm" 331 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:42 +0000] "PASS (hidden)" 230 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:42 +0000] "PBSZ 0" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:42 +0000] "PROT P" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:42 +0000] "FEAT" 211 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:42 +0000] "SYST" 215 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:42 +0000] "TYPE I" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:42 +0000] "EPSV" 229 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:42 +0000] "LIST /3cx" 226 166
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:42 +0000] "QUIT" 221 -
144.202.51.254 UNKNOWN - [30/Mar/2022:21:17:42 +0000] "USER datacomm" 331 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:42 +0000] "PASS (hidden)" 230 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:42 +0000] "PBSZ 0" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:43 +0000] "PROT P" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:43 +0000] "FEAT" 211 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:43 +0000] "SYST" 215 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:43 +0000] "DELE /3cx/3CXScheduledBackup.zip" 250 2216937809
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:43 +0000] "QUIT" 221 -
144.202.51.254 UNKNOWN - [30/Mar/2022:21:17:43 +0000] "USER datacomm" 331 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:43 +0000] "PASS (hidden)" 230 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:43 +0000] "PBSZ 0" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:43 +0000] "PROT P" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:43 +0000] "FEAT" 211 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:43 +0000] "SYST" 215 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:44 +0000] "DELE /3cx/3CXScheduledBackup.zip" 550 0
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:44 +0000] "QUIT" 221 -
144.202.51.254 UNKNOWN - [30/Mar/2022:21:17:44 +0000] "USER datacomm" 331 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:44 +0000] "PASS (hidden)" 230 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:44 +0000] "PBSZ 0" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:44 +0000] "PROT P" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:44 +0000] "FEAT" 211 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:44 +0000] "SYST" 215 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:17:44 +0000] "RNFR /3cx/3CXScheduledBackup.zip.tmp" 350 0
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:18:26 +0000] "RNTO /3cx/3CXScheduledBackup.zip" 250 0
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:18:26 +0000] "RNFR /3cx/3CXScheduledBackup.zip.tmp" 550 -
144.202.51.254 UNKNOWN - [30/Mar/2022:21:18:35 +0000] "USER datacomm" 331 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:18:35 +0000] "PASS (hidden)" 230 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:18:35 +0000] "PBSZ 0" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:18:35 +0000] "PROT P" 200 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:18:35 +0000] "FEAT" 211 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:18:35 +0000] "SYST" 215 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:18:35 +0000] "RNFR /3cx/3CXScheduledBackup.zip.tmp" 550 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:18:45 +0000] "RNFR /3cx/3CXScheduledBackup.zip.tmp" 550 -
144.202.51.254 UNKNOWN datacomm [30/Mar/2022:21:18:45 +0000] "QUIT" 221 -
 
Hi @bigdessert,

Do you by chance have a limit on simultaneous connections to your FTP server?
 
We do not have any limit on simultaneous connections. Also, FYI this isn't a busy FTP server in fact we setup a new one yesterday just to rule out that possibility and this log is from the only 3CX system that is backing up to it.
 
Hi @bigdessert,

If you do a normal backup, do you get any errors?

Can you also temporarily reset your password to something simple and schedule a backup for a few minutes time, then run a packet capture on the PBX (Dashboard >> Activity Log >> Settings >> Verbose then start the Capture). Once the Capture is complete, download the dump file and PM me a copy. I'd like to see what is happening on both ends.
 
Backup to local filesystem is no problem. Sending a PM with the capture of FTP backup.
 
  • Like
Reactions: VasilisV_3CX
This is definitely a bug in V18. Before my upgrade from V16 to V18, I change my backup source to local to grab a local copy of the ZIP backup. After the update, I changed it back to FTP and put my info back in, copy and paste from what it was before. I can't even set the FTP location, it errors and says Cannot connect to FTP. I have other 3CX V16 instances using the same FTP server with same login credentials. Nothing else changed with this instance other than the V18 update - same server, same IP, same hostname, same everything.

Are there any active cases with support on this issue?
 
Never did get to the bottom of this. What I did do though was switch to sftp and has been flawless since.
 
Something certainly changed. We have some customers that backup to a local FTP server (owned by them) and some that backup to our managed FTPS server.

1 customer with 2 installs and local ftp - continued no issue.1 customer had issues and we ended up switching them to SMB (that's all their FTP was used for and they would have preferred SMB but it didn't exist until v16).

All clients using our managed ftps system - no issue.
 
Status
Not open for further replies.

Latest Posts

Forum statistics

Threads
111,974
Messages
590,083
Members
164,900
Latest member
Silent_Guru
3CX Logo Footer Copyright © Sitemap Privacy
Top Bottom