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/apt-pbo-trendy-1.0.8/817.cudf.caixa.log.runsolver ./apt-pbo-trendy-1.0.8 /home/misc2010/data/misc4/caixa//817.cudf /home/misc2010/tmp/201103031013/apt-pbo-trendy-1.0.8/817.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.83 1.76 1.72 5/36 303
/proc/meminfo: memFree=308424/1048576 swapFree=0/0
[pid=301] ppid=300 vsize=1672 CPUtime=0
/proc/301/stat : 301 (sh) S 300 301 29493 34817 29493 4202496 220 174 0 0 0 0 0 0 18 0 1 0 76370496 1712128 128 1283457024 134512640 134593992 4290760256 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/301/statm: 418 128 112 20 0 45 0
[pid=303] ppid=301 vsize=4220 CPUtime=0.02
/proc/303/stat : 303 (apt-pbo) R 301 301 29493 34817 29493 4202496 726 0 0 0 2 0 0 0 25 0 1 0 76370496 4321280 674 1283457024 134512640 135745756 4291272160 18446744073709551615 134813003 0 0 128 0 0 0 0 17 0 0 0 0
/proc/303/statm: 1055 674 406 302 0 319 0

[startup+0.127421 s]
/proc/loadavg: 1.83 1.76 1.72 5/36 303
/proc/meminfo: memFree=308424/1048576 swapFree=0/0
[pid=301] ppid=300 vsize=1672 CPUtime=0
/proc/301/stat : 301 (sh) S 300 301 29493 34817 29493 4202496 220 174 0 0 0 0 0 0 18 0 1 0 76370496 1712128 128 1283457024 134512640 134593992 4290760256 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/301/statm: 418 128 112 20 0 45 0
[pid=303] ppid=301 vsize=8228 CPUtime=0.04
/proc/303/stat : 303 (apt-pbo) R 301 301 29493 34817 29493 4202496 1558 409 0 0 4 0 0 0 25 0 1 0 76370496 8425472 1400 1283457024 134512640 135745756 4291272160 18446744073709551615 4294960130 0 0 128 0 0 0 0 17 0 0 0 0
/proc/303/statm: 2057 1400 648 302 0 790 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9900

[startup+0.207439 s]
/proc/loadavg: 1.83 1.76 1.72 5/36 303
/proc/meminfo: memFree=308424/1048576 swapFree=0/0
[pid=301] ppid=300 vsize=1672 CPUtime=0
/proc/301/stat : 301 (sh) S 300 301 29493 34817 29493 4202496 220 174 0 0 0 0 0 0 18 0 1 0 76370496 1712128 128 1283457024 134512640 134593992 4290760256 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/301/statm: 418 128 112 20 0 45 0
[pid=303] ppid=301 vsize=8228 CPUtime=0.04
/proc/303/stat : 303 (apt-pbo) S 301 301 29493 34817 29493 4202496 1576 409 0 0 4 0 0 0 25 0 1 0 76370496 8425472 1400 1283457024 134512640 135745756 4291272160 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/303/statm: 2057 1400 648 302 0 790 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9900

[startup+0.307457 s]
/proc/loadavg: 1.83 1.76 1.72 5/36 303
/proc/meminfo: memFree=308424/1048576 swapFree=0/0
[pid=301] ppid=300 vsize=1672 CPUtime=0
/proc/301/stat : 301 (sh) S 300 301 29493 34817 29493 4202496 220 174 0 0 0 0 0 0 18 0 1 0 76370496 1712128 128 1283457024 134512640 134593992 4290760256 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/301/statm: 418 128 112 20 0 45 0
[pid=303] ppid=301 vsize=8228 CPUtime=0.04
/proc/303/stat : 303 (apt-pbo) S 301 301 29493 34817 29493 4202496 1576 409 0 0 4 0 0 0 25 0 1 0 76370496 8425472 1400 1283457024 134512640 135745756 4291272160 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/303/statm: 2057 1400 648 302 0 790 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9900

[startup+0.707552 s]
/proc/loadavg: 1.83 1.76 1.72 5/36 303
/proc/meminfo: memFree=308424/1048576 swapFree=0/0
[pid=301] ppid=300 vsize=1672 CPUtime=0
/proc/301/stat : 301 (sh) S 300 301 29493 34817 29493 4202496 220 174 0 0 0 0 0 0 18 0 1 0 76370496 1712128 128 1283457024 134512640 134593992 4290760256 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/301/statm: 418 128 112 20 0 45 0
[pid=303] ppid=301 vsize=8228 CPUtime=0.04
/proc/303/stat : 303 (apt-pbo) S 301 301 29493 34817 29493 4202496 1576 409 0 0 4 0 0 0 25 0 1 0 76370496 8425472 1400 1283457024 134512640 135745756 4291272160 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/303/statm: 2057 1400 648 302 0 790 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9900

