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/rand915.sarge-etch-lenny-squeeze.cudf.sarge-etch-lenny-squeeze.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/icse/sarge-etch-lenny-squeeze/rand915.sarge-etch-lenny-squeeze.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/rand915.sarge-etch-lenny-squeeze.cudf.sarge-etch-lenny-squeeze.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.00 1.01 1.02 1/44 28028
/proc/meminfo: memFree=727992/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=3020 CPUtime=0
/proc/28028/stat : 28028 (runsolver) D 28027 28028 4159 34819 4229 4202560 72 0 0 0 0 0 0 0 24 0 1 0 883343002 3092480 93 1283457024 134512640 134586868 4287355296 18446744073709551615 4294960130 0 0 0 24578 18446744071564332000 0 0 17 0 0 0 0
/proc/28028/statm: 755 93 62 19 0 53 0

[startup+0.149558 s]
/proc/loadavg: 1.00 1.01 1.02 1/44 28028
/proc/meminfo: memFree=727992/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1680

[startup+0.205569 s]
/proc/loadavg: 1.00 1.01 1.02 1/44 28028
/proc/meminfo: memFree=727992/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1680

[startup+0.305559 s]
/proc/loadavg: 1.00 1.01 1.02 1/44 28028
/proc/meminfo: memFree=727992/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1680

[startup+0.709729 s]
/proc/loadavg: 1.00 1.01 1.02 1/44 28028
/proc/meminfo: memFree=727992/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1680

[startup+1.50994 s]
/proc/loadavg: 1.00 1.01 1.02 2/47 28034
/proc/meminfo: memFree=706688/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=8348 CPUtime=0.03
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 1581 412 29 0 3 0 0 0 25 0 1 0 883343003 8548352 1421 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 2087 1421 646 301 0 820 0
[pid=28034] ppid=28031 vsize=25132 CPUtime=1.1
/proc/28034/stat : 28034 (cudftodeb.nativ) R 28031 28028 4159 34819 4229 4202496 5847 0 10 0 106 4 0 0 25 0 1 0 883343036 25735168 5774 1283457024 134512640 135029684 4290764480 18446744073709551615 135004033 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/28034/statm: 6283 5774 247 127 0 5666 0
Current children cumulated CPU time (s) 1.13
Current children cumulated vsize (KiB) 35160

[startup+3.11039 s]
/proc/loadavg: 1.00 1.01 1.02 2/47 28034
/proc/meminfo: memFree=684988/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=8348 CPUtime=0.03
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 1581 412 29 0 3 0 0 0 25 0 1 0 883343003 8548352 1421 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 2087 1421 646 301 0 820 0
[pid=28034] ppid=28031 vsize=56640 CPUtime=2.7
/proc/28034/stat : 28034 (cudftodeb.nativ) R 28031 28028 4159 34819 4229 4202496 13728 0 10 0 263 7 0 0 25 0 1 0 883343036 57999360 13655 1283457024 134512640 135029684 4290764480 18446744073709551615 134976170 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/28034/statm: 14160 13655 247 127 0 13543 0
Current children cumulated CPU time (s) 2.73
Current children cumulated vsize (KiB) 66668

[startup+6.31135 s]
/proc/loadavg: 1.00 1.01 1.02 2/47 28034
/proc/meminfo: memFree=619888/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=8348 CPUtime=0.03
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 1581 412 29 0 3 0 0 0 25 0 1 0 883343003 8548352 1421 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 2087 1421 646 301 0 820 0
[pid=28034] ppid=28031 vsize=108808 CPUtime=5.9
/proc/28034/stat : 28034 (cudftodeb.nativ) R 28031 28028 4159 34819 4229 4202496 26682 0 10 0 547 43 0 0 25 0 1 0 883343036 111419392 26609 1283457024 134512640 135029684 4290764480 18446744073709551615 4294960130 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/28034/statm: 27202 26609 258 127 0 26585 0
Current children cumulated CPU time (s) 5.93
Current children cumulated vsize (KiB) 118836

