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/811.cudf.caixa.log.runsolver ./apt-pbo-paranoid-1.0.8 /home/misc2010/data/misc4/caixa//811.cudf /home/misc2010/tmp/201103110955/apt-pbo-paranoid-1.0.8/811.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.13 1.16 1.10 4/36 24087
/proc/meminfo: memFree=90276/1048576 swapFree=0/0
[pid=24087] ppid=24086 vsize=3024 CPUtime=0.01
/proc/24087/stat : 24087 (runsolver) R 24086 12462 12462 34817 12462 4202560 67 0 0 0 0 1 0 0 25 0 1 0 144519390 3096576 88 1283457024 134512640 134586868 4289094608 18446744073709551615 4294960130 0 0 0 24578 0 0 0 17 0 0 0 0
/proc/24087/statm: 756 88 56 19 0 55 0

[startup+0.190228 s]
/proc/loadavg: 1.13 1.16 1.10 4/36 24087
/proc/meminfo: memFree=90276/1048576 swapFree=0/0
[pid=24087] ppid=24086 vsize=1672 CPUtime=0.01
/proc/24087/stat : 24087 (sh) S 24086 24087 12462 34817 12462 4202496 223 176 0 0 0 1 0 0 25 0 1 0 144519390 1712128 129 1283457024 134512640 134593992 4289885536 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24087/statm: 418 129 112 20 0 45 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 1672

[startup+0.212645 s]
/proc/loadavg: 1.13 1.16 1.10 4/36 24087
/proc/meminfo: memFree=90276/1048576 swapFree=0/0
[pid=24087] ppid=24086 vsize=1672 CPUtime=0.01
/proc/24087/stat : 24087 (sh) S 24086 24087 12462 34817 12462 4202496 223 176 0 0 0 1 0 0 25 0 1 0 144519390 1712128 129 1283457024 134512640 134593992 4289885536 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24087/statm: 418 129 112 20 0 45 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 1672

[startup+0.302692 s]
/proc/loadavg: 1.13 1.16 1.10 4/36 24087
/proc/meminfo: memFree=90276/1048576 swapFree=0/0
[pid=24087] ppid=24086 vsize=1672 CPUtime=0.01
/proc/24087/stat : 24087 (sh) S 24086 24087 12462 34817 12462 4202496 223 176 0 0 0 1 0 0 25 0 1 0 144519390 1712128 129 1283457024 134512640 134593992 4289885536 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24087/statm: 418 129 112 20 0 45 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 1672

[startup+0.712807 s]
/proc/loadavg: 1.13 1.16 1.10 4/36 24087
/proc/meminfo: memFree=90276/1048576 swapFree=0/0
[pid=24087] ppid=24086 vsize=1672 CPUtime=0.01
/proc/24087/stat : 24087 (sh) S 24086 24087 12462 34817 12462 4202496 223 176 0 0 0 1 0 0 25 0 1 0 144519390 1712128 129 1283457024 134512640 134593992 4289885536 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24087/statm: 418 129 112 20 0 45 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 1672

[startup+1.50307 s]
/proc/loadavg: 1.13 1.16 1.10 2/39 24093
/proc/meminfo: memFree=52844/1048576 swapFree=0/0
[pid=24087] ppid=24086 vsize=1672 CPUtime=0.01
/proc/24087/stat : 24087 (sh) S 24086 24087 12462 34817 12462 4202496 223 176 0 0 0 1 0 0 25 0 1 0 144519390 1712128 129 1283457024 134512640 134593992 4289885536 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24087/statm: 418 129 112 20 0 45 0
[pid=24089] ppid=24087 vsize=8224 CPUtime=0.04
/proc/24089/stat : 24089 (apt-pbo) S 24087 24087 12462 34817 12462 4202496 1576 409 0 0 3 1 0 0 25 0 1 0 144519390 8421376 1400 1283457024 134512640 135745756 4287896224 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/24089/statm: 2056 1400 648 302 0 789 0
[pid=24092] ppid=24089 vsize=37884 CPUtime=1.4
/proc/24092/stat : 24092 (cudftodeb.nativ) R 24089 24087 12462 34817 12462 4202496 9128 0 0 0 135 5 0 0 25 0 1 0 144519395 38793216 9049 1283457024 134512640 135029684 4292151056 18446744073709551615 134967018 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/24092/statm: 9471 9049 246 127 0 8852 0
Current children cumulated CPU time (s) 1.45
Current children cumulated vsize (KiB) 47780