[startup+1.50772 s]
/proc/loadavg: 1.83 1.76 1.72 2/38 307
/proc/meminfo: memFree=279540/1048576 swapFree=0/0
[pid=301] ppid=300 vsize=1672 CPUtime=0
/proc/301/stat : 301 (sh) S 300 301 29493 34817 29493 4202496 220 174 0 0 0 0 0 0 18 0 1 0 76370496 1712128 128 1283457024 134512640 134593992 4290760256 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/301/statm: 418 128 112 20 0 45 0
[pid=303] ppid=301 vsize=8228 CPUtime=0.04
/proc/303/stat : 303 (apt-pbo) S 301 301 29493 34817 29493 4202496 1576 409 0 0 4 0 0 0 25 0 1 0 76370496 8425472 1400 1283457024 134512640 135745756 4291272160 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/303/statm: 2057 1400 648 302 0 790 0
[pid=307] ppid=303 vsize=37272 CPUtime=1.46
/proc/307/stat : 307 (cudftodeb.nativ) R 303 301 29493 34817 29493 4202496 8981 0 0 0 143 3 0 0 25 0 1 0 76370501 38166528 8902 1283457024 134512640 135029684 4287486624 18446744073709551615 134967018 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/307/statm: 9318 8902 246 127 0 8699 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 47172

[startup+3.10805 s]
/proc/loadavg: 1.83 1.76 1.72 2/38 307
/proc/meminfo: memFree=261436/1048576 swapFree=0/0
[pid=301] ppid=300 vsize=1672 CPUtime=0
/proc/301/stat : 301 (sh) S 300 301 29493 34817 29493 4202496 220 174 0 0 0 0 0 0 18 0 1 0 76370496 1712128 128 1283457024 134512640 134593992 4290760256 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/301/statm: 418 128 112 20 0 45 0
[pid=303] ppid=301 vsize=8228 CPUtime=0.04
/proc/303/stat : 303 (apt-pbo) S 301 301 29493 34817 29493 4202496 1576 409 0 0 4 0 0 0 25 0 1 0 76370496 8425472 1400 1283457024 134512640 135745756 4291272160 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/303/statm: 2057 1400 648 302 0 790 0
[pid=307] ppid=303 vsize=65496 CPUtime=3.05
/proc/307/stat : 307 (cudftodeb.nativ) R 303 301 29493 34817 29493 4202496 16003 0 0 0 287 18 0 0 25 0 1 0 76370501 67067904 15924 1283457024 134512640 135029684 4287486624 18446744073709551615 134967018 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/307/statm: 16374 15924 258 127 0 15755 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 75396

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

[startup+3.20806 s]
/proc/loadavg: 1.83 1.76 1.72 2/38 307
/proc/meminfo: memFree=261436/1048576 swapFree=0/0
[pid=301] ppid=300 vsize=1672 CPUtime=0
/proc/301/stat : 301 (sh) S 300 301 29493 34817 29493 4202496 220 174 0 0 0 0 0 0 18 0 1 0 76370496 1712128 128 1283457024 134512640 134593992 4290760256 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/301/statm: 418 128 112 20 0 45 0
[pid=303] ppid=301 vsize=8228 CPUtime=0.04
/proc/303/stat : 303 (apt-pbo) S 301 301 29493 34817 29493 4202496 1576 409 0 0 4 0 0 0 25 0 1 0 76370496 8425472 1400 1283457024 134512640 135745756 4291272160 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/303/statm: 2057 1400 648 302 0 790 0
[pid=307] ppid=303 vsize=68016 CPUtime=3.15
/proc/307/stat : 307 (cudftodeb.nativ) R 303 301 29493 34817 29493 4202496 16581 0 0 0 296 19 0 0 25 0 1 0 76370501 69648384 16502 1283457024 134512640 135029684 4287486624 18446744073709551615 134969984 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/307/statm: 17004 16502 258 127 0 16385 0
Current children cumulated CPU time (s) 3.19
Current children cumulated vsize (KiB) 77916

[startup+4.80842 s]
/proc/loadavg: 1.76 1.74 1.71 2/38 307
/proc/meminfo: memFree=243828/1048576 swapFree=0/0
[pid=301] ppid=300 vsize=1672 CPUtime=0
/proc/301/stat : 301 (sh) S 300 301 29493 34817 29493 4202496 220 174 0 0 0 0 0 0 18 0 1 0 76370496 1712128 128 1283457024 134512640 134593992 4290760256 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/301/statm: 418 128 112 20 0 45 0
[pid=303] ppid=301 vsize=8228 CPUtime=4.56
/proc/303/stat : 303 (apt-pbo) S 301 301 29493 34817 29493 4202496 1750 17671 0 0 4 0 406 46 18 0 1 0 76370496 8425472 1426 1283457024 134512640 135745756 4291272160 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/303/statm: 2057 1426 653 302 0 790 0
Current children cumulated CPU time (s) 4.56
Current children cumulated vsize (KiB) 9900

