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.cudf.sarge-etch.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/icse/sarge-etch/rand915.sarge-etch.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/rand915.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.19 1.10 1.03 1/44 28545
/proc/meminfo: memFree=811752/1048576 swapFree=2077608/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) R 28544 28545 4159 34819 4229 4202496 206 0 0 0 0 0 0 0 25 0 1 0 883505529 1720320 127 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/28545/statm: 420 127 110 20 0 46 0
[pid=28546] ppid=28545 vsize=1680 CPUtime=0
/proc/28546/stat : 28546 (sh) R 28545 28545 4159 34819 4229 4202560 0 0 0 0 0 0 0 0 25 0 1 0 883505529 1720320 17 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/28546/statm: 420 17 0 20 0 46 0

[startup+0.154636 s]
/proc/loadavg: 1.19 1.10 1.03 1/44 28545
/proc/meminfo: memFree=811752/1048576 swapFree=2077608/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1680

[startup+0.206616 s]
/proc/loadavg: 1.19 1.10 1.03 1/44 28545
/proc/meminfo: memFree=811752/1048576 swapFree=2077608/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1680

[startup+0.311642 s]
/proc/loadavg: 1.19 1.10 1.03 1/44 28545
/proc/meminfo: memFree=811752/1048576 swapFree=2077608/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1680

[startup+0.711725 s]
/proc/loadavg: 1.19 1.10 1.03 1/44 28545
/proc/meminfo: memFree=811752/1048576 swapFree=2077608/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1680

[startup+1.51189 s]
/proc/loadavg: 1.19 1.10 1.03 2/47 28551
/proc/meminfo: memFree=789648/1048576 swapFree=2077608/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=8352 CPUtime=0.03
/proc/28548/stat : 28548 (apt-pbo) S 28545 28545 4159 34819 4229 4202496 1611 413 5 0 2 1 0 0 25 0 1 0 883505530 8552448 1421 1283457024 134512640 135744540 4289015456 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28548/statm: 2088 1421 646 301 0 821 0
[pid=28551] ppid=28548 vsize=28156 CPUtime=1.24
/proc/28551/stat : 28551 (cudftodeb.nativ) R 28548 28545 4159 34819 4229 4202496 6627 0 8 0 122 2 0 0 25 0 1 0 883505550 28831744 6555 1283457024 134512640 135029684 4292607824 18446744073709551615 134842998 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/28551/statm: 7039 6555 247 127 0 6422 0
Current children cumulated CPU time (s) 1.27
Current children cumulated vsize (KiB) 38188

[startup+3.11221 s]
/proc/loadavg: 1.17 1.10 1.03 2/47 28551
/proc/meminfo: memFree=765716/1048576 swapFree=2077608/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=8352 CPUtime=0.03
/proc/28548/stat : 28548 (apt-pbo) S 28545 28545 4159 34819 4229 4202496 1611 413 5 0 2 1 0 0 25 0 1 0 883505530 8552448 1421 1283457024 134512640 135744540 4289015456 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28548/statm: 2088 1421 646 301 0 821 0
[pid=28551] ppid=28548 vsize=51844 CPUtime=2.84
/proc/28551/stat : 28551 (cudftodeb.nativ) R 28548 28545 4159 34819 4229 4202496 12615 0 8 0 242 42 0 0 25 0 1 0 883505550 53088256 12543 1283457024 134512640 135029684 4292607824 18446744073709551615 4294960130 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/28551/statm: 12961 12543 258 127 0 12344 0
Current children cumulated CPU time (s) 2.87
Current children cumulated vsize (KiB) 61876

[startup+6.31109 s]
/proc/loadavg: 1.17 1.10 1.03 1/48 28559
/proc/meminfo: memFree=767472/1048576 swapFree=2077608/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=21828 CPUtime=4.59
/proc/28548/stat : 28548 (apt-pbo) S 28545 28545 4159 34819 4229 4202496 5527 20192 5 196 15 4 366 74 18 0 1 0 883505530 22351872 4683 1283457024 134512640 135744540 4289015456 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28548/statm: 5457 4683 3494 301 0 1229 0
Current children cumulated CPU time (s) 4.59
Current children cumulated vsize (KiB) 23508
heavy processes:

