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/rand108.sarge-etch.cudf.sarge-etch.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/icse/sarge-etch/rand108.sarge-etch.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/rand108.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.29 1.12 1.05 3/45 6347
/proc/meminfo: memFree=782456/1048576 swapFree=2077656/2097144
[pid=6342] ppid=6341 vsize=1680 CPUtime=0
/proc/6342/stat : 6342 (sh) S 6341 6342 4159 34819 4229 4202496 223 174 0 0 0 0 0 0 25 0 1 0 878039108 1720320 129 1283457024 134512640 134594024 4288140192 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6342/statm: 420 129 112 20 0 46 0
[pid=6344] ppid=6342 vsize=8356 CPUtime=0.04
/proc/6344/stat : 6344 (apt-pbo) S 6342 6342 4159 34819 4229 4202496 1619 413 0 0 4 0 0 0 25 0 1 0 878039108 8556544 1422 1283457024 134512640 135744540 4294133888 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/6344/statm: 2089 1422 646 301 0 822 0
[pid=6347] ppid=6344 vsize=3320 CPUtime=0.01
/proc/6347/stat : 6347 (cudftodeb.nativ) R 6344 6342 4159 34819 4229 4202496 465 0 0 0 1 0 0 0 25 0 1 0 878039114 3399680 385 1283457024 134512640 135029684 4292566880 18446744073709551615 134646506 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/6347/statm: 830 385 246 127 0 213 0

[startup+0.258613 s]
/proc/loadavg: 1.29 1.12 1.05 3/45 6347
/proc/meminfo: memFree=782456/1048576 swapFree=2077656/2097144
[pid=6342] ppid=6341 vsize=1680 CPUtime=0
/proc/6342/stat : 6342 (sh) S 6341 6342 4159 34819 4229 4202496 223 174 0 0 0 0 0 0 25 0 1 0 878039108 1720320 129 1283457024 134512640 134594024 4288140192 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6342/statm: 420 129 112 20 0 46 0
[pid=6344] ppid=6342 vsize=8356 CPUtime=0.04
/proc/6344/stat : 6344 (apt-pbo) S 6342 6342 4159 34819 4229 4202496 1619 413 0 0 4 0 0 0 25 0 1 0 878039108 8556544 1422 1283457024 134512640 135744540 4294133888 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/6344/statm: 2089 1422 646 301 0 822 0
[pid=6347] ppid=6344 vsize=7492 CPUtime=0.21
/proc/6347/stat : 6347 (cudftodeb.nativ) R 6344 6342 4159 34819 4229 4202496 1487 0 0 0 21 0 0 0 25 0 1 0 878039114 7671808 1407 1283457024 134512640 135029684 4292566880 18446744073709551615 134845170 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/6347/statm: 1873 1407 247 127 0 1256 0
Current children cumulated CPU time (s) 0.25
Current children cumulated vsize (KiB) 17528

[startup+0.308619 s]
/proc/loadavg: 1.29 1.12 1.05 3/45 6347
/proc/meminfo: memFree=782456/1048576 swapFree=2077656/2097144
[pid=6342] ppid=6341 vsize=1680 CPUtime=0
/proc/6342/stat : 6342 (sh) S 6341 6342 4159 34819 4229 4202496 223 174 0 0 0 0 0 0 25 0 1 0 878039108 1720320 129 1283457024 134512640 134594024 4288140192 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6342/statm: 420 129 112 20 0 46 0
[pid=6344] ppid=6342 vsize=8356 CPUtime=0.04
/proc/6344/stat : 6344 (apt-pbo) S 6342 6342 4159 34819 4229 4202496 1619 413 0 0 4 0 0 0 25 0 1 0 878039108 8556544 1422 1283457024 134512640 135744540 4294133888 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/6344/statm: 2089 1422 646 301 0 822 0
[pid=6347] ppid=6344 vsize=8500 CPUtime=0.26
/proc/6347/stat : 6347 (cudftodeb.nativ) R 6344 6342 4159 34819 4229 4202496 1732 0 0 0 26 0 0 0 25 0 1 0 878039114 8704000 1652 1283457024 134512640 135029684 4292566880 18446744073709551615 134973080 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/6347/statm: 2125 1652 247 127 0 1508 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 18536

