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/randa651ed.cudf.difficult.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/2010/difficult//randa651ed.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/randa651ed.cudf.difficult.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.04 1.00 1/40 3238
/proc/meminfo: memFree=742044/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=3020 CPUtime=0
/proc/3238/stat : 3238 (runsolver) R 3237 3238 4159 34819 4229 4202560 72 0 0 0 0 0 0 0 25 0 1 0 885106447 3092480 93 1283457024 134512640 134586868 4293320640 18446744073709551615 4294960130 0 0 0 24578 0 0 0 17 0 0 0 0
/proc/3238/statm: 755 93 62 19 0 53 0

[startup+0.154146 s]
/proc/loadavg: 1.06 1.04 1.00 1/40 3238
/proc/meminfo: memFree=742044/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1676

[startup+0.206136 s]
/proc/loadavg: 1.06 1.04 1.00 1/40 3238
/proc/meminfo: memFree=742044/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1676

[startup+0.309719 s]
/proc/loadavg: 1.06 1.04 1.00 1/40 3238
/proc/meminfo: memFree=742044/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1676

[startup+0.709837 s]
/proc/loadavg: 1.06 1.04 1.00 1/40 3238
/proc/meminfo: memFree=742044/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1676

[startup+1.51003 s]
/proc/loadavg: 1.06 1.04 1.00 2/43 3244
/proc/meminfo: memFree=718824/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=8352 CPUtime=0.03
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 1610 414 5 0 3 0 0 0 25 0 1 0 885106447 8552448 1422 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 2088 1422 646 301 0 821 0
[pid=3244] ppid=3241 vsize=29168 CPUtime=1.25
/proc/3244/stat : 3244 (cudftodeb.nativ) R 3241 3238 4159 34819 4229 4202496 6971 0 9 0 124 1 0 0 25 0 1 0 885106466 29868032 6897 1283457024 134512640 135029684 4290967056 18446744073709551615 134984438 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/3244/statm: 7292 6897 247 127 0 6675 0
Current children cumulated CPU time (s) 1.28
Current children cumulated vsize (KiB) 39196

[startup+3.11042 s]
/proc/loadavg: 1.06 1.04 1.00 2/43 3244
/proc/meminfo: memFree=696628/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=8352 CPUtime=0.03
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 1610 414 5 0 3 0 0 0 25 0 1 0 885106447 8552448 1422 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 2088 1422 646 301 0 821 0
[pid=3244] ppid=3241 vsize=64708 CPUtime=2.86
/proc/3244/stat : 3244 (cudftodeb.nativ) R 3241 3238 4159 34819 4229 4202496 15670 0 9 0 282 4 0 0 25 0 1 0 885106466 66260992 15596 1283457024 134512640 135029684 4290967056 18446744073709551615 134968806 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/3244/statm: 16177 15596 257 127 0 15560 0
Current children cumulated CPU time (s) 2.89
Current children cumulated vsize (KiB) 74736

[startup+6.31155 s]
/proc/loadavg: 1.06 1.04 1.00 2/43 3244
/proc/meminfo: memFree=685468/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=8352 CPUtime=0.03
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 1610 414 5 0 3 0 0 0 25 0 1 0 885106447 8552448 1422 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 2088 1422 646 301 0 821 0
[pid=3244] ppid=3241 vsize=47068 CPUtime=5.95
/proc/3244/stat : 3244 (cudftodeb.nativ) R 3241 3238 4159 34819 4229 4202496 19910 0 9 0 513 82 0 0 25 0 1 0 885106466 48197632 11336 1283457024 134512640 135029684 4290967056 18446744073709551615 4294960130 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/3244/statm: 11767 11336 258 127 0 11150 0
Current children cumulated CPU time (s) 5.98
Current children cumulated vsize (KiB) 57096

[startup+12.7091 s]
/proc/loadavg: 1.05 1.03 1.00 2/43 3258
/proc/meminfo: memFree=656020/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=31504 CPUtime=9.92
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 7744 35706 6 297 33 29 781 149 18 0 1 0 885106447 32260096 7021 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 7876 7021 5166 301 0 1883 0
[pid=3258] ppid=3241 vsize=12484 CPUtime=0.66
/proc/3258/stat : 3258 (wbo) R 3241 3238 4159 34819 4229 4202496 3450 0 2 0 60 6 0 0 20 0 1 0 885107648 12783616 2858 1283457024 4194304 5578286 140734282722688 18446744073709551615 4884020 0 0 0 3 0 0 0 17 0 0 0 0
/proc/3258/statm: 3121 2858 158 338 0 2780 0
Current children cumulated CPU time (s) 10.58
Current children cumulated vsize (KiB) 45664

