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/201103110955/apt-pbo-paranoid-1.0.8/4066.cudf.caixa.log.runsolver ./apt-pbo-paranoid-1.0.8 /home/misc2010/data/misc4/caixa//4066.cudf /home/misc2010/tmp/201103110955/apt-pbo-paranoid-1.0.8/4066.cudf.caixa.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.20 1.17 1.09 5/37 21409
/proc/meminfo: memFree=93268/1048576 swapFree=0/0
[pid=21407] ppid=21406 vsize=1672 CPUtime=0
/proc/21407/stat : 21407 (sh) S 21406 21407 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144472316 1712128 129 1283457024 134512640 134593992 4289844560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21407/statm: 418 129 112 20 0 45 0
[pid=21409] ppid=21407 vsize=3272 CPUtime=0
/proc/21409/stat : 21409 (apt-pbo) R 21407 21407 12462 34817 12462 4202496 312 0 0 0 0 0 0 0 25 0 1 0 144472316 3350528 260 1283457024 134512640 135745756 4289592384 18446744073709551615 4159431398 0 0 128 0 0 0 0 17 0 0 0 0
/proc/21409/statm: 818 260 208 302 0 86 0

[startup+0.141213 s]
/proc/loadavg: 1.20 1.17 1.09 5/37 21409
/proc/meminfo: memFree=93268/1048576 swapFree=0/0
[pid=21407] ppid=21406 vsize=1672 CPUtime=0
/proc/21407/stat : 21407 (sh) S 21406 21407 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144472316 1712128 129 1283457024 134512640 134593992 4289844560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21407/statm: 418 129 112 20 0 45 0
[pid=21409] ppid=21407 vsize=8228 CPUtime=0.05
/proc/21409/stat : 21409 (apt-pbo) S 21407 21407 12462 34817 12462 4202496 1575 408 0 0 4 0 0 1 25 0 1 0 144472316 8425472 1400 1283457024 134512640 135745756 4289592384 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21409/statm: 2057 1400 648 302 0 790 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9900

[startup+0.213267 s]
/proc/loadavg: 1.20 1.17 1.09 5/37 21409
/proc/meminfo: memFree=93268/1048576 swapFree=0/0
[pid=21407] ppid=21406 vsize=1672 CPUtime=0
/proc/21407/stat : 21407 (sh) S 21406 21407 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144472316 1712128 129 1283457024 134512640 134593992 4289844560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21407/statm: 418 129 112 20 0 45 0
[pid=21409] ppid=21407 vsize=8228 CPUtime=0.05
/proc/21409/stat : 21409 (apt-pbo) S 21407 21407 12462 34817 12462 4202496 1575 408 0 0 4 0 0 1 25 0 1 0 144472316 8425472 1400 1283457024 134512640 135745756 4289592384 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21409/statm: 2057 1400 648 302 0 790 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9900

[startup+0.313284 s]
/proc/loadavg: 1.20 1.17 1.09 5/37 21409
/proc/meminfo: memFree=93268/1048576 swapFree=0/0
[pid=21407] ppid=21406 vsize=1672 CPUtime=0
/proc/21407/stat : 21407 (sh) S 21406 21407 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144472316 1712128 129 1283457024 134512640 134593992 4289844560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21407/statm: 418 129 112 20 0 45 0
[pid=21409] ppid=21407 vsize=8228 CPUtime=0.05
/proc/21409/stat : 21409 (apt-pbo) S 21407 21407 12462 34817 12462 4202496 1575 408 0 0 4 0 0 1 25 0 1 0 144472316 8425472 1400 1283457024 134512640 135745756 4289592384 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21409/statm: 2057 1400 648 302 0 790 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9900

[startup+0.710927 s]
/proc/loadavg: 1.20 1.17 1.09 5/37 21409
/proc/meminfo: memFree=93268/1048576 swapFree=0/0
[pid=21407] ppid=21406 vsize=1672 CPUtime=0
/proc/21407/stat : 21407 (sh) S 21406 21407 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144472316 1712128 129 1283457024 134512640 134593992 4289844560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21407/statm: 418 129 112 20 0 45 0
[pid=21409] ppid=21407 vsize=8228 CPUtime=0.05
/proc/21409/stat : 21409 (apt-pbo) S 21407 21407 12462 34817 12462 4202496 1575 408 0 0 4 0 0 1 25 0 1 0 144472316 8425472 1400 1283457024 134512640 135745756 4289592384 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21409/statm: 2057 1400 648 302 0 790 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9900

