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/591.cudf.caixa.log.runsolver ./apt-pbo-trendy-1.0.8 /home/misc2010/data/misc4/caixa//591.cudf /home/misc2010/tmp/201103031013/apt-pbo-trendy-1.0.8/591.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.70 1.74 1.67 3/34 22703
/proc/meminfo: memFree=324508/1048576 swapFree=0/0
[pid=22702] ppid=22701 vsize=1672 CPUtime=0
/proc/22702/stat : 22702 (sh) R 22701 22702 29493 34817 29493 4202496 205 0 0 0 0 0 0 0 25 0 1 0 76305821 1712128 126 1283457024 134512640 134593992 4290489856 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/22702/statm: 418 126 110 20 0 45 0
[pid=22703] ppid=22702 vsize=1672 CPUtime=0
/proc/22703/stat : 22703 (sh) R 22702 22702 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 76305821 1712128 16 1283457024 134512640 134593992 4290489856 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/22703/statm: 418 16 0 20 0 45 0

[startup+0.11517 s]
/proc/loadavg: 1.70 1.74 1.67 3/34 22703
/proc/meminfo: memFree=324508/1048576 swapFree=0/0
[pid=22702] ppid=22701 vsize=1672 CPUtime=0
/proc/22702/stat : 22702 (sh) S 22701 22702 29493 34817 29493 4202496 220 175 0 0 0 0 0 0 25 0 1 0 76305821 1712128 128 1283457024 134512640 134593992 4290489856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22702/statm: 418 128 112 20 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1672

[startup+0.215207 s]
/proc/loadavg: 1.70 1.74 1.67 3/34 22703
/proc/meminfo: memFree=324508/1048576 swapFree=0/0
[pid=22702] ppid=22701 vsize=1672 CPUtime=0
/proc/22702/stat : 22702 (sh) S 22701 22702 29493 34817 29493 4202496 220 175 0 0 0 0 0 0 25 0 1 0 76305821 1712128 128 1283457024 134512640 134593992 4290489856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22702/statm: 418 128 112 20 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1672

[startup+0.315234 s]
/proc/loadavg: 1.70 1.74 1.67 3/34 22703
/proc/meminfo: memFree=324508/1048576 swapFree=0/0
[pid=22702] ppid=22701 vsize=1672 CPUtime=0
/proc/22702/stat : 22702 (sh) S 22701 22702 29493 34817 29493 4202496 220 175 0 0 0 0 0 0 25 0 1 0 76305821 1712128 128 1283457024 134512640 134593992 4290489856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22702/statm: 418 128 112 20 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1672

[startup+0.715336 s]
/proc/loadavg: 1.70 1.74 1.67 3/34 22703
/proc/meminfo: memFree=324508/1048576 swapFree=0/0
[pid=22702] ppid=22701 vsize=1672 CPUtime=0
/proc/22702/stat : 22702 (sh) S 22701 22702 29493 34817 29493 4202496 220 175 0 0 0 0 0 0 25 0 1 0 76305821 1712128 128 1283457024 134512640 134593992 4290489856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22702/statm: 418 128 112 20 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1672

[startup+1.51555 s]
/proc/loadavg: 1.70 1.74 1.67 2/36 22708
/proc/meminfo: memFree=295084/1048576 swapFree=0/0
[pid=22702] ppid=22701 vsize=1672 CPUtime=0
/proc/22702/stat : 22702 (sh) S 22701 22702 29493 34817 29493 4202496 220 175 0 0 0 0 0 0 25 0 1 0 76305821 1712128 128 1283457024 134512640 134593992 4290489856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22702/statm: 418 128 112 20 0 45 0
[pid=22705] ppid=22702 vsize=8232 CPUtime=0.05
/proc/22705/stat : 22705 (apt-pbo) S 22702 22702 29493 34817 29493 4202496 1582 410 0 0 5 0 0 0 25 0 1 0 76305821 8429568 1401 1283457024 134512640 135745756 4290925968 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22705/statm: 2058 1401 648 302 0 791 0
[pid=22708] ppid=22705 vsize=37252 CPUtime=1.45
/proc/22708/stat : 22708 (cudftodeb.nativ) R 22705 22702 29493 34817 29493 4202496 8916 0 0 0 144 1 0 0 25 0 1 0 76305827 38146048 8836 1283457024 134512640 135029684 4289635504 18446744073709551615 134969984 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/22708/statm: 9313 8836 246 127 0 8694 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 47156

