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/201103021629/uns-trendy-0.0004/rand384.cudf.heavy.log.runsolver ./uns-trendy-0.0004 /home/misc2010/data/misc4/heavy//rand384.cudf /home/misc2010/tmp/201103021629/uns-trendy-0.0004/rand384.cudf.heavy.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.46 1.15 0.97 5/39 11548
/proc/meminfo: memFree=311128/1048576 swapFree=0/0
[pid=11547] ppid=11546 vsize=1672 CPUtime=0.01
/proc/11547/stat : 11547 (uns-trendy-0.00) R 11546 11547 1684 34817 1684 4202496 209 0 0 0 0 1 0 0 25 0 1 0 68488904 1712128 130 1283457024 134512640 134593992 4287042208 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/11547/statm: 418 130 113 20 0 45 0
[pid=11548] ppid=11547 vsize=1672 CPUtime=0
/proc/11548/stat : 11548 (uns-trendy-0.00) R 11547 11547 1684 34817 1684 4202560 0 0 0 0 0 0 0 0 25 0 1 0 68488904 1712128 17 1283457024 134512640 134593992 4287042208 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/11548/statm: 418 17 0 20 0 45 0

[startup+0.161115 s]
/proc/loadavg: 1.46 1.15 0.97 5/39 11548
/proc/meminfo: memFree=311128/1048576 swapFree=0/0
[pid=11547] ppid=11546 vsize=1672 CPUtime=0.01
/proc/11547/stat : 11547 (uns-trendy-0.00) S 11546 11547 1684 34817 1684 4202496 217 0 0 0 0 1 0 0 25 0 1 0 68488904 1712128 130 1283457024 134512640 134593992 4287042208 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11547/statm: 418 130 113 20 0 45 0
[pid=11548] ppid=11547 vsize=15488 CPUtime=0.15
/proc/11548/stat : 11548 (cudfsolver-stat) R 11547 11547 1684 34817 1684 4202496 2254 0 0 0 15 0 0 0 25 0 1 0 68488904 15859712 2181 1283457024 134512640 141746657 4290129216 18446744073709551615 134599618 0 0 0 0 0 0 0 17 0 0 0 0
/proc/11548/statm: 3872 2181 149 1767 0 2082 0
Current children cumulated CPU time (s) 0.16
Current children cumulated vsize (KiB) 17160

[startup+0.211127 s]
/proc/loadavg: 1.46 1.15 0.97 5/39 11548
/proc/meminfo: memFree=311128/1048576 swapFree=0/0
[pid=11547] ppid=11546 vsize=1672 CPUtime=0.01
/proc/11547/stat : 11547 (uns-trendy-0.00) S 11546 11547 1684 34817 1684 4202496 217 0 0 0 0 1 0 0 25 0 1 0 68488904 1712128 130 1283457024 134512640 134593992 4287042208 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11547/statm: 418 130 113 20 0 45 0
[pid=11548] ppid=11547 vsize=17684 CPUtime=0.2
/proc/11548/stat : 11548 (cudfsolver-stat) R 11547 11547 1684 34817 1684 4202496 2809 0 0 0 20 0 0 0 25 0 1 0 68488904 18108416 2736 1283457024 134512640 141746657 4290129216 18446744073709551615 140889872 0 0 0 0 0 0 0 17 0 0 0 0
/proc/11548/statm: 4421 2736 149 1767 0 2631 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 19356

[startup+0.311154 s]
/proc/loadavg: 1.46 1.15 0.97 5/39 11548
/proc/meminfo: memFree=311128/1048576 swapFree=0/0
[pid=11547] ppid=11546 vsize=1672 CPUtime=0.01
/proc/11547/stat : 11547 (uns-trendy-0.00) S 11546 11547 1684 34817 1684 4202496 217 0 0 0 0 1 0 0 25 0 1 0 68488904 1712128 130 1283457024 134512640 134593992 4287042208 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11547/statm: 418 130 113 20 0 45 0
[pid=11548] ppid=11547 vsize=22216 CPUtime=0.3
/proc/11548/stat : 11548 (cudfsolver-stat) R 11547 11547 1684 34817 1684 4202496 3975 0 0 0 30 0 0 0 25 0 1 0 68488904 22749184 3870 1283457024 134512640 141746657 4290129216 18446744073709551615 140925740 0 0 0 0 0 0 0 17 0 0 0 0
/proc/11548/statm: 5554 3870 150 1767 0 3764 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 23888