[startup+25.5117 s]
/proc/loadavg: 1.04 1.03 1.00 2/43 3258
/proc/meminfo: memFree=620504/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=31504 CPUtime=9.94
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 7744 35706 6 297 34 30 781 149 18 0 1 0 885106447 32260096 7021 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 7876 7021 5166 301 0 1883 0
[pid=3258] ppid=3241 vsize=42736 CPUtime=13.45
/proc/3258/stat : 3258 (wbo) R 3241 3238 4159 34819 4229 4202496 10988 0 2 0 1324 21 0 0 25 0 1 0 885107648 43761664 10396 1283457024 4194304 5578286 140734282722688 18446744073709551615 4286082 0 0 0 3 0 0 0 17 0 0 0 0
/proc/3258/statm: 10684 10396 158 338 0 10343 0
Current children cumulated CPU time (s) 23.39
Current children cumulated vsize (KiB) 75916

[startup+51.107 s]
/proc/loadavg: 1.02 1.03 1.00 2/43 3258
/proc/meminfo: memFree=615172/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=31504 CPUtime=9.94
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 7744 35706 6 297 34 30 781 149 18 0 1 0 885106447 32260096 7021 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 7876 7021 5166 301 0 1883 0
[pid=3258] ppid=3241 vsize=48640 CPUtime=39.02
/proc/3258/stat : 3258 (wbo) R 3241 3238 4159 34819 4229 4202496 12445 0 2 0 3871 31 0 0 25 0 1 0 885107648 49807360 11853 1283457024 4194304 5578286 140734282722688 18446744073709551615 4200704 0 0 0 3 0 0 0 17 0 0 0 0
/proc/3258/statm: 12160 11853 158 338 0 11819 0
Current children cumulated CPU time (s) 48.96
Current children cumulated vsize (KiB) 81820

[startup+102.31 s]
/proc/loadavg: 1.01 1.02 1.00 2/43 3258
/proc/meminfo: memFree=590868/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=31504 CPUtime=9.94
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 7744 35706 6 297 34 30 781 149 18 0 1 0 885106447 32260096 7021 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 7876 7021 5166 301 0 1883 0
[pid=3258] ppid=3241 vsize=72708 CPUtime=90.16
/proc/3258/stat : 3258 (wbo) R 3241 3238 4159 34819 4229 4202496 18463 0 2 0 8977 39 0 0 25 0 1 0 885107648 74452992 17871 1283457024 4194304 5578286 140734282722688 18446744073709551615 4200272 0 0 0 3 0 0 0 17 0 0 0 0
/proc/3258/statm: 18177 17871 158 338 0 17836 0
Current children cumulated CPU time (s) 100.1
Current children cumulated vsize (KiB) 105888

[startup+162.305 s]
/proc/loadavg: 1.00 1.02 1.00 2/43 3258
/proc/meminfo: memFree=590868/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=31504 CPUtime=9.95
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 7744 35706 6 297 35 30 781 149 18 0 1 0 885106447 32260096 7021 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 7876 7021 5166 301 0 1883 0
[pid=3258] ppid=3241 vsize=72708 CPUtime=150.07
/proc/3258/stat : 3258 (wbo) R 3241 3238 4159 34819 4229 4202496 18463 0 2 0 14955 52 0 0 25 0 1 0 885107648 74452992 17871 1283457024 4194304 5578286 140734282722688 18446744073709551615 4289940 0 0 0 3 0 0 0 17 0 0 0 0
/proc/3258/statm: 18177 17871 158 338 0 17836 0
Current children cumulated CPU time (s) 160.02
Current children cumulated vsize (KiB) 105888

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

[startup+179.21 s]
/proc/loadavg: 1.00 1.02 1.00 2/43 3258
/proc/meminfo: memFree=590868/1048576 swapFree=2080068/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=31504 CPUtime=9.95
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 7744 35706 6 297 35 30 781 149 18 0 1 0 885106447 32260096 7021 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 7876 7021 5166 301 0 1883 0
[pid=3258] ppid=3241 vsize=72708 CPUtime=166.97
/proc/3258/stat : 3258 (wbo) R 3241 3238 4159 34819 4229 4202496 18463 0 2 0 16643 54 0 0 25 0 1 0 885107648 74452992 17871 1283457024 4194304 5578286 140734282722688 18446744073709551615 4289893 0 0 0 3 0 0 0 17 0 0 0 0
/proc/3258/statm: 18177 17871 158 338 0 17836 0
Current children cumulated CPU time (s) 176.92
Current children cumulated vsize (KiB) 105888