[startup+12.7064 s]
/proc/loadavg: 1.00 1.01 1.02 2/48 28042
/proc/meminfo: memFree=661236/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=8348 CPUtime=9.77
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 1756 30096 29 10 4 0 827 146 19 0 1 0 883343003 8548352 1447 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/28031/statm: 2087 1447 651 301 0 820 0
[pid=28035] ppid=28031 vsize=2576 CPUtime=0
/proc/28035/stat : 28035 (apt-get.sh) S 28031 28028 4159 34819 4229 4202496 409 489 0 0 0 0 0 0 20 0 1 0 883344018 2637824 275 1283457024 134512640 135304128 4291526288 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28035/statm: 644 275 235 194 0 30 0
[pid=28038] ppid=28035 vsize=52748 CPUtime=1.54
/proc/28038/stat : 28038 (apt-get) D 28035 28028 4159 34819 4229 4202496 6913 1685 383 0 115 4 31 4 18 0 1 0 883344019 54013952 7164 1283457024 134512640 134649604 4294480144 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/28038/statm: 13187 7164 7108 34 0 69 0
Current children cumulated CPU time (s) 11.31
Current children cumulated vsize (KiB) 65352

[startup+25.5083 s]
/proc/loadavg: 1.08 1.03 1.02 2/47 28048
/proc/meminfo: memFree=560928/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=40480 CPUtime=19.48
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 10043 49450 29 413 68 56 1532 292 18 0 1 0 883343003 41451520 9129 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 10120 9129 7161 301 0 2006 0
[pid=28048] ppid=28031 vsize=38008 CPUtime=3.18
/proc/28048/stat : 28048 (wbo) R 28031 28028 4159 34819 4229 4202496 11325 0 16 0 306 12 0 0 25 0 1 0 883345222 38920192 9076 1283457024 4194304 5578286 140735256051648 18446744073709551615 4289932 0 0 0 3 0 0 0 17 0 0 0 0
/proc/28048/statm: 9502 9076 158 338 0 9161 0
Current children cumulated CPU time (s) 22.66
Current children cumulated vsize (KiB) 80168

[startup+51.1144 s]
/proc/loadavg: 1.05 1.02 1.02 2/47 28048
/proc/meminfo: memFree=519264/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=40480 CPUtime=19.48
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 10043 49450 29 413 68 56 1532 292 18 0 1 0 883343003 41451520 9129 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 10120 9129 7161 301 0 2006 0
[pid=28048] ppid=28031 vsize=80472 CPUtime=28.78
/proc/28048/stat : 28048 (wbo) R 28031 28028 4159 34819 4229 4202496 21931 0 16 0 2852 26 0 0 25 0 1 0 883345222 82403328 19682 1283457024 4194304 5578286 140735256051648 18446744073709551615 4200752 0 0 0 3 0 0 0 17 0 0 0 0
/proc/28048/statm: 20118 19682 158 338 0 19777 0
Current children cumulated CPU time (s) 48.26
Current children cumulated vsize (KiB) 122632

[startup+102.307 s]
/proc/loadavg: 1.02 1.02 1.01 2/47 28048
/proc/meminfo: memFree=478840/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=40480 CPUtime=19.48
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 10043 49450 29 413 68 56 1532 292 18 0 1 0 883343003 41451520 9129 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 10120 9129 7161 301 0 2006 0
[pid=28048] ppid=28031 vsize=119656 CPUtime=79.88
/proc/28048/stat : 28048 (wbo) R 28031 28028 4159 34819 4229 4202496 31727 0 16 0 7954 34 0 0 25 0 1 0 883345222 122527744 29478 1283457024 4194304 5578286 140735256051648 18446744073709551615 4200704 0 0 0 3 0 0 0 17 0 0 0 0
/proc/28048/statm: 29914 29478 158 338 0 29573 0
Current children cumulated CPU time (s) 99.36
Current children cumulated vsize (KiB) 161816

