runsolver Copyright (C) 2010 Olivier ROUSSEL

This is runsolver version 3.2.9a (svn: 651)

This program is distributed in the hope that it will be useful,
but WITHOUT ANY WARRANTY; without even the implied warranty of
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
GNU General Public License for more details.

command line: /home/misc2010/bin/runsolver -s SIGUSR1 -M 1124 -C 290 -d 10 -w /home/misc2010/tmp/201108300820/aspcud-1.5/e69a0e36-9ef1-11df-9d4a-00163e46d37a.cudf.dudf-real.log.runsolver ./aspcud-1.5 /home/misc2010/data/2011/dudf-real//e69a0e36-9ef1-11df-9d4a-00163e46d37a.cudf /home/misc2010/tmp/201108300820/aspcud-1.5/e69a0e36-9ef1-11df-9d4a-00163e46d37a.cudf.dudf-real.result +sum(installedsize) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 290 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 320 seconds
Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB
Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB
Current StackSize limit: 8192 KiB


[startup+0 s]
/proc/loadavg: 0.91 0.98 0.99 3/38 17978
/proc/meminfo: memFree=934824/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=0
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 1517 0 0 0 0 0 0 25 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=2600 CPUtime=0
/proc/17976/stat : 17976 (aspcud-1.5) R 17968 17968 2160 34817 2160 4202560 111 0 0 0 0 0 0 0 25 0 1 0 59309764 2662400 132 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 0 6 1132494585 0 0 0 17 0 0 0 0
/proc/17976/statm: 650 132 83 194 0 37 0
[pid=17977] ppid=17968 vsize=2600 CPUtime=0
/proc/17977/stat : 17977 (aspcud-1.5) R 17968 17968 2160 34817 2160 4202560 111 0 0 0 0 0 0 0 25 0 1 0 59309764 2662400 132 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 0 6 1132494585 0 0 0 17 0 0 0 0
/proc/17977/statm: 650 132 83 194 0 37 0
[pid=17978] ppid=17968 vsize=2600 CPUtime=0
/proc/17978/stat : 17978 (aspcud-1.5) D 17968 17968 2160 34817 2160 4202560 110 0 0 0 0 0 0 0 25 0 1 0 59309764 2662400 131 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 0 6 1132494585 18446744071564252162 0 0 17 0 0 0 0
/proc/17978/statm: 650 131 82 194 0 37 0

[startup+0.183098 s]
/proc/loadavg: 0.91 0.98 0.99 3/38 17978
/proc/meminfo: memFree=934824/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=0
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 1517 0 0 0 0 0 0 25 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=1920 CPUtime=0
/proc/17976/stat : 17976 (clasp) D 17968 17968 2160 34817 2160 4202496 162 0 11 0 0 0 0 0 24 0 1 0 59309764 1966080 41 1283457024 134512640 136285277 4289853712 18446744073709551615 135139632 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/17976/statm: 480 41 32 433 0 45 0
[pid=17977] ppid=17968 vsize=2576 CPUtime=0
/proc/17977/stat : 17977 (gringo) D 17968 17968 2160 34817 2160 4202496 159 0 8 0 0 0 0 0 24 0 1 0 59309764 2637824 35 1283457024 134512640 136933539 4293606992 18446744073709551615 136441108 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/17977/statm: 644 35 26 592 0 49 0
[pid=17978] ppid=17968 vsize=1432 CPUtime=0
/proc/17978/stat : 17978 (cudf2lp) D 17968 17968 2160 34817 2160 4202496 163 0 9 0 0 0 0 0 24 0 1 0 59309764 1466368 40 1283457024 134512640 135786343 4290250528 18446744073709551615 134792368 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/17978/statm: 358 40 30 311 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 8528

[startup+0.207116 s]
/proc/loadavg: 0.91 0.98 0.99 3/38 17978
/proc/meminfo: memFree=934824/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=0
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 1517 0 0 0 0 0 0 25 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=1920 CPUtime=0
/proc/17976/stat : 17976 (clasp) D 17968 17968 2160 34817 2160 4202496 162 0 11 0 0 0 0 0 24 0 1 0 59309764 1966080 41 1283457024 134512640 136285277 4289853712 18446744073709551615 135139632 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/17976/statm: 480 41 32 433 0 45 0
[pid=17977] ppid=17968 vsize=2576 CPUtime=0
/proc/17977/stat : 17977 (gringo) D 17968 17968 2160 34817 2160 4202496 166 0 11 0 0 0 0 0 24 0 1 0 59309764 2637824 45 1283457024 134512640 136933539 4293606992 18446744073709551615 135746608 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/17977/statm: 644 45 35 592 0 49 0
[pid=17978] ppid=17968 vsize=1432 CPUtime=0
/proc/17978/stat : 17978 (cudf2lp) D 17968 17968 2160 34817 2160 4202496 163 0 10 0 0 0 0 0 24 0 1 0 59309764 1466368 41 1283457024 134512640 135786343 4290250528 18446744073709551615 134712784 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/17978/statm: 358 41 31 311 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 8528

