pmmcli_daemon running with high CPU load "forever"

[pinhighwedge]

---------------------------------------------------------------
PRODUCT, VERSION, MICROUPDATE, OPERATING SYSTEM, ARCHITECTURE
11.5.30 Ubuntu 10.04 115140407.17

PROBLEM DESCRIPTION
It seems like I ran into the same issue another user had recently in this thread:
http://forum.parallels.com/showthread.php?303467-pmmcli-daemon-running-constantly

Unfortunately I don't know what helped him at the end. The thread is closed so I had to create a new one.

Backups have been working for a long time with the same configuration that we have today. Suddenly we determined a high CPU load caused by pmmcli_daemon. It seems like this process never really ends.
We have to kill pmmcli_daemon every day manually. The log files don't really help us in determining the reason for this "endless loop" in pmmcli_daemon.


STEPS TO REPRODUCE
Wait for pmmcli_daemon to start.


EXPECTED RESULT
pmmcli_daemon to end after a certain amount of time.

ANY ADDITIONAL INFORMATION
Thanks for you help.
--------------------------------------------------------------

 

[pinhighwedge]

So nobody has an idea what could be wrong?
Could someone please point me to log files where pmmcli_daemon logs what exactly he is doing?
Is there any way to start pmmcli_daemon manually?

I got tonns of the following output when strace'ing the pmmcli_daemon PID:

..
mmap(NULL, 223399936, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b276bb5b000
munmap(0x2b2786573000, 223399936) = 0
mmap(NULL, 223399936, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2b2779068000
munmap(0x2b276bb5b000, 223399936) = 0
...

The process has a CPU time of 1400 hours. This really shouldn't be normal.

Sometimes this process reads a bunch of data like this one:
read(4, "/bin/tar: httpdocs/test/engine/connectors/api/tmp/547904c8f6bc016466c55b43b45ce5d9.tmp: Cannot stat: No such file or directory....., 61440) = 61440

So I thought that it might have something to do with temporary files which have been deleted in the meantime. Indeed, this directory had 12 Million files in this directory.
I removed all files and all backups from this client. Unfortunately even after two days the problem still persist.

So where is pmmcli_daemon getting this information from "httpdocs/test/engine/connectors/api/tmp/547904c8f6bc016466c55b43b45ce5d9.tmp"

 

[pinhighwedge]

So obviously nobody from Parallels is able to answer my questions regarding this Plesk bug.

I disabled the backups for the domain where the files: httpdocs/test/engine/connectors/api/tmp/547904c8f6bc016466c55b43b45ce5d9.tmp were located.
Even though I disabled the backup I still got it listed when executing the following SQL command:

# plesk db
mysql> select d.id as 'Domain ID',d.name as 'Domain name',c.cname as 'Client Name',bs.obj_type as 'Backup type',bs.repository as 'Destination',bs.last as 'Last time',bs.active as 'Status',bs.backup_time as 'Time',bs.content_type as 'Type',bs.period 'Period'from domains d INNER JOIN clients c ON d.cl_id=c.id INNER JOIN BackupsScheduled bs ON d.id=bs.obj_id WHERE bs.active='true';

So I decided to remove the entry manually from the table BackupsScheduled.
Unfortunately it didn't help and the backup? procedure is still running until it gets manually killed.

I put some more effort in investigating the strace output and I found out that "read(4," is reading from the following file: /opt/psa/PMM/sessions/2014-07-03-205405.884/migration.result

The file migration.result is 229MB large and contains tons of the following lines:

<message id="8b6f6ff2-8a58-4307-8909-1d9eca2bc02a" severity="warning" code="msgtext">
            <description>Failed to pack files abcdef_abcdef.com_apache-files_1407032054 in /var/lib/psa/dumps/clients/abcdef/domains/abcdef.com [ 101127366656 bytes free of 268435456000 bytes total on mount point 0]</description>
          </message>
          <message id="e6a8199e-4d05-4974-8ea9-7f3b97b0294f" severity="warning" code="msgtext">
            <description>/bin/tar: httpdocs/test/images/articles/33f15a2100fec068ef7b0f9a2bdf46f4_5.jpg: Cannot stat: No such file or directory
/bin/tar: httpdocs/test/images/articles/ff4b536b1c8cbe2497838713c75016ea_1.jpg: Cannot stat: No such file or directory
/bin/tar: httpdocs/test/images/articles/370caadff250bb4d710f63330b8a6d44_2.jpg: Cannot stat: No such file or directory
/bin/tar: httpdocs/test/images/articles/cb3744d2b4fb7d00c640ddb9973cc7bf_0.jpg: Cannot stat: No such file or directory
/bin/tar: httpdocs/test/images/articles/daa1e2c59d8d3c9a57773a70e3739ede_3.jpg: Cannot stat: No such file or directory
....
/bin/tar: httpdocs/test/engine/connectors/api/tmp/a3548cbfad263735ae6d6827979ef613.tmp: Cannot stat: No such file or directory
/bin/tar: Exiting with failure status due to previous errors
</description>
          </message>
          <message id="ccd8b004-16fa-41ea-8ade-f4ed03a123ed" severity="warning" code="msgtext">
            <description>Failed to pack files abcdef__abcdef.com_user-data_1407032054 in /var/lib/psa/dumps/clients/abcdef/domains/abcdef.com [ 87276105728 bytes free of 268435456000 bytes total on mount point 0]</description>
          </message>
        </object>
      </object>
    </object>
  </execution-result>

I deleted those temporary files (1.7 Mio approx.) on July, 3rd. So obviously a backup process was running trying to access those files.

But the big question is: Why is it trying to read those files each and every day?
After 21 hours he got to read line 780000 of 1900000 lines and it took 8 hours to read the last 60000 lines.

I'll try now to kill pmmcli_daemon again and I'll move the session dir "/opt/psa/PMM/sessions/2014-07-03-205405.884" to another location.

Unfortunately nobody from Parallels tries to explain how pmmcli_daemon works and why it is reading old session log files.

 

[pinhighwedge]

Problem solved

Today, after moving the directory "/opt/psa/PMM/sessions/2014-07-03-205405.884" to a different location yesterday, pmmcli_daemon isn't wasting CPU time anymore.

So the problem seems to be solved.

The question is why this happend and whether this is an expected behaviour or not. In my opinion it is a bug and Parallels did nothing to help nor to solve it.