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/201012061533/aptitude-paranoid-1.0/rand316.sarge-etch-lenny-squeeze.cudf.sarge-etch-lenny-squeeze.log.runsolver ./aptitude-paranoid-1.0 /home/misc2010/data/icse/sarge-etch-lenny-squeeze/rand316.sarge-etch-lenny-squeeze.cudf /home/misc2010/tmp/201012061533/aptitude-paranoid-1.0/rand316.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.08 1.05 1.06 3/45 11485
/proc/meminfo: memFree=735036/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2568 CPUtime=0
/proc/11484/stat : 11484 (aptitude-parano) R 11483 11484 2059 34821 2220 4202496 358 0 0 0 0 0 0 0 25 0 1 0 875292329 2629632 272 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/11484/statm: 642 272 232 194 0 28 0

[startup+0.151601 s]
/proc/loadavg: 1.08 1.05 1.06 3/45 11485
/proc/meminfo: memFree=735036/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2584 CPUtime=0.04
/proc/11484/stat : 11484 (aptitude-parano) R 11483 11484 2059 34821 2220 4202496 550 1858 0 0 0 0 0 4 25 0 1 0 875292329 2646016 284 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/11484/statm: 646 284 240 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 2584

[startup+0.211607 s]
/proc/loadavg: 1.08 1.05 1.06 3/45 11485
/proc/meminfo: memFree=735036/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2584 CPUtime=0.04
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 568 1858 0 0 0 0 0 4 25 0 1 0 875292329 2646016 284 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 646 284 240 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 2584

[startup+0.311624 s]
/proc/loadavg: 1.08 1.05 1.06 3/45 11485
/proc/meminfo: memFree=735036/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2584 CPUtime=0.04
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 568 1858 0 0 0 0 0 4 25 0 1 0 875292329 2646016 284 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 646 284 240 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 2584

[startup+0.711717 s]
/proc/loadavg: 1.08 1.05 1.06 3/45 11485
/proc/meminfo: memFree=735036/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2584 CPUtime=0.04
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 568 1858 0 0 0 0 0 4 25 0 1 0 875292329 2646016 284 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 646 284 240 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 2584

[startup+1.51193 s]
/proc/loadavg: 1.08 1.05 1.06 2/47 11495
/proc/meminfo: memFree=694832/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2584 CPUtime=0.04
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 568 1858 0 0 0 0 0 4 25 0 1 0 875292329 2646016 284 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 646 284 240 194 0 32 0
[pid=11495] ppid=11484 vsize=31764 CPUtime=1.46
/proc/11495/stat : 11495 (cudftodeb.nativ) R 11484 11484 2059 34821 2220 4202496 7527 0 0 0 142 4 0 0 25 0 1 0 875292334 32526336 7454 1283457024 134512640 135004320 4289232096 18446744073709551615 134940133 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/11495/statm: 7941 7454 225 121 0 7333 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 34348

[startup+3.11231 s]
/proc/loadavg: 1.08 1.05 1.06 2/47 11495
/proc/meminfo: memFree=673628/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2584 CPUtime=0.04
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 568 1858 0 0 0 0 0 4 25 0 1 0 875292329 2646016 284 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 646 284 240 194 0 32 0
[pid=11495] ppid=11484 vsize=62404 CPUtime=3.06
/proc/11495/stat : 11495 (cudftodeb.nativ) R 11484 11484 2059 34821 2220 4202496 14989 0 0 0 301 5 0 0 25 0 1 0 875292334 63901696 14916 1283457024 134512640 135004320 4289232096 18446744073709551615 134943780 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/11495/statm: 15601 14916 225 121 0 14993 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 64988

[startup+6.31321 s]
/proc/loadavg: 1.15 1.07 1.07 2/47 11495
/proc/meminfo: memFree=610016/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2584 CPUtime=0.04
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 568 1858 0 0 0 0 0 4 25 0 1 0 875292329 2646016 284 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 646 284 240 194 0 32 0
[pid=11495] ppid=11484 vsize=115460 CPUtime=6.25
/proc/11495/stat : 11495 (cudftodeb.nativ) R 11484 11484 2059 34821 2220 4202496 28089 0 0 0 614 11 0 0 25 0 1 0 875292334 118231040 28016 1283457024 134512640 135004320 4289232096 18446744073709551615 134996365 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/11495/statm: 28865 28016 237 121 0 28257 0
Current children cumulated CPU time (s) 6.29
Current children cumulated vsize (KiB) 118044

