Problems and Technical Issues with Rosetta@home

Message boards : Number crunching : Problems and Technical Issues with Rosetta@home

To post messages, you must log in.

Previous · 1 . . . 192 · 193 · 194 · 195 · 196 · 197 · 198 . . . 309 · Next

AuthorMessage
Profile Greg_BE
Avatar

Send message
Joined: 30 May 06
Posts: 5691
Credit: 5,859,226
RAC: 0
Message 105595 - Posted: 20 Mar 2022, 18:07:58 UTC - in response to Message 105590.  

It seems Someone has made incorrect workunits and sent them to the system without testing.



Probably the same twit that made those other faulty tasks
ID: 105595 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Profile Greg_BE
Avatar

Send message
Joined: 30 May 06
Posts: 5691
Credit: 5,859,226
RAC: 0
Message 105597 - Posted: 20 Mar 2022, 18:09:58 UTC - in response to Message 105588.  

zxcvbob - check and see if the task begins with aagb-
If it is, just abort it. It's got bugs.
ID: 105597 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Profile Greg_BE
Avatar

Send message
Joined: 30 May 06
Posts: 5691
Credit: 5,859,226
RAC: 0
Message 105598 - Posted: 20 Mar 2022, 18:19:44 UTC - in response to Message 105589.  
Last modified: 20 Mar 2022, 18:20:05 UTC

Ron,

Your completing 4.2 tasks ok.
Your might be failing on Pythons as they are something different.
At the bottom of this page (your account version) https://boinc.bakerlab.org/rosetta/show_host_detail.php?hostid=6179325 should be a button to turn on or turn off VirtualBox VM jobs.
Make sure you have virtual box installed and that your VT-x is turned on in your BIOS.
Then try again to download some work.
ID: 105598 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Sid Celery

Send message
Joined: 11 Feb 08
Posts: 2141
Credit: 41,538,222
RAC: 10,691
Message 105604 - Posted: 21 Mar 2022, 0:43:07 UTC - in response to Message 105594.  
Last modified: 21 Mar 2022, 0:43:56 UTC

Looks like aagb sequence has problems.
You have one and I have one.
I think the other guy who is stalled probably got one.

Imo that's saying too much.
I have a lot of aagb tasks that are running perfectly fine and, without going through the detail, I think the majority are running just fine.
But if there is a problem somewhere, it might be more likely on an aagb task, but that's only based on 1 task being reported from each of maybe 3 people here.

I wouldn't get pre-emptive on this. Use the method I described above on long-running tasks and, if CPU time is lagging excessively, abort them because nothing will restart them otherwise, whatever the task-name happens to be.

One other thing I've noticed that's a bit weird with all Python tasks:
CPU time often shows a few minutes <more> than Elapsed time, which is obviously impossible.
Seems like the clock doesn't start running until after some initialising has gone on.
Or something.
Doesn't make any difference to anything - just odd
ID: 105604 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Sid Celery

Send message
Joined: 11 Feb 08
Posts: 2141
Credit: 41,538,222
RAC: 10,691
Message 105605 - Posted: 21 Mar 2022, 1:04:21 UTC - in response to Message 105604.  

One other thing I decided to do the other day on my one PC that runs Python tasks, which may help someone else.
Instead of maximising the RAM I allocate to Boinc to run as many tasks as possible (I reached either 11 or 12 with 95% RAM at one point) I reduced the RAM allocation to 88% so that only 10 run at a time from 16 hyperthreaded cores.
When I maximised RAM I had instances of a crash that would take all the other tasks out with a Computation Error, causing lots of downtime, especially if it happened overnight or when I was away.
With slightly reduced RAM and fewer tasks running at once, that seems to have stopped.
Not ideal, but much more successful for me.
ID: 105605 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Mr P Hucker
Avatar

Send message
Joined: 12 Aug 06
Posts: 1600
Credit: 12,116,986
RAC: 9,863
Message 105606 - Posted: 21 Mar 2022, 1:59:12 UTC

Did anyone come to a conclusion on my stderr outputs?
ID: 105606 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Profile Greg_BE
Avatar

Send message
Joined: 30 May 06
Posts: 5691
Credit: 5,859,226
RAC: 0
Message 105609 - Posted: 21 Mar 2022, 9:31:49 UTC - in response to Message 105606.  

Did anyone come to a conclusion on my stderr outputs?



Your vbox sequence for startup is normal, which means the problem happens later in the process.

I had radical time change error somewhere after 4 hours after boinc came back to the task after working on other tasks.

There was a time descrepency between the checkpoint and the start point. How that happened is beyond my understanding. But it fubar'd the task to where it was not function and had to be aborted.

So let your tasks run longer and look after the setup and first checkpoint for anything not normal.

If it's all normal then it's something deep inside the task we can not see.
ID: 105609 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Profile Greg_BE
Avatar

Send message
Joined: 30 May 06
Posts: 5691
Credit: 5,859,226
RAC: 0
Message 105610 - Posted: 21 Mar 2022, 9:31:50 UTC - in response to Message 105606.  

Did anyone come to a conclusion on my stderr outputs?



Your vbox sequence for startup is normal, which means the problem happens later in the process.

I had radical time change error somewhere after 4 hours after boinc came back to the task after working on other tasks.

There was a time descrepency between the checkpoint and the start point. How that happened is beyond my understanding. But it fubar'd the task to where it was not function and had to be aborted.

So let your tasks run longer and look after the setup and first checkpoint for anything not normal.

If it's all normal then it's something deep inside the task we can not see.
ID: 105610 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Mr P Hucker
Avatar

Send message
Joined: 12 Aug 06
Posts: 1600
Credit: 12,116,986
RAC: 9,863
Message 105612 - Posted: 21 Mar 2022, 9:51:53 UTC - in response to Message 105610.  

This is a bad computer after having run a Python for 1 day 5 hours, with CPU usage at 16 minutes:

2022-03-20 00:53:25 (43240): Detected: vboxwrapper 26202
2022-03-20 00:53:25 (43240): Detected: BOINC client v7.19.0
2022-03-20 00:53:27 (43240): Detected: VirtualBox VboxManage Interface (Version: 5.2.44)
2022-03-20 00:53:27 (43240): Feature: Checkpoint interval offset (186 seconds)
2022-03-20 00:53:27 (43240): Detected: Minimum checkpoint interval (600.000000 seconds)
2022-03-20 00:53:29 (43240): Create VM. (boinc_923b5ddf89fefc4a, slot#0)
2022-03-20 00:53:29 (43240): Setting Memory Size for VM. (6144MB)
2022-03-20 00:53:29 (43240): Setting CPU Count for VM. (1)
2022-03-20 00:53:30 (43240): Setting Chipset Options for VM.
2022-03-20 00:53:30 (43240): Setting Boot Options for VM.
2022-03-20 00:53:30 (43240): Setting Network Configuration for NAT.
2022-03-20 00:53:31 (43240): Disabling VM Network Access.
2022-03-20 00:53:31 (43240): Disabling USB Support for VM.
2022-03-20 00:53:31 (43240): Disabling COM Port Support for VM.
2022-03-20 00:53:31 (43240): Disabling LPT Port Support for VM.
2022-03-20 00:53:32 (43240): Disabling Audio Support for VM.
2022-03-20 00:53:32 (43240): Disabling Clipboard Support for VM.
2022-03-20 00:53:32 (43240): Disabling Drag and Drop Support for VM.
2022-03-20 00:53:33 (43240): Adding storage controller(s) to VM.
2022-03-20 00:53:33 (43240): Adding virtual disk drive to VM. (vm_image.vdi)
2022-03-20 00:53:33 (43240): Adding VirtualBox Guest Additions to VM.
2022-03-20 00:53:33 (43240): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB)
2022-03-20 00:53:34 (43240): Enabling shared directory for VM.
2022-03-20 00:53:34 (43240): Starting VM using VBoxManage interface. (boinc_923b5ddf89fefc4a, slot#0)
2022-03-20 00:53:42 (43240): Successfully started VM. (PID = '42088')
2022-03-20 00:53:42 (43240): Reporting VM Process ID to BOINC.
2022-03-20 00:53:42 (43240): Guest Log: BIOS: VirtualBox 5.2.44
2022-03-20 00:53:42 (43240): Guest Log: CPUID EDX: 0x078bfbff
2022-03-20 00:53:42 (43240): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63
2022-03-20 00:53:42 (43240): VM state change detected. (old = 'poweredoff', new = 'running')
2022-03-20 00:53:42 (43240): Preference change detected
2022-03-20 00:53:42 (43240): Setting CPU throttle for VM. (100%)
2022-03-20 00:53:42 (43240): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 30 seconds) or (Vbox_job.xml: 600 seconds))
2022-03-20 00:53:44 (43240): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032
2022-03-20 00:53:44 (43240): Guest Log: BIOS: Booting from Hard Disk...
2022-03-20 00:53:49 (43240): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
2022-03-20 00:53:49 (43240): Guest Log: vboxguest: misc device minor 58, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
2022-03-20 00:53:54 (43240): Guest Log: VBoxService 5.2.42 r137960 (verbosity: 0) linux.amd64 (May 13 2020 21:45:13) release log
2022-03-20 00:53:54 (43240): Guest Log: 00:00:00.000224 main     Log opened 2022-03-20T00:53:52.350889000Z
2022-03-20 00:53:54 (43240): Guest Log: 00:00:00.000407 main     OS Product: Linux
2022-03-20 00:53:54 (43240): Guest Log: 00:00:00.000460 main     OS Release: 4.19.0-14-amd64
2022-03-20 00:53:54 (43240): Guest Log: 00:00:00.000518 main     OS Version: #1 SMP Debian 4.19.171-2 (2021-01-30)
2022-03-20 00:53:54 (43240): Guest Log: 00:00:00.000569 main     Executable: /opt/VBoxGuestAdditions-5.2.42/sbin/VBoxService
2022-03-20 00:53:54 (43240): Guest Log: 00:00:00.000570 main     Process ID: 539
2022-03-20 00:53:54 (43240): Guest Log: 00:00:00.000571 main     Package type: LINUX_64BITS_GENERIC
2022-03-20 00:53:54 (43240): Guest Log: 00:00:00.002363 main     5.2.42 r137960 started. Verbose level = 0
2022-03-20 01:06:50 (43240): Creating new snapshot for VM.
2022-03-20 01:06:55 (43240): Checkpoint completed.
2022-03-20 01:16:51 (43240): Creating new snapshot for VM.
2022-03-20 01:16:56 (43240): Deleting stale snapshot.
2022-03-20 01:16:57 (43240): Checkpoint completed.
2022-03-20 01:26:52 (43240): Creating new snapshot for VM.
2022-03-20 01:26:58 (43240): Deleting stale snapshot.
2022-03-20 01:26:58 (43240): Checkpoint completed.
2022-03-20 01:36:53 (43240): Creating new snapshot for VM.
2022-03-20 01:36:59 (43240): Deleting stale snapshot.
2022-03-20 01:36:59 (43240): Checkpoint completed.
2022-03-20 01:46:55 (43240): Creating new snapshot for VM.
2022-03-20 01:47:00 (43240): Deleting stale snapshot.
2022-03-20 01:47:01 (43240): Checkpoint completed.
2022-03-20 01:56:56 (43240): Creating new snapshot for VM.
2022-03-20 01:57:01 (43240): Deleting stale snapshot.
2022-03-20 01:57:02 (43240): Checkpoint completed.
2022-03-20 02:06:57 (43240): Creating new snapshot for VM.
2022-03-20 02:07:03 (43240): Deleting stale snapshot.
2022-03-20 02:07:03 (43240): Checkpoint completed.
2022-03-20 02:16:59 (43240): Creating new snapshot for VM.
2022-03-20 02:17:04 (43240): Deleting stale snapshot.
2022-03-20 02:17:05 (43240): Checkpoint completed.
2022-03-20 02:27:00 (43240): Creating new snapshot for VM.
2022-03-20 02:27:05 (43240): Deleting stale snapshot.
2022-03-20 02:27:06 (43240): Checkpoint completed.
2022-03-20 02:33:47 (43240): Status Report: Elapsed Time: '6000.317190'
2022-03-20 02:33:47 (43240): Status Report: CPU Time: '66.250000'
2022-03-20 02:37:01 (43240): Creating new snapshot for VM.
2022-03-20 02:37:07 (43240): Deleting stale snapshot.
2022-03-20 02:37:07 (43240): Checkpoint completed.
2022-03-20 02:47:03 (43240): Creating new snapshot for VM.
2022-03-20 02:47:08 (43240): Deleting stale snapshot.
2022-03-20 02:47:08 (43240): Checkpoint completed.
2022-03-20 02:57:04 (43240): Creating new snapshot for VM.
2022-03-20 02:57:09 (43240): Deleting stale snapshot.
2022-03-20 02:57:10 (43240): Checkpoint completed.
2022-03-20 03:07:05 (43240): Creating new snapshot for VM.
2022-03-20 03:07:10 (43240): Deleting stale snapshot.
2022-03-20 03:07:11 (43240): Checkpoint completed.
2022-03-20 03:17:06 (43240): Creating new snapshot for VM.
2022-03-20 03:17:12 (43240): Deleting stale snapshot.
2022-03-20 03:17:12 (43240): Checkpoint completed.
2022-03-20 03:27:08 (43240): Creating new snapshot for VM.
2022-03-20 03:27:13 (43240): Deleting stale snapshot.
2022-03-20 03:27:14 (43240): Checkpoint completed.
2022-03-20 03:37:09 (43240): Creating new snapshot for VM.
2022-03-20 03:37:15 (43240): Deleting stale snapshot.
2022-03-20 03:37:15 (43240): Checkpoint completed.
2022-03-20 03:47:11 (43240): Creating new snapshot for VM.
2022-03-20 03:47:16 (43240): Deleting stale snapshot.
2022-03-20 03:47:16 (43240): Checkpoint completed.
2022-03-20 03:57:12 (43240): Creating new snapshot for VM.
2022-03-20 03:57:17 (43240): Deleting stale snapshot.
2022-03-20 03:57:18 (43240): Checkpoint completed.
2022-03-20 04:07:13 (43240): Creating new snapshot for VM.
2022-03-20 04:07:19 (43240): Deleting stale snapshot.
2022-03-20 04:07:19 (43240): Checkpoint completed.
2022-03-20 04:13:52 (43240): Status Report: Elapsed Time: '12000.697428'
2022-03-20 04:13:52 (43240): Status Report: CPU Time: '119.265625'
2022-03-20 04:17:14 (43240): Creating new snapshot for VM.
2022-03-20 04:17:20 (43240): Deleting stale snapshot.
2022-03-20 04:17:20 (43240): Checkpoint completed.
2022-03-20 04:27:16 (43240): Creating new snapshot for VM.
2022-03-20 04:27:21 (43240): Deleting stale snapshot.
2022-03-20 04:27:22 (43240): Checkpoint completed.
2022-03-20 04:37:17 (43240): Creating new snapshot for VM.
2022-03-20 04:37:23 (43240): Deleting stale snapshot.
2022-03-20 04:37:23 (43240): Checkpoint completed.
2022-03-20 04:47:18 (43240): Creating new snapshot for VM.
2022-03-20 04:47:24 (43240): Deleting stale snapshot.
2022-03-20 04:47:24 (43240): Checkpoint completed.
2022-03-20 04:57:20 (43240): Creating new snapshot for VM.
2022-03-20 04:57:25 (43240): Deleting stale snapshot.
2022-03-20 04:57:25 (43240): Checkpoint completed.
2022-03-20 05:07:21 (43240): Creating new snapshot for VM.
2022-03-20 05:07:26 (43240): Deleting stale snapshot.
2022-03-20 05:07:27 (43240): Checkpoint completed.
2022-03-20 05:17:22 (43240): Creating new snapshot for VM.
2022-03-20 05:17:28 (43240): Deleting stale snapshot.
2022-03-20 05:17:28 (43240): Checkpoint completed.
2022-03-20 05:27:23 (43240): Creating new snapshot for VM.
2022-03-20 05:27:29 (43240): Deleting stale snapshot.
2022-03-20 05:27:29 (43240): Checkpoint completed.
2022-03-20 05:37:25 (43240): Creating new snapshot for VM.
2022-03-20 05:37:30 (43240): Deleting stale snapshot.
2022-03-20 05:37:30 (43240): Checkpoint completed.
2022-03-20 05:47:26 (43240): Creating new snapshot for VM.
2022-03-20 05:47:31 (43240): Deleting stale snapshot.
2022-03-20 05:47:32 (43240): Checkpoint completed.
2022-03-20 05:53:57 (43240): Status Report: Elapsed Time: '18000.910646'
2022-03-20 05:53:57 (43240): Status Report: CPU Time: '171.703125'
2022-03-20 05:57:27 (43240): Creating new snapshot for VM.
2022-03-20 05:57:33 (43240): Deleting stale snapshot.
2022-03-20 05:57:33 (43240): Checkpoint completed.
2022-03-20 06:07:28 (43240): Creating new snapshot for VM.
2022-03-20 06:07:34 (43240): Deleting stale snapshot.
2022-03-20 06:07:34 (43240): Checkpoint completed.
2022-03-20 06:17:30 (43240): Creating new snapshot for VM.
2022-03-20 06:17:35 (43240): Deleting stale snapshot.
2022-03-20 06:17:35 (43240): Checkpoint completed.
2022-03-20 06:27:31 (43240): Creating new snapshot for VM.
2022-03-20 06:27:36 (43240): Deleting stale snapshot.
2022-03-20 06:27:37 (43240): Checkpoint completed.
2022-03-20 06:37:32 (43240): Creating new snapshot for VM.
2022-03-20 06:37:38 (43240): Deleting stale snapshot.
2022-03-20 06:37:38 (43240): Checkpoint completed.
2022-03-20 06:47:34 (43240): Creating new snapshot for VM.
2022-03-20 06:47:39 (43240): Deleting stale snapshot.
2022-03-20 06:47:39 (43240): Checkpoint completed.
2022-03-20 06:57:35 (43240): Creating new snapshot for VM.
2022-03-20 06:57:40 (43240): Deleting stale snapshot.
2022-03-20 06:57:41 (43240): Checkpoint completed.
2022-03-20 07:07:37 (43240): Creating new snapshot for VM.
2022-03-20 07:07:42 (43240): Deleting stale snapshot.
2022-03-20 07:07:42 (43240): Checkpoint completed.
2022-03-20 07:17:38 (43240): Creating new snapshot for VM.
2022-03-20 07:17:43 (43240): Deleting stale snapshot.
2022-03-20 07:17:44 (43240): Checkpoint completed.
2022-03-20 07:27:39 (43240): Creating new snapshot for VM.
2022-03-20 07:27:45 (43240): Deleting stale snapshot.
2022-03-20 07:27:45 (43240): Checkpoint completed.
2022-03-20 07:34:03 (43240): Status Report: Elapsed Time: '24001.541325'
2022-03-20 07:34:03 (43240): Status Report: CPU Time: '226.156250'
2022-03-20 07:37:41 (43240): Creating new snapshot for VM.
2022-03-20 07:37:46 (43240): Deleting stale snapshot.
2022-03-20 07:37:46 (43240): Checkpoint completed.
2022-03-20 07:47:42 (43240): Creating new snapshot for VM.
2022-03-20 07:47:47 (43240): Deleting stale snapshot.
2022-03-20 07:47:48 (43240): Checkpoint completed.
2022-03-20 07:57:43 (43240): Creating new snapshot for VM.
2022-03-20 07:57:49 (43240): Deleting stale snapshot.
2022-03-20 07:57:49 (43240): Checkpoint completed.
2022-03-20 08:07:45 (43240): Creating new snapshot for VM.
2022-03-20 08:07:50 (43240): Deleting stale snapshot.
2022-03-20 08:07:51 (43240): Checkpoint completed.
2022-03-20 08:17:46 (43240): Creating new snapshot for VM.
2022-03-20 08:17:52 (43240): Deleting stale snapshot.
2022-03-20 08:17:52 (43240): Checkpoint completed.
2022-03-20 08:27:48 (43240): Creating new snapshot for VM.
2022-03-20 08:27:53 (43240): Deleting stale snapshot.
2022-03-20 08:27:53 (43240): Checkpoint completed.
2022-03-20 08:37:49 (43240): Creating new snapshot for VM.
2022-03-20 08:37:54 (43240): Deleting stale snapshot.
2022-03-20 08:37:55 (43240): Checkpoint completed.
2022-03-20 08:47:50 (43240): Creating new snapshot for VM.
2022-03-20 08:47:56 (43240): Deleting stale snapshot.
2022-03-20 08:47:56 (43240): Checkpoint completed.
2022-03-20 08:57:52 (43240): Creating new snapshot for VM.
2022-03-20 08:57:57 (43240): Deleting stale snapshot.
2022-03-20 08:57:58 (43240): Checkpoint completed.
2022-03-20 09:07:53 (43240): Creating new snapshot for VM.
2022-03-20 09:07:59 (43240): Deleting stale snapshot.
2022-03-20 09:07:59 (43240): Checkpoint completed.
2022-03-20 09:14:10 (43240): Status Report: Elapsed Time: '30001.684675'
2022-03-20 09:14:10 (43240): Status Report: CPU Time: '280.656250'
2022-03-20 09:17:55 (43240): Creating new snapshot for VM.
2022-03-20 09:18:00 (43240): Deleting stale snapshot.
2022-03-20 09:18:00 (43240): Checkpoint completed.
2022-03-20 09:27:56 (43240): Creating new snapshot for VM.
2022-03-20 09:28:01 (43240): Deleting stale snapshot.
2022-03-20 09:28:02 (43240): Checkpoint completed.
2022-03-20 09:37:57 (43240): Creating new snapshot for VM.
2022-03-20 09:38:03 (43240): Deleting stale snapshot.
2022-03-20 09:38:03 (43240): Checkpoint completed.
2022-03-20 09:47:59 (43240): Creating new snapshot for VM.
2022-03-20 09:48:04 (43240): Deleting stale snapshot.
2022-03-20 09:48:04 (43240): Checkpoint completed.
2022-03-20 09:58:00 (43240): Creating new snapshot for VM.
2022-03-20 09:58:05 (43240): Deleting stale snapshot.
2022-03-20 09:58:06 (43240): Checkpoint completed.
2022-03-20 10:08:01 (43240): Creating new snapshot for VM.
2022-03-20 10:08:07 (43240): Deleting stale snapshot.
2022-03-20 10:08:07 (43240): Checkpoint completed.
2022-03-20 10:18:03 (43240): Creating new snapshot for VM.
2022-03-20 10:18:08 (43240): Deleting stale snapshot.
2022-03-20 10:18:08 (43240): Checkpoint completed.
2022-03-20 10:28:04 (43240): Creating new snapshot for VM.
2022-03-20 10:28:09 (43240): Deleting stale snapshot.
2022-03-20 10:28:10 (43240): Checkpoint completed.
2022-03-20 10:38:05 (43240): Creating new snapshot for VM.
2022-03-20 10:38:11 (43240): Deleting stale snapshot.
2022-03-20 10:38:11 (43240): Checkpoint completed.
2022-03-20 10:48:07 (43240): Creating new snapshot for VM.
2022-03-20 10:48:12 (43240): Deleting stale snapshot.
2022-03-20 10:48:12 (43240): Checkpoint completed.
2022-03-20 10:54:18 (43240): Status Report: Elapsed Time: '36002.538818'
2022-03-20 10:54:18 (43240): Status Report: CPU Time: '335.437500'
2022-03-20 10:58:08 (43240): Creating new snapshot for VM.
2022-03-20 10:58:13 (43240): Deleting stale snapshot.
2022-03-20 10:58:14 (43240): Checkpoint completed.
2022-03-20 11:08:09 (43240): Creating new snapshot for VM.
2022-03-20 11:08:15 (43240): Deleting stale snapshot.
2022-03-20 11:08:15 (43240): Checkpoint completed.
2022-03-20 11:18:11 (43240): Creating new snapshot for VM.
2022-03-20 11:18:16 (43240): Deleting stale snapshot.
2022-03-20 11:18:16 (43240): Checkpoint completed.
2022-03-20 11:28:12 (43240): Creating new snapshot for VM.
2022-03-20 11:28:17 (43240): Deleting stale snapshot.
2022-03-20 11:28:18 (43240): Checkpoint completed.
2022-03-20 11:38:13 (43240): Creating new snapshot for VM.
2022-03-20 11:38:19 (43240): Deleting stale snapshot.
2022-03-20 11:38:19 (43240): Checkpoint completed.
2022-03-20 11:48:15 (43240): Creating new snapshot for VM.
2022-03-20 11:48:20 (43240): Deleting stale snapshot.
2022-03-20 11:48:20 (43240): Checkpoint completed.
2022-03-20 11:58:16 (43240): Creating new snapshot for VM.
2022-03-20 11:58:21 (43240): Deleting stale snapshot.
2022-03-20 11:58:22 (43240): Checkpoint completed.
2022-03-20 12:08:17 (43240): Creating new snapshot for VM.
2022-03-20 12:08:23 (43240): Deleting stale snapshot.
2022-03-20 12:08:23 (43240): Checkpoint completed.
2022-03-20 12:18:19 (43240): Creating new snapshot for VM.
2022-03-20 12:18:24 (43240): Deleting stale snapshot.
2022-03-20 12:18:24 (43240): Checkpoint completed.
2022-03-20 12:28:20 (43240): Creating new snapshot for VM.
2022-03-20 12:28:25 (43240): Deleting stale snapshot.
2022-03-20 12:28:26 (43240): Checkpoint completed.
2022-03-20 12:34:25 (43240): Status Report: Elapsed Time: '42003.361456'
2022-03-20 12:34:25 (43240): Status Report: CPU Time: '389.171875'
2022-03-20 12:38:21 (43240): Creating new snapshot for VM.
2022-03-20 12:38:27 (43240): Deleting stale snapshot.
2022-03-20 12:38:27 (43240): Checkpoint completed.
2022-03-20 12:48:23 (43240): Creating new snapshot for VM.
2022-03-20 12:48:28 (43240): Deleting stale snapshot.
2022-03-20 12:48:28 (43240): Checkpoint completed.
2022-03-20 12:58:24 (43240): Creating new snapshot for VM.
2022-03-20 12:58:29 (43240): Deleting stale snapshot.
2022-03-20 12:58:30 (43240): Checkpoint completed.
2022-03-20 13:08:26 (43240): Creating new snapshot for VM.
2022-03-20 13:08:31 (43240): Deleting stale snapshot.
2022-03-20 13:08:31 (43240): Checkpoint completed.
2022-03-20 13:18:27 (43240): Creating new snapshot for VM.
2022-03-20 13:18:32 (43240): Deleting stale snapshot.
2022-03-20 13:18:33 (43240): Checkpoint completed.
2022-03-20 13:28:28 (43240): Creating new snapshot for VM.
2022-03-20 13:28:34 (43240): Deleting stale snapshot.
2022-03-20 13:28:34 (43240): Checkpoint completed.
2022-03-20 13:38:30 (43240): Creating new snapshot for VM.
2022-03-20 13:38:35 (43240): Deleting stale snapshot.
2022-03-20 13:38:35 (43240): Checkpoint completed.
2022-03-20 13:48:31 (43240): Creating new snapshot for VM.
2022-03-20 13:48:36 (43240): Deleting stale snapshot.
2022-03-20 13:48:37 (43240): Checkpoint completed.
2022-03-20 13:58:32 (43240): Creating new snapshot for VM.
2022-03-20 13:58:38 (43240): Deleting stale snapshot.
2022-03-20 13:58:38 (43240): Checkpoint completed.
2022-03-20 14:08:34 (43240): Creating new snapshot for VM.
2022-03-20 14:08:39 (43240): Deleting stale snapshot.
2022-03-20 14:08:39 (43240): Checkpoint completed.
2022-03-20 14:14:33 (43240): Status Report: Elapsed Time: '48004.224939'
2022-03-20 14:14:33 (43240): Status Report: CPU Time: '442.734375'
2022-03-20 14:18:35 (43240): Creating new snapshot for VM.
2022-03-20 14:18:41 (43240): Deleting stale snapshot.
2022-03-20 14:18:42 (43240): Checkpoint completed.
2022-03-20 14:28:37 (43240): Creating new snapshot for VM.
2022-03-20 14:28:42 (43240): Deleting stale snapshot.
2022-03-20 14:28:42 (43240): Checkpoint completed.
2022-03-20 14:38:38 (43240): Creating new snapshot for VM.
2022-03-20 14:38:43 (43240): Deleting stale snapshot.
2022-03-20 14:38:44 (43240): Checkpoint completed.
2022-03-20 14:48:39 (43240): Creating new snapshot for VM.
2022-03-20 14:48:45 (43240): Deleting stale snapshot.
2022-03-20 14:48:45 (43240): Checkpoint completed.
2022-03-20 14:58:41 (43240): Creating new snapshot for VM.
2022-03-20 14:58:46 (43240): Deleting stale snapshot.
2022-03-20 14:58:46 (43240): Checkpoint completed.
2022-03-20 15:08:42 (43240): Creating new snapshot for VM.
2022-03-20 15:08:47 (43240): Deleting stale snapshot.
2022-03-20 15:08:48 (43240): Checkpoint completed.
2022-03-20 15:18:43 (43240): Creating new snapshot for VM.
2022-03-20 15:18:49 (43240): Deleting stale snapshot.
2022-03-20 15:18:49 (43240): Checkpoint completed.
2022-03-20 15:28:45 (43240): Creating new snapshot for VM.
2022-03-20 15:28:50 (43240): Deleting stale snapshot.
2022-03-20 15:28:50 (43240): Checkpoint completed.
2022-03-20 15:38:46 (43240): Creating new snapshot for VM.
2022-03-20 15:38:51 (43240): Deleting stale snapshot.
2022-03-20 15:38:52 (43240): Checkpoint completed.
2022-03-20 15:48:47 (43240): Creating new snapshot for VM.
2022-03-20 15:48:53 (43240): Deleting stale snapshot.
2022-03-20 15:48:53 (43240): Checkpoint completed.
2022-03-20 15:54:40 (43240): Status Report: Elapsed Time: '54005.212576'
2022-03-20 15:54:40 (43240): Status Report: CPU Time: '498.093750'
2022-03-20 15:58:49 (43240): Creating new snapshot for VM.
2022-03-20 15:58:54 (43240): Deleting stale snapshot.
2022-03-20 15:58:54 (43240): Checkpoint completed.
2022-03-20 16:08:50 (43240): Creating new snapshot for VM.
2022-03-20 16:08:55 (43240): Deleting stale snapshot.
2022-03-20 16:08:56 (43240): Checkpoint completed.
2022-03-20 16:18:51 (43240): Creating new snapshot for VM.
2022-03-20 16:18:57 (43240): Deleting stale snapshot.
2022-03-20 16:18:57 (43240): Checkpoint completed.
2022-03-20 16:28:53 (43240): Creating new snapshot for VM.
2022-03-20 16:28:58 (43240): Deleting stale snapshot.
2022-03-20 16:28:58 (43240): Checkpoint completed.
2022-03-20 16:38:54 (43240): Creating new snapshot for VM.
2022-03-20 16:38:59 (43240): Deleting stale snapshot.
2022-03-20 16:39:00 (43240): Checkpoint completed.
2022-03-20 16:48:55 (43240): Creating new snapshot for VM.
2022-03-20 16:49:01 (43240): Deleting stale snapshot.
2022-03-20 16:49:02 (43240): Checkpoint completed.
2022-03-20 16:58:57 (43240): Creating new snapshot for VM.
2022-03-20 16:59:02 (43240): Deleting stale snapshot.
2022-03-20 16:59:03 (43240): Checkpoint completed.
2022-03-20 17:08:58 (43240): Creating new snapshot for VM.
2022-03-20 17:09:04 (43240): Deleting stale snapshot.
2022-03-20 17:09:04 (43240): Checkpoint completed.
2022-03-20 17:19:00 (43240): Creating new snapshot for VM.
2022-03-20 17:19:05 (43240): Deleting stale snapshot.
2022-03-20 17:19:06 (43240): Checkpoint completed.
2022-03-20 17:29:01 (43240): Creating new snapshot for VM.
2022-03-20 17:29:07 (43240): Deleting stale snapshot.
2022-03-20 17:29:07 (43240): Checkpoint completed.
2022-03-20 17:34:47 (43240): Status Report: Elapsed Time: '60005.333231'
2022-03-20 17:34:47 (43240): Status Report: CPU Time: '552.015625'
2022-03-20 17:39:03 (43240): Creating new snapshot for VM.
2022-03-20 17:39:08 (43240): Deleting stale snapshot.
2022-03-20 17:39:08 (43240): Checkpoint completed.
2022-03-20 17:49:04 (43240): Creating new snapshot for VM.
2022-03-20 17:49:09 (43240): Deleting stale snapshot.
2022-03-20 17:49:10 (43240): Checkpoint completed.
2022-03-20 17:59:05 (43240): Creating new snapshot for VM.
2022-03-20 17:59:11 (43240): Deleting stale snapshot.
2022-03-20 17:59:11 (43240): Checkpoint completed.
2022-03-20 18:09:07 (43240): Creating new snapshot for VM.
2022-03-20 18:09:12 (43240): Deleting stale snapshot.
2022-03-20 18:09:12 (43240): Checkpoint completed.
2022-03-20 18:19:08 (43240): Creating new snapshot for VM.
2022-03-20 18:19:13 (43240): Deleting stale snapshot.
2022-03-20 18:19:14 (43240): Checkpoint completed.
2022-03-20 18:29:10 (43240): Creating new snapshot for VM.
2022-03-20 18:29:15 (43240): Deleting stale snapshot.
2022-03-20 18:29:15 (43240): Checkpoint completed.
2022-03-20 18:39:11 (43240): Creating new snapshot for VM.
2022-03-20 18:39:16 (43240): Deleting stale snapshot.
2022-03-20 18:39:17 (43240): Checkpoint completed.
2022-03-20 18:49:12 (43240): Creating new snapshot for VM.
2022-03-20 18:49:17 (43240): Deleting stale snapshot.
2022-03-20 18:49:18 (43240): Checkpoint completed.
2022-03-20 18:59:14 (43240): Creating new snapshot for VM.
2022-03-20 18:59:19 (43240): Deleting stale snapshot.
2022-03-20 18:59:19 (43240): Checkpoint completed.
2022-03-20 19:09:15 (43240): Creating new snapshot for VM.
2022-03-20 19:09:20 (43240): Deleting stale snapshot.
2022-03-20 19:09:21 (43240): Checkpoint completed.
2022-03-20 19:14:55 (43240): Status Report: Elapsed Time: '66006.244211'
2022-03-20 19:14:55 (43240): Status Report: CPU Time: '606.281250'
2022-03-20 19:19:16 (43240): Creating new snapshot for VM.
2022-03-20 19:19:22 (43240): Deleting stale snapshot.
2022-03-20 19:19:22 (43240): Checkpoint completed.
2022-03-20 19:29:18 (43240): Creating new snapshot for VM.
2022-03-20 19:29:23 (43240): Deleting stale snapshot.
2022-03-20 19:29:23 (43240): Checkpoint completed.
2022-03-20 19:39:19 (43240): Creating new snapshot for VM.
2022-03-20 19:39:24 (43240): Deleting stale snapshot.
2022-03-20 19:39:25 (43240): Checkpoint completed.
2022-03-20 19:49:20 (43240): Creating new snapshot for VM.
2022-03-20 19:49:26 (43240): Deleting stale snapshot.
2022-03-20 19:49:26 (43240): Checkpoint completed.
2022-03-20 19:59:22 (43240): Creating new snapshot for VM.
2022-03-20 19:59:27 (43240): Deleting stale snapshot.
2022-03-20 19:59:27 (43240): Checkpoint completed.
2022-03-20 20:09:23 (43240): Creating new snapshot for VM.
2022-03-20 20:09:28 (43240): Deleting stale snapshot.
2022-03-20 20:09:29 (43240): Checkpoint completed.
2022-03-20 20:19:24 (43240): Creating new snapshot for VM.
2022-03-20 20:19:30 (43240): Deleting stale snapshot.
2022-03-20 20:19:30 (43240): Checkpoint completed.
2022-03-20 20:29:26 (43240): Creating new snapshot for VM.
2022-03-20 20:29:31 (43240): Deleting stale snapshot.
2022-03-20 20:29:31 (43240): Checkpoint completed.
2022-03-20 20:39:27 (43240): Creating new snapshot for VM.
2022-03-20 20:39:32 (43240): Deleting stale snapshot.
2022-03-20 20:39:33 (43240): Checkpoint completed.
2022-03-20 20:49:28 (43240): Creating new snapshot for VM.
2022-03-20 20:49:34 (43240): Deleting stale snapshot.
2022-03-20 20:49:34 (43240): Checkpoint completed.
2022-03-20 20:55:03 (43240): Status Report: Elapsed Time: '72007.079634'
2022-03-20 20:55:03 (43240): Status Report: CPU Time: '660.046875'
2022-03-20 20:59:30 (43240): Creating new snapshot for VM.
2022-03-20 20:59:35 (43240): Deleting stale snapshot.
2022-03-20 20:59:36 (43240): Checkpoint completed.
2022-03-20 21:09:31 (43240): Creating new snapshot for VM.
2022-03-20 21:09:36 (43240): Deleting stale snapshot.
2022-03-20 21:09:37 (43240): Checkpoint completed.
2022-03-20 21:19:33 (43240): Creating new snapshot for VM.
2022-03-20 21:19:38 (43240): Deleting stale snapshot.
2022-03-20 21:19:38 (43240): Checkpoint completed.
2022-03-20 21:29:34 (43240): Creating new snapshot for VM.
2022-03-20 21:29:39 (43240): Deleting stale snapshot.
2022-03-20 21:29:40 (43240): Checkpoint completed.
2022-03-20 21:39:35 (43240): Creating new snapshot for VM.
2022-03-20 21:39:41 (43240): Deleting stale snapshot.
2022-03-20 21:39:41 (43240): Checkpoint completed.
2022-03-20 21:49:37 (43240): Creating new snapshot for VM.
2022-03-20 21:49:42 (43240): Deleting stale snapshot.
2022-03-20 21:49:42 (43240): Checkpoint completed.
2022-03-20 21:59:38 (43240): Creating new snapshot for VM.
2022-03-20 21:59:43 (43240): Deleting stale snapshot.
2022-03-20 21:59:44 (43240): Checkpoint completed.
2022-03-20 22:09:39 (43240): Creating new snapshot for VM.
2022-03-20 22:09:44 (43240): Deleting stale snapshot.
2022-03-20 22:09:45 (43240): Checkpoint completed.
2022-03-20 22:19:40 (43240): Creating new snapshot for VM.
2022-03-20 22:19:46 (43240): Deleting stale snapshot.
2022-03-20 22:19:46 (43240): Checkpoint completed.
2022-03-20 22:29:42 (43240): Creating new snapshot for VM.
2022-03-20 22:29:47 (43240): Deleting stale snapshot.
2022-03-20 22:29:47 (43240): Checkpoint completed.
2022-03-20 22:35:10 (43240): Status Report: Elapsed Time: '78007.920580'
2022-03-20 22:35:10 (43240): Status Report: CPU Time: '714.343750'
2022-03-20 22:39:43 (43240): Creating new snapshot for VM.
2022-03-20 22:39:48 (43240): Deleting stale snapshot.
2022-03-20 22:39:49 (43240): Checkpoint completed.
2022-03-20 22:49:44 (43240): Creating new snapshot for VM.
2022-03-20 22:49:49 (43240): Deleting stale snapshot.
2022-03-20 22:49:50 (43240): Checkpoint completed.
2022-03-20 22:59:45 (43240): Creating new snapshot for VM.
2022-03-20 22:59:51 (43240): Deleting stale snapshot.
2022-03-20 22:59:51 (43240): Checkpoint completed.
2022-03-20 23:09:47 (43240): Creating new snapshot for VM.
2022-03-20 23:09:52 (43240): Deleting stale snapshot.
2022-03-20 23:09:52 (43240): Checkpoint completed.
2022-03-20 23:19:48 (43240): Creating new snapshot for VM.
2022-03-20 23:19:53 (43240): Deleting stale snapshot.
2022-03-20 23:19:54 (43240): Checkpoint completed.
2022-03-20 23:29:49 (43240): Creating new snapshot for VM.
2022-03-20 23:29:55 (43240): Deleting stale snapshot.
2022-03-20 23:29:55 (43240): Checkpoint completed.
2022-03-20 23:39:51 (43240): Creating new snapshot for VM.
2022-03-20 23:39:56 (43240): Deleting stale snapshot.
2022-03-20 23:39:56 (43240): Checkpoint completed.
2022-03-20 23:49:52 (43240): Creating new snapshot for VM.
2022-03-20 23:49:57 (43240): Deleting stale snapshot.
2022-03-20 23:49:58 (43240): Checkpoint completed.
2022-03-20 23:59:53 (43240): Creating new snapshot for VM.
2022-03-20 23:59:59 (43240): Deleting stale snapshot.
2022-03-20 23:59:59 (43240): Checkpoint completed.
2022-03-21 00:09:55 (43240): Creating new snapshot for VM.
2022-03-21 00:10:00 (43240): Deleting stale snapshot.
2022-03-21 00:10:01 (43240): Checkpoint completed.
2022-03-21 00:15:17 (43240): Status Report: Elapsed Time: '84008.341488'
2022-03-21 00:15:17 (43240): Status Report: CPU Time: '768.343750'
2022-03-21 00:19:56 (43240): Creating new snapshot for VM.
2022-03-21 00:20:02 (43240): Deleting stale snapshot.
2022-03-21 00:20:02 (43240): Checkpoint completed.
2022-03-21 00:29:58 (43240): Creating new snapshot for VM.
2022-03-21 00:30:03 (43240): Deleting stale snapshot.
2022-03-21 00:30:03 (43240): Checkpoint completed.
2022-03-21 00:39:59 (43240): Creating new snapshot for VM.
2022-03-21 00:40:04 (43240): Deleting stale snapshot.
2022-03-21 00:40:05 (43240): Checkpoint completed.
2022-03-21 00:50:00 (43240): Creating new snapshot for VM.
2022-03-21 00:50:06 (43240): Deleting stale snapshot.
2022-03-21 00:50:06 (43240): Checkpoint completed.
2022-03-21 01:00:02 (43240): Creating new snapshot for VM.
2022-03-21 01:00:07 (43240): Deleting stale snapshot.
2022-03-21 01:00:07 (43240): Checkpoint completed.
2022-03-21 01:10:03 (43240): Creating new snapshot for VM.
2022-03-21 01:10:08 (43240): Deleting stale snapshot.
2022-03-21 01:10:09 (43240): Checkpoint completed.
2022-03-21 01:20:05 (43240): Creating new snapshot for VM.
2022-03-21 01:20:10 (43240): Deleting stale snapshot.
2022-03-21 01:20:10 (43240): Checkpoint completed.
2022-03-21 01:30:06 (43240): Creating new snapshot for VM.
2022-03-21 01:30:11 (43240): Deleting stale snapshot.
2022-03-21 01:30:12 (43240): Checkpoint completed.
2022-03-21 01:40:07 (43240): Creating new snapshot for VM.
2022-03-21 01:40:13 (43240): Deleting stale snapshot.
2022-03-21 01:40:13 (43240): Checkpoint completed.
2022-03-21 01:50:09 (43240): Creating new snapshot for VM.
2022-03-21 01:50:14 (43240): Deleting stale snapshot.
2022-03-21 01:50:14 (43240): Checkpoint completed.
2022-03-21 01:55:25 (43240): Status Report: Elapsed Time: '90009.256927'
2022-03-21 01:55:25 (43240): Status Report: CPU Time: '822.156250'
2022-03-21 02:00:10 (43240): Creating new snapshot for VM.
2022-03-21 02:00:15 (43240): Deleting stale snapshot.
2022-03-21 02:00:16 (43240): Checkpoint completed.
2022-03-21 02:10:11 (43240): Creating new snapshot for VM.
2022-03-21 02:10:17 (43240): Deleting stale snapshot.
2022-03-21 02:10:19 (43240): Checkpoint completed.
2022-03-21 02:20:13 (43240): Creating new snapshot for VM.
2022-03-21 02:20:18 (43240): Deleting stale snapshot.
2022-03-21 02:20:18 (43240): Checkpoint completed.
2022-03-21 02:30:14 (43240): Creating new snapshot for VM.
2022-03-21 02:30:19 (43240): Deleting stale snapshot.
2022-03-21 02:30:20 (43240): Checkpoint completed.
2022-03-21 02:40:15 (43240): Creating new snapshot for VM.
2022-03-21 02:40:21 (43240): Deleting stale snapshot.
2022-03-21 02:40:21 (43240): Checkpoint completed.
2022-03-21 02:50:17 (43240): Creating new snapshot for VM.
2022-03-21 02:50:22 (43240): Deleting stale snapshot.
2022-03-21 02:50:22 (43240): Checkpoint completed.
2022-03-21 03:00:18 (43240): Creating new snapshot for VM.
2022-03-21 03:00:23 (43240): Deleting stale snapshot.
2022-03-21 03:00:24 (43240): Checkpoint completed.
2022-03-21 03:10:19 (43240): Creating new snapshot for VM.
2022-03-21 03:10:25 (43240): Deleting stale snapshot.
2022-03-21 03:10:25 (43240): Checkpoint completed.
2022-03-21 03:20:21 (43240): Creating new snapshot for VM.
2022-03-21 03:20:26 (43240): Deleting stale snapshot.
2022-03-21 03:20:26 (43240): Checkpoint completed.
2022-03-21 03:30:22 (43240): Creating new snapshot for VM.
2022-03-21 03:30:27 (43240): Deleting stale snapshot.
2022-03-21 03:30:28 (43240): Checkpoint completed.
2022-03-21 03:35:32 (43240): Status Report: Elapsed Time: '96010.017061'
2022-03-21 03:35:32 (43240): Status Report: CPU Time: '876.625000'
2022-03-21 03:40:23 (43240): Creating new snapshot for VM.
2022-03-21 03:40:29 (43240): Deleting stale snapshot.
2022-03-21 03:40:29 (43240): Checkpoint completed.
2022-03-21 03:50:25 (43240): Creating new snapshot for VM.
2022-03-21 03:50:30 (43240): Deleting stale snapshot.
2022-03-21 03:50:30 (43240): Checkpoint completed.
2022-03-21 04:00:26 (43240): Creating new snapshot for VM.
2022-03-21 04:00:31 (43240): Deleting stale snapshot.
2022-03-21 04:00:32 (43240): Checkpoint completed.
2022-03-21 04:10:27 (43240): Creating new snapshot for VM.
2022-03-21 04:10:33 (43240): Deleting stale snapshot.
2022-03-21 04:10:33 (43240): Checkpoint completed.
2022-03-21 04:20:29 (43240): Creating new snapshot for VM.
2022-03-21 04:20:34 (43240): Deleting stale snapshot.
2022-03-21 04:20:34 (43240): Checkpoint completed.
2022-03-21 04:30:30 (43240): Creating new snapshot for VM.
2022-03-21 04:30:35 (43240): Deleting stale snapshot.
2022-03-21 04:30:36 (43240): Checkpoint completed.
2022-03-21 04:40:31 (43240): Creating new snapshot for VM.
2022-03-21 04:40:36 (43240): Deleting stale snapshot.
2022-03-21 04:40:37 (43240): Checkpoint completed.
2022-03-21 04:50:33 (43240): Creating new snapshot for VM.
2022-03-21 04:50:38 (43240): Deleting stale snapshot.
2022-03-21 04:50:38 (43240): Checkpoint completed.
2022-03-21 05:00:34 (43240): Creating new snapshot for VM.
2022-03-21 05:00:39 (43240): Deleting stale snapshot.
2022-03-21 05:00:40 (43240): Checkpoint completed.
2022-03-21 05:10:35 (43240): Creating new snapshot for VM.
2022-03-21 05:10:40 (43240): Deleting stale snapshot.
2022-03-21 05:10:41 (43240): Checkpoint completed.
2022-03-21 05:15:39 (43240): Status Report: Elapsed Time: '102010.728695'
2022-03-21 05:15:39 (43240): Status Report: CPU Time: '929.796875'
2022-03-21 05:20:36 (43240): Creating new snapshot for VM.
2022-03-21 05:20:42 (43240): Deleting stale snapshot.
2022-03-21 05:20:42 (43240): Checkpoint completed.
2022-03-21 05:26:59 (43240): VM state change detected. (old = 'running', new = 'paused')
2022-03-21 07:09:33 (21056): Detected: vboxwrapper 26202
2022-03-21 07:09:33 (21056): Detected: BOINC client v7.19.0
2022-03-21 07:09:35 (21056): Detected: VirtualBox VboxManage Interface (Version: 5.2.44)
2022-03-21 07:09:35 (21056): Feature: Checkpoint interval offset (59 seconds)
2022-03-21 07:09:35 (21056): Detected: Minimum checkpoint interval (600.000000 seconds)
2022-03-21 07:09:35 (21056): Guest Log: BIOS: VirtualBox 5.2.44
2022-03-21 07:09:35 (21056): Guest Log: CPUID EDX: 0x078bfbff
2022-03-21 07:09:35 (21056): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63
2022-03-21 07:09:35 (21056): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032
2022-03-21 07:09:35 (21056): Guest Log: BIOS: Booting from Hard Disk...
2022-03-21 07:09:35 (21056): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
2022-03-21 07:09:35 (21056): Guest Log: vboxguest: misc device minor 58, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
2022-03-21 07:09:35 (21056): Guest Log: VBoxService 5.2.42 r137960 (verbosity: 0) linux.amd64 (May 13 2020 21:45:13) release log
2022-03-21 07:09:35 (21056): Guest Log: 00:00:00.000224 main     Log opened 2022-03-20T00:53:52.350889000Z
2022-03-21 07:09:35 (21056): Guest Log: 00:00:00.000407 main     OS Product: Linux
2022-03-21 07:09:35 (21056): Guest Log: 00:00:00.000460 main     OS Release: 4.19.0-14-amd64
2022-03-21 07:09:35 (21056): Guest Log: 00:00:00.000518 main     OS Version: #1 SMP Debian 4.19.171-2 (2021-01-30)
2022-03-21 07:09:35 (21056): Guest Log: 00:00:00.000569 main     Executable: /opt/VBoxGuestAdditions-5.2.42/sbin/VBoxService
2022-03-21 07:09:35 (21056): Guest Log: 00:00:00.000570 main     Process ID: 539
2022-03-21 07:09:35 (21056): Guest Log: 00:00:00.000571 main     Package type: LINUX_64BITS_GENERIC
2022-03-21 07:09:35 (21056): Guest Log: 00:00:00.002363 main     5.2.42 r137960 started. Verbose level = 0
2022-03-21 07:09:35 (21056): Restore from previously saved snapshot.
2022-03-21 07:09:36 (21056): Restore completed.
2022-03-21 07:09:36 (21056): Starting VM using VBoxManage interface. (boinc_923b5ddf89fefc4a, slot#0)
2022-03-21 07:09:46 (21056): Successfully started VM. (PID = '44596')
2022-03-21 07:09:46 (21056): Reporting VM Process ID to BOINC.
2022-03-21 07:09:46 (21056): VM state change detected. (old = 'poweredoff', new = 'running')
2022-03-21 07:09:46 (21056): Status Report: Elapsed Time: '102307.728695'
2022-03-21 07:09:46 (21056): Status Report: CPU Time: '929.843750'
2022-03-21 07:09:46 (21056): Preference change detected
2022-03-21 07:09:46 (21056): Setting CPU throttle for VM. (100%)
2022-03-21 07:09:47 (21056): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 30 seconds) or (Vbox_job.xml: 600 seconds))
2022-03-21 07:09:53 (21056): Guest Log: 28:13:39.279466 timesync vgsvcTimeSyncWorker: Radical host time change: 6 558 642 000 000ns (HostNow=1 647 846 593 490 000 000 ns HostLast=1 647 840 034 848 000 000 ns)
2022-03-21 07:10:03 (21056): Guest Log: 28:13:49.279865 timesync vgsvcTimeSyncWorker: Radical guest time change: 7 351 860 403 000ns (GuestNow=1 647 846 603 490 458 000 ns GuestLast=1 647 839 251 630 055 000 ns fSetTimeLastLoop=true )
2022-03-21 07:20:47 (21056): Creating new snapshot for VM.
2022-03-21 07:20:52 (21056): Deleting stale snapshot.
2022-03-21 07:20:53 (21056): Checkpoint completed.
2022-03-21 07:30:48 (21056): Creating new snapshot for VM.
2022-03-21 07:30:56 (21056): Deleting stale snapshot.
2022-03-21 07:30:57 (21056): Checkpoint completed.
2022-03-21 07:40:49 (21056): Creating new snapshot for VM.
2022-03-21 07:40:55 (21056): Deleting stale snapshot.
2022-03-21 07:40:55 (21056): Checkpoint completed.
2022-03-21 07:50:51 (21056): Creating new snapshot for VM.
2022-03-21 07:50:56 (21056): Deleting stale snapshot.
2022-03-21 07:50:56 (21056): Checkpoint completed.
2022-03-21 08:00:52 (21056): Creating new snapshot for VM.
2022-03-21 08:00:57 (21056): Deleting stale snapshot.
2022-03-21 08:00:58 (21056): Checkpoint completed.
2022-03-21 08:10:53 (21056): Creating new snapshot for VM.
2022-03-21 08:10:59 (21056): Deleting stale snapshot.
2022-03-21 08:10:59 (21056): Checkpoint completed.
2022-03-21 08:20:10 (21056): VM state change detected. (old = 'running', new = 'paused')
ID: 105612 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Sid Celery

