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/201012070034/apt-pbo-trendy-1.0.6/rand316.sarge-etch.cudf.sarge-etch.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/icse/sarge-etch/rand316.sarge-etch.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/rand316.sarge-etch.cudf.sarge-etch.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.00 1.00 5/41 15324
/proc/meminfo: memFree=788172/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=3548 CPUtime=0.01
/proc/15324/stat : 15324 (apt-pbo) R 15322 15322 4159 34819 4229 4202496 533 0 0 0 1 0 0 0 25 0 1 0 880342691 3633152 475 1283457024 134512640 135744540 4292007536 18446744073709551615 4158519983 0 0 128 0 0 0 0 17 0 0 0 0
/proc/15324/statm: 887 475 365 301 0 155 0

[startup+0.167009 s]
/proc/loadavg: 1.08 1.00 1.00 5/41 15324
/proc/meminfo: memFree=788172/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=8356 CPUtime=0.06
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 1618 414 0 0 6 0 0 0 25 0 1 0 880342691 8556544 1422 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 2089 1422 646 301 0 822 0
Current children cumulated CPU time (s) 0.06
Current children cumulated vsize (KiB) 10028

[startup+0.207018 s]
/proc/loadavg: 1.08 1.00 1.00 5/41 15324
/proc/meminfo: memFree=788172/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=8356 CPUtime=0.06
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 1618 414 0 0 6 0 0 0 25 0 1 0 880342691 8556544 1422 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 2089 1422 646 301 0 822 0
Current children cumulated CPU time (s) 0.06
Current children cumulated vsize (KiB) 10028

[startup+0.30704 s]
/proc/loadavg: 1.08 1.00 1.00 5/41 15324
/proc/meminfo: memFree=788172/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=8356 CPUtime=0.06
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 1618 414 0 0 6 0 0 0 25 0 1 0 880342691 8556544 1422 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 2089 1422 646 301 0 822 0
Current children cumulated CPU time (s) 0.06
Current children cumulated vsize (KiB) 10028

[startup+0.707173 s]
/proc/loadavg: 1.08 1.00 1.00 5/41 15324
/proc/meminfo: memFree=788172/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=8356 CPUtime=0.06
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 1618 414 0 0 6 0 0 0 25 0 1 0 880342691 8556544 1422 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 2089 1422 646 301 0 822 0
Current children cumulated CPU time (s) 0.06
Current children cumulated vsize (KiB) 10028

[startup+1.50745 s]
/proc/loadavg: 1.08 1.00 1.00 2/43 15328
/proc/meminfo: memFree=764140/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=8356 CPUtime=0.06
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 1618 414 0 0 6 0 0 0 25 0 1 0 880342691 8556544 1422 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 2089 1422 646 301 0 822 0
[pid=15328] ppid=15324 vsize=33200 CPUtime=1.44
/proc/15328/stat : 15328 (cudftodeb.nativ) R 15324 15322 4159 34819 4229 4202496 7995 0 0 0 140 4 0 0 25 0 1 0 880342696 33996800 7914 1283457024 134512640 135029684 4292351792 18446744073709551615 4160237068 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/15328/statm: 8300 7914 257 127 0 7683 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 43228

[startup+3.10777 s]
/proc/loadavg: 1.08 1.00 1.00 2/43 15328
/proc/meminfo: memFree=741572/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=8356 CPUtime=0.06
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 1618 414 0 0 6 0 0 0 25 0 1 0 880342691 8556544 1422 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 2089 1422 646 301 0 822 0
[pid=15328] ppid=15324 vsize=51848 CPUtime=3.04
/proc/15328/stat : 15328 (cudftodeb.nativ) R 15324 15322 4159 34819 4229 4202496 12625 0 0 0 252 52 0 0 25 0 1 0 880342696 53092352 12544 1283457024 134512640 135029684 4292351792 18446744073709551615 134968855 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/15328/statm: 12962 12544 258 127 0 12345 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 61876

[startup+6.30454 s]
/proc/loadavg: 1.07 1.00 1.00 1/44 15336
/proc/meminfo: memFree=746664/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=21832 CPUtime=4.66
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 5533 20228 0 168 17 4 365 80 18 0 1 0 880342691 22355968 4684 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 5458 4684 3494 301 0 1230 0
Current children cumulated CPU time (s) 4.66
Current children cumulated vsize (KiB) 23504
heavy processes:

[startup+12.7061 s]
/proc/loadavg: 1.07 1.00 1.00 2/43 15342
/proc/meminfo: memFree=713448/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=23776 CPUtime=6.82
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 6141 24918 0 168 26 19 514 123 18 0 1 0 880342691 24346624 5173 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 5944 5173 3497 301 0 1716 0
[pid=15342] ppid=15324 vsize=27536 CPUtime=4.73
/proc/15342/stat : 15342 (wbo) R 15324 15322 4159 34819 4229 4202496 7166 0 0 0 468 5 0 0 25 0 1 0 880343485 28196864 6608 1283457024 4194304 5578286 140737066471072 18446744073709551615 4262093 0 0 0 3 0 0 0 17 0 0 0 0
/proc/15342/statm: 6884 6608 158 338 0 6543 0
Current children cumulated CPU time (s) 11.55
Current children cumulated vsize (KiB) 52984

[startup+25.5093 s]
/proc/loadavg: 1.05 1.00 1.00 2/43 15342
/proc/meminfo: memFree=693740/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=23776 CPUtime=6.84
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 6141 24918 0 168 28 19 514 123 18 0 1 0 880342691 24346624 5173 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 5944 5173 3497 301 0 1716 0
[pid=15342] ppid=15324 vsize=45676 CPUtime=17.53
/proc/15342/stat : 15342 (wbo) R 15324 15322 4159 34819 4229 4202496 11666 0 0 0 1741 12 0 0 25 0 1 0 880343485 46772224 11108 1283457024 4194304 5578286 140737066471072 18446744073709551615 4273920 0 0 0 3 0 0 0 17 0 0 0 0
/proc/15342/statm: 11419 11108 158 338 0 11078 0
Current children cumulated CPU time (s) 24.37
Current children cumulated vsize (KiB) 71124

[startup+51.1159 s]
/proc/loadavg: 1.03 1.00 1.00 2/43 15342
/proc/meminfo: memFree=688408/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=23776 CPUtime=6.84
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 6141 24918 0 168 28 19 514 123 18 0 1 0 880342691 24346624 5173 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 5944 5173 3497 301 0 1716 0
[pid=15342] ppid=15324 vsize=51652 CPUtime=43.09
/proc/15342/stat : 15342 (wbo) R 15324 15322 4159 34819 4229 4202496 13161 0 0 0 4289 20 0 0 25 0 1 0 880343485 52891648 12603 1283457024 4194304 5578286 140737066471072 18446744073709551615 4289908 0 0 0 3 0 0 0 17 0 0 0 0
/proc/15342/statm: 12913 12603 158 338 0 12572 0
Current children cumulated CPU time (s) 49.93
Current children cumulated vsize (KiB) 77100

[startup+102.31 s]
/proc/loadavg: 1.01 1.00 1.00 2/43 15342
/proc/meminfo: memFree=672040/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=23776 CPUtime=6.84
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 6141 24918 0 168 28 19 514 123 18 0 1 0 880342691 24346624 5173 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 5944 5173 3497 301 0 1716 0
[pid=15342] ppid=15324 vsize=67492 CPUtime=94.23
/proc/15342/stat : 15342 (wbo) R 15324 15322 4159 34819 4229 4202496 17143 0 0 0 9386 37 0 0 25 0 1 0 880343485 69111808 16585 1283457024 4194304 5578286 140737066471072 18446744073709551615 4289927 0 0 0 3 0 0 0 17 0 0 0 0
/proc/15342/statm: 16873 16585 158 338 0 16532 0
Current children cumulated CPU time (s) 101.07
Current children cumulated vsize (KiB) 92940

[startup+162.309 s]
/proc/loadavg: 1.00 1.00 1.00 2/43 15342
/proc/meminfo: memFree=652448/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=23776 CPUtime=6.84
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 6141 24918 0 168 28 19 514 123 18 0 1 0 880342691 24346624 5173 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 5944 5173 3497 301 0 1716 0
[pid=15342] ppid=15324 vsize=87236 CPUtime=154.15
/proc/15342/stat : 15342 (wbo) R 15324 15322 4159 34819 4229 4202496 22053 0 0 0 15363 52 0 0 25 0 1 0 880343485 89329664 21495 1283457024 4194304 5578286 140737066471072 18446744073709551615 4289578 0 0 0 3 0 0 0 17 0 0 0 0
/proc/15342/statm: 21809 21495 158 338 0 21468 0
Current children cumulated CPU time (s) 160.99
Current children cumulated vsize (KiB) 112684

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

