Message boards : ATLAS application : Slower than a snail sleeping task
Message board moderation

To post messages, you must log in.

AuthorMessage
greg_be

Send message
Joined: 28 Dec 08
Posts: 204
Credit: 1,334,265
RAC: 2,007
Message 41063 - Posted: 24 Dec 2019, 21:20:49 UTC

This is nuts...look at the completion rate!
You'll have to read through the text to see what I mean.
Here is one out take:
2019-12-24 18:54:15 (2752): Status Report: Elapsed Time: '151302.555752'
2019-12-24 18:54:15 (2752): Status Report: CPU Time: '8.453125'
2019-12-24 20:34:21 (2752): Status Report: Elapsed Time: '157302.555752'
2019-12-24 20:34:21 (2752): Status Report: CPU Time: '8.484375'

.03 seconds of CPU time in 2 hrs? Whats going on?
In 30 seconds of real clock time the task moved only .00010%
This is absurd!
I'll let it run into Christmas day. But if it is not done by 8-9am its being aborted, which is a shame. But I do have other work waiting.
Also going to try a 4 core script that was mentioned in another thread I created. I am currently running 8 cores.
---------------------------------------------------------

2019-12-22 00:59:10 (21808): Detected: vboxwrapper 26197
2019-12-22 00:59:10 (21808): Detected: BOINC client v7.7
2019-12-22 00:59:11 (21808): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2019-12-22 00:59:12 (21808): Successfully copied 'init_data.xml' to the shared directory.
2019-12-22 00:59:13 (21808): Create VM. (boinc_4d36eee313f98af0, slot#7)
2019-12-22 00:59:14 (21808): Setting Memory Size for VM. (4252MB)
2019-12-22 00:59:14 (21808): Setting CPU Count for VM. (1)
2019-12-22 00:59:15 (21808): Setting Chipset Options for VM.
2019-12-22 00:59:15 (21808): Setting Boot Options for VM.
2019-12-22 00:59:16 (21808): Setting Network Configuration for NAT.
2019-12-22 00:59:16 (21808): Enabling VM Network Access.
2019-12-22 00:59:17 (21808): Disabling USB Support for VM.
2019-12-22 00:59:17 (21808): Disabling COM Port Support for VM.
2019-12-22 00:59:18 (21808): Disabling LPT Port Support for VM.
2019-12-22 00:59:18 (21808): Disabling Audio Support for VM.
2019-12-22 00:59:19 (21808): Disabling Clipboard Support for VM.
2019-12-22 00:59:19 (21808): Disabling Drag and Drop Support for VM.
2019-12-22 00:59:19 (21808): Adding storage controller(s) to VM.
2019-12-22 00:59:20 (21808): Adding virtual disk drive to VM. (vm_image.vdi)
2019-12-22 00:59:54 (21808): Error in storage attach (fixed disk) for VM: -2135228409
Command:
VBoxManage -q storageattach "boinc_4d36eee313f98af0" --storagectl "Hard Disk Controller" --port 0 --device 0 --type hdd --setuuid "" --medium "C:\boinc data\slots\7/vm_image.vdi"
Output:
VBoxManage.exe: error: Medium 'C:\boinc data\slots\7\vm_image.vdi' is not accessible. UUID {5e2342bb-76a4-44ff-81f6-2f3283cde68f} of the medium 'C:\boinc data\slots\7\vm_image.vdi' does not match the value {a7f10cc1-6018-4ac8-8058-fd19abdd51b8} stored in the media registry ('C:\Users\Greg\.VirtualBox\VirtualBox.xml')
VBoxManage.exe: error: Details: code VBOX_E_INVALID_OBJECT_STATE (0x80bb0007), component MediumWrap, interface IMedium, callee IUnknown
VBoxManage.exe: error: Context: "SetIds(fSetNewUuid, bstrNewUuid.raw(), fSetNewParentUuid, bstrNewParentUuid.raw())" at line 694 of file VBoxManageStorageController.cpp
VBoxManage.exe: error: Failed to set the medium/parent medium UUID

Notes:

Another VirtualBox management application has locked the session for
this VM. BOINC cannot properly monitor this VM
and so this job will be aborted.


2019-12-22 00:59:54 (21808): Could not create VM
2019-12-22 00:59:54 (21808): ERROR: VM failed to start
2019-12-22 00:59:59 (21808):
NOTE: VM session lock error encountered.
BOINC will be notified that it needs to clean up the environment.
This might be a temporary problem and so this job will be rescheduled for another time.

2019-12-22 09:50:38 (17324): Detected: vboxwrapper 26197
2019-12-22 09:50:38 (17324): Detected: BOINC client v7.7
2019-12-22 09:50:39 (17324): Detected: VirtualBox VboxManage Interface (Version: 6.0.14)
2019-12-22 09:50:39 (17324): Starting VM using VBoxManage interface. (boinc_4d36eee313f98af0, slot#7)
2019-12-22 09:50:44 (17324): Successfully started VM. (PID = '22956')
2019-12-22 09:50:44 (17324): Reporting VM Process ID to BOINC.
2019-12-22 09:50:44 (17324): Guest Log: BIOS: VirtualBox 6.0.14

2019-12-22 09:50:44 (17324): Guest Log: CPUID EDX: 0x178bfbff

2019-12-22 09:50:44 (17324): VM state change detected. (old = 'PoweredOff', new = 'Running')
2019-12-22 09:50:44 (17324): Preference change detected
2019-12-22 09:50:44 (17324): Setting CPU throttle for VM. (92%)
2019-12-22 09:50:46 (17324): Setting checkpoint interval to 900 seconds. (Higher value of (Preference: 180 seconds) or (Vbox_job.xml: 900 seconds))
2019-12-22 09:50:46 (17324): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032

2019-12-22 09:50:46 (17324): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=80

2019-12-22 09:50:46 (17324): Guest Log: BIOS: Boot from Hard Disk 0 failed

2019-12-22 09:50:46 (17324): Guest Log: BIOS: Boot : bseqnr=2, bootseq=0003

2019-12-22 09:50:46 (17324): Guest Log: BIOS: CDROM boot failure code : 0002

2019-12-22 09:50:46 (17324): Guest Log: BIOS: Boot from CD-ROM failed

2019-12-22 09:50:46 (17324): Guest Log: Could not read from the boot medium! System halted.

2019-12-22 09:52:38 (17324): VM state change detected. (old = 'Running', new = 'Paused')
2019-12-22 09:52:42 (17324): Stopping VM.
2019-12-22 10:00:55 (11808): Detected: vboxwrapper 26197
2019-12-22 10:00:55 (11808): Detected: BOINC client v7.7
2019-12-22 10:00:55 (11808): Detected: VirtualBox VboxManage Interface (Version: 6.1.0)
2019-12-22 10:00:56 (11808): Starting VM using VBoxManage interface. (boinc_4d36eee313f98af0, slot#7)
2019-12-22 10:01:03 (11808): Successfully started VM. (PID = '10652')
2019-12-22 10:01:03 (11808): Reporting VM Process ID to BOINC.
2019-12-22 10:01:03 (11808): VM state change detected. (old = 'PoweredOff', new = 'Running')
2019-12-22 10:01:03 (11808): Preference change detected
2019-12-22 10:01:03 (11808): Setting CPU throttle for VM. (92%)
2019-12-22 10:01:03 (11808): Setting checkpoint interval to 900 seconds. (Higher value of (Preference: 180 seconds) or (Vbox_job.xml: 900 seconds))
2019-12-22 11:54:48 (11808): Status Report: Elapsed Time: '6000.130892'
2019-12-22 11:54:48 (11808): Status Report: CPU Time: '3.609375'
2019-12-22 13:41:42 (11808): Status Report: Elapsed Time: '12000.130892'
2019-12-22 13:41:42 (11808): Status Report: CPU Time: '3.656250'
2019-12-22 15:27:38 (11808): Status Report: Elapsed Time: '18000.130892'
2019-12-22 15:27:38 (11808): Status Report: CPU Time: '3.828125'
2019-12-22 17:12:31 (11808): Status Report: Elapsed Time: '24000.130892'
2019-12-22 17:12:31 (11808): Status Report: CPU Time: '3.828125'
2019-12-22 18:55:01 (11808): Status Report: Elapsed Time: '30000.130892'
2019-12-22 18:55:01 (11808): Status Report: CPU Time: '3.906250'
2019-12-22 20:36:06 (11808): Status Report: Elapsed Time: '36000.130892'
2019-12-22 20:36:06 (11808): Status Report: CPU Time: '4.093750'
2019-12-22 22:16:51 (11808): Status Report: Elapsed Time: '42000.130892'
2019-12-22 22:16:51 (11808): Status Report: CPU Time: '4.296875'
2019-12-22 23:57:50 (11808): Status Report: Elapsed Time: '48000.130892'
2019-12-22 23:57:50 (11808): Status Report: CPU Time: '4.421875'
2019-12-23 01:39:15 (11808): Status Report: Elapsed Time: '54000.130892'
2019-12-23 01:39:15 (11808): Status Report: CPU Time: '4.625000'
2019-12-23 03:20:23 (11808): Status Report: Elapsed Time: '60000.130892'
2019-12-23 03:20:23 (11808): Status Report: CPU Time: '4.781250'
2019-12-23 05:01:31 (11808): Status Report: Elapsed Time: '66000.130892'
2019-12-23 05:01:31 (11808): Status Report: CPU Time: '5.015625'
2019-12-23 06:42:39 (11808): Status Report: Elapsed Time: '72000.130892'
2019-12-23 06:42:39 (11808): Status Report: CPU Time: '5.234375'
2019-12-23 08:23:45 (11808): Status Report: Elapsed Time: '78000.130892'
2019-12-23 08:23:45 (11808): Status Report: CPU Time: '5.390625'
2019-12-23 10:04:56 (11808): Status Report: Elapsed Time: '84000.130892'
2019-12-23 10:04:56 (11808): Status Report: CPU Time: '5.640625'
2019-12-23 11:46:07 (11808): Status Report: Elapsed Time: '90000.130892'
2019-12-23 11:46:07 (11808): Status Report: CPU Time: '5.796875'
2019-12-23 13:27:14 (11808): Status Report: Elapsed Time: '96000.130892'
2019-12-23 13:27:14 (11808): Status Report: CPU Time: '6.000000'
2019-12-23 15:09:20 (11808): Status Report: Elapsed Time: '102000.130892'
2019-12-23 15:09:20 (11808): Status Report: CPU Time: '6.218750'
2019-12-23 15:32:01 (11808): VM state change detected. (old = 'Running', new = 'Paused')
2019-12-23 15:36:42 (11808): VM state change detected. (old = 'Paused', new = 'Running')
2019-12-23 17:05:37 (11808): Status Report: Elapsed Time: '108000.423361'
2019-12-23 17:05:37 (11808): Status Report: CPU Time: '6.500000'
2019-12-23 18:58:34 (11808): Status Report: Elapsed Time: '114000.871103'
2019-12-23 18:58:34 (11808): Status Report: CPU Time: '6.531250'
2019-12-23 20:46:53 (11808): Status Report: Elapsed Time: '120000.871103'
2019-12-23 20:46:53 (11808): Status Report: CPU Time: '6.531250'
2019-12-23 22:28:57 (11808): Status Report: Elapsed Time: '126000.871103'
2019-12-23 22:28:57 (11808): Status Report: CPU Time: '6.531250'
2019-12-24 11:23:35 (2752): Detected: vboxwrapper 26197
2019-12-24 11:23:35 (2752): Detected: BOINC client v7.7
2019-12-24 11:23:37 (2752): Detected: VirtualBox VboxManage Interface (Version: 6.1.0)
2019-12-24 11:23:38 (2752): Starting VM using VBoxManage interface. (boinc_4d36eee313f98af0, slot#7)
2019-12-24 11:23:44 (2752): Successfully started VM. (PID = '17992')
2019-12-24 11:23:44 (2752): Reporting VM Process ID to BOINC.
2019-12-24 11:23:44 (2752): Guest Log: BIOS: VirtualBox 6.1.0

2019-12-24 11:23:44 (2752): Guest Log: CPUID EDX: 0x178bfbff

2019-12-24 11:23:44 (2752): VM state change detected. (old = 'PoweredOff', new = 'Running')
2019-12-24 11:23:44 (2752): Status Report: Elapsed Time: '127301.871103'
2019-12-24 11:23:44 (2752): Status Report: CPU Time: '6.531250'
2019-12-24 11:23:44 (2752): Preference change detected
2019-12-24 11:23:44 (2752): Setting CPU throttle for VM. (90%)
2019-12-24 11:23:45 (2752): Setting checkpoint interval to 900 seconds. (Higher value of (Preference: 180 seconds) or (Vbox_job.xml: 900 seconds))
2019-12-24 11:23:45 (2752): Guest Log: BIOS: Boot : bseqnr=1, bootseq=0032

2019-12-24 11:23:45 (2752): Guest Log: int13_harddisk: function 02, unmapped device for ELDL=80

2019-12-24 11:23:45 (2752): Guest Log: BIOS: Boot from Hard Disk 0 failed

2019-12-24 11:23:45 (2752): Guest Log: BIOS: Boot : bseqnr=2, bootseq=0003

2019-12-24 11:23:45 (2752): Guest Log: BIOS: CDROM boot failure code : 0002

2019-12-24 11:23:45 (2752): Guest Log: BIOS: Boot from CD-ROM failed

2019-12-24 11:23:45 (2752): Guest Log: Could not read from the boot medium! System halted.

2019-12-24 13:15:11 (2752): Status Report: Elapsed Time: '133301.871103'
2019-12-24 13:15:11 (2752): Status Report: CPU Time: '8.328125'
2019-12-24 15:14:27 (2752): Status Report: Elapsed Time: '139302.555752'
2019-12-24 15:14:27 (2752): Status Report: CPU Time: '8.375000'
2019-12-24 17:07:45 (2752): Status Report: Elapsed Time: '145302.555752'
2019-12-24 17:07:45 (2752): Status Report: CPU Time: '8.390625'
2019-12-24 18:54:15 (2752): Status Report: Elapsed Time: '151302.555752'
2019-12-24 18:54:15 (2752): Status Report: CPU Time: '8.453125'
2019-12-24 20:34:21 (2752): Status Report: Elapsed Time: '157302.555752'
2019-12-24 20:34:21 (2752): Status Report: CPU Time: '8.484375'
2019-12-24 21:31:28 (2752): Preference change detected
2019-12-24 21:31:28 (2752): Setting CPU throttle for VM. (98%)
2019-12-24 21:31:28 (2752): Setting checkpoint interval to 900 seconds. (Higher value of (Preference: 180 seconds) or (Vbox_job.xml: 900 seconds))
ID: 41063 · Report as offensive     Reply Quote
greg_be

Send message
Joined: 28 Dec 08
Posts: 204
Credit: 1,334,265
RAC: 2,007
Message 41065 - Posted: 25 Dec 2019, 1:15:43 UTC

2019-12-24 22:14:53 (2752): Status Report: Elapsed Time: '163302.555752'
2019-12-24 22:14:53 (2752): Status Report: CPU Time: '8.484375'
2019-12-24 23:57:04 (2752): Status Report: Elapsed Time: '169303.240511'
2019-12-24 23:57:04 (2752): Status Report: CPU Time: '8.484375'
2019-12-25 00:04:25 (2752): VM state change detected. (old = 'Running', new = 'Paused')


**Task Aborted at 99.99350%* Run time in 8hr segments 1 day 20hrs etc.
Went from a estimated 14 seconds completion time to 10 seconds completion time and at a rate of .00010% every 30 seconds its going to take another day to complete which is nonsense.
ID: 41065 · Report as offensive     Reply Quote
maeax

Send message
Joined: 2 May 07
Posts: 884
Credit: 32,833,132
RAC: 45,329
Message 41066 - Posted: 25 Dec 2019, 1:55:54 UTC

You run too many tasks for not enough memory.
Reduce your tasks. For example only sixtrack (Prefs).
Atlas need more than 4 GByte RAM with only one CPU!
You have "only" 24 GByte and so many Atlas tasks running (Also Theory, sixtrack). This is not possible.
Test it with one Atlas task only. Yeti's Checklist is a good help.
ID: 41066 · Report as offensive     Reply Quote
greg_be

Send message
Joined: 28 Dec 08
Posts: 204
Credit: 1,334,265
RAC: 2,007
Message 41082 - Posted: 26 Dec 2019, 19:11:50 UTC - in response to Message 41066.  

You run too many tasks for not enough memory.
Reduce your tasks. For example only sixtrack (Prefs).
Atlas need more than 4 GByte RAM with only one CPU!
You have "only" 24 GByte and so many Atlas tasks running (Also Theory, sixtrack). This is not possible.
Test it with one Atlas task only. Yeti's Checklist is a good help.


Things are better now. Quit CPU FAH tasks. Left their GPU function in place.
I was also overheating my radiator even with the best fans.
I think FAH CPU was causing the troubles.
Things are better now that I quit that.
ID: 41082 · Report as offensive     Reply Quote

Message boards : ATLAS application : Slower than a snail sleeping task


©2020 CERN