Send message
Joined: 11 Feb 08
Posts: 2141
Credit: 41,538,222
RAC: 10,691
Message 105613 - Posted: 21 Mar 2022, 12:09:20 UTC - in response to Message 105605.  

One other thing I decided to do the other day on my one PC that runs Python tasks, which may help someone else.
Instead of maximising the RAM I allocate to Boinc to run as many tasks as possible (I reached either 11 or 12 with 95% RAM at one point) I reduced the RAM allocation to 88% so that only 10 run at a time from 16 hyperthreaded cores.
When I maximised RAM I had instances of a crash that would take all the other tasks out with a Computation Error, causing lots of downtime, especially if it happened overnight or when I was away.
With slightly reduced RAM and fewer tasks running at once, that seems to have stopped.
Not ideal, but much more successful for me.

Spoke too soon. It happened again an hour ago. All running tasks and the rest of the cache crash out at the same time, with a 24hr backoff.
Set no new tasks, upload all the errored tasks, once cleared allow new tasks and a fresh AIMNet_vm_v2.vdi comes down (2Gb) and everything starts running fine again.
I think it's caused by a corruption of the AIMNet_vm_v2.vdi file
ID: 105613 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Sid Celery

Send message
Joined: 11 Feb 08
Posts: 2141
Credit: 41,538,222
RAC: 10,691
Message 105614 - Posted: 21 Mar 2022, 12:26:04 UTC - in response to Message 105612.  
Last modified: 21 Mar 2022, 12:30:29 UTC

