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/1.cudf.caixa.log.runsolver ./apt-pbo-paranoid-1.0.8 /home/misc2010/data/misc4/caixa//1.cudf /home/misc2010/tmp/201103110955/apt-pbo-paranoid-1.0.8/1.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: 0.00 0.00 0.00 2/37 12475
/proc/meminfo: memFree=9056/1048576 swapFree=0/0
[pid=12475] ppid=12474 vsize=3020 CPUtime=0
/proc/12475/stat : 12475 (runsolver) R 12474 12475 12462 34817 12462 4202560 72 0 0 0 0 0 0 0 25 0 1 0 143643213 3092480 93 1283457024 134512640 134586868 4291931792 18446744073709551615 4294960130 0 0 0 24578 0 0 0 17 0 0 0 0
/proc/12475/statm: 755 93 62 19 0 54 0

[startup+0.124588 s]
/proc/loadavg: 0.00 0.00 0.00 2/37 12475
/proc/meminfo: memFree=9056/1048576 swapFree=0/0
[pid=12475] ppid=12474 vsize=1668 CPUtime=0
/proc/12475/stat : 12475 (sh) S 12474 12475 12462 34817 12462 4202496 220 174 0 0 0 0 0 0 25 0 1 0 143643213 1708032 128 1283457024 134512640 134593992 4292710416 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12475/statm: 417 128 112 20 0 44 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1668

[startup+0.204582 s]
/proc/loadavg: 0.00 0.00 0.00 2/37 12475
/proc/meminfo: memFree=9056/1048576 swapFree=0/0
[pid=12475] ppid=12474 vsize=1668 CPUtime=0
/proc/12475/stat : 12475 (sh) S 12474 12475 12462 34817 12462 4202496 220 174 0 0 0 0 0 0 25 0 1 0 143643213 1708032 128 1283457024 134512640 134593992 4292710416 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12475/statm: 417 128 112 20 0 44 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1668

[startup+0.304568 s]
/proc/loadavg: 0.00 0.00 0.00 2/37 12475
/proc/meminfo: memFree=9056/1048576 swapFree=0/0
[pid=12475] ppid=12474 vsize=1668 CPUtime=0
/proc/12475/stat : 12475 (sh) S 12474 12475 12462 34817 12462 4202496 220 174 0 0 0 0 0 0 25 0 1 0 143643213 1708032 128 1283457024 134512640 134593992 4292710416 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12475/statm: 417 128 112 20 0 44 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1668

[startup+0.710482 s]
/proc/loadavg: 0.00 0.00 0.00 2/37 12475
/proc/meminfo: memFree=9056/1048576 swapFree=0/0
[pid=12475] ppid=12474 vsize=1668 CPUtime=0
/proc/12475/stat : 12475 (sh) S 12474 12475 12462 34817 12462 4202496 220 174 0 0 0 0 0 0 25 0 1 0 143643213 1708032 128 1283457024 134512640 134593992 4292710416 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12475/statm: 417 128 112 20 0 44 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1668

[startup+1.51079 s]
/proc/loadavg: 0.00 0.00 0.00 2/40 12481
/proc/meminfo: memFree=6080/1048576 swapFree=0/0
[pid=12475] ppid=12474 vsize=1668 CPUtime=0
/proc/12475/stat : 12475 (sh) S 12474 12475 12462 34817 12462 4202496 220 174 0 0 0 0 0 0 25 0 1 0 143643213 1708032 128 1283457024 134512640 134593992 4292710416 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12475/statm: 417 128 112 20 0 44 0
[pid=12478] ppid=12475 vsize=8228 CPUtime=0.02
/proc/12478/stat : 12478 (apt-pbo) S 12475 12475 12462 34817 12462 4202496 1546 409 29 0 2 0 0 0 24 0 1 0 143643213 8425472 1400 1283457024 134512640 135745756 4290927488 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/12478/statm: 2057 1400 648 302 0 790 0
[pid=12481] ppid=12478 vsize=28700 CPUtime=0.98
/proc/12481/stat : 12481 (cudftodeb.nativ) R 12478 12475 12462 34817 12462 4202496 6842 0 9 0 95 3 0 0 25 0 1 0 143643258 29388800 6772 1283457024 134512640 135029684 4290172592 18446744073709551615 134973030 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/12481/statm: 7175 6772 246 127 0 6556 0
Current children cumulated CPU time (s) 1
Current children cumulated vsize (KiB) 38596

