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/201103110955/apt-pbo-paranoid-1.0.8/4008.cudf.caixa.log.runsolver ./apt-pbo-paranoid-1.0.8 /home/misc2010/data/misc4/caixa//4008.cudf /home/misc2010/tmp/201103110955/apt-pbo-paranoid-1.0.8/4008.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.10 1.15 1.06 5/37 19848
/proc/meminfo: memFree=56348/1048576 swapFree=0/0
[pid=19846] ppid=19845 vsize=1672 CPUtime=0
/proc/19846/stat : 19846 (sh) S 19845 19846 12462 34817 12462 4202496 221 174 0 0 0 0 0 0 18 0 1 0 144445503 1712128 129 1283457024 134512640 134593992 4293343408 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/19846/statm: 418 129 112 20 0 45 0
[pid=19848] ppid=19846 vsize=3544 CPUtime=0
/proc/19848/stat : 19848 (apt-pbo) R 19846 19846 12462 34817 12462 4202496 518 0 0 0 0 0 0 0 25 0 1 0 144445503 3629056 466 1283457024 134512640 135745756 4291675712 18446744073709551615 4158780855 0 0 128 0 0 0 0 17 0 0 0 0
/proc/19848/statm: 886 466 359 302 0 154 0

[startup+0.124157 s]
/proc/loadavg: 1.10 1.15 1.06 5/37 19848
/proc/meminfo: memFree=56348/1048576 swapFree=0/0
[pid=19846] ppid=19845 vsize=1672 CPUtime=0
/proc/19846/stat : 19846 (sh) S 19845 19846 12462 34817 12462 4202496 221 174 0 0 0 0 0 0 18 0 1 0 144445503 1712128 129 1283457024 134512640 134593992 4293343408 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/19846/statm: 418 129 112 20 0 45 0
[pid=19848] ppid=19846 vsize=8228 CPUtime=0.05
/proc/19848/stat : 19848 (apt-pbo) S 19846 19846 12462 34817 12462 4202496 1578 411 0 0 3 2 0 0 25 0 1 0 144445503 8425472 1401 1283457024 134512640 135745756 4291675712 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/19848/statm: 2057 1401 648 302 0 790 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9900

[startup+0.206439 s]
/proc/loadavg: 1.10 1.15 1.06 5/37 19848
/proc/meminfo: memFree=56348/1048576 swapFree=0/0
[pid=19846] ppid=19845 vsize=1672 CPUtime=0
/proc/19846/stat : 19846 (sh) S 19845 19846 12462 34817 12462 4202496 221 174 0 0 0 0 0 0 18 0 1 0 144445503 1712128 129 1283457024 134512640 134593992 4293343408 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/19846/statm: 418 129 112 20 0 45 0
[pid=19848] ppid=19846 vsize=8228 CPUtime=0.05
/proc/19848/stat : 19848 (apt-pbo) S 19846 19846 12462 34817 12462 4202496 1578 411 0 0 3 2 0 0 25 0 1 0 144445503 8425472 1401 1283457024 134512640 135745756 4291675712 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/19848/statm: 2057 1401 648 302 0 790 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9900

[startup+0.306446 s]
/proc/loadavg: 1.10 1.15 1.06 5/37 19848
/proc/meminfo: memFree=56348/1048576 swapFree=0/0
[pid=19846] ppid=19845 vsize=1672 CPUtime=0
/proc/19846/stat : 19846 (sh) S 19845 19846 12462 34817 12462 4202496 221 174 0 0 0 0 0 0 18 0 1 0 144445503 1712128 129 1283457024 134512640 134593992 4293343408 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/19846/statm: 418 129 112 20 0 45 0
[pid=19848] ppid=19846 vsize=8228 CPUtime=0.05
/proc/19848/stat : 19848 (apt-pbo) S 19846 19846 12462 34817 12462 4202496 1578 411 0 0 3 2 0 0 25 0 1 0 144445503 8425472 1401 1283457024 134512640 135745756 4291675712 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/19848/statm: 2057 1401 648 302 0 790 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9900

[startup+0.706576 s]
/proc/loadavg: 1.10 1.15 1.06 5/37 19848
/proc/meminfo: memFree=56348/1048576 swapFree=0/0
[pid=19846] ppid=19845 vsize=1672 CPUtime=0
/proc/19846/stat : 19846 (sh) S 19845 19846 12462 34817 12462 4202496 221 174 0 0 0 0 0 0 18 0 1 0 144445503 1712128 129 1283457024 134512640 134593992 4293343408 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/19846/statm: 418 129 112 20 0 45 0
[pid=19848] ppid=19846 vsize=8228 CPUtime=0.05
/proc/19848/stat : 19848 (apt-pbo) S 19846 19846 12462 34817 12462 4202496 1578 411 0 0 3 2 0 0 25 0 1 0 144445503 8425472 1401 1283457024 134512640 135745756 4291675712 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/19848/statm: 2057 1401 648 302 0 790 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9900