[startup+0.309697 s]
/proc/loadavg: 0.91 0.98 0.99 3/38 17978
/proc/meminfo: memFree=934824/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=0
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 1517 0 0 0 0 0 0 25 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=1924 CPUtime=0
/proc/17976/stat : 17976 (clasp) S 17968 17968 2160 34817 2160 4202496 274 0 18 0 0 0 0 0 23 0 1 0 59309764 1970176 159 1283457024 134512640 136285277 4289853712 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/17976/statm: 481 159 144 433 0 46 0
[pid=17977] ppid=17968 vsize=2576 CPUtime=0
/proc/17977/stat : 17977 (gringo) D 17968 17968 2160 34817 2160 4202496 247 0 19 0 0 0 0 0 23 0 1 0 59309764 2637824 133 1283457024 134512640 136933539 4293606992 18446744073709551615 134542304 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/17977/statm: 644 133 121 592 0 49 0
[pid=17978] ppid=17968 vsize=1840 CPUtime=0
/proc/17978/stat : 17978 (cudf2lp) D 17968 17968 2160 34817 2160 4202496 381 0 15 0 0 0 0 0 23 0 1 0 59309764 1884160 263 1283457024 134512640 135786343 4290250528 18446744073709551615 135258478 0 0 6 0 18446744071564332000 0 0 17 0 0 0 0
/proc/17978/statm: 460 263 127 311 0 147 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 8940

[startup+0.707091 s]
/proc/loadavg: 0.91 0.98 0.99 3/38 17978
/proc/meminfo: memFree=934824/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=0
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 1517 0 0 0 0 0 0 25 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=1924 CPUtime=0
/proc/17976/stat : 17976 (clasp) S 17968 17968 2160 34817 2160 4202496 274 0 18 0 0 0 0 0 23 0 1 0 59309764 1970176 159 1283457024 134512640 136285277 4289853712 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/17976/statm: 481 159 144 433 0 46 0
[pid=17977] ppid=17968 vsize=2584 CPUtime=0
/proc/17977/stat : 17977 (gringo) S 17968 17968 2160 34817 2160 4202496 381 0 23 0 0 0 0 0 22 0 1 0 59309764 2646016 271 1283457024 134512640 136933539 4293606992 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/17977/statm: 646 271 242 592 0 51 0
[pid=17978] ppid=17968 vsize=9920 CPUtime=0.32
/proc/17978/stat : 17978 (cudf2lp) R 17968 17968 2160 34817 2160 4202496 2688 0 15 0 29 3 0 0 24 0 1 0 59309764 10158080 2210 1283457024 134512640 135786343 4290250528 18446744073709551615 134584755 0 0 6 0 0 0 0 17 0 0 0 0
/proc/17978/statm: 2480 2210 128 311 0 2167 0
Current children cumulated CPU time (s) 0.32
Current children cumulated vsize (KiB) 17028

[startup+1.50716 s]
/proc/loadavg: 0.91 0.98 0.99 2/39 17980
/proc/meminfo: memFree=903240/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=0
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 1517 0 0 0 0 0 0 25 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=1924 CPUtime=0
/proc/17976/stat : 17976 (clasp) S 17968 17968 2160 34817 2160 4202496 274 0 18 0 0 0 0 0 23 0 1 0 59309764 1970176 159 1283457024 134512640 136285277 4289853712 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/17976/statm: 481 159 144 433 0 46 0
[pid=17977] ppid=17968 vsize=2584 CPUtime=0
/proc/17977/stat : 17977 (gringo) S 17968 17968 2160 34817 2160 4202496 381 0 23 0 0 0 0 0 22 0 1 0 59309764 2646016 271 1283457024 134512640 136933539 4293606992 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/17977/statm: 646 271 242 592 0 51 0
[pid=17978] ppid=17968 vsize=26956 CPUtime=1.05
/proc/17978/stat : 17978 (cudf2lp) R 17968 17968 2160 34817 2160 4202496 7653 0 15 0 100 5 0 0 25 0 1 0 59309764 27602944 6020 1283457024 134512640 135786343 4290250528 18446744073709551615 135258478 0 0 6 0 0 0 0 17 0 0 0 0
/proc/17978/statm: 6739 6020 128 311 0 6426 0
Current children cumulated CPU time (s) 1.05
Current children cumulated vsize (KiB) 34064

