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/uns-trendy-0.0004/4047.cudf.caixa.log.runsolver ./uns-trendy-0.0004 /home/misc2010/data/misc4/caixa//4047.cudf /home/misc2010/tmp/201103031013/uns-trendy-0.0004/4047.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.73 1.68 1.68 5/34 1051
/proc/meminfo: memFree=306456/1048576 swapFree=0/0
[pid=1050] ppid=1049 vsize=1676 CPUtime=0
/proc/1050/stat : 1050 (uns-trendy-0.00) S 1049 1050 29493 34817 29493 4202496 215 0 0 0 0 0 0 0 18 0 1 0 76149108 1716224 130 1283457024 134512640 134593992 4286857856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1050/statm: 419 130 113 20 0 46 0
[pid=1051] ppid=1050 vsize=8356 CPUtime=0.02
/proc/1051/stat : 1051 (cudfsolver-stat) R 1050 1050 29493 34817 29493 4202496 465 0 0 0 2 0 0 0 25 0 1 0 76149108 8556544 419 1283457024 134512640 141746657 4290764256 18446744073709551615 140925762 0 0 0 0 0 0 0 17 0 0 0 0
/proc/1051/statm: 2089 419 147 1767 0 299 0

[startup+0.2137 s]
/proc/loadavg: 1.73 1.68 1.68 5/34 1051
/proc/meminfo: memFree=306456/1048576 swapFree=0/0
[pid=1050] ppid=1049 vsize=1676 CPUtime=0
/proc/1050/stat : 1050 (uns-trendy-0.00) S 1049 1050 29493 34817 29493 4202496 215 0 0 0 0 0 0 0 18 0 1 0 76149108 1716224 130 1283457024 134512640 134593992 4286857856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1050/statm: 419 130 113 20 0 46 0
[pid=1051] ppid=1050 vsize=21084 CPUtime=0.21
/proc/1051/stat : 1051 (cudfsolver-stat) R 1050 1050 29493 34817 29493 4202496 3701 0 0 0 19 2 0 0 25 0 1 0 76149108 21590016 3569 1283457024 134512640 141746657 4290764256 18446744073709551615 134625151 0 0 0 0 0 0 0 17 0 0 0 0
/proc/1051/statm: 5271 3569 148 1767 0 3481 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 22760

[startup+0.303719 s]
/proc/loadavg: 1.73 1.68 1.68 5/34 1051
/proc/meminfo: memFree=306456/1048576 swapFree=0/0
[pid=1050] ppid=1049 vsize=1676 CPUtime=0
/proc/1050/stat : 1050 (uns-trendy-0.00) S 1049 1050 29493 34817 29493 4202496 215 0 0 0 0 0 0 0 18 0 1 0 76149108 1716224 130 1283457024 134512640 134593992 4286857856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1050/statm: 419 130 113 20 0 46 0
[pid=1051] ppid=1050 vsize=26472 CPUtime=0.3
/proc/1051/stat : 1051 (cudfsolver-stat) R 1050 1050 29493 34817 29493 4202496 5128 0 0 0 27 3 0 0 25 0 1 0 76149108 27107328 4921 1283457024 134512640 141746657 4290764256 18446744073709551615 134636108 0 0 0 0 0 0 0 17 0 0 0 0
/proc/1051/statm: 6618 4921 148 1767 0 4828 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 28148

[startup+0.413745 s]
/proc/loadavg: 1.73 1.68 1.68 5/34 1051
/proc/meminfo: memFree=306456/1048576 swapFree=0/0
[pid=1050] ppid=1049 vsize=1676 CPUtime=0
/proc/1050/stat : 1050 (uns-trendy-0.00) S 1049 1050 29493 34817 29493 4202496 215 0 0 0 0 0 0 0 18 0 1 0 76149108 1716224 130 1283457024 134512640 134593992 4286857856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1050/statm: 419 130 113 20 0 46 0
[pid=1051] ppid=1050 vsize=33076 CPUtime=0.41
/proc/1051/stat : 1051 (cudfsolver-stat) R 1050 1050 29493 34817 29493 4202496 6812 0 0 0 38 3 0 0 25 0 1 0 76149108 33869824 6572 1283457024 134512640 141746657 4290764256 18446744073709551615 134632224 0 0 0 0 0 0 0 17 0 0 0 0
/proc/1051/statm: 8269 6572 148 1767 0 6479 0
Current children cumulated CPU time (s) 0.41
Current children cumulated vsize (KiB) 34752

[startup+0.703811 s]
/proc/loadavg: 1.73 1.68 1.68 5/34 1051
/proc/meminfo: memFree=306456/1048576 swapFree=0/0
[pid=1050] ppid=1049 vsize=1676 CPUtime=0
/proc/1050/stat : 1050 (uns-trendy-0.00) S 1049 1050 29493 34817 29493 4202496 215 0 0 0 0 0 0 0 18 0 1 0 76149108 1716224 130 1283457024 134512640 134593992 4286857856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1050/statm: 419 130 113 20 0 46 0
[pid=1051] ppid=1050 vsize=49444 CPUtime=0.7
/proc/1051/stat : 1051 (cudfsolver-stat) R 1050 1050 29493 34817 29493 4202496 11099 0 0 0 67 3 0 0 25 0 1 0 76149108 50630656 10598 1283457024 134512640 141746657 4290764256 18446744073709551615 140925753 0 0 0 0 0 0 0 17 0 0 0 0
/proc/1051/statm: 12361 10598 148 1767 0 10571 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 51120