[startup+0.408637 s]
/proc/loadavg: 1.29 1.12 1.05 3/45 6347
/proc/meminfo: memFree=782456/1048576 swapFree=2077656/2097144
[pid=6342] ppid=6341 vsize=1680 CPUtime=0
/proc/6342/stat : 6342 (sh) S 6341 6342 4159 34819 4229 4202496 223 174 0 0 0 0 0 0 25 0 1 0 878039108 1720320 129 1283457024 134512640 134594024 4288140192 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6342/statm: 420 129 112 20 0 46 0
[pid=6344] ppid=6342 vsize=8356 CPUtime=0.04
/proc/6344/stat : 6344 (apt-pbo) S 6342 6342 4159 34819 4229 4202496 1619 413 0 0 4 0 0 0 25 0 1 0 878039108 8556544 1422 1283457024 134512640 135744540 4294133888 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/6344/statm: 2089 1422 646 301 0 822 0
[pid=6347] ppid=6344 vsize=10516 CPUtime=0.36
/proc/6347/stat : 6347 (cudftodeb.nativ) R 6344 6342 4159 34819 4229 4202496 2235 0 0 0 36 0 0 0 25 0 1 0 878039114 10768384 2155 1283457024 134512640 135029684 4292566880 18446744073709551615 134555941 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/6347/statm: 2629 2155 247 127 0 2012 0
Current children cumulated CPU time (s) 0.4
Current children cumulated vsize (KiB) 20552

[startup+0.708682 s]
/proc/loadavg: 1.29 1.12 1.05 3/45 6347
/proc/meminfo: memFree=782456/1048576 swapFree=2077656/2097144
[pid=6342] ppid=6341 vsize=1680 CPUtime=0
/proc/6342/stat : 6342 (sh) S 6341 6342 4159 34819 4229 4202496 223 174 0 0 0 0 0 0 25 0 1 0 878039108 1720320 129 1283457024 134512640 134594024 4288140192 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6342/statm: 420 129 112 20 0 46 0
[pid=6344] ppid=6342 vsize=8356 CPUtime=0.04
/proc/6344/stat : 6344 (apt-pbo) S 6342 6342 4159 34819 4229 4202496 1619 413 0 0 4 0 0 0 25 0 1 0 878039108 8556544 1422 1283457024 134512640 135744540 4294133888 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/6344/statm: 2089 1422 646 301 0 822 0
[pid=6347] ppid=6344 vsize=16060 CPUtime=0.66
/proc/6347/stat : 6347 (cudftodeb.nativ) R 6344 6342 4159 34819 4229 4202496 3712 0 0 0 66 0 0 0 25 0 1 0 878039114 16445440 3632 1283457024 134512640 135029684 4292566880 18446744073709551615 134984556 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/6347/statm: 4015 3632 247 127 0 3398 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 26096

[startup+1.5088 s]
/proc/loadavg: 1.29 1.12 1.05 2/46 6348
/proc/meminfo: memFree=759772/1048576 swapFree=2077656/2097144
[pid=6342] ppid=6341 vsize=1680 CPUtime=0
/proc/6342/stat : 6342 (sh) S 6341 6342 4159 34819 4229 4202496 223 174 0 0 0 0 0 0 25 0 1 0 878039108 1720320 129 1283457024 134512640 134594024 4288140192 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6342/statm: 420 129 112 20 0 46 0
[pid=6344] ppid=6342 vsize=8356 CPUtime=0.04
/proc/6344/stat : 6344 (apt-pbo) S 6342 6342 4159 34819 4229 4202496 1619 413 0 0 4 0 0 0 25 0 1 0 878039108 8556544 1422 1283457024 134512640 135744540 4294133888 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/6344/statm: 2089 1422 646 301 0 822 0
[pid=6347] ppid=6344 vsize=33196 CPUtime=1.45
/proc/6347/stat : 6347 (cudftodeb.nativ) R 6344 6342 4159 34819 4229 4202496 7994 0 0 0 145 0 0 0 25 0 1 0 878039114 33992704 7914 1283457024 134512640 135029684 4292566880 18446744073709551615 4159660073 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/6347/statm: 8299 7914 257 127 0 7682 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 43232