[startup+162.312 s]
/proc/loadavg: 1.00 1.01 1.01 2/47 28048
/proc/meminfo: memFree=423536/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=40480 CPUtime=19.48
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 10043 49450 29 413 68 56 1532 292 18 0 1 0 883343003 41451520 9129 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 10120 9129 7161 301 0 2006 0
[pid=28048] ppid=28031 vsize=175800 CPUtime=139.85
/proc/28048/stat : 28048 (wbo) R 28031 28028 4159 34819 4229 4202496 45740 0 16 0 13929 56 0 0 25 0 1 0 883345222 180019200 43491 1283457024 4194304 5578286 140735256051648 18446744073709551615 4289893 0 0 0 3 0 0 0 17 0 0 0 0
/proc/28048/statm: 43950 43491 158 338 0 43609 0
Current children cumulated CPU time (s) 159.33
Current children cumulated vsize (KiB) 217960

[startup+222.311 s]
/proc/loadavg: 1.00 1.01 1.00 2/47 28048
/proc/meminfo: memFree=79064/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=40480 CPUtime=19.48
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 10049 49450 29 413 68 56 1532 292 18 0 1 0 883343003 41451520 9129 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 10120 9129 7161 301 0 2006 0
[pid=28048] ppid=28031 vsize=520068 CPUtime=199.79
/proc/28048/stat : 28048 (wbo) R 28031 28028 4159 34819 4229 4202496 132972 0 16 0 19893 86 0 0 25 0 1 0 883345222 532549632 129697 1283457024 4194304 5578286 140735256051648 18446744073709551615 4315183 0 0 0 3 0 0 0 17 0 0 0 0
/proc/28048/statm: 130017 129697 160 338 0 129676 0
Current children cumulated CPU time (s) 219.27
Current children cumulated vsize (KiB) 562228

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

[startup+230.413 s]
/proc/loadavg: 1.00 1.01 1.00 2/47 28048
/proc/meminfo: memFree=5856/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=40480 CPUtime=19.48
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 10049 49450 29 413 68 56 1532 292 18 0 1 0 883343003 41451520 9129 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 10120 9129 7161 301 0 2006 0
[pid=28048] ppid=28031 vsize=706824 CPUtime=207.88
/proc/28048/stat : 28048 (wbo) R 28031 28028 4159 34819 4229 4202496 179716 0 16 0 20688 100 0 0 25 0 1 0 883345222 723787776 176441 1283457024 4194304 5578286 140735256051648 18446744073709551615 4199344 0 0 0 3 0 0 0 17 0 0 0 0
/proc/28048/statm: 176706 176441 160 338 0 176365 0
Current children cumulated CPU time (s) 227.36
Current children cumulated vsize (KiB) 748984

[startup+243.212 s]
/proc/loadavg: 1.00 1.01 1.00 2/47 28048
/proc/meminfo: memFree=841548/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=71632 CPUtime=24.77
/proc/28031/stat : 28031 (apt-pbo) R 28028 28028 4159 34819 4229 4202496 18184 49450 30 413 594 59 1532 292 25 0 1 0 883343003 73351168 16893 1283457024 134512640 135744540 4287418032 18446744073709551615 135069684 0 0 128 0 0 0 0 17 0 0 0 0
/proc/28031/statm: 17908 16893 7166 301 0 9794 0
[pid=28048] ppid=28031 vsize=0 CPUtime=215.1
/proc/28048/stat : 28048 (wbo) Z 28031 28028 4159 34819 4229 4202508 219603 0 18 0 21391 119 0 0 25 0 1 0 883345222 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/28048/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 239.87
Current children cumulated vsize (KiB) 73312

[startup+249.613 s]
/proc/loadavg: 1.00 1.00 1.00 2/47 28048
/proc/meminfo: memFree=841548/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=71488 CPUtime=31.17
/proc/28031/stat : 28031 (apt-pbo) R 28028 28028 4159 34819 4229 4202496 18189 49450 30 413 1234 59 1532 292 25 0 1 0 883343003 73203712 16862 1283457024 134512640 135744540 4287418032 18446744073709551615 135069684 0 0 128 0 0 0 0 17 0 0 0 0
/proc/28031/statm: 17872 16862 7166 301 0 9758 0
[pid=28048] ppid=28031 vsize=0 CPUtime=215.1
/proc/28048/stat : 28048 (wbo) Z 28031 28028 4159 34819 4229 4202508 219603 0 18 0 21391 119 0 0 25 0 1 0 883345222 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/28048/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 246.27
Current children cumulated vsize (KiB) 73168

