Backup process stuck in loop

[Matthew James]

Hi,

It appears my full server backup (or one of the domain backups) never completes and gets itself stuck in a loop. It causes high load on the server and I cannot see which backup process is causing it to happen (server or domain etc).

12182 root 35 10 23640 15m 836 R 84.2 0.8 678:57.87 /usr/bin/perl /usr/local/psa/admin/bin/plesk_agent_manager domains-id --owner-uid=03b9383c-6900-

stracing the process shows the following:

--- SIGPIPE (Broken pipe) @ 0 (0) ---
write(1, "v) {\n\t\tif ( 'keypress' == ev.typ"..., 36864) = -1 EPIPE (Broken pipe)
--- SIGPIPE (Broken pipe) @ 0 (0) ---
write(1, "v) {\n\t\tif ( 'keypress' == ev.typ"..., 36864) = -1 EPIPE (Broken pipe)
--- SIGPIPE (Broken pipe) @ 0 (0) ---
write(1, "v) {\n\t\tif ( 'keypress' == ev.typ"..., 36864) = -1 EPIPE (Broken pipe)

This just repeats itself over and over again.

Any ideas how I can track down what's causing this to happen and fix the problem?

Thanks

 

[IgorG]

Logs from /usr/local/psa/PMM/ should be investigated at least.

 

[Matthew James]

Hi IgorG,

Which logs are you specifically referring to here, as there are lots...

pmmcli_daemon.log contains lots of these:

2011-05-12 12:48:58 Action UnsuspendTaskAction started
2011-05-12 12:48:58 Action param: session_id:/usr/local/psa/PMM/sessions/2011-04-16-041702.991
2011-05-12 12:48:58 Action MailToAction started
2011-05-12 12:48:58 Action params: task_type:Backup, owner_guid:03b9383c-6900-4974-96a5-a453ba02e9d6, owner_type:None, creation_date:2011-Apr-15 04:17:02, fullname:None, logfilename:/usr/local/psa/PMM/sessions/2011-04-15-041701.604/migration.result, mail_to:[email protected]
2011-05-12 12:48:58 exception during action processing
Stacktrace is: Traceback (most recent call last):
File "/usr/local/psa/admin/share/pmmcli/pmmcli_daemon_actions.py", line 545, in process
action_item.process(logger)
File "/usr/local/psa/admin/share/pmmcli/pmmcli_daemon_actions.py", line 320, in process
mailsender.send(logger,self.__mail_to,self.__task_type,self.__task_status,self.__owner_guid,self.__owner_type,self.__creation_date,self.__fullname,self.__logfilename)
File "/usr/local/psa/admin/share/pmmcli/pmmcli_daemon_actions.py", line 281, in send
sendmail = subprocess.Popen(["sendmail",mail_sender,"-t","-oi"], stdin = subprocess.PIPE)
File "/usr/lib/python2.4/subprocess.py", line 550, in __init__
errread, errwrite)
File "/usr/lib/python2.4/subprocess.py", line 993, in _execute_child
raise child_exception
OSError: [Errno 2] No such file or directory

2011-05-12 12:48:58 Action UnsuspendTaskAction started
2011-05-12 12:48:58 Action param: session_id:/usr/local/psa/PMM/sessions/2011-04-15-041701.604
2011-05-12 12:48:58 Action PmmcliLogRotateAction started
2011-05-12 12:48:58 Action param: file_namemmcli.log
2011-05-12 12:48:58 Action PmmcliLogRotateAction started
2011-05-12 12:48:58 Action param: file_namemmcli_daemon.log
2011-05-12 12:48:58 Action PmmcliLogRotateAction started
2011-05-12 12:48:58 Action param: file_name:migration.log
2011-05-12 12:48:58 Action PmmcliLogRotateAction started
2011-05-12 12:48:58 Action param: file_name:migration_handler.log
2011-05-12 12:48:58 daemon job delayed for 30 minutes

And pmmcli.log is full of:

29142: 2011-05-12 13:04:35,275 DEBUG --> <pmmcli.GetTaskStatusAction object at 0xb7f11a6c>
29142: 2011-05-12 13:04:35,275 INFO parameters: ['8557']
29142: 2011-05-12 13:04:35,279 DEBUG <pmmcli.ActionRunner object at 0xb7f1188c>: doActivity
29142: 2011-05-12 13:04:35,279 DEBUG Acquired session mutex: MainThread
29142: 2011-05-12 13:04:35,304 DEBUG Released session mutex: MainThread
29142: 2011-05-12 13:04:35,304 DEBUG <pmmcli.GetTaskStatusAction object at 0xb7f11a6c>: response
29142: 2011-05-12 13:04:35,305 INFO Outgoing packet:
<?xml version="1.0" encoding="UTF-8"?>
<response>
<errcode>0</errcode>
<data>
<task-status task-id="8557">
<working>
<dumping total-accounts="0" completed-domains="0" completed-accounts="0" total-domains="1">
</dumping>
</working>
</task-status>
</data>
</response>