[startup+3.10353 s]
/proc/loadavg: 1.12 1.16 1.10 2/39 24093
/proc/meminfo: memFree=30416/1048576 swapFree=0/0
[pid=24087] ppid=24086 vsize=1672 CPUtime=0.01
/proc/24087/stat : 24087 (sh) S 24086 24087 12462 34817 12462 4202496 223 176 0 0 0 1 0 0 25 0 1 0 144519390 1712128 129 1283457024 134512640 134593992 4289885536 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24087/statm: 418 129 112 20 0 45 0
[pid=24089] ppid=24087 vsize=8224 CPUtime=0.04
/proc/24089/stat : 24089 (apt-pbo) S 24087 24087 12462 34817 12462 4202496 1576 409 0 0 3 1 0 0 25 0 1 0 144519390 8421376 1400 1283457024 134512640 135745756 4287896224 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/24089/statm: 2056 1400 648 302 0 789 0
[pid=24092] ppid=24089 vsize=62580 CPUtime=3
/proc/24092/stat : 24092 (cudftodeb.nativ) R 24089 24087 12462 34817 12462 4202496 15250 0 0 0 284 16 0 0 25 0 1 0 144519395 64081920 15171 1283457024 134512640 135029684 4292151056 18446744073709551615 4294960130 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/24092/statm: 15645 15171 258 127 0 15026 0
Current children cumulated CPU time (s) 3.05
Current children cumulated vsize (KiB) 72476

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

[startup+3.21356 s]
/proc/loadavg: 1.12 1.16 1.10 2/39 24093
/proc/meminfo: memFree=30416/1048576 swapFree=0/0
[pid=24087] ppid=24086 vsize=1672 CPUtime=0.01
/proc/24087/stat : 24087 (sh) S 24086 24087 12462 34817 12462 4202496 223 176 0 0 0 1 0 0 25 0 1 0 144519390 1712128 129 1283457024 134512640 134593992 4289885536 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24087/statm: 418 129 112 20 0 45 0
[pid=24089] ppid=24087 vsize=8224 CPUtime=0.04
/proc/24089/stat : 24089 (apt-pbo) S 24087 24087 12462 34817 12462 4202496 1576 409 0 0 3 1 0 0 25 0 1 0 144519390 8421376 1400 1283457024 134512640 135745756 4287896224 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/24089/statm: 2056 1400 648 302 0 789 0
[pid=24092] ppid=24089 vsize=63084 CPUtime=3.11
/proc/24092/stat : 24092 (cudftodeb.nativ) R 24089 24087 12462 34817 12462 4202496 15391 0 0 0 293 18 0 0 25 0 1 0 144519395 64598016 15312 1283457024 134512640 135029684 4292151056 18446744073709551615 134884419 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/24092/statm: 15771 15312 258 127 0 15152 0
Current children cumulated CPU time (s) 3.16
Current children cumulated vsize (KiB) 72980

[startup+4.81392 s]
/proc/loadavg: 1.12 1.16 1.10 2/39 24093
/proc/meminfo: memFree=5232/1048576 swapFree=0/0
[pid=24087] ppid=24086 vsize=1672 CPUtime=0.01
/proc/24087/stat : 24087 (sh) S 24086 24087 12462 34817 12462 4202496 223 176 0 0 0 1 0 0 25 0 1 0 144519390 1712128 129 1283457024 134512640 134593992 4289885536 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24087/statm: 418 129 112 20 0 45 0
[pid=24089] ppid=24087 vsize=8224 CPUtime=0.04
/proc/24089/stat : 24089 (apt-pbo) S 24087 24087 12462 34817 12462 4202496 1576 409 0 0 3 1 0 0 25 0 1 0 144519390 8421376 1400 1283457024 134512640 135745756 4287896224 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/24089/statm: 2056 1400 648 302 0 789 0
[pid=24092] ppid=24089 vsize=71148 CPUtime=4.71
/proc/24092/stat : 24092 (cudftodeb.nativ) R 24089 24087 12462 34817 12462 4202496 17391 0 0 0 418 53 0 0 25 0 1 0 144519395 72855552 17312 1283457024 134512640 135029684 4292151056 18446744073709551615 134969019 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/24092/statm: 17787 17312 258 127 0 17168 0
Current children cumulated CPU time (s) 4.76
Current children cumulated vsize (KiB) 81044

