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/rand6d933e.cudf.easy.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/2010/easy//rand6d933e.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/rand6d933e.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.91 0.99 0.99 1/44 27263
/proc/meminfo: memFree=801960/1048576 swapFree=2077036/2097144
[pid=27263] ppid=27262 vsize=3028 CPUtime=0
/proc/27263/stat : 27263 (runsolver) R 27262 27263 4159 34819 4229 4202560 73 0 0 0 0 0 0 0 25 0 1 0 883131558 3100672 94 1283457024 134512640 134586868 4292085408 18446744073709551615 4294960130 0 0 0 24578 0 0 0 17 0 0 0 0
/proc/27263/statm: 757 94 62 19 0 55 0

[startup+0.173865 s]
/proc/loadavg: 0.91 0.99 0.99 1/44 27263
/proc/meminfo: memFree=801960/1048576 swapFree=2077036/2097144
[pid=27263] ppid=27262 vsize=1680 CPUtime=0
/proc/27263/stat : 27263 (sh) S 27262 27263 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883131558 1720320 129 1283457024 134512640 134594024 4294101344 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/27263/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1680

[startup+0.204862 s]
/proc/loadavg: 0.91 0.99 0.99 1/44 27263
/proc/meminfo: memFree=801960/1048576 swapFree=2077036/2097144
[pid=27263] ppid=27262 vsize=1680 CPUtime=0
/proc/27263/stat : 27263 (sh) S 27262 27263 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883131558 1720320 129 1283457024 134512640 134594024 4294101344 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/27263/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1680

[startup+0.304873 s]
/proc/loadavg: 0.91 0.99 0.99 1/44 27263
/proc/meminfo: memFree=801960/1048576 swapFree=2077036/2097144
[pid=27263] ppid=27262 vsize=1680 CPUtime=0
/proc/27263/stat : 27263 (sh) S 27262 27263 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883131558 1720320 129 1283457024 134512640 134594024 4294101344 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/27263/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1680

[startup+0.704946 s]
/proc/loadavg: 0.91 0.99 0.99 1/44 27263
/proc/meminfo: memFree=801960/1048576 swapFree=2077036/2097144
[pid=27263] ppid=27262 vsize=1680 CPUtime=0
/proc/27263/stat : 27263 (sh) S 27262 27263 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883131558 1720320 129 1283457024 134512640 134594024 4294101344 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/27263/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1680

[startup+1.50512 s]
/proc/loadavg: 0.91 0.99 0.99 2/47 27269
/proc/meminfo: memFree=781284/1048576 swapFree=2077036/2097144
[pid=27263] ppid=27262 vsize=1680 CPUtime=0
/proc/27263/stat : 27263 (sh) S 27262 27263 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883131558 1720320 129 1283457024 134512640 134594024 4294101344 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/27263/statm: 420 129 112 20 0 46 0
[pid=27266] ppid=27263 vsize=8356 CPUtime=0.03
/proc/27266/stat : 27266 (apt-pbo) S 27263 27263 4159 34819 4229 4202496 1605 413 5 0 2 1 0 0 25 0 1 0 883131559 8556544 1422 1283457024 134512640 135744540 4288820896 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/27266/statm: 2089 1422 646 301 0 822 0
[pid=27269] ppid=27266 vsize=27148 CPUtime=1.12
/proc/27269/stat : 27269 (cudftodeb.nativ) R 27266 27263 4159 34819 4229 4202496 6362 0 9 0 110 2 0 0 25 0 1 0 883131591 27799552 6289 1283457024 134512640 135029684 4290309712 18446744073709551615 134984786 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27269/statm: 6787 6289 247 127 0 6170 0
Current children cumulated CPU time (s) 1.15
Current children cumulated vsize (KiB) 37184

[startup+3.10284 s]
/proc/loadavg: 0.92 0.99 0.99 2/47 27269
/proc/meminfo: memFree=756732/1048576 swapFree=2077036/2097144
[pid=27263] ppid=27262 vsize=1680 CPUtime=0
/proc/27263/stat : 27263 (sh) S 27262 27263 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883131558 1720320 129 1283457024 134512640 134594024 4294101344 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/27263/statm: 420 129 112 20 0 46 0
[pid=27266] ppid=27263 vsize=8356 CPUtime=0.03
/proc/27266/stat : 27266 (apt-pbo) S 27263 27263 4159 34819 4229 4202496 1605 413 5 0 2 1 0 0 25 0 1 0 883131559 8556544 1422 1283457024 134512640 135744540 4288820896 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/27266/statm: 2089 1422 646 301 0 822 0
[pid=27269] ppid=27266 vsize=53860 CPUtime=2.65
/proc/27269/stat : 27269 (cudftodeb.nativ) R 27266 27263 4159 34819 4229 4202496 13024 0 9 0 229 36 0 0 25 0 1 0 883131591 55152640 12951 1283457024 134512640 135029684 4290309712 18446744073709551615 4294960130 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27269/statm: 13465 12951 258 127 0 12848 0
Current children cumulated CPU time (s) 2.68
Current children cumulated vsize (KiB) 63896

