Message boards : Number crunching : Problems and Technical Issues with Rosetta@home
Previous · 1 . . . 192 · 193 · 194 · 195 · 196 · 197 · 198 . . . 300 · Next
Author | Message |
---|---|
Greg_BE Send message Joined: 30 May 06 Posts: 5691 Credit: 5,859,226 RAC: 0 |
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- |
stratos412 Send message Joined: 18 Mar 20 Posts: 12 Credit: 153,595 RAC: 158 |
@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... |
zxcvbob Send message Joined: 4 Jan 06 Posts: 8 Credit: 830,878 RAC: 0 |
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 |
Ron Send message Joined: 17 Feb 22 Posts: 1 Credit: 304,233 RAC: 50 |
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 |
kotenok2000 Send message Joined: 22 Feb 11 Posts: 258 Credit: 483,503 RAC: 133 |
It seems Someone has made incorrect workunits and sent them to the system without testing. |
Sid Celery Send message Joined: 11 Feb 08 Posts: 2117 Credit: 41,146,905 RAC: 16,321 |
If you have a task you think is stalled, best to click on it and select properties on the left. Every post since I sent this last night can most easily be resolved by reading this (probably for the first time) |
Greg_BE Send message Joined: 30 May 06 Posts: 5691 Credit: 5,859,226 RAC: 0 |
Looks like aagb sequence has problems. You have one and I have one. I think the other guy who is stalled probably got one. |
Greg_BE Send message Joined: 30 May 06 Posts: 5691 Credit: 5,859,226 RAC: 0 |
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 |
Greg_BE Send message Joined: 30 May 06 Posts: 5691 Credit: 5,859,226 RAC: 0 |
zxcvbob - check and see if the task begins with aagb- If it is, just abort it. It's got bugs. |
Greg_BE Send message Joined: 30 May 06 Posts: 5691 Credit: 5,859,226 RAC: 0 |
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. |
Sid Celery Send message Joined: 11 Feb 08 Posts: 2117 Credit: 41,146,905 RAC: 16,321 |
Looks like aagb sequence has problems. 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 |
Sid Celery Send message Joined: 11 Feb 08 Posts: 2117 Credit: 41,146,905 RAC: 16,321 |
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. |
Mr P Hucker Send message Joined: 12 Aug 06 Posts: 1600 Credit: 11,717,270 RAC: 11,974 |
Did anyone come to a conclusion on my stderr outputs? |
Greg_BE Send message Joined: 30 May 06 Posts: 5691 Credit: 5,859,226 RAC: 0 |
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. |
Greg_BE Send message Joined: 30 May 06 Posts: 5691 Credit: 5,859,226 RAC: 0 |
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. |
Mr P Hucker Send message Joined: 12 Aug 06 Posts: 1600 Credit: 11,717,270 RAC: 11,974 |
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') |
Sid Celery Send message Joined: 11 Feb 08 Posts: 2117 Credit: 41,146,905 RAC: 16,321 |
One other thing I decided to do the other day on my one PC that runs Python tasks, which may help someone else. 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 |
Sid Celery Send message Joined: 11 Feb 08 Posts: 2117 Credit: 41,146,905 RAC: 16,321 |
This is a bad computer after having run a Python for 1 day 5 hours, with CPU usage at 16 minutes: 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. |
Mr P Hucker Send message Joined: 12 Aug 06 Posts: 1600 Credit: 11,717,270 RAC: 11,974 |
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.What made yours download that file again? I only get that when I attach the project. |
Mr P Hucker Send message Joined: 12 Aug 06 Posts: 1600 Credit: 11,717,270 RAC: 11,974 |
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%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. |
Message boards :
Number crunching :
Problems and Technical Issues with Rosetta@home
©2024 University of Washington
https://www.bakerlab.org