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/201012091704/aspcud-1.3/rand7902a8.cudf.impossible.log.runsolver ./aspcud-1.3 /home/misc2010/data/2010/impossible//rand7902a8.cudf /home/misc2010/tmp/201012091704/aspcud-1.3/rand7902a8.cudf.impossible.result -changed,-notuptodate,-removed,-new 

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: 1.17 1.08 1.02 3/40 5491
/proc/meminfo: memFree=422200/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2588 CPUtime=0
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 374 0 0 0 0 0 0 0 25 0 1 0 901198268 2650112 281 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/5488/statm: 647 281 237 194 0 33 0
[pid=5489] ppid=5488 vsize=2588 CPUtime=0
/proc/5489/stat : 5489 (aspcud-1.3) S 5488 5488 25521 34816 2180 4202560 114 0 0 0 0 0 0 0 25 0 1 0 901198268 2650112 128 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 0 0 65538 18446744071564457842 0 0 17 0 0 0 0
/proc/5489/statm: 647 128 83 194 0 33 0
[pid=5490] ppid=5489 vsize=2588 CPUtime=0
/proc/5490/stat : 5490 (aspcud-1.3) S 5489 5488 25521 34816 2180 4202560 156 0 0 0 0 0 0 0 25 0 1 0 901198268 2650112 159 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 0 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5490/statm: 647 159 114 194 0 33 0
[pid=5491] ppid=5490 vsize=40 CPUtime=0
/proc/5491/stat : 5491 (readlink) R 5490 5488 25521 34816 2180 4194304 55 0 0 0 0 0 0 0 25 0 1 0 901198268 40960 2 1283457024 0 0 4290700267 18446744073709551615 4294960130 0 0 0 0 0 0 0 17 0 0 0 0
/proc/5491/statm: 10 2 0 0 0 1 0

[startup+0.12302 s]
/proc/loadavg: 1.17 1.08 1.02 3/40 5491
/proc/meminfo: memFree=422200/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=0
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 569 1507 0 0 0 0 0 0 25 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.213049 s]
/proc/loadavg: 1.17 1.08 1.02 3/40 5491
/proc/meminfo: memFree=422200/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=0
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 569 1507 0 0 0 0 0 0 25 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.303062 s]
/proc/loadavg: 1.17 1.08 1.02 3/40 5491
/proc/meminfo: memFree=422200/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=0
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 569 1507 0 0 0 0 0 0 25 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.703179 s]
/proc/loadavg: 1.17 1.08 1.02 3/40 5491
/proc/meminfo: memFree=422200/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=0
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 569 1507 0 0 0 0 0 0 25 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+1.50343 s]
/proc/loadavg: 1.16 1.08 1.02 2/41 5499
/proc/meminfo: memFree=387592/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=0
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 569 1507 0 0 0 0 0 0 25 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=1872 CPUtime=0.01
/proc/5497/stat : 5497 (clasp) S 5488 5488 25521 34816 2180 4202496 284 0 0 0 0 1 0 0 25 0 1 0 901198269 1916928 153 1283457024 134512640 136223643 4288406464 18446744073709551615 135666734 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/5497/statm: 468 153 138 418 0 48 0
[pid=5498] ppid=5488 vsize=2608 CPUtime=0
/proc/5498/stat : 5498 (gringo) S 5488 5488 25521 34816 2180 4202496 407 0 0 0 0 0 0 0 25 0 1 0 901198269 2670592 277 1283457024 134512640 136959103 4286816944 18446744073709551615 135656590 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/5498/statm: 652 277 247 598 0 51 0
[pid=5499] ppid=5488 vsize=61700 CPUtime=1.48
/proc/5499/stat : 5499 (cudf2lp) R 5488 5488 25521 34816 2180 4202496 16768 0 0 0 140 8 0 0 25 0 1 0 901198269 63180800 14616 1283457024 134512640 135749571 4293953920 18446744073709551615 134549811 0 0 6 0 0 0 0 17 0 0 0 0
/proc/5499/statm: 15425 14616 130 302 0 15121 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 68776

[startup+3.10387 s]
/proc/loadavg: 1.16 1.08 1.02 3/41 5499
/proc/meminfo: memFree=347044/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=2
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 20514 0 0 0 0 190 10 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=22364 CPUtime=0.09
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 6197 0 0 0 7 2 0 0 18 0 1 0 901198269 22900736 5205 1283457024 134512640 136223643 4288406464 18446744073709551615 135666734 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 5591 5205 174 418 0 5171 0
[pid=5498] ppid=5488 vsize=41356 CPUtime=1
/proc/5498/stat : 5498 (gringo) R 5488 5488 25521 34816 2180 4202496 11165 0 0 0 100 0 0 0 18 0 1 0 901198269 42348544 7323 1283457024 134512640 136959103 4286816944 18446744073709551615 134901376 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5498/statm: 10339 7323 256 598 0 9738 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 66316