[startup+3.10905 s]
/proc/loadavg: 1.29 1.12 1.05 2/46 6348
/proc/meminfo: memFree=736832/1048576 swapFree=2077656/2097144
[pid=6342] ppid=6341 vsize=1680 CPUtime=0
/proc/6342/stat : 6342 (sh) S 6341 6342 4159 34819 4229 4202496 223 174 0 0 0 0 0 0 25 0 1 0 878039108 1720320 129 1283457024 134512640 134594024 4288140192 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6342/statm: 420 129 112 20 0 46 0
[pid=6344] ppid=6342 vsize=8356 CPUtime=0.04
/proc/6344/stat : 6344 (apt-pbo) S 6342 6342 4159 34819 4229 4202496 1619 413 0 0 4 0 0 0 25 0 1 0 878039108 8556544 1422 1283457024 134512640 135744540 4294133888 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/6344/statm: 2089 1422 646 301 0 822 0
[pid=6347] ppid=6344 vsize=51844 CPUtime=3.06
/proc/6347/stat : 6347 (cudftodeb.nativ) R 6344 6342 4159 34819 4229 4202496 12623 0 0 0 270 36 0 0 25 0 1 0 878039114 53088256 12543 1283457024 134512640 135029684 4292566880 18446744073709551615 135015969 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/6347/statm: 12961 12543 258 127 0 12344 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 61880

[startup+6.30714 s]
/proc/loadavg: 1.27 1.12 1.05 2/45 6356
/proc/meminfo: memFree=743180/1048576 swapFree=2077656/2097144
[pid=6342] ppid=6341 vsize=1680 CPUtime=0
/proc/6342/stat : 6342 (sh) S 6341 6342 4159 34819 4229 4202496 223 174 0 0 0 0 0 0 25 0 1 0 878039108 1720320 129 1283457024 134512640 134594024 4288140192 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6342/statm: 420 129 112 20 0 46 0
[pid=6344] ppid=6342 vsize=21832 CPUtime=4.65
/proc/6344/stat : 6344 (apt-pbo) S 6342 6342 4159 34819 4229 4202496 5537 20225 0 168 17 6 379 63 18 0 1 0 878039108 22355968 4684 1283457024 134512640 135744540 4294133888 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/6344/statm: 5458 4684 3494 301 0 1230 0
Current children cumulated CPU time (s) 4.65
Current children cumulated vsize (KiB) 23512
heavy processes:

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

[startup+6.50718 s]
/proc/loadavg: 1.27 1.12 1.05 2/47 6361
/proc/meminfo: memFree=740296/1048576 swapFree=2077656/2097144
[pid=6342] ppid=6341 vsize=1680 CPUtime=0
/proc/6342/stat : 6342 (sh) S 6341 6342 4159 34819 4229 4202496 223 174 0 0 0 0 0 0 25 0 1 0 878039108 1720320 129 1283457024 134512640 134594024 4288140192 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6342/statm: 420 129 112 20 0 46 0
[pid=6344] ppid=6342 vsize=21832 CPUtime=4.66
/proc/6344/stat : 6344 (apt-pbo) S 6342 6342 4159 34819 4229 4202496 5537 20225 0 168 18 6 379 63 18 0 1 0 878039108 22355968 4684 1283457024 134512640 135744540 4294133888 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/6344/statm: 5458 4684 3494 301 0 1230 0
[pid=6358] ppid=6344 vsize=2580 CPUtime=0
/proc/6358/stat : 6358 (apt-get.sh) S 6344 6342 4159 34819 4229 4202496 463 489 0 0 0 0 0 0 18 0 1 0 878039673 2641920 276 1283457024 134512640 135304128 4292570672 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6358/statm: 645 276 235 194 0 31 0
[pid=6361] ppid=6358 vsize=17248 CPUtime=0.76
/proc/6361/stat : 6361 (apt-get) R 6358 6342 4159 34819 4229 4202496 3686 0 0 0 69 7 0 0 25 0 1 0 878039673 17661952 3612 1283457024 134512640 134649604 4291194128 18446744073709551615 4157261548 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/6361/statm: 4312 3612 3191 34 0 441 0
Current children cumulated CPU time (s) 5.42
Current children cumulated vsize (KiB) 43340

