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 . . . 191 · 192 · 193 · 194 · 195 · 196 · 197 . . . 309 · Next

AuthorMessage
kotenok2000
Avatar

Send message
Joined: 22 Feb 11
Posts: 272
Credit: 507,897
RAC: 274
Message 105565 - Posted: 20 Mar 2022, 1:09:31 UTC - in response to Message 105564.  

Now add stdout from good computer.
ID: 105565 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
kotenok2000
Avatar

Send message
Joined: 22 Feb 11
Posts: 272
Credit: 507,897
RAC: 274
Message 105566 - Posted: 20 Mar 2022, 1:12:28 UTC - in response to Message 105564.  
Last modified: 20 Mar 2022, 1:14:39 UTC

Where did you get BOINC client v7.19.0?
Latest windows version is 7.16.20 at https://boinc.berkeley.edu/download_all.php
You have two computers with boinc 7.19.0 installed.
ID: 105566 · 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: 8,091
Message 105568 - Posted: 20 Mar 2022, 2:01:03 UTC - in response to Message 105565.  

Now add stdout from good computer.
Running for 13 minutes properly on a good machine that never fails a python:

2022-03-20 01:41:59 (5320): Detected: vboxwrapper 26202
2022-03-20 01:41:59 (5320): Detected: BOINC client v7.19.0
2022-03-20 01:42:00 (5320): Detected: VirtualBox VboxManage Interface (Version: 5.2.44)
2022-03-20 01:42:00 (5320): Feature: Checkpoint interval offset (318 seconds)
2022-03-20 01:42:00 (5320): Detected: Minimum checkpoint interval (600.000000 seconds)
2022-03-20 01:42:01 (5320): Create VM. (boinc_02fbad8d939a70ec, slot#0)
2022-03-20 01:42:02 (5320): Setting Memory Size for VM. (6144MB)
2022-03-20 01:42:02 (5320): Setting CPU Count for VM. (1)
2022-03-20 01:42:02 (5320): Setting Chipset Options for VM.
2022-03-20 01:42:02 (5320): Setting Boot Options for VM.
2022-03-20 01:42:03 (5320): Setting Network Configuration for NAT.
2022-03-20 01:42:03 (5320): Disabling VM Network Access.
2022-03-20 01:42:03 (5320): Disabling USB Support for VM.
2022-03-20 01:42:04 (5320): Disabling COM Port Support for VM.
2022-03-20 01:42:04 (5320): Disabling LPT Port Support for VM.
2022-03-20 01:42:04 (5320): Disabling Audio Support for VM.
2022-03-20 01:42:04 (5320): Disabling Clipboard Support for VM.
2022-03-20 01:42:05 (5320): Disabling Drag and Drop Support for VM.
2022-03-20 01:42:05 (5320): Adding storage controller(s) to VM.
2022-03-20 01:42:05 (5320): Adding virtual disk drive to VM. (vm_image.vdi)
2022-03-20 01:42:06 (5320): Adding VirtualBox Guest Additions to VM.
2022-03-20 01:42:06 (5320): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB)
2022-03-20 01:42:06 (5320): Enabling shared directory for VM.
2022-03-20 01:42:07 (5320): Starting VM using VBoxManage interface. (boinc_02fbad8d939a70ec, slot#0)
2022-03-20 01:42:12 (5320): Successfully started VM. (PID = '2264')
2022-03-20 01:42:12 (5320): Reporting VM Process ID to BOINC.
2022-03-20 01:42:12 (5320): Guest Log: BIOS: VirtualBox 5.2.44
2022-03-20 01:42:12 (5320): Guest Log: CPUID EDX: 0x078bfbff
2022-03-20 01:42:12 (5320): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63
2022-03-20 01:42:12 (5320): VM state change detected. (old = 'poweredoff', new = 'running')
2022-03-20 01:42:12 (5320): Preference change detected
2022-03-20 01:42:12 (5320): Setting CPU throttle for VM. (100%)
2022-03-20 01:42:13 (5320): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2022-03-20 01:42:14 (5320): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032
2022-03-20 01:42:14 (5320): Guest Log: BIOS: Booting from Hard Disk...
2022-03-20 01:42:17 (5320): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
2022-03-20 01:42:17 (5320): Guest Log: vboxguest: misc device minor 58, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
2022-03-20 01:42:22 (5320): Guest Log: VBoxService 5.2.42 r137960 (verbosity: 0) linux.amd64 (May 13 2020 21:45:13) release log
2022-03-20 01:42:22 (5320): Guest Log: 00:00:00.000133 main     Log opened 2022-03-20T01:42:20.323740000Z
2022-03-20 01:42:23 (5320): Guest Log: 00:00:00.000189 main     OS Product: Linux
2022-03-20 01:42:23 (5320): Guest Log: 00:00:00.000212 main     OS Release: 4.19.0-14-amd64
2022-03-20 01:42:23 (5320): Guest Log: 00:00:00.000232 main     OS Version: #1 SMP Debian 4.19.171-2 (2021-01-30)
2022-03-20 01:42:23 (5320): Guest Log: 00:00:00.000252 main     Executable: /opt/VBoxGuestAdditions-5.2.42/sbin/VBoxService
2022-03-20 01:42:23 (5320): Guest Log: 00:00:00.000253 main     Process ID: 522
2022-03-20 01:42:23 (5320): Guest Log: 00:00:00.000253 main     Package type: LINUX_64BITS_GENERIC
2022-03-20 01:42:23 (5320): Guest Log: 00:00:00.001460 main     5.2.42 r137960 started. Verbose level = 0
2022-03-20 01:57:32 (5320): Creating new snapshot for VM.
2022-03-20 01:57:39 (5320): Checkpoint completed.
ID: 105568 · 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: 8,091
Message 105569 - Posted: 20 Mar 2022, 2:01:25 UTC - in response to Message 105566.  

Where did you get BOINC client v7.19.0?
Latest windows version is 7.16.20 at https://boinc.berkeley.edu/download_all.php
Pre release from Github. You have to compile it yourself. Don't ask me how that's done, someone did it for me. David Anderson refuses to issue a new version just now for some unknown reason, even though he promised one. I needed it to fix the error where Boinc downloads horrendous amounts of tasks if you limit how many of one app can run, like Python. I ended up with a queue of 500 Pythons on a machine which I only allowed to run 9 at a time. It would never have done them by the deadline.

I'll email you the three compiled files if you wish. It's 5.1MB.

You have two computers with boinc 7.19.0 installed.
7 actually, but only two have recently contacted Rosetta under my account, I usually use Gridcoin pool, but I can't if I want to run Python, since all my gridcoin hosts have been banned from Python and I can't reset them.
ID: 105569 · 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 105572 - Posted: 20 Mar 2022, 2:41:34 UTC - in response to Message 105539.  

I have one work-unit that has been running for days. I thought it was stuck yesterday morning at 99.1%, but it was still climbing *very* slowly. Today it is at 99.9+%; maybe it will be finished by tomorrow. It was due yesterday so I don't know if it will even be accepted. It's a virtual-box one. I'm trying now to figure out how to post a screenshot. Apparently, I can't just add an attachment. And I can't copy text from the Boinc Manager. It's one of the aagb-mNMPHE ones.

If you have a task you think is stalled, best to click on it and select properties on the left.
If there's a large difference between CPU time and Elapsed time, then it's stalled and you can only abort it.

In my 5+ days away I returned to a couple of tasks that'd been running 2 and 3 days respectively. Both had much-reduced CPU time - just a couple of hours.

See one's output here
aagb-ACHC-mPHE-GPN-ACHC12C_10_2578961_3_0
Run time 3 days 15 hours 28 min 42 sec
CPU time 2 hours 4 min 4 sec

Typically, if later tasks are completing before earlier tasks, check properties of those earlier tasks and abort them if necessary.
A much better method than checking in Task Manager - I find this method best, so give it a try.
ID: 105572 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
stratos412

Send message
Joined: 18 Mar 20
Posts: 12
Credit: 161,224
RAC: 152
Message 105574 - Posted: 20 Mar 2022, 8:01:49 UTC

Hello all.

Is anyone having issues with those new python projects?
I have downloaded three python projects on my old PC (OS: Linux Mint // CPU: Intel Core Duo @2.13Ghz).
I started crunching one of them and still running for two days now. It seems that it keeps calculating but in a very slow way.
The problem is that I can run only one at the time because of luck of RAM (only 4GB). In addition with the strict deadline (download the projects on the 18/3 and deadline on 21/3), it doesn't seem I can manage all of them...:/.
Does anyone else encounter issues with python projects and is anything with can do to about it?
P.S. Task was 95% completed on 23.30 pm and that time (10.00 am) is on 97,3%. It means about 0,25% per hour....
ID: 105574 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Profile Grant (SSSF)

Send message
Joined: 28 Mar 20
Posts: 1725
Credit: 18,417,319
RAC: 20,286
Message 105575 - Posted: 20 Mar 2022, 8:33:00 UTC - in response to Message 105574.  

P.S. Task was 95% completed on 23.30 pm and that time (10.00 am) is on 97,3%. It means about 0,25% per hour....
It's a common issue with some Python Tasks.
Aborting such Tasks is the general met hind for dealing with them.
With luck, the next one should run OK.
Grant
Darwin NT
ID: 105575 · 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 105576 - Posted: 20 Mar 2022, 8:39:23 UTC - in response to Message 105574.  

Hello all.

Is anyone having issues with those new python projects?
I have downloaded three python projects on my old PC (OS: Linux Mint // CPU: Intel Core Duo @2.13Ghz).
I started crunching one of them and still running for two days now. It seems that it keeps calculating but in a very slow way.
The problem is that I can run only one at the time because of luck of RAM (only 4GB). In addition with the strict deadline (download the projects on the 18/3 and deadline on 21/3), it doesn't seem I can manage all of them...:/.
Does anyone else encounter issues with python projects and is anything with can do to about it?
P.S. Task was 95% completed on 23.30 pm and that time (10.00 am) is on 97,3%. It means about 0,25% per hour....


What other projects are you running on your system?
If anything else is running at the same time, then it is possible there is not enough system resources to run python.

I can't see anything physically that would prevent it from running normal.
I thought maybe processor cache, but that is the same as one of your new computers.
I'm not a linux guy, but I guess your using the latest version.
RAM limitation could be part of your problem.

I would suggest you do the same as what I suggested to Peter. Give us the text of the stderr file. Maybe there is something we can see in there. Do that before you abort the task or the next task. Do it somewhere after 15% completion, then we can see run times and model counts and snapshot rates among other things.
ID: 105576 · 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 105577 - Posted: 20 Mar 2022, 8:40:27 UTC - in response to Message 105575.  

P.S. Task was 95% completed on 23.30 pm and that time (10.00 am) is on 97,3%. It means about 0,25% per hour....
It's a common issue with some Python Tasks.
Aborting such Tasks is the general met hind for dealing with them.
With luck, the next one should run OK.


He already aborted 2 and is struggling with the third.
So aborting will get him no where.
ID: 105577 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
stratos412

Send message
Joined: 18 Mar 20
Posts: 12
Credit: 161,224
RAC: 152
Message 105579 - Posted: 20 Mar 2022, 9:14:28 UTC - in response to Message 105576.  

@Greg_BE.

Nothing else is running. Only one task of Rosetta. The older tasks of Rosetta (not the pythons), were running pretty well.
Those was my first python projects. About PC limitations you are correct. PC is is pretty old, so it's struggling with RAM and Cache...
Yep, unfortunately, I have already aborted two tasks.

P.S. Where is the stderr file? I am on Linux and I think there is a different log file...
ID: 105579 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
stratos412

Send message
Joined: 18 Mar 20
Posts: 12
Credit: 161,224
RAC: 152
Message 105580 - Posted: 20 Mar 2022, 9:24:24 UTC

Found stderr file



2022-03-18 12:05:02 (6262): vboxwrapper (7.7.26197): starting
2022-03-18 12:05:03 (6262): Feature: Checkpoint interval offset (92 seconds)
2022-03-18 12:05:03 (6262): Detected: VirtualBox VboxManage Interface (Version: 6.1.32)
2022-03-18 12:05:03 (6262): Detected: Minimum checkpoint interval (600.000000 seconds)
2022-03-18 12:05:03 (6262): Create VM. (boinc_02a4a3021936da98, slot#0)
2022-03-18 12:05:04 (6262): Setting Memory Size for VM. (6144MB)
2022-03-18 12:05:04 (6262): Setting CPU Count for VM. (1)
2022-03-18 12:05:04 (6262): Setting Chipset Options for VM.
2022-03-18 12:05:04 (6262): Setting Boot Options for VM.
2022-03-18 12:05:04 (6262): Setting Network Configuration for NAT.
2022-03-18 12:05:04 (6262): Disabling VM Network Access.
2022-03-18 12:05:04 (6262): Disabling USB Support for VM.
2022-03-18 12:05:04 (6262): Disabling COM Port Support for VM.
2022-03-18 12:05:04 (6262): Disabling LPT Port Support for VM.
2022-03-18 12:05:05 (6262): Disabling Audio Support for VM.
2022-03-18 12:05:05 (6262): Disabling Clipboard Support for VM.
2022-03-18 12:05:05 (6262): Disabling Drag and Drop Support for VM.
2022-03-18 12:05:05 (6262): Adding storage controller(s) to VM.
2022-03-18 12:05:05 (6262): Adding virtual disk drive to VM. (vm_image.vdi)
2022-03-18 12:05:05 (6262): Adding network bandwidth throttle group to VM. (Defaulting to 1024GB)
2022-03-18 12:05:05 (6262): Enabling shared directory for VM.
2022-03-18 12:05:05 (6262): Starting VM. (boinc_02a4a3021936da98, slot#0)
2022-03-18 12:05:07 (6262): Successfully started VM. (PID = '6636')
2022-03-18 12:05:07 (6262): Reporting VM Process ID to BOINC.
2022-03-18 12:05:07 (6262): Guest Log: BIOS: VirtualBox 6.1.31_SPB
2022-03-18 12:05:07 (6262): Guest Log: CPUID EDX: 0x178bfbff
2022-03-18 12:05:07 (6262): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63
2022-03-18 12:05:07 (6262): VM state change detected. (old = 'poweroff', new = 'running')
2022-03-18 12:05:08 (6262): Preference change detected
2022-03-18 12:05:08 (6262): Setting CPU throttle for VM. (70%)
2022-03-18 12:05:08 (6262): Setting checkpoint interval to 900 seconds. (Higher value of (Preference: 900 seconds) or (Vbox_job.xml: 600 seconds))
2022-03-18 12:05:09 (6262): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032
2022-03-18 12:05:09 (6262): Guest Log: BIOS: Booting from Hard Disk...
2022-03-18 12:05:32 (6262): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
2022-03-18 12:05:32 (6262): Guest Log: vboxguest: misc device minor 58, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
2022-03-18 12:06:27 (6262): Guest Log: VBoxService 5.2.42 r137960 (verbosity: 0) linux.amd64 (May 13 2020 21:45:13) release log
2022-03-18 12:06:27 (6262): Guest Log: 00:00:00.001547 main Log opened 2022-03-18T12:06:26.053022000Z
2022-03-18 12:06:27 (6262): Guest Log: 00:00:00.002386 main OS Product: Linux
2022-03-18 12:06:27 (6262): Guest Log: 00:00:00.002494 main OS Release: 4.19.0-14-amd64
2022-03-18 12:06:27 (6262): Guest Log: 00:00:00.002601 main OS Version: #1 SMP Debian 4.19.171-2 (2021-01-30)
2022-03-18 12:06:27 (6262): Guest Log: 00:00:00.002667 main Executable: /opt/VBoxGuestAdditions-5.2.42/sbin/VBoxService
2022-03-18 12:06:27 (6262): Guest Log: 00:00:00.002668 main Process ID: 508
2022-03-18 12:06:27 (6262): Guest Log: 00:00:00.002669 main Package type: LINUX_64BITS_GENERIC
2022-03-18 12:06:27 (6262): Guest Log: 00:00:00.005202 main 5.2.42 r137960 started. Verbose level = 0
2022-03-18 12:06:37 (6262): Guest Log: 00:00:10.092240 timesync vgsvcTimeSyncWorker: Radical guest time change: -7 188 961 373 000ns (GuestNow=1 647 597 997 177 962 000 ns GuestLast=1 647 605 186 139 335 000 ns fSetTimeLastLoop=true )
2022-03-18 12:21:32 (6262): Creating new snapshot for VM.
2022-03-18 12:21:42 (6262): Checkpoint completed.
2022-03-18 12:36:49 (6262): Creating new snapshot for VM.
2022-03-18 12:36:59 (6262): Deleting stale snapshot.
2022-03-18 12:36:59 (6262): Checkpoint completed.
2022-03-18 12:52:02 (6262): Creating new snapshot for VM.
2022-03-18 12:52:12 (6262): Deleting stale snapshot.
2022-03-18 12:52:12 (6262): Checkpoint completed.
2022-03-18 13:07:15 (6262): Creating new snapshot for VM.
2022-03-18 13:07:25 (6262): Deleting stale snapshot.
2022-03-18 13:07:25 (6262): Checkpoint completed.
2022-03-18 13:22:28 (6262): Creating new snapshot for VM.
2022-03-18 13:22:38 (6262): Deleting stale snapshot.
2022-03-18 13:22:38 (6262): Checkpoint completed.
2022-03-18 13:37:41 (6262): Creating new snapshot for VM.
2022-03-18 13:37:50 (6262): Deleting stale snapshot.
2022-03-18 13:37:50 (6262): Checkpoint completed.
2022-03-18 13:44:12 (6262): Status Report: Elapsed Time: '6000.727319'
2022-03-18 13:44:12 (6262): Status Report: CPU Time: '181.730000'
2022-03-18 13:52:54 (6262): Creating new snapshot for VM.
2022-03-18 13:53:03 (6262): Deleting stale snapshot.
2022-03-18 13:53:03 (6262): Checkpoint completed.
2022-03-18 14:08:11 (6262): Creating new snapshot for VM.
2022-03-18 14:08:20 (6262): Deleting stale snapshot.
2022-03-18 14:08:21 (6262): Checkpoint completed.
2022-03-18 14:23:32 (6262): Creating new snapshot for VM.
2022-03-18 14:23:42 (6262): Deleting stale snapshot.
2022-03-18 14:23:43 (6262): Checkpoint completed.
2022-03-18 14:38:53 (6262): Creating new snapshot for VM.
2022-03-18 14:39:03 (6262): Deleting stale snapshot.
2022-03-18 14:39:03 (6262): Checkpoint completed.
2022-03-18 14:54:15 (6262): Creating new snapshot for VM.
2022-03-18 14:54:25 (6262): Deleting stale snapshot.
2022-03-18 14:54:25 (6262): Checkpoint completed.
2022-03-18 15:09:36 (6262): Creating new snapshot for VM.
2022-03-18 15:09:45 (6262): Deleting stale snapshot.
2022-03-18 15:09:46 (6262): Checkpoint completed.
2022-03-18 15:23:17 (6262): Status Report: Elapsed Time: '12000.871435'
2022-03-18 15:23:17 (6262): Status Report: CPU Time: '312.550000'
2022-03-18 15:24:58 (6262): Creating new snapshot for VM.
2022-03-18 15:25:07 (6262): Deleting stale snapshot.
2022-03-18 15:25:08 (6262): Checkpoint completed.
2022-03-18 15:40:19 (6262): Creating new snapshot for VM.
2022-03-18 15:40:29 (6262): Deleting stale snapshot.
2022-03-18 15:40:30 (6262): Checkpoint completed.
2022-03-18 15:55:41 (6262): Creating new snapshot for VM.
2022-03-18 15:55:50 (6262): Deleting stale snapshot.
2022-03-18 15:55:51 (6262): Checkpoint completed.
2022-03-18 16:11:02 (6262): Creating new snapshot for VM.
2022-03-18 16:11:13 (6262): Deleting stale snapshot.
2022-03-18 16:11:15 (6262): Checkpoint completed.
2022-03-18 16:26:26 (6262): Creating new snapshot for VM.
2022-03-18 16:26:35 (6262): Deleting stale snapshot.
2022-03-18 16:26:36 (6262): Checkpoint completed.
2022-03-18 16:41:45 (6262): Creating new snapshot for VM.
2022-03-18 16:41:54 (6262): Deleting stale snapshot.
2022-03-18 16:41:55 (6262): Checkpoint completed.
2022-03-18 16:57:06 (6262): Creating new snapshot for VM.
2022-03-18 16:57:16 (6262): Deleting stale snapshot.
2022-03-18 16:57:16 (6262): Checkpoint completed.
2022-03-18 17:02:24 (6262): Status Report: Elapsed Time: '18001.359512'
2022-03-18 17:02:24 (6262): Status Report: CPU Time: '452.100000'
2022-03-18 17:12:27 (6262): Creating new snapshot for VM.
2022-03-18 17:12:37 (6262): Deleting stale snapshot.
2022-03-18 17:12:37 (6262): Checkpoint completed.
2022-03-18 17:27:49 (6262): Creating new snapshot for VM.
2022-03-18 17:27:58 (6262): Deleting stale snapshot.
2022-03-18 17:27:59 (6262): Checkpoint completed.
2022-03-18 17:43:10 (6262): Creating new snapshot for VM.
2022-03-18 17:43:19 (6262): Deleting stale snapshot.
2022-03-18 17:43:20 (6262): Checkpoint completed.
2022-03-18 17:58:32 (6262): Creating new snapshot for VM.
2022-03-18 17:58:42 (6262): Deleting stale snapshot.
2022-03-18 17:58:42 (6262): Checkpoint completed.
2022-03-18 18:13:51 (6262): Creating new snapshot for VM.
2022-03-18 18:14:00 (6262): Deleting stale snapshot.
2022-03-18 18:14:00 (6262): Checkpoint completed.
2022-03-18 18:29:05 (6262): Creating new snapshot for VM.
2022-03-18 18:29:14 (6262): Deleting stale snapshot.
2022-03-18 18:29:14 (6262): Checkpoint completed.
2022-03-18 18:41:29 (6262): Status Report: Elapsed Time: '24002.201932'
2022-03-18 18:41:29 (6262): Status Report: CPU Time: '585.260000'
2022-03-18 18:44:19 (6262): Creating new snapshot for VM.
2022-03-18 18:44:28 (6262): Deleting stale snapshot.
2022-03-18 18:44:29 (6262): Checkpoint completed.
2022-03-18 18:59:33 (6262): Creating new snapshot for VM.
2022-03-18 18:59:42 (6262): Deleting stale snapshot.
2022-03-18 18:59:43 (6262): Checkpoint completed.
2022-03-18 19:14:52 (6262): Creating new snapshot for VM.
2022-03-18 19:15:01 (6262): Deleting stale snapshot.
2022-03-18 19:15:02 (6262): Checkpoint completed.
2022-03-18 19:30:06 (6262): Creating new snapshot for VM.
2022-03-18 19:30:15 (6262): Deleting stale snapshot.
2022-03-18 19:30:16 (6262): Checkpoint completed.
2022-03-18 19:45:20 (6262): Creating new snapshot for VM.
2022-03-18 19:45:29 (6262): Deleting stale snapshot.
2022-03-18 19:45:30 (6262): Checkpoint completed.
2022-03-18 20:00:34 (6262): Creating new snapshot for VM.
2022-03-18 20:00:43 (6262): Deleting stale snapshot.
2022-03-18 20:00:44 (6262): Checkpoint completed.
2022-03-18 20:15:48 (6262): Creating new snapshot for VM.
2022-03-18 20:15:57 (6262): Deleting stale snapshot.
2022-03-18 20:15:57 (6262): Checkpoint completed.
2022-03-18 20:20:36 (6262): Status Report: Elapsed Time: '30002.719832'
2022-03-18 20:20:36 (6262): Status Report: CPU Time: '722.790000'
2022-03-18 20:31:03 (6262): Creating new snapshot for VM.
2022-03-18 20:31:12 (6262): Deleting stale snapshot.
2022-03-18 20:31:12 (6262): Checkpoint completed.
2022-03-18 20:46:24 (6262): Creating new snapshot for VM.
2022-03-18 20:46:34 (6262): Deleting stale snapshot.
2022-03-18 20:46:34 (6262): Checkpoint completed.
2022-03-18 21:01:45 (6262): Creating new snapshot for VM.
2022-03-18 21:01:56 (6262): Deleting stale snapshot.
2022-03-18 21:01:56 (6262): Checkpoint completed.
2022-03-18 21:17:08 (6262): Creating new snapshot for VM.
2022-03-18 21:17:18 (6262): Deleting stale snapshot.
2022-03-18 21:17:18 (6262): Checkpoint completed.
2022-03-18 21:32:29 (6262): Creating new snapshot for VM.
2022-03-18 21:32:39 (6262): Deleting stale snapshot.
2022-03-18 21:32:39 (6262): Checkpoint completed.
2022-03-18 21:47:50 (6262): Creating new snapshot for VM.
2022-03-18 21:47:59 (6262): Deleting stale snapshot.
2022-03-18 21:48:00 (6262): Checkpoint completed.
2022-03-18 21:59:42 (6262): Status Report: Elapsed Time: '36002.952542'
2022-03-18 21:59:42 (6262): Status Report: CPU Time: '853.460000'
2022-03-18 22:03:11 (6262): Creating new snapshot for VM.
2022-03-18 22:03:20 (6262): Deleting stale snapshot.
2022-03-18 22:03:20 (6262): Checkpoint completed.
2022-03-18 22:18:32 (6262): Creating new snapshot for VM.
2022-03-18 22:18:42 (6262): Deleting stale snapshot.
2022-03-18 22:18:42 (6262): Checkpoint completed.
2022-03-18 22:33:53 (6262): Creating new snapshot for VM.
2022-03-18 22:34:03 (6262): Deleting stale snapshot.
2022-03-18 22:34:03 (6262): Checkpoint completed.
2022-03-18 22:49:14 (6262): Creating new snapshot for VM.
2022-03-18 22:49:23 (6262): Deleting stale snapshot.
2022-03-18 22:49:24 (6262): Checkpoint completed.
2022-03-18 23:04:36 (6262): Creating new snapshot for VM.
2022-03-18 23:04:45 (6262): Deleting stale snapshot.
2022-03-18 23:04:46 (6262): Checkpoint completed.
2022-03-18 23:19:57 (6262): Creating new snapshot for VM.
2022-03-18 23:20:06 (6262): Deleting stale snapshot.
2022-03-18 23:20:07 (6262): Checkpoint completed.
2022-03-18 23:35:19 (6262): Creating new snapshot for VM.
2022-03-18 23:35:29 (6262): Deleting stale snapshot.
2022-03-18 23:35:29 (6262): Checkpoint completed.
2022-03-18 23:38:49 (6262): Status Report: Elapsed Time: '42003.917933'
2022-03-18 23:38:49 (6262): Status Report: CPU Time: '992.170000'
2022-03-18 23:50:41 (6262): Creating new snapshot for VM.
2022-03-18 23:50:50 (6262): Deleting stale snapshot.
2022-03-18 23:50:51 (6262): Checkpoint completed.
2022-03-19 00:06:02 (6262): Creating new snapshot for VM.
2022-03-19 00:06:11 (6262): Deleting stale snapshot.
2022-03-19 00:06:11 (6262): Checkpoint completed.
2022-03-19 00:10:36 (6262): VM state change detected. (old = 'running', new = 'paused')
2022-03-19 00:10:42 (6262): VM state change detected. (old = 'paused', new = 'running')
2022-03-19 00:21:22 (6262): Creating new snapshot for VM.
2022-03-19 00:21:32 (6262): Deleting stale snapshot.
2022-03-19 00:21:33 (6262): Checkpoint completed.
2022-03-19 00:36:43 (6262): Creating new snapshot for VM.
2022-03-19 00:36:52 (6262): Deleting stale snapshot.
2022-03-19 00:36:52 (6262): Checkpoint completed.
2022-03-19 00:52:02 (6262): Creating new snapshot for VM.
2022-03-19 00:52:11 (6262): Deleting stale snapshot.
2022-03-19 00:52:12 (6262): Checkpoint completed.
2022-03-19 01:07:23 (6262): Creating new snapshot for VM.
2022-03-19 01:07:32 (6262): Deleting stale snapshot.
2022-03-19 01:07:33 (6262): Checkpoint completed.
2022-03-19 01:18:02 (6262): Status Report: Elapsed Time: '48004.210757'
2022-03-19 01:18:02 (6262): Status Report: CPU Time: '1131.480000'
2022-03-19 01:22:43 (6262): Creating new snapshot for VM.
2022-03-19 01:22:52 (6262): Deleting stale snapshot.
2022-03-19 01:22:53 (6262): Checkpoint completed.
2022-03-19 01:38:03 (6262): Creating new snapshot for VM.
2022-03-19 01:38:13 (6262): Deleting stale snapshot.
2022-03-19 01:38:13 (6262): Checkpoint completed.
2022-03-19 01:53:23 (6262): Creating new snapshot for VM.
2022-03-19 01:53:33 (6262): Deleting stale snapshot.
2022-03-19 01:53:34 (6262): Checkpoint completed.
2022-03-19 02:08:44 (6262): Creating new snapshot for VM.
2022-03-19 02:08:53 (6262): Deleting stale snapshot.
2022-03-19 02:08:53 (6262): Checkpoint completed.
2022-03-19 02:24:03 (6262): Creating new snapshot for VM.
2022-03-19 02:24:13 (6262): Deleting stale snapshot.
2022-03-19 02:24:13 (6262): Checkpoint completed.
2022-03-19 02:39:24 (6262): Creating new snapshot for VM.
2022-03-19 02:39:34 (6262): Deleting stale snapshot.
2022-03-19 02:39:34 (6262): Checkpoint completed.
2022-03-19 02:54:44 (6262): Creating new snapshot for VM.
2022-03-19 02:54:54 (6262): Deleting stale snapshot.
2022-03-19 02:54:55 (6262): Checkpoint completed.
2022-03-19 02:57:08 (6262): Status Report: Elapsed Time: '54004.555802'
2022-03-19 02:57:08 (6262): Status Report: CPU Time: '1284.160000'
2022-03-19 03:10:04 (6262): Creating new snapshot for VM.
2022-03-19 03:10:14 (6262): Deleting stale snapshot.
2022-03-19 03:10:15 (6262): Checkpoint completed.
2022-03-19 03:25:25 (6262): Creating new snapshot for VM.
2022-03-19 03:25:35 (6262): Deleting stale snapshot.
2022-03-19 03:25:35 (6262): Checkpoint completed.
2022-03-19 03:40:45 (6262): Creating new snapshot for VM.
2022-03-19 03:40:55 (6262): Deleting stale snapshot.
2022-03-19 03:40:55 (6262): Checkpoint completed.
2022-03-19 03:56:05 (6262): Creating new snapshot for VM.
2022-03-19 03:56:14 (6262): Deleting stale snapshot.
2022-03-19 03:56:15 (6262): Checkpoint completed.
2022-03-19 04:11:25 (6262): Creating new snapshot for VM.
2022-03-19 04:11:35 (6262): Deleting stale snapshot.
2022-03-19 04:11:35 (6262): Checkpoint completed.
2022-03-19 04:26:44 (6262): Creating new snapshot for VM.
2022-03-19 04:26:53 (6262): Deleting stale snapshot.
2022-03-19 04:26:54 (6262): Checkpoint completed.
2022-03-19 04:36:15 (6262): Status Report: Elapsed Time: '60005.245731'
2022-03-19 04:36:15 (6262): Status Report: CPU Time: '1426.140000'
2022-03-19 04:41:58 (6262): Creating new snapshot for VM.
2022-03-19 04:42:08 (6262): Deleting stale snapshot.
2022-03-19 04:42:08 (6262): Checkpoint completed.
2022-03-19 04:57:12 (6262): Creating new snapshot for VM.
2022-03-19 04:57:22 (6262): Deleting stale snapshot.
2022-03-19 04:57:22 (6262): Checkpoint completed.
2022-03-19 05:12:26 (6262): Creating new snapshot for VM.
2022-03-19 05:12:36 (6262): Deleting stale snapshot.
2022-03-19 05:12:37 (6262): Checkpoint completed.
2022-03-19 05:27:41 (6262): Creating new snapshot for VM.
2022-03-19 05:27:50 (6262): Deleting stale snapshot.
2022-03-19 05:27:51 (6262): Checkpoint completed.
2022-03-19 05:42:55 (6262): Creating new snapshot for VM.
2022-03-19 05:43:04 (6262): Deleting stale snapshot.
2022-03-19 05:43:05 (6262): Checkpoint completed.
2022-03-19 05:58:09 (6262): Creating new snapshot for VM.
2022-03-19 05:58:18 (6262): Deleting stale snapshot.
2022-03-19 05:58:19 (6262): Checkpoint completed.
2022-03-19 06:13:24 (6262): Creating new snapshot for VM.
2022-03-19 06:13:34 (6262): Deleting stale snapshot.
2022-03-19 06:13:34 (6262): Checkpoint completed.
2022-03-19 06:15:17 (6262): Status Report: Elapsed Time: '66005.671532'
2022-03-19 06:15:17 (6262): Status Report: CPU Time: '1564.950000'
2022-03-19 06:28:38 (6262): Creating new snapshot for VM.
2022-03-19 06:28:48 (6262): Deleting stale snapshot.
2022-03-19 06:28:48 (6262): Checkpoint completed.
2022-03-19 06:43:52 (6262): Creating new snapshot for VM.
2022-03-19 06:44:02 (6262): Deleting stale snapshot.
2022-03-19 06:44:02 (6262): Checkpoint completed.
2022-03-19 06:59:06 (6262): Creating new snapshot for VM.
2022-03-19 06:59:16 (6262): Deleting stale snapshot.
2022-03-19 06:59:16 (6262): Checkpoint completed.
2022-03-19 07:14:21 (6262): Creating new snapshot for VM.
2022-03-19 07:14:30 (6262): Deleting stale snapshot.
2022-03-19 07:14:30 (6262): Checkpoint completed.
2022-03-19 07:29:35 (6262): Creating new snapshot for VM.
2022-03-19 07:29:44 (6262): Deleting stale snapshot.
2022-03-19 07:29:44 (6262): Checkpoint completed.
2022-03-19 07:44:48 (6262): Creating new snapshot for VM.
2022-03-19 07:44:58 (6262): Deleting stale snapshot.
2022-03-19 07:44:58 (6262): Checkpoint completed.
2022-03-19 07:54:20 (6262): Status Report: Elapsed Time: '72006.556076'
2022-03-19 07:54:20 (6262): Status Report: CPU Time: '1693.620000'
2022-03-19 08:00:03 (6262): Creating new snapshot for VM.
2022-03-19 08:00:13 (6262): Deleting stale snapshot.
2022-03-19 08:00:13 (6262): Checkpoint completed.
2022-03-19 08:08:53 (6262): Preference change detected
2022-03-19 08:08:53 (6262): Setting CPU throttle for VM. (70%)
2022-03-19 08:08:53 (6262): Setting checkpoint interval to 900 seconds. (Higher value of (Preference: 900 seconds) or (Vbox_job.xml: 600 seconds))
2022-03-19 08:15:18 (6262): Creating new snapshot for VM.
2022-03-19 08:15:28 (6262): Deleting stale snapshot.
2022-03-19 08:15:28 (6262): Checkpoint completed.
2022-03-19 08:30:33 (6262): Creating new snapshot for VM.
2022-03-19 08:30:42 (6262): Deleting stale snapshot.
2022-03-19 08:30:43 (6262): Checkpoint completed.
2022-03-19 08:45:47 (6262): Creating new snapshot for VM.
2022-03-19 08:45:57 (6262): Deleting stale snapshot.
2022-03-19 08:45:57 (6262): Checkpoint completed.
2022-03-19 08:47:29 (6262): VM state change detected. (old = 'running', new = 'paused')
2022-03-19 08:47:40 (6262): VM state change detected. (old = 'paused', new = 'running')
2022-03-19 09:01:07 (6262): Creating new snapshot for VM.
2022-03-19 09:01:17 (6262): Deleting stale snapshot.
2022-03-19 09:01:17 (6262): Checkpoint completed.
2022-03-19 09:16:28 (6262): Creating new snapshot for VM.
2022-03-19 09:16:37 (6262): Deleting stale snapshot.
2022-03-19 09:16:38 (6262): Checkpoint completed.
2022-03-19 09:31:42 (6262): Creating new snapshot for VM.
2022-03-19 09:31:51 (6262): Deleting stale snapshot.
2022-03-19 09:31:51 (6262): Checkpoint completed.
2022-03-19 09:33:36 (6262): Status Report: Elapsed Time: '78006.973077'
2022-03-19 09:33:36 (6262): Status Report: CPU Time: '1833.090000'
2022-03-19 09:46:56 (6262): Creating new snapshot for VM.
2022-03-19 09:47:05 (6262): Deleting stale snapshot.
2022-03-19 09:47:06 (6262): Checkpoint completed.
2022-03-19 10:02:10 (6262): Creating new snapshot for VM.
2022-03-19 10:02:19 (6262): Deleting stale snapshot.
2022-03-19 10:02:19 (6262): Checkpoint completed.
2022-03-19 10:17:24 (6262): Creating new snapshot for VM.
2022-03-19 10:17:33 (6262): Deleting stale snapshot.
2022-03-19 10:17:34 (6262): Checkpoint completed.
2022-03-19 10:26:50 (6262): VM state change detected. (old = 'running', new = 'paused')
2022-03-19 10:26:54 (6262): VM state change detected. (old = 'paused', new = 'running')
2022-03-19 10:32:40 (6262): Creating new snapshot for VM.
2022-03-19 10:32:49 (6262): Deleting stale snapshot.
2022-03-19 10:32:50 (6262): Checkpoint completed.
2022-03-19 10:48:01 (6262): Creating new snapshot for VM.
2022-03-19 10:48:12 (6262): Deleting stale snapshot.
2022-03-19 10:48:12 (6262): Checkpoint completed.
2022-03-19 11:03:23 (6262): Creating new snapshot for VM.
2022-03-19 11:03:33 (6262): Deleting stale snapshot.
2022-03-19 11:03:34 (6262): Checkpoint completed.
2022-03-19 11:12:45 (6262): Status Report: Elapsed Time: '84007.761108'
2022-03-19 11:12:45 (6262): Status Report: CPU Time: '1962.750000'
2022-03-19 11:18:45 (6262): Creating new snapshot for VM.
2022-03-19 11:18:55 (6262): Deleting stale snapshot.
2022-03-19 11:18:56 (6262): Checkpoint completed.
2022-03-19 11:34:06 (6262): Creating new snapshot for VM.
2022-03-19 11:34:16 (6262): Deleting stale snapshot.
2022-03-19 11:34:17 (6262): Checkpoint completed.
2022-03-19 11:49:29 (6262): Creating new snapshot for VM.
2022-03-19 11:49:39 (6262): Deleting stale snapshot.
2022-03-19 11:49:39 (6262): Checkpoint completed.
2022-03-19 12:04:51 (6262): Creating new snapshot for VM.
2022-03-19 12:05:01 (6262): Deleting stale snapshot.
2022-03-19 12:05:01 (6262): Checkpoint completed.
2022-03-19 12:20:13 (6262): Creating new snapshot for VM.
2022-03-19 12:20:23 (6262): Deleting stale snapshot.
2022-03-19 12:20:24 (6262): Checkpoint completed.
2022-03-19 12:35:34 (6262): Creating new snapshot for VM.
2022-03-19 12:35:44 (6262): Deleting stale snapshot.
2022-03-19 12:35:45 (6262): Checkpoint completed.
2022-03-19 12:50:56 (6262): Creating new snapshot for VM.
2022-03-19 12:51:05 (6262): Deleting stale snapshot.
2022-03-19 12:51:06 (6262): Checkpoint completed.
2022-03-19 12:51:51 (6262): Status Report: Elapsed Time: '90007.911948'
2022-03-19 12:51:51 (6262): Status Report: CPU Time: '2102.600000'
2022-03-19 13:06:17 (6262): Creating new snapshot for VM.
2022-03-19 13:06:27 (6262): Deleting stale snapshot.
2022-03-19 13:06:28 (6262): Checkpoint completed.
2022-03-19 13:21:39 (6262): Creating new snapshot for VM.
2022-03-19 13:21:48 (6262): Deleting stale snapshot.
2022-03-19 13:21:48 (6262): Checkpoint completed.
2022-03-19 13:37:00 (6262): Creating new snapshot for VM.
2022-03-19 13:37:10 (6262): Deleting stale snapshot.
2022-03-19 13:37:10 (6262): Checkpoint completed.
2022-03-19 13:52:22 (6262): Creating new snapshot for VM.
2022-03-19 13:52:32 (6262): Deleting stale snapshot.
2022-03-19 13:52:32 (6262): Checkpoint completed.
2022-03-19 14:07:44 (6262): Creating new snapshot for VM.
2022-03-19 14:07:53 (6262): Deleting stale snapshot.
2022-03-19 14:07:54 (6262): Checkpoint completed.
2022-03-19 14:23:05 (6262): Creating new snapshot for VM.
2022-03-19 14:23:15 (6262): Deleting stale snapshot.
2022-03-19 14:23:15 (6262): Checkpoint completed.
2022-03-19 14:30:58 (6262): Status Report: Elapsed Time: '96008.415744'
2022-03-19 14:30:58 (6262): Status Report: CPU Time: '2236.450000'
2022-03-19 14:38:19 (6262): Creating new snapshot for VM.
2022-03-19 14:38:29 (6262): Deleting stale snapshot.
2022-03-19 14:38:30 (6262): Checkpoint completed.
2022-03-19 14:53:36 (6262): Creating new snapshot for VM.
2022-03-19 14:53:46 (6262): Deleting stale snapshot.
2022-03-19 14:53:46 (6262): Checkpoint completed.
2022-03-19 15:08:58 (6262): Creating new snapshot for VM.
2022-03-19 15:09:07 (6262): Deleting stale snapshot.
2022-03-19 15:09:08 (6262): Checkpoint completed.
2022-03-19 15:24:19 (6262): Creating new snapshot for VM.
2022-03-19 15:24:28 (6262): Deleting stale snapshot.
2022-03-19 15:24:28 (6262): Checkpoint completed.
2022-03-19 15:39:40 (6262): Creating new snapshot for VM.
2022-03-19 15:39:49 (6262): Deleting stale snapshot.
2022-03-19 15:39:50 (6262): Checkpoint completed.
2022-03-19 15:55:01 (6262): Creating new snapshot for VM.
2022-03-19 15:55:12 (6262): Deleting stale snapshot.
2022-03-19 15:55:13 (6262): Checkpoint completed.
2022-03-19 16:10:04 (6262): Status Report: Elapsed Time: '102008.568190'
2022-03-19 16:10:04 (6262): Status Report: CPU Time: '2369.390000'
2022-03-19 16:10:24 (6262): Creating new snapshot for VM.
2022-03-19 16:10:34 (6262): Deleting stale snapshot.
2022-03-19 16:10:34 (6262): Checkpoint completed.
2022-03-19 16:25:46 (6262): Creating new snapshot for VM.
2022-03-19 16:25:56 (6262): Deleting stale snapshot.
2022-03-19 16:25:56 (6262): Checkpoint completed.
2022-03-19 16:41:08 (6262): Creating new snapshot for VM.
2022-03-19 16:41:18 (6262): Deleting stale snapshot.
2022-03-19 16:41:18 (6262): Checkpoint completed.
2022-03-19 16:56:30 (6262): Creating new snapshot for VM.
2022-03-19 16:56:39 (6262): Deleting stale snapshot.
2022-03-19 16:56:39 (6262): Checkpoint completed.
2022-03-19 17:11:51 (6262): Creating new snapshot for VM.
2022-03-19 17:12:01 (6262): Deleting stale snapshot.
2022-03-19 17:12:01 (6262): Checkpoint completed.
2022-03-19 17:27:13 (6262): Creating new snapshot for VM.
2022-03-19 17:27:23 (6262): Deleting stale snapshot.
2022-03-19 17:27:24 (6262): Checkpoint completed.
2022-03-19 17:42:35 (6262): Creating new snapshot for VM.
2022-03-19 17:42:45 (6262): Deleting stale snapshot.
2022-03-19 17:42:45 (6262): Checkpoint completed.
2022-03-19 17:49:11 (6262): Status Report: Elapsed Time: '108009.537952'
2022-03-19 17:49:11 (6262): Status Report: CPU Time: '2509.140000'
2022-03-19 17:57:57 (6262): Creating new snapshot for VM.
2022-03-19 17:58:07 (6262): Deleting stale snapshot.
2022-03-19 17:58:08 (6262): Checkpoint completed.
2022-03-19 18:13:19 (6262): Creating new snapshot for VM.
2022-03-19 18:13:29 (6262): Deleting stale snapshot.
2022-03-19 18:13:30 (6262): Checkpoint completed.
2022-03-19 18:28:42 (6262): Creating new snapshot for VM.
2022-03-19 18:28:52 (6262): Deleting stale snapshot.
2022-03-19 18:28:52 (6262): Checkpoint completed.
2022-03-19 18:44:03 (6262): Creating new snapshot for VM.
2022-03-19 18:44:13 (6262): Deleting stale snapshot.
2022-03-19 18:44:14 (6262): Checkpoint completed.
2022-03-19 18:59:20 (6262): Creating new snapshot for VM.
2022-03-19 18:59:30 (6262): Deleting stale snapshot.
2022-03-19 18:59:30 (6262): Checkpoint completed.
2022-03-19 19:14:35 (6262): Creating new snapshot for VM.
2022-03-19 19:14:44 (6262): Deleting stale snapshot.
2022-03-19 19:14:45 (6262): Checkpoint completed.
2022-03-19 19:28:16 (6262): Status Report: Elapsed Time: '114009.793707'
2022-03-19 19:28:16 (6262): Status Report: CPU Time: '2641.930000'
2022-03-19 19:29:49 (6262): Creating new snapshot for VM.
2022-03-19 19:29:58 (6262): Deleting stale snapshot.
2022-03-19 19:29:59 (6262): Checkpoint completed.
2022-03-19 19:45:04 (6262): Creating new snapshot for VM.
2022-03-19 19:45:14 (6262): Deleting stale snapshot.
2022-03-19 19:45:14 (6262): Checkpoint completed.
2022-03-19 20:00:18 (6262): Creating new snapshot for VM.
2022-03-19 20:00:28 (6262): Deleting stale snapshot.
2022-03-19 20:00:28 (6262): Checkpoint completed.
2022-03-19 20:15:32 (6262): Creating new snapshot for VM.
2022-03-19 20:15:42 (6262): Deleting stale snapshot.
2022-03-19 20:15:43 (6262): Checkpoint completed.
2022-03-19 20:30:48 (6262): Creating new snapshot for VM.
2022-03-19 20:30:57 (6262): Deleting stale snapshot.
2022-03-19 20:30:58 (6262): Checkpoint completed.
2022-03-19 20:46:03 (6262): Creating new snapshot for VM.
2022-03-19 20:46:13 (6262): Deleting stale snapshot.
2022-03-19 20:46:13 (6262): Checkpoint completed.
2022-03-19 21:01:17 (6262): Creating new snapshot for VM.
2022-03-19 21:01:27 (6262): Deleting stale snapshot.
2022-03-19 21:01:27 (6262): Checkpoint completed.
2022-03-19 21:07:18 (6262): Status Report: Elapsed Time: '120009.804537'
2022-03-19 21:07:18 (6262): Status Report: CPU Time: '2780.740000'
2022-03-19 21:16:33 (6262): Creating new snapshot for VM.
2022-03-19 21:16:42 (6262): Deleting stale snapshot.
2022-03-19 21:16:42 (6262): Checkpoint completed.
2022-03-19 21:31:47 (6262): Creating new snapshot for VM.
2022-03-19 21:31:56 (6262): Deleting stale snapshot.
2022-03-19 21:31:56 (6262): Checkpoint completed.
2022-03-19 21:47:02 (6262): Creating new snapshot for VM.
2022-03-19 21:47:11 (6262): Deleting stale snapshot.
2022-03-19 21:47:12 (6262): Checkpoint completed.
2022-03-19 22:02:16 (6262): Creating new snapshot for VM.
2022-03-19 22:02:25 (6262): Deleting stale snapshot.
2022-03-19 22:02:26 (6262): Checkpoint completed.
2022-03-19 22:17:30 (6262): Creating new snapshot for VM.
2022-03-19 22:17:40 (6262): Deleting stale snapshot.
2022-03-19 22:17:40 (6262): Checkpoint completed.
2022-03-19 22:32:45 (6262): Creating new snapshot for VM.
2022-03-19 22:32:54 (6262): Deleting stale snapshot.
2022-03-19 22:32:55 (6262): Checkpoint completed.
2022-03-19 22:46:20 (6262): Status Report: Elapsed Time: '126009.921324'
2022-03-19 22:46:20 (6262): Status Report: CPU Time: '2910.340000'
2022-03-19 22:48:03 (6262): Creating new snapshot for VM.
2022-03-19 22:48:13 (6262): Deleting stale snapshot.
2022-03-19 22:48:14 (6262): Checkpoint completed.
2022-03-19 23:03:24 (6262): Creating new snapshot for VM.
2022-03-19 23:03:34 (6262): Deleting stale snapshot.
2022-03-19 23:03:35 (6262): Checkpoint completed.
2022-03-19 23:18:47 (6262): Creating new snapshot for VM.
2022-03-19 23:18:57 (6262): Deleting stale snapshot.
2022-03-19 23:18:57 (6262): Checkpoint completed.
2022-03-19 23:34:23 (6262): Creating new snapshot for VM.
2022-03-19 23:34:33 (6262): Deleting stale snapshot.
2022-03-19 23:34:33 (6262): Checkpoint completed.
2022-03-19 23:49:44 (6262): Creating new snapshot for VM.
2022-03-19 23:49:54 (6262): Deleting stale snapshot.
2022-03-19 23:49:54 (6262): Checkpoint completed.
2022-03-20 00:05:06 (6262): Creating new snapshot for VM.
2022-03-20 00:05:16 (6262): Deleting stale snapshot.
2022-03-20 00:05:16 (6262): Checkpoint completed.
2022-03-20 00:20:28 (6262): Creating new snapshot for VM.
2022-03-20 00:20:38 (6262): Deleting stale snapshot.
2022-03-20 00:20:39 (6262): Checkpoint completed.
2022-03-20 00:25:42 (6262): Status Report: Elapsed Time: '132010.786012'
2022-03-20 00:25:42 (6262): Status Report: CPU Time: '3055.020000'
2022-03-20 00:35:50 (6262): Creating new snapshot for VM.
2022-03-20 00:36:00 (6262): Deleting stale snapshot.
2022-03-20 00:36:01 (6262): Checkpoint completed.
2022-03-20 00:51:11 (6262): Creating new snapshot for VM.
2022-03-20 00:51:21 (6262): Deleting stale snapshot.
2022-03-20 00:51:22 (6262): Checkpoint completed.
ID: 105580 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Profile Grant (SSSF)

Send message
Joined: 28 Mar 20
Posts: 1725
Credit: 18,417,319
RAC: 20,286
Message 105581 - Posted: 20 Mar 2022, 10:01:04 UTC - in response to Message 105577.  

He already aborted 2 and is struggling with the third.
The aborted Tasks were never even started- the third one is actually the first one to be processed.
Grant
Darwin NT
ID: 105581 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
kotenok2000
Avatar

Send message
Joined: 22 Feb 11
Posts: 272
Credit: 507,897
RAC: 274
Message 105582 - Posted: 20 Mar 2022, 10:04:32 UTC - in response to Message 105581.  

Open virtualbox gui and show what the vm shows on screen.
ID: 105582 · 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 105583 - Posted: 20 Mar 2022, 10:28:11 UTC
Last modified: 20 Mar 2022, 10:42:06 UTC

What task is that?

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.

2022-03-19 00:24:07 (5380): VM state change detected. (old = 'running', new = 'paused')
2022-03-19 00:24:34 (5380): Powering off VM.
2022-03-19 00:24:34 (5380): Successfully stopped VM.
2022-03-19 09:54:01 (8908): Detected: vboxwrapper 26202
2022-03-19 09:54:01 (8908): Detected: BOINC client v7.16.20
2022-03-19 09:54:02 (8908): Detected: VirtualBox VboxManage Interface (Version: 6.1.32)
2022-03-19 09:54:03 (8908): Feature: Checkpoint interval offset (533 seconds)
2022-03-19 09:54:03 (8908): Detected: Minimum checkpoint interval (600.000000 seconds)
2022-03-19 09:54:03 (8908): Guest Log: BIOS: VirtualBox 6.1.32
2022-03-19 09:54:03 (8908): Guest Log: CPUID EDX: 0x178bfbff
2022-03-19 09:54:03 (8908): Guest Log: BIOS: ata0-0: PCHS=16383/16/63 LCHS=1024/255/63
2022-03-19 09:54:03 (8908): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032
2022-03-19 09:54:03 (8908): Guest Log: BIOS: Booting from Hard Disk...
2022-03-19 09:54:03 (8908): Guest Log: vgdrvHeartbeatInit: Setting up heartbeat to trigger every 2000 milliseconds
2022-03-19 09:54:03 (8908): Guest Log: vboxguest: misc device minor 58, IRQ 20, I/O port d020, MMIO at 00000000f0400000 (size 0x400000)
2022-03-19 09:54:03 (8908): Guest Log: VBoxService 5.2.42 r137960 (verbosity: 0) linux.amd64 (May 13 2020 21:45:13) release log
2022-03-19 09:54:03 (8908): Guest Log: 00:00:00.000313 main Log opened 2022-03-18T22:00:54.742980000Z
2022-03-19 09:54:03 (8908): Guest Log: 00:00:00.000421 main OS Product: Linux
2022-03-19 09:54:03 (8908): Guest Log: 00:00:00.000476 main OS Release: 4.19.0-14-amd64
2022-03-19 09:54:03 (8908): Guest Log: 00:00:00.000505 main OS Version: #1 SMP Debian 4.19.171-2 (2021-01-30)
2022-03-19 09:54:03 (8908): Guest Log: 00:00:00.000536 main Executable: /opt/VBoxGuestAdditions-5.2.42/sbin/VBoxService
2022-03-19 09:54:03 (8908): Guest Log: 00:00:00.000537 main Process ID: 540
2022-03-19 09:54:03 (8908): Guest Log: 00:00:00.000537 main Package type: LINUX_64BITS_GENERIC
2022-03-19 09:54:03 (8908): Guest Log: 00:00:00.002038 main 5.2.42 r137960 started. Verbose level = 0
2022-03-19 09:54:03 (8908): Guest Log: 00:00:10.015594 timesync vgsvcTimeSyncWorker: Radical guest time change: -3 588 659 421 000ns (GuestNow=1 647 637 266 096 888 000 ns GuestLast=1 647 640 854 756 309 000 ns fSetTimeLastLoop=true )
2022-03-19 09:54:03 (8908): Restore from previously saved snapshot.
2022-03-19 09:54:03 (8908): Restore completed.
2022-03-19 09:54:03 (8908): Starting VM using VBoxManage interface. (boinc_7f4f3cd2cadd12f2, slot#8)
2022-03-19 09:54:12 (8908): Successfully started VM. (PID = '15224')
2022-03-19 09:54:12 (8908): Reporting VM Process ID to BOINC.
2022-03-19 09:54:12 (8908): VM state change detected. (old = 'poweredoff', new = 'running')
2022-03-19 09:54:12 (8908): Status Report: Elapsed Time: '8131.306395'
2022-03-19 09:54:12 (8908): Status Report: CPU Time: '8386.953125'
2022-03-19 09:54:12 (8908): Preference change detected
2022-03-19 09:54:12 (8908): Setting CPU throttle for VM. (98%)
2022-03-19 09:54:12 (8908): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2022-03-19 09:54:18 (8908): Guest Log: 02:19:40.428489 timesync vgsvcTimeSyncWorker: Radical host time change: 34 342 910 000 000ns (HostNow=1 647 680 057 820 000 000 ns HostLast=1 647 645 714 910 000 000 ns)
2022-03-19 09:54:28 (8908): Guest Log: 02:19:50.428917 timesync vgsvcTimeSyncWorker: Radical guest time change: 34 431 310 621 000ns (GuestNow=1 647 680 067 820 439 000 ns GuestLast=1 647 645 636 509 818 000 ns fSetTimeLastLoop=true )

Radical host time change.
What is going on?
Because now the task is running at only 21% of CPU core, but growing only .001% per 2 seconds (Boinc tasks)

2022-03-19 11:35:07 (8908): Status Report: Elapsed Time: '14131.394492'
2022-03-19 11:35:07 (8908): Status Report: CPU Time: '12873.968750'

2022-03-19 13:16:05 (8908): Status Report: Elapsed Time: '20132.371849'
2022-03-19 13:16:05 (8908): Status Report: CPU Time: '13008.515625'

2022-03-19 16:42:44 (8908): Status Report: Elapsed Time: '32133.506234'
2022-03-19 16:42:44 (8908): Status Report: CPU Time: '13207.640625'

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 )

And again this radical host time change

And now off by 30,000 seconds
2022-03-19 21:12:30 (8908): Status Report: Elapsed Time: '44134.865454'
2022-03-19 21:12:30 (8908): Status Report: CPU Time: '13374.765625'

Now its getting stupid:
022-03-19 22:54:16 (8908): Status Report: Elapsed Time: '50135.530892'
2022-03-19 22:54:16 (8908): Status Report: CPU Time: '13458.546875'

Shutdown #2 for the night and restart
2022-03-20 00:36:51 (8908): Status Report: Elapsed Time: '56136.291916'
2022-03-20 00:36:51 (8908): Status Report: CPU Time: '13537.859375'
2022-03-20 00:40:36 (8908): VM state change detected. (old = 'running', new = 'paused')
2022-03-20 00:40:40 (8908): Powering off VM.
2022-03-20 00:40:40 (8908): Successfully stopped VM.
2022-03-20 09:19:38 (14368): Detected: vboxwrapper 26202
2022-03-20 09:19:38 (14368): Detected: BOINC client v7.16.20
2022-03-20 09:19:40 (14368): Detected: VirtualBox VboxManage Interface (Version: 6.1.32)
2022-03-20 09:19:40 (14368): Feature: Checkpoint interval offset (259 seconds)
2022-03-20 09:19:40 (14368): Detected: Minimum checkpoint interval (600.000000 seconds)
2022-03-20 09:19:40 (14368): Guest Log: 02:19:40.428489 timesync vgsvcTimeSyncWorker: Radical host time change: 34 342 910 000 000ns (HostNow=1 647 680 057 820 000 000 ns HostLast=1 647 645 714 910 000 000 ns)
2022-03-20 09:19:40 (14368): Guest Log: 02:19:50.428917 timesync vgsvcTimeSyncWorker: Radical guest time change: 34 431 310 621 000ns (GuestNow=1 647 680 067 820 439 000 ns GuestLast=1 647 645 636 509 818 000 ns fSetTimeLastLoop=true )
2022-03-20 09:19:40 (14368): 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-20 09:19:40 (14368): 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 )
2022-03-20 09:19:40 (14368): Restore from previously saved snapshot.
2022-03-20 09:19:40 (14368): Restore completed.
2022-03-20 09:19:40 (14368): Starting VM using VBoxManage interface. (boinc_7f4f3cd2cadd12f2, slot#8)
2022-03-20 09:19:50 (14368): Successfully started VM. (PID = '7968')
2022-03-20 09:19:50 (14368): Reporting VM Process ID to BOINC.
2022-03-20 09:19:50 (14368): VM state change detected. (old = 'poweredoff', new = 'running')
2022-03-20 09:19:50 (14368): Status Report: Elapsed Time: '56107.412793'
2022-03-20 09:19:50 (14368): Status Report: CPU Time: '13529.968750'
2022-03-20 09:19:50 (14368): Preference change detected
2022-03-20 09:19:50 (14368): Setting CPU throttle for VM. (98%)
2022-03-20 09:19:50 (14368): Setting checkpoint interval to 600 seconds. (Higher value of (Preference: 60 seconds) or (Vbox_job.xml: 600 seconds))
2022-03-20 09:19:54 (14368): Guest Log: 15:43:47.080401 timesync vgsvcTimeSyncWorker: Radical host time change: 31 416 803 000 000ns (HostNow=1 647 764 393 807 000 000 ns HostLast=1 647 732 977 004 000 000 ns)
2022-03-20 09:20:04 (14368): Guest Log: 15:43:57.081570 timesync vgsvcTimeSyncWorker: Radical guest time change: 31 599 661 821 000ns (GuestNow=1 647 764 403 808 204 000 ns GuestLast=1 647 732 804 146 383 000 ns fSetTimeLastLoop=true )

Now its hopeless:
2022-03-20 11:01:15 (14368): Status Report: Elapsed Time: '62108.028191'
2022-03-20 11:01:15 (14368): Status Report: CPU Time: '13609.671875'

-Aborted-
ID: 105583 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
stratos412

Send message
Joined: 18 Mar 20
Posts: 12
Credit: 161,224
RAC: 152
Message 105586 - Posted: 20 Mar 2022, 12:04:33 UTC - in response to Message 105582.  
Last modified: 20 Mar 2022, 12:05:26 UTC

@kotenok2000

VIRTUALBOX

https://drive.google.com/file/d/1-mdLfOKK6Vs3u1RtCyHwHB2s4Sj37uKO/view?usp=sharing


Does it worth to keep it running?
I will restart my PC to see wht's going on...
ID: 105586 · 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 105588 - Posted: 20 Mar 2022, 14:22:08 UTC - in response to Message 105572.  

At this rate, it might be finished by this afternoon, or perhaps tomorrow. I tried suspending all the other non-python tasks to free up CPU cycles but that made no difference. I think when this is finished I'm going to uninstall vbox. BTW this is running on a laptop, but a one year old fairly high-end one. (10th gen Core I5 processor, 16GB RAM, NVDIA GPU, and a SSD)
Application
rosetta python projects 1.03 (vbox64)
Name
aagb-mNMPHE_pp-PPS-GPN-mLARD_pp_12_2631200_3
State
Running
Received
3/15/2022 12:27:54 AM
Report deadline
3/18/2022 12:27:54 AM
Estimated computation size
80,000 GFLOPs
CPU time
06:32:05
CPU time since checkpoint
---
Elapsed time
4d 00:20:03
Estimated time remaining
00:00:02
Fraction done
99.999%
Virtual memory size
6.18 MB
Working set size
2.79 GB
Directory
slots/5
Process ID
14696
Progress rate
1.080% per hour
Executable
vboxwrapper_26203_windows_x86_64.exe

ID: 105588 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Ron

Send message
Joined: 17 Feb 22
Posts: 1
Credit: 310,495
RAC: 170
Message 105589 - Posted: 20 Mar 2022, 14:30:32 UTC

Hello,

I am new to Rosetta, but not to Boinc projects.

Below is a copy of my project properties. Why are there so many failed tasks? And can I do anything about it?

Thanks,
Ron.
Email: ronlowe53@outlook.com

General
URL
https://boinc.bakerlab.org/rosetta/
User name
Ron
Team name
Resource share
100
Disk usage
1.59 GB
Computer ID
6179325
Suspended via GUI
no
Don't request tasks
no
Host location
default
Tasks completed
37
Tasks failed
364
Credit
User
10,257 total, 216.33 average
Host
10,257 total, 216.33 average
Scheduling
Scheduling priority
-1.01
CPU task request deferred for
00:14:58
CPU task request deferral interval
00:40:00
Don't request tasks for Intel GPU
Project has no apps for Intel GPU
Last scheduler reply
20/03/2022 14:03:12
ID: 105589 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
kotenok2000
Avatar

Send message
Joined: 22 Feb 11
Posts: 272
Credit: 507,897
RAC: 274
Message 105590 - Posted: 20 Mar 2022, 14:36:28 UTC - in response to Message 105589.  

It seems Someone has made incorrect workunits and sent them to the system without testing.
ID: 105590 · 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 105593 - Posted: 20 Mar 2022, 17:16:30 UTC - in response to Message 105572.  

If you have a task you think is stalled, best to click on it and select properties on the left.
If there's a large difference between CPU time and Elapsed time, then it's stalled and you can only abort it.

In my 5+ days away I returned to a couple of tasks that'd been running 2 and 3 days respectively. Both had much-reduced CPU time - just a couple of hours.

See one's output here
aagb-ACHC-mPHE-GPN-ACHC12C_10_2578961_3_0
Run time 3 days 15 hours 28 min 42 sec
CPU time 2 hours 4 min 4 sec

Typically, if later tasks are completing before earlier tasks, check properties of those earlier tasks and abort them if necessary.
A much better method than checking in Task Manager - I find this method best, so give it a try.

Every post since I sent this last night can most easily be resolved by reading this (probably for the first time)
ID: 105593 · 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 105594 - Posted: 20 Mar 2022, 18:07:20 UTC - in response to Message 105593.  

Looks like aagb sequence has problems.
You have one and I have one.
I think the other guy who is stalled probably got one.
ID: 105594 · Rating: 0 · rate: Rate + / Rate - Report as offensive    Reply Quote
Previous · 1 . . . 191 · 192 · 193 · 194 · 195 · 196 · 197 . . . 309 · Next

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



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