[startup+12.7096 s]
/proc/loadavg: 1.14 1.06 1.07 1/47 11506
/proc/meminfo: memFree=611248/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2592 CPUtime=8.9
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 700 34590 0 1 0 0 864 26 19 0 1 0 875292329 2654208 295 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 648 295 249 194 0 34 0
[pid=11505] ppid=11484 vsize=40516 CPUtime=1.5
/proc/11505/stat : 11505 (aptitude) R 11484 11484 2059 34821 2220 4202496 14574 241 388 0 138 12 0 0 18 0 1 0 875293325 41488384 7946 1283457024 134512640 137933492 4287647584 18446744073709551615 4159903950 0 134217728 4096 0 0 0 0 17 0 0 0 0
/proc/11505/statm: 10129 7946 7276 836 0 640 0
Current children cumulated CPU time (s) 10.4
Current children cumulated vsize (KiB) 43108

[startup+25.5121 s]
/proc/loadavg: 1.11 1.06 1.07 2/48 11509
/proc/meminfo: memFree=528160/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2592 CPUtime=8.9
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 700 34590 0 1 0 0 864 26 19 0 1 0 875292329 2654208 295 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 648 295 249 194 0 34 0
[pid=11505] ppid=11484 vsize=139112 CPUtime=14.29
/proc/11505/stat : 11505 (aptitude) S 11484 11484 2059 34821 2220 4202496 37569 651 388 0 1402 27 0 0 15 0 2 0 875293325 142450688 28662 1283457024 134512640 137933492 4287647584 18446744073709551615 4294960130 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0
/proc/11505/statm: 34778 28662 7706 836 0 25289 0
[pid=11505/tid=11507] ppid=11484 vsize=139112 CPUtime=10.24
/proc/11505/task/11507/stat : 11507 (aptitude) R 11484 11484 2059 34821 2220 4202560 18065 651 0 0 1012 12 0 0 25 0 2 0 875293643 142450688 28662 1283457024 134512640 137933492 4287647584 18446744073709551615 135914080 0 134217728 4096 0 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 23.19
Current children cumulated vsize (KiB) 141704

[startup+51.1101 s]
/proc/loadavg: 1.07 1.05 1.06 2/48 11509
/proc/meminfo: memFree=400688/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2592 CPUtime=8.9
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 700 34590 0 1 0 0 864 26 19 0 1 0 875292329 2654208 295 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 648 295 249 194 0 34 0
[pid=11505] ppid=11484 vsize=268644 CPUtime=39.85
/proc/11505/stat : 11505 (aptitude) S 11484 11484 2059 34821 2220 4202496 69956 651 388 0 3938 47 0 0 15 0 2 0 875293325 275091456 61049 1283457024 134512640 137933492 4287647584 18446744073709551615 4294960130 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0
/proc/11505/statm: 67161 61049 7722 836 0 57672 0
[pid=11505/tid=11507] ppid=11484 vsize=268644 CPUtime=35.81
/proc/11505/task/11507/stat : 11507 (aptitude) R 11484 11484 2059 34821 2220 4202560 50445 651 0 0 3549 32 0 0 25 0 2 0 875293643 275091456 61049 1283457024 134512640 137933492 4287647584 18446744073709551615 4153457988 0 134217728 4096 0 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 48.75
Current children cumulated vsize (KiB) 271236

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

[startup+51.2101 s]
/proc/loadavg: 1.07 1.05 1.06 2/48 11509
/proc/meminfo: memFree=400688/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2592 CPUtime=8.9
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 700 34590 0 1 0 0 864 26 19 0 1 0 875292329 2654208 295 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 648 295 249 194 0 34 0
[pid=11505] ppid=11484 vsize=269040 CPUtime=39.95
/proc/11505/stat : 11505 (aptitude) S 11484 11484 2059 34821 2220 4202496 70074 651 388 0 3948 47 0 0 15 0 2 0 875293325 275496960 61167 1283457024 134512640 137933492 4287647584 18446744073709551615 4294960130 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0
/proc/11505/statm: 67260 61167 7722 836 0 57771 0
[pid=11505/tid=11507] ppid=11484 vsize=269040 CPUtime=35.91
/proc/11505/task/11507/stat : 11507 (aptitude) R 11484 11484 2059 34821 2220 4202560 50563 651 0 0 3559 32 0 0 25 0 2 0 875293643 275496960 61167 1283457024 134512640 137933492 4287647584 18446744073709551615 4155662916 0 134217728 4096 0 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 48.85
Current children cumulated vsize (KiB) 271632

