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/1dcce248-4bb4-11df-9e6e-00163e7a6f5e.cudf.debian-dudf.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/debian-dudf//1dcce248-4bb4-11df-9e6e-00163e7a6f5e.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/1dcce248-4bb4-11df-9e6e-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.84 0.96 0.99 5/44 6970
/proc/meminfo: memFree=773708/1048576 swapFree=2077664/2097144
[pid=6969] ppid=6968 vsize=2572 CPUtime=0
/proc/6969/stat : 6969 (apt-get-trendy-) R 6968 6969 4159 34819 4229 4202496 357 0 0 0 0 0 0 0 25 0 1 0 878170843 2633728 271 1283457024 134512640 135304128 4291145280 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/6969/statm: 643 271 232 194 0 29 0
[pid=6970] ppid=6969 vsize=2572 CPUtime=0
/proc/6970/stat : 6970 (apt-get-trendy-) R 6969 6969 4159 34819 4229 4202560 0 0 0 0 0 0 0 0 25 0 1 0 878170843 2633728 39 1283457024 134512640 135304128 4291145280 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/6970/statm: 643 39 0 194 0 29 0

[startup+0.181639 s]
/proc/loadavg: 0.84 0.96 0.99 5/44 6970
/proc/meminfo: memFree=773708/1048576 swapFree=2077664/2097144
[pid=6969] ppid=6968 vsize=2584 CPUtime=0
/proc/6969/stat : 6969 (apt-get-trendy-) S 6968 6969 4159 34819 4229 4202496 508 1359 0 0 0 0 0 0 25 0 1 0 878170843 2646016 279 1283457024 134512640 135304128 4291145280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6969/statm: 646 279 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.205649 s]
/proc/loadavg: 0.84 0.96 0.99 5/44 6970
/proc/meminfo: memFree=773708/1048576 swapFree=2077664/2097144
[pid=6969] ppid=6968 vsize=2584 CPUtime=0
/proc/6969/stat : 6969 (apt-get-trendy-) S 6968 6969 4159 34819 4229 4202496 508 1359 0 0 0 0 0 0 25 0 1 0 878170843 2646016 279 1283457024 134512640 135304128 4291145280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6969/statm: 646 279 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.305658 s]
/proc/loadavg: 0.84 0.96 0.99 5/44 6970
/proc/meminfo: memFree=773708/1048576 swapFree=2077664/2097144
[pid=6969] ppid=6968 vsize=2584 CPUtime=0
/proc/6969/stat : 6969 (apt-get-trendy-) S 6968 6969 4159 34819 4229 4202496 508 1359 0 0 0 0 0 0 25 0 1 0 878170843 2646016 279 1283457024 134512640 135304128 4291145280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6969/statm: 646 279 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.715487 s]
/proc/loadavg: 0.84 0.96 0.99 5/44 6970
/proc/meminfo: memFree=773708/1048576 swapFree=2077664/2097144
[pid=6969] ppid=6968 vsize=2584 CPUtime=0.02
/proc/6969/stat : 6969 (apt-get-trendy-) S 6968 6969 4159 34819 4229 4202496 555 1858 0 0 0 0 1 1 22 0 1 0 878170843 2646016 282 1283457024 134512640 135304128 4291145280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6969/statm: 646 282 240 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 2584

[startup+1.51564 s]
/proc/loadavg: 0.85 0.96 0.99 2/45 6980
/proc/meminfo: memFree=714960/1048576 swapFree=2077664/2097144
[pid=6969] ppid=6968 vsize=2584 CPUtime=0.02
/proc/6969/stat : 6969 (apt-get-trendy-) S 6968 6969 4159 34819 4229 4202496 555 1858 0 0 0 0 1 1 22 0 1 0 878170843 2646016 282 1283457024 134512640 135304128 4291145280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6969/statm: 646 282 240 194 0 32 0
[pid=6980] ppid=6969 vsize=25812 CPUtime=1.18
/proc/6980/stat : 6980 (cudftodeb.nativ) R 6969 6969 4159 34819 4229 4202496 6044 0 0 0 116 2 0 0 25 0 1 0 878170876 26431488 5971 1283457024 134512640 135004320 4293572864 18446744073709551615 134986387 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/6980/statm: 6453 5971 225 121 0 5845 0
Current children cumulated CPU time (s) 1.2
Current children cumulated vsize (KiB) 28396

[startup+3.10607 s]
/proc/loadavg: 0.85 0.96 0.99 2/45 6980
/proc/meminfo: memFree=694376/1048576 swapFree=2077664/2097144
[pid=6969] ppid=6968 vsize=2584 CPUtime=0.02
/proc/6969/stat : 6969 (apt-get-trendy-) S 6968 6969 4159 34819 4229 4202496 555 1858 0 0 0 0 1 1 22 0 1 0 878170843 2646016 282 1283457024 134512640 135304128 4291145280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6969/statm: 646 282 240 194 0 32 0
[pid=6980] ppid=6969 vsize=53964 CPUtime=2.77
/proc/6980/stat : 6980 (cudftodeb.nativ) R 6969 6969 4159 34819 4229 4202496 12972 0 0 0 272 5 0 0 25 0 1 0 878170876 55259136 12899 1283457024 134512640 135004320 4293572864 18446744073709551615 134945035 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/6980/statm: 13491 12899 225 121 0 12883 0
Current children cumulated CPU time (s) 2.79
Current children cumulated vsize (KiB) 56548

