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/201103031013/apt-pbo-trendy-1.0.8/643.cudf.caixa.log.runsolver ./apt-pbo-trendy-1.0.8 /home/misc2010/data/misc4/caixa//643.cudf /home/misc2010/tmp/201103031013/apt-pbo-trendy-1.0.8/643.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: 2.12 1.89 1.74 4/34 24624
/proc/meminfo: memFree=309080/1048576 swapFree=0/0
[pid=24622] ppid=24621 vsize=1672 CPUtime=0
/proc/24622/stat : 24622 (sh) S 24621 24622 29493 34817 29493 4202496 223 174 0 0 0 0 0 0 24 0 1 0 76317610 1712128 129 1283457024 134512640 134593992 4286927504 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24622/statm: 418 129 112 20 0 45 0
[pid=24624] ppid=24622 vsize=4896 CPUtime=0.02
/proc/24624/stat : 24624 (apt-pbo) R 24622 24622 29493 34817 29493 4202496 911 0 0 0 2 0 0 0 25 0 1 0 76317610 5013504 850 1283457024 134512640 135745756 4287072736 18446744073709551615 134867674 0 0 128 0 0 0 0 17 0 0 0 0
/proc/24624/statm: 1224 850 409 302 0 488 0

[startup+0.137152 s]
/proc/loadavg: 2.12 1.89 1.74 4/34 24624
/proc/meminfo: memFree=309080/1048576 swapFree=0/0
[pid=24622] ppid=24621 vsize=1672 CPUtime=0
/proc/24622/stat : 24622 (sh) S 24621 24622 29493 34817 29493 4202496 223 174 0 0 0 0 0 0 24 0 1 0 76317610 1712128 129 1283457024 134512640 134593992 4286927504 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24622/statm: 418 129 112 20 0 45 0
[pid=24624] ppid=24622 vsize=8236 CPUtime=0.04
/proc/24624/stat : 24624 (apt-pbo) R 24622 24622 29493 34817 29493 4202496 1561 409 0 0 4 0 0 0 25 0 1 0 76317610 8433664 1401 1283457024 134512640 135745756 4287072736 18446744073709551615 4294960130 0 0 128 0 0 0 0 17 0 0 0 0
/proc/24624/statm: 2059 1401 648 302 0 792 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9908

[startup+0.207179 s]
/proc/loadavg: 2.12 1.89 1.74 4/34 24624
/proc/meminfo: memFree=309080/1048576 swapFree=0/0
[pid=24622] ppid=24621 vsize=1672 CPUtime=0
/proc/24622/stat : 24622 (sh) S 24621 24622 29493 34817 29493 4202496 223 174 0 0 0 0 0 0 24 0 1 0 76317610 1712128 129 1283457024 134512640 134593992 4286927504 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24622/statm: 418 129 112 20 0 45 0
[pid=24624] ppid=24622 vsize=8236 CPUtime=0.04
/proc/24624/stat : 24624 (apt-pbo) S 24622 24622 29493 34817 29493 4202496 1580 409 0 0 4 0 0 0 25 0 1 0 76317610 8433664 1401 1283457024 134512640 135745756 4287072736 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/24624/statm: 2059 1401 648 302 0 792 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9908

[startup+0.307212 s]
/proc/loadavg: 2.12 1.89 1.74 4/34 24624
/proc/meminfo: memFree=309080/1048576 swapFree=0/0
[pid=24622] ppid=24621 vsize=1672 CPUtime=0
/proc/24622/stat : 24622 (sh) S 24621 24622 29493 34817 29493 4202496 223 174 0 0 0 0 0 0 24 0 1 0 76317610 1712128 129 1283457024 134512640 134593992 4286927504 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24622/statm: 418 129 112 20 0 45 0
[pid=24624] ppid=24622 vsize=8236 CPUtime=0.04
/proc/24624/stat : 24624 (apt-pbo) S 24622 24622 29493 34817 29493 4202496 1580 409 0 0 4 0 0 0 25 0 1 0 76317610 8433664 1401 1283457024 134512640 135745756 4287072736 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/24624/statm: 2059 1401 648 302 0 792 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9908

[startup+0.707342 s]
/proc/loadavg: 2.12 1.89 1.74 4/34 24624
/proc/meminfo: memFree=309080/1048576 swapFree=0/0
[pid=24622] ppid=24621 vsize=1672 CPUtime=0
/proc/24622/stat : 24622 (sh) S 24621 24622 29493 34817 29493 4202496 223 174 0 0 0 0 0 0 24 0 1 0 76317610 1712128 129 1283457024 134512640 134593992 4286927504 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24622/statm: 418 129 112 20 0 45 0
[pid=24624] ppid=24622 vsize=8236 CPUtime=0.04
/proc/24624/stat : 24624 (apt-pbo) S 24622 24622 29493 34817 29493 4202496 1580 409 0 0 4 0 0 0 25 0 1 0 76317610 8433664 1401 1283457024 134512640 135745756 4287072736 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/24624/statm: 2059 1401 648 302 0 792 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 9908

