Replies to This Discussion

Permalink Reply by Jerry Schmidt on September 11, 2013 at 1:17pm

Hello Roger,

Backup policies have the ability to manage multiple folders. Is it possible that you have two backup polices that are both backing up the same folder?

• ▶ Reply

Permalink Reply by Roger Jackson on September 11, 2013 at 1:31pm

Nope I am positive and in addition I am not using the CBT feature either. I am just looking to get a straight copy of the VM. I have been looking at other issues with the software for days now and trying to avoid dealing with support since I am on the free product. Documentation is virtually non-existent.

I was using the free version to test it out to see if I like it or not. It has been running about a 2 months now and I am already hitting weird error messages and call support messages as well. All in all, I do not think this is a very good product if I am having these kinds of issues for a very minor backup scheme I have for it. It had seemed to work well in the beginning but now I am getting an error message that the /var/logs are full 0% available when as far as I can tell there is space available and another one telling me to delete snapshot XYZ manually.

Be that as it may, I did some more testing and sure enough if I make a change to the policy and save it the job immediately kicks off and does it thing. Which it shouldn't be doing since it is supposed to go off at night. So odd ...

• ▶ Reply

Permalink Reply by Jerry Schmidt on September 11, 2013 at 1:50pm

Maybe someone can else can weigh in on why the jobs are running twice a day if only scheduled to run once a day and why they run when you save the backup policy. I have not seen this issue yet.

/var/logs may be filling up because the system integrity check is enabled in the advanced configuration and there are VM(s) in the environment that need check disk run. If this is the case and the issues with the VM(s) is not resolved then /var/logs can fill up. To avoid this you can disable that feature in vmPro. The logs can be truncate, but it would require a support ticket.

The message about needing to manual delete a snapshot can be caused by many different issues, but to resolve you can clear the alert from vmPro and then access the VM(s) with the snapshot, right click, select snapshot manager, select the snapshot and then delete it. Check vmPro and you should see the error on the VM clear and backups on that VM(s) should resume. Moving forward it would be good to monitor and if the error returns, make note of what was going on with the VM and vmPro when the snapshot is not properly removed.

• ▶ Reply

Permalink Reply by Roger Jackson on September 11, 2013 at 2:01pm

Well that is what makes it even stranger to me is that it is referencing what to me looks like a file on the vmPro appliance itself and not on the snapshot chain of the vm itself. In actuality there are no snapshots at all of the vm. I deleted all the messages I got today but I will post them tomorrow as I get them daily now and we can see if anyone can point me in the right direction for solutions.

But definitely it is running twice a day and I have no idea why and as I mentioned my friend is using the same free version and it does the same to him. So I am now thinking that if you are running the full pay version maybe it is just a bug in the free version.

• ▶ Reply

Permalink Reply by Jerry Schmidt on September 12, 2013 at 5:22am

Post the errors when you get a chance.

There is no difference between the free version and the paid version other that the limit on data that can be backed up and the paid version allows for technical support.

• ▶ Reply

Permalink Reply by Roger Jackson on September 12, 2013 at 7:48am

I agree I would think they "should" be the same but the fact that they limited the size of the source does mean they have altered it in some way which may have introduced a bug.

Here is one of the first errors I started getting. But the thing is there are no snapshots of the VM at all and I have no idea where the "quantum" dir is located; I am guessing on the vmPro VM somewhere but I don't have access to it via the command line

ESX Server 'vmi04.c2k.com',  Virtual Machine '421c2924-a11c-d5af-e0d6-d650dd706961': VM 'VSvdi01' on server 'vmi04.c2k.com' has a leftover vmPRO snapshot created over 7 days ago.  If you are no longer exporting this VM, Please manually delete snapshot 'Quantum: 4644f1c4c6e611e2b813005056bc17de'. If it isn't automatically removed after the next backup please contact support.

Here is where the job is already running when the scheduled time kicks off.

Q-vmPRO-ii                         Error     This policy is already running and concurrent policy execution              13.00 GB     08 Sep 20:00:04  08 Sep 20:00:04  0 seconds                       0%      

vdicon01                        Error     This policy is already running and concurrent policy execution              92.00 GB     08 Sep 20:00:05  08 Sep 20:00:05  0 seconds                       0%      

vdicon02                        Error     This policy is already running and concurrent policy execution              40.00 GB     08 Sep 20:00:05  08 Sep 20:00:05  0 seconds                       0%      

Then this started happening and there is no problem with the target when I checked it.

