Fresh install of PBX, FTP backup works, FTP restore fails, then even an uploaded restore fails... now cannot trust FreePBX

I have a fresh FreePBX deployment here. The first thing I did once I rearched the admin interface, was set up FTP in the filestore, then create a backup. I then made an extension so I can see if a restore worked. I then run that backup, it works great, Filezilla Server shows normal behaviour without errors, and I can see the backup on the FTP server machine.

If I then go to FreePBX backup and restore, I can see in the “restore from the cloud” section the backup I had just made. All details are correct. I hit the play icon to restore the backup. It fails.

The FreePBX admin interface says:

Running with: /usr/sbin/fwconsole backup --filestore='974c7f48-52ea-46d6-9a12-0b2c44c8c517' --restore='ftp       55186644 May 21 20:28 20220521-192726-1653161246-16.0.19-309585354.tar.gz' --transaction='b976a2a6-e782-440a-bb66-499b32e0aa32'
Retrieving ftp       55186644 May 21 20:28 20220521-192726-1653161246-16.0.19-309585354.tar.gz from FTP:Windows VPS...
In Filesystem.php line 389:
                                                                               
  File not found at path: ftp       55186644 May 21 20:28 20220521-192726-165  
  3161246-16.0.19-309585354.tar.gz        

And the Filezilla Server says:

(000499)21/05/2022 20:43:45 - (not logged in) (REMOVED-MY-IP)> AUTH TLS
(000499)21/05/2022 20:43:45 - (not logged in) (REMOVED-MY-IP)> 234 Using authentication type TLS
(000499)21/05/2022 20:43:45 - (not logged in) (REMOVED-MY-IP)> TLS connection established
(000499)21/05/2022 20:43:45 - (not logged in) (REMOVED-MY-IP)> PBSZ 0
(000499)21/05/2022 20:43:45 - (not logged in) (REMOVED-MY-IP)> 200 PBSZ=0
(000499)21/05/2022 20:43:45 - (not logged in) (REMOVED-MY-IP)> PROT P
(000499)21/05/2022 20:43:45 - (not logged in) (REMOVED-MY-IP)> 200 Protection level set to P
(000499)21/05/2022 20:43:45 - (not logged in) (REMOVED-MY-IP)> USER FreePBX
(000499)21/05/2022 20:43:45 - (not logged in) (REMOVED-MY-IP)> 331 Password required for freepbx
(000499)21/05/2022 20:43:45 - (not logged in) (REMOVED-MY-IP)> PASS **********
(000499)21/05/2022 20:43:45 - freepbx (REMOVED-MY-IP)> 230 Logged on
(000499)21/05/2022 20:43:45 - freepbx (REMOVED-MY-IP)> PASV
(000499)21/05/2022 20:43:45 - freepbx (REMOVED-MY-IP)> 227 Entering Passive Mode (207,180,193,163,43,69)
(000499)21/05/2022 20:43:45 - freepbx (REMOVED-MY-IP)> CWD /
(000499)21/05/2022 20:43:45 - freepbx (REMOVED-MY-IP)> 250 CWD successful. "/" is current directory.
(000499)21/05/2022 20:43:45 - freepbx (REMOVED-MY-IP)> PWD
(000499)21/05/2022 20:43:45 - freepbx (REMOVED-MY-IP)> 257 "/" is current directory.
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> HELP
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> 214-The following commands are recognized:
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)>    ABOR   ADAT   ALLO   APPE   AUTH   CDUP   CLNT   CWD 
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)>    DELE   EPRT   EPSV   FEAT   HASH   HELP   LIST   MDTM
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)>    MFMT   MKD    MLSD   MLST   MODE   NLST   NOOP   NOP 
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)>    OPTS   PASS   PASV   PBSZ   PORT   PROT   PWD    QUIT
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)>    REST   RETR   RMD    RNFR   RNTO   SITE   SIZE   STOR
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)>    STRU   SYST   TYPE   USER   XCUP   XCWD   XMKD   XPWD
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)>    XRMD
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> 214 Have a nice day.
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> CWD ftp       55186644 May 21 20:28 20220521-192726-1653161246-16.0.19-309585354.tar.gz
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> 550 CWD failed. "/ftp       55186644 May 21 20:28 20220521-192726-1653161246-16.0.19-309585354.tar.gz": directory not found.
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> NOOP
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> 200 OK
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> TYPE A
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> 200 Type set to A
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> LIST -A ftp       55186644 May 21 20:28 20220521-192726-1653161246-16.0.19-309585354.tar.gz
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> 550 Directory not found.
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> QUIT
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> 221 Goodbye
(000499)21/05/2022 20:43:46 - freepbx (REMOVED-MY-IP)> disconnected.