[startup+3.10807 s]
/proc/loadavg: 0.91 0.98 0.99 3/39 17980
/proc/meminfo: memFree=866140/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=0
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 1517 0 0 0 0 0 0 25 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=17860 CPUtime=0.04
/proc/17976/stat : 17976 (clasp) S 17968 17968 2160 34817 2160 4202496 4868 0 21 0 4 0 0 0 18 0 1 0 59309764 18288640 4098 1283457024 134512640 136285277 4289853712 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/17976/statm: 4465 4098 177 433 0 4030 0
[pid=17977] ppid=17968 vsize=28512 CPUtime=0.85
/proc/17977/stat : 17977 (gringo) R 17968 17968 2160 34817 2160 4202496 8325 0 23 0 85 0 0 0 18 0 1 0 59309764 29196288 4921 1283457024 134512640 136933539 4293606992 18446744073709551615 135998671 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/17977/statm: 7128 4921 242 592 0 6533 0
[pid=17978] ppid=17968 vsize=37888 CPUtime=1.71
/proc/17978/stat : 17978 (cudf2lp) R 17968 17968 2160 34817 2160 4202496 11983 0 15 0 163 8 0 0 25 0 1 0 59309764 38797312 9260 1283457024 134512640 135786343 4290250528 18446744073709551615 135258574 0 0 6 0 0 0 0 17 0 0 0 0
/proc/17978/statm: 9472 9260 139 311 0 9159 0
Current children cumulated CPU time (s) 2.6
Current children cumulated vsize (KiB) 86860

[startup+6.30888 s]
/proc/loadavg: 0.92 0.98 0.99 3/38 17980
/proc/meminfo: memFree=792252/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=2.12
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 13503 0 15 0 0 202 10 18 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=72184 CPUtime=0.21
/proc/17976/stat : 17976 (clasp) S 17968 17968 2160 34817 2160 4202496 21528 0 21 0 16 5 0 0 18 0 1 0 59309764 73916416 17219 1283457024 134512640 136285277 4289853712 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/17976/statm: 18046 17219 177 433 0 17611 0
[pid=17977] ppid=17968 vsize=109348 CPUtime=3.49
/proc/17977/stat : 17977 (gringo) R 17968 17968 2160 34817 2160 4202496 36519 0 23 0 337 12 0 0 19 0 1 0 59309764 111972352 23036 1283457024 134512640 136933539 4293606992 18446744073709551615 134688168 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/17977/statm: 27337 23036 253 592 0 26742 0
Current children cumulated CPU time (s) 5.82
Current children cumulated vsize (KiB) 184132

[startup+12.7116 s]
/proc/loadavg: 0.93 0.98 0.99 2/37 17981
/proc/meminfo: memFree=759168/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=8.6
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 83137 0 38 0 0 817 43 18 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=152392 CPUtime=3.62
/proc/17976/stat : 17976 (clasp) R 17968 17968 2160 34817 2160 4202496 49198 0 21 0 347 15 0 0 23 0 1 0 59309764 156049408 37684 1283457024 134512640 136285277 4289853712 18446744073709551615 134902073 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/17976/statm: 38098 37684 218 433 0 37663 0
Current children cumulated CPU time (s) 12.22
Current children cumulated vsize (KiB) 154992

[startup+25.5145 s]
/proc/loadavg: 0.94 0.98 0.99 2/37 17982
/proc/meminfo: memFree=689852/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=8.6
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 83137 0 38 0 0 817 43 18 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=226844 CPUtime=16.42
/proc/17976/stat : 17976 (clasp) R 17968 17968 2160 34817 2160 4202496 68372 0 21 0 1614 28 0 0 25 0 1 0 59309764 232288256 56418 1283457024 134512640 136285277 4289853712 18446744073709551615 134966690 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/17976/statm: 56711 56418 234 433 0 56276 0
Current children cumulated CPU time (s) 25.02
Current children cumulated vsize (KiB) 229444

[startup+51.1107 s]
/proc/loadavg: 0.96 0.98 0.99 2/36 17983
/proc/meminfo: memFree=84128/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=8.6
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 83137 0 38 0 0 817 43 18 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=846112 CPUtime=41.99
/proc/17976/stat : 17976 (clasp) R 17968 17968 2160 34817 2160 4202496 223194 0 21 0 4136 63 0 0 25 0 1 0 59309764 866418688 211240 1283457024 134512640 136285277 4289853712 18446744073709551615 134951781 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/17976/statm: 211528 211240 234 433 0 211093 0
Current children cumulated CPU time (s) 50.59
Current children cumulated vsize (KiB) 848712

Solver just ended. Dumping a history of the last processes samples