[startup+6.30525 s]
/proc/loadavg: 0.92 0.99 0.99 1/48 27277
/proc/meminfo: memFree=756380/1048576 swapFree=2077036/2097144
[pid=27263] ppid=27262 vsize=1680 CPUtime=0
/proc/27263/stat : 27263 (sh) S 27262 27263 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883131558 1720320 129 1283457024 134512640 134594024 4294101344 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/27263/statm: 420 129 112 20 0 46 0
[pid=27266] ppid=27263 vsize=22768 CPUtime=4.77
/proc/27266/stat : 27266 (apt-pbo) S 27263 27263 4159 34819 4229 4202496 5410 20058 5 195 13 1 381 82 18 0 1 0 883131559 23314432 4905 1283457024 134512640 135744540 4288820896 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/27266/statm: 5692 4905 3681 301 0 1272 0
Current children cumulated CPU time (s) 4.77
Current children cumulated vsize (KiB) 24448
heavy processes:

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

[startup+6.41129 s]
/proc/loadavg: 0.92 0.99 0.99 1/47 27278
/proc/meminfo: memFree=753648/1048576 swapFree=2077036/2097144
[pid=27263] ppid=27262 vsize=1680 CPUtime=0
/proc/27263/stat : 27263 (sh) S 27262 27263 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883131558 1720320 129 1283457024 134512640 134594024 4294101344 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/27263/statm: 420 129 112 20 0 46 0
[pid=27266] ppid=27263 vsize=23160 CPUtime=4.81
/proc/27266/stat : 27266 (apt-pbo) R 27263 27263 4159 34819 4229 4202496 5777 21167 5 207 15 2 382 82 18 0 1 0 883131559 23715840 5025 1283457024 134512640 135744540 4288820896 18446744073709551615 135179230 0 0 128 0 0 0 0 17 0 0 0 0
/proc/27266/statm: 5790 5025 3681 301 0 1370 0
Current children cumulated CPU time (s) 4.81
Current children cumulated vsize (KiB) 24840

[startup+7.11056 s]
/proc/loadavg: 0.93 0.99 0.99 3/48 27282
/proc/meminfo: memFree=750356/1048576 swapFree=2077036/2097144
[pid=27263] ppid=27262 vsize=1680 CPUtime=0
/proc/27263/stat : 27263 (sh) S 27262 27263 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883131558 1720320 129 1283457024 134512640 134594024 4294101344 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/27263/statm: 420 129 112 20 0 46 0
[pid=27266] ppid=27263 vsize=23292 CPUtime=4.93
/proc/27266/stat : 27266 (apt-pbo) S 27263 27263 4159 34819 4229 4202496 5889 21167 5 207 22 7 382 82 18 0 1 0 883131559 23851008 5032 1283457024 134512640 135744540 4288820896 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/27266/statm: 5823 5032 3682 301 0 1403 0
[pid=27279] ppid=27266 vsize=2580 CPUtime=0
/proc/27279/stat : 27279 (apt-get.sh) S 27266 27263 4159 34819 4229 4202496 488 489 0 0 0 0 0 0 18 0 1 0 883132200 2641920 277 1283457024 134512640 135304128 4288957040 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27279/statm: 645 277 235 194 0 31 0
[pid=27282] ppid=27279 vsize=18508 CPUtime=0.6
/proc/27282/stat : 27282 (apt-get) R 27279 27263 4159 34819 4229 4202496 4045 0 0 0 52 8 0 0 25 0 1 0 883132200 18952192 3934 1283457024 134512640 134649604 4294397904 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/27282/statm: 4627 3934 3381 34 0 564 0
Current children cumulated CPU time (s) 5.53
Current children cumulated vsize (KiB) 46060

[startup+7.51067 s]
/proc/loadavg: 0.93 0.99 0.99 3/48 27282
/proc/meminfo: memFree=750356/1048576 swapFree=2077036/2097144
[pid=27263] ppid=27262 vsize=1680 CPUtime=0
/proc/27263/stat : 27263 (sh) S 27262 27263 4159 34819 4229 4202496 222 175 0 0 0 0 0 0 25 0 1 0 883131558 1720320 129 1283457024 134512640 134594024 4294101344 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/27263/statm: 420 129 112 20 0 46 0
[pid=27266] ppid=27263 vsize=23292 CPUtime=4.96
/proc/27266/stat : 27266 (apt-pbo) S 27263 27263 4159 34819 4229 4202496 5889 21167 5 207 23 9 382 82 18 0 1 0 883131559 23851008 5032 1283457024 134512640 135744540 4288820896 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/27266/statm: 5823 5032 3682 301 0 1403 0
[pid=27279] ppid=27266 vsize=2580 CPUtime=0
/proc/27279/stat : 27279 (apt-get.sh) S 27266 27263 4159 34819 4229 4202496 488 489 0 0 0 0 0 0 18 0 1 0 883132200 2641920 277 1283457024 134512640 135304128 4288957040 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27279/statm: 645 277 235 194 0 31 0
[pid=27282] ppid=27279 vsize=18508 CPUtime=0.96
/proc/27282/stat : 27282 (apt-get) R 27279 27263 4159 34819 4229 4202496 4059 0 0 0 82 14 0 0 25 0 1 0 883132200 18952192 3948 1283457024 134512640 134649604 4294397904 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/27282/statm: 4627 3948 3382 34 0 564 0
Current children cumulated CPU time (s) 5.92
Current children cumulated vsize (KiB) 46060

Child status: 0
Real time (s): 7.58302
CPU time (s): 5.96037
CPU user time (s): 4.88831
CPU system time (s): 1.07207
CPU usage (%): 78.6016
Max. virtual memory (cumulated for all children) (KiB): 65408

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.8883
system time used= 1.07207
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= 213
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 27857
involuntary context switches= 27657

runsolver used 0 second user time and 0.008 second system time

The end