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/randbe9acf.cudf.easy.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/2010/easy//randbe9acf.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/randbe9acf.cudf.easy.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.98 0.99 0.99 2/40 5248
/proc/meminfo: memFree=799868/1048576 swapFree=2077620/2097144
[pid=5248] ppid=5247 vsize=1676 CPUtime=0
/proc/5248/stat : 5248 (sh) S 5247 5248 4159 34819 4229 4202496 223 176 0 0 0 0 0 0 25 0 1 0 885409897 1716224 129 1283457024 134512640 134594024 4289520896 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5248/statm: 419 129 112 20 0 45 0
[pid=5250] ppid=5248 vsize=1676 CPUtime=0
/proc/5250/stat : 5250 (sh) R 5248 5248 4159 34819 4229 4202560 41 0 0 0 0 0 0 0 25 0 1 0 885409897 1716224 50 1283457024 134512640 134594024 4289520896 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/5250/statm: 419 50 32 20 0 45 0

[startup+0.144504 s]
/proc/loadavg: 0.98 0.99 0.99 2/40 5248
/proc/meminfo: memFree=799868/1048576 swapFree=2077620/2097144
[pid=5248] ppid=5247 vsize=1676 CPUtime=0
/proc/5248/stat : 5248 (sh) S 5247 5248 4159 34819 4229 4202496 223 176 0 0 0 0 0 0 25 0 1 0 885409897 1716224 129 1283457024 134512640 134594024 4289520896 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5248/statm: 419 129 112 20 0 45 0
[pid=5250] ppid=5248 vsize=5748 CPUtime=0.02
/proc/5250/stat : 5250 (apt-pbo) D 5248 5248 4159 34819 4229 4202496 1102 0 3 0 2 0 0 0 25 0 1 0 885409897 5885952 1045 1283457024 134512640 135744540 4288427616 18446744073709551615 4159989758 0 0 128 0 18446744071564332000 0 0 17 0 0 0 0
/proc/5250/statm: 1437 1045 418 301 0 650 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 7424

[startup+0.204547 s]
/proc/loadavg: 0.98 0.99 0.99 2/40 5248
/proc/meminfo: memFree=799868/1048576 swapFree=2077620/2097144
[pid=5248] ppid=5247 vsize=1676 CPUtime=0
/proc/5248/stat : 5248 (sh) S 5247 5248 4159 34819 4229 4202496 223 176 0 0 0 0 0 0 25 0 1 0 885409897 1716224 129 1283457024 134512640 134594024 4289520896 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5248/statm: 419 129 112 20 0 45 0
[pid=5250] ppid=5248 vsize=8352 CPUtime=0.02
/proc/5250/stat : 5250 (apt-pbo) S 5248 5248 4159 34819 4229 4202496 1605 414 5 0 2 0 0 0 25 0 1 0 885409897 8552448 1422 1283457024 134512640 135744540 4288427616 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/5250/statm: 2088 1422 646 301 0 821 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 10028

[startup+0.304549 s]
/proc/loadavg: 0.98 0.99 0.99 2/40 5248
/proc/meminfo: memFree=799868/1048576 swapFree=2077620/2097144
[pid=5248] ppid=5247 vsize=1676 CPUtime=0
/proc/5248/stat : 5248 (sh) S 5247 5248 4159 34819 4229 4202496 223 176 0 0 0 0 0 0 25 0 1 0 885409897 1716224 129 1283457024 134512640 134594024 4289520896 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5248/statm: 419 129 112 20 0 45 0
[pid=5250] ppid=5248 vsize=8352 CPUtime=0.02
/proc/5250/stat : 5250 (apt-pbo) S 5248 5248 4159 34819 4229 4202496 1605 414 5 0 2 0 0 0 25 0 1 0 885409897 8552448 1422 1283457024 134512640 135744540 4288427616 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/5250/statm: 2088 1422 646 301 0 821 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 10028

[startup+0.708378 s]
/proc/loadavg: 0.98 0.99 0.99 2/40 5248
/proc/meminfo: memFree=799868/1048576 swapFree=2077620/2097144
[pid=5248] ppid=5247 vsize=1676 CPUtime=0
/proc/5248/stat : 5248 (sh) S 5247 5248 4159 34819 4229 4202496 223 176 0 0 0 0 0 0 25 0 1 0 885409897 1716224 129 1283457024 134512640 134594024 4289520896 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5248/statm: 419 129 112 20 0 45 0
[pid=5250] ppid=5248 vsize=8352 CPUtime=0.02
/proc/5250/stat : 5250 (apt-pbo) S 5248 5248 4159 34819 4229 4202496 1605 414 5 0 2 0 0 0 25 0 1 0 885409897 8552448 1422 1283457024 134512640 135744540 4288427616 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/5250/statm: 2088 1422 646 301 0 821 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 10028

