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/201103031013/aspcud-paranoid-1.4/4050.cudf.caixa.log.runsolver ./aspcud-paranoid-1.4 /home/misc2010/data/misc4/caixa//4050.cudf /home/misc2010/tmp/201103031013/aspcud-paranoid-1.4/4050.cudf.caixa.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.59 1.65 1.68 5/35 1896
/proc/meminfo: memFree=307612/1048576 swapFree=0/0
[pid=1894] ppid=1893 vsize=2584 CPUtime=0
/proc/1894/stat : 1894 (aspcud-paranoid) S 1893 1894 29493 34817 29493 4202496 372 0 0 0 0 0 0 0 18 0 1 0 76154988 2646016 279 1283457024 134512640 135304128 4293894448 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/1894/statm: 646 279 234 194 0 33 0
[pid=1895] ppid=1894 vsize=2584 CPUtime=0
/proc/1895/stat : 1895 (aspcud-paranoid) S 1894 1894 29493 34817 29493 4202560 115 0 0 0 0 0 0 0 25 0 1 0 76154989 2646016 131 1283457024 134512640 135304128 4293894448 18446744073709551615 4294960130 0 0 0 65538 18446744071564457842 0 0 17 0 0 0 0
/proc/1895/statm: 646 131 85 194 0 33 0
[pid=1896] ppid=1895 vsize=2584 CPUtime=0
/proc/1896/stat : 1896 (aspcud-paranoid) R 1895 1894 29493 34817 29493 4202560 127 0 0 0 0 0 0 0 25 0 1 0 76154989 2646016 150 1283457024 134512640 135304128 4293894448 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/1896/statm: 646 150 104 194 0 33 0
[pid=1897] ppid=1896 vsize=2584 CPUtime=0
/proc/1897/stat : 1897 (aspcud-paranoid) R 1896 1894 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 76154989 2646016 46 1283457024 134512640 135304128 4293894448 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/1897/statm: 646 46 0 194 0 33 0

[startup+0.154024 s]
/proc/loadavg: 1.59 1.65 1.68 5/35 1896
/proc/meminfo: memFree=307612/1048576 swapFree=0/0
[pid=1894] ppid=1893 vsize=2596 CPUtime=0
/proc/1894/stat : 1894 (aspcud-paranoid) S 1893 1894 29493 34817 29493 4202496 658 2944 0 0 0 0 0 0 25 0 1 0 76154988 2658304 299 1283457024 134512640 135304128 4293894448 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/1894/statm: 649 299 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.204026 s]
/proc/loadavg: 1.59 1.65 1.68 5/35 1896
/proc/meminfo: memFree=307612/1048576 swapFree=0/0
[pid=1894] ppid=1893 vsize=2596 CPUtime=0
/proc/1894/stat : 1894 (aspcud-paranoid) S 1893 1894 29493 34817 29493 4202496 658 2944 0 0 0 0 0 0 25 0 1 0 76154988 2658304 299 1283457024 134512640 135304128 4293894448 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/1894/statm: 649 299 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.304046 s]
/proc/loadavg: 1.59 1.65 1.68 5/35 1896
/proc/meminfo: memFree=307612/1048576 swapFree=0/0
[pid=1894] ppid=1893 vsize=2596 CPUtime=0
/proc/1894/stat : 1894 (aspcud-paranoid) S 1893 1894 29493 34817 29493 4202496 658 2944 0 0 0 0 0 0 25 0 1 0 76154988 2658304 299 1283457024 134512640 135304128 4293894448 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/1894/statm: 649 299 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+0.70411 s]
/proc/loadavg: 1.59 1.65 1.68 5/35 1896
/proc/meminfo: memFree=307612/1048576 swapFree=0/0
[pid=1894] ppid=1893 vsize=2596 CPUtime=0
/proc/1894/stat : 1894 (aspcud-paranoid) S 1893 1894 29493 34817 29493 4202496 658 2944 0 0 0 0 0 0 25 0 1 0 76154988 2658304 299 1283457024 134512640 135304128 4293894448 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/1894/statm: 649 299 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

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

[startup+0.804128 s]
/proc/loadavg: 1.59 1.65 1.68 5/35 1896
/proc/meminfo: memFree=307612/1048576 swapFree=0/0
[pid=1894] ppid=1893 vsize=2596 CPUtime=0
/proc/1894/stat : 1894 (aspcud-paranoid) S 1893 1894 29493 34817 29493 4202496 658 2944 0 0 0 0 0 0 25 0 1 0 76154988 2658304 299 1283457024 134512640 135304128 4293894448 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/1894/statm: 649 299 251 194 0 36 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2596

[startup+1.2042 s]
/proc/loadavg: 1.59 1.65 1.68 2/36 1911
/proc/meminfo: memFree=284544/1048576 swapFree=0/0
[pid=1894] ppid=1893 vsize=2596 CPUtime=0.62
/proc/1894/stat : 1894 (aspcud-paranoid) S 1893 1894 29493 34817 29493 4202496 658 10814 0 0 0 0 60 2 18 0 1 0 76154988 2658304 299 1283457024 134512640 135304128 4293894448 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/1894/statm: 649 299 251 194 0 36 0
[pid=1909] ppid=1894 vsize=12644 CPUtime=0.09
/proc/1909/stat : 1909 (clasp) S 1894 1894 29493 34817 29493 4202496 3319 0 0 0 7 2 0 0 18 0 1 0 76154990 12947456 2801 1283457024 134512640 136241547 4289385616 18446744073709551615 135683070 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/1909/statm: 3161 2801 175 423 0 2736 0
[pid=1910] ppid=1894 vsize=19868 CPUtime=0.46
/proc/1910/stat : 1910 (gringo) R 1894 1894 29493 34817 29493 4202496 4796 0 0 0 44 2 0 0 20 0 1 0 76154990 20344832 4035 1283457024 134512640 136959103 4290502176 18446744073709551615 134668244 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/1910/statm: 4967 4035 256 598 0 4366 0
Current children cumulated CPU time (s) 1.17
Current children cumulated vsize (KiB) 35108

[startup+1.30424 s]
/proc/loadavg: 1.59 1.65 1.68 2/36 1911
/proc/meminfo: memFree=284544/1048576 swapFree=0/0
[pid=1894] ppid=1893 vsize=2596 CPUtime=1.17
/proc/1894/stat : 1894 (aspcud-paranoid) S 1893 1894 29493 34817 29493 4202496 658 16012 0 0 0 0 111 6 15 0 1 0 76154988 2658304 299 1283457024 134512640 135304128 4293894448 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/1894/statm: 649 299 251 194 0 36 0
[pid=1909] ppid=1894 vsize=13996 CPUtime=0.11
/proc/1909/stat : 1909 (clasp) R 1894 1894 29493 34817 29493 4202496 3937 0 0 0 9 2 0 0 18 0 1 0 76154990 14331904 3214 1283457024 134512640 136241547 4289385616 18446744073709551615 135632229 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/1909/statm: 3499 3214 188 423 0 3074 0
Current children cumulated CPU time (s) 1.28
Current children cumulated vsize (KiB) 16592

Child status: 0
Real time (s): 1.37248
CPU time (s): 1.36008
CPU user time (s): 1.24408
CPU system time (s): 0.116007
CPU usage (%): 99.0968
Max. virtual memory (cumulated for all children) (KiB): 35108

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 1.24408
system time used= 0.116007
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 33777
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= 1155
involuntary context switches= 1151

runsolver used 0 second user time and 0.012 second system time

The end