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/rand550.sarge-etch.cudf.sarge-etch.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/icse/sarge-etch/rand550.sarge-etch.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/rand550.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.18 1.07 1.04 5/47 20493
/proc/meminfo: memFree=810132/1048576 swapFree=2077688/2097144
[pid=20492] ppid=20491 vsize=1672 CPUtime=0
/proc/20492/stat : 20492 (sh) R 20491 20492 4159 34819 4229 4202496 206 0 0 0 0 0 0 0 25 0 1 0 881676535 1712128 126 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/20492/statm: 418 126 110 20 0 44 0
[pid=20493] ppid=20492 vsize=1672 CPUtime=0
/proc/20493/stat : 20493 (sh) R 20492 20492 4159 34819 4229 4202560 0 0 0 0 0 0 0 0 25 0 1 0 881676536 1712128 16 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/20493/statm: 418 16 0 20 0 44 0

[startup+0.14611 s]
/proc/loadavg: 1.18 1.07 1.04 5/47 20493
/proc/meminfo: memFree=810132/1048576 swapFree=2077688/2097144
[pid=20492] ppid=20491 vsize=1672 CPUtime=0
/proc/20492/stat : 20492 (sh) S 20491 20492 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 881676535 1712128 128 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20492/statm: 418 128 112 20 0 44 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1672

[startup+0.206126 s]
/proc/loadavg: 1.18 1.07 1.04 5/47 20493
/proc/meminfo: memFree=810132/1048576 swapFree=2077688/2097144
[pid=20492] ppid=20491 vsize=1672 CPUtime=0
/proc/20492/stat : 20492 (sh) S 20491 20492 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 881676535 1712128 128 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20492/statm: 418 128 112 20 0 44 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1672

[startup+0.306145 s]
/proc/loadavg: 1.18 1.07 1.04 5/47 20493
/proc/meminfo: memFree=810132/1048576 swapFree=2077688/2097144
[pid=20492] ppid=20491 vsize=1672 CPUtime=0
/proc/20492/stat : 20492 (sh) S 20491 20492 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 881676535 1712128 128 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20492/statm: 418 128 112 20 0 44 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1672

[startup+0.706203 s]
/proc/loadavg: 1.18 1.07 1.04 5/47 20493
/proc/meminfo: memFree=810132/1048576 swapFree=2077688/2097144
[pid=20492] ppid=20491 vsize=1672 CPUtime=0
/proc/20492/stat : 20492 (sh) S 20491 20492 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 881676535 1712128 128 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20492/statm: 418 128 112 20 0 44 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1672

[startup+1.50633 s]
/proc/loadavg: 1.16 1.07 1.03 2/49 20498
/proc/meminfo: memFree=786040/1048576 swapFree=2077688/2097144
[pid=20492] ppid=20491 vsize=1672 CPUtime=0
/proc/20492/stat : 20492 (sh) S 20491 20492 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 881676535 1712128 128 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20492/statm: 418 128 112 20 0 44 0
[pid=20495] ppid=20492 vsize=8356 CPUtime=0.05
/proc/20495/stat : 20495 (apt-pbo) S 20492 20492 4159 34819 4229 4202496 1618 413 0 0 4 1 0 0 25 0 1 0 881676536 8556544 1422 1283457024 134512640 135744540 4293777440 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/20495/statm: 2089 1422 646 301 0 822 0
[pid=20498] ppid=20495 vsize=33200 CPUtime=1.44
/proc/20498/stat : 20498 (cudftodeb.nativ) R 20495 20492 4159 34819 4229 4202496 7994 0 0 0 135 9 0 0 25 0 1 0 881676541 33996800 7914 1283457024 134512640 135029684 4291440208 18446744073709551615 134969984 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/20498/statm: 8300 7914 257 127 0 7683 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 43228

[startup+3.10826 s]
/proc/loadavg: 1.16 1.07 1.03 2/49 20498
/proc/meminfo: memFree=763224/1048576 swapFree=2077688/2097144
[pid=20492] ppid=20491 vsize=1672 CPUtime=0
/proc/20492/stat : 20492 (sh) S 20491 20492 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 881676535 1712128 128 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20492/statm: 418 128 112 20 0 44 0
[pid=20495] ppid=20492 vsize=8356 CPUtime=0.05
/proc/20495/stat : 20495 (apt-pbo) S 20492 20492 4159 34819 4229 4202496 1618 413 0 0 4 1 0 0 25 0 1 0 881676536 8556544 1422 1283457024 134512640 135744540 4293777440 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/20495/statm: 2089 1422 646 301 0 822 0
[pid=20498] ppid=20495 vsize=51848 CPUtime=2.93
/proc/20498/stat : 20498 (cudftodeb.nativ) R 20495 20492 4159 34819 4229 4202496 12623 0 0 0 251 42 0 0 25 0 1 0 881676541 53092352 12543 1283457024 134512640 135029684 4291440208 18446744073709551615 134874694 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/20498/statm: 12962 12543 258 127 0 12345 0
Current children cumulated CPU time (s) 2.98
Current children cumulated vsize (KiB) 61876

