Remote FTP Backup - Error Code 1

[DeviateDefiant]

Evening folks,

This issue has been stumping me for a while now. Backups to an external FTP repo will not complete and haven't done for some time, they accumulate in the server repo - the FTP repo itself is accessible just fine using CLI commands.

The local backup itself completes fine so I assume this isn't a space issue, /var is mounted on the main RAID5 storage with tons of space to spare, everything else is stuck on a smaller partition - this would not have enough room to accommodate the backup - I say this incase it would be replicated elsewhere before transport for whatever reason.

Plesk 12.0.18 Update #60 on Debian 7 x64

Expand/Collapse Block: Several Log Files

migration.result

<?xml version="1.0" encoding="UTF-8"?>
  <execution-result status="error" log-location="/opt/psa/PMM/sessions/2015-08-20-005303.5/migration.result">
  <message id="7506c67c-7461-469b-8dd1-7e2938dddfb4" severity="error" code="msgtext">
  <description>Can&#39;t upload file &#39;manual_info_1508200053.xml&#39; to ftp. Error code: 1</description>
  </message>
  </execution-result>

migration.log

(...)
[2015-08-20 01:04:21.950| 6185] INFO: pmm-ras finished. Exit code: 0
[2015-08-20 01:04:21.968| 6187] INFO: pmm-ras started : /opt/psa/admin/bin/pmm-ras --export-dump-as-file --dump-specification=manual_info_1508200053.xml --dump-file-specification=ftp://REMOVED@REMOVED//manual_1508200053.tar --debug --verbose --session-path=/opt/psa/PMM/sessions/2015-08-20-005303.5
[2015-08-20 01:04:21.968| 6187] INFO: Repository '/var/lib/psa/dumps': Initializing...
[2015-08-20 01:04:21.968| 6187] INFO: Transport: Get repository transport /var/lib/psa/dumps
[2015-08-20 01:04:21.969| 6187] INFO: Transport: Init credentials for user ''
[2015-08-20 01:04:21.969| 6187] INFO: Repository '/var/lib/psa/dumps': Initialized
[2015-08-20 01:04:21.969| 6187] INFO: Repository 'ftp://REMOVED//': Initializing...
[2015-08-20 01:04:21.969| 6187] INFO: Transport: Get repository transport ftp://REMOVED//
[2015-08-20 01:04:21.969| 6187] INFO: Transport: Init credentials for user 'REMOVED'
[2015-08-20 01:04:21.970| 6187] INFO: Repository 'ftp://REMOVED//': Initialized
[2015-08-20 01:04:21.971| 6187] INFO: pmm-ras finished. Exit code: 1

psadump.log

(...)
== STDERR ====================
1+0 records in
1+0 records out
31457280 bytes (31 MB) copied, 0.0236099 s, 1.3 GB/s
Use of uninitialized value in numeric eq (==) at /opt/psa/admin/bin/plesk_agent_manager line 828.
[2015-08-20 01:04:21.968| 6187] INFO: pmm-ras started : /opt/psa/admin/bin/pmm-ras --export-dump-as-file --dump-specification=manual_info_1508200053.xml --dump-file-specification=ftp://REMOVED@REMOVED//manual_1508200053.tar --debug --verbose --session-path=/opt/psa/PMM/sessions/2015-08-20-005303.5
[2015-08-20 01:04:21.968| 6187] INFO: Repository '/var/lib/psa/dumps': Initializing...
[2015-08-20 01:04:21.968| 6187] INFO: Transport: Get repository transport /var/lib/psa/dumps
[2015-08-20 01:04:21.969| 6187] INFO: Transport: Init credentials for user ''
[2015-08-20 01:04:21.969| 6187] INFO: Repository '/var/lib/psa/dumps': Initialized
[2015-08-20 01:04:21.969| 6187] INFO: Repository 'ftp://REMOVED//': Initializing...
[2015-08-20 01:04:21.969| 6187] INFO: Transport: Get repository transport ftp://REMOVED//
[2015-08-20 01:04:21.969| 6187] INFO: Transport: Init credentials for user 'REMOVED'
[2015-08-20 01:04:21.970| 6187] INFO: Repository 'ftp://REMOVED//': Initialized
[2015-08-20 01:04:21.971| 6187] INFO: pmm-ras finished. Exit code: 1

==============================

pmmcli.log

(...)
[2015-08-20 00:53:03.288|29819] DEBUG: LOG: custom log /var/log/plesk/PMM/backup-2015-08-20-00-53-03-568/backup.log
[2015-08-20 00:53:03.290|29819] INFO: Executing asynchronously <subprocess[29820] 'nice --adjustment=10 /usr/bin/perl /opt/psa/admin/bin/plesk_agent_manager server --owner-uid=73a932b8-8c61-441d-827c-4681a33a2f9b --owner-type=server --backup-profile-name=manual --description=Server backup. -vvvv --session-path=/opt/psa/PMM/sessions/2015-08-20-005303.5 --output-file=ftp://REMOVED@REMOVED//'>
[2015-08-20 00:53:03.290|29819] DEBUG: Acquired session mutex: MainThread
[2015-08-20 00:53:03.290|29819] DEBUG: detecting running pmmcli daemon...
[2015-08-20 00:53:03.290|29819] DEBUG: starting pmmcli daemon...
[2015-08-20 00:53:03.291|29819] DEBUG: Executing asynchronously [29821] process
[2015-08-20 00:53:03.291|29819] DEBUG: Released session mutex: MainThread
[2015-08-20 00:53:03.291|29819] DEBUG: Acquired session mutex: MainThread
[2015-08-20 00:53:03.292|29819] DEBUG: Released session mutex: MainThread
[2015-08-20 00:53:03.292|29819] DEBUG: <pmmcli.MakeDumpAction object at 0xd26690>: response
[2015-08-20 00:53:03.293|29819] INFO: Outgoing packet:
<?xml version="1.0" ?><response>
  <errcode>0</errcode>
  <data>
  <task-id>29820</task-id>
  </data>
</response>

I've read dozens of forum posts, any KB articles that seem relevant and tried everything proposed. I've reapplied all the latest patches, and I'm literally just scratching my head.

What am I missing folks?

I'd request formal support but the pricing seems pretty high for what could be a simple issue I'm overlooking.

Any advice greatly appreciated,
Leo

 

[IgorG]

Do you have any output of following command:

# grep 'FTP ERROR' /usr/local/psa/PMM/sessions/<timestamp>/migration.result

Also try to run the test from this KB article - http://kb.odin.com/en/125978

 

[DeviateDefiant]

Apologies for the late reply, I didn't have email notification set-up.

No output from the command, and no issue running the test in the KB article:

[2015-08-22 09:41:46.524| 5685] INFO: < 226-File successfully transferred
[2015-08-22 09:41:46.524| 5685] INFO: < 226 32.455 seconds (measured here), 58.54 Mbytes per second
(...)
[2015-08-22 09:41:46.525| 5685] INFO: pmm-ras finished. Exit code: 0

 

[DeviateDefiant]

Does anyone have any further suggestions?

 

[DeviateDefiant]

Another bump.

 

[DeviateDefiant]

Further bump, @IgorG?

 

[IgorG]

I can suggest you contact Odin Support Team.