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/201012070034/apt-get-trendy-1.0/9bb87ab4-4c36-11df-bc1e-00163e7a6f5e.cudf.debian-dudf.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/debian-dudf//9bb87ab4-4c36-11df-bc1e-00163e7a6f5e.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/9bb87ab4-4c36-11df-bc1e-00163e7a6f5e.cudf.debian-dudf.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.95 1.00 1.03 1/40 1831
/proc/meminfo: memFree=689820/1048576 swapFree=2080268/2097144
[pid=1831] ppid=1830 vsize=3024 CPUtime=0
/proc/1831/stat : 1831 (runsolver) D 1830 1831 4159 34819 4229 4202560 72 0 0 0 0 0 0 0 25 0 1 0 884916723 3096576 93 1283457024 134512640 134586868 4290423984 18446744073709551615 4294960130 0 0 0 24578 18446744071564332000 0 0 17 0 0 0 0
/proc/1831/statm: 756 93 62 19 0 54 0

[startup+0.157771 s]
/proc/loadavg: 0.95 1.00 1.03 1/40 1831
/proc/meminfo: memFree=689820/1048576 swapFree=2080268/2097144
[pid=1831] ppid=1830 vsize=2584 CPUtime=0
/proc/1831/stat : 1831 (apt-get-trendy-) S 1830 1831 4159 34819 4229 4202496 517 1364 0 0 0 0 0 0 25 0 1 0 884916723 2646016 280 1283457024 134512640 135304128 4287652592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1831/statm: 646 280 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.20548 s]
/proc/loadavg: 0.95 1.00 1.03 1/40 1831
/proc/meminfo: memFree=689820/1048576 swapFree=2080268/2097144
[pid=1831] ppid=1830 vsize=2584 CPUtime=0
/proc/1831/stat : 1831 (apt-get-trendy-) S 1830 1831 4159 34819 4229 4202496 517 1364 0 0 0 0 0 0 25 0 1 0 884916723 2646016 280 1283457024 134512640 135304128 4287652592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1831/statm: 646 280 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.305478 s]
/proc/loadavg: 0.95 1.00 1.03 1/40 1831
/proc/meminfo: memFree=689820/1048576 swapFree=2080268/2097144
[pid=1831] ppid=1830 vsize=2584 CPUtime=0
/proc/1831/stat : 1831 (apt-get-trendy-) S 1830 1831 4159 34819 4229 4202496 517 1364 0 0 0 0 0 0 25 0 1 0 884916723 2646016 280 1283457024 134512640 135304128 4287652592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1831/statm: 646 280 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.707732 s]
/proc/loadavg: 0.95 1.00 1.03 1/40 1831
/proc/meminfo: memFree=689820/1048576 swapFree=2080268/2097144
[pid=1831] ppid=1830 vsize=2584 CPUtime=0.03
/proc/1831/stat : 1831 (apt-get-trendy-) S 1830 1831 4159 34819 4229 4202496 566 1859 0 4 0 0 0 3 22 0 1 0 884916723 2646016 283 1283457024 134512640 135304128 4287652592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1831/statm: 646 283 240 194 0 32 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 2584

[startup+1.50794 s]
/proc/loadavg: 0.95 1.00 1.03 2/42 1842
/proc/meminfo: memFree=631592/1048576 swapFree=2080268/2097144
[pid=1831] ppid=1830 vsize=2584 CPUtime=0.03
/proc/1831/stat : 1831 (apt-get-trendy-) S 1830 1831 4159 34819 4229 4202496 566 1859 0 4 0 0 0 3 22 0 1 0 884916723 2646016 283 1283457024 134512640 135304128 4287652592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1831/statm: 646 283 240 194 0 32 0
[pid=1842] ppid=1831 vsize=23340 CPUtime=1.07
/proc/1842/stat : 1842 (cudftodeb.nativ) R 1831 1831 4159 34819 4229 4202496 5449 0 8 0 106 1 0 0 25 0 1 0 884916762 23900160 5383 1283457024 134512640 135004320 4293932000 18446744073709551615 134959999 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/1842/statm: 5835 5383 225 121 0 5227 0
Current children cumulated CPU time (s) 1.1
Current children cumulated vsize (KiB) 25924

[startup+3.1083 s]
/proc/loadavg: 0.95 1.00 1.03 2/42 1842
/proc/meminfo: memFree=610636/1048576 swapFree=2080268/2097144
[pid=1831] ppid=1830 vsize=2584 CPUtime=0.03
/proc/1831/stat : 1831 (apt-get-trendy-) S 1830 1831 4159 34819 4229 4202496 566 1859 0 4 0 0 0 3 22 0 1 0 884916723 2646016 283 1283457024 134512640 135304128 4287652592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1831/statm: 646 283 240 194 0 32 0
[pid=1842] ppid=1831 vsize=52484 CPUtime=2.67
/proc/1842/stat : 1842 (cudftodeb.nativ) R 1831 1831 4159 34819 4229 4202496 12602 0 8 0 263 4 0 0 25 0 1 0 884916762 53743616 12536 1283457024 134512640 135004320 4293932000 18446744073709551615 134996501 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/1842/statm: 13121 12536 225 121 0 12513 0
Current children cumulated CPU time (s) 2.7
Current children cumulated vsize (KiB) 55068