This is a bad computer after having run a Python for 1 day 5 hours, with CPU usage at 16 minutes:

...
2022-03-20 02:33:47 (43240): Status Report: Elapsed Time: '6000.317190'
2022-03-20 02:33:47 (43240): Status Report: CPU Time: '66.250000'
...
2022-03-20 04:13:52 (43240): Status Report: Elapsed Time: '12000.697428'
2022-03-20 04:13:52 (43240): Status Report: CPU Time: '119.265625'
...
2022-03-20 05:53:57 (43240): Status Report: Elapsed Time: '18000.910646'
2022-03-20 05:53:57 (43240): Status Report: CPU Time: '171.703125'
...
2022-03-20 07:34:03 (43240): Status Report: Elapsed Time: '24001.541325'
2022-03-20 07:34:03 (43240): Status Report: CPU Time: '226.156250'
...
2022-03-20 09:14:10 (43240): Status Report: Elapsed Time: '30001.684675'
2022-03-20 09:14:10 (43240): Status Report: CPU Time: '280.656250'
...
2022-03-20 10:54:18 (43240): Status Report: Elapsed Time: '36002.538818'
2022-03-20 10:54:18 (43240): Status Report: CPU Time: '335.437500'
...
2022-03-20 12:34:25 (43240): Status Report: Elapsed Time: '42003.361456'
2022-03-20 12:34:25 (43240): Status Report: CPU Time: '389.171875'
...
2022-03-20 14:14:33 (43240): Status Report: Elapsed Time: '48004.224939'
2022-03-20 14:14:33 (43240): Status Report: CPU Time: '442.734375'
...
2022-03-20 15:54:40 (43240): Status Report: Elapsed Time: '54005.212576'
2022-03-20 15:54:40 (43240): Status Report: CPU Time: '498.093750'
...
2022-03-20 17:34:47 (43240): Status Report: Elapsed Time: '60005.333231'
2022-03-20 17:34:47 (43240): Status Report: CPU Time: '552.015625'
...
2022-03-20 19:14:55 (43240): Status Report: Elapsed Time: '66006.244211'
2022-03-20 19:14:55 (43240): Status Report: CPU Time: '606.281250'
...
2022-03-20 20:55:03 (43240): Status Report: Elapsed Time: '72007.079634'
2022-03-20 20:55:03 (43240): Status Report: CPU Time: '660.046875'
...
2022-03-20 22:35:10 (43240): Status Report: Elapsed Time: '78007.920580'
2022-03-20 22:35:10 (43240): Status Report: CPU Time: '714.343750'
...
2022-03-21 00:15:17 (43240): Status Report: Elapsed Time: '84008.341488'
2022-03-21 00:15:17 (43240): Status Report: CPU Time: '768.343750'
...
2022-03-21 01:55:25 (43240): Status Report: Elapsed Time: '90009.256927'
2022-03-21 01:55:25 (43240): Status Report: CPU Time: '822.156250'
...
2022-03-21 03:35:32 (43240): Status Report: Elapsed Time: '96010.017061'
2022-03-21 03:35:32 (43240): Status Report: CPU Time: '876.625000'
...
2022-03-21 05:15:39 (43240): Status Report: Elapsed Time: '102010.728695'
2022-03-21 05:15:39 (43240): Status Report: CPU Time: '929.796875'
...
2022-03-21 07:09:46 (21056): VM state change detected. (old = 'poweredoff', new = 'running')
2022-03-21 07:09:46 (21056): Status Report: Elapsed Time: '102307.728695'
2022-03-21 07:09:46 (21056): Status Report: CPU Time: '929.843750'
2022-03-21 07:09:46 (21056): Preference change detected
2022-03-21 07:09:46 (21056): Setting CPU throttle for VM. (100%)