[startup+12.7133 s]
/proc/loadavg: 1.15 1.09 1.03 2/47 28565
/proc/meminfo: memFree=738008/1048576 swapFree=2077608/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=23704 CPUtime=6.64
/proc/28548/stat : 28548 (apt-pbo) S 28545 28545 4159 34819 4229 4202496 6114 24881 5 196 20 18 522 104 18 0 1 0 883505530 24272896 5155 1283457024 134512640 135744540 4289015456 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28548/statm: 5926 5155 3497 301 0 1698 0
[pid=28565] ppid=28548 vsize=24148 CPUtime=4.75
/proc/28565/stat : 28565 (wbo) R 28548 28545 4159 34819 4229 4202496 6296 0 1 0 461 14 0 0 25 0 1 0 883506322 24727552 5760 1283457024 4194304 5578286 140734122551616 18446744073709551615 4200752 0 0 0 3 0 0 0 17 0 0 0 0
/proc/28565/statm: 6037 5760 158 338 0 5696 0
Current children cumulated CPU time (s) 11.39
Current children cumulated vsize (KiB) 49532

[startup+25.5059 s]
/proc/loadavg: 1.12 1.09 1.03 2/47 28565
/proc/meminfo: memFree=722020/1048576 swapFree=2077608/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=23704 CPUtime=6.66
/proc/28548/stat : 28548 (apt-pbo) S 28545 28545 4159 34819 4229 4202496 6114 24881 5 196 21 19 522 104 18 0 1 0 883505530 24272896 5155 1283457024 134512640 135744540 4289015456 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28548/statm: 5926 5155 3497 301 0 1698 0
[pid=28565] ppid=28548 vsize=37464 CPUtime=17.5
/proc/28565/stat : 28565 (wbo) R 28548 28545 4159 34819 4229 4202496 9618 0 1 0 1730 20 0 0 25 0 1 0 883506322 38363136 9082 1283457024 4194304 5578286 140734122551616 18446744073709551615 4289902 0 0 0 3 0 0 0 17 0 0 0 0
/proc/28565/statm: 9366 9082 158 338 0 9025 0
Current children cumulated CPU time (s) 24.16
Current children cumulated vsize (KiB) 62848

[startup+51.1116 s]
/proc/loadavg: 1.08 1.08 1.02 2/47 28565
/proc/meminfo: memFree=710116/1048576 swapFree=2077608/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=23704 CPUtime=6.66
/proc/28548/stat : 28548 (apt-pbo) S 28545 28545 4159 34819 4229 4202496 6114 24881 5 196 21 19 522 104 18 0 1 0 883505530 24272896 5155 1283457024 134512640 135744540 4289015456 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28548/statm: 5926 5155 3497 301 0 1698 0
[pid=28565] ppid=28548 vsize=49444 CPUtime=43.09
/proc/28565/stat : 28565 (wbo) R 28548 28545 4159 34819 4229 4202496 12595 0 1 0 4281 28 0 0 25 0 1 0 883506322 50630656 12059 1283457024 4194304 5578286 140734122551616 18446744073709551615 4289880 0 0 0 3 0 0 0 17 0 0 0 0
/proc/28565/statm: 12361 12059 158 338 0 12020 0
Current children cumulated CPU time (s) 49.75
Current children cumulated vsize (KiB) 74828

[startup+102.315 s]
/proc/loadavg: 1.03 1.07 1.02 2/48 28569
/proc/meminfo: memFree=694188/1048576 swapFree=2077628/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=23704 CPUtime=6.68
/proc/28548/stat : 28548 (apt-pbo) S 28545 28545 4159 34819 4229 4202496 6114 24881 5 196 23 19 522 104 18 0 1 0 883505530 24272896 5155 1283457024 134512640 135744540 4289015456 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28548/statm: 5926 5155 3497 301 0 1698 0
[pid=28565] ppid=28548 vsize=64164 CPUtime=94.24
/proc/28565/stat : 28565 (wbo) R 28548 28545 4159 34819 4229 4202496 16276 0 1 0 9385 39 0 0 25 0 1 0 883506322 65703936 15740 1283457024 4194304 5578286 140734122551616 18446744073709551615 4200704 0 0 0 3 0 0 0 17 0 0 0 0
/proc/28565/statm: 16041 15740 158 338 0 15700 0
Current children cumulated CPU time (s) 100.92
Current children cumulated vsize (KiB) 89548