[startup+1.50504 s]
/proc/loadavg: 1.09 1.14 1.06 2/39 19852
/proc/meminfo: memFree=19796/1048576 swapFree=0/0
[pid=19846] ppid=19845 vsize=1672 CPUtime=0
/proc/19846/stat : 19846 (sh) S 19845 19846 12462 34817 12462 4202496 221 174 0 0 0 0 0 0 18 0 1 0 144445503 1712128 129 1283457024 134512640 134593992 4293343408 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/19846/statm: 418 129 112 20 0 45 0
[pid=19848] ppid=19846 vsize=8228 CPUtime=0.05
/proc/19848/stat : 19848 (apt-pbo) S 19846 19846 12462 34817 12462 4202496 1578 411 0 0 3 2 0 0 25 0 1 0 144445503 8425472 1401 1283457024 134512640 135745756 4291675712 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/19848/statm: 2057 1401 648 302 0 790 0
[pid=19852] ppid=19848 vsize=36240 CPUtime=1.38
/proc/19852/stat : 19852 (cudftodeb.nativ) R 19848 19846 12462 34817 12462 4202496 8700 0 0 0 129 9 0 0 25 0 1 0 144445508 37109760 8620 1283457024 134512640 135029684 4290022656 18446744073709551615 4160469566 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/19852/statm: 9060 8620 257 127 0 8441 0
Current children cumulated CPU time (s) 1.43
Current children cumulated vsize (KiB) 46140

[startup+3.10528 s]
/proc/loadavg: 1.09 1.14 1.06 2/39 19852
/proc/meminfo: memFree=6352/1048576 swapFree=0/0
[pid=19846] ppid=19845 vsize=1672 CPUtime=0
/proc/19846/stat : 19846 (sh) S 19845 19846 12462 34817 12462 4202496 221 174 0 0 0 0 0 0 18 0 1 0 144445503 1712128 129 1283457024 134512640 134593992 4293343408 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/19846/statm: 418 129 112 20 0 45 0
[pid=19848] ppid=19846 vsize=8228 CPUtime=0.05
/proc/19848/stat : 19848 (apt-pbo) S 19846 19846 12462 34817 12462 4202496 1578 411 0 0 3 2 0 0 25 0 1 0 144445503 8425472 1401 1283457024 134512640 135745756 4291675712 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/19848/statm: 2057 1401 648 302 0 790 0
[pid=19852] ppid=19848 vsize=52500 CPUtime=2.98
/proc/19852/stat : 19852 (cudftodeb.nativ) R 19848 19846 12462 34817 12462 4202496 12746 0 0 0 257 41 0 0 25 0 1 0 144445508 53760000 12666 1283457024 134512640 135029684 4290022656 18446744073709551615 134876195 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/19852/statm: 13125 12666 258 127 0 12506 0
Current children cumulated CPU time (s) 3.03
Current children cumulated vsize (KiB) 62400

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

[startup+3.2053 s]
/proc/loadavg: 1.09 1.14 1.06 2/39 19852
/proc/meminfo: memFree=6352/1048576 swapFree=0/0
[pid=19846] ppid=19845 vsize=1672 CPUtime=0
/proc/19846/stat : 19846 (sh) S 19845 19846 12462 34817 12462 4202496 221 174 0 0 0 0 0 0 18 0 1 0 144445503 1712128 129 1283457024 134512640 134593992 4293343408 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/19846/statm: 418 129 112 20 0 45 0
[pid=19848] ppid=19846 vsize=8228 CPUtime=0.05
/proc/19848/stat : 19848 (apt-pbo) S 19846 19846 12462 34817 12462 4202496 1578 411 0 0 3 2 0 0 25 0 1 0 144445503 8425472 1401 1283457024 134512640 135745756 4291675712 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/19848/statm: 2057 1401 648 302 0 790 0
[pid=19852] ppid=19848 vsize=52500 CPUtime=3.08
/proc/19852/stat : 19852 (cudftodeb.nativ) R 19848 19846 12462 34817 12462 4202496 12746 0 0 0 263 45 0 0 25 0 1 0 144445508 53760000 12666 1283457024 134512640 135029684 4290022656 18446744073709551615 134876011 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/19852/statm: 13125 12666 258 127 0 12506 0
Current children cumulated CPU time (s) 3.13
Current children cumulated vsize (KiB) 62400

