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-paranoid-0.0004/9bb87ab4-4c36-11df-bc1e-00163e7a6f5e.cudf.debian.log.runsolver ./uns-paranoid-0.0004 /home/misc2010/data/misc4/debian//9bb87ab4-4c36-11df-bc1e-00163e7a6f5e.cudf /home/misc2010/tmp/201103031013/uns-paranoid-0.0004/9bb87ab4-4c36-11df-bc1e-00163e7a6f5e.cudf.debian.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.06 1.08 1.04 3/35 21072
/proc/meminfo: memFree=690200/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=7700 CPUtime=0.01
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 290 0 0 0 1 0 0 0 25 0 1 0 75495558 7884800 247 1283457024 134512640 141746657 4294502736 18446744073709551615 140925765 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 1925 247 149 1767 0 135 0

[startup+0.176662 s]
/proc/loadavg: 1.06 1.08 1.04 3/35 21072
/proc/meminfo: memFree=690200/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=15780 CPUtime=0.17
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 2346 0 0 0 14 3 0 0 25 0 1 0 75495558 16158720 2274 1283457024 134512640 141746657 4294502736 18446744073709551615 134597375 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 3945 2274 149 1767 0 2155 0
Current children cumulated CPU time (s) 0.17
Current children cumulated vsize (KiB) 17452

[startup+0.206674 s]
/proc/loadavg: 1.06 1.08 1.04 3/35 21072
/proc/meminfo: memFree=690200/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=17040 CPUtime=0.21
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 2654 0 0 0 18 3 0 0 25 0 1 0 75495558 17448960 2582 1283457024 134512640 141746657 4294502736 18446744073709551615 134597377 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 4260 2582 149 1767 0 2470 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 18712

[startup+0.306688 s]
/proc/loadavg: 1.06 1.08 1.04 3/35 21072
/proc/meminfo: memFree=690200/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=21432 CPUtime=0.31
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 3754 0 0 0 28 3 0 0 25 0 1 0 75495558 21946368 3650 1283457024 134512640 141746657 4294502736 18446744073709551615 134598598 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 5358 3650 150 1767 0 3568 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 23104

[startup+0.706781 s]
/proc/loadavg: 1.06 1.08 1.04 3/35 21072
/proc/meminfo: memFree=690200/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=37512 CPUtime=0.7
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 7799 0 0 0 65 5 0 0 25 0 1 0 75495558 38412288 7634 1283457024 134512640 141746657 4294502736 18446744073709551615 140925132 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 9378 7634 150 1767 0 7588 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 39184

[startup+1.50696 s]
/proc/loadavg: 1.06 1.08 1.04 2/36 21073
/proc/meminfo: memFree=645576/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=66808 CPUtime=1.5
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 15321 0 0 0 140 10 0 0 25 0 1 0 75495558 68411392 14987 1283457024 134512640 141746657 4294502736 18446744073709551615 140908523 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 16702 14987 150 1767 0 14912 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 68480

[startup+3.10739 s]
/proc/loadavg: 1.06 1.08 1.04 2/36 21073
/proc/meminfo: memFree=602796/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=141316 CPUtime=3.11
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 29926 0 0 0 292 19 0 0 25 0 1 0 75495558 144707584 29060 1283457024 134512640 141746657 4294502736 18446744073709551615 138888594 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 35329 29060 438 1767 0 33176 0
Current children cumulated CPU time (s) 3.11
Current children cumulated vsize (KiB) 142988

[startup+6.30833 s]
/proc/loadavg: 1.06 1.08 1.04 2/36 21073
/proc/meminfo: memFree=573408/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=141316 CPUtime=6.31
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 30582 0 0 0 612 19 0 0 25 0 1 0 75495558 144707584 29716 1283457024 134512640 141746657 4294502736 18446744073709551615 138885303 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 35329 29716 468 1767 0 33176 0
Current children cumulated CPU time (s) 6.31
Current children cumulated vsize (KiB) 142988