[startup+1.50764 s]
/proc/loadavg: 2.12 1.89 1.74 2/36 24628
/proc/meminfo: memFree=281056/1048576 swapFree=0/0
[pid=24622] ppid=24621 vsize=1672 CPUtime=0
/proc/24622/stat : 24622 (sh) S 24621 24622 29493 34817 29493 4202496 223 174 0 0 0 0 0 0 24 0 1 0 76317610 1712128 129 1283457024 134512640 134593992 4286927504 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24622/statm: 418 129 112 20 0 45 0
[pid=24624] ppid=24622 vsize=8236 CPUtime=0.04
/proc/24624/stat : 24624 (apt-pbo) S 24622 24622 29493 34817 29493 4202496 1580 409 0 0 4 0 0 0 25 0 1 0 76317610 8433664 1401 1283457024 134512640 135745756 4287072736 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/24624/statm: 2059 1401 648 302 0 792 0
[pid=24628] ppid=24624 vsize=37776 CPUtime=1.45
/proc/24628/stat : 24628 (cudftodeb.nativ) R 24624 24622 29493 34817 29493 4202496 9016 0 0 0 139 6 0 0 25 0 1 0 76317616 38682624 8937 1283457024 134512640 135029684 4287888128 18446744073709551615 134974442 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/24628/statm: 9444 8937 246 127 0 8825 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 47684

[startup+3.10851 s]
/proc/loadavg: 2.03 1.88 1.73 2/36 24628
/proc/meminfo: memFree=263076/1048576 swapFree=0/0
[pid=24622] ppid=24621 vsize=1672 CPUtime=0
/proc/24622/stat : 24622 (sh) S 24621 24622 29493 34817 29493 4202496 223 174 0 0 0 0 0 0 24 0 1 0 76317610 1712128 129 1283457024 134512640 134593992 4286927504 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24622/statm: 418 129 112 20 0 45 0
[pid=24624] ppid=24622 vsize=8236 CPUtime=0.04
/proc/24624/stat : 24624 (apt-pbo) S 24622 24622 29493 34817 29493 4202496 1580 409 0 0 4 0 0 0 25 0 1 0 76317610 8433664 1401 1283457024 134512640 135745756 4287072736 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/24624/statm: 2059 1401 648 302 0 792 0
[pid=24628] ppid=24624 vsize=64992 CPUtime=3.05
/proc/24628/stat : 24628 (cudftodeb.nativ) R 24624 24622 29493 34817 29493 4202496 15851 0 0 0 287 18 0 0 25 0 1 0 76317616 66551808 15772 1283457024 134512640 135029684 4287888128 18446744073709551615 134876153 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/24628/statm: 16248 15772 258 127 0 15629 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 74900

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

[startup+3.20332 s]
/proc/loadavg: 2.03 1.88 1.73 2/36 24628
/proc/meminfo: memFree=263076/1048576 swapFree=0/0
[pid=24622] ppid=24621 vsize=1672 CPUtime=0
/proc/24622/stat : 24622 (sh) S 24621 24622 29493 34817 29493 4202496 223 174 0 0 0 0 0 0 24 0 1 0 76317610 1712128 129 1283457024 134512640 134593992 4286927504 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24622/statm: 418 129 112 20 0 45 0
[pid=24624] ppid=24622 vsize=8236 CPUtime=0.04
/proc/24624/stat : 24624 (apt-pbo) S 24622 24622 29493 34817 29493 4202496 1580 409 0 0 4 0 0 0 25 0 1 0 76317610 8433664 1401 1283457024 134512640 135745756 4287072736 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/24624/statm: 2059 1401 648 302 0 792 0
[pid=24628] ppid=24624 vsize=65496 CPUtime=3.06
/proc/24628/stat : 24628 (cudftodeb.nativ) D 24624 24622 29493 34817 29493 4202496 15924 0 0 0 288 18 0 0 25 0 1 0 76317616 67067904 15845 1283457024 134512640 135029684 4287888128 18446744073709551615 4294960130 0 0 0 1024 18446744071564252162 0 0 17 0 0 0 0
/proc/24628/statm: 16374 15845 258 127 0 15755 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 75404