[startup+4.00439 s]
/proc/loadavg: 1.09 1.14 1.06 2/39 19852
/proc/meminfo: memFree=6360/1048576 swapFree=0/0
[pid=19846] ppid=19845 vsize=1672 CPUtime=0
/proc/19846/stat : 19846 (sh) S 19845 19846 12462 34817 12462 4202496 221 174 0 0 0 0 0 0 18 0 1 0 144445503 1712128 129 1283457024 134512640 134593992 4293343408 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/19846/statm: 418 129 112 20 0 45 0
[pid=19848] ppid=19846 vsize=8228 CPUtime=3.7
/proc/19848/stat : 19848 (apt-pbo) S 19846 19846 12462 34817 12462 4202496 1752 13158 0 0 3 2 306 59 18 0 1 0 144445503 8425472 1427 1283457024 134512640 135745756 4291675712 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/19848/statm: 2057 1427 653 302 0 790 0
Current children cumulated CPU time (s) 3.7
Current children cumulated vsize (KiB) 9900

[startup+4.4044 s]
/proc/loadavg: 1.09 1.14 1.06 1/40 19860
/proc/meminfo: memFree=44636/1048576 swapFree=0/0
[pid=19846] ppid=19845 vsize=1672 CPUtime=0
/proc/19846/stat : 19846 (sh) S 19845 19846 12462 34817 12462 4202496 221 174 0 0 0 0 0 0 18 0 1 0 144445503 1712128 129 1283457024 134512640 134593992 4293343408 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/19846/statm: 418 129 112 20 0 45 0
[pid=19848] ppid=19846 vsize=8228 CPUtime=3.7
/proc/19848/stat : 19848 (apt-pbo) S 19846 19846 12462 34817 12462 4202496 1752 13158 0 0 3 2 306 59 18 0 1 0 144445503 8425472 1427 1283457024 134512640 135745756 4291675712 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/19848/statm: 2057 1427 653 302 0 790 0
[pid=19853] ppid=19848 vsize=2572 CPUtime=0.01
/proc/19853/stat : 19853 (apt-get.sh) S 19848 19846 12462 34817 12462 4202496 407 489 0 0 1 0 0 0 18 0 1 0 144445881 2633728 273 1283457024 134512640 135304128 4293345344 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/19853/statm: 643 273 232 194 0 30 0
[pid=19856] ppid=19853 vsize=52748 CPUtime=0.18
/proc/19856/stat : 19856 (apt-get) D 19853 19846 12462 34817 12462 4202496 568 1747 1 0 0 0 16 2 25 0 1 0 144445882 54013952 437 1283457024 134512640 134650667 4292278128 18446744073709551615 4294960130 0 0 4096 134217728 18446744071696460772 0 0 17 0 0 0 0
/proc/19856/statm: 13187 437 388 34 0 70 0
Current children cumulated CPU time (s) 3.89
Current children cumulated vsize (KiB) 65220

[startup+4.60444 s]
/proc/loadavg: 1.09 1.14 1.06 1/40 19860
/proc/meminfo: memFree=44636/1048576 swapFree=0/0
[pid=19846] ppid=19845 vsize=1672 CPUtime=0
/proc/19846/stat : 19846 (sh) S 19845 19846 12462 34817 12462 4202496 221 174 0 0 0 0 0 0 18 0 1 0 144445503 1712128 129 1283457024 134512640 134593992 4293343408 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/19846/statm: 418 129 112 20 0 45 0
[pid=19848] ppid=19846 vsize=57188 CPUtime=3.9
/proc/19848/stat : 19848 (apt-pbo) D 19846 19846 12462 34817 12462 4202496 1883 16405 1 1 3 2 324 61 18 0 1 0 144445503 58560512 1457 1283457024 134512640 135745756 4291675712 18446744073709551615 4294960130 0 0 128 0 18446744071696460772 0 0 17 0 0 0 0
/proc/19848/statm: 14297 1457 680 302 0 822 0
Current children cumulated CPU time (s) 3.9
Current children cumulated vsize (KiB) 58860

Child status: 100
Real time (s): 4.62606
CPU time (s): 3.91624
CPU user time (s): 3.2762
CPU system time (s): 0.64004
CPU usage (%): 84.6561
Max. virtual memory (cumulated for all children) (KiB): 65220

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.2762
system time used= 0.64004
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 18882
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= 53
involuntary context switches= 158

runsolver used 0 second user time and 0 second system time

The end