[startup+1.50856 s]
/proc/loadavg: 0.98 0.99 0.99 2/43 5254
/proc/meminfo: memFree=776836/1048576 swapFree=2077620/2097144
[pid=5248] ppid=5247 vsize=1676 CPUtime=0
/proc/5248/stat : 5248 (sh) S 5247 5248 4159 34819 4229 4202496 223 176 0 0 0 0 0 0 25 0 1 0 885409897 1716224 129 1283457024 134512640 134594024 4289520896 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5248/statm: 419 129 112 20 0 45 0
[pid=5250] ppid=5248 vsize=8352 CPUtime=0.02
/proc/5250/stat : 5250 (apt-pbo) S 5248 5248 4159 34819 4229 4202496 1605 414 5 0 2 0 0 0 25 0 1 0 885409897 8552448 1422 1283457024 134512640 135744540 4288427616 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/5250/statm: 2088 1422 646 301 0 821 0
[pid=5254] ppid=5250 vsize=28660 CPUtime=1.24
/proc/5254/stat : 5254 (cudftodeb.nativ) R 5250 5248 4159 34819 4229 4202496 6814 0 8 0 119 5 0 0 25 0 1 0 885409915 29347840 6740 1283457024 134512640 135029684 4289413376 18446744073709551615 135002696 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/5254/statm: 7165 6740 247 127 0 6548 0
Current children cumulated CPU time (s) 1.26
Current children cumulated vsize (KiB) 38688

[startup+3.10893 s]
/proc/loadavg: 0.98 0.99 0.99 2/43 5254
/proc/meminfo: memFree=752532/1048576 swapFree=2077620/2097144
[pid=5248] ppid=5247 vsize=1676 CPUtime=0
/proc/5248/stat : 5248 (sh) S 5247 5248 4159 34819 4229 4202496 223 176 0 0 0 0 0 0 25 0 1 0 885409897 1716224 129 1283457024 134512640 134594024 4289520896 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5248/statm: 419 129 112 20 0 45 0
[pid=5250] ppid=5248 vsize=8352 CPUtime=0.02
/proc/5250/stat : 5250 (apt-pbo) S 5248 5248 4159 34819 4229 4202496 1605 414 5 0 2 0 0 0 25 0 1 0 885409897 8552448 1422 1283457024 134512640 135744540 4288427616 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/5250/statm: 2088 1422 646 301 0 821 0
[pid=5254] ppid=5250 vsize=55372 CPUtime=2.84
/proc/5254/stat : 5254 (cudftodeb.nativ) R 5250 5248 4159 34819 4229 4202496 13493 0 8 0 248 36 0 0 25 0 1 0 885409915 56700928 13419 1283457024 134512640 135029684 4289413376 18446744073709551615 134971691 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/5254/statm: 13843 13419 258 127 0 13226 0
Current children cumulated CPU time (s) 2.86
Current children cumulated vsize (KiB) 65400

[startup+6.30694 s]
/proc/loadavg: 0.98 0.99 0.99 1/44 5262
/proc/meminfo: memFree=754360/1048576 swapFree=2077620/2097144
[pid=5248] ppid=5247 vsize=1676 CPUtime=0
/proc/5248/stat : 5248 (sh) S 5247 5248 4159 34819 4229 4202496 223 176 0 0 0 0 0 0 25 0 1 0 885409897 1716224 129 1283457024 134512640 134594024 4289520896 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5248/statm: 419 129 112 20 0 45 0
[pid=5250] ppid=5248 vsize=23288 CPUtime=4.82
/proc/5250/stat : 5250 (apt-pbo) S 5248 5248 4159 34819 4229 4202496 5890 21166 5 206 13 1 396 72 18 0 1 0 885409897 23846912 5032 1283457024 134512640 135744540 4288427616 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/5250/statm: 5822 5032 3682 301 0 1402 0
Current children cumulated CPU time (s) 4.82
Current children cumulated vsize (KiB) 24964
heavy processes:

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

