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/201012061533/aspcud-paranoid-1.3/1dcce248-4bb4-11df-9e6e-00163e7a6f5e.cudf.debian-dudf.log.runsolver ./aspcud-paranoid-1.3 /home/misc2010/data/2010/debian-dudf//1dcce248-4bb4-11df-9e6e-00163e7a6f5e.cudf /home/misc2010/tmp/201012061533/aspcud-paranoid-1.3/1dcce248-4bb4-11df-9e6e-00163e7a6f5e.cudf.debian-dudf.result 

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.28 1.11 1.09 5/52 5190
/proc/meminfo: memFree=639520/1048576 swapFree=2073632/2097144
[pid=5189] ppid=5188 vsize=2592 CPUtime=0
/proc/5189/stat : 5189 (aspcud-paranoid) R 5188 5189 2059 34821 2220 4202496 368 0 0 0 0 0 0 0 25 0 1 0 874549264 2654208 282 1283457024 134512640 135304128 4292294496 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/5189/statm: 648 282 237 194 0 34 0
[pid=5190] ppid=5189 vsize=2592 CPUtime=0
/proc/5190/stat : 5190 (aspcud-paranoid) R 5189 5189 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 1 0 874549264 2654208 45 1283457024 134512640 135304128 4292294496 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/5190/statm: 648 45 0 194 0 34 0

[startup+0.185624 s]
/proc/loadavg: 1.28 1.11 1.09 5/52 5190
/proc/meminfo: memFree=639520/1048576 swapFree=2073632/2097144
[pid=5189] ppid=5188 vsize=2604 CPUtime=0.01
/proc/5189/stat : 5189 (aspcud-paranoid) S 5188 5189 2059 34821 2220 4202496 666 2929 0 0 0 0 1 0 25 0 1 0 874549264 2666496 301 1283457024 134512640 135304128 4292294496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5189/statm: 651 301 253 194 0 37 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2604

[startup+0.205637 s]
/proc/loadavg: 1.28 1.11 1.09 5/52 5190
/proc/meminfo: memFree=639520/1048576 swapFree=2073632/2097144
[pid=5189] ppid=5188 vsize=2604 CPUtime=0.01
/proc/5189/stat : 5189 (aspcud-paranoid) S 5188 5189 2059 34821 2220 4202496 666 2929 0 0 0 0 1 0 25 0 1 0 874549264 2666496 301 1283457024 134512640 135304128 4292294496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5189/statm: 651 301 253 194 0 37 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2604

[startup+0.305649 s]
/proc/loadavg: 1.28 1.11 1.09 5/52 5190
/proc/meminfo: memFree=639520/1048576 swapFree=2073632/2097144
[pid=5189] ppid=5188 vsize=2604 CPUtime=0.01
/proc/5189/stat : 5189 (aspcud-paranoid) S 5188 5189 2059 34821 2220 4202496 666 2929 0 0 0 0 1 0 25 0 1 0 874549264 2666496 301 1283457024 134512640 135304128 4292294496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5189/statm: 651 301 253 194 0 37 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2604

[startup+0.705732 s]
/proc/loadavg: 1.28 1.11 1.09 5/52 5190
/proc/meminfo: memFree=639520/1048576 swapFree=2073632/2097144
[pid=5189] ppid=5188 vsize=2604 CPUtime=0.01
/proc/5189/stat : 5189 (aspcud-paranoid) S 5188 5189 2059 34821 2220 4202496 666 2929 0 0 0 0 1 0 25 0 1 0 874549264 2666496 301 1283457024 134512640 135304128 4292294496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5189/statm: 651 301 253 194 0 37 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2604

[startup+1.50591 s]
/proc/loadavg: 1.28 1.11 1.09 3/55 5206
/proc/meminfo: memFree=597068/1048576 swapFree=2073632/2097144
[pid=5189] ppid=5188 vsize=2604 CPUtime=0.01
/proc/5189/stat : 5189 (aspcud-paranoid) S 5188 5189 2059 34821 2220 4202496 666 2929 0 0 0 0 1 0 25 0 1 0 874549264 2666496 301 1283457024 134512640 135304128 4292294496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5189/statm: 651 301 253 194 0 37 0
[pid=5204] ppid=5189 vsize=6444 CPUtime=0
/proc/5204/stat : 5204 (clasp) S 5189 5189 2059 34821 2220 4202496 1544 0 0 0 0 0 0 0 18 0 1 0 874549266 6598656 1329 1283457024 134512640 136223643 4288947232 18446744073709551615 135666734 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/5204/statm: 1611 1329 174 418 0 1191 0
[pid=5205] ppid=5189 vsize=9344 CPUtime=0.24
/proc/5205/stat : 5205 (gringo) S 5189 5189 2059 34821 2220 4202496 2481 0 0 0 22 2 0 0 18 0 1 0 874549266 9568256 1574 1283457024 134512640 136959103 4287302416 18446744073709551615 135656590 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/5205/statm: 2336 1574 247 598 0 1735 0
[pid=5206] ppid=5189 vsize=40872 CPUtime=1.24
/proc/5206/stat : 5206 (cudf2lp) R 5189 5189 2059 34821 2220 4202496 13293 0 0 0 122 2 0 0 25 0 1 0 874549266 41852928 10022 1283457024 134512640 135749571 4288496720 18446744073709551615 134794916 0 0 6 0 0 0 0 17 0 0 0 0
/proc/5206/statm: 10218 10022 129 302 0 9914 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 59264