[startup+6.31258 s]
/proc/loadavg: 1.16 1.07 1.03 1/50 20506
/proc/meminfo: memFree=768000/1048576 swapFree=2077688/2097144
[pid=20492] ppid=20491 vsize=1672 CPUtime=0
/proc/20492/stat : 20492 (sh) S 20491 20492 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 881676535 1712128 128 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20492/statm: 418 128 112 20 0 44 0
[pid=20495] ppid=20492 vsize=21832 CPUtime=4.66
/proc/20495/stat : 20495 (apt-pbo) S 20492 20492 4159 34819 4229 4202496 5529 20223 0 168 18 4 376 68 18 0 1 0 881676536 22355968 4684 1283457024 134512640 135744540 4293777440 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/20495/statm: 5458 4684 3494 301 0 1230 0
Current children cumulated CPU time (s) 4.66
Current children cumulated vsize (KiB) 23504
heavy processes:

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

[startup+6.4026 s]
/proc/loadavg: 1.15 1.07 1.03 2/50 20511
/proc/meminfo: memFree=764652/1048576 swapFree=2077688/2097144
[pid=20492] ppid=20491 vsize=1672 CPUtime=0
/proc/20492/stat : 20492 (sh) S 20491 20492 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 881676535 1712128 128 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20492/statm: 418 128 112 20 0 44 0
[pid=20495] ppid=20492 vsize=21832 CPUtime=4.67
/proc/20495/stat : 20495 (apt-pbo) S 20492 20492 4159 34819 4229 4202496 5529 20223 0 168 19 4 376 68 18 0 1 0 881676536 22355968 4684 1283457024 134512640 135744540 4293777440 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/20495/statm: 5458 4684 3494 301 0 1230 0
[pid=20508] ppid=20495 vsize=2580 CPUtime=0
/proc/20508/stat : 20508 (apt-get.sh) S 20495 20492 4159 34819 4229 4202496 461 487 0 0 0 0 0 0 18 0 1 0 881677105 2641920 277 1283457024 134512640 135304128 4294766624 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20508/statm: 645 277 235 194 0 31 0
[pid=20511] ppid=20508 vsize=17244 CPUtime=0.61
/proc/20511/stat : 20511 (apt-get) R 20508 20492 4159 34819 4229 4202496 3685 0 0 0 53 8 0 0 25 0 1 0 881677105 17657856 3611 1283457024 134512640 134649604 4294770768 18446744073709551615 4156642673 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/20511/statm: 4311 3611 3191 34 0 440 0
Current children cumulated CPU time (s) 5.28
Current children cumulated vsize (KiB) 43328

[startup+7.20273 s]
/proc/loadavg: 1.15 1.07 1.03 2/50 20511
/proc/meminfo: memFree=764404/1048576 swapFree=2077688/2097144
[pid=20492] ppid=20491 vsize=1672 CPUtime=0
/proc/20492/stat : 20492 (sh) S 20491 20492 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 881676535 1712128 128 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20492/statm: 418 128 112 20 0 44 0
[pid=20495] ppid=20492 vsize=21832 CPUtime=4.78
/proc/20495/stat : 20495 (apt-pbo) R 20492 20492 4159 34819 4229 4202496 5529 20223 0 168 22 12 376 68 18 0 1 0 881676536 22355968 4684 1283457024 134512640 135744540 4293777440 18446744073709551615 4294960130 0 0 128 0 0 0 0 17 0 0 0 0
/proc/20495/statm: 5458 4684 3494 301 0 1230 0
[pid=20508] ppid=20495 vsize=2580 CPUtime=0
/proc/20508/stat : 20508 (apt-get.sh) S 20495 20492 4159 34819 4229 4202496 461 487 0 0 0 0 0 0 18 0 1 0 881677105 2641920 277 1283457024 134512640 135304128 4294766624 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20508/statm: 645 277 235 194 0 31 0
[pid=20511] ppid=20508 vsize=17244 CPUtime=1.31
/proc/20511/stat : 20511 (apt-get) R 20508 20492 4159 34819 4229 4202496 3700 0 0 0 117 14 0 0 25 0 1 0 881677105 17657856 3626 1283457024 134512640 134649604 4294770768 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/20511/statm: 4311 3626 3191 34 0 440 0
Current children cumulated CPU time (s) 6.09
Current children cumulated vsize (KiB) 43328

