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/rande4fcd8.cudf.difficult.log.runsolver ./aspcud-1.3 /home/misc2010/data/2010/difficult//rande4fcd8.cudf /home/misc2010/tmp/201012091704/aspcud-1.3/rande4fcd8.cudf.difficult.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.54 1.18 1.04 4/39 10432
/proc/meminfo: memFree=330216/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2584 CPUtime=0
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 374 0 0 0 0 0 0 0 25 0 1 0 902207194 2646016 281 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/10430/statm: 646 281 237 194 0 32 0
[pid=10431] ppid=10430 vsize=2584 CPUtime=0
/proc/10431/stat : 10431 (aspcud-1.3) R 10430 10430 25521 34816 2180 4202560 105 0 0 0 0 0 0 0 25 0 1 0 902207194 2646016 127 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/10431/statm: 646 127 82 194 0 32 0
[pid=10432] ppid=10431 vsize=2584 CPUtime=0
/proc/10432/stat : 10432 (aspcud-1.3) R 10431 10430 25521 34816 2180 4202560 0 0 0 0 0 0 0 0 25 0 1 0 902207194 2646016 45 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/10432/statm: 646 45 0 194 0 32 0

[startup+0.107429 s]
/proc/loadavg: 1.54 1.18 1.04 4/39 10432
/proc/meminfo: memFree=330216/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=0
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 1510 0 0 0 0 0 0 25 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2592

[startup+0.207452 s]
/proc/loadavg: 1.54 1.18 1.04 4/39 10432
/proc/meminfo: memFree=330216/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=0
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 1510 0 0 0 0 0 0 25 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2592

[startup+0.307466 s]
/proc/loadavg: 1.54 1.18 1.04 4/39 10432
/proc/meminfo: memFree=330216/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=0
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 1510 0 0 0 0 0 0 25 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2592

[startup+0.707567 s]
/proc/loadavg: 1.54 1.18 1.04 4/39 10432
/proc/meminfo: memFree=330216/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=0
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 1510 0 0 0 0 0 0 25 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2592

[startup+1.50775 s]
/proc/loadavg: 1.54 1.18 1.04 3/40 10441
/proc/meminfo: memFree=317948/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=13584 CPUtime=0.33
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 3484 0 0 0 33 0 0 0 18 0 1 0 902207196 13910016 2983 1283457024 134512640 136223643 4292681680 18446744073709551615 134929199 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 3396 2983 225 418 0 2976 0
Current children cumulated CPU time (s) 1.48
Current children cumulated vsize (KiB) 16176

[startup+3.10808 s]
/proc/loadavg: 1.49 1.17 1.04 2/39 10441
/proc/meminfo: memFree=317468/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=15172 CPUtime=1.93
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 3885 0 0 0 193 0 0 0 20 0 1 0 902207196 15536128 3384 1283457024 134512640 136223643 4292681680 18446744073709551615 134630063 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 3793 3384 225 418 0 3373 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 17764

[startup+6.30876 s]
/proc/loadavg: 1.49 1.17 1.04 2/39 10441
/proc/meminfo: memFree=317468/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=15172 CPUtime=5.14
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 3885 0 0 0 514 0 0 0 25 0 1 0 902207196 15536128 3384 1283457024 134512640 136223643 4292681680 18446744073709551615 134924387 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 3793 3384 225 418 0 3373 0
Current children cumulated CPU time (s) 6.29
Current children cumulated vsize (KiB) 17764

[startup+12.7101 s]
/proc/loadavg: 1.42 1.17 1.04 2/39 10441
/proc/meminfo: memFree=302712/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=29888 CPUtime=11.54
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 7566 0 0 0 1152 2 0 0 25 0 1 0 902207196 30605312 7065 1283457024 134512640 136223643 4292681680 18446744073709551615 134931096 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 7472 7065 225 418 0 7052 0
Current children cumulated CPU time (s) 12.69
Current children cumulated vsize (KiB) 32480

[startup+25.512 s]
/proc/loadavg: 1.35 1.16 1.04 2/39 10441
/proc/meminfo: memFree=301100/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=31472 CPUtime=24.34
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 7970 0 0 0 2432 2 0 0 25 0 1 0 902207196 32227328 7469 1283457024 134512640 136223643 4292681680 18446744073709551615 134664705 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 7868 7469 225 418 0 7448 0
Current children cumulated CPU time (s) 25.49
Current children cumulated vsize (KiB) 34064

[startup+51.1066 s]
/proc/loadavg: 1.23 1.15 1.04 2/39 10441
/proc/meminfo: memFree=295272/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=37308 CPUtime=49.92
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 9409 0 0 0 4990 2 0 0 25 0 1 0 902207196 38203392 8908 1283457024 134512640 136223643 4292681680 18446744073709551615 134924336 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 9327 8908 225 418 0 8907 0
Current children cumulated CPU time (s) 51.07
Current children cumulated vsize (KiB) 39900

[startup+102.307 s]
/proc/loadavg: 1.09 1.12 1.03 2/39 10441
/proc/meminfo: memFree=289692/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=42868 CPUtime=101.04
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 10798 0 0 0 10101 3 0 0 25 0 1 0 902207196 43896832 10297 1283457024 134512640 136223643 4292681680 18446744073709551615 134924367 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 10717 10297 225 418 0 10297 0
Current children cumulated CPU time (s) 102.19
Current children cumulated vsize (KiB) 45460

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

[startup+102.407 s]
/proc/loadavg: 1.09 1.12 1.03 2/39 10441
/proc/meminfo: memFree=289692/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=42868 CPUtime=101.14
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 10798 0 0 0 10111 3 0 0 25 0 1 0 902207196 43896832 10297 1283457024 134512640 136223643 4292681680 18446744073709551615 134713027 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 10717 10297 225 418 0 10297 0
Current children cumulated CPU time (s) 102.29
Current children cumulated vsize (KiB) 45460