[startup+1.51109 s]
/proc/loadavg: 1.20 1.17 1.09 2/39 21413
/proc/meminfo: memFree=55648/1048576 swapFree=0/0
[pid=21407] ppid=21406 vsize=1672 CPUtime=0
/proc/21407/stat : 21407 (sh) S 21406 21407 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144472316 1712128 129 1283457024 134512640 134593992 4289844560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21407/statm: 418 129 112 20 0 45 0
[pid=21409] ppid=21407 vsize=8228 CPUtime=0.05
/proc/21409/stat : 21409 (apt-pbo) S 21407 21407 12462 34817 12462 4202496 1575 408 0 0 4 0 0 1 25 0 1 0 144472316 8425472 1400 1283457024 134512640 135745756 4289592384 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21409/statm: 2057 1400 648 302 0 790 0
[pid=21413] ppid=21409 vsize=37252 CPUtime=1.41
/proc/21413/stat : 21413 (cudftodeb.nativ) R 21409 21407 12462 34817 12462 4202496 8857 0 0 0 136 5 0 0 25 0 1 0 144472321 38146048 8778 1283457024 134512640 135029684 4290461040 18446744073709551615 134969822 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/21413/statm: 9313 8778 246 127 0 8694 0
Current children cumulated CPU time (s) 1.46
Current children cumulated vsize (KiB) 47152

[startup+3.11154 s]
/proc/loadavg: 1.19 1.17 1.09 2/39 21413
/proc/meminfo: memFree=31612/1048576 swapFree=0/0
[pid=21407] ppid=21406 vsize=1672 CPUtime=0
/proc/21407/stat : 21407 (sh) S 21406 21407 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144472316 1712128 129 1283457024 134512640 134593992 4289844560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21407/statm: 418 129 112 20 0 45 0
[pid=21409] ppid=21407 vsize=8228 CPUtime=0.05
/proc/21409/stat : 21409 (apt-pbo) S 21407 21407 12462 34817 12462 4202496 1575 408 0 0 4 0 0 1 25 0 1 0 144472316 8425472 1400 1283457024 134512640 135745756 4289592384 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21409/statm: 2057 1400 648 302 0 790 0
[pid=21413] ppid=21409 vsize=59056 CPUtime=3.01
/proc/21413/stat : 21413 (cudftodeb.nativ) R 21409 21407 12462 34817 12462 4202496 14370 0 0 0 287 14 0 0 25 0 1 0 144472321 60473344 14291 1283457024 134512640 135029684 4290461040 18446744073709551615 4158289960 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/21413/statm: 14764 14291 258 127 0 14145 0
Current children cumulated CPU time (s) 3.06
Current children cumulated vsize (KiB) 68956

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

[startup+3.21157 s]
/proc/loadavg: 1.19 1.17 1.09 2/39 21413
/proc/meminfo: memFree=31612/1048576 swapFree=0/0
[pid=21407] ppid=21406 vsize=1672 CPUtime=0
/proc/21407/stat : 21407 (sh) S 21406 21407 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144472316 1712128 129 1283457024 134512640 134593992 4289844560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21407/statm: 418 129 112 20 0 45 0
[pid=21409] ppid=21407 vsize=8228 CPUtime=0.05
/proc/21409/stat : 21409 (apt-pbo) S 21407 21407 12462 34817 12462 4202496 1575 408 0 0 4 0 0 1 25 0 1 0 144472316 8425472 1400 1283457024 134512640 135745756 4289592384 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21409/statm: 2057 1400 648 302 0 790 0
[pid=21413] ppid=21409 vsize=60064 CPUtime=3.11
/proc/21413/stat : 21413 (cudftodeb.nativ) R 21409 21407 12462 34817 12462 4202496 14620 0 0 0 295 16 0 0 25 0 1 0 144472321 61505536 14541 1283457024 134512640 135029684 4290461040 18446744073709551615 4294960130 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/21413/statm: 15016 14541 258 127 0 14397 0
Current children cumulated CPU time (s) 3.16
Current children cumulated vsize (KiB) 69964