[startup+51.2107 s]
/proc/loadavg: 0.96 0.98 0.99 2/36 17983
/proc/meminfo: memFree=84128/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=8.6
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 83137 0 38 0 0 817 43 18 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=849748 CPUtime=42.09
/proc/17976/stat : 17976 (clasp) R 17968 17968 2160 34817 2160 4202496 224103 0 21 0 4146 63 0 0 25 0 1 0 59309764 870141952 212149 1283457024 134512640 136285277 4289853712 18446744073709551615 134639147 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/17976/statm: 212437 212149 234 433 0 212002 0
Current children cumulated CPU time (s) 50.69
Current children cumulated vsize (KiB) 852348

[startup+54.4115 s]
/proc/loadavg: 0.96 0.98 0.99 2/36 17983
/proc/meminfo: memFree=4144/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=8.6
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 83137 0 38 0 0 817 43 18 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=916420 CPUtime=45.28
/proc/17976/stat : 17976 (clasp) R 17968 17968 2160 34817 2160 4204544 240778 0 21 0 4458 70 0 0 25 0 1 0 59309764 938414080 228824 1283457024 134512640 136285277 4289853712 18446744073709551615 134628497 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/17976/statm: 229105 228824 234 433 0 228670 0
Current children cumulated CPU time (s) 53.88
Current children cumulated vsize (KiB) 919020

[startup+56.0121 s]
/proc/loadavg: 1.04 1.00 0.99 2/36 17983
/proc/meminfo: memFree=4284/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=8.6
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 83137 0 38 0 0 817 43 18 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=953688 CPUtime=46.87
/proc/17976/stat : 17976 (clasp) R 17968 17968 2160 34817 2160 4202496 250064 0 21 0 4613 74 0 0 25 0 1 0 59309764 976576512 238110 1283457024 134512640 136285277 4289853712 18446744073709551615 134669462 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/17976/statm: 238422 238110 234 433 0 237987 0
Current children cumulated CPU time (s) 55.47
Current children cumulated vsize (KiB) 956288

[startup+56.8123 s]
/proc/loadavg: 1.04 1.00 0.99 2/36 17983
/proc/meminfo: memFree=4288/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=8.6
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 83137 0 38 0 0 817 43 18 0 1 0 59309763 2662400 299 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 299 251 194 0 37 0
[pid=17976] ppid=17968 vsize=970376 CPUtime=47.66
/proc/17976/stat : 17976 (clasp) R 17968 17968 2160 34817 2160 4202496 254251 0 21 0 4692 74 0 0 25 0 1 0 59309764 993665024 242297 1283457024 134512640 136285277 4289853712 18446744073709551615 134955202 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/17976/statm: 242594 242297 234 433 0 242159 0
Current children cumulated CPU time (s) 56.26
Current children cumulated vsize (KiB) 972976

[startup+57.6124 s]
/proc/loadavg: 1.04 1.00 0.99 2/36 17983
/proc/meminfo: memFree=4628/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=8.6
/proc/17968/stat : 17968 (aspcud-1.5) S 17967 17968 2160 34817 2160 4202496 581 83137 0 38 0 0 817 43 18 0 1 0 59309763 2662400 90 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/17968/statm: 650 90 42 194 0 37 0
[pid=17976] ppid=17968 vsize=983956 CPUtime=48.46
/proc/17976/stat : 17976 (clasp) R 17968 17968 2160 34817 2160 4202496 257646 0 21 0 4768 78 0 0 25 0 1 0 59309764 1007570944 245509 1283457024 134512640 136285277 4289853712 18446744073709551615 134963458 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/17976/statm: 245989 245509 51 433 0 245554 0
Current children cumulated CPU time (s) 57.06
Current children cumulated vsize (KiB) 986556

[startup+58.3067 s]
/proc/loadavg: 1.04 1.00 0.99 2/36 17983
/proc/meminfo: memFree=4628/1048576 swapFree=0/0
[pid=17968] ppid=17967 vsize=2600 CPUtime=57.24
/proc/17968/stat : 17968 (aspcud-1.5) D 17967 17968 2160 34817 2160 4202496 751 341171 18 66 0 0 5587 137 18 0 1 0 59309763 2662400 209 1283457024 134512640 135304128 4290418064 18446744073709551615 4294960130 0 0 16902 1132543225 18446744071564252162 0 0 17 0 0 0 0
/proc/17968/statm: 650 209 161 194 0 37 0
Current children cumulated CPU time (s) 57.24
Current children cumulated vsize (KiB) 2600

Child status: 0
Real time (s): 58.3791
CPU time (s): 57.2516
CPU user time (s): 55.8755
CPU system time (s): 1.37609
CPU usage (%): 98.0686
Max. virtual memory (cumulated for all children) (KiB): 986556

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 55.8755
system time used= 1.37609
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 344329
page faults= 90
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 10786
involuntary context switches= 9952

runsolver used 0 second user time and 0.048003 second system time

The end