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/201108241238/aspcud-trendy-1.5/ed1cc19e-51b7-11e0-8436-00163e1e087d.cudf.dudf-real.log.runsolver ./aspcud-trendy-1.5 /home/misc2010/data/2011/dudf-real//ed1cc19e-51b7-11e0-8436-00163e1e087d.cudf /home/misc2010/tmp/201108241238/aspcud-trendy-1.5/ed1cc19e-51b7-11e0-8436-00163e1e087d.cudf.dudf-real.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.22 1.14 1.10 5/35 2044
/proc/meminfo: memFree=329184/1048576 swapFree=0/0
[pid=2042] ppid=2041 vsize=2588 CPUtime=0
/proc/2042/stat : 2042 (aspcud-trendy-1) S 2041 2042 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 5214131 2650112 279 1283457024 134512640 135304128 4293208128 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/2042/statm: 647 279 234 194 0 34 0
[pid=2043] ppid=2042 vsize=2588 CPUtime=0
/proc/2043/stat : 2043 (aspcud-trendy-1) R 2042 2042 1511 34817 1511 4202560 110 0 0 0 0 0 0 0 25 0 1 0 5214131 2650112 132 1283457024 134512640 135304128 4293208128 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/2043/statm: 647 132 86 194 0 34 0
[pid=2044] ppid=2043 vsize=2588 CPUtime=0
/proc/2044/stat : 2044 (aspcud-trendy-1) R 2043 2042 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 5214132 2650112 46 1283457024 134512640 135304128 4293208128 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/2044/statm: 647 46 0 194 0 34 0

[startup+0.184682 s]
/proc/loadavg: 1.22 1.14 1.10 5/35 2044
/proc/meminfo: memFree=329184/1048576 swapFree=0/0
[pid=2042] ppid=2041 vsize=2596 CPUtime=0.01
/proc/2042/stat : 2042 (aspcud-trendy-1) S 2041 2042 1511 34817 1511 4202496 623 2230 0 0 0 0 0 1 25 0 1 0 5214131 2658304 298 1283457024 134512640 135304128 4293208128 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/2042/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2596

[startup+0.20468 s]
/proc/loadavg: 1.22 1.14 1.10 5/35 2044
/proc/meminfo: memFree=329184/1048576 swapFree=0/0
[pid=2042] ppid=2041 vsize=2596 CPUtime=0.01
/proc/2042/stat : 2042 (aspcud-trendy-1) S 2041 2042 1511 34817 1511 4202496 623 2230 0 0 0 0 0 1 25 0 1 0 5214131 2658304 298 1283457024 134512640 135304128 4293208128 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/2042/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2596

[startup+0.304701 s]
/proc/loadavg: 1.22 1.14 1.10 5/35 2044
/proc/meminfo: memFree=329184/1048576 swapFree=0/0
[pid=2042] ppid=2041 vsize=2596 CPUtime=0.01
/proc/2042/stat : 2042 (aspcud-trendy-1) S 2041 2042 1511 34817 1511 4202496 623 2230 0 0 0 0 0 1 25 0 1 0 5214131 2658304 298 1283457024 134512640 135304128 4293208128 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/2042/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2596

[startup+0.704817 s]
/proc/loadavg: 1.22 1.14 1.10 5/35 2044
/proc/meminfo: memFree=329184/1048576 swapFree=0/0
[pid=2042] ppid=2041 vsize=2596 CPUtime=0.01
/proc/2042/stat : 2042 (aspcud-trendy-1) S 2041 2042 1511 34817 1511 4202496 623 2230 0 0 0 0 0 1 25 0 1 0 5214131 2658304 298 1283457024 134512640 135304128 4293208128 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/2042/statm: 649 298 251 194 0 36 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2596

