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/randf406d5.cudf.difficult.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/2010/difficult//randf406d5.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/randf406d5.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: 0.99 0.98 0.99 5/41 7228
/proc/meminfo: memFree=695300/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) R 7226 7227 4159 34819 4229 4202496 205 0 0 0 0 0 0 0 25 0 1 0 885642446 1712128 126 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/7227/statm: 418 126 110 20 0 44 0
[pid=7228] ppid=7227 vsize=1672 CPUtime=0
/proc/7228/stat : 7228 (sh) R 7227 7227 4159 34819 4229 4202560 0 0 0 0 0 0 0 0 25 0 1 0 885642447 1712128 16 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/7228/statm: 418 16 0 20 0 44 0

[startup+0.184631 s]
/proc/loadavg: 0.99 0.98 0.99 5/41 7228
/proc/meminfo: memFree=695300/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1672

[startup+0.204633 s]
/proc/loadavg: 0.99 0.98 0.99 5/41 7228
/proc/meminfo: memFree=695300/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1672

[startup+0.304662 s]
/proc/loadavg: 0.99 0.98 0.99 5/41 7228
/proc/meminfo: memFree=695300/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1672

[startup+0.704753 s]
/proc/loadavg: 0.99 0.98 0.99 5/41 7228
/proc/meminfo: memFree=695300/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1672

[startup+1.50494 s]
/proc/loadavg: 0.99 0.98 0.99 2/43 7233
/proc/meminfo: memFree=670216/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=8348 CPUtime=0.05
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 1608 412 0 0 4 1 0 0 25 0 1 0 885642447 8548352 1421 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 2087 1421 646 301 0 820 0
[pid=7233] ppid=7230 vsize=33196 CPUtime=1.44
/proc/7233/stat : 7233 (cudftodeb.nativ) R 7230 7227 4159 34819 4229 4202496 7886 0 0 0 143 1 0 0 25 0 1 0 885642452 33992704 7804 1283457024 134512640 135029684 4292874176 18446744073709551615 134977563 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/7233/statm: 8299 7804 247 127 0 7682 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 43216

[startup+3.10526 s]
/proc/loadavg: 0.99 0.98 0.99 2/43 7233
/proc/meminfo: memFree=647772/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=8348 CPUtime=0.05
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 1608 412 0 0 4 1 0 0 25 0 1 0 885642447 8548352 1421 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 2087 1421 646 301 0 820 0
[pid=7233] ppid=7230 vsize=67224 CPUtime=3.03
/proc/7233/stat : 7233 (cudftodeb.nativ) R 7230 7227 4159 34819 4229 4202496 16379 0 0 0 296 7 0 0 25 0 1 0 885642452 68837376 16297 1283457024 134512640 135029684 4292874176 18446744073709551615 134885856 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/7233/statm: 16806 16297 258 127 0 16189 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 77244

[startup+6.31065 s]
/proc/loadavg: 1.07 1.00 0.99 2/43 7233
/proc/meminfo: memFree=640216/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=8348 CPUtime=0.05
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 1608 412 0 0 4 1 0 0 25 0 1 0 885642447 8548352 1421 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 2087 1421 646 301 0 820 0
[pid=7233] ppid=7230 vsize=47064 CPUtime=6.15
/proc/7233/stat : 7233 (cudftodeb.nativ) R 7230 7227 4159 34819 4229 4202496 19917 0 0 0 522 93 0 0 25 0 1 0 885642452 48193536 11335 1283457024 134512640 135029684 4292874176 18446744073709551615 4158879269 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/7233/statm: 11766 11335 258 127 0 11149 0
Current children cumulated CPU time (s) 6.2
Current children cumulated vsize (KiB) 57084

[startup+12.7056 s]
/proc/loadavg: 1.07 1.00 0.99 2/43 7247
/proc/meminfo: memFree=608352/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=31504 CPUtime=10.15
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 7740 35739 0 267 28 20 810 157 18 0 1 0 885642447 32260096 7017 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 7876 7017 5164 301 0 1883 0
[pid=7247] ppid=7230 vsize=14424 CPUtime=0.92
/proc/7247/stat : 7247 (wbo) R 7230 7227 4159 34819 4229 4202496 3978 0 0 0 86 6 0 0 21 0 1 0 885643625 14770176 3327 1283457024 4194304 5578286 140735300893392 18446744073709551615 4289880 0 0 0 3 0 0 0 17 0 0 0 0
/proc/7247/statm: 3606 3327 158 338 0 3265 0
Current children cumulated CPU time (s) 11.07
Current children cumulated vsize (KiB) 47600

