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/apt-get-paranoid-1.0/rand915.sarge-etch-lenny-squeeze.cudf.sarge-etch-lenny-squeeze.log.runsolver ./apt-get-paranoid-1.0 /home/misc2010/data/icse/sarge-etch-lenny-squeeze/rand915.sarge-etch-lenny-squeeze.cudf /home/misc2010/tmp/201012061533/apt-get-paranoid-1.0/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.40 1.30 1.21 2/46 24153
/proc/meminfo: memFree=725876/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2584 CPUtime=0
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 508 1357 0 0 0 0 0 0 25 0 1 0 876148833 2646016 279 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 646 279 237 194 0 32 0
[pid=24153] ppid=24145 vsize=2000 CPUtime=0.02
/proc/24153/stat : 24153 (cp) R 24145 24145 2059 34821 2220 4202496 253 0 0 0 0 2 0 0 25 0 1 0 876148834 2048000 182 1283457024 134512640 134614052 4288162832 18446744073709551615 4294960130 0 0 0 0 0 0 0 17 0 0 0 0
/proc/24153/statm: 500 182 145 25 0 46 0

[startup+0.234388 s]
/proc/loadavg: 1.40 1.30 1.21 2/46 24153
/proc/meminfo: memFree=725876/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2584 CPUtime=0.04
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 553 1856 0 0 0 0 0 4 25 0 1 0 876148833 2646016 282 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 646 282 240 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 2584

[startup+0.3044 s]
/proc/loadavg: 1.40 1.30 1.21 2/46 24153
/proc/meminfo: memFree=725876/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2584 CPUtime=0.04
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 553 1856 0 0 0 0 0 4 25 0 1 0 876148833 2646016 282 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 646 282 240 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 2584

[startup+0.404414 s]
/proc/loadavg: 1.40 1.30 1.21 2/46 24153
/proc/meminfo: memFree=725876/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2584 CPUtime=0.04
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 553 1856 0 0 0 0 0 4 25 0 1 0 876148833 2646016 282 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 646 282 240 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 2584

[startup+0.704458 s]
/proc/loadavg: 1.40 1.30 1.21 2/46 24153
/proc/meminfo: memFree=725876/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2584 CPUtime=0.04
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 553 1856 0 0 0 0 0 4 25 0 1 0 876148833 2646016 282 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 646 282 240 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 2584

[startup+1.50458 s]
/proc/loadavg: 1.40 1.30 1.21 2/47 24156
/proc/meminfo: memFree=690188/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2584 CPUtime=0.04
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 553 1856 0 0 0 0 0 4 25 0 1 0 876148833 2646016 282 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 646 282 240 194 0 32 0
[pid=24156] ppid=24145 vsize=32512 CPUtime=1.46
/proc/24156/stat : 24156 (cudftodeb.nativ) R 24145 24145 2059 34821 2220 4202496 7710 0 0 0 144 2 0 0 25 0 1 0 876148838 33292288 7637 1283457024 134512640 135004320 4291385072 18446744073709551615 134525867 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/24156/statm: 8128 7637 225 121 0 7520 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 35096

[startup+3.1072 s]
/proc/loadavg: 1.40 1.30 1.21 2/47 24156
/proc/meminfo: memFree=668984/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2584 CPUtime=0.04
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 553 1856 0 0 0 0 0 4 25 0 1 0 876148833 2646016 282 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 646 282 240 194 0 32 0
[pid=24156] ppid=24145 vsize=63152 CPUtime=3.04
/proc/24156/stat : 24156 (cudftodeb.nativ) R 24145 24145 2059 34821 2220 4202496 15164 0 0 0 302 2 0 0 25 0 1 0 876148838 64667648 15091 1283457024 134512640 135004320 4291385072 18446744073709551615 134979128 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/24156/statm: 15788 15091 225 121 0 15180 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 65736

[startup+6.30812 s]
/proc/loadavg: 1.37 1.29 1.21 2/47 24156
/proc/meminfo: memFree=606860/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2584 CPUtime=0.04
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 553 1856 0 0 0 0 0 4 25 0 1 0 876148833 2646016 282 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 646 282 240 194 0 32 0
[pid=24156] ppid=24145 vsize=115716 CPUtime=6.22
/proc/24156/stat : 24156 (cudftodeb.nativ) R 24145 24145 2059 34821 2220 4202496 28151 0 0 0 608 14 0 0 25 0 1 0 876148838 118493184 28078 1283457024 134512640 135004320 4291385072 18446744073709551615 134848126 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/24156/statm: 28929 28078 237 121 0 28321 0
Current children cumulated CPU time (s) 6.26
Current children cumulated vsize (KiB) 118300

[startup+12.7144 s]
/proc/loadavg: 1.42 1.30 1.21 1/47 24166
/proc/meminfo: memFree=609332/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2592 CPUtime=8.86
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 689 34696 0 1 1 0 856 29 18 0 1 0 876148833 2654208 293 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 648 293 249 194 0 34 0
[pid=24166] ppid=24145 vsize=33556 CPUtime=1.51
/proc/24166/stat : 24166 (apt-get) R 24145 24145 2059 34821 2220 4202496 14010 0 388 0 141 10 0 0 18 0 1 0 876149824 34361344 7467 1283457024 134512640 134619611 4292045888 18446744073709551615 4159976119 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/24166/statm: 8389 7467 6839 27 0 632 0
Current children cumulated CPU time (s) 10.37
Current children cumulated vsize (KiB) 36148

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