[startup+204.809 s]
/proc/loadavg: 1.08 1.03 1.01 1/43 3258
/proc/meminfo: memFree=6388/1048576 swapFree=2075444/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=31504 CPUtime=9.95
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 7748 35706 6 297 35 30 781 149 18 0 1 0 885106447 32260096 6753 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 7876 6753 4898 301 0 1883 0
[pid=3258] ppid=3241 vsize=966596 CPUtime=192.1
/proc/3258/stat : 3258 (wbo) R 3241 3238 4159 34819 4229 4202496 242100 0 2 0 19079 131 0 0 25 0 1 0 885107648 989794304 237834 1283457024 4194304 5578286 140734282722688 18446744073709551615 4291072 0 0 0 3 0 0 0 17 0 0 0 0
/proc/3258/statm: 241649 237834 59 338 0 241308 0
Current children cumulated CPU time (s) 202.05
Current children cumulated vsize (KiB) 999776

[startup+211.211 s]
/proc/loadavg: 1.07 1.03 1.00 2/43 3258
/proc/meminfo: memFree=941712/1048576 swapFree=2080268/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=50664 CPUtime=13.78
/proc/3241/stat : 3241 (apt-pbo) R 3238 3238 4159 34819 4229 4202496 13089 35706 25 297 414 34 781 149 25 0 1 0 885106447 51879936 11746 1283457024 134512640 135744540 4291380368 18446744073709551615 135070127 0 0 128 0 0 0 0 17 0 0 0 0
/proc/3241/statm: 12666 11746 5108 301 0 6673 0
[pid=3258] ppid=3241 vsize=0 CPUtime=193.57
/proc/3258/stat : 3258 (wbo) Z 3241 3238 4159 34819 4229 4202508 266302 0 13 0 19207 150 0 0 22 0 1 0 885107648 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/3258/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 207.35
Current children cumulated vsize (KiB) 52340

[startup+214.412 s]
/proc/loadavg: 1.07 1.03 1.00 2/43 3258
/proc/meminfo: memFree=941712/1048576 swapFree=2080268/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=50664 CPUtime=16.98
/proc/3241/stat : 3241 (apt-pbo) R 3238 3238 4159 34819 4229 4202496 13089 35706 25 297 734 34 781 149 25 0 1 0 885106447 51879936 11746 1283457024 134512640 135744540 4291380368 18446744073709551615 135068211 0 0 128 0 0 0 0 17 0 0 0 0
/proc/3241/statm: 12666 11746 5108 301 0 6673 0
[pid=3258] ppid=3241 vsize=0 CPUtime=193.57
/proc/3258/stat : 3258 (wbo) Z 3241 3238 4159 34819 4229 4202508 266302 0 13 0 19207 150 0 0 22 0 1 0 885107648 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/3258/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 210.55
Current children cumulated vsize (KiB) 52340

[startup+217.609 s]
/proc/loadavg: 1.07 1.03 1.00 2/43 3258
/proc/meminfo: memFree=941712/1048576 swapFree=2080268/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=50664 CPUtime=19.55
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 13126 35706 26 297 991 34 781 149 20 0 1 0 885106447 51879936 11749 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 12666 11749 5111 301 0 6673 0
[pid=3258] ppid=3241 vsize=0 CPUtime=193.57
/proc/3258/stat : 3258 (wbo) Z 3241 3238 4159 34819 4229 4202508 266302 0 13 0 19207 150 0 0 22 0 1 0 885107648 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/3258/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 213.12
Current children cumulated vsize (KiB) 52340