[startup+256.015 s]
/proc/loadavg: 1.08 1.02 1.01 2/49 28052
/proc/meminfo: memFree=851368/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=71488 CPUtime=33.85
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 18223 49450 30 413 1477 84 1532 292 18 0 1 0 883343003 73203712 16862 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 17872 16862 7166 301 0 9758 0
[pid=28048] ppid=28031 vsize=0 CPUtime=215.1
/proc/28048/stat : 28048 (wbo) Z 28031 28028 4159 34819 4229 4202508 219603 0 18 0 21391 119 0 0 25 0 1 0 883345222 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/28048/statm: 0 0 0 0 0 0 0
[pid=28049] ppid=28031 vsize=2692 CPUtime=0
/proc/28049/stat : 28049 (apt-get.sh) S 28031 28028 4159 34819 4229 4202496 475 494 0 0 0 0 0 0 25 0 1 0 883368181 2756608 306 1283457024 134512640 135304128 4292959024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28049/statm: 673 306 235 194 0 59 0
[pid=28052] ppid=28049 vsize=34124 CPUtime=3.69
/proc/28052/stat : 28052 (apt-get) R 28049 28028 4159 34819 4229 4202496 7754 0 0 0 315 54 0 0 25 0 1 0 883368183 34942976 7632 1283457024 134512640 134649604 4289050544 18446744073709551615 4159565216 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/28052/statm: 8531 7632 6855 34 0 774 0
Current children cumulated CPU time (s) 252.64
Current children cumulated vsize (KiB) 109984

[startup+257.609 s]
/proc/loadavg: 1.15 1.04 1.01 2/49 28052
/proc/meminfo: memFree=848640/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=71488 CPUtime=34.12
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 18223 49450 30 413 1488 100 1532 292 18 0 1 0 883343003 73203712 16862 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 17872 16862 7166 301 0 9758 0
[pid=28048] ppid=28031 vsize=0 CPUtime=215.1
/proc/28048/stat : 28048 (wbo) Z 28031 28028 4159 34819 4229 4202508 219603 0 18 0 21391 119 0 0 25 0 1 0 883345222 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/28048/statm: 0 0 0 0 0 0 0
[pid=28049] ppid=28031 vsize=2692 CPUtime=0
/proc/28049/stat : 28049 (apt-get.sh) S 28031 28028 4159 34819 4229 4202496 475 494 0 0 0 0 0 0 25 0 1 0 883368181 2756608 306 1283457024 134512640 135304128 4292959024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28049/statm: 673 306 235 194 0 59 0
[pid=28052] ppid=28049 vsize=34380 CPUtime=4.94
/proc/28052/stat : 28052 (apt-get) R 28049 28028 4159 34819 4229 4202496 7798 0 0 0 424 70 0 0 25 0 1 0 883368183 35205120 7676 1283457024 134512640 134649604 4289050544 18446744073709551615 4158668500 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/28052/statm: 8595 7676 6855 34 0 838 0
Current children cumulated CPU time (s) 254.16
Current children cumulated vsize (KiB) 110240

[startup+259.21 s]
/proc/loadavg: 1.15 1.04 1.01 2/49 28052
/proc/meminfo: memFree=847400/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=71488 CPUtime=34.29
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 18223 49450 30 413 1495 110 1532 292 18 0 1 0 883343003 73203712 16862 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 17872 16862 7166 301 0 9758 0
[pid=28048] ppid=28031 vsize=0 CPUtime=215.1
/proc/28048/stat : 28048 (wbo) Z 28031 28028 4159 34819 4229 4202508 219603 0 18 0 21391 119 0 0 25 0 1 0 883345222 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/28048/statm: 0 0 0 0 0 0 0
[pid=28049] ppid=28031 vsize=2692 CPUtime=0
/proc/28049/stat : 28049 (apt-get.sh) S 28031 28028 4159 34819 4229 4202496 475 494 0 0 0 0 0 0 25 0 1 0 883368181 2756608 306 1283457024 134512640 135304128 4292959024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28049/statm: 673 306 235 194 0 59 0
[pid=28052] ppid=28049 vsize=34380 CPUtime=6.37
/proc/28052/stat : 28052 (apt-get) R 28049 28028 4159 34819 4229 4202496 7811 0 0 0 546 91 0 0 25 0 1 0 883368183 35205120 7689 1283457024 134512640 134649604 4289050544 18446744073709551615 4156914475 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/28052/statm: 8595 7689 6855 34 0 838 0
Current children cumulated CPU time (s) 255.76
Current children cumulated vsize (KiB) 110240

