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/rand986.sarge-etch-lenny-squeeze.cudf.sarge-etch-lenny-squeeze.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/icse/sarge-etch-lenny-squeeze/rand986.sarge-etch-lenny-squeeze.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/rand986.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.95 1.02 1.05 2/45 30230
/proc/meminfo: memFree=759832/1048576 swapFree=2077616/2097144
[pid=30230] ppid=30229 vsize=3028 CPUtime=0
/proc/30230/stat : 30230 (runsolver) D 30229 30230 4159 34819 4229 4202560 72 0 0 0 0 0 0 0 25 0 1 0 883876033 3100672 94 1283457024 134512640 134586868 4287021408 18446744073709551615 4294960130 0 0 0 24578 18446744071564332000 0 0 17 0 0 0 0
/proc/30230/statm: 757 94 62 19 0 55 0

[startup+0.121505 s]
/proc/loadavg: 0.95 1.02 1.05 2/45 30230
/proc/meminfo: memFree=759832/1048576 swapFree=2077616/2097144
[pid=30230] ppid=30229 vsize=2584 CPUtime=0
/proc/30230/stat : 30230 (apt-get-trendy-) S 30229 30230 4159 34819 4229 4202496 516 1357 0 0 0 0 0 0 25 0 1 0 883876033 2646016 280 1283457024 134512640 135304128 4294431072 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30230/statm: 646 280 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.20548 s]
/proc/loadavg: 0.95 1.02 1.05 2/45 30230
/proc/meminfo: memFree=759832/1048576 swapFree=2077616/2097144
[pid=30230] ppid=30229 vsize=2584 CPUtime=0
/proc/30230/stat : 30230 (apt-get-trendy-) S 30229 30230 4159 34819 4229 4202496 516 1357 0 0 0 0 0 0 25 0 1 0 883876033 2646016 280 1283457024 134512640 135304128 4294431072 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30230/statm: 646 280 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.305475 s]
/proc/loadavg: 0.95 1.02 1.05 2/45 30230
/proc/meminfo: memFree=759832/1048576 swapFree=2077616/2097144
[pid=30230] ppid=30229 vsize=2584 CPUtime=0
/proc/30230/stat : 30230 (apt-get-trendy-) S 30229 30230 4159 34819 4229 4202496 516 1357 0 0 0 0 0 0 25 0 1 0 883876033 2646016 280 1283457024 134512640 135304128 4294431072 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30230/statm: 646 280 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.705549 s]
/proc/loadavg: 0.95 1.02 1.05 2/45 30230
/proc/meminfo: memFree=759832/1048576 swapFree=2077616/2097144
[pid=30230] ppid=30229 vsize=2584 CPUtime=0.01
/proc/30230/stat : 30230 (apt-get-trendy-) S 30229 30230 4159 34819 4229 4202496 564 1852 0 4 0 0 0 1 22 0 1 0 883876033 2646016 283 1283457024 134512640 135304128 4294431072 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30230/statm: 646 283 240 194 0 32 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2584

[startup+1.50573 s]
/proc/loadavg: 0.95 1.02 1.05 2/47 30241
/proc/meminfo: memFree=705304/1048576 swapFree=2077616/2097144
[pid=30230] ppid=30229 vsize=2584 CPUtime=0.01
/proc/30230/stat : 30230 (apt-get-trendy-) S 30229 30230 4159 34819 4229 4202496 564 1852 0 4 0 0 0 1 22 0 1 0 883876033 2646016 283 1283457024 134512640 135304128 4294431072 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30230/statm: 646 283 240 194 0 32 0
[pid=30241] ppid=30230 vsize=25564 CPUtime=1.11
/proc/30241/stat : 30241 (cudftodeb.nativ) R 30230 30230 4159 34819 4229 4202496 5964 0 8 0 109 2 0 0 25 0 1 0 883876067 26177536 5899 1283457024 134512640 135004320 4294916320 18446744073709551615 134634326 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/30241/statm: 6391 5899 225 121 0 5783 0
Current children cumulated CPU time (s) 1.12
Current children cumulated vsize (KiB) 28148