[startup+1.50504 s]
/proc/loadavg: 1.22 1.14 1.10 2/37 2056
/proc/meminfo: memFree=307448/1048576 swapFree=0/0
[pid=2042] ppid=2041 vsize=2596 CPUtime=0.01
/proc/2042/stat : 2042 (aspcud-trendy-1) S 2041 2042 1511 34817 1511 4202496 623 2230 0 0 0 0 0 1 25 0 1 0 5214131 2658304 298 1283457024 134512640 135304128 4293208128 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/2042/statm: 649 298 251 194 0 36 0
[pid=2054] ppid=2042 vsize=4620 CPUtime=0.01
/proc/2054/stat : 2054 (clasp) S 2042 2042 1511 34817 1511 4202496 989 0 0 0 1 0 0 0 18 0 1 0 5214133 4730880 856 1283457024 134512640 136285277 4293070864 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0
/proc/2054/statm: 1155 856 177 433 0 720 0
[pid=2055] ppid=2042 vsize=6776 CPUtime=0.15
/proc/2055/stat : 2055 (gringo) R 2042 2042 1511 34817 1511 4202496 1594 0 0 0 14 1 0 0 18 0 1 0 5214133 6938624 1088 1283457024 134512640 136933539 4287097568 18446744073709551615 134750259 0 0 6 16384 0 0 0 17 0 0 0 0
/proc/2055/statm: 1694 1088 242 592 0 1099 0
[pid=2056] ppid=2042 vsize=30780 CPUtime=1.33
/proc/2056/stat : 2056 (cudf2lp) R 2042 2042 1511 34817 1511 4202496 10043 0 0 0 132 1 0 0 25 0 1 0 5214133 31518720 7490 1283457024 134512640 135786343 4291155680 18446744073709551615 135258574 0 0 6 0 0 0 0 17 0 0 0 0
/proc/2056/statm: 7695 7490 137 311 0 7382 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 44772

[startup+3.10552 s]
/proc/loadavg: 1.28 1.15 1.11 3/36 2056
/proc/meminfo: memFree=292460/1048576 swapFree=0/0
[pid=2042] ppid=2041 vsize=2596 CPUtime=2.22
/proc/2042/stat : 2042 (aspcud-trendy-1) S 2041 2042 1511 34817 1511 4202496 624 20134 0 0 0 0 209 13 15 0 1 0 5214131 2658304 298 1283457024 134512640 135304128 4293208128 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/2042/statm: 649 298 251 194 0 36 0
[pid=2054] ppid=2042 vsize=23472 CPUtime=0.88
/proc/2054/stat : 2054 (clasp) R 2042 2042 1511 34817 1511 4202496 6681 0 0 0 88 0 0 0 19 0 1 0 5214133 24035328 5594 1283457024 134512640 136285277 4293070864 18446744073709551615 134686770 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/2054/statm: 5868 5594 234 433 0 5433 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 26068

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

[startup+3.20555 s]
/proc/loadavg: 1.28 1.15 1.11 3/36 2056
/proc/meminfo: memFree=292460/1048576 swapFree=0/0
[pid=2042] ppid=2041 vsize=2596 CPUtime=2.22
/proc/2042/stat : 2042 (aspcud-trendy-1) S 2041 2042 1511 34817 1511 4202496 624 20134 0 0 0 0 209 13 15 0 1 0 5214131 2658304 298 1283457024 134512640 135304128 4293208128 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/2042/statm: 649 298 251 194 0 36 0
[pid=2054] ppid=2042 vsize=23472 CPUtime=0.98
/proc/2054/stat : 2054 (clasp) R 2042 2042 1511 34817 1511 4202496 6681 0 0 0 98 0 0 0 19 0 1 0 5214133 24035328 5594 1283457024 134512640 136285277 4293070864 18446744073709551615 134930675 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/2054/statm: 5868 5594 234 433 0 5433 0
Current children cumulated CPU time (s) 3.2
Current children cumulated vsize (KiB) 26068

[startup+3.30558 s]
/proc/loadavg: 1.28 1.15 1.11 2/35 2056
/proc/meminfo: memFree=307108/1048576 swapFree=0/0
[pid=2042] ppid=2041 vsize=2596 CPUtime=2.22
/proc/2042/stat : 2042 (aspcud-trendy-1) S 2041 2042 1511 34817 1511 4202496 624 20134 0 0 0 0 209 13 15 0 1 0 5214131 2658304 298 1283457024 134512640 135304128 4293208128 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0
/proc/2042/statm: 649 298 251 194 0 36 0
[pid=2054] ppid=2042 vsize=23472 CPUtime=1.08
/proc/2054/stat : 2054 (clasp) R 2042 2042 1511 34817 1511 4202496 6681 0 0 0 108 0 0 0 19 0 1 0 5214133 24035328 5594 1283457024 134512640 136285277 4293070864 18446744073709551615 134669462 0 0 6 18944 0 0 0 17 0 0 0 0
/proc/2054/statm: 5868 5594 234 433 0 5433 0
Current children cumulated CPU time (s) 3.3
Current children cumulated vsize (KiB) 26068

Child status: 0
Real time (s): 3.3754
CPU time (s): 3.37221
CPU user time (s): 3.2082
CPU system time (s): 0.16401
CPU usage (%): 99.9056
Max. virtual memory (cumulated for all children) (KiB): 50128

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.2082
system time used= 0.16401
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 31327
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= 831
involuntary context switches= 604

runsolver used 0 second user time and 0 second system time

The end