[startup+12.7106 s]
/proc/loadavg: 1.05 1.08 1.04 2/36 21073
/proc/meminfo: memFree=548740/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=174716 CPUtime=12.7
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 38842 0 0 0 1246 24 0 0 25 0 1 0 75495558 178909184 36139 1283457024 134512640 141746657 4294502736 18446744073709551615 136761529 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 43679 36139 521 1767 0 41526 0
Current children cumulated CPU time (s) 12.7
Current children cumulated vsize (KiB) 176388

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

[startup+12.8107 s]
/proc/loadavg: 1.05 1.08 1.04 2/36 21073
/proc/meminfo: memFree=548740/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=174716 CPUtime=12.8
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 38849 0 0 0 1256 24 0 0 25 0 1 0 75495558 178909184 36146 1283457024 134512640 141746657 4294502736 18446744073709551615 136759658 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 43679 36146 521 1767 0 41526 0
Current children cumulated CPU time (s) 12.8
Current children cumulated vsize (KiB) 176388

[startup+16.0116 s]
/proc/loadavg: 1.05 1.08 1.04 2/36 21073
/proc/meminfo: memFree=532620/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=187420 CPUtime=16.01
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 43763 0 0 0 1575 26 0 0 25 0 1 0 75495558 191918080 40351 1283457024 134512640 141746657 4294502736 18446744073709551615 138888607 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 46855 40351 691 1767 0 44702 0
Current children cumulated CPU time (s) 16.01
Current children cumulated vsize (KiB) 189092

[startup+19.2024 s]
/proc/loadavg: 1.04 1.08 1.04 2/35 21073
/proc/meminfo: memFree=531016/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=179476 CPUtime=19.18
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 43917 0 0 0 1892 26 0 0 25 0 1 0 75495558 183783424 38558 1283457024 134512640 141746657 4294502736 18446744073709551615 136221508 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 44869 38558 691 1767 0 42716 0
Current children cumulated CPU time (s) 19.18
Current children cumulated vsize (KiB) 181148

[startup+20.0028 s]
/proc/loadavg: 1.04 1.08 1.04 2/35 21073
/proc/meminfo: memFree=532008/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=179476 CPUtime=19.98
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 46565 0 0 0 1972 26 0 0 25 0 1 0 75495558 183783424 41206 1283457024 134512640 141746657 4294502736 18446744073709551615 138911683 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 44869 41206 1398 1767 0 42716 0
Current children cumulated CPU time (s) 19.98
Current children cumulated vsize (KiB) 181148

[startup+20.803 s]
/proc/loadavg: 1.04 1.08 1.04 2/35 21073
/proc/meminfo: memFree=532008/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=179476 CPUtime=20.79
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202496 49085 0 0 0 2050 29 0 0 25 0 1 0 75495558 183783424 42592 1283457024 134512640 141746657 4294502736 18446744073709551615 135511665 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 44869 42592 703 1767 0 42716 0
Current children cumulated CPU time (s) 20.79
Current children cumulated vsize (KiB) 181148

[startup+21.0143 s]
/proc/loadavg: 1.04 1.08 1.04 2/35 21073
/proc/meminfo: memFree=522468/1048576 swapFree=0/0
[pid=21071] ppid=21070 vsize=1672 CPUtime=0
/proc/21071/stat : 21071 (uns-paranoid-0.) S 21070 21071 29493 34817 29493 4202496 214 0 0 0 0 0 0 0 25 0 1 0 75495558 1712128 129 1283457024 134512640 134593992 4289989936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21071/statm: 418 129 113 20 0 45 0
[pid=21072] ppid=21071 vsize=0 CPUtime=20.96
/proc/21072/stat : 21072 (cudfsolver-stat) R 21071 21071 29493 34817 29493 4202500 51073 0 3 0 2064 32 0 0 25 0 1 0 75495558 0 0 1283457024 0 0 0 0 0 0 0 0 0 0 0 0 17 0 0 0 0
/proc/21072/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 20.96
Current children cumulated vsize (KiB) 1672

Child status: 0
Real time (s): 21.0279
CPU time (s): 20.9733
CPU user time (s): 20.6453
CPU system time (s): 0.32802
CPU usage (%): 99.7402
Max. virtual memory (cumulated for all children) (KiB): 189092

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 20.6453
system time used= 0.32802
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 51288
page faults= 3
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 6
involuntary context switches= 267

runsolver used 0 second user time and 0 second system time

The end