[startup+128.013 s]
/proc/loadavg: 1.06 1.11 1.03 2/39 10441
/proc/meminfo: memFree=289692/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=42868 CPUtime=126.73
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 10799 0 0 0 12670 3 0 0 25 0 1 0 902207196 43896832 10298 1283457024 134512640 136223643 4292681680 18446744073709551615 134928992 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 10717 10298 225 418 0 10297 0
Current children cumulated CPU time (s) 127.88
Current children cumulated vsize (KiB) 45460

[startup+140.805 s]
/proc/loadavg: 1.05 1.10 1.03 2/39 10441
/proc/meminfo: memFree=289692/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=42868 CPUtime=139.52
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 10799 0 0 0 13949 3 0 0 25 0 1 0 902207196 43896832 10298 1283457024 134512640 136223643 4292681680 18446744073709551615 134711998 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 10717 10298 225 418 0 10297 0
Current children cumulated CPU time (s) 140.67
Current children cumulated vsize (KiB) 45460

[startup+153.61 s]
/proc/loadavg: 1.04 1.10 1.03 2/39 10441
/proc/meminfo: memFree=289692/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=42868 CPUtime=152.29
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 10799 0 0 0 15226 3 0 0 25 0 1 0 902207196 43896832 10298 1283457024 134512640 136223643 4292681680 18446744073709551615 134928848 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 10717 10298 225 418 0 10297 0
Current children cumulated CPU time (s) 153.44
Current children cumulated vsize (KiB) 45460

[startup+156.81 s]
/proc/loadavg: 1.04 1.10 1.03 2/39 10441
/proc/meminfo: memFree=289692/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=42868 CPUtime=155.49
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 10799 0 0 0 15546 3 0 0 25 0 1 0 902207196 43896832 10298 1283457024 134512640 136223643 4292681680 18446744073709551615 134711761 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 10717 10298 225 418 0 10297 0
Current children cumulated CPU time (s) 156.64
Current children cumulated vsize (KiB) 45460

[startup+158.411 s]
/proc/loadavg: 1.03 1.10 1.03 2/39 10441
/proc/meminfo: memFree=289692/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=42868 CPUtime=157.09
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 10799 0 0 0 15706 3 0 0 25 0 1 0 902207196 43896832 10298 1283457024 134512640 136223643 4292681680 18446744073709551615 134712012 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 10717 10298 225 418 0 10297 0
Current children cumulated CPU time (s) 158.24
Current children cumulated vsize (KiB) 45460

[startup+159.211 s]
/proc/loadavg: 1.03 1.10 1.03 2/39 10441
/proc/meminfo: memFree=289692/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=42868 CPUtime=157.89
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 10799 0 0 0 15786 3 0 0 25 0 1 0 902207196 43896832 10298 1283457024 134512640 136223643 4292681680 18446744073709551615 134630038 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 10717 10298 225 418 0 10297 0
Current children cumulated CPU time (s) 159.04
Current children cumulated vsize (KiB) 45460

[startup+159.611 s]
/proc/loadavg: 1.03 1.10 1.03 2/39 10441
/proc/meminfo: memFree=289692/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=42868 CPUtime=158.29
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 10799 0 0 0 15826 3 0 0 25 0 1 0 902207196 43896832 10298 1283457024 134512640 136223643 4292681680 18446744073709551615 134650964 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 10717 10298 225 418 0 10297 0
Current children cumulated CPU time (s) 159.44
Current children cumulated vsize (KiB) 45460

[startup+159.811 s]
/proc/loadavg: 1.03 1.10 1.03 2/39 10441
/proc/meminfo: memFree=289692/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2592 CPUtime=1.15
/proc/10430/stat : 10430 (aspcud-1.3) S 10429 10430 25521 34816 2180 4202496 569 14533 0 0 0 0 108 7 17 0 1 0 902207194 2654208 299 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/10430/statm: 648 299 253 194 0 34 0
[pid=10439] ppid=10430 vsize=42868 CPUtime=158.49
/proc/10439/stat : 10439 (clasp) R 10430 10430 25521 34816 2180 4202496 10799 0 0 0 15846 3 0 0 25 0 1 0 902207196 43896832 10298 1283457024 134512640 136223643 4292681680 18446744073709551615 134930964 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/10439/statm: 10717 10298 225 418 0 10297 0
Current children cumulated CPU time (s) 159.64
Current children cumulated vsize (KiB) 45460

[startup+159.911 s]
/proc/loadavg: 1.03 1.10 1.03 2/39 10441
/proc/meminfo: memFree=289692/1048576 swapFree=2095372/2097144
[pid=10430] ppid=10429 vsize=2596 CPUtime=159.74
/proc/10430/stat : 10430 (aspcud-1.3) R 10429 10430 25521 34816 2180 4202496 662 25953 0 0 0 0 15962 12 20 0 1 0 902207194 2658304 305 1283457024 134512640 135304128 4289944896 18446744073709551615 4294960130 0 65538 16902 1132543225 0 0 0 17 0 0 0 0
/proc/10430/statm: 649 305 258 194 0 35 0
Current children cumulated CPU time (s) 159.74
Current children cumulated vsize (KiB) 2596

Child status: 0
Real time (s): 159.925
CPU time (s): 159.77
CPU user time (s): 159.63
CPU system time (s): 0.140008
CPU usage (%): 99.9031
Max. virtual memory (cumulated for all children) (KiB): 45460

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 159.63
system time used= 0.140008
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 29487
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= 400
involuntary context switches= 2159

runsolver used 0 second user time and 0 second system time

The end