[startup+3.10634 s]
/proc/loadavg: 1.28 1.11 1.09 3/55 5206
/proc/meminfo: memFree=568300/1048576 swapFree=2073632/2097144
[pid=5189] ppid=5188 vsize=2604 CPUtime=1.48
/proc/5189/stat : 5189 (aspcud-paranoid) S 5188 5189 2059 34821 2220 4202496 667 16226 0 0 0 0 145 3 18 0 1 0 874549264 2666496 301 1283457024 134512640 135304128 4292294496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5189/statm: 651 301 253 194 0 37 0
[pid=5204] ppid=5189 vsize=33208 CPUtime=0.14
/proc/5204/stat : 5204 (clasp) R 5189 5189 2059 34821 2220 4202496 9387 0 0 0 10 4 0 0 18 0 1 0 874549266 34004992 7886 1283457024 134512640 136223643 4288947232 18446744073709551615 135609367 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5204/statm: 8302 7886 174 418 0 7882 0
[pid=5205] ppid=5189 vsize=53420 CPUtime=1.46
/proc/5205/stat : 5205 (gringo) R 5189 5189 2059 34821 2220 4202496 15794 0 0 0 140 6 0 0 18 0 1 0 874549266 54702080 11033 1283457024 134512640 136959103 4287302416 18446744073709551615 135656494 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5205/statm: 13355 11033 256 598 0 12754 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 89232

[startup+6.30725 s]
/proc/loadavg: 1.26 1.11 1.09 2/53 5206
/proc/meminfo: memFree=587304/1048576 swapFree=2073632/2097144
[pid=5189] ppid=5188 vsize=2604 CPUtime=3.48
/proc/5189/stat : 5189 (aspcud-paranoid) S 5188 5189 2059 34821 2220 4202496 667 34428 0 0 0 0 337 11 18 0 1 0 874549264 2666496 301 1283457024 134512640 135304128 4292294496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5189/statm: 651 301 253 194 0 37 0
[pid=5204] ppid=5189 vsize=56320 CPUtime=2.81
/proc/5204/stat : 5204 (clasp) R 5189 5189 2059 34821 2220 4202496 16517 0 0 0 274 7 0 0 22 0 1 0 874549266 57671680 12981 1283457024 134512640 136223643 4288947232 18446744073709551615 134650496 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5204/statm: 14080 12981 223 418 0 13660 0
Current children cumulated CPU time (s) 6.29
Current children cumulated vsize (KiB) 58924

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

[startup+6.40727 s]
/proc/loadavg: 1.26 1.11 1.09 2/53 5206
/proc/meminfo: memFree=587304/1048576 swapFree=2073632/2097144
[pid=5189] ppid=5188 vsize=2604 CPUtime=3.48
/proc/5189/stat : 5189 (aspcud-paranoid) S 5188 5189 2059 34821 2220 4202496 667 34428 0 0 0 0 337 11 18 0 1 0 874549264 2666496 301 1283457024 134512640 135304128 4292294496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5189/statm: 651 301 253 194 0 37 0
[pid=5204] ppid=5189 vsize=56320 CPUtime=2.91
/proc/5204/stat : 5204 (clasp) R 5189 5189 2059 34821 2220 4202496 16517 0 0 0 284 7 0 0 23 0 1 0 874549266 57671680 12981 1283457024 134512640 136223643 4288947232 18446744073709551615 134870708 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5204/statm: 14080 12981 223 418 0 13660 0
Current children cumulated CPU time (s) 6.39
Current children cumulated vsize (KiB) 58924

[startup+6.80736 s]
/proc/loadavg: 1.26 1.11 1.09 2/53 5206
/proc/meminfo: memFree=587312/1048576 swapFree=2073632/2097144
[pid=5189] ppid=5188 vsize=2604 CPUtime=3.48
/proc/5189/stat : 5189 (aspcud-paranoid) S 5188 5189 2059 34821 2220 4202496 667 34428 0 0 0 0 337 11 18 0 1 0 874549264 2666496 301 1283457024 134512640 135304128 4292294496 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/5189/statm: 651 301 253 194 0 37 0
[pid=5204] ppid=5189 vsize=56320 CPUtime=3.31
/proc/5204/stat : 5204 (clasp) R 5189 5189 2059 34821 2220 4202496 16517 0 0 0 324 7 0 0 24 0 1 0 874549266 57671680 12981 1283457024 134512640 136223643 4288947232 18446744073709551615 134650414 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/5204/statm: 14080 12981 223 418 0 13660 0
Current children cumulated CPU time (s) 6.79
Current children cumulated vsize (KiB) 58924

[startup+7.20741 s]
/proc/loadavg: 1.26 1.11 1.09 2/53 5206
/proc/meminfo: memFree=587312/1048576 swapFree=2073632/2097144
[pid=5189] ppid=5188 vsize=2604 CPUtime=7.2
/proc/5189/stat : 5189 (aspcud-paranoid) R 5188 5189 2059 34821 2220 4202496 719 51161 0 0 0 1 700 19 22 0 1 0 874549264 2666496 305 1283457024 134512640 135304128 4292294496 18446744073709551615 4294960130 0 65538 16902 1132543225 0 0 0 17 0 0 0 0
/proc/5189/statm: 651 305 257 194 0 37 0
Current children cumulated CPU time (s) 7.2
Current children cumulated vsize (KiB) 2604

Child status: 0
Real time (s): 7.23062
CPU time (s): 7.22845
CPU user time (s): 7.02444
CPU system time (s): 0.204012
CPU usage (%): 99.97
Max. virtual memory (cumulated for all children) (KiB): 105860

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 7.02444
system time used= 0.204012
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 55516
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= 2874
involuntary context switches= 2320

runsolver used 0 second user time and 0 second system time

The end