[startup+25.5081 s]
/proc/loadavg: 1.05 1.00 0.99 2/43 7247
/proc/meminfo: memFree=577360/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=31504 CPUtime=10.15
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 7740 35739 0 267 28 20 810 157 18 0 1 0 885642447 32260096 7017 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 7876 7017 5164 301 0 1883 0
[pid=7247] ppid=7230 vsize=42384 CPUtime=13.72
/proc/7247/stat : 7247 (wbo) R 7230 7227 4159 34819 4229 4202496 10978 0 0 0 1354 18 0 0 25 0 1 0 885643625 43401216 10327 1283457024 4194304 5578286 140735300893392 18446744073709551615 4273264 0 0 0 3 0 0 0 17 0 0 0 0
/proc/7247/statm: 10596 10327 158 338 0 10255 0
Current children cumulated CPU time (s) 23.87
Current children cumulated vsize (KiB) 75560

[startup+51.103 s]
/proc/loadavg: 1.03 1.00 0.99 2/43 7247
/proc/meminfo: memFree=566076/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=31504 CPUtime=10.15
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 7740 35739 0 267 28 20 810 157 18 0 1 0 885642447 32260096 7017 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 7876 7017 5164 301 0 1883 0
[pid=7247] ppid=7230 vsize=52936 CPUtime=39.27
/proc/7247/stat : 7247 (wbo) R 7230 7227 4159 34819 4229 4202496 13616 0 0 0 3906 21 0 0 25 0 1 0 885643625 54206464 12965 1283457024 4194304 5578286 140735300893392 18446744073709551615 4200272 0 0 0 3 0 0 0 17 0 0 0 0
/proc/7247/statm: 13234 12965 158 338 0 12893 0
Current children cumulated CPU time (s) 49.42
Current children cumulated vsize (KiB) 86112

[startup+102.307 s]
/proc/loadavg: 1.01 1.00 0.99 2/43 7247
/proc/meminfo: memFree=552312/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=31504 CPUtime=10.15
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 7740 35739 0 267 28 20 810 157 18 0 1 0 885642447 32260096 7017 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 7876 7017 5164 301 0 1883 0
[pid=7247] ppid=7230 vsize=67532 CPUtime=90.43
/proc/7247/stat : 7247 (wbo) R 7230 7227 4159 34819 4229 4202496 17257 0 0 0 9011 32 0 0 25 0 1 0 885643625 69152768 16606 1283457024 4194304 5578286 140735300893392 18446744073709551615 4200272 0 0 0 3 0 0 0 17 0 0 0 0
/proc/7247/statm: 16883 16606 158 338 0 16542 0
Current children cumulated CPU time (s) 100.58
Current children cumulated vsize (KiB) 100708

[startup+162.311 s]
/proc/loadavg: 1.00 1.00 0.99 2/43 7247
/proc/meminfo: memFree=546732/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=31504 CPUtime=10.15
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 7740 35739 0 267 28 20 810 157 18 0 1 0 885642447 32260096 7017 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 7876 7017 5164 301 0 1883 0
[pid=7247] ppid=7230 vsize=73092 CPUtime=150.37
/proc/7247/stat : 7247 (wbo) R 7230 7227 4159 34819 4229 4202496 18637 0 0 0 14995 42 0 0 25 0 1 0 885643625 74846208 17986 1283457024 4194304 5578286 140735300893392 18446744073709551615 4289914 0 0 0 3 0 0 0 17 0 0 0 0
/proc/7247/statm: 18273 17986 158 338 0 17932 0
Current children cumulated CPU time (s) 160.52
Current children cumulated vsize (KiB) 106268

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

[startup+179.215 s]
/proc/loadavg: 1.00 1.00 0.99 2/43 7247
/proc/meminfo: memFree=546732/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=31504 CPUtime=10.15
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 7740 35739 0 267 28 20 810 157 18 0 1 0 885642447 32260096 7017 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 7876 7017 5164 301 0 1883 0
[pid=7247] ppid=7230 vsize=73092 CPUtime=167.24
/proc/7247/stat : 7247 (wbo) R 7230 7227 4159 34819 4229 4202496 18637 0 0 0 16681 43 0 0 25 0 1 0 885643625 74846208 17986 1283457024 4194304 5578286 140735300893392 18446744073709551615 4289940 0 0 0 3 0 0 0 17 0 0 0 0
/proc/7247/statm: 18273 17986 158 338 0 17932 0
Current children cumulated CPU time (s) 177.39
Current children cumulated vsize (KiB) 106268