[startup+3.10616 s]
/proc/loadavg: 0.95 1.01 1.05 2/47 30241
/proc/meminfo: memFree=683108/1048576 swapFree=2077616/2097144
[pid=30230] ppid=30229 vsize=2584 CPUtime=0.01
/proc/30230/stat : 30230 (apt-get-trendy-) S 30229 30230 4159 34819 4229 4202496 564 1852 0 4 0 0 0 1 22 0 1 0 883876033 2646016 283 1283457024 134512640 135304128 4294431072 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30230/statm: 646 283 240 194 0 32 0
[pid=30241] ppid=30230 vsize=56940 CPUtime=2.7
/proc/30241/stat : 30241 (cudftodeb.nativ) R 30230 30230 4159 34819 4229 4202496 13709 0 8 0 268 2 0 0 25 0 1 0 883876067 58306560 13644 1283457024 134512640 135004320 4294916320 18446744073709551615 134977712 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/30241/statm: 14235 13644 225 121 0 13627 0
Current children cumulated CPU time (s) 2.71
Current children cumulated vsize (KiB) 59524

[startup+6.30697 s]
/proc/loadavg: 0.95 1.01 1.05 2/47 30241
/proc/meminfo: memFree=617884/1048576 swapFree=2077616/2097144
[pid=30230] ppid=30229 vsize=2584 CPUtime=0.01
/proc/30230/stat : 30230 (apt-get-trendy-) S 30229 30230 4159 34819 4229 4202496 564 1852 0 4 0 0 0 1 22 0 1 0 883876033 2646016 283 1283457024 134512640 135304128 4294431072 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30230/statm: 646 283 240 194 0 32 0
[pid=30241] ppid=30230 vsize=111992 CPUtime=5.89
/proc/30241/stat : 30241 (cudftodeb.nativ) R 30230 30230 4159 34819 4229 4202496 27168 0 8 0 576 13 0 0 25 0 1 0 883876067 114679808 27103 1283457024 134512640 135004320 4294916320 18446744073709551615 134996501 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/30241/statm: 27998 27103 237 121 0 27390 0
Current children cumulated CPU time (s) 5.9
Current children cumulated vsize (KiB) 114576

[startup+12.7063 s]
/proc/loadavg: 0.96 1.01 1.05 1/47 30251
/proc/meminfo: memFree=614600/1048576 swapFree=2077616/2097144
[pid=30230] ppid=30229 vsize=2592 CPUtime=8.75
/proc/30230/stat : 30230 (apt-get-trendy-) S 30229 30230 4159 34819 4229 4202496 701 34667 0 24 0 0 847 28 18 0 1 0 883876033 2654208 294 1283457024 134512640 135304128 4294431072 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30230/statm: 648 294 249 194 0 34 0
[pid=30251] ppid=30230 vsize=101452 CPUtime=1.33
/proc/30251/stat : 30251 (apt-get) D 30230 30230 4159 34819 4229 4202496 6951 0 388 0 122 11 0 0 18 0 1 0 883877079 103886848 7263 1283457024 134512640 134619611 4288960864 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/30251/statm: 25363 7263 7210 27 0 57 0
Current children cumulated CPU time (s) 10.08
Current children cumulated vsize (KiB) 104044
heavy processes:

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

[startup+12.8063 s]
/proc/loadavg: 0.96 1.01 1.05 1/47 30251
/proc/meminfo: memFree=614060/1048576 swapFree=2077616/2097144
[pid=30230] ppid=30229 vsize=2592 CPUtime=8.75
/proc/30230/stat : 30230 (apt-get-trendy-) S 30229 30230 4159 34819 4229 4202496 701 34667 0 24 0 0 847 28 18 0 1 0 883876033 2654208 294 1283457024 134512640 135304128 4294431072 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30230/statm: 648 294 249 194 0 34 0
[pid=30251] ppid=30230 vsize=101452 CPUtime=1.33
/proc/30251/stat : 30251 (apt-get) D 30230 30230 4159 34819 4229 4202496 6951 0 388 0 122 11 0 0 18 0 1 0 883877079 103886848 7263 1283457024 134512640 134619611 4288960864 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/30251/statm: 25363 7263 7210 27 0 57 0
Current children cumulated CPU time (s) 10.08
Current children cumulated vsize (KiB) 104044