[startup+76.8058 s]
/proc/loadavg: 1.05 1.05 1.06 2/48 11509
/proc/meminfo: memFree=282640/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2592 CPUtime=8.9
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 700 34590 0 1 0 0 864 26 19 0 1 0 875292329 2654208 295 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 648 295 249 194 0 34 0
[pid=11505] ppid=11484 vsize=387764 CPUtime=65.51
/proc/11505/stat : 11505 (aptitude) S 11484 11484 2059 34821 2220 4202496 99715 651 388 0 6494 57 0 0 15 0 2 0 875293325 397070336 90808 1283457024 134512640 137933492 4287647584 18446744073709551615 4294960130 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0
/proc/11505/statm: 96941 90808 7722 836 0 87452 0
[pid=11505/tid=11507] ppid=11484 vsize=387764 CPUtime=61.46
/proc/11505/task/11507/stat : 11507 (aptitude) R 11484 11484 2059 34821 2220 4202560 80204 651 0 0 6104 42 0 0 25 0 2 0 875293643 397070336 90808 1283457024 134512640 137933492 4287647584 18446744073709551615 136314136 0 134217728 4096 0 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 74.41
Current children cumulated vsize (KiB) 390356

[startup+89.6107 s]
/proc/loadavg: 1.04 1.05 1.06 2/48 11509
/proc/meminfo: memFree=225600/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2592 CPUtime=8.9
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 700 34590 0 1 0 0 864 26 19 0 1 0 875292329 2654208 295 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 648 295 249 194 0 34 0
[pid=11505] ppid=11484 vsize=442940 CPUtime=78.28
/proc/11505/stat : 11505 (aptitude) S 11484 11484 2059 34821 2220 4202496 113526 651 388 0 7763 65 0 0 15 0 2 0 875293325 453570560 104619 1283457024 134512640 137933492 4287647584 18446744073709551615 4294960130 0 134217728 4096 0 18446744073709551615 0 0 17 0 0 0 0
/proc/11505/statm: 110735 104619 7722 836 0 101246 0
[pid=11505/tid=11507] ppid=11484 vsize=442940 CPUtime=74.24
/proc/11505/task/11507/stat : 11507 (aptitude) R 11484 11484 2059 34821 2220 4202560 94015 651 0 0 7374 50 0 0 25 0 2 0 875293643 453570560 104619 1283457024 134512640 137933492 4287647584 18446744073709551615 4155662916 0 134217728 4096 0 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 87.18
Current children cumulated vsize (KiB) 445532

[startup+96.0051 s]
/proc/loadavg: 1.19 1.08 1.07 2/47 11511
/proc/meminfo: memFree=606040/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2592 CPUtime=93.02
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 728 154358 0 389 0 0 9189 113 18 0 1 0 875292329 2654208 295 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 648 295 249 194 0 34 0
[pid=11511] ppid=11484 vsize=14544 CPUtime=0.56
/proc/11511/stat : 11511 (aptsolutions.na) R 11484 11484 2059 34821 2220 4202496 3297 0 0 0 56 0 0 0 20 0 1 0 875301874 14893056 3184 1283457024 134512640 134971616 4291522272 18446744073709551615 134954282 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/11511/statm: 3636 3184 204 113 0 3038 0
Current children cumulated CPU time (s) 93.58
Current children cumulated vsize (KiB) 17136

[startup+97.6055 s]
/proc/loadavg: 1.19 1.08 1.07 2/47 11511
/proc/meminfo: memFree=583720/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2592 CPUtime=93.02
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 728 154358 0 389 0 0 9189 113 18 0 1 0 875292329 2654208 295 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 648 295 249 194 0 34 0
[pid=11511] ppid=11484 vsize=46236 CPUtime=2.15
/proc/11511/stat : 11511 (aptsolutions.na) R 11484 11484 2059 34821 2220 4202496 11112 0 0 0 212 3 0 0 25 0 1 0 875301874 47345664 10997 1283457024 134512640 134971616 4291522272 18446744073709551615 134954309 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/11511/statm: 11559 10997 204 113 0 10961 0
Current children cumulated CPU time (s) 95.17
Current children cumulated vsize (KiB) 48828

