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-get-trendy-1.0/rand915.sarge-etch-lenny-squeeze.cudf.sarge-etch-lenny-squeeze.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/icse/sarge-etch-lenny-squeeze/rand915.sarge-etch-lenny-squeeze.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-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: 0.94 1.00 1.03 3/45 27952
/proc/meminfo: memFree=703892/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2584 CPUtime=0
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 508 1359 0 0 0 0 0 0 25 0 1 0 883324286 2646016 279 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 646 279 237 194 0 32 0

[startup+0.114154 s]
/proc/loadavg: 0.94 1.00 1.03 3/45 27952
/proc/meminfo: memFree=703892/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2584 CPUtime=0
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 508 1359 0 0 0 0 0 0 25 0 1 0 883324286 2646016 279 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 646 279 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.206199 s]
/proc/loadavg: 0.94 1.00 1.03 3/45 27952
/proc/meminfo: memFree=703892/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2584 CPUtime=0
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 508 1359 0 0 0 0 0 0 25 0 1 0 883324286 2646016 279 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 646 279 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.306171 s]
/proc/loadavg: 0.94 1.00 1.03 3/45 27952
/proc/meminfo: memFree=703892/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2584 CPUtime=0.02
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 554 1859 0 0 0 0 0 2 23 0 1 0 883324286 2646016 282 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 646 282 240 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 2584

[startup+0.709773 s]
/proc/loadavg: 0.94 1.00 1.03 3/45 27952
/proc/meminfo: memFree=703892/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2584 CPUtime=0.02
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 554 1859 0 0 0 0 0 2 23 0 1 0 883324286 2646016 282 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 646 282 240 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 2584

[startup+1.50989 s]
/proc/loadavg: 0.94 1.00 1.03 2/46 27962
/proc/meminfo: memFree=649224/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2584 CPUtime=0.02
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 554 1859 0 0 0 0 0 2 23 0 1 0 883324286 2646016 282 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 646 282 240 194 0 32 0
[pid=27962] ppid=27951 vsize=27300 CPUtime=1.16
/proc/27962/stat : 27962 (cudftodeb.nativ) R 27951 27951 4159 34819 4229 4202496 6376 0 6 0 115 1 0 0 25 0 1 0 883324317 27955200 6309 1283457024 134512640 135004320 4292734064 18446744073709551615 134634914 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27962/statm: 6825 6309 225 121 0 6217 0
Current children cumulated CPU time (s) 1.18
Current children cumulated vsize (KiB) 29884

[startup+3.11014 s]
/proc/loadavg: 0.94 1.00 1.03 2/46 27962
/proc/meminfo: memFree=626656/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2584 CPUtime=0.02
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 554 1859 0 0 0 0 0 2 23 0 1 0 883324286 2646016 282 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 646 282 240 194 0 32 0
[pid=27962] ppid=27951 vsize=57684 CPUtime=2.76
/proc/27962/stat : 27962 (cudftodeb.nativ) R 27951 27951 4159 34819 4229 4202496 13842 0 6 0 275 1 0 0 25 0 1 0 883324317 59068416 13775 1283457024 134512640 135004320 4292734064 18446744073709551615 134995972 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27962/statm: 14421 13775 225 121 0 13813 0
Current children cumulated CPU time (s) 2.78
Current children cumulated vsize (KiB) 60268

[startup+6.31162 s]
/proc/loadavg: 0.94 1.00 1.03 2/46 27962
/proc/meminfo: memFree=561432/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2584 CPUtime=0.02
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 554 1859 0 0 0 0 0 2 23 0 1 0 883324286 2646016 282 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 646 282 240 194 0 32 0
[pid=27962] ppid=27951 vsize=112732 CPUtime=5.95
/proc/27962/stat : 27962 (cudftodeb.nativ) R 27951 27951 4159 34819 4229 4202496 27352 0 6 0 591 4 0 0 25 0 1 0 883324317 115437568 27285 1283457024 134512640 135004320 4292734064 18446744073709551615 134996501 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27962/statm: 28183 27285 237 121 0 27575 0
Current children cumulated CPU time (s) 5.97
Current children cumulated vsize (KiB) 115316

[startup+12.707 s]
/proc/loadavg: 1.03 1.01 1.03 1/46 27972
/proc/meminfo: memFree=560852/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2592 CPUtime=8.79
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 689 34682 0 11 0 0 857 22 18 0 1 0 883324286 2654208 293 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 648 293 249 194 0 34 0
[pid=27972] ppid=27951 vsize=101456 CPUtime=1.36
/proc/27972/stat : 27972 (apt-get) D 27951 27951 4159 34819 4229 4202496 6951 0 388 0 126 10 0 0 18 0 1 0 883325327 103890944 7263 1283457024 134512640 134619611 4294260336 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/27972/statm: 25364 7263 7210 27 0 58 0
Current children cumulated CPU time (s) 10.15
Current children cumulated vsize (KiB) 104048
heavy processes:

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