SmartMotion has stalled while copying /export/vmi04.c2k.com/VSvdi01 for over 1 hour and may be hung. Please check your target storage or abort the running task.

then this started showing up

05 Sep 07:06:03  Quantum vmPRO internal filesystem /var/log is low on space: 100% used (0 MB free).

And this from the log?

'Jul 19 13:01:10 localhost logrotate: ALERT exited abnormally with [1]'

'Jun 22 13:59:43 localhost watchdog: ALERT: Postgresql is down, restart'

Then this is the newest one I am getting for a VM

SmartMotion has stalled while copying /export/vmi04.camp2k.com/KY-VPC for 30 minutes and may be hung. Please check your target storage or abort the running task. 

/vmfs/volumes/5177f593-8c1e5b06-8d86-90b11c2c87c8/KY-VPC/KY-VPC-flat.vmdk: Transport endpoint is not connected

Basically it looks like it has all turned into a hot mess. I am thinking I will just blow it away and start over again to get it sorted out but seriously not very impressed that it degraded into this so quickly. I have used Veeam, Replay, vRanger, TriLead and some others just checking them out and have not had any of them act this weird or they had documentation that was available already to sort out any issues or via forum posts.

• ▶ Reply

Permalink Reply by Jon McNerny on September 12, 2013 at 10:29am

Let's start with the orginal problem.

When you update a policy you should see some logging from the 'controller' such as this.

2013-09-12 11:09:45: controller/INFO:: ControllerCommands.py:3362 New controller command: update_backup_policy (39a228d3-106a-4239-8c64-aa551a47ed6b) 2013-09-12 11:09:45: controller/INFO:: ControllerCommands.py:3289 Enter command: update_backup_policy (39a228d3-106a-4239-8c64-aa551a47ed6b), pid: 27461 2013-09-12 11:09:46: controller/INFO:: ControllerCommands.py:3293 Exit command normally: update_backup_policy (39a228d3-106a-4239-8c64-aa551a47ed6b), pid: 27461 2013-09-12 11:09:46: controller/INFO:: utils.py:81 check_for_finished_cmds(ControllerCommands.pyc:3425): command process finished: 27461

Then you will see the smartmotion log a quick test on the NAS. 2013-09-12 11:09:45,643 smartmotion/INFO:: Tomato.py:1190 check mount 6a06d24b-fdb9-4fe7-b766-008ca00003d8, NFSvmpro 2013-09-12 11:09:45,645 smartmotion/INFO:: mount_manager.py:142 Locking storage "6a06d24b-fdb9-4fe7-b766-008ca00003d8" for command 1cc6fa3a-878f-422b-9dfd-2d74b60fae81test 2013-09-12 11:09:46,001 smartmotion/INFO:: mount_manager.py:158 Unlocking storage "6a06d24b-fdb9-4fe7-b766-008ca00003d8" for command 1cc6fa3a-878f-422b-9dfd-2d74b60fae81test 2013-09-12 11:09:46,003 smartmotion/INFO:: mount_manager.py:205 Storage test write successful for "6a06d24b-fdb9-4fe7-b766-008ca00003d8" 2013-09-12 11:09:46,003 smartmotion/INFO:: Tomato.py:1213 check mount 6a06d24b-fdb9-4fe7-b766-008ca00003d8, passed

When a policy starts a backup i would expect to see some logginn from the smartmotion like this...

2013-09-12 11:19:02,739 smartmotion/INFO:: Tomato.py:461 Running SmartMotion copy: ['/usr/local/pancetera/bin/smartcp', '--preserve=timestamps', '--sparse=always', '--stats-output=json', '/export/WindowsVMs/Win2008R2 VSS Jon/Win2008R2 VSS Jon.vmdk', '/storage/.6a06d24b-fdb9-4fe7-b766-008ca00003d8/2013-09/2013-09-12-111901/WindowsVMs/Win2008R2 VSS Jon']

We don't, intentionally kick off a backup once a policy is modified, do you have logging to support this?

In addition if there has been a backup right when you configure a policy we should see a timestamp in your NAS target.

Here for example we can see i manually kicked off a backup at 11:19 today, but my policy configuration happened at 11:09 ten minutes earlier.  If the poly config triggers the backup, we should see it right away I'm thinking.

bash-4.1# pwd /storage/NFSvmpro/2013-09 bash-4.1# ls | grep 2013-09-12- 2013-09-12-000002 2013-09-12-083351 2013-09-12-111901

You can look at the logs in question from Help>vmpro system in the GUI if you'd like to share some time stamps.  You'll have to pull the NAS details on your own.

Jon

• ▶ Reply