[startup+4.00631 s]
/proc/loadavg: 2.03 1.88 1.73 2/36 24628
/proc/meminfo: memFree=239392/1048576 swapFree=0/0
[pid=24622] ppid=24621 vsize=1672 CPUtime=0
/proc/24622/stat : 24622 (sh) S 24621 24622 29493 34817 29493 4202496 223 174 0 0 0 0 0 0 24 0 1 0 76317610 1712128 129 1283457024 134512640 134593992 4286927504 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24622/statm: 418 129 112 20 0 45 0
[pid=24624] ppid=24622 vsize=8236 CPUtime=0.04
/proc/24624/stat : 24624 (apt-pbo) S 24622 24622 29493 34817 29493 4202496 1580 409 0 0 4 0 0 0 25 0 1 0 76317610 8433664 1401 1283457024 134512640 135745756 4287072736 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/24624/statm: 2059 1401 648 302 0 792 0
[pid=24628] ppid=24624 vsize=52392 CPUtime=3.84
/proc/24628/stat : 24628 (cudftodeb.nativ) R 24624 24622 29493 34817 29493 4202496 16126 0 0 0 353 31 0 0 25 0 1 0 76317616 53649408 12668 1283457024 134512640 135029684 4287888128 18446744073709551615 134971530 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/24628/statm: 13098 12668 258 127 0 12479 0
Current children cumulated CPU time (s) 3.88
Current children cumulated vsize (KiB) 62300

[startup+4.80647 s]
/proc/loadavg: 2.03 1.88 1.73 2/36 24628
/proc/meminfo: memFree=246708/1048576 swapFree=0/0
[pid=24622] ppid=24621 vsize=1672 CPUtime=0
/proc/24622/stat : 24622 (sh) S 24621 24622 29493 34817 29493 4202496 223 174 0 0 0 0 0 0 24 0 1 0 76317610 1712128 129 1283457024 134512640 134593992 4286927504 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24622/statm: 418 129 112 20 0 45 0
[pid=24624] ppid=24622 vsize=8236 CPUtime=4.49
/proc/24624/stat : 24624 (apt-pbo) S 24622 24622 29493 34817 29493 4202496 1754 16911 0 0 4 0 399 46 18 0 1 0 76317610 8433664 1427 1283457024 134512640 135745756 4287072736 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/24624/statm: 2059 1427 653 302 0 792 0
Current children cumulated CPU time (s) 4.49
Current children cumulated vsize (KiB) 9908

[startup+5.20738 s]
/proc/loadavg: 2.03 1.88 1.73 2/36 24628
/proc/meminfo: memFree=246708/1048576 swapFree=0/0
[pid=24622] ppid=24621 vsize=1672 CPUtime=0
/proc/24622/stat : 24622 (sh) S 24621 24622 29493 34817 29493 4202496 223 174 0 0 0 0 0 0 24 0 1 0 76317610 1712128 129 1283457024 134512640 134593992 4286927504 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24622/statm: 418 129 112 20 0 45 0
[pid=24624] ppid=24622 vsize=8236 CPUtime=4.49
/proc/24624/stat : 24624 (apt-pbo) S 24622 24622 29493 34817 29493 4202496 1754 16911 0 0 4 0 399 46 18 0 1 0 76317610 8433664 1427 1283457024 134512640 135745756 4287072736 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/24624/statm: 2059 1427 653 302 0 792 0
Current children cumulated CPU time (s) 4.49
Current children cumulated vsize (KiB) 9908

[startup+5.30744 s]
/proc/loadavg: 2.03 1.88 1.73 2/36 24628
/proc/meminfo: memFree=246708/1048576 swapFree=0/0
[pid=24622] ppid=24621 vsize=1672 CPUtime=0
/proc/24622/stat : 24622 (sh) S 24621 24622 29493 34817 29493 4202496 223 174 0 0 0 0 0 0 24 0 1 0 76317610 1712128 129 1283457024 134512640 134593992 4286927504 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/24622/statm: 418 129 112 20 0 45 0
[pid=24624] ppid=24622 vsize=8236 CPUtime=4.49
/proc/24624/stat : 24624 (apt-pbo) S 24622 24622 29493 34817 29493 4202496 1754 16911 0 0 4 0 399 46 18 0 1 0 76317610 8433664 1427 1283457024 134512640 135745756 4287072736 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/24624/statm: 2059 1427 653 302 0 792 0
Current children cumulated CPU time (s) 4.49
Current children cumulated vsize (KiB) 9908

Child status: 100
Real time (s): 5.40577
CPU time (s): 4.7523
CPU user time (s): 4.26027
CPU system time (s): 0.49203
CPU usage (%): 87.9116
Max. virtual memory (cumulated for all children) (KiB): 75908

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.26027
system time used= 0.49203
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 22637
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= 45
involuntary context switches= 83

runsolver used 0 second user time and 0 second system time

The end