[startup+12.8069 s]
/proc/loadavg: 1.03 1.01 1.03 1/46 27972
/proc/meminfo: memFree=560312/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2592 CPUtime=8.79
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 689 34682 0 11 0 0 857 22 18 0 1 0 883324286 2654208 293 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 648 293 249 194 0 34 0
[pid=27972] ppid=27951 vsize=101456 CPUtime=1.36
/proc/27972/stat : 27972 (apt-get) D 27951 27951 4159 34819 4229 4202496 6951 0 388 0 126 10 0 0 18 0 1 0 883325327 103890944 7263 1283457024 134512640 134619611 4294260336 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/27972/statm: 25364 7263 7210 27 0 58 0
Current children cumulated CPU time (s) 10.15
Current children cumulated vsize (KiB) 104048

[startup+16.0117 s]
/proc/loadavg: 1.02 1.01 1.03 2/46 27972
/proc/meminfo: memFree=555476/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2592 CPUtime=8.79
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 689 34682 0 11 0 0 857 22 18 0 1 0 883324286 2654208 293 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 648 293 249 194 0 34 0
[pid=27972] ppid=27951 vsize=36180 CPUtime=4.13
/proc/27972/stat : 27972 (apt-get) R 27951 27951 4159 34819 4229 4202496 14745 0 388 0 401 12 0 0 22 0 1 0 883325327 37048320 8111 1283457024 134512640 134619611 4294260336 18446744073709551615 4159755370 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/27972/statm: 9045 8111 6887 27 0 1288 0
Current children cumulated CPU time (s) 12.92
Current children cumulated vsize (KiB) 38772

[startup+17.6036 s]
/proc/loadavg: 1.02 1.01 1.03 2/46 27973
/proc/meminfo: memFree=530868/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2592 CPUtime=13.02
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 709 49456 0 399 0 0 1266 36 19 0 1 0 883324286 2654208 293 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 648 293 249 194 0 34 0
[pid=27973] ppid=27951 vsize=32148 CPUtime=1.46
/proc/27973/stat : 27973 (aptsolutions.na) R 27951 27951 4159 34819 4229 4202496 7647 0 3 0 144 2 0 0 25 0 1 0 883325898 32919552 7538 1283457024 134512640 134971616 4287049312 18446744073709551615 134954180 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27973/statm: 8037 7538 204 113 0 7439 0
Current children cumulated CPU time (s) 14.48
Current children cumulated vsize (KiB) 34740

[startup+19.2039 s]
/proc/loadavg: 1.02 1.01 1.03 2/46 27973
/proc/meminfo: memFree=508548/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2592 CPUtime=13.02
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 709 49456 0 399 0 0 1266 36 19 0 1 0 883324286 2654208 293 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 648 293 249 194 0 34 0
[pid=27973] ppid=27951 vsize=63104 CPUtime=3.06
/proc/27973/stat : 27973 (aptsolutions.na) R 27951 27951 4159 34819 4229 4202496 15203 0 3 0 299 7 0 0 25 0 1 0 883325898 64618496 15092 1283457024 134512640 134971616 4287049312 18446744073709551615 134927600 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27973/statm: 15776 15092 204 113 0 15178 0
Current children cumulated CPU time (s) 16.08
Current children cumulated vsize (KiB) 65696

[startup+19.6039 s]
/proc/loadavg: 1.02 1.01 1.03 2/46 27973
/proc/meminfo: memFree=508548/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2592 CPUtime=13.02
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 709 49456 0 399 0 0 1266 36 19 0 1 0 883324286 2654208 293 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 648 293 249 194 0 34 0
[pid=27973] ppid=27951 vsize=72092 CPUtime=3.47
/proc/27973/stat : 27973 (aptsolutions.na) R 27951 27951 4159 34819 4229 4202496 17447 0 3 0 340 7 0 0 25 0 1 0 883325898 73822208 17336 1283457024 134512640 134971616 4287049312 18446744073709551615 134964261 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27973/statm: 18023 17336 208 113 0 17425 0
Current children cumulated CPU time (s) 16.49
Current children cumulated vsize (KiB) 74684

[startup+19.804 s]
/proc/loadavg: 1.02 1.01 1.03 2/46 27973
/proc/meminfo: memFree=483252/1048576 swapFree=2077608/2097144
[pid=27951] ppid=27950 vsize=2592 CPUtime=13.02
/proc/27951/stat : 27951 (apt-get-trendy-) S 27950 27951 4159 34819 4229 4202496 709 49456 0 399 0 0 1266 36 19 0 1 0 883324286 2654208 293 1283457024 134512640 135304128 4291030560 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27951/statm: 648 293 249 194 0 34 0
[pid=27973] ppid=27951 vsize=81016 CPUtime=3.66
/proc/27973/stat : 27973 (aptsolutions.na) R 27951 27951 4159 34819 4229 4202496 19497 0 3 0 357 9 0 0 25 0 1 0 883325898 82960384 19386 1283457024 134512640 134971616 4287049312 18446744073709551615 4294960130 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27973/statm: 20254 19386 209 113 0 19656 0
Current children cumulated CPU time (s) 16.68
Current children cumulated vsize (KiB) 83608

Child status: 0
Real time (s): 19.8138
CPU time (s): 16.701
CPU user time (s): 16.241
CPU system time (s): 0.460028
CPU usage (%): 84.2899
Max. virtual memory (cumulated for all children) (KiB): 123996

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 16.241
system time used= 0.460028
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 69677
page faults= 402
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 416
involuntary context switches= 276

runsolver used 0 second user time and 0 second system time

The end