[startup+179.204 s]
/proc/loadavg: 1.00 1.00 1.00 2/43 15342
/proc/meminfo: memFree=650960/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=23776 CPUtime=6.84
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 6141 24918 0 168 28 19 514 123 18 0 1 0 880342691 24346624 5173 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 5944 5173 3497 301 0 1716 0
[pid=15342] ppid=15324 vsize=88548 CPUtime=171.04
/proc/15342/stat : 15342 (wbo) R 15324 15322 4159 34819 4229 4202496 22405 0 0 0 17048 56 0 0 25 0 1 0 880343485 90673152 21847 1283457024 4194304 5578286 140737066471072 18446744073709551615 4289936 0 0 0 3 0 0 0 17 0 0 0 0
/proc/15342/statm: 22137 21847 158 338 0 21796 0
Current children cumulated CPU time (s) 177.88
Current children cumulated vsize (KiB) 113996

[startup+192.008 s]
/proc/loadavg: 1.00 1.00 1.00 2/43 15342
/proc/meminfo: memFree=370348/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=23776 CPUtime=6.84
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 6142 24918 0 168 28 19 514 123 18 0 1 0 880342691 24346624 5173 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 5944 5173 3497 301 0 1716 0
[pid=15342] ppid=15324 vsize=443720 CPUtime=183.81
/proc/15342/stat : 15342 (wbo) R 15324 15322 4159 34819 4229 4202496 111479 0 0 0 18298 83 0 0 25 0 1 0 880343485 454369280 110702 1283457024 4194304 5578286 140737066471072 18446744073709551615 4266515 0 0 0 3 0 0 0 17 0 0 0 0
/proc/15342/statm: 110930 110702 160 338 0 110589 0
Current children cumulated CPU time (s) 190.65
Current children cumulated vsize (KiB) 469168

[startup+195.205 s]
/proc/loadavg: 1.00 1.00 1.00 2/43 15342
/proc/meminfo: memFree=5400/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=23776 CPUtime=6.84
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 6142 24918 0 168 28 19 514 123 18 0 1 0 880342691 24346624 5173 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 5944 5173 3497 301 0 1716 0
[pid=15342] ppid=15324 vsize=812172 CPUtime=186.97
/proc/15342/stat : 15342 (wbo) R 15324 15322 4159 34819 4229 4202496 203567 0 0 0 18585 112 0 0 25 0 1 0 880343485 831664128 202790 1283457024 4194304 5578286 140737066471072 18446744073709551615 4291090 0 0 0 3 0 0 0 17 0 0 0 0
/proc/15342/statm: 203043 202790 160 338 0 202702 0
Current children cumulated CPU time (s) 193.81
Current children cumulated vsize (KiB) 837620

[startup+196.809 s]
/proc/loadavg: 1.00 1.00 1.00 2/43 15342
/proc/meminfo: memFree=5804/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=24896 CPUtime=7.13
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 6801 24918 0 168 53 23 514 123 18 0 1 0 880342691 25493504 5463 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 6224 5463 3501 301 0 1996 0
[pid=15342] ppid=15324 vsize=0 CPUtime=187.68
/proc/15342/stat : 15342 (wbo) Z 15324 15322 4159 34819 4229 4202508 221232 0 0 0 18639 129 0 0 25 0 1 0 880343485 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/15342/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 194.81
Current children cumulated vsize (KiB) 26568

