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-paranoid-0.0004/rand190.cudf.heavy.log.runsolver ./uns-paranoid-0.0004 /home/misc2010/data/misc4/heavy//rand190.cudf /home/misc2010/tmp/201103021629/uns-paranoid-0.0004/rand190.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.08 1.04 0.78 3/40 6722
/proc/meminfo: memFree=322272/1048576 swapFree=0/0
[pid=6721] ppid=6720 vsize=1672 CPUtime=0
/proc/6721/stat : 6721 (uns-paranoid-0.) S 6720 6721 1684 34817 1684 4202496 215 0 0 0 0 0 0 0 25 0 1 0 68384832 1712128 129 1283457024 134512640 134593992 4294355360 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6721/statm: 418 129 113 20 0 45 0
[pid=6722] ppid=6721 vsize=8096 CPUtime=0.01
/proc/6722/stat : 6722 (cudfsolver-stat) R 6721 6721 1684 34817 1684 4202496 386 0 0 0 1 0 0 0 25 0 1 0 68384832 8290304 336 1283457024 134512640 141746657 4288002912 18446744073709551615 140925804 0 0 0 0 0 0 0 17 0 0 0 0
/proc/6722/statm: 2024 336 149 1767 0 234 0

[startup+0.192957 s]
/proc/loadavg: 1.08 1.04 0.78 3/40 6722
/proc/meminfo: memFree=322272/1048576 swapFree=0/0
[pid=6721] ppid=6720 vsize=1672 CPUtime=0
/proc/6721/stat : 6721 (uns-paranoid-0.) S 6720 6721 1684 34817 1684 4202496 215 0 0 0 0 0 0 0 25 0 1 0 68384832 1712128 129 1283457024 134512640 134593992 4294355360 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6721/statm: 418 129 113 20 0 45 0
[pid=6722] ppid=6721 vsize=16892 CPUtime=0.18
/proc/6722/stat : 6722 (cudfsolver-stat) R 6721 6721 1684 34817 1684 4202496 2608 0 0 0 16 2 0 0 25 0 1 0 68384832 17297408 2530 1283457024 134512640 141746657 4288002912 18446744073709551615 134637263 0 0 0 0 0 0 0 17 0 0 0 0
/proc/6722/statm: 4223 2530 149 1767 0 2433 0
Current children cumulated CPU time (s) 0.18
Current children cumulated vsize (KiB) 18564

[startup+0.212948 s]
/proc/loadavg: 1.08 1.04 0.78 3/40 6722
/proc/meminfo: memFree=322272/1048576 swapFree=0/0
[pid=6721] ppid=6720 vsize=1672 CPUtime=0
/proc/6721/stat : 6721 (uns-paranoid-0.) S 6720 6721 1684 34817 1684 4202496 215 0 0 0 0 0 0 0 25 0 1 0 68384832 1712128 129 1283457024 134512640 134593992 4294355360 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6721/statm: 418 129 113 20 0 45 0
[pid=6722] ppid=6721 vsize=17684 CPUtime=0.2
/proc/6722/stat : 6722 (cudfsolver-stat) R 6721 6721 1684 34817 1684 4202496 2819 0 0 0 18 2 0 0 25 0 1 0 68384832 18108416 2741 1283457024 134512640 141746657 4288002912 18446744073709551615 140925762 0 0 0 0 0 0 0 17 0 0 0 0
/proc/6722/statm: 4421 2741 149 1767 0 2631 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 19356

[startup+0.31297 s]
/proc/loadavg: 1.08 1.04 0.78 3/40 6722
/proc/meminfo: memFree=322272/1048576 swapFree=0/0
[pid=6721] ppid=6720 vsize=1672 CPUtime=0
/proc/6721/stat : 6721 (uns-paranoid-0.) S 6720 6721 1684 34817 1684 4202496 215 0 0 0 0 0 0 0 25 0 1 0 68384832 1712128 129 1283457024 134512640 134593992 4294355360 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6721/statm: 418 129 113 20 0 45 0
[pid=6722] ppid=6721 vsize=22216 CPUtime=0.3
/proc/6722/stat : 6722 (cudfsolver-stat) R 6721 6721 1684 34817 1684 4202496 3974 0 0 0 28 2 0 0 25 0 1 0 68384832 22749184 3864 1283457024 134512640 141746657 4288002912 18446744073709551615 140925748 0 0 0 0 0 0 0 17 0 0 0 0
/proc/6722/statm: 5554 3864 150 1767 0 3764 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 23888

[startup+0.713097 s]
/proc/loadavg: 1.08 1.04 0.78 3/40 6722
/proc/meminfo: memFree=322272/1048576 swapFree=0/0
[pid=6721] ppid=6720 vsize=1672 CPUtime=0
/proc/6721/stat : 6721 (uns-paranoid-0.) S 6720 6721 1684 34817 1684 4202496 215 0 0 0 0 0 0 0 25 0 1 0 68384832 1712128 129 1283457024 134512640 134593992 4294355360 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6721/statm: 418 129 113 20 0 45 0
[pid=6722] ppid=6721 vsize=38692 CPUtime=0.7
/proc/6722/stat : 6722 (cudfsolver-stat) R 6721 6721 1684 34817 1684 4202496 8167 0 0 0 66 4 0 0 25 0 1 0 68384832 39620608 7960 1283457024 134512640 141746657 4288002912 18446744073709551615 140925696 0 0 0 0 0 0 0 17 0 0 0 0
/proc/6722/statm: 9673 7960 150 1767 0 7883 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 40364

