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/rand0695fb.cudf.impossible.log.runsolver ./aspcud-paranoid-1.3 /home/misc2010/data/2010/impossible//rand0695fb.cudf /home/misc2010/tmp/201012061533/aspcud-paranoid-1.3/rand0695fb.cudf.impossible.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.71 1.35 0.86 4/52 3422
/proc/meminfo: memFree=313168/1048576 swapFree=2095580/2097144
[pid=3420] ppid=3419 vsize=2588 CPUtime=0
/proc/3420/stat : 3420 (aspcud-paranoid) S 3419 3420 2059 34821 2220 4202496 375 0 0 0 0 0 0 0 25 0 1 0 874364657 2650112 282 1283457024 134512640 135304128 4289062016 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/3420/statm: 647 282 237 194 0 33 0
[pid=3421] ppid=3420 vsize=2588 CPUtime=0
/proc/3421/stat : 3421 (aspcud-paranoid) R 3420 3420 2059 34821 2220 4202560 105 0 0 0 0 0 0 0 25 0 1 0 874364658 2650112 128 1283457024 134512640 135304128 4289062016 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/3421/statm: 647 128 82 194 0 33 0
[pid=3422] ppid=3421 vsize=2588 CPUtime=0
/proc/3422/stat : 3422 (aspcud-paranoid) R 3421 3420 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 1 0 874364658 2650112 46 1283457024 134512640 135304128 4289062016 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/3422/statm: 647 46 0 194 0 33 0

[startup+0.126311 s]
/proc/loadavg: 1.71 1.35 0.86 4/52 3422
/proc/meminfo: memFree=313168/1048576 swapFree=2095580/2097144
[pid=3420] ppid=3419 vsize=2600 CPUtime=0.01
/proc/3420/stat : 3420 (aspcud-paranoid) S 3419 3420 2059 34821 2220 4202496 664 2926 0 0 0 0 0 1 25 0 1 0 874364657 2662400 301 1283457024 134512640 135304128 4289062016 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3420/statm: 650 301 253 194 0 36 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2600

[startup+0.206335 s]
/proc/loadavg: 1.71 1.35 0.86 4/52 3422
/proc/meminfo: memFree=313168/1048576 swapFree=2095580/2097144
[pid=3420] ppid=3419 vsize=2600 CPUtime=0.01
/proc/3420/stat : 3420 (aspcud-paranoid) S 3419 3420 2059 34821 2220 4202496 664 2926 0 0 0 0 0 1 25 0 1 0 874364657 2662400 301 1283457024 134512640 135304128 4289062016 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3420/statm: 650 301 253 194 0 36 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2600

[startup+0.306347 s]
/proc/loadavg: 1.71 1.35 0.86 4/52 3422
/proc/meminfo: memFree=313168/1048576 swapFree=2095580/2097144
[pid=3420] ppid=3419 vsize=2600 CPUtime=0.01
/proc/3420/stat : 3420 (aspcud-paranoid) S 3419 3420 2059 34821 2220 4202496 664 2926 0 0 0 0 0 1 25 0 1 0 874364657 2662400 301 1283457024 134512640 135304128 4289062016 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3420/statm: 650 301 253 194 0 36 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2600

[startup+0.706433 s]
/proc/loadavg: 1.71 1.35 0.86 4/52 3422
/proc/meminfo: memFree=313168/1048576 swapFree=2095580/2097144
[pid=3420] ppid=3419 vsize=2600 CPUtime=0.01
/proc/3420/stat : 3420 (aspcud-paranoid) S 3419 3420 2059 34821 2220 4202496 664 2926 0 0 0 0 0 1 25 0 1 0 874364657 2662400 301 1283457024 134512640 135304128 4289062016 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3420/statm: 650 301 253 194 0 36 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2600

[startup+1.50667 s]
/proc/loadavg: 1.71 1.35 0.86 2/54 3437
/proc/meminfo: memFree=278200/1048576 swapFree=2095580/2097144
[pid=3420] ppid=3419 vsize=2600 CPUtime=0.01
/proc/3420/stat : 3420 (aspcud-paranoid) S 3419 3420 2059 34821 2220 4202496 664 2926 0 0 0 0 0 1 25 0 1 0 874364657 2662400 301 1283457024 134512640 135304128 4289062016 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3420/statm: 650 301 253 194 0 36 0
[pid=3435] ppid=3420 vsize=1868 CPUtime=0
/proc/3435/stat : 3435 (clasp) S 3420 3420 2059 34821 2220 4202496 286 0 0 0 0 0 0 0 25 0 1 0 874364659 1912832 153 1283457024 134512640 136223643 4289201248 18446744073709551615 135666734 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/3435/statm: 467 153 138 418 0 47 0
[pid=3436] ppid=3420 vsize=2612 CPUtime=0
/proc/3436/stat : 3436 (gringo) S 3420 3420 2059 34821 2220 4202496 408 0 0 0 0 0 0 0 25 0 1 0 874364659 2674688 277 1283457024 134512640 136959103 4293241008 18446744073709551615 135656590 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0
/proc/3436/statm: 653 277 247 598 0 52 0
[pid=3437] ppid=3420 vsize=61432 CPUtime=1.48
/proc/3437/stat : 3437 (cudf2lp) R 3420 3420 2059 34821 2220 4202496 16724 0 0 0 142 6 0 0 25 0 1 0 874364659 62906368 14569 1283457024 134512640 135749571 4287720336 18446744073709551615 135198528 0 0 6 0 0 0 0 17 0 0 0 0
/proc/3437/statm: 15358 14569 127 302 0 15054 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 68512