[startup+3.11123 s]
/proc/loadavg: 0.00 0.00 0.00 3/40 12481
/proc/meminfo: memFree=5716/1048576 swapFree=0/0
[pid=12475] ppid=12474 vsize=1668 CPUtime=0
/proc/12475/stat : 12475 (sh) S 12474 12475 12462 34817 12462 4202496 220 174 0 0 0 0 0 0 25 0 1 0 143643213 1708032 128 1283457024 134512640 134593992 4292710416 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12475/statm: 417 128 112 20 0 44 0
[pid=12478] ppid=12475 vsize=8228 CPUtime=0.02
/proc/12478/stat : 12478 (apt-pbo) S 12475 12475 12462 34817 12462 4202496 1546 409 29 0 2 0 0 0 24 0 1 0 143643213 8425472 1400 1283457024 134512640 135745756 4290927488 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/12478/statm: 2057 1400 648 302 0 790 0
[pid=12481] ppid=12478 vsize=56924 CPUtime=2.57
/proc/12481/stat : 12481 (cudftodeb.nativ) R 12478 12475 12462 34817 12462 4202496 13743 0 9 0 247 10 0 0 25 0 1 0 143643258 58290176 13673 1283457024 134512640 135029684 4290172592 18446744073709551615 134974948 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/12481/statm: 14231 13673 258 127 0 13612 0
Current children cumulated CPU time (s) 2.59
Current children cumulated vsize (KiB) 66820

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

[startup+3.21126 s]
/proc/loadavg: 0.00 0.00 0.00 3/40 12481
/proc/meminfo: memFree=5716/1048576 swapFree=0/0
[pid=12475] ppid=12474 vsize=1668 CPUtime=0
/proc/12475/stat : 12475 (sh) S 12474 12475 12462 34817 12462 4202496 220 174 0 0 0 0 0 0 25 0 1 0 143643213 1708032 128 1283457024 134512640 134593992 4292710416 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12475/statm: 417 128 112 20 0 44 0
[pid=12478] ppid=12475 vsize=8228 CPUtime=0.02
/proc/12478/stat : 12478 (apt-pbo) S 12475 12475 12462 34817 12462 4202496 1546 409 29 0 2 0 0 0 24 0 1 0 143643213 8425472 1400 1283457024 134512640 135745756 4290927488 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/12478/statm: 2057 1400 648 302 0 790 0
[pid=12481] ppid=12478 vsize=57932 CPUtime=2.67
/proc/12481/stat : 12481 (cudftodeb.nativ) R 12478 12475 12462 34817 12462 4202496 14012 0 9 0 255 12 0 0 25 0 1 0 143643258 59322368 13942 1283457024 134512640 135029684 4290172592 18446744073709551615 134973030 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/12481/statm: 14483 13942 258 127 0 13864 0
Current children cumulated CPU time (s) 2.69
Current children cumulated vsize (KiB) 67828

[startup+4.80487 s]
/proc/loadavg: 0.08 0.02 0.01 2/40 12481
/proc/meminfo: memFree=21676/1048576 swapFree=0/0
[pid=12475] ppid=12474 vsize=1668 CPUtime=0
/proc/12475/stat : 12475 (sh) S 12474 12475 12462 34817 12462 4202496 220 174 0 0 0 0 0 0 25 0 1 0 143643213 1708032 128 1283457024 134512640 134593992 4292710416 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12475/statm: 417 128 112 20 0 44 0
[pid=12478] ppid=12475 vsize=8228 CPUtime=0.02
/proc/12478/stat : 12478 (apt-pbo) S 12475 12475 12462 34817 12462 4202496 1546 409 29 0 2 0 0 0 24 0 1 0 143643213 8425472 1400 1283457024 134512640 135745756 4290927488 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/12478/statm: 2057 1400 648 302 0 790 0
[pid=12481] ppid=12478 vsize=52388 CPUtime=4.13
/proc/12481/stat : 12481 (cudftodeb.nativ) D 12478 12475 12462 34817 12462 4202496 16868 0 9 0 369 44 0 0 25 0 1 0 143643258 53645312 12669 1283457024 134512640 135029684 4290172592 18446744073709551615 4294960130 0 0 0 1024 18446744071564332537 0 0 17 0 0 0 0
/proc/12481/statm: 13097 12669 258 127 0 12478 0
Current children cumulated CPU time (s) 4.15
Current children cumulated vsize (KiB) 62284