[startup+162.308 s]
/proc/loadavg: 1.01 1.05 1.01 2/47 28569
/proc/meminfo: memFree=669652/1048576 swapFree=2077628/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=23704 CPUtime=6.68
/proc/28548/stat : 28548 (apt-pbo) S 28545 28545 4159 34819 4229 4202496 6114 24881 5 196 23 19 522 104 18 0 1 0 883505530 24272896 5155 1283457024 134512640 135744540 4289015456 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28548/statm: 5926 5155 3497 301 0 1698 0
[pid=28565] ppid=28548 vsize=88380 CPUtime=154.18
/proc/28565/stat : 28565 (wbo) R 28548 28545 4159 34819 4229 4202496 22315 0 1 0 15362 56 0 0 25 0 1 0 883506322 90501120 21779 1283457024 4194304 5578286 140734122551616 18446744073709551615 4289936 0 0 0 3 0 0 0 17 0 0 0 0
/proc/28565/statm: 22095 21779 158 338 0 21754 0
Current children cumulated CPU time (s) 160.86
Current children cumulated vsize (KiB) 113764

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

[startup+179.204 s]
/proc/loadavg: 1.01 1.05 1.01 2/47 28569
/proc/meminfo: memFree=669652/1048576 swapFree=2077628/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=23704 CPUtime=6.68
/proc/28548/stat : 28548 (apt-pbo) S 28545 28545 4159 34819 4229 4202496 6114 24881 5 196 23 19 522 104 18 0 1 0 883505530 24272896 5155 1283457024 134512640 135744540 4289015456 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28548/statm: 5926 5155 3497 301 0 1698 0
[pid=28565] ppid=28548 vsize=88380 CPUtime=171.06
/proc/28565/stat : 28565 (wbo) R 28548 28545 4159 34819 4229 4202496 22316 0 1 0 17048 58 0 0 25 0 1 0 883506322 90501120 21780 1283457024 4194304 5578286 140734122551616 18446744073709551615 4289842 0 0 0 3 0 0 0 17 0 0 0 0
/proc/28565/statm: 22095 21780 158 338 0 21754 0
Current children cumulated CPU time (s) 177.74
Current children cumulated vsize (KiB) 113764

[startup+192.007 s]
/proc/loadavg: 1.00 1.05 1.01 2/47 28569
/proc/meminfo: memFree=393876/1048576 swapFree=2077628/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=23704 CPUtime=6.69
/proc/28548/stat : 28548 (apt-pbo) S 28545 28545 4159 34819 4229 4202496 6119 24881 5 196 24 19 522 104 18 0 1 0 883505530 24272896 5155 1283457024 134512640 135744540 4289015456 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28548/statm: 5926 5155 3497 301 0 1698 0
[pid=28565] ppid=28548 vsize=435392 CPUtime=183.84
/proc/28565/stat : 28565 (wbo) R 28548 28545 4159 34819 4229 4202496 109306 0 1 0 18285 99 0 0 25 0 1 0 883506322 445841408 108586 1283457024 4194304 5578286 140734122551616 18446744073709551615 4884165 0 0 0 3 0 0 0 17 0 0 0 0
/proc/28565/statm: 108848 108586 160 338 0 108507 0
Current children cumulated CPU time (s) 190.53
Current children cumulated vsize (KiB) 460776

[startup+198.405 s]
/proc/loadavg: 1.00 1.04 1.01 2/47 28569
/proc/meminfo: memFree=749644/1048576 swapFree=2077628/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=30372 CPUtime=11.14
/proc/28548/stat : 28548 (apt-pbo) R 28545 28545 4159 34819 4229 4202496 8129 24881 6 196 469 19 522 104 25 0 1 0 883505530 31100928 6816 1283457024 134512640 135744540 4289015456 18446744073709551615 135161572 0 0 128 0 0 0 0 17 0 0 0 0
/proc/28548/statm: 7593 6816 3501 301 0 3365 0
[pid=28565] ppid=28548 vsize=0 CPUtime=185.74
/proc/28565/stat : 28565 (wbo) Z 28548 28545 4159 34819 4229 4202508 162526 0 3 0 18457 117 0 0 25 0 1 0 883506322 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/28565/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 196.88
Current children cumulated vsize (KiB) 32052

[startup+204.807 s]
/proc/loadavg: 1.00 1.04 1.01 2/47 28569
/proc/meminfo: memFree=742576/1048576 swapFree=2077628/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=37308 CPUtime=17.54
/proc/28548/stat : 28548 (apt-pbo) R 28545 28545 4159 34819 4229 4202496 9878 24881 6 196 1108 20 522 104 25 0 1 0 883505530 38203392 8565 1283457024 134512640 135744540 4289015456 18446744073709551615 135093287 0 0 128 0 0 0 0 17 0 0 0 0
/proc/28548/statm: 9327 8565 3501 301 0 5099 0
[pid=28565] ppid=28548 vsize=0 CPUtime=185.74
/proc/28565/stat : 28565 (wbo) Z 28548 28545 4159 34819 4229 4202508 162526 0 3 0 18457 117 0 0 25 0 1 0 883506322 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/28565/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 203.28
Current children cumulated vsize (KiB) 38988

[startup+206.407 s]
/proc/loadavg: 1.00 1.04 1.01 2/47 28569
/proc/meminfo: memFree=742576/1048576 swapFree=2077628/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=37308 CPUtime=19.14
/proc/28548/stat : 28548 (apt-pbo) R 28545 28545 4159 34819 4229 4202496 9878 24881 6 196 1268 20 522 104 25 0 1 0 883505530 38203392 8565 1283457024 134512640 135744540 4289015456 18446744073709551615 135170243 0 0 128 0 0 0 0 17 0 0 0 0
/proc/28548/statm: 9327 8565 3501 301 0 5099 0
[pid=28565] ppid=28548 vsize=0 CPUtime=185.74
/proc/28565/stat : 28565 (wbo) Z 28548 28545 4159 34819 4229 4202508 162526 0 3 0 18457 117 0 0 25 0 1 0 883506322 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/28565/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 204.88
Current children cumulated vsize (KiB) 38988

[startup+207.207 s]
/proc/loadavg: 1.00 1.04 1.01 4/49 28571
/proc/meminfo: memFree=742164/1048576 swapFree=2077628/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=37308 CPUtime=19.54
/proc/28548/stat : 28548 (apt-pbo) R 28545 28545 4159 34819 4229 4202496 9910 24881 6 196 1308 20 522 104 25 0 1 0 883505530 38203392 8565 1283457024 134512640 135744540 4289015456 18446744073709551615 4294960130 0 0 128 0 0 0 0 17 0 0 0 0
/proc/28548/statm: 9327 8565 3501 301 0 5099 0
[pid=28565] ppid=28548 vsize=0 CPUtime=185.74
/proc/28565/stat : 28565 (wbo) Z 28548 28545 4159 34819 4229 4202508 162526 0 3 0 18457 117 0 0 25 0 1 0 883506322 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/28565/statm: 0 0 0 0 0 0 0
[pid=28570] ppid=28548 vsize=2768 CPUtime=0
/proc/28570/stat : 28570 (apt-get.sh) S 28548 28545 4159 34819 4229 4202496 499 496 0 0 0 0 0 0 25 0 1 0 883526209 2834432 323 1283457024 134512640 135304128 4288164048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28570/statm: 692 323 235 194 0 78 0
Current children cumulated CPU time (s) 205.28
Current children cumulated vsize (KiB) 41756

[startup+208.007 s]
/proc/loadavg: 1.00 1.04 1.01 3/49 28573
/proc/meminfo: memFree=742660/1048576 swapFree=2077628/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=37308 CPUtime=19.56
/proc/28548/stat : 28548 (apt-pbo) R 28545 28545 4159 34819 4229 4202496 9910 24881 6 196 1310 20 522 104 25 0 1 0 883505530 38203392 8565 1283457024 134512640 135744540 4289015456 18446744073709551615 135123788 0 0 128 0 0 0 0 17 0 0 0 0
/proc/28548/statm: 9327 8565 3501 301 0 5099 0
[pid=28565] ppid=28548 vsize=0 CPUtime=185.74
/proc/28565/stat : 28565 (wbo) Z 28548 28545 4159 34819 4229 4202508 162526 0 3 0 18457 117 0 0 25 0 1 0 883506322 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/28565/statm: 0 0 0 0 0 0 0
[pid=28570] ppid=28548 vsize=2768 CPUtime=0
/proc/28570/stat : 28570 (apt-get.sh) S 28548 28545 4159 34819 4229 4202496 499 496 0 0 0 0 0 0 25 0 1 0 883526209 2834432 323 1283457024 134512640 135304128 4288164048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28570/statm: 692 323 235 194 0 78 0
[pid=28573] ppid=28570 vsize=17256 CPUtime=1.17
/proc/28573/stat : 28573 (apt-get) R 28570 28545 4159 34819 4229 4202496 3705 0 0 0 110 7 0 0 25 0 1 0 883526211 17670144 3631 1283457024 134512640 134649604 4289159680 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/28573/statm: 4314 3631 3191 34 0 443 0
Current children cumulated CPU time (s) 206.47
Current children cumulated vsize (KiB) 59012

[startup+208.407 s]
/proc/loadavg: 1.00 1.04 1.01 3/49 28573
/proc/meminfo: memFree=742660/1048576 swapFree=2077628/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=37308 CPUtime=19.56
/proc/28548/stat : 28548 (apt-pbo) S 28545 28545 4159 34819 4229 4202496 9910 24881 6 196 1310 20 522 104 25 0 1 0 883505530 38203392 8565 1283457024 134512640 135744540 4289015456 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28548/statm: 9327 8565 3501 301 0 5099 0
[pid=28565] ppid=28548 vsize=0 CPUtime=185.74
/proc/28565/stat : 28565 (wbo) Z 28548 28545 4159 34819 4229 4202508 162526 0 3 0 18457 117 0 0 25 0 1 0 883506322 0 0 1283457024 0 0 0 0 0 0 0 0 3 18446744071564254338 0 0 17 0 0 0 0
/proc/28565/statm: 0 0 0 0 0 0 0
[pid=28570] ppid=28548 vsize=2768 CPUtime=0
/proc/28570/stat : 28570 (apt-get.sh) S 28548 28545 4159 34819 4229 4202496 499 496 0 0 0 0 0 0 25 0 1 0 883526209 2834432 323 1283457024 134512640 135304128 4288164048 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28570/statm: 692 323 235 194 0 78 0
[pid=28573] ppid=28570 vsize=17480 CPUtime=1.57
/proc/28573/stat : 28573 (apt-get) R 28570 28545 4159 34819 4229 4202496 3726 0 0 0 140 17 0 0 25 0 1 0 883526211 17899520 3652 1283457024 134512640 134649604 4289159680 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/28573/statm: 4370 3652 3192 34 0 499 0
Current children cumulated CPU time (s) 206.87
Current children cumulated vsize (KiB) 59236

[startup+208.504 s]
/proc/loadavg: 1.00 1.04 1.01 3/49 28573
/proc/meminfo: memFree=742660/1048576 swapFree=2077628/2097144
[pid=28545] ppid=28544 vsize=1680 CPUtime=0
/proc/28545/stat : 28545 (sh) S 28544 28545 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883505529 1720320 129 1283457024 134512640 134594024 4288332752 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28545/statm: 420 129 112 20 0 46 0
[pid=28548] ppid=28545 vsize=37332 CPUtime=206.91
/proc/28548/stat : 28548 (apt-pbo) S 28545 28545 4159 34819 4229 4202496 11031 192140 6 199 1310 20 19119 242 25 0 1 0 883505530 38227968 8572 1283457024 134512640 135744540 4289015456 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28548/statm: 9333 8572 3502 301 0 5105 0
Current children cumulated CPU time (s) 206.91
Current children cumulated vsize (KiB) 39012

Child status: 0
Real time (s): 208.536
CPU time (s): 206.945
CPU user time (s): 204.301
CPU system time (s): 2.64417
CPU usage (%): 99.2372
Max. virtual memory (cumulated for all children) (KiB): 666728

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 204.301
system time used= 2.64417
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 204093
page faults= 206
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 54603
involuntary context switches= 57019

runsolver used 0 second user time and 0.004 second system time

The end