[startup+218.409 s]
/proc/loadavg: 1.07 1.03 1.00 2/45 3262
/proc/meminfo: memFree=936540/1048576 swapFree=2080268/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=50664 CPUtime=19.65
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 13126 35706 26 297 996 39 781 149 18 0 1 0 885106447 51879936 11749 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 12666 11749 5111 301 0 6673 0
[pid=3258] ppid=3241 vsize=0 CPUtime=193.57
/proc/3258/stat : 3258 (wbo) Z 3241 3238 4159 34819 4229 4202508 266302 0 13 0 19207 150 0 0 22 0 1 0 885107648 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/3258/statm: 0 0 0 0 0 0 0
[pid=3259] ppid=3241 vsize=2612 CPUtime=0
/proc/3259/stat : 3259 (apt-get.sh) S 3241 3238 4159 34819 4229 4202496 415 489 21 1 0 0 0 0 24 0 1 0 885128146 2674688 285 1283457024 134512640 135304128 4287631696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3259/statm: 653 285 235 194 0 39 0
[pid=3262] ppid=3259 vsize=25100 CPUtime=0.96
/proc/3262/stat : 3262 (apt-get) R 3259 3238 4159 34819 4229 4202496 5598 0 8 0 88 8 0 0 25 0 1 0 885128164 25702400 5490 1283457024 134512640 134649604 4292950256 18446744073709551615 4159208316 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/3262/statm: 6275 5490 4861 34 0 639 0
Current children cumulated CPU time (s) 214.18
Current children cumulated vsize (KiB) 80052

[startup+219.209 s]
/proc/loadavg: 1.06 1.03 1.00 2/45 3262
/proc/meminfo: memFree=935424/1048576 swapFree=2080268/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=50664 CPUtime=19.73
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 13126 35706 26 297 1000 43 781 149 18 0 1 0 885106447 51879936 11749 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 12666 11749 5111 301 0 6673 0
[pid=3258] ppid=3241 vsize=0 CPUtime=193.57
/proc/3258/stat : 3258 (wbo) Z 3241 3238 4159 34819 4229 4202508 266302 0 13 0 19207 150 0 0 22 0 1 0 885107648 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/3258/statm: 0 0 0 0 0 0 0
[pid=3259] ppid=3241 vsize=2612 CPUtime=0
/proc/3259/stat : 3259 (apt-get.sh) S 3241 3238 4159 34819 4229 4202496 415 489 21 1 0 0 0 0 24 0 1 0 885128146 2674688 285 1283457024 134512640 135304128 4287631696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3259/statm: 653 285 235 194 0 39 0
[pid=3262] ppid=3259 vsize=25348 CPUtime=1.68
/proc/3262/stat : 3262 (apt-get) R 3259 3238 4159 34819 4229 4202496 5630 0 8 0 156 12 0 0 25 0 1 0 885128164 25956352 5522 1283457024 134512640 134649604 4292950256 18446744073709551615 4157381350 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/3262/statm: 6337 5522 4861 34 0 701 0
Current children cumulated CPU time (s) 214.98
Current children cumulated vsize (KiB) 80300

[startup+219.604 s]
/proc/loadavg: 1.06 1.03 1.00 2/45 3262
/proc/meminfo: memFree=935424/1048576 swapFree=2080268/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=50664 CPUtime=215.35
/proc/3241/stat : 3241 (apt-pbo) S 3238 3238 4159 34819 4229 4202496 14261 308558 26 341 1004 47 20159 325 19 0 1 0 885106447 51879936 11756 1283457024 134512640 135744540 4291380368 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/3241/statm: 12666 11756 5118 301 0 6673 0
Current children cumulated CPU time (s) 215.35
Current children cumulated vsize (KiB) 52340

[startup+219.708 s]
/proc/loadavg: 1.06 1.03 1.00 2/45 3262
/proc/meminfo: memFree=935424/1048576 swapFree=2080268/2097144
[pid=3238] ppid=3237 vsize=1676 CPUtime=0
/proc/3238/stat : 3238 (sh) S 3237 3238 4159 34819 4229 4202496 220 175 0 0 0 0 0 0 25 0 1 0 885106447 1716224 128 1283457024 134512640 134594024 4291157648 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/3238/statm: 419 128 112 20 0 45 0
[pid=3241] ppid=3238 vsize=29936 CPUtime=215.36
/proc/3241/stat : 3241 (apt-pbo) R 3238 3238 4159 34819 4229 4202496 14683 308558 26 341 1005 47 20159 325 18 0 1 0 885106447 30654464 6828 1283457024 134512640 135744540 4291380368 18446744073709551615 4159054884 0 0 128 0 0 0 0 17 0 0 0 0
/proc/3241/statm: 7484 6828 656 301 0 6217 0
Current children cumulated CPU time (s) 215.36
Current children cumulated vsize (KiB) 31612

Child status: 0
Real time (s): 219.726
CPU time (s): 215.381
CPU user time (s): 211.649
CPU system time (s): 3.73223
CPU usage (%): 98.0229
Max. virtual memory (cumulated for all children) (KiB): 1096812

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 211.649
system time used= 3.73223
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 323762
page faults= 370
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 101872
involuntary context switches= 104335

runsolver used 0 second user time and 0.008 second system time

The end