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/556.cudf.caixa.log.runsolver ./apt-pbo-paranoid-1.0.8 /home/misc2010/data/misc4/caixa//556.cudf /home/misc2010/tmp/201103110955/apt-pbo-paranoid-1.0.8/556.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.16 1.10 3/39 22871
/proc/meminfo: memFree=79428/1048576 swapFree=0/0
[pid=22870] ppid=22869 vsize=1676 CPUtime=0
/proc/22870/stat : 22870 (sh) R 22869 22870 12462 34817 12462 4202496 206 0 0 0 0 0 0 0 25 0 1 0 144497579 1716224 127 1283457024 134512640 134593992 4289479936 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/22870/statm: 419 127 110 20 0 46 0
[pid=22871] ppid=22870 vsize=1676 CPUtime=0
/proc/22871/stat : 22871 (sh) R 22870 22870 12462 34817 12462 4202560 0 0 0 0 0 0 0 0 25 0 1 0 144497579 1716224 17 1283457024 134512640 134593992 4289479936 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/22871/statm: 419 17 0 20 0 46 0

[startup+0.141453 s]
/proc/loadavg: 1.20 1.16 1.10 3/39 22871
/proc/meminfo: memFree=79428/1048576 swapFree=0/0
[pid=22870] ppid=22869 vsize=1676 CPUtime=0.01
/proc/22870/stat : 22870 (sh) S 22869 22870 12462 34817 12462 4202496 222 175 0 0 0 0 1 0 25 0 1 0 144497579 1716224 129 1283457024 134512640 134593992 4289479936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22870/statm: 419 129 112 20 0 46 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 1676

[startup+0.205475 s]
/proc/loadavg: 1.20 1.16 1.10 3/39 22871
/proc/meminfo: memFree=79428/1048576 swapFree=0/0
[pid=22870] ppid=22869 vsize=1676 CPUtime=0.01
/proc/22870/stat : 22870 (sh) S 22869 22870 12462 34817 12462 4202496 222 175 0 0 0 0 1 0 25 0 1 0 144497579 1716224 129 1283457024 134512640 134593992 4289479936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22870/statm: 419 129 112 20 0 46 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 1676

[startup+0.305537 s]
/proc/loadavg: 1.20 1.16 1.10 3/39 22871
/proc/meminfo: memFree=79428/1048576 swapFree=0/0
[pid=22870] ppid=22869 vsize=1676 CPUtime=0.01
/proc/22870/stat : 22870 (sh) S 22869 22870 12462 34817 12462 4202496 222 175 0 0 0 0 1 0 25 0 1 0 144497579 1716224 129 1283457024 134512640 134593992 4289479936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22870/statm: 419 129 112 20 0 46 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 1676

[startup+0.706764 s]
/proc/loadavg: 1.20 1.16 1.10 3/39 22871
/proc/meminfo: memFree=79428/1048576 swapFree=0/0
[pid=22870] ppid=22869 vsize=1676 CPUtime=0.01
/proc/22870/stat : 22870 (sh) S 22869 22870 12462 34817 12462 4202496 222 175 0 0 0 0 1 0 25 0 1 0 144497579 1716224 129 1283457024 134512640 134593992 4289479936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22870/statm: 419 129 112 20 0 46 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 1676

[startup+1.50696 s]
/proc/loadavg: 1.20 1.16 1.10 2/41 22876
/proc/meminfo: memFree=42604/1048576 swapFree=0/0
[pid=22870] ppid=22869 vsize=1676 CPUtime=0.01
/proc/22870/stat : 22870 (sh) S 22869 22870 12462 34817 12462 4202496 222 175 0 0 0 0 1 0 25 0 1 0 144497579 1716224 129 1283457024 134512640 134593992 4289479936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22870/statm: 419 129 112 20 0 46 0
[pid=22873] ppid=22870 vsize=8232 CPUtime=0.04
/proc/22873/stat : 22873 (apt-pbo) S 22870 22870 12462 34817 12462 4202496 1581 411 0 0 4 0 0 0 25 0 1 0 144497579 8429568 1401 1283457024 134512640 135745756 4289733744 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22873/statm: 2058 1401 648 302 0 791 0
[pid=22876] ppid=22873 vsize=36744 CPUtime=1.39
/proc/22876/stat : 22876 (cudftodeb.nativ) R 22873 22870 12462 34817 12462 4202496 8858 0 0 0 137 2 0 0 25 0 1 0 144497584 37625856 8778 1283457024 134512640 135029684 4288099120 18446744073709551615 135011886 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/22876/statm: 9186 8778 246 127 0 8567 0
Current children cumulated CPU time (s) 1.44
Current children cumulated vsize (KiB) 46652