[startup+5.20768 s]
/proc/loadavg: 1.76 1.74 1.71 2/38 307
/proc/meminfo: memFree=243828/1048576 swapFree=0/0
[pid=301] ppid=300 vsize=1672 CPUtime=0
/proc/301/stat : 301 (sh) S 300 301 29493 34817 29493 4202496 220 174 0 0 0 0 0 0 18 0 1 0 76370496 1712128 128 1283457024 134512640 134593992 4290760256 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/301/statm: 418 128 112 20 0 45 0
[pid=303] ppid=301 vsize=8228 CPUtime=4.56
/proc/303/stat : 303 (apt-pbo) S 301 301 29493 34817 29493 4202496 1750 17671 0 0 4 0 406 46 18 0 1 0 76370496 8425472 1426 1283457024 134512640 135745756 4291272160 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/303/statm: 2057 1426 653 302 0 790 0
Current children cumulated CPU time (s) 4.56
Current children cumulated vsize (KiB) 9900

[startup+5.40773 s]
/proc/loadavg: 1.76 1.74 1.71 2/38 307
/proc/meminfo: memFree=243828/1048576 swapFree=0/0
[pid=301] ppid=300 vsize=1672 CPUtime=0
/proc/301/stat : 301 (sh) S 300 301 29493 34817 29493 4202496 220 174 0 0 0 0 0 0 18 0 1 0 76370496 1712128 128 1283457024 134512640 134593992 4290760256 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/301/statm: 418 128 112 20 0 45 0
[pid=303] ppid=301 vsize=8228 CPUtime=4.56
/proc/303/stat : 303 (apt-pbo) S 301 301 29493 34817 29493 4202496 1750 17671 0 0 4 0 406 46 18 0 1 0 76370496 8425472 1426 1283457024 134512640 135745756 4291272160 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/303/statm: 2057 1426 653 302 0 790 0
Current children cumulated CPU time (s) 4.56
Current children cumulated vsize (KiB) 9900

[startup+5.50773 s]
/proc/loadavg: 1.76 1.74 1.71 1/39 315
/proc/meminfo: memFree=279396/1048576 swapFree=0/0
[pid=301] ppid=300 vsize=1672 CPUtime=0
/proc/301/stat : 301 (sh) S 300 301 29493 34817 29493 4202496 220 174 0 0 0 0 0 0 18 0 1 0 76370496 1712128 128 1283457024 134512640 134593992 4290760256 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/301/statm: 418 128 112 20 0 45 0
[pid=303] ppid=301 vsize=8228 CPUtime=4.56
/proc/303/stat : 303 (apt-pbo) S 301 301 29493 34817 29493 4202496 1750 17671 0 0 4 0 406 46 18 0 1 0 76370496 8425472 1426 1283457024 134512640 135745756 4291272160 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/303/statm: 2057 1426 653 302 0 790 0
[pid=308] ppid=303 vsize=2572 CPUtime=0.01
/proc/308/stat : 308 (apt-get.sh) S 303 301 29493 34817 29493 4202496 406 491 0 0 0 1 0 0 18 0 1 0 76370954 2633728 273 1283457024 134512640 135304128 4294859184 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/308/statm: 643 273 232 194 0 30 0
[pid=311] ppid=308 vsize=52748 CPUtime=0.24
/proc/311/stat : 311 (apt-get) D 308 301 29493 34817 29493 4202496 566 1746 1 0 0 0 20 4 24 0 1 0 76370955 54013952 437 1283457024 134512640 134650667 4291055184 18446744073709551615 4294960130 0 0 4096 134217728 18446744071696460772 0 0 17 0 0 0 0
/proc/311/statm: 13187 437 388 34 0 70 0
Current children cumulated CPU time (s) 4.81
Current children cumulated vsize (KiB) 65220

Child status: 100
Real time (s): 5.54792
CPU time (s): 4.8363
CPU user time (s): 4.30827
CPU system time (s): 0.528033
CPU usage (%): 87.1733
Max. virtual memory (cumulated for all children) (KiB): 78924

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.30827
system time used= 0.528033
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 23391
page faults= 2
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 43
involuntary context switches= 86

runsolver used 0 second user time and 0.004 second system time

The end