[startup+5.60656 s]
/proc/loadavg: 1.12 1.16 1.10 1/40 24101
/proc/meminfo: memFree=60844/1048576 swapFree=0/0
[pid=24087] ppid=24086 vsize=1672 CPUtime=0.01
/proc/24087/stat : 24087 (sh) S 24086 24087 12462 34817 12462 4202496 223 176 0 0 0 1 0 0 25 0 1 0 144519390 1712128 129 1283457024 134512640 134593992 4289885536 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24087/statm: 418 129 112 20 0 45 0
[pid=24089] ppid=24087 vsize=8224 CPUtime=4.92
/proc/24089/stat : 24089 (apt-pbo) S 24087 24087 12462 34817 12462 4202496 1751 17801 0 0 3 1 432 56 18 0 1 0 144519390 8421376 1426 1283457024 134512640 135745756 4287896224 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/24089/statm: 2056 1426 653 302 0 789 0
[pid=24094] ppid=24089 vsize=2568 CPUtime=0
/proc/24094/stat : 24094 (apt-get.sh) S 24089 24087 12462 34817 12462 4202496 405 492 0 0 0 0 0 0 22 0 1 0 144519905 2629632 272 1283457024 134512640 135304128 4292149024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24094/statm: 642 272 232 194 0 29 0
[pid=24097] ppid=24094 vsize=52744 CPUtime=0.23
/proc/24097/stat : 24097 (apt-get) D 24094 24087 12462 34817 12462 4202496 566 1743 1 0 0 0 20 3 24 0 1 0 144519906 54009856 437 1283457024 134512640 134650667 4290428336 18446744073709551615 4294960130 0 0 4096 134217728 18446744071696460772 0 0 17 0 0 0 0
/proc/24097/statm: 13186 437 388 34 0 69 0
Current children cumulated CPU time (s) 5.16
Current children cumulated vsize (KiB) 65208

[startup+6.0066 s]
/proc/loadavg: 1.12 1.16 1.10 1/40 24101
/proc/meminfo: memFree=60844/1048576 swapFree=0/0
[pid=24087] ppid=24086 vsize=1672 CPUtime=0.01
/proc/24087/stat : 24087 (sh) S 24086 24087 12462 34817 12462 4202496 223 176 0 0 0 1 0 0 25 0 1 0 144519390 1712128 129 1283457024 134512640 134593992 4289885536 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24087/statm: 418 129 112 20 0 45 0
[pid=24089] ppid=24087 vsize=8224 CPUtime=4.92
/proc/24089/stat : 24089 (apt-pbo) S 24087 24087 12462 34817 12462 4202496 1751 17801 0 0 3 1 432 56 18 0 1 0 144519390 8421376 1426 1283457024 134512640 135745756 4287896224 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/24089/statm: 2056 1426 653 302 0 789 0
[pid=24094] ppid=24089 vsize=2568 CPUtime=0
/proc/24094/stat : 24094 (apt-get.sh) S 24089 24087 12462 34817 12462 4202496 405 492 0 0 0 0 0 0 22 0 1 0 144519905 2629632 272 1283457024 134512640 135304128 4292149024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24094/statm: 642 272 232 194 0 29 0
[pid=24097] ppid=24094 vsize=52744 CPUtime=0.23
/proc/24097/stat : 24097 (apt-get) D 24094 24087 12462 34817 12462 4202496 566 1743 1 0 0 0 20 3 22 0 1 0 144519906 54009856 437 1283457024 134512640 134650667 4290428336 18446744073709551615 4294960130 0 0 4096 134217728 18446744071696460772 0 0 17 0 0 0 0
/proc/24097/statm: 13186 437 388 34 0 69 0
Current children cumulated CPU time (s) 5.16
Current children cumulated vsize (KiB) 65208

Child status: 100
Real time (s): 6.09657
CPU time (s): 5.18432
CPU user time (s): 4.56029
CPU system time (s): 0.624039
CPU usage (%): 85.0368
Max. virtual memory (cumulated for all children) (KiB): 81044

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.56029
system time used= 0.624039
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 23527
page faults= 4
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 59
involuntary context switches= 196

runsolver used 0 second user time and 0 second system time

The end