[startup+6.30706 s]
/proc/loadavg: 0.95 0.98 0.99 2/45 6980
/proc/meminfo: memFree=637088/1048576 swapFree=2077664/2097144
[pid=6969] ppid=6968 vsize=2584 CPUtime=0.02
/proc/6969/stat : 6969 (apt-get-trendy-) S 6968 6969 4159 34819 4229 4202496 555 1858 0 0 0 0 1 1 22 0 1 0 878170843 2646016 282 1283457024 134512640 135304128 4291145280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6969/statm: 646 282 240 194 0 32 0
[pid=6980] ppid=6969 vsize=109484 CPUtime=5.94
/proc/6980/stat : 6980 (cudftodeb.nativ) R 6969 6969 4159 34819 4229 4202496 26557 0 0 0 586 8 0 0 25 0 1 0 878170876 112111616 26484 1283457024 134512640 135004320 4293572864 18446744073709551615 134996501 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/6980/statm: 27371 26484 237 121 0 26763 0
Current children cumulated CPU time (s) 5.96
Current children cumulated vsize (KiB) 112068

[startup+12.7064 s]
/proc/loadavg: 1.03 0.99 1.00 1/45 6990
/proc/meminfo: memFree=633564/1048576 swapFree=2077664/2097144
[pid=6969] ppid=6968 vsize=2592 CPUtime=9.05
/proc/6969/stat : 6969 (apt-get-trendy-) S 6968 6969 4159 34819 4229 4202496 688 34079 0 1 0 0 884 21 18 0 1 0 878170843 2654208 293 1283457024 134512640 135304128 4291145280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6969/statm: 648 293 249 194 0 34 0
[pid=6990] ppid=6969 vsize=101452 CPUtime=1.26
/proc/6990/stat : 6990 (apt-get) D 6969 6969 4159 34819 4229 4202496 6527 0 363 0 118 8 0 0 18 0 1 0 878171897 103886848 6814 1283457024 134512640 134619611 4290247680 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/6990/statm: 25363 6814 6761 27 0 57 0
Current children cumulated CPU time (s) 10.31
Current children cumulated vsize (KiB) 104044

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

[startup+12.8064 s]
/proc/loadavg: 1.03 0.99 1.00 1/45 6990
/proc/meminfo: memFree=633564/1048576 swapFree=2077664/2097144
[pid=6969] ppid=6968 vsize=2592 CPUtime=9.05
/proc/6969/stat : 6969 (apt-get-trendy-) S 6968 6969 4159 34819 4229 4202496 688 34079 0 1 0 0 884 21 18 0 1 0 878170843 2654208 293 1283457024 134512640 135304128 4291145280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6969/statm: 648 293 249 194 0 34 0
[pid=6990] ppid=6969 vsize=101452 CPUtime=1.26
/proc/6990/stat : 6990 (apt-get) D 6969 6969 4159 34819 4229 4202496 6527 0 363 0 118 8 0 0 18 0 1 0 878171897 103886848 6814 1283457024 134512640 134619611 4290247680 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/6990/statm: 25363 6814 6761 27 0 57 0
Current children cumulated CPU time (s) 10.31
Current children cumulated vsize (KiB) 104044

[startup+13.0077 s]
/proc/loadavg: 1.03 0.99 1.00 1/45 6990
/proc/meminfo: memFree=633564/1048576 swapFree=2077664/2097144
[pid=6969] ppid=6968 vsize=2592 CPUtime=9.05
/proc/6969/stat : 6969 (apt-get-trendy-) S 6968 6969 4159 34819 4229 4202496 688 34079 0 1 0 0 884 21 18 0 1 0 878170843 2654208 293 1283457024 134512640 135304128 4291145280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6969/statm: 648 293 249 194 0 34 0
[pid=6990] ppid=6969 vsize=31620 CPUtime=1.4
/proc/6990/stat : 6990 (apt-get) R 6969 6969 4159 34819 4229 4202496 13134 0 363 0 131 9 0 0 18 0 1 0 878171897 32378880 7015 1283457024 134512640 134619611 4290247680 18446744073709551615 4159820856 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/6990/statm: 7905 7015 6420 27 0 599 0
Current children cumulated CPU time (s) 10.45
Current children cumulated vsize (KiB) 34212

[startup+13.1078 s]
/proc/loadavg: 1.03 0.99 1.00 1/45 6990
/proc/meminfo: memFree=633564/1048576 swapFree=2077664/2097144
[pid=6969] ppid=6968 vsize=2592 CPUtime=9.05
/proc/6969/stat : 6969 (apt-get-trendy-) S 6968 6969 4159 34819 4229 4202496 688 34079 0 1 0 0 884 21 18 0 1 0 878170843 2654208 293 1283457024 134512640 135304128 4291145280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/6969/statm: 648 293 249 194 0 34 0
[pid=6990] ppid=6969 vsize=31972 CPUtime=1.5
/proc/6990/stat : 6990 (apt-get) R 6969 6969 4159 34819 4229 4202496 13229 0 363 0 141 9 0 0 18 0 1 0 878171897 32739328 7109 1283457024 134512640 134619611 4290247680 18446744073709551615 4157009626 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/6990/statm: 7993 7109 6447 27 0 687 0
Current children cumulated CPU time (s) 10.55
Current children cumulated vsize (KiB) 34564

Child status: 100
Real time (s): 13.1446
CPU time (s): 10.6087
CPU user time (s): 10.2806
CPU system time (s): 0.32802
CPU usage (%): 80.7075
Max. virtual memory (cumulated for all children) (KiB): 116808

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 10.2806
system time used= 0.32802
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 48034
page faults= 364
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 402
involuntary context switches= 195

runsolver used 0 second user time and 0 second system time

The end