[startup+3.11578 s]
/proc/loadavg: 1.70 1.74 1.67 2/36 22708
/proc/meminfo: memFree=276732/1048576 swapFree=0/0
[pid=22702] ppid=22701 vsize=1672 CPUtime=0
/proc/22702/stat : 22702 (sh) S 22701 22702 29493 34817 29493 4202496 220 175 0 0 0 0 0 0 25 0 1 0 76305821 1712128 128 1283457024 134512640 134593992 4290489856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22702/statm: 418 128 112 20 0 45 0
[pid=22705] ppid=22702 vsize=8232 CPUtime=0.05
/proc/22705/stat : 22705 (apt-pbo) S 22702 22702 29493 34817 29493 4202496 1582 410 0 0 5 0 0 0 25 0 1 0 76305821 8429568 1401 1283457024 134512640 135745756 4290925968 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22705/statm: 2058 1401 648 302 0 791 0
[pid=22708] ppid=22705 vsize=65104 CPUtime=3.05
/proc/22708/stat : 22708 (cudftodeb.nativ) R 22705 22702 29493 34817 29493 4202496 15886 0 0 0 288 17 0 0 25 0 1 0 76305827 66666496 15806 1283457024 134512640 135029684 4289635504 18446744073709551615 134974454 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/22708/statm: 16276 15806 258 127 0 15657 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 75008

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

[startup+3.2158 s]
/proc/loadavg: 1.70 1.74 1.67 2/36 22708
/proc/meminfo: memFree=276732/1048576 swapFree=0/0
[pid=22702] ppid=22701 vsize=1672 CPUtime=0
/proc/22702/stat : 22702 (sh) S 22701 22702 29493 34817 29493 4202496 220 175 0 0 0 0 0 0 25 0 1 0 76305821 1712128 128 1283457024 134512640 134593992 4290489856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22702/statm: 418 128 112 20 0 45 0
[pid=22705] ppid=22702 vsize=8232 CPUtime=0.05
/proc/22705/stat : 22705 (apt-pbo) S 22702 22702 29493 34817 29493 4202496 1582 410 0 0 5 0 0 0 25 0 1 0 76305821 8429568 1401 1283457024 134512640 135745756 4290925968 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/22705/statm: 2058 1401 648 302 0 791 0
[pid=22708] ppid=22705 vsize=66112 CPUtime=3.15
/proc/22708/stat : 22708 (cudftodeb.nativ) R 22705 22702 29493 34817 29493 4202496 16139 0 0 0 295 20 0 0 25 0 1 0 76305827 67698688 16059 1283457024 134512640 135029684 4289635504 18446744073709551615 134888875 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/22708/statm: 16528 16059 258 127 0 15909 0
Current children cumulated CPU time (s) 3.2
Current children cumulated vsize (KiB) 76016

[startup+4.8076 s]
/proc/loadavg: 1.70 1.74 1.67 2/36 22708
/proc/meminfo: memFree=257884/1048576 swapFree=0/0
[pid=22702] ppid=22701 vsize=1672 CPUtime=0
/proc/22702/stat : 22702 (sh) S 22701 22702 29493 34817 29493 4202496 220 175 0 0 0 0 0 0 25 0 1 0 76305821 1712128 128 1283457024 134512640 134593992 4290489856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22702/statm: 418 128 112 20 0 45 0
[pid=22705] ppid=22702 vsize=8232 CPUtime=4.6
/proc/22705/stat : 22705 (apt-pbo) S 22702 22702 29493 34817 29493 4202496 1755 16917 0 0 5 0 406 49 18 0 1 0 76305821 8429568 1427 1283457024 134512640 135745756 4290925968 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/22705/statm: 2058 1427 653 302 0 791 0
Current children cumulated CPU time (s) 4.6
Current children cumulated vsize (KiB) 9904