[startup+6.40696 s]
/proc/loadavg: 0.98 0.99 0.99 3/44 5267
/proc/meminfo: memFree=748768/1048576 swapFree=2077620/2097144
[pid=5248] ppid=5247 vsize=1676 CPUtime=0
/proc/5248/stat : 5248 (sh) S 5247 5248 4159 34819 4229 4202496 223 176 0 0 0 0 0 0 25 0 1 0 885409897 1716224 129 1283457024 134512640 134594024 4289520896 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5248/statm: 419 129 112 20 0 45 0
[pid=5250] ppid=5248 vsize=23288 CPUtime=4.82
/proc/5250/stat : 5250 (apt-pbo) S 5248 5248 4159 34819 4229 4202496 5890 21166 5 206 13 1 396 72 18 0 1 0 885409897 23846912 5032 1283457024 134512640 135744540 4288427616 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/5250/statm: 5822 5032 3682 301 0 1402 0
[pid=5264] ppid=5250 vsize=2580 CPUtime=0.01
/proc/5264/stat : 5264 (apt-get.sh) S 5250 5248 4159 34819 4229 4202496 486 486 0 0 0 1 0 0 18 0 1 0 885410520 2641920 277 1283457024 134512640 135304128 4288451056 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5264/statm: 645 277 235 194 0 31 0
[pid=5267] ppid=5264 vsize=18512 CPUtime=0.16
/proc/5267/stat : 5267 (apt-get) R 5264 5248 4159 34819 4229 4202496 4030 0 0 0 15 1 0 0 22 0 1 0 885410521 18956288 3919 1283457024 134512640 134649604 4294858800 18446744073709551615 4156876129 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/5267/statm: 4628 3919 3381 34 0 565 0
Current children cumulated CPU time (s) 4.99
Current children cumulated vsize (KiB) 46056

[startup+7.20716 s]
/proc/loadavg: 0.98 0.99 0.99 2/44 5267
/proc/meminfo: memFree=748148/1048576 swapFree=2077620/2097144
[pid=5248] ppid=5247 vsize=1676 CPUtime=0
/proc/5248/stat : 5248 (sh) S 5247 5248 4159 34819 4229 4202496 223 176 0 0 0 0 0 0 25 0 1 0 885409897 1716224 129 1283457024 134512640 134594024 4289520896 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5248/statm: 419 129 112 20 0 45 0
[pid=5250] ppid=5248 vsize=23288 CPUtime=4.94
/proc/5250/stat : 5250 (apt-pbo) R 5248 5248 4159 34819 4229 4202496 5890 21166 5 206 18 8 396 72 18 0 1 0 885409897 23846912 5032 1283457024 134512640 135744540 4288427616 18446744073709551615 4159611715 0 0 128 0 0 0 0 17 0 0 0 0
/proc/5250/statm: 5822 5032 3682 301 0 1402 0
[pid=5264] ppid=5250 vsize=2580 CPUtime=0.01
/proc/5264/stat : 5264 (apt-get.sh) S 5250 5248 4159 34819 4229 4202496 486 486 0 0 0 1 0 0 18 0 1 0 885410520 2641920 277 1283457024 134512640 135304128 4288451056 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5264/statm: 645 277 235 194 0 31 0
[pid=5267] ppid=5264 vsize=18512 CPUtime=0.84
/proc/5267/stat : 5267 (apt-get) R 5264 5248 4159 34819 4229 4202496 4056 0 0 0 67 17 0 0 25 0 1 0 885410521 18956288 3945 1283457024 134512640 134649604 4294858800 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/5267/statm: 4628 3945 3381 34 0 565 0
Current children cumulated CPU time (s) 5.79
Current children cumulated vsize (KiB) 46056

[startup+7.40496 s]
/proc/loadavg: 0.98 0.99 0.99 2/44 5267
/proc/meminfo: memFree=748148/1048576 swapFree=2077620/2097144
[pid=5248] ppid=5247 vsize=1676 CPUtime=0
/proc/5248/stat : 5248 (sh) S 5247 5248 4159 34819 4229 4202496 223 176 0 0 0 0 0 0 25 0 1 0 885409897 1716224 129 1283457024 134512640 134594024 4289520896 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/5248/statm: 419 129 112 20 0 45 0
[pid=5250] ppid=5248 vsize=24176 CPUtime=5.97
/proc/5250/stat : 5250 (apt-pbo) S 5248 5248 4159 34819 4229 4202496 6229 26210 5 206 19 10 473 95 18 0 1 0 885409897 24756224 5257 1283457024 134512640 135744540 4288427616 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/5250/statm: 6044 5257 3685 301 0 1624 0
Current children cumulated CPU time (s) 5.97
Current children cumulated vsize (KiB) 25852

Child status: 0
Real time (s): 7.45945
CPU time (s): 5.98437
CPU user time (s): 4.92831
CPU system time (s): 1.05607
CPU usage (%): 80.2254
Max. virtual memory (cumulated for all children) (KiB): 65400

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.92831
system time used= 1.05607
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 33161
page faults= 212
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 28201
involuntary context switches= 28034

runsolver used 0 second user time and 0.008 second system time

The end