[startup+7.60281 s]
/proc/loadavg: 1.15 1.07 1.03 2/50 20511
/proc/meminfo: memFree=764404/1048576 swapFree=2077688/2097144
[pid=20492] ppid=20491 vsize=1672 CPUtime=0
/proc/20492/stat : 20492 (sh) S 20491 20492 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 881676535 1712128 128 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20492/statm: 418 128 112 20 0 44 0
[pid=20495] ppid=20492 vsize=21832 CPUtime=4.88
/proc/20495/stat : 20495 (apt-pbo) S 20492 20492 4159 34819 4229 4202496 5529 20223 0 168 26 18 376 68 18 0 1 0 881676536 22355968 4684 1283457024 134512640 135744540 4293777440 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/20495/statm: 5458 4684 3494 301 0 1230 0
[pid=20508] ppid=20495 vsize=2580 CPUtime=0
/proc/20508/stat : 20508 (apt-get.sh) S 20495 20492 4159 34819 4229 4202496 461 487 0 0 0 0 0 0 18 0 1 0 881677105 2641920 277 1283457024 134512640 135304128 4294766624 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20508/statm: 645 277 235 194 0 31 0
[pid=20511] ppid=20508 vsize=17468 CPUtime=1.61
/proc/20511/stat : 20511 (apt-get) R 20508 20492 4159 34819 4229 4202496 3720 0 0 0 143 18 0 0 25 0 1 0 881677105 17887232 3646 1283457024 134512640 134649604 4294770768 18446744073709551615 4156361279 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/20511/statm: 4367 3646 3191 34 0 496 0
Current children cumulated CPU time (s) 6.49
Current children cumulated vsize (KiB) 43552

[startup+7.80286 s]
/proc/loadavg: 1.15 1.07 1.03 2/50 20511
/proc/meminfo: memFree=763040/1048576 swapFree=2077688/2097144
[pid=20492] ppid=20491 vsize=1672 CPUtime=0
/proc/20492/stat : 20492 (sh) S 20491 20492 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 881676535 1712128 128 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20492/statm: 418 128 112 20 0 44 0
[pid=20495] ppid=20492 vsize=21832 CPUtime=4.88
/proc/20495/stat : 20495 (apt-pbo) S 20492 20492 4159 34819 4229 4202496 5529 20223 0 168 26 18 376 68 18 0 1 0 881676536 22355968 4684 1283457024 134512640 135744540 4293777440 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/20495/statm: 5458 4684 3494 301 0 1230 0
[pid=20508] ppid=20495 vsize=2580 CPUtime=0
/proc/20508/stat : 20508 (apt-get.sh) S 20495 20492 4159 34819 4229 4202496 461 487 0 0 0 0 0 0 18 0 1 0 881677105 2641920 277 1283457024 134512640 135304128 4294766624 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20508/statm: 645 277 235 194 0 31 0
[pid=20511] ppid=20508 vsize=17468 CPUtime=1.81
/proc/20511/stat : 20511 (apt-get) R 20508 20492 4159 34819 4229 4202496 3723 0 0 0 154 27 0 0 25 0 1 0 881677105 17887232 3649 1283457024 134512640 134649604 4294770768 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/20511/statm: 4367 3649 3192 34 0 496 0
Current children cumulated CPU time (s) 6.69
Current children cumulated vsize (KiB) 43552

[startup+7.91359 s]
/proc/loadavg: 1.15 1.07 1.03 2/50 20511
/proc/meminfo: memFree=763040/1048576 swapFree=2077688/2097144
[pid=20492] ppid=20491 vsize=1672 CPUtime=0
/proc/20492/stat : 20492 (sh) S 20491 20492 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 881676535 1712128 128 1283457024 134512640 134594024 4291231376 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20492/statm: 418 128 112 20 0 44 0
[pid=20495] ppid=20492 vsize=22596 CPUtime=6.75
/proc/20495/stat : 20495 (apt-pbo) R 20492 20492 4159 34819 4229 4202496 6296 24907 0 168 27 20 532 96 18 0 1 0 881676536 23138304 2834 1283457024 134512640 135744540 4293777440 18446744073709551615 4294960130 0 0 128 0 0 0 0 17 0 0 0 0
/proc/20495/statm: 5649 2834 1450 301 0 1421 0
Current children cumulated CPU time (s) 6.75
Current children cumulated vsize (KiB) 24268

Child status: 0
Real time (s): 7.91653
CPU time (s): 6.76042
CPU user time (s): 5.59635
CPU system time (s): 1.16407
CPU usage (%): 85.3962
Max. virtual memory (cumulated for all children) (KiB): 65352

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 5.59635
system time used= 1.16407
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 31742
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= 49636
involuntary context switches= 49615

runsolver used 0 second user time and 0 second system time

The end