[startup+13.6144 s]
/proc/loadavg: 0.96 1.01 1.05 2/47 30251
/proc/meminfo: memFree=611580/1048576 swapFree=2077616/2097144
[pid=30230] ppid=30229 vsize=2592 CPUtime=8.75
/proc/30230/stat : 30230 (apt-get-trendy-) S 30229 30230 4159 34819 4229 4202496 701 34667 0 24 0 0 847 28 18 0 1 0 883876033 2654208 294 1283457024 134512640 135304128 4294431072 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30230/statm: 648 294 249 194 0 34 0
[pid=30251] ppid=30230 vsize=33880 CPUtime=1.84
/proc/30251/stat : 30251 (apt-get) R 30230 30230 4159 34819 4229 4202496 14148 0 388 0 172 12 0 0 18 0 1 0 883877079 34693120 7557 1283457024 134512640 134619611 4288960864 18446744073709551615 4159115593 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/30251/statm: 8470 7557 6869 27 0 713 0
Current children cumulated CPU time (s) 10.59
Current children cumulated vsize (KiB) 36472

[startup+14.0146 s]
/proc/loadavg: 0.96 1.01 1.05 2/47 30251
/proc/meminfo: memFree=611580/1048576 swapFree=2077616/2097144
[pid=30230] ppid=30229 vsize=2592 CPUtime=8.75
/proc/30230/stat : 30230 (apt-get-trendy-) S 30229 30230 4159 34819 4229 4202496 701 34667 0 24 0 0 847 28 18 0 1 0 883876033 2654208 294 1283457024 134512640 135304128 4294431072 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30230/statm: 648 294 249 194 0 34 0
[pid=30251] ppid=30230 vsize=34292 CPUtime=2.24
/proc/30251/stat : 30251 (apt-get) R 30230 30230 4159 34819 4229 4202496 14237 0 388 0 212 12 0 0 19 0 1 0 883877079 35115008 7646 1283457024 134512640 134619611 4288960864 18446744073709551615 4159103244 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/30251/statm: 8573 7646 6872 27 0 816 0
Current children cumulated CPU time (s) 10.99
Current children cumulated vsize (KiB) 36884

[startup+14.1146 s]
/proc/loadavg: 0.96 1.01 1.05 2/47 30251
/proc/meminfo: memFree=611580/1048576 swapFree=2077616/2097144
[pid=30230] ppid=30229 vsize=2592 CPUtime=8.75
/proc/30230/stat : 30230 (apt-get-trendy-) S 30229 30230 4159 34819 4229 4202496 701 34667 0 24 0 0 847 28 18 0 1 0 883876033 2654208 294 1283457024 134512640 135304128 4294431072 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/30230/statm: 648 294 249 194 0 34 0
[pid=30251] ppid=30230 vsize=34292 CPUtime=2.34
/proc/30251/stat : 30251 (apt-get) R 30230 30230 4159 34819 4229 4202496 14237 0 388 0 222 12 0 0 19 0 1 0 883877079 35115008 7646 1283457024 134512640 134619611 4288960864 18446744073709551615 4159103244 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/30251/statm: 8573 7646 6872 27 0 816 0
Current children cumulated CPU time (s) 11.09
Current children cumulated vsize (KiB) 36884

Child status: 100
Real time (s): 14.1836
CPU time (s): 11.1647
CPU user time (s): 10.7647
CPU system time (s): 0.400025
CPU usage (%): 78.7153
Max. virtual memory (cumulated for all children) (KiB): 124000

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

runsolver used 0.004 second user time and 0.008 second system time

The end