This is what I see with jobs that stall. Lots of elapsed time, but no CPU time. I note the line that says CPU throttle 100%
I guess I have this kind of machine too.

I know it's annoying nannying, but you have to do what I've described above.
If a task seems to be taking too long, by which I mean if you see later tasks finishing before earlier tasks, and certainly if tasks go over 8hrs, check task properties.
If it's getting no CPU time just abort it. They <never> recover.

People are sending enormous reports in here, and obviously it's important to try to prevent tasks going zombie in the first place, but don't waste time hoping a bad task will recover itself. They don't.
It's a terrible solution, I accept, but it does solve an immediate issue

If I look at a good result, it shows for example

2022-03-21 05:23:19 (11204): Status Report: Elapsed Time: '12001.814686'
2022-03-21 05:23:19 (11204): Status Report: CPU Time: '11981.781250'

Run time 3 hours 35 min 44 sec
CPU time 3 hours 35 min 44 sec

So these enormous differences on a bad task should be visible very early.
Just kill them outright and move on.
ID: 105614 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Mr P Hucker
Avatar

Send message
Joined: 12 Aug 06
Posts: 1600
Credit: 12,116,986
RAC: 9,863
Message 105615 - Posted: 21 Mar 2022, 13:07:32 UTC - in response to Message 105613.  