[startup+6.30499 s]
/proc/loadavg: 1.16 1.08 1.02 2/39 5499
/proc/meminfo: memFree=387376/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=3.43
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 33894 0 0 0 0 331 12 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=38452 CPUtime=2.86
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 10965 0 0 0 283 3 0 0 23 0 1 0 901198269 39374848 8802 1283457024 134512640 136223643 4288406464 18446744073709551615 134924387 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 9613 8802 225 418 0 9193 0
Current children cumulated CPU time (s) 6.29
Current children cumulated vsize (KiB) 41048

[startup+12.7065 s]
/proc/loadavg: 1.13 1.08 1.02 2/39 5499
/proc/meminfo: memFree=381548/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=3.43
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 33894 0 0 0 0 331 12 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=44896 CPUtime=9.26
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 12577 0 0 0 922 4 0 0 25 0 1 0 901198269 45973504 10414 1283457024 134512640 136223643 4288406464 18446744073709551615 134917906 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 11224 10414 225 418 0 10804 0
Current children cumulated CPU time (s) 12.69
Current children cumulated vsize (KiB) 47492

[startup+25.512 s]
/proc/loadavg: 1.11 1.08 1.02 2/39 5499
/proc/meminfo: memFree=381548/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=3.43
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 33894 0 0 0 0 331 12 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=44896 CPUtime=22.06
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 12580 0 0 0 2202 4 0 0 25 0 1 0 901198269 45973504 10417 1283457024 134512640 136223643 4288406464 18446744073709551615 134931099 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 11224 10417 225 418 0 10804 0
Current children cumulated CPU time (s) 25.49
Current children cumulated vsize (KiB) 47492

[startup+51.1119 s]
/proc/loadavg: 1.07 1.07 1.02 2/39 5499
/proc/meminfo: memFree=371380/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=3.43
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 33894 0 0 0 0 331 12 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=57172 CPUtime=47.59
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 15655 0 0 0 4752 7 0 0 25 0 1 0 901198269 58544128 13492 1283457024 134512640 136223643 4288406464 18446744073709551615 134930043 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 14293 13492 225 418 0 13873 0
Current children cumulated CPU time (s) 51.02
Current children cumulated vsize (KiB) 59768

[startup+102.305 s]
/proc/loadavg: 1.03 1.05 1.01 2/39 5499
/proc/meminfo: memFree=336040/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=3.43
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 33894 0 0 0 0 331 12 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=90384 CPUtime=98.7
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 23930 0 0 0 9858 12 0 0 25 0 1 0 901198269 92553216 21767 1283457024 134512640 136223643 4288406464 18446744073709551615 134931000 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 22596 21767 225 418 0 22176 0
Current children cumulated CPU time (s) 102.13
Current children cumulated vsize (KiB) 92980

[startup+162.311 s]
/proc/loadavg: 1.01 1.04 1.01 2/39 5499
/proc/meminfo: memFree=313100/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=3.43
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 33894 0 0 0 0 331 12 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=113292 CPUtime=158.64
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 29629 0 0 0 15847 17 0 0 25 0 1 0 901198269 116011008 27466 1283457024 134512640 136223643 4288406464 18446744073709551615 134931099 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 28323 27466 225 418 0 27903 0
Current children cumulated CPU time (s) 162.07
Current children cumulated vsize (KiB) 115888

[startup+222.306 s]
/proc/loadavg: 1.00 1.03 1.00 2/40 5500
/proc/meminfo: memFree=298204/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=3.43
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 33894 0 0 0 0 331 12 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=127800 CPUtime=218.56
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 33259 0 0 0 21838 18 0 0 25 0 1 0 901198269 130867200 31096 1283457024 134512640 136223643 4288406464 18446744073709551615 134920331 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 31950 31096 225 418 0 31530 0
Current children cumulated CPU time (s) 221.99
Current children cumulated vsize (KiB) 130396

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

[startup+224.007 s]
/proc/loadavg: 1.00 1.03 1.00 2/40 5500
/proc/meminfo: memFree=298204/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=3.43
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 33894 0 0 0 0 331 12 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=127800 CPUtime=220.26
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 33259 0 0 0 22008 18 0 0 25 0 1 0 901198269 130867200 31096 1283457024 134512640 136223643 4288406464 18446744073709551615 134928984 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 31950 31096 225 418 0 31530 0
Current children cumulated CPU time (s) 223.69
Current children cumulated vsize (KiB) 130396