[startup+5.20747 s]
/proc/loadavg: 1.70 1.74 1.67 2/36 22708
/proc/meminfo: memFree=257884/1048576 swapFree=0/0
[pid=22702] ppid=22701 vsize=1672 CPUtime=0
/proc/22702/stat : 22702 (sh) S 22701 22702 29493 34817 29493 4202496 220 175 0 0 0 0 0 0 25 0 1 0 76305821 1712128 128 1283457024 134512640 134593992 4290489856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22702/statm: 418 128 112 20 0 45 0
[pid=22705] ppid=22702 vsize=8232 CPUtime=4.6
/proc/22705/stat : 22705 (apt-pbo) S 22702 22702 29493 34817 29493 4202496 1755 16917 0 0 5 0 406 49 18 0 1 0 76305821 8429568 1427 1283457024 134512640 135745756 4290925968 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/22705/statm: 2058 1427 653 302 0 791 0
Current children cumulated CPU time (s) 4.6
Current children cumulated vsize (KiB) 9904

[startup+5.40749 s]
/proc/loadavg: 1.70 1.74 1.67 2/36 22708
/proc/meminfo: memFree=257884/1048576 swapFree=0/0
[pid=22702] ppid=22701 vsize=1672 CPUtime=0
/proc/22702/stat : 22702 (sh) S 22701 22702 29493 34817 29493 4202496 220 175 0 0 0 0 0 0 25 0 1 0 76305821 1712128 128 1283457024 134512640 134593992 4290489856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22702/statm: 418 128 112 20 0 45 0
[pid=22705] ppid=22702 vsize=8232 CPUtime=4.6
/proc/22705/stat : 22705 (apt-pbo) S 22702 22702 29493 34817 29493 4202496 1755 16917 0 0 5 0 406 49 18 0 1 0 76305821 8429568 1427 1283457024 134512640 135745756 4290925968 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/22705/statm: 2058 1427 653 302 0 791 0
Current children cumulated CPU time (s) 4.6
Current children cumulated vsize (KiB) 9904

[startup+5.50748 s]
/proc/loadavg: 1.65 1.72 1.67 1/37 22716
/proc/meminfo: memFree=295820/1048576 swapFree=0/0
[pid=22702] ppid=22701 vsize=1672 CPUtime=0
/proc/22702/stat : 22702 (sh) S 22701 22702 29493 34817 29493 4202496 220 175 0 0 0 0 0 0 25 0 1 0 76305821 1712128 128 1283457024 134512640 134593992 4290489856 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22702/statm: 418 128 112 20 0 45 0
[pid=22705] ppid=22702 vsize=8232 CPUtime=4.6
/proc/22705/stat : 22705 (apt-pbo) S 22702 22702 29493 34817 29493 4202496 1755 16917 0 0 5 0 406 49 18 0 1 0 76305821 8429568 1427 1283457024 134512640 135745756 4290925968 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0
/proc/22705/statm: 2058 1427 653 302 0 791 0
[pid=22709] ppid=22705 vsize=2572 CPUtime=0.01
/proc/22709/stat : 22709 (apt-get.sh) S 22705 22702 29493 34817 29493 4202496 404 490 0 0 0 1 0 0 21 0 1 0 76306282 2633728 272 1283457024 134512640 135304128 4290215232 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22709/statm: 643 272 232 194 0 30 0
[pid=22712] ppid=22709 vsize=52748 CPUtime=0.22
/proc/22712/stat : 22712 (apt-get) D 22709 22702 29493 34817 29493 4202496 568 1739 1 0 0 0 20 2 24 0 1 0 76306283 54013952 437 1283457024 134512640 134650667 4293515424 18446744073709551615 4294960130 0 0 4096 134217728 18446744071696460772 0 0 17 0 0 0 0
/proc/22712/statm: 13187 437 388 34 0 70 0
Current children cumulated CPU time (s) 4.83
Current children cumulated vsize (KiB) 65224

Child status: 100
Real time (s): 5.56178
CPU time (s): 4.8523
CPU user time (s): 4.32027
CPU system time (s): 0.532033
CPU usage (%): 87.2437
Max. virtual memory (cumulated for all children) (KiB): 76016

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.32027
system time used= 0.532033
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 22634
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= 44
involuntary context switches= 85

runsolver used 0 second user time and 0 second system time

The end