[startup+7.30739 s]
/proc/loadavg: 1.27 1.12 1.05 2/47 6361
/proc/meminfo: memFree=739924/1048576 swapFree=2077656/2097144
[pid=6342] ppid=6341 vsize=1680 CPUtime=0
/proc/6342/stat : 6342 (sh) S 6341 6342 4159 34819 4229 4202496 223 174 0 0 0 0 0 0 25 0 1 0 878039108 1720320 129 1283457024 134512640 134594024 4288140192 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6342/statm: 420 129 112 20 0 46 0
[pid=6344] ppid=6342 vsize=21832 CPUtime=4.74
/proc/6344/stat : 6344 (apt-pbo) S 6342 6342 4159 34819 4229 4202496 5537 20225 0 168 18 14 379 63 18 0 1 0 878039108 22355968 4684 1283457024 134512640 135744540 4294133888 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/6344/statm: 5458 4684 3494 301 0 1230 0
[pid=6358] ppid=6344 vsize=2580 CPUtime=0
/proc/6358/stat : 6358 (apt-get.sh) S 6344 6342 4159 34819 4229 4202496 463 489 0 0 0 0 0 0 18 0 1 0 878039673 2641920 276 1283457024 134512640 135304128 4292570672 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6358/statm: 645 276 235 194 0 31 0
[pid=6361] ppid=6358 vsize=17248 CPUtime=1.49
/proc/6361/stat : 6361 (apt-get) R 6358 6342 4159 34819 4229 4202496 3702 0 0 0 133 16 0 0 25 0 1 0 878039673 17661952 3628 1283457024 134512640 134649604 4291194128 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/6361/statm: 4312 3628 3191 34 0 441 0
Current children cumulated CPU time (s) 6.23
Current children cumulated vsize (KiB) 43340

[startup+7.70748 s]
/proc/loadavg: 1.27 1.12 1.05 2/47 6361
/proc/meminfo: memFree=739924/1048576 swapFree=2077656/2097144
[pid=6342] ppid=6341 vsize=1680 CPUtime=0
/proc/6342/stat : 6342 (sh) S 6341 6342 4159 34819 4229 4202496 223 174 0 0 0 0 0 0 25 0 1 0 878039108 1720320 129 1283457024 134512640 134594024 4288140192 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6342/statm: 420 129 112 20 0 46 0
[pid=6344] ppid=6342 vsize=21832 CPUtime=4.78
/proc/6344/stat : 6344 (apt-pbo) S 6342 6342 4159 34819 4229 4202496 5537 20225 0 168 20 16 379 63 18 0 1 0 878039108 22355968 4684 1283457024 134512640 135744540 4294133888 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/6344/statm: 5458 4684 3494 301 0 1230 0
[pid=6358] ppid=6344 vsize=2580 CPUtime=0
/proc/6358/stat : 6358 (apt-get.sh) S 6344 6342 4159 34819 4229 4202496 463 489 0 0 0 0 0 0 18 0 1 0 878039673 2641920 276 1283457024 134512640 135304128 4292570672 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6358/statm: 645 276 235 194 0 31 0
[pid=6361] ppid=6358 vsize=17472 CPUtime=1.85
/proc/6361/stat : 6361 (apt-get) R 6358 6342 4159 34819 4229 4202496 3723 0 0 0 167 18 0 0 25 0 1 0 878039673 17891328 3649 1283457024 134512640 134649604 4291194128 18446744073709551615 4157256887 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/6361/statm: 4368 3649 3191 34 0 497 0
Current children cumulated CPU time (s) 6.63
Current children cumulated vsize (KiB) 43564

[startup+7.90755 s]
/proc/loadavg: 1.25 1.12 1.05 2/47 6361
/proc/meminfo: memFree=737692/1048576 swapFree=2077656/2097144
[pid=6342] ppid=6341 vsize=1680 CPUtime=0
/proc/6342/stat : 6342 (sh) S 6341 6342 4159 34819 4229 4202496 223 174 0 0 0 0 0 0 25 0 1 0 878039108 1720320 129 1283457024 134512640 134594024 4288140192 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/6342/statm: 420 129 112 20 0 46 0
[pid=6344] ppid=6342 vsize=23804 CPUtime=6.8
/proc/6344/stat : 6344 (apt-pbo) R 6342 6342 4159 34819 4229 4202496 6106 24914 0 168 20 18 556 86 18 0 1 0 878039108 24375296 5180 1283457024 134512640 135744540 4294133888 18446744073709551615 4294960130 0 0 128 0 0 0 0 17 0 0 0 0
/proc/6344/statm: 5951 5180 3497 301 0 1723 0
Current children cumulated CPU time (s) 6.8
Current children cumulated vsize (KiB) 25484

Child status: 0
Real time (s): 7.96121
CPU time (s): 6.84043
CPU user time (s): 5.78036
CPU system time (s): 1.06007
CPU usage (%): 85.922
Max. virtual memory (cumulated for all children) (KiB): 65368

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 5.78036
system time used= 1.06007
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 31789
page faults= 168
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 53076
involuntary context switches= 53048

runsolver used 0 second user time and 0.012 second system time

The end