[startup+4.81209 s]
/proc/loadavg: 1.19 1.17 1.09 2/39 21413
/proc/meminfo: memFree=6272/1048576 swapFree=0/0
[pid=21407] ppid=21406 vsize=1672 CPUtime=0
/proc/21407/stat : 21407 (sh) S 21406 21407 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144472316 1712128 129 1283457024 134512640 134593992 4289844560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21407/statm: 418 129 112 20 0 45 0
[pid=21409] ppid=21407 vsize=8228 CPUtime=0.05
/proc/21409/stat : 21409 (apt-pbo) S 21407 21407 12462 34817 12462 4202496 1575 408 0 0 4 0 0 1 25 0 1 0 144472316 8425472 1400 1283457024 134512640 135745756 4289592384 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/21409/statm: 2057 1400 648 302 0 790 0
[pid=21413] ppid=21409 vsize=66616 CPUtime=4.71
/proc/21413/stat : 21413 (cudftodeb.nativ) R 21409 21407 12462 34817 12462 4202496 16249 0 0 0 422 49 0 0 25 0 1 0 144472321 68214784 16170 1283457024 134512640 135029684 4290461040 18446744073709551615 4158286685 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/21413/statm: 16654 16170 258 127 0 16035 0
Current children cumulated CPU time (s) 4.76
Current children cumulated vsize (KiB) 76516

[startup+5.21415 s]
/proc/loadavg: 1.19 1.17 1.09 2/39 21413
/proc/meminfo: memFree=6272/1048576 swapFree=0/0
[pid=21407] ppid=21406 vsize=1672 CPUtime=0
/proc/21407/stat : 21407 (sh) S 21406 21407 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144472316 1712128 129 1283457024 134512640 134593992 4289844560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21407/statm: 418 129 112 20 0 45 0
[pid=21409] ppid=21407 vsize=8228 CPUtime=4.87
/proc/21409/stat : 21409 (apt-pbo) S 21407 21407 12462 34817 12462 4202496 1749 16658 0 0 4 0 430 53 18 0 1 0 144472316 8425472 1426 1283457024 134512640 135745756 4289592384 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/21409/statm: 2057 1426 653 302 0 790 0
Current children cumulated CPU time (s) 4.87
Current children cumulated vsize (KiB) 9900

[startup+5.60555 s]
/proc/loadavg: 1.19 1.17 1.09 1/40 21421
/proc/meminfo: memFree=56120/1048576 swapFree=0/0
[pid=21407] ppid=21406 vsize=1672 CPUtime=0
/proc/21407/stat : 21407 (sh) S 21406 21407 12462 34817 12462 4202496 223 175 0 0 0 0 0 0 18 0 1 0 144472316 1712128 129 1283457024 134512640 134593992 4289844560 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/21407/statm: 418 129 112 20 0 45 0
[pid=21409] ppid=21407 vsize=8228 CPUtime=4.87
/proc/21409/stat : 21409 (apt-pbo) S 21407 21407 12462 34817 12462 4202496 1749 16658 0 0 4 0 430 53 18 0 1 0 144472316 8425472 1426 1283457024 134512640 135745756 4289592384 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/21409/statm: 2057 1426 653 302 0 790 0
[pid=21414] ppid=21409 vsize=2572 CPUtime=0.01
/proc/21414/stat : 21414 (apt-get.sh) S 21409 21407 12462 34817 12462 4202496 407 488 0 0 0 1 0 0 18 0 1 0 144472820 2633728 273 1283457024 134512640 135304128 4286931488 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21414/statm: 643 273 232 194 0 30 0
[pid=21417] ppid=21414 vsize=52744 CPUtime=0.24
/proc/21417/stat : 21417 (apt-get) D 21414 21407 12462 34817 12462 4202496 567 1745 1 0 0 0 20 4 24 0 1 0 144472820 54009856 437 1283457024 134512640 134650667 4292681680 18446744073709551615 4294960130 0 0 4096 134217728 18446744071696460772 0 0 17 0 0 0 0
/proc/21417/statm: 13186 437 388 34 0 69 0
Current children cumulated CPU time (s) 5.12
Current children cumulated vsize (KiB) 65216

Child status: 100
Real time (s): 5.64727
CPU time (s): 5.14832
CPU user time (s): 4.55228
CPU system time (s): 0.596037
CPU usage (%): 91.1647
Max. virtual memory (cumulated for all children) (KiB): 76516

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.55228
system time used= 0.596037
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 22378
page faults= 2
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 53
involuntary context switches= 204

runsolver used 0 second user time and 0 second system time

The end