[startup+6.30913 s]
/proc/loadavg: 0.95 1.00 1.03 2/42 1842
/proc/meminfo: memFree=551860/1048576 swapFree=2080268/2097144
[pid=1831] ppid=1830 vsize=2584 CPUtime=0.03
/proc/1831/stat : 1831 (apt-get-trendy-) S 1830 1831 4159 34819 4229 4202496 566 1859 0 4 0 0 0 3 22 0 1 0 884916723 2646016 283 1283457024 134512640 135304128 4287652592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1831/statm: 646 283 240 194 0 32 0
[pid=1842] ppid=1831 vsize=108252 CPUtime=5.86
/proc/1842/stat : 1842 (cudftodeb.nativ) R 1831 1831 4159 34819 4229 4202496 26246 0 8 0 575 11 0 0 25 0 1 0 884916762 110850048 26180 1283457024 134512640 135004320 4293932000 18446744073709551615 134996501 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/1842/statm: 27063 26180 237 121 0 26455 0
Current children cumulated CPU time (s) 5.89
Current children cumulated vsize (KiB) 110836

[startup+12.7063 s]
/proc/loadavg: 0.96 1.00 1.03 1/42 1852
/proc/meminfo: memFree=547388/1048576 swapFree=2080268/2097144
[pid=1831] ppid=1830 vsize=2592 CPUtime=9.06
/proc/1831/stat : 1831 (apt-get-trendy-) S 1830 1831 4159 34819 4229 4202496 700 34055 0 24 0 0 876 30 18 0 1 0 884916723 2654208 294 1283457024 134512640 135304128 4287652592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1831/statm: 648 294 249 194 0 34 0
[pid=1852] ppid=1831 vsize=101456 CPUtime=1.25
/proc/1852/stat : 1852 (apt-get) D 1831 1831 4159 34819 4229 4202496 6527 0 363 0 117 8 0 0 18 0 1 0 884917789 103890944 6814 1283457024 134512640 134619611 4290243584 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/1852/statm: 25364 6814 6761 27 0 58 0
Current children cumulated CPU time (s) 10.31
Current children cumulated vsize (KiB) 104048

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

[startup+12.8063 s]
/proc/loadavg: 0.96 1.00 1.03 1/42 1852
/proc/meminfo: memFree=547388/1048576 swapFree=2080268/2097144
[pid=1831] ppid=1830 vsize=2592 CPUtime=9.06
/proc/1831/stat : 1831 (apt-get-trendy-) S 1830 1831 4159 34819 4229 4202496 700 34055 0 24 0 0 876 30 18 0 1 0 884916723 2654208 294 1283457024 134512640 135304128 4287652592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1831/statm: 648 294 249 194 0 34 0
[pid=1852] ppid=1831 vsize=101456 CPUtime=1.25
/proc/1852/stat : 1852 (apt-get) R 1831 1831 4159 34819 4229 4202496 6527 0 363 0 117 8 0 0 18 0 1 0 884917789 103890944 6814 1283457024 134512640 134619611 4290243584 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/1852/statm: 25364 6814 6761 27 0 58 0
Current children cumulated CPU time (s) 10.31
Current children cumulated vsize (KiB) 104048

[startup+13.207 s]
/proc/loadavg: 0.96 1.00 1.03 2/42 1852
/proc/meminfo: memFree=543952/1048576 swapFree=2080268/2097144
[pid=1831] ppid=1830 vsize=2592 CPUtime=9.06
/proc/1831/stat : 1831 (apt-get-trendy-) S 1830 1831 4159 34819 4229 4202496 700 34055 0 24 0 0 876 30 18 0 1 0 884916723 2654208 294 1283457024 134512640 135304128 4287652592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1831/statm: 648 294 249 194 0 34 0
[pid=1852] ppid=1831 vsize=31624 CPUtime=1.42
/proc/1852/stat : 1852 (apt-get) R 1831 1831 4159 34819 4229 4202496 13134 0 363 0 132 10 0 0 18 0 1 0 884917789 32382976 7015 1283457024 134512640 134619611 4290243584 18446744073709551615 4160095780 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/1852/statm: 7906 7015 6420 27 0 600 0
Current children cumulated CPU time (s) 10.48
Current children cumulated vsize (KiB) 34216

[startup+13.307 s]
/proc/loadavg: 0.96 1.00 1.03 2/42 1852
/proc/meminfo: memFree=543952/1048576 swapFree=2080268/2097144
[pid=1831] ppid=1830 vsize=2592 CPUtime=9.06
/proc/1831/stat : 1831 (apt-get-trendy-) S 1830 1831 4159 34819 4229 4202496 700 34055 0 24 0 0 876 30 18 0 1 0 884916723 2654208 294 1283457024 134512640 135304128 4287652592 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1831/statm: 648 294 249 194 0 34 0
[pid=1852] ppid=1831 vsize=31800 CPUtime=1.52
/proc/1852/stat : 1852 (apt-get) R 1831 1831 4159 34819 4229 4202496 13253 0 363 0 142 10 0 0 18 0 1 0 884917789 32563200 7089 1283457024 134512640 134619611 4290243584 18446744073709551615 4160095248 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/1852/statm: 7950 7089 6449 27 0 644 0
Current children cumulated CPU time (s) 10.58
Current children cumulated vsize (KiB) 34392

Child status: 100
Real time (s): 13.3293
CPU time (s): 10.6047
CPU user time (s): 10.1886
CPU system time (s): 0.416026
CPU usage (%): 79.559
Max. virtual memory (cumulated for all children) (KiB): 116812

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 10.1886
system time used= 0.416026
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 48023
page faults= 387
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 456
involuntary context switches= 210

runsolver used 0 second user time and 0.004 second system time

The end