Spoke too soon. It happened again an hour ago. All running tasks and the rest of the cache crash out at the same time, with a 24hr backoff.
Set no new tasks, upload all the errored tasks, once cleared allow new tasks and a fresh AIMNet_vm_v2.vdi comes down (2Gb) and everything starts running fine again.
I think it's caused by a corruption of the AIMNet_vm_v2.vdi file
What made yours download that file again? I only get that when I attach the project.
ID: 105615 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Mr P Hucker
Avatar

Send message
Joined: 12 Aug 06
Posts: 1600
Credit: 12,116,986
RAC: 9,863
Message 105616 - Posted: 21 Mar 2022, 13:09:48 UTC - in response to Message 105614.  
Last modified: 21 Mar 2022, 13:10:10 UTC

This is what I see with jobs that stall. Lots of elapsed time, but no CPU time. I note the line that says CPU throttle 100%
I guess I have this kind of machine too.

I know it's annoying nannying, but you have to do what I've described above.
If a task seems to be taking too long, by which I mean if you see later tasks finishing before earlier tasks, and certainly if tasks go over 8hrs, check task properties.
If it's getting no CPU time just abort it. They <never> recover.

People are sending enormous reports in here, and obviously it's important to try to prevent tasks going zombie in the first place, but don't waste time hoping a bad task will recover itself. They don't.
It's a terrible solution, I accept, but it does solve an immediate issue