[startup+1.50404 s]
/proc/loadavg: 1.73 1.68 1.68 2/35 1052
/proc/meminfo: memFree=244620/1048576 swapFree=0/0
[pid=1050] ppid=1049 vsize=1676 CPUtime=0
/proc/1050/stat : 1050 (uns-trendy-0.00) S 1049 1050 29493 34817 29493 4202496 215 0 0 0 0 0 0 0 18 0 1 0 76149108 1716224 130 1283457024 134512640 134593992 4286857856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1050/statm: 419 130 113 20 0 46 0
[pid=1051] ppid=1050 vsize=79248 CPUtime=1.5
/proc/1051/stat : 1051 (cudfsolver-stat) R 1050 1050 29493 34817 29493 4202496 17248 0 0 0 144 6 0 0 25 0 1 0 76149108 81149952 16587 1283457024 134512640 141746657 4290764256 18446744073709551615 136223314 0 0 0 0 0 0 0 17 0 0 0 0
/proc/1051/statm: 19812 16587 462 1767 0 17659 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 80924

[startup+3.10444 s]
/proc/loadavg: 1.67 1.66 1.68 2/35 1052
/proc/meminfo: memFree=241024/1048576 swapFree=0/0
[pid=1050] ppid=1049 vsize=1676 CPUtime=0
/proc/1050/stat : 1050 (uns-trendy-0.00) S 1049 1050 29493 34817 29493 4202496 215 0 0 0 0 0 0 0 18 0 1 0 76149108 1716224 130 1283457024 134512640 134593992 4286857856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1050/statm: 419 130 113 20 0 46 0
[pid=1051] ppid=1050 vsize=93684 CPUtime=3.1
/proc/1051/stat : 1051 (cudfsolver-stat) R 1050 1050 29493 34817 29493 4202496 19994 0 0 0 302 8 0 0 25 0 1 0 76149108 95932416 18474 1283457024 134512640 141746657 4290764256 18446744073709551615 135038916 0 0 0 0 0 0 0 17 0 0 0 0
/proc/1051/statm: 23421 18474 782 1767 0 21268 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 95360

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

[startup+3.30447 s]
/proc/loadavg: 1.67 1.66 1.68 2/35 1052
/proc/meminfo: memFree=241024/1048576 swapFree=0/0
[pid=1050] ppid=1049 vsize=1676 CPUtime=0
/proc/1050/stat : 1050 (uns-trendy-0.00) S 1049 1050 29493 34817 29493 4202496 215 0 0 0 0 0 0 0 18 0 1 0 76149108 1716224 130 1283457024 134512640 134593992 4286857856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1050/statm: 419 130 113 20 0 46 0
[pid=1051] ppid=1050 vsize=93684 CPUtime=3.3
/proc/1051/stat : 1051 (cudfsolver-stat) R 1050 1050 29493 34817 29493 4202496 21132 0 0 0 321 9 0 0 25 0 1 0 76149108 95932416 19612 1283457024 134512640 141746657 4290764256 18446744073709551615 134740111 0 0 0 0 0 0 0 17 0 0 0 0
/proc/1051/statm: 23421 19612 804 1767 0 21268 0
Current children cumulated CPU time (s) 3.3
Current children cumulated vsize (KiB) 95360

[startup+3.70456 s]
/proc/loadavg: 1.67 1.66 1.68 2/35 1052
/proc/meminfo: memFree=232096/1048576 swapFree=0/0
[pid=1050] ppid=1049 vsize=1676 CPUtime=0
/proc/1050/stat : 1050 (uns-trendy-0.00) S 1049 1050 29493 34817 29493 4202496 215 0 0 0 0 0 0 0 18 0 1 0 76149108 1716224 130 1283457024 134512640 134593992 4286857856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1050/statm: 419 130 113 20 0 46 0
[pid=1051] ppid=1050 vsize=93684 CPUtime=3.7
/proc/1051/stat : 1051 (cudfsolver-stat) R 1050 1050 29493 34817 29493 4202496 21132 0 0 0 361 9 0 0 25 0 1 0 76149108 95932416 19612 1283457024 134512640 141746657 4290764256 18446744073709551615 134739922 0 0 0 0 0 0 0 17 0 0 0 0
/proc/1051/statm: 23421 19612 804 1767 0 21268 0
Current children cumulated CPU time (s) 3.7
Current children cumulated vsize (KiB) 95360

[startup+4.10471 s]
/proc/loadavg: 1.67 1.66 1.68 2/35 1052
/proc/meminfo: memFree=232096/1048576 swapFree=0/0
[pid=1050] ppid=1049 vsize=1676 CPUtime=0
/proc/1050/stat : 1050 (uns-trendy-0.00) S 1049 1050 29493 34817 29493 4202496 215 0 0 0 0 0 0 0 18 0 1 0 76149108 1716224 130 1283457024 134512640 134593992 4286857856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1050/statm: 419 130 113 20 0 46 0
[pid=1051] ppid=1050 vsize=110068 CPUtime=4.1
/proc/1051/stat : 1051 (cudfsolver-stat) R 1050 1050 29493 34817 29493 4202496 23741 0 0 0 401 9 0 0 25 0 1 0 76149108 112709632 21653 1283457024 134512640 141746657 4290764256 18446744073709551615 136761264 0 0 0 0 0 0 0 17 0 0 0 0
/proc/1051/statm: 27517 21653 814 1767 0 25364 0
Current children cumulated CPU time (s) 4.1
Current children cumulated vsize (KiB) 111744

Child status: 0
Real time (s): 4.18896
CPU time (s): 4.18026
CPU user time (s): 4.07225
CPU system time (s): 0.108006
CPU usage (%): 99.7924
Max. virtual memory (cumulated for all children) (KiB): 111744

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.07225
system time used= 0.108006
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 23965
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= 3
involuntary context switches= 59

runsolver used 0 second user time and 0 second system time

The end