[startup+1.51326 s]
/proc/loadavg: 1.08 1.04 0.78 2/41 6723
/proc/meminfo: memFree=275656/1048576 swapFree=0/0
[pid=6721] ppid=6720 vsize=1672 CPUtime=0
/proc/6721/stat : 6721 (uns-paranoid-0.) S 6720 6721 1684 34817 1684 4202496 215 0 0 0 0 0 0 0 25 0 1 0 68384832 1712128 129 1283457024 134512640 134593992 4294355360 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6721/statm: 418 129 113 20 0 45 0
[pid=6722] ppid=6721 vsize=79736 CPUtime=1.51
/proc/6722/stat : 6722 (cudfsolver-stat) R 6721 6721 1684 34817 1684 4202496 16044 0 0 0 145 6 0 0 25 0 1 0 68384832 81649664 15642 1283457024 134512640 141746657 4288002912 18446744073709551615 136223314 0 0 0 0 0 0 0 17 0 0 0 0
/proc/6722/statm: 19934 15642 447 1767 0 17781 0
Current children cumulated CPU time (s) 1.51
Current children cumulated vsize (KiB) 81408

[startup+3.11375 s]
/proc/loadavg: 1.08 1.04 0.78 2/41 6723
/proc/meminfo: memFree=261148/1048576 swapFree=0/0
[pid=6721] ppid=6720 vsize=1672 CPUtime=0
/proc/6721/stat : 6721 (uns-paranoid-0.) S 6720 6721 1684 34817 1684 4202496 215 0 0 0 0 0 0 0 25 0 1 0 68384832 1712128 129 1283457024 134512640 134593992 4294355360 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6721/statm: 418 129 113 20 0 45 0
[pid=6722] ppid=6721 vsize=79736 CPUtime=3.11
/proc/6722/stat : 6722 (cudfsolver-stat) R 6721 6721 1684 34817 1684 4202496 17250 0 0 0 304 7 0 0 25 0 1 0 68384832 81649664 16846 1283457024 134512640 141746657 4288002912 18446744073709551615 138880142 0 0 0 0 0 0 0 17 0 0 0 0
/proc/6722/statm: 19934 16846 693 1767 0 17781 0
Current children cumulated CPU time (s) 3.11
Current children cumulated vsize (KiB) 81408

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

[startup+3.21378 s]
/proc/loadavg: 1.08 1.04 0.78 2/41 6723
/proc/meminfo: memFree=261148/1048576 swapFree=0/0
[pid=6721] ppid=6720 vsize=1672 CPUtime=0
/proc/6721/stat : 6721 (uns-paranoid-0.) S 6720 6721 1684 34817 1684 4202496 215 0 0 0 0 0 0 0 25 0 1 0 68384832 1712128 129 1283457024 134512640 134593992 4294355360 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6721/statm: 418 129 113 20 0 45 0
[pid=6722] ppid=6721 vsize=79736 CPUtime=3.21
/proc/6722/stat : 6722 (cudfsolver-stat) R 6721 6721 1684 34817 1684 4202496 17281 0 0 0 314 7 0 0 25 0 1 0 68384832 81649664 16877 1283457024 134512640 141746657 4288002912 18446744073709551615 134869629 0 0 0 0 0 0 0 17 0 0 0 0
/proc/6722/statm: 19934 16877 704 1767 0 17781 0
Current children cumulated CPU time (s) 3.21
Current children cumulated vsize (KiB) 81408

[startup+3.41386 s]
/proc/loadavg: 1.08 1.04 0.78 2/41 6724
/proc/meminfo: memFree=255692/1048576 swapFree=0/0
[pid=6721] ppid=6720 vsize=1672 CPUtime=0
/proc/6721/stat : 6721 (uns-paranoid-0.) S 6720 6721 1684 34817 1684 4202496 215 0 0 0 0 0 0 0 25 0 1 0 68384832 1712128 129 1283457024 134512640 134593992 4294355360 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6721/statm: 418 129 113 20 0 45 0
[pid=6722] ppid=6721 vsize=79736 CPUtime=3.41
/proc/6722/stat : 6722 (cudfsolver-stat) R 6721 6721 1684 34817 1684 4202496 18233 0 0 0 334 7 0 0 25 0 1 0 68384832 81649664 17829 1283457024 134512640 141746657 4288002912 18446744073709551615 134739922 0 0 0 0 0 0 0 17 0 0 0 0
/proc/6722/statm: 19934 17829 818 1767 0 17781 0
Current children cumulated CPU time (s) 3.41
Current children cumulated vsize (KiB) 81408

Child status: 0
Real time (s): 3.4794
CPU time (s): 3.47622
CPU user time (s): 3.39621
CPU system time (s): 0.080005
CPU usage (%): 99.9084
Max. virtual memory (cumulated for all children) (KiB): 81408

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

runsolver used 0 second user time and 0 second system time

The end