[startup+0.711241 s]
/proc/loadavg: 1.46 1.15 0.97 5/39 11548
/proc/meminfo: memFree=311128/1048576 swapFree=0/0
[pid=11547] ppid=11546 vsize=1672 CPUtime=0.01
/proc/11547/stat : 11547 (uns-trendy-0.00) S 11546 11547 1684 34817 1684 4202496 217 0 0 0 0 1 0 0 25 0 1 0 68488904 1712128 130 1283457024 134512640 134593992 4287042208 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11547/statm: 418 130 113 20 0 45 0
[pid=11548] ppid=11547 vsize=38824 CPUtime=0.7
/proc/11548/stat : 11548 (cudfsolver-stat) R 11547 11547 1684 34817 1684 4202496 8200 0 0 0 66 4 0 0 25 0 1 0 68488904 39755776 7998 1283457024 134512640 141746657 4290129216 18446744073709551615 140908523 0 0 0 0 0 0 0 17 0 0 0 0
/proc/11548/statm: 9706 7998 150 1767 0 7916 0
Current children cumulated CPU time (s) 0.71
Current children cumulated vsize (KiB) 40496

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

[startup+0.811262 s]
/proc/loadavg: 1.46 1.15 0.97 5/39 11548
/proc/meminfo: memFree=311128/1048576 swapFree=0/0
[pid=11547] ppid=11546 vsize=1672 CPUtime=0.01
/proc/11547/stat : 11547 (uns-trendy-0.00) S 11546 11547 1684 34817 1684 4202496 217 0 0 0 0 1 0 0 25 0 1 0 68488904 1712128 130 1283457024 134512640 134593992 4287042208 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11547/statm: 418 130 113 20 0 45 0
[pid=11548] ppid=11547 vsize=42916 CPUtime=0.8
/proc/11548/stat : 11548 (cudfsolver-stat) R 11547 11547 1684 34817 1684 4202496 9210 0 0 0 76 4 0 0 25 0 1 0 68488904 43945984 9008 1283457024 134512640 141746657 4290129216 18446744073709551615 134625304 0 0 0 0 0 0 0 17 0 0 0 0
/proc/11548/statm: 10729 9008 150 1767 0 8939 0
Current children cumulated CPU time (s) 0.81
Current children cumulated vsize (KiB) 44588

[startup+1.21131 s]
/proc/loadavg: 1.46 1.15 0.97 2/40 11549
/proc/meminfo: memFree=263996/1048576 swapFree=0/0
[pid=11547] ppid=11546 vsize=1672 CPUtime=0.01
/proc/11547/stat : 11547 (uns-trendy-0.00) S 11546 11547 1684 34817 1684 4202496 217 0 0 0 0 1 0 0 25 0 1 0 68488904 1712128 130 1283457024 134512640 134593992 4287042208 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/11547/statm: 418 130 113 20 0 45 0
[pid=11548] ppid=11547 vsize=58748 CPUtime=1.2
/proc/11548/stat : 11548 (cudfsolver-stat) R 11547 11547 1684 34817 1684 4202496 13262 0 0 0 112 8 0 0 25 0 1 0 68488904 60157952 12930 1283457024 134512640 141746657 4290129216 18446744073709551615 134601848 0 0 0 0 0 0 0 17 0 0 0 0
/proc/11548/statm: 14687 12930 150 1767 0 12897 0
Current children cumulated CPU time (s) 1.21
Current children cumulated vsize (KiB) 60420

Child status: 139
Real time (s): 1.26879
CPU time (s): 1.27208
CPU user time (s): 1.16007
CPU system time (s): 0.112007
CPU usage (%): 100.259
Max. virtual memory (cumulated for all children) (KiB): 60420

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 1.16007
system time used= 0.112007
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 13958
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= 21

runsolver used 0 second user time and 0 second system time

The end