[startup+192.011 s]
/proc/loadavg: 1.00 1.00 0.99 2/43 7247
/proc/meminfo: memFree=546732/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=31504 CPUtime=10.15
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 7740 35739 0 267 28 20 810 157 18 0 1 0 885642447 32260096 7017 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 7876 7017 5164 301 0 1883 0
[pid=7247] ppid=7230 vsize=73092 CPUtime=180.02
/proc/7247/stat : 7247 (wbo) R 7230 7227 4159 34819 4229 4202496 18637 0 0 0 17959 43 0 0 25 0 1 0 885643625 74846208 17986 1283457024 4194304 5578286 140735300893392 18446744073709551615 4273264 0 0 0 3 0 0 0 17 0 0 0 0
/proc/7247/statm: 18273 17986 158 338 0 17932 0
Current children cumulated CPU time (s) 190.17
Current children cumulated vsize (KiB) 106268

[startup+198.413 s]
/proc/loadavg: 1.00 1.00 0.99 2/43 7247
/proc/meminfo: memFree=21592/1048576 swapFree=2077680/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=31504 CPUtime=10.15
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 7745 35739 0 267 28 20 810 157 18 0 1 0 885642447 32260096 7017 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 7876 7017 5164 301 0 1883 0
[pid=7247] ppid=7230 vsize=633812 CPUtime=186.4
/proc/7247/stat : 7247 (wbo) R 7230 7227 4159 34819 4229 4202496 159020 0 0 0 18564 76 0 0 25 0 1 0 885643625 649023488 158183 1283457024 4194304 5578286 140735300893392 18446744073709551615 4290370 0 0 0 3 0 0 0 17 0 0 0 0
/proc/7247/statm: 158453 158183 160 338 0 158112 0
Current children cumulated CPU time (s) 196.55
Current children cumulated vsize (KiB) 666988

[startup+201.605 s]
/proc/loadavg: 1.08 1.01 1.00 2/43 7247
/proc/meminfo: memFree=834324/1048576 swapFree=2080288/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=34252 CPUtime=11.09
/proc/7230/stat : 7230 (apt-pbo) R 7227 7227 4159 34819 4229 4202496 8800 35739 0 267 122 20 810 157 19 0 1 0 885642447 35074048 7709 1283457024 134512640 135744540 4294754592 18446744073709551615 4157983825 0 0 128 0 0 0 0 17 0 0 0 0
/proc/7230/statm: 8563 7709 5168 301 0 2570 0
[pid=7247] ppid=7230 vsize=0 CPUtime=188.59
/proc/7247/stat : 7247 (wbo) Z 7230 7227 4159 34819 4229 4202508 208177 0 0 0 18755 104 0 0 25 0 1 0 885643625 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/7247/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 199.68
Current children cumulated vsize (KiB) 35924

[startup+204.812 s]
/proc/loadavg: 1.07 1.01 1.00 2/45 7251
/proc/meminfo: memFree=830576/1048576 swapFree=2080288/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=37964 CPUtime=13.01
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 9748 35739 0 267 310 24 810 157 18 0 1 0 885642447 38875136 8625 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 9491 8625 5168 301 0 3498 0
[pid=7247] ppid=7230 vsize=0 CPUtime=188.59
/proc/7247/stat : 7247 (wbo) Z 7230 7227 4159 34819 4229 4202508 208177 0 0 0 18755 104 0 0 25 0 1 0 885643625 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/7247/statm: 0 0 0 0 0 0 0
[pid=7248] ppid=7230 vsize=2600 CPUtime=0
/proc/7248/stat : 7248 (apt-get.sh) S 7230 7227 4159 34819 4229 4202496 428 490 2 1 0 0 0 0 25 0 1 0 885662791 2662400 283 1283457024 134512640 135304128 4294662368 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7248/statm: 650 283 235 194 0 36 0
[pid=7251] ppid=7248 vsize=25104 CPUtime=1.1
/proc/7251/stat : 7251 (apt-get) R 7248 7227 4159 34819 4229 4202496 5612 0 2 0 98 12 0 0 25 0 1 0 885662800 25706496 5498 1283457024 134512640 134649604 4289832608 18446744073709551615 4157254813 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/7251/statm: 6276 5498 4859 34 0 640 0
Current children cumulated CPU time (s) 202.7
Current children cumulated vsize (KiB) 67340