[startup+5.60494 s]
/proc/loadavg: 0.08 0.02 0.01 2/40 12481
/proc/meminfo: memFree=15104/1048576 swapFree=0/0
[pid=12475] ppid=12474 vsize=1668 CPUtime=0
/proc/12475/stat : 12475 (sh) S 12474 12475 12462 34817 12462 4202496 220 174 0 0 0 0 0 0 25 0 1 0 143643213 1708032 128 1283457024 134512640 134593992 4292710416 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12475/statm: 417 128 112 20 0 44 0
[pid=12478] ppid=12475 vsize=8228 CPUtime=4.56
/proc/12478/stat : 12478 (apt-pbo) S 12475 12475 12462 34817 12462 4202496 1720 17778 29 9 2 0 402 52 18 0 1 0 143643213 8425472 1426 1283457024 134512640 135745756 4290927488 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/12478/statm: 2057 1426 653 302 0 790 0
Current children cumulated CPU time (s) 4.56
Current children cumulated vsize (KiB) 9896

[startup+6.00495 s]
/proc/loadavg: 0.08 0.02 0.01 2/40 12481
/proc/meminfo: memFree=15104/1048576 swapFree=0/0
[pid=12475] ppid=12474 vsize=1668 CPUtime=0
/proc/12475/stat : 12475 (sh) S 12474 12475 12462 34817 12462 4202496 220 174 0 0 0 0 0 0 25 0 1 0 143643213 1708032 128 1283457024 134512640 134593992 4292710416 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12475/statm: 417 128 112 20 0 44 0
[pid=12478] ppid=12475 vsize=8228 CPUtime=4.56
/proc/12478/stat : 12478 (apt-pbo) S 12475 12475 12462 34817 12462 4202496 1720 17778 29 9 2 0 402 52 18 0 1 0 143643213 8425472 1426 1283457024 134512640 135745756 4290927488 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/12478/statm: 2057 1426 653 302 0 790 0
Current children cumulated CPU time (s) 4.56
Current children cumulated vsize (KiB) 9896

[startup+6.20495 s]
/proc/loadavg: 0.08 0.02 0.01 2/40 12481
/proc/meminfo: memFree=15104/1048576 swapFree=0/0
[pid=12475] ppid=12474 vsize=1668 CPUtime=0
/proc/12475/stat : 12475 (sh) S 12474 12475 12462 34817 12462 4202496 220 174 0 0 0 0 0 0 25 0 1 0 143643213 1708032 128 1283457024 134512640 134593992 4292710416 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/12475/statm: 417 128 112 20 0 44 0
[pid=12478] ppid=12475 vsize=8356 CPUtime=4.77
/proc/12478/stat : 12478 (apt-pbo) R 12475 12475 12462 34817 12462 4202496 2018 21012 30 13 2 0 421 54 16 0 1 0 143643213 8556544 1469 1283457024 134512640 135745756 4290927488 18446744073709551615 135125170 0 0 128 0 0 0 0 17 0 0 0 0
/proc/12478/statm: 2089 1469 684 302 0 822 0
Current children cumulated CPU time (s) 4.77
Current children cumulated vsize (KiB) 10024

Child status: 100
Real time (s): 6.20639
CPU time (s): 4.7923
CPU user time (s): 4.23226
CPU system time (s): 0.560035
CPU usage (%): 77.2156
Max. virtual memory (cumulated for all children) (KiB): 78916

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.23226
system time used= 0.560035
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 23457
page faults= 43
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 230
involuntary context switches= 259

runsolver used 0 second user time and 0 second system time

The end