If I look at a good result, it shows for example

2022-03-21 05:23:19 (11204): Status Report: Elapsed Time: '12001.814686'
2022-03-21 05:23:19 (11204): Status Report: CPU Time: '11981.781250'

Run time 3 hours 35 min 44 sec
CPU time 3 hours 35 min 44 sec

So these enormous differences on a bad task should be visible very early.
Just kill them outright and move on.
But I don't have the same problem as you, mine are worse. I have 2 computers which do every single task perfectly, and 5 computers which stall every single one. There's no point in me just aborting the bad ones, because they're all bad ones!

And I can see they're broken at a glance, as I use Boinctasks which shows wall time followed by CPU time in brackets.
ID: 105616 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Sid Celery

Send message
Joined: 11 Feb 08
Posts: 2141
Credit: 41,538,222
RAC: 10,691
Message 105617 - Posted: 21 Mar 2022, 13:15:46 UTC - in response to Message 105583.  

This is a task that is still running but barely for some reason. (aagb-mPPS-mPHE-mACHC13T-ACHC12C)
It was running fine until I shut it down and restarted.
...
I paused BOINC for a bit because it was overloading my system for some reason:
2022-03-19 19:04:46 (8908): VM state change detected. (old = 'running', new = 'paused')
2022-03-19 20:11:49 (8908): VM state change detected. (old = 'paused', new = 'running')
2022-03-19 20:11:54 (8908): Guest Log: 11:22:16.381991 timesync vgsvcTimeSyncWorker: Radical host time change: 4 033 163 000 000ns (HostNow=1 647 717 113 448 000 000 ns HostLast=1 647 713 080 285 000 000 ns)
2022-03-19 20:12:04 (8908): Guest Log: 11:22:26.382377 timesync vgsvcTimeSyncWorker: Radical guest time change: 4 509 674 906 000ns (GuestNow=1 647 717 123 448 400 000 ns GuestLast=1 647 712 613 773 494 000 ns fSetTimeLastLoop=true )
...
Shutdown #2 for the night and restart
...
2022-03-20 09:19:50 (14368): Setting CPU throttle for VM. (98%)