[startup+3.10701 s]
/proc/loadavg: 1.71 1.35 0.86 2/54 3437
/proc/meminfo: memFree=238148/1048576 swapFree=2095580/2097144
[pid=3420] ppid=3419 vsize=2600 CPUtime=2.1
/proc/3420/stat : 3420 (aspcud-paranoid) S 3419 3420 2059 34821 2220 4202496 665 21933 0 0 0 0 200 10 18 0 1 0 874364657 2662400 301 1283457024 134512640 135304128 4289062016 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3420/statm: 650 301 253 194 0 36 0
[pid=3435] ppid=3420 vsize=22108 CPUtime=0.1
/proc/3435/stat : 3435 (clasp) R 3420 3420 2059 34821 2220 4202496 6140 0 0 0 7 3 0 0 18 0 1 0 874364659 22638592 5146 1283457024 134512640 136223643 4289201248 18446744073709551615 135666734 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/3435/statm: 5527 5146 174 418 0 5107 0
[pid=3436] ppid=3420 vsize=39692 CPUtime=0.9
/proc/3436/stat : 3436 (gringo) R 3420 3420 2059 34821 2220 4202496 10863 0 0 0 84 6 0 0 18 0 1 0 874364659 40644608 7437 1283457024 134512640 136959103 4293241008 18446744073709551615 134737955 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/3436/statm: 9923 7437 256 598 0 9322 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 64400

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

[startup+3.20704 s]
/proc/loadavg: 1.71 1.35 0.86 2/54 3437
/proc/meminfo: memFree=238148/1048576 swapFree=2095580/2097144
[pid=3420] ppid=3419 vsize=2600 CPUtime=2.1
/proc/3420/stat : 3420 (aspcud-paranoid) S 3419 3420 2059 34821 2220 4202496 665 21933 0 0 0 0 200 10 18 0 1 0 874364657 2662400 301 1283457024 134512640 135304128 4289062016 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3420/statm: 650 301 253 194 0 36 0
[pid=3435] ppid=3420 vsize=22768 CPUtime=0.11
/proc/3435/stat : 3435 (clasp) R 3420 3420 2059 34821 2220 4202496 6308 0 0 0 8 3 0 0 18 0 1 0 874364659 23314432 5314 1283457024 134512640 136223643 4289201248 18446744073709551615 135666734 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/3435/statm: 5692 5314 174 418 0 5272 0
[pid=3436] ppid=3420 vsize=41880 CPUtime=0.99
/proc/3436/stat : 3436 (gringo) R 3420 3420 2059 34821 2220 4202496 11458 0 0 0 93 6 0 0 18 0 1 0 874364659 42885120 7903 1283457024 134512640 136959103 4293241008 18446744073709551615 134901494 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/3436/statm: 10470 7903 256 598 0 9869 0
Current children cumulated CPU time (s) 3.2
Current children cumulated vsize (KiB) 67248

[startup+4.00732 s]
/proc/loadavg: 1.71 1.35 0.86 3/53 3437
/proc/meminfo: memFree=259120/1048576 swapFree=2095580/2097144
[pid=3420] ppid=3419 vsize=2600 CPUtime=3.33
/proc/3420/stat : 3420 (aspcud-paranoid) S 3419 3420 2059 34821 2220 4202496 665 34512 0 0 0 0 316 17 18 0 1 0 874364657 2662400 301 1283457024 134512640 135304128 4289062016 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3420/statm: 650 301 253 194 0 36 0
[pid=3435] ppid=3420 vsize=36120 CPUtime=0.65
/proc/3435/stat : 3435 (clasp) R 3420 3420 2059 34821 2220 4202496 10261 0 0 0 58 7 0 0 18 0 1 0 874364659 36986880 8262 1283457024 134512640 136223643 4289201248 18446744073709551615 135671233 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/3435/statm: 9030 8262 217 418 0 8610 0
Current children cumulated CPU time (s) 3.98
Current children cumulated vsize (KiB) 38720

[startup+4.20722 s]
/proc/loadavg: 1.71 1.35 0.86 3/53 3437
/proc/meminfo: memFree=259120/1048576 swapFree=2095580/2097144
[pid=3420] ppid=3419 vsize=2600 CPUtime=3.33
/proc/3420/stat : 3420 (aspcud-paranoid) S 3419 3420 2059 34821 2220 4202496 665 34512 0 0 0 0 316 17 18 0 1 0 874364657 2662400 301 1283457024 134512640 135304128 4289062016 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/3420/statm: 650 301 253 194 0 36 0
[pid=3435] ppid=3420 vsize=36120 CPUtime=0.85
/proc/3435/stat : 3435 (clasp) R 3420 3420 2059 34821 2220 4202496 10277 0 0 0 78 7 0 0 18 0 1 0 874364659 36986880 8278 1283457024 134512640 136223643 4289201248 18446744073709551615 134931129 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/3435/statm: 9030 8278 223 418 0 8610 0
Current children cumulated CPU time (s) 4.18
Current children cumulated vsize (KiB) 38720

Child status: 0
Real time (s): 4.25148
CPU time (s): 4.24427
CPU user time (s): 3.97225
CPU system time (s): 0.272017
CPU usage (%): 99.8304
Max. virtual memory (cumulated for all children) (KiB): 95264

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.97225
system time used= 0.272017
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 49032
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= 1542
involuntary context switches= 1098

runsolver used 0 second user time and 0 second system time

The end