[startup+259.61 s]
/proc/loadavg: 1.15 1.04 1.01 2/49 28052
/proc/meminfo: memFree=841696/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=71488 CPUtime=34.34
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 18223 49450 30 413 1496 114 1532 292 18 0 1 0 883343003 73203712 16862 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 17872 16862 7166 301 0 9758 0
[pid=28048] ppid=28031 vsize=0 CPUtime=215.1
/proc/28048/stat : 28048 (wbo) Z 28031 28028 4159 34819 4229 4202508 219603 0 18 0 21391 119 0 0 25 0 1 0 883345222 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/28048/statm: 0 0 0 0 0 0 0
[pid=28049] ppid=28031 vsize=2692 CPUtime=0
/proc/28049/stat : 28049 (apt-get.sh) S 28031 28028 4159 34819 4229 4202496 475 494 0 0 0 0 0 0 25 0 1 0 883368181 2756608 306 1283457024 134512640 135304128 4292959024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28049/statm: 673 306 235 194 0 59 0
[pid=28052] ppid=28049 vsize=34380 CPUtime=6.73
/proc/28052/stat : 28052 (apt-get) R 28049 28028 4159 34819 4229 4202496 7815 0 0 0 569 104 0 0 25 0 1 0 883368183 35205120 7693 1283457024 134512640 134649604 4289050544 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/28052/statm: 8595 7693 6856 34 0 838 0
Current children cumulated CPU time (s) 256.17
Current children cumulated vsize (KiB) 110240

[startup+260.01 s]
/proc/loadavg: 1.15 1.04 1.01 2/49 28052
/proc/meminfo: memFree=841696/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=71488 CPUtime=256.35
/proc/28031/stat : 28031 (apt-pbo) S 28028 28028 4159 34819 4229 4202496 19874 277850 30 431 1497 116 23493 529 18 0 1 0 883343003 73203712 16862 1283457024 134512640 135744540 4287418032 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28031/statm: 17872 16862 7166 301 0 9758 0
Current children cumulated CPU time (s) 256.35
Current children cumulated vsize (KiB) 73168

[startup+260.103 s]
/proc/loadavg: 1.15 1.04 1.01 2/49 28052
/proc/meminfo: memFree=841696/1048576 swapFree=2077608/2097144
[pid=28028] ppid=28027 vsize=1680 CPUtime=0
/proc/28028/stat : 28028 (sh) S 28027 28028 4159 34819 4229 4202496 222 176 0 0 0 0 0 0 25 0 1 0 883343002 1720320 129 1283457024 134512640 134594024 4292511632 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28028/statm: 420 129 112 20 0 46 0
[pid=28031] ppid=28028 vsize=71284 CPUtime=256.39
/proc/28031/stat : 28031 (apt-pbo) R 28028 28028 4159 34819 4229 4202496 20331 277850 30 431 1500 117 23493 529 18 0 1 0 883343003 72994816 16810 1283457024 134512640 135744540 4287418032 18446744073709551615 135211976 0 0 128 0 0 0 0 17 0 0 0 0
/proc/28031/statm: 17821 16810 7166 301 0 9707 0
Current children cumulated CPU time (s) 256.39
Current children cumulated vsize (KiB) 72964

Child status: 0
Real time (s): 260.149
CPU time (s): 256.416
CPU user time (s): 249.952
CPU system time (s): 6.4644
CPU usage (%): 98.5652
Max. virtual memory (cumulated for all children) (KiB): 908608

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 249.952
system time used= 6.4644
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 298841
page faults= 462
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 355381
involuntary context switches= 358476

runsolver used 0 second user time and 0.004 second system time

The end