[startup+227.208 s]
/proc/loadavg: 1.00 1.03 1.00 2/40 5500
/proc/meminfo: memFree=298204/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=3.43
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 33894 0 0 0 0 331 12 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=127800 CPUtime=223.45
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 33259 0 0 0 22327 18 0 0 25 0 1 0 901198269 130867200 31096 1283457024 134512640 136223643 4288406464 18446744073709551615 134929273 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 31950 31096 225 418 0 31530 0
Current children cumulated CPU time (s) 226.88
Current children cumulated vsize (KiB) 130396

[startup+228.808 s]
/proc/loadavg: 1.00 1.03 1.00 2/40 5500
/proc/meminfo: memFree=298204/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=3.43
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 33894 0 0 0 0 331 12 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=127800 CPUtime=225.05
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 33259 0 0 0 22487 18 0 0 25 0 1 0 901198269 130867200 31096 1283457024 134512640 136223643 4288406464 18446744073709551615 134664719 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 31950 31096 225 418 0 31530 0
Current children cumulated CPU time (s) 228.48
Current children cumulated vsize (KiB) 130396

[startup+229.608 s]
/proc/loadavg: 1.00 1.03 1.00 2/40 5500
/proc/meminfo: memFree=298204/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=3.43
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 33894 0 0 0 0 331 12 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=127800 CPUtime=225.85
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 33259 0 0 0 22567 18 0 0 25 0 1 0 901198269 130867200 31096 1283457024 134512640 136223643 4288406464 18446744073709551615 134929649 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 31950 31096 225 418 0 31530 0
Current children cumulated CPU time (s) 229.28
Current children cumulated vsize (KiB) 130396

[startup+230.008 s]
/proc/loadavg: 1.00 1.03 1.00 2/40 5500
/proc/meminfo: memFree=298204/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=3.43
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 33894 0 0 0 0 331 12 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=127800 CPUtime=226.25
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 33259 0 0 0 22607 18 0 0 25 0 1 0 901198269 130867200 31096 1283457024 134512640 136223643 4288406464 18446744073709551615 134931099 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 31950 31096 225 418 0 31530 0
Current children cumulated CPU time (s) 229.68
Current children cumulated vsize (KiB) 130396

[startup+230.408 s]
/proc/loadavg: 1.00 1.03 1.00 2/40 5500
/proc/meminfo: memFree=298204/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2596 CPUtime=3.43
/proc/5488/stat : 5488 (aspcud-1.3) S 5487 5488 25521 34816 2180 4202496 570 33894 0 0 0 0 331 12 18 0 1 0 901198268 2658304 299 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5488/statm: 649 299 253 194 0 35 0
[pid=5497] ppid=5488 vsize=127800 CPUtime=226.65
/proc/5497/stat : 5497 (clasp) R 5488 5488 25521 34816 2180 4202496 33259 0 0 0 22647 18 0 0 25 0 1 0 901198269 130867200 31096 1283457024 134512640 136223643 4288406464 18446744073709551615 134928998 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5497/statm: 31950 31096 225 418 0 31530 0
Current children cumulated CPU time (s) 230.08
Current children cumulated vsize (KiB) 130396

[startup+230.508 s]
/proc/loadavg: 1.00 1.03 1.00 2/40 5500
/proc/meminfo: memFree=298204/1048576 swapFree=2095372/2097144
[pid=5488] ppid=5487 vsize=2636 CPUtime=230.19
/proc/5488/stat : 5488 (aspcud-1.3) R 5487 5488 25521 34816 2180 4202496 822 69457 0 0 0 0 22985 34 18 0 1 0 901198268 2699264 314 1283457024 134512640 135304128 4290620912 18446744073709551615 4294960130 0 65538 16902 1132543225 0 0 0 17 0 0 0 0
/proc/5488/statm: 659 314 258 194 0 45 0
Current children cumulated CPU time (s) 230.19
Current children cumulated vsize (KiB) 2636

Child status: 0
Real time (s): 230.513
CPU time (s): 230.206
CPU user time (s): 229.85
CPU system time (s): 0.356022
CPU usage (%): 99.8671
Max. virtual memory (cumulated for all children) (KiB): 130396

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 229.85
system time used= 0.356022
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 71311
page faults= 0
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1629
involuntary context switches= 3865

runsolver used 0 second user time and 0 second system time

The end