[startup+205.612 s]
/proc/loadavg: 1.07 1.01 1.00 2/45 7251
/proc/meminfo: memFree=830576/1048576 swapFree=2080288/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=37964 CPUtime=13.08
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 9748 35739 0 267 313 28 810 157 18 0 1 0 885642447 38875136 8625 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 9491 8625 5168 301 0 3498 0
[pid=7247] ppid=7230 vsize=0 CPUtime=188.59
/proc/7247/stat : 7247 (wbo) Z 7230 7227 4159 34819 4229 4202508 208177 0 0 0 18755 104 0 0 25 0 1 0 885643625 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/7247/statm: 0 0 0 0 0 0 0
[pid=7248] ppid=7230 vsize=2600 CPUtime=0
/proc/7248/stat : 7248 (apt-get.sh) S 7230 7227 4159 34819 4229 4202496 428 490 2 1 0 0 0 0 25 0 1 0 885662791 2662400 283 1283457024 134512640 135304128 4294662368 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7248/statm: 650 283 235 194 0 36 0
[pid=7251] ppid=7248 vsize=25352 CPUtime=1.83
/proc/7251/stat : 7251 (apt-get) R 7248 7227 4159 34819 4229 4202496 5636 0 2 0 162 21 0 0 25 0 1 0 885662800 25960448 5522 1283457024 134512640 134649604 4289832608 18446744073709551615 4157283570 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/7251/statm: 6338 5522 4859 34 0 702 0
Current children cumulated CPU time (s) 203.5
Current children cumulated vsize (KiB) 67588

[startup+206.013 s]
/proc/loadavg: 1.07 1.01 1.00 2/45 7251
/proc/meminfo: memFree=829088/1048576 swapFree=2080288/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=37964 CPUtime=13.15
/proc/7230/stat : 7230 (apt-pbo) S 7227 7227 4159 34819 4229 4202496 9748 35739 0 267 316 32 810 157 18 0 1 0 885642447 38875136 8625 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/7230/statm: 9491 8625 5168 301 0 3498 0
[pid=7247] ppid=7230 vsize=0 CPUtime=188.59
/proc/7247/stat : 7247 (wbo) Z 7230 7227 4159 34819 4229 4202508 208177 0 0 0 18755 104 0 0 25 0 1 0 885643625 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/7247/statm: 0 0 0 0 0 0 0
[pid=7248] ppid=7230 vsize=2600 CPUtime=0
/proc/7248/stat : 7248 (apt-get.sh) S 7230 7227 4159 34819 4229 4202496 428 490 2 1 0 0 0 0 25 0 1 0 885662791 2662400 283 1283457024 134512640 135304128 4294662368 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7248/statm: 650 283 235 194 0 36 0
[pid=7251] ppid=7248 vsize=25352 CPUtime=2.16
/proc/7251/stat : 7251 (apt-get) R 7248 7227 4159 34819 4229 4202496 5641 0 2 0 186 30 0 0 25 0 1 0 885662800 25960448 5527 1283457024 134512640 134649604 4289832608 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/7251/statm: 6338 5527 4860 34 0 702 0
Current children cumulated CPU time (s) 203.9
Current children cumulated vsize (KiB) 67588

[startup+206.203 s]
/proc/loadavg: 1.07 1.01 1.00 2/45 7251
/proc/meminfo: memFree=829088/1048576 swapFree=2080288/2097144
[pid=7227] ppid=7226 vsize=1672 CPUtime=0
/proc/7227/stat : 7227 (sh) S 7226 7227 4159 34819 4229 4202496 220 174 0 0 0 0 0 0 25 0 1 0 885642446 1712128 128 1283457024 134512640 134594024 4292321184 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/7227/statm: 418 128 112 20 0 44 0
[pid=7230] ppid=7227 vsize=38108 CPUtime=204
/proc/7230/stat : 7230 (apt-pbo) D 7227 7227 4159 34819 4229 4202496 11129 250488 0 272 317 33 19754 296 20 0 1 0 885642447 39022592 8671 1283457024 134512640 135744540 4294754592 18446744073709551615 4294960130 0 0 128 0 18446744071564252162 0 0 17 0 0 0 0
/proc/7230/statm: 9527 8671 5168 301 0 3534 0
Current children cumulated CPU time (s) 204
Current children cumulated vsize (KiB) 39780

Child status: 0
Real time (s): 206.247
CPU time (s): 204.021
CPU user time (s): 200.717
CPU system time (s): 3.30421
CPU usage (%): 98.9206
Max. virtual memory (cumulated for all children) (KiB): 858044

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 200.717
system time used= 3.30421
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 262262
page faults= 274
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 111508
involuntary context switches= 113876

runsolver used 0.012 second user time and 0 second system time

The end