[startup+3.10729 s]
/proc/loadavg: 1.20 1.16 1.10 2/41 22876
/proc/meminfo: memFree=20104/1048576 swapFree=0/0
[pid=22870] ppid=22869 vsize=1676 CPUtime=0.01
/proc/22870/stat : 22870 (sh) S 22869 22870 12462 34817 12462 4202496 222 175 0 0 0 0 1 0 25 0 1 0 144497579 1716224 129 1283457024 134512640 134593992 4289479936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22870/statm: 419 129 112 20 0 46 0
[pid=22873] ppid=22870 vsize=8232 CPUtime=0.04
/proc/22873/stat : 22873 (apt-pbo) S 22870 22870 12462 34817 12462 4202496 1581 411 0 0 4 0 0 0 25 0 1 0 144497579 8429568 1401 1283457024 134512640 135745756 4289733744 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22873/statm: 2058 1401 648 302 0 791 0
[pid=22876] ppid=22873 vsize=64596 CPUtime=2.99
/proc/22876/stat : 22876 (cudftodeb.nativ) R 22873 22870 12462 34817 12462 4202496 15655 0 0 0 280 19 0 0 25 0 1 0 144497584 66146304 15575 1283457024 134512640 135029684 4288099120 18446744073709551615 134974488 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/22876/statm: 16149 15575 258 127 0 15530 0
Current children cumulated CPU time (s) 3.04
Current children cumulated vsize (KiB) 74504

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

[startup+3.2073 s]
/proc/loadavg: 1.20 1.16 1.10 2/41 22876
/proc/meminfo: memFree=20104/1048576 swapFree=0/0
[pid=22870] ppid=22869 vsize=1676 CPUtime=0.01
/proc/22870/stat : 22870 (sh) S 22869 22870 12462 34817 12462 4202496 222 175 0 0 0 0 1 0 25 0 1 0 144497579 1716224 129 1283457024 134512640 134593992 4289479936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22870/statm: 419 129 112 20 0 46 0
[pid=22873] ppid=22870 vsize=8232 CPUtime=0.04
/proc/22873/stat : 22873 (apt-pbo) S 22870 22870 12462 34817 12462 4202496 1581 411 0 0 4 0 0 0 25 0 1 0 144497579 8429568 1401 1283457024 134512640 135745756 4289733744 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22873/statm: 2058 1401 648 302 0 791 0
[pid=22876] ppid=22873 vsize=65604 CPUtime=3.1
/proc/22876/stat : 22876 (cudftodeb.nativ) R 22873 22870 12462 34817 12462 4202496 16013 0 0 0 288 22 0 0 25 0 1 0 144497584 67178496 15933 1283457024 134512640 135029684 4288099120 18446744073709551615 134869520 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/22876/statm: 16401 15933 258 127 0 15782 0
Current children cumulated CPU time (s) 3.15
Current children cumulated vsize (KiB) 75512

[startup+4.80577 s]
/proc/loadavg: 1.20 1.16 1.10 2/41 22877
/proc/meminfo: memFree=5296/1048576 swapFree=0/0
[pid=22870] ppid=22869 vsize=1676 CPUtime=0.01
/proc/22870/stat : 22870 (sh) S 22869 22870 12462 34817 12462 4202496 222 175 0 0 0 0 1 0 25 0 1 0 144497579 1716224 129 1283457024 134512640 134593992 4289479936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22870/statm: 419 129 112 20 0 46 0
[pid=22873] ppid=22870 vsize=8232 CPUtime=4.4
/proc/22873/stat : 22873 (apt-pbo) S 22870 22870 12462 34817 12462 4202496 1754 16550 0 0 4 0 382 54 18 0 1 0 144497579 8429568 1427 1283457024 134512640 135745756 4289733744 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/22873/statm: 2058 1427 653 302 0 791 0
Current children cumulated CPU time (s) 4.41
Current children cumulated vsize (KiB) 9908