[startup+197.61 s]
/proc/loadavg: 1.00 1.00 1.00 2/45 15346
/proc/meminfo: memFree=888652/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=24896 CPUtime=7.28
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 6801 24918 0 168 58 33 514 123 18 0 1 0 880342691 25493504 5463 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 6224 5463 3501 301 0 1996 0
[pid=15342] ppid=15324 vsize=0 CPUtime=187.68
/proc/15342/stat : 15342 (wbo) Z 15324 15322 4159 34819 4229 4202508 221232 0 0 0 18639 129 0 0 25 0 1 0 880343485 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/15342/statm: 0 0 0 0 0 0 0
[pid=15343] ppid=15324 vsize=2588 CPUtime=0
/proc/15343/stat : 15343 (apt-get.sh) S 15324 15322 4159 34819 4229 4202496 421 488 2 1 0 0 0 0 19 0 1 0 880362313 2650112 280 1283457024 134512640 135304128 4290353456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15343/statm: 647 280 235 194 0 33 0
[pid=15346] ppid=15343 vsize=17252 CPUtime=1.03
/proc/15346/stat : 15346 (apt-get) R 15343 15322 4159 34819 4229 4202496 3698 0 2 0 83 20 0 0 25 0 1 0 880362319 17666048 3626 1283457024 134512640 134649604 4290834448 18446744073709551615 4156750399 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/15346/statm: 4313 3626 3191 34 0 442 0
Current children cumulated CPU time (s) 195.99
Current children cumulated vsize (KiB) 46408

[startup+198.41 s]
/proc/loadavg: 1.00 1.00 1.00 2/45 15346
/proc/meminfo: memFree=887412/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=24896 CPUtime=7.36
/proc/15324/stat : 15324 (apt-pbo) S 15322 15322 4159 34819 4229 4202496 6801 24918 0 168 59 40 514 123 18 0 1 0 880342691 25493504 5463 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/15324/statm: 6224 5463 3501 301 0 1996 0
[pid=15342] ppid=15324 vsize=0 CPUtime=187.68
/proc/15342/stat : 15342 (wbo) Z 15324 15322 4159 34819 4229 4202508 221232 0 0 0 18639 129 0 0 25 0 1 0 880343485 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/15342/statm: 0 0 0 0 0 0 0
[pid=15343] ppid=15324 vsize=2588 CPUtime=0
/proc/15343/stat : 15343 (apt-get.sh) S 15324 15322 4159 34819 4229 4202496 421 488 2 1 0 0 0 0 19 0 1 0 880362313 2650112 280 1283457024 134512640 135304128 4290353456 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15343/statm: 647 280 235 194 0 33 0
[pid=15346] ppid=15343 vsize=17476 CPUtime=1.74
/proc/15346/stat : 15346 (apt-get) R 15343 15322 4159 34819 4229 4202496 3722 0 2 0 143 31 0 0 25 0 1 0 880362319 17895424 3650 1283457024 134512640 134649604 4290834448 18446744073709551615 4156750399 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/15346/statm: 4369 3650 3191 34 0 498 0
Current children cumulated CPU time (s) 196.78
Current children cumulated vsize (KiB) 46632

[startup+198.61 s]
/proc/loadavg: 1.00 1.00 1.00 2/45 15346
/proc/meminfo: memFree=887412/1048576 swapFree=2080272/2097144
[pid=15322] ppid=15321 vsize=1672 CPUtime=0
/proc/15322/stat : 15322 (sh) S 15321 15322 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 18 0 1 0 880342690 1712128 128 1283457024 134512640 134594024 4293312640 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/15322/statm: 418 128 112 20 0 44 0
[pid=15324] ppid=15322 vsize=24900 CPUtime=196.93
/proc/15324/stat : 15324 (apt-pbo) R 15322 15322 4159 34819 4229 4202496 7630 250796 0 173 59 42 19301 291 18 0 1 0 880342691 25497600 5465 1283457024 134512640 135744540 4292007536 18446744073709551615 4294960130 0 0 128 0 0 0 0 17 0 0 0 0
/proc/15324/statm: 6225 5465 3502 301 0 1997 0
Current children cumulated CPU time (s) 196.93
Current children cumulated vsize (KiB) 26572

Child status: 0
Real time (s): 198.657
CPU time (s): 196.964
CPU user time (s): 193.632
CPU system time (s): 3.33221
CPU usage (%): 99.1479
Max. virtual memory (cumulated for all children) (KiB): 904468

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 193.632
system time used= 3.33221
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 259379
page faults= 173
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 107838
involuntary context switches= 110134

runsolver used 0 second user time and 0 second system time

The end