Greg, these are extracts from one of your reports. There's something you've said here I can confirm.

When you (and I) pause or reboot or there's some reason to stop processing then restart, this is when I notice zombie tasks appearing straight away after.
Going back to what you were saying earlier, it may well be that aagb tasks have a problem with re-starting most of all, but check them all anyway.

And again, there's a line in there talking about "Setting CPU throttle for VM. (98%)"

So what I'm going to suggest is to be very wary after pausing or rebooting.
Re-check tasks to see if they've restarted ok.
If they haven't restarted using CPU time, abort them. They'll have done all the work they're going to do.
Maybe 2 out of 10 will have a problem in my experience.

Once you do this, see if any other problems develop. In my very limited experience, they won't as you'll have addressed the issues as soon as they appear.
Give it a few days and report how things are going.
ID: 105617 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
zxcvbob

Send message
Joined: 4 Jan 06
Posts: 8
Credit: 830,878
RAC: 0
Message 105618 - Posted: 21 Mar 2022, 13:55:37 UTC - in response to Message 105597.  

Yes it was an aagb* task. I aborted it and uninstalled vbox. I'm running 4.2 tasks just fine, and am going to attach a couple more computers to R@H today (without vbox.) I also have an old Xeon-based server with Linux installed (I don't run it much because the cooling fan is so loud); I wonder if it will run those tasks natively?
ID: 105618 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Mr P Hucker
Avatar

Send message
Joined: 12 Aug 06
Posts: 1600
Credit: 12,116,986
RAC: 9,863
Message 105619 - Posted: 21 Mar 2022, 15:18:48 UTC - in response to Message 105618.  

Yes it was an aagb* task. I aborted it and uninstalled vbox. I'm running 4.2 tasks just fine, and am going to attach a couple more computers to R@H today (without vbox.) I also have an old Xeon-based server with Linux installed (I don't run it much because the cooling fan is so loud); I wonder if it will run those tasks natively?
Welcome to the club, I have two dual Xeon X5650 computers. Change the fan, you can get lovely quiet things on Ebay. I've done the reverse, I have mine cooled with some very loud 120V 6 inch fans I bought 30 years ago as a teenager from a bankruptcy recycling company. Not sure what they were from, but they have solid steel very sharp blades! Hurts if your finger gets in there, or on the 120V terminals!
ID: 105619 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Profile Greg_BE
Avatar

Send message
Joined: 30 May 06
Posts: 5691
Credit: 5,859,226
RAC: 0
Message 105624 - Posted: 21 Mar 2022, 18:01:06 UTC - in response to Message 105617.  

Sid, again aagb

Started 1056 it is now 1855
Right off the bat the times are wrong:

2022-03-21 12:38:25 (7640): Status Report: Elapsed Time: '6000.608391'
2022-03-21 12:38:25 (7640): Status Report: CPU Time: '16.687500'

6000 for 16 seconds? WTF? And just under 2 hours in.

And then this:
2022-03-21 14:20:03 (7640): Status Report: Elapsed Time: '12001.508751'
2022-03-21 14:20:03 (7640): Status Report: CPU Time: '28.937500'
No pause still.

2022-03-21 17:57:22 (7640): Status Report: Elapsed Time: '24002.140787'
2022-03-21 17:57:22 (7640): Status Report: CPU Time: '49.781250'

Never paused once.

So its deeper than my machine and BOINC
Killed it at 62.69% after over 7.5 hrs of working.

What a joke! .19% of a core. Waste of time!
ID: 105624 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Mr P Hucker
Avatar

Send message
Joined: 12 Aug 06
Posts: 1600
Credit: 12,116,986
RAC: 9,863
Message 105625 - Posted: 21 Mar 2022, 18:11:45 UTC - in response to Message 105624.  
Last modified: 21 Mar 2022, 18:12:33 UTC

Some kind of a response from them would be nice, perhaps one of:

1) We know there's a problem but our programmers are too inept to fix it.

2) We didn't know there was a problem because our heads are buried in the sand.

3) We know there's a problem and we're working on fixing it by [insert date]
ID: 105625 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Profile robertmiles

Send message
Joined: 16 Jun 08
Posts: 1234
Credit: 14,338,560
RAC: 2,014
Message 105628 - Posted: 21 Mar 2022, 19:07:39 UTC

An idea to check for the python tasks failing all at once:

Something may be writing into a location in the *.vdi files that is supposed to be read-only, and is shared among all the python tasks running at once.

To check for this:

1. While no python tasks are running, go to the shared directory for read-only Rosetta@Home files. On my computer, it is:

C:/ProgramData/BOINC/projects/boinc.bakerlab.org_rosetta

If your computer does not run under Windows 10, expect a different directory name.

For each file with a name ending with .vdi , make a copy elsewhere.

2. Allow many python tasks to start.

Watch for all of them to fail at once. If this happen, make a second copy of each of the files with names ending with vdi .

Start a program that will check two binary files, and tell you if they are identical or not. Tell it to compare the old and new copies of each of the vdi files.

Let us know if the copies were identical or not. Unless you have special information on the file structures, don't bother with what the differences are.


Another idea: vbox64 (which is used by python tasks) may have problems restarting from checkpoints, but not always. I have not thought of a way to check for that.
ID: 105628 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
kotenok2000
Avatar

Send message
Joined: 22 Feb 11
Posts: 272
Credit: 507,897
RAC: 334
Message 105629 - Posted: 21 Mar 2022, 19:30:56 UTC - in response to Message 105628.  
Last modified: 21 Mar 2022, 19:31:08 UTC

Virtualbox tasks do not write to boinc.bakerlab.org_rosetta vdi
They fully copy vdi files to slot directories.
All 7 gigabytes.
ID: 105629 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Previous · 1 . . . 192 · 193 · 194 · 195 · 196 · 197 · 198 . . . 309 · Next

Message boards : Number crunching : Problems and Technical Issues with Rosetta@home



©2024 University of Washington
https://www.bakerlab.org