[startup+5.20578 s]
/proc/loadavg: 1.20 1.16 1.10 2/41 22877
/proc/meminfo: memFree=5296/1048576 swapFree=0/0
[pid=22870] ppid=22869 vsize=1676 CPUtime=0.01
/proc/22870/stat : 22870 (sh) S 22869 22870 12462 34817 12462 4202496 222 175 0 0 0 0 1 0 25 0 1 0 144497579 1716224 129 1283457024 134512640 134593992 4289479936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22870/statm: 419 129 112 20 0 46 0
[pid=22873] ppid=22870 vsize=8232 CPUtime=4.4
/proc/22873/stat : 22873 (apt-pbo) S 22870 22870 12462 34817 12462 4202496 1754 16550 0 0 4 0 382 54 18 0 1 0 144497579 8429568 1427 1283457024 134512640 135745756 4289733744 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/22873/statm: 2058 1427 653 302 0 791 0
Current children cumulated CPU time (s) 4.41
Current children cumulated vsize (KiB) 9908

[startup+5.40577 s]
/proc/loadavg: 1.20 1.16 1.10 2/41 22877
/proc/meminfo: memFree=5296/1048576 swapFree=0/0
[pid=22870] ppid=22869 vsize=1676 CPUtime=0.01
/proc/22870/stat : 22870 (sh) S 22869 22870 12462 34817 12462 4202496 222 175 0 0 0 0 1 0 25 0 1 0 144497579 1716224 129 1283457024 134512640 134593992 4289479936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22870/statm: 419 129 112 20 0 46 0
[pid=22873] ppid=22870 vsize=8232 CPUtime=4.4
/proc/22873/stat : 22873 (apt-pbo) S 22870 22870 12462 34817 12462 4202496 1754 16550 0 0 4 0 382 54 18 0 1 0 144497579 8429568 1427 1283457024 134512640 135745756 4289733744 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/22873/statm: 2058 1427 653 302 0 791 0
Current children cumulated CPU time (s) 4.41
Current children cumulated vsize (KiB) 9908

[startup+5.5058 s]
/proc/loadavg: 1.26 1.18 1.10 1/40 22885
/proc/meminfo: memFree=57288/1048576 swapFree=0/0
[pid=22870] ppid=22869 vsize=1676 CPUtime=0.01
/proc/22870/stat : 22870 (sh) S 22869 22870 12462 34817 12462 4202496 222 175 0 0 0 0 1 0 25 0 1 0 144497579 1716224 129 1283457024 134512640 134593992 4289479936 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22870/statm: 419 129 112 20 0 46 0
[pid=22873] ppid=22870 vsize=57192 CPUtime=4.63
/proc/22873/stat : 22873 (apt-pbo) D 22870 22870 12462 34817 12462 4202496 1885 19796 1 1 4 0 400 59 18 0 1 0 144497579 58564608 1457 1283457024 134512640 135745756 4289733744 18446744073709551615 4294960130 0 0 128 0 18446744071696460772 0 0 17 0 0 0 0
/proc/22873/statm: 14298 1457 680 302 0 823 0
Current children cumulated CPU time (s) 4.64
Current children cumulated vsize (KiB) 58868

Child status: 100
Real time (s): 5.52213
CPU time (s): 4.66029
CPU user time (s): 4.06425
CPU system time (s): 0.596037
CPU usage (%): 84.393
Max. virtual memory (cumulated for all children) (KiB): 76016

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.06425
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= 22277
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= 55
involuntary context switches= 167

runsolver used 0 second user time and 0 second system time

The end