[startup+12.9144 s]
/proc/loadavg: 1.42 1.30 1.21 1/47 24166
/proc/meminfo: memFree=609332/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2592 CPUtime=8.86
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 689 34696 0 1 1 0 856 29 18 0 1 0 876148833 2654208 293 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 648 293 249 194 0 34 0
[pid=24166] ppid=24145 vsize=33880 CPUtime=1.71
/proc/24166/stat : 24166 (apt-get) R 24145 24145 2059 34821 2220 4202496 14147 0 388 0 161 10 0 0 18 0 1 0 876149824 34693120 7556 1283457024 134512640 134619611 4292045888 18446744073709551615 4159975739 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/24166/statm: 8470 7556 6868 27 0 713 0
Current children cumulated CPU time (s) 10.57
Current children cumulated vsize (KiB) 36472

[startup+16.1152 s]
/proc/loadavg: 1.39 1.30 1.21 2/47 24166
/proc/meminfo: memFree=604496/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2592 CPUtime=13.26
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 709 49470 0 389 1 0 1282 43 18 0 1 0 876148833 2654208 293 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 648 293 249 194 0 34 0
Current children cumulated CPU time (s) 13.26
Current children cumulated vsize (KiB) 2592

[startup+17.7055 s]
/proc/loadavg: 1.39 1.30 1.21 2/47 24167
/proc/meminfo: memFree=567792/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2592 CPUtime=13.26
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 709 49470 0 389 1 0 1282 43 18 0 1 0 876148833 2654208 293 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 648 293 249 194 0 34 0
[pid=24167] ppid=24145 vsize=44748 CPUtime=2.1
/proc/24167/stat : 24167 (aptsolutions.na) R 24145 24145 2059 34821 2220 4202496 10692 0 0 0 202 8 0 0 25 0 1 0 876150394 45821952 10578 1283457024 134512640 134971616 4289631504 18446744073709551615 134698992 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/24167/statm: 11187 10578 204 113 0 10589 0
Current children cumulated CPU time (s) 15.36
Current children cumulated vsize (KiB) 47340

[startup+18.5057 s]
/proc/loadavg: 1.39 1.30 1.21 2/47 24167
/proc/meminfo: memFree=567792/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2592 CPUtime=13.26
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 709 49470 0 389 1 0 1282 43 18 0 1 0 876148833 2654208 293 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 648 293 249 194 0 34 0
[pid=24167] ppid=24145 vsize=59132 CPUtime=2.89
/proc/24167/stat : 24167 (aptsolutions.na) R 24145 24145 2059 34821 2220 4202496 14294 0 0 0 281 8 0 0 25 0 1 0 876150394 60551168 14180 1283457024 134512640 134971616 4289631504 18446744073709551615 134800587 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/24167/statm: 14783 14180 204 113 0 14185 0
Current children cumulated CPU time (s) 16.15
Current children cumulated vsize (KiB) 61724

[startup+18.9058 s]
/proc/loadavg: 1.39 1.30 1.21 2/47 24167
/proc/meminfo: memFree=547456/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2592 CPUtime=13.26
/proc/24145/stat : 24145 (apt-get-paranoi) S 24144 24145 2059 34821 2220 4202496 709 49470 0 389 1 0 1282 43 18 0 1 0 876148833 2654208 293 1283457024 134512640 135304128 4290362736 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/24145/statm: 648 293 249 194 0 34 0
[pid=24167] ppid=24145 vsize=67324 CPUtime=3.29
/proc/24167/stat : 24167 (aptsolutions.na) R 24145 24145 2059 34821 2220 4202496 16245 0 0 0 321 8 0 0 25 0 1 0 876150394 68939776 16131 1283457024 134512640 134971616 4289631504 18446744073709551615 134954063 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/24167/statm: 16831 16131 204 113 0 16233 0
Current children cumulated CPU time (s) 16.55
Current children cumulated vsize (KiB) 69916

[startup+19.3058 s]
/proc/loadavg: 1.39 1.30 1.21 2/47 24167
/proc/meminfo: memFree=547456/1048576 swapFree=2078744/2097144
[pid=24145] ppid=24144 vsize=2592 CPUtime=16.96
/proc/24145/stat : 24145 (apt-get-paranoi) R 24144 24145 2059 34821 2220 4202496 711 68972 0 389 2 0 1641 53 18 0 1 0 876148833 2654208 293 1283457024 134512640 135304128 4290362736 18446744073709551615 134773523 0 65536 4 65538 0 0 0 17 0 0 0 0
/proc/24145/statm: 648 293 249 194 0 34 0
Current children cumulated CPU time (s) 16.96
Current children cumulated vsize (KiB) 2592

Child status: 0
Real time (s): 19.3063
CPU time (s): 16.9731
CPU user time (s): 16.437
CPU system time (s): 0.536033
CPU usage (%): 87.9146
Max. virtual memory (cumulated for all children) (KiB): 124004

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 16.437
system time used= 0.536033
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 69695
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= 270
involuntary context switches= 329

runsolver used 0 second user time and 0 second system time

The end