But the file is there, and is completely untouched from the backup I made only minutes before. If I try the download button intead, it downloads a 0 bytes file.

I then tried to upload the file under “Upload your restore files”. This restore takes forever, way longer than any other restore I’ve ever done on any other system, and it then fails. The log is huge so I won’t paste it all here, but this is the last bit:

Reloading...... DONE
Running Post Restore Hooks.. Please note that hook will restart httpd service so please refresh your page (using new ports) 
Running Post Restore Hooks DONE
Finished
There were warnings during the restore process
	Can't find the module data for ttsengines
	Can't find the module data for callback
	Can't find the module data for callerid
	Can't find the module data for calllimit
	Can't find the module data for conferencespro
	Can't find the module data for miscdests
	Can't find the module data for phonebook
	Can't find the module data for setcid
npm WARN deprecated [email protected]: Package no longer supported. Contact [email protected] for more info.
npm WARN deprecated [email protected]: This version of 'is-buffer' is out-of-date. You must update to v1.1.6 or newer

The backup did remove the extension, so it seems some of it did work, but for both restores to fail on a fresh system, as a new FreePBX user, is extremely concerning.

If I did do any future deployments, I wouldn’t feel comfortable doing it anywhere else than a Virtual Machine where I could use the VM’s snapshot features to restore a backup which would also be significantly faster. A bare metal install is clearly a poor idea.

The restore path looks odd in your log file. You could try to correct that manually using the command line. I haven’t checked whether this is configuration problem or a small bug in the backup script.

I wouldn’t know how to do that on the command line, but I haven’t tried to Google it yet. That being said, I shouldn’t need to. Backup and restore should just work and be the most stable part of the whole system, in my view, and as it’s a fresh system, I guess this is a bug?

I think the first place is to review your configurations. I suspect if it’s a 0kb file then there is nothing set in the backup options. As you’ve mentioned it’s a fairly fundamental part of the system and if there was that much of a big there would be more reports in the forum.

Most issues I have seen recently is usually involving restoring from an older/EOL version.

I would recheck through your steps on the wiki to make sure you have followed the back up process correctly and that you have selected all the correct options to backup.

I think the OPs real point is that this restore was part of an acceptance test, rather than being done in anger, but most people’s first encounter with a restore will be one when something has broken, and it is particularly important that a restore should work the first time attempted.

Restores are potentially dangerous operations, and people won’t want to do a restore, on an operational system just to confirm it would work, and few would try restores on a spare system. I’m not sure, but I suspect the licence enforcement measures could well get in the way of a test restore onto a second system, for anyone with commercial modules.

@rsmithuk It’s a normal size file on the FTP server itself, it’s only a 0kb file when downloading it through the “Restore from the cloud interface”. I don’t see what configuration I would need to change considering the file on the FTP server is normal. The backup has a name, and everything else except selecting FTP as the location, is the default. There should not be any configuration problems from default. I believe I have followed the process correctly.

@david55 Absolutely, I wanted to test the backup function before I actually need it, and the fact it doesn’t work straight out of the box is concerning. I’ve done another test today with a system that isn’t fresh, backing up and restoring to itself, and it has failed again. This new server (the one for this original post was bare metal) is on Hyper-V. The built in restore from an uploaded file took about 20 minutes, yet I can click a Hyper-V checkpoint and restore the server in 10 seconds. If I cannot trust the built in backup solution then the only alternative would be to use it in a virtual machine, but I wonder what performance penalty that has?

I have been using VirtualBox for many years now. I usually install Linux Mint on an Intel NUC and install freePBX within VirtualBox. There are no issues with performance and it is 100% stable. You can return to a previous snapshot within seconds and you can export the freePBX VM to any other hardware.

Was going to file a bug report, but versions are not included, so ask that you please do that with enough detail for engineering to repro. https://issues.freepbx.org/

@Charles_Darwin Good to know, thanks. Even if the restore process did work, it takes far too long at 20+ minutes, when a VM restore takes 10 seconds, so it’s almost certain I’d deploy any future Sangoma system in a VM, providing it didn’t hit performance. To hear it has been performing well for you is excellent. I do wonder how restoring to different hardware would impact any commercial modules though? Does the MAC address stay with an exported VM? Intruging.

@lgaetz Although I’ve been able to reproduce again, I don’t have the energy at the moment to do it again, but when I do, I’ll try to slip in an issue, thanks.

In Virtualbox there is an export option (non-standard, you’ll find out), which worked last time I checked…1 year ago.
But of course there is always the possibility that you have to re-activate and move licences.

My own testing is working fine, I’m able to restore from cloud FTP without issue. In order to get this resolved, we need someone with the issue to open a ticket.

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.