There are also lots of other logs in this directory, which one should I specifically be looking at, I can't see anything that shows what the problem is in any of them.

Thanks

 

[Matthew James]

Further to last response, just seen the bit that mentions the migration.result log above, so looked at that and can see errors:

[root@aries logs]# cat /usr/local/psa/PMM/sessions/2011-04-15-041701.604/migration.result
<?xml version="1.0" encoding="UTF-8"?>
<execution-result status="error" log-location="/usr/local/psa/PMM/sessions/2011-04-15-041701.604/migration.result">
<object name="test.com" type="domain">
<object name="test.com" type="hosting">
<message id="a291e7a3-ead1-4267-8ce8-7195ac4345dd" severity="error" code="msgtext">
<description>Unable to rotate dump: The dump rotation is failed with code '1' at /usr/local/psa/admin/bin/plesk_agent_manager line 1108.
at /usr/local/psa/admin/bin/plesk_agent_manager line 1108
main::rotateDump('/backups', 'undef', 2, '03b9383c-6900-4974-96a5-a453ba02e9d6', 1, '/usr/local/psa/PMM/sessions/2011-04-15-041701.604', 'undef') called at /usr/local/psa/admin/bin/plesk_agent_manager line 742
main::__ANON__() called at /usr/local/psa/PMM/agents/shared/Error.pm line 405
eval {...} called at /usr/local/psa/PMM/agents/shared/Error.pm line 397
Error::subs::try('CODE(0xa0e1610)', 'HASH(0xa0e1670)') called at /usr/local/psa/admin/bin/plesk_agent_manager line 750
main:erform('verbose', 0, 'owner-uid', '03b9383c-6900-4974-96a5-a453ba02e9d6', 'split-size', 'undef', 'domains-id', 'ARRAY(0x9ada3a8)', 'session-path', ...) called at /usr/local/psa/admin/bin/plesk_agent_manager line 1166
main::__ANON__() called at /usr/local/psa/PMM/agents/shared/Error.pm line 398
eval {...} called at /usr/local/psa/PMM/agents/shared/Error.pm line 397
Error::subs::try('CODE(0x9ad9b44)', 'HASH(0xa74f1b0)') called at /usr/local/psa/admin/bin/plesk_agent_manager line 1175
main::main() called at /usr/local/psa/admin/bin/plesk_agent_manager line 1177.
</description>
</message>
<message id="9f377ee0-a2ef-4caf-815a-fe1484dcd1b4" severity="error" code="CheckDump">
<description>Unable to check dump: Could not check dump. Invalid xml response:
at /usr/local/psa/PMM/agents/PleskX/PmmCli.pm line 177
PmmCli:arseCheckDumpResult('Error: adjacent parameter is empty in \'dump-file-specificati...') called at /usr/local/psa/admin/bin/plesk_agent_manager line 1092
main::checkDump('/backups', '', '/usr/local/psa/PMM/sessions/2011-04-15-041701.604') called at /usr/local/psa/admin/bin/plesk_agent_manager line 648
main::__ANON__() called at /usr/local/psa/PMM/agents/shared/Error.pm line 405
eval {...} called at /usr/local/psa/PMM/agents/shared/Error.pm line 397
Error::subs::try('CODE(0xa0e1610)', 'HASH(0xa0e16d0)') called at /usr/local/psa/admin/bin/plesk_agent_manager line 656
main:erform('verbose', 0, 'owner-uid', '03b9383c-6900-4974-96a5-a453ba02e9d6', 'split-size', 'undef', 'domains-id', 'ARRAY(0x9ada3a8)', 'session-path', ...) called at /usr/local/psa/admin/bin/plesk_agent_manager line 1166
main::__ANON__() called at /usr/local/psa/PMM/agents/shared/Error.pm line 398
eval {...} called at /usr/local/psa/PMM/agents/shared/Error.pm line 397
Error::subs::try('CODE(0x9ad9b44)', 'HASH(0xa74f1b0)') called at /usr/local/psa/admin/bin/plesk_agent_manager line 1175
main::main() called at /usr/local/psa/admin/bin/plesk_agent_manager line 1177.
</description>
</message>
<message id="65292db4-6534-4541-85e6-084a9a14c8dd" severity="error" code="fatal">
<description>Unable to create dump</description>
</message>
</object>
</object>
</execution-result>

So if it is unable to create this dump, should it not just continue with the rest of the backup process rather than just sitting there stuck in a constant loop causing high load on the server? It happens every single day and I have to kill the process every single day:

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
9072 root 35 10 23640 15m 804 R 98.4 0.8 513:32.54 /usr/bin/perl /usr/local/psa/admin/bin/plesk_agent_manager domains-id --owner-uid=03b9383c-6900-4974-96a5-a453ba02e9d6 --dump-rotation=2 --session-pa

 

[micxz]

Same errors here.

I'm getting the same errors when limiting the backups to one copy and scheduling them. First backup goes good then when the rotate happens in chokes.

psa v10.2.0_build1011110331.11 os_CentOS 5