[startup+98.4056 s]
/proc/loadavg: 1.19 1.08 1.07 2/47 11511
/proc/meminfo: memFree=562392/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2592 CPUtime=93.02
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 728 154358 0 389 0 0 9189 113 18 0 1 0 875292329 2654208 295 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 648 295 249 194 0 34 0
[pid=11511] ppid=11484 vsize=61124 CPUtime=2.94
/proc/11511/stat : 11511 (aptsolutions.na) R 11484 11484 2059 34821 2220 4202496 14738 0 0 0 290 4 0 0 25 0 1 0 875301874 62590976 14623 1283457024 134512640 134971616 4291522272 18446744073709551615 134954119 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/11511/statm: 15281 14623 204 113 0 14683 0
Current children cumulated CPU time (s) 95.96
Current children cumulated vsize (KiB) 63716

[startup+98.8057 s]
/proc/loadavg: 1.19 1.08 1.07 2/47 11511
/proc/meminfo: memFree=562392/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2592 CPUtime=93.02
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 728 154358 0 389 0 0 9189 113 18 0 1 0 875292329 2654208 295 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 648 295 249 194 0 34 0
[pid=11511] ppid=11484 vsize=69060 CPUtime=3.35
/proc/11511/stat : 11511 (aptsolutions.na) R 11484 11484 2059 34821 2220 4202496 16675 0 0 0 330 5 0 0 25 0 1 0 875301874 70717440 16560 1283457024 134512640 134971616 4291522272 18446744073709551615 134606600 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/11511/statm: 17265 16560 204 113 0 16667 0
Current children cumulated CPU time (s) 96.37
Current children cumulated vsize (KiB) 71652

[startup+99.0058 s]
/proc/loadavg: 1.18 1.08 1.07 2/47 11511
/proc/meminfo: memFree=540444/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2592 CPUtime=93.02
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 728 154358 0 389 0 0 9189 113 18 0 1 0 875292329 2654208 295 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 648 295 249 194 0 34 0
[pid=11511] ppid=11484 vsize=75080 CPUtime=3.54
/proc/11511/stat : 11511 (aptsolutions.na) R 11484 11484 2059 34821 2220 4202496 18142 0 0 0 348 6 0 0 25 0 1 0 875301874 76881920 18027 1283457024 134512640 134971616 4291522272 18446744073709551615 134911483 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/11511/statm: 18770 18027 209 113 0 18172 0
Current children cumulated CPU time (s) 96.56
Current children cumulated vsize (KiB) 77672

[startup+99.1061 s]
/proc/loadavg: 1.18 1.08 1.07 2/47 11511
/proc/meminfo: memFree=540444/1048576 swapFree=2078768/2097144
[pid=11484] ppid=11483 vsize=2592 CPUtime=93.02
/proc/11484/stat : 11484 (aptitude-parano) S 11483 11484 2059 34821 2220 4202496 728 154358 0 389 0 0 9189 113 18 0 1 0 875292329 2654208 295 1283457024 134512640 135304128 4288359296 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/11484/statm: 648 295 249 194 0 34 0
[pid=11511] ppid=11484 vsize=0 CPUtime=3.65
/proc/11511/stat : 11511 (aptsolutions.na) R 11484 11484 2059 34821 2220 4202500 19393 0 0 0 358 7 0 0 25 0 1 0 875301874 0 0 1283457024 0 0 0 0 0 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/11511/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 96.67
Current children cumulated vsize (KiB) 2592

Child status: 0
Real time (s): 99.1104
CPU time (s): 96.694
CPU user time (s): 95.478
CPU system time (s): 1.21608
CPU usage (%): 97.5619
Max. virtual memory (cumulated for all children) (KiB): 459532

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 95.478
system time used= 1.21608
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 174494
page faults= 389
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 450
involuntary context switches= 1515

runsolver used 0.004 second user time and 0 second system time

The end