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/103c9978-5408-11df-9bc1-00163e7a6f5e.cudf.debian-dudf.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/debian-dudf//103c9978-5408-11df-9bc1-00163e7a6f5e.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/103c9978-5408-11df-9bc1-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.91 0.59 1/43 4472
/proc/meminfo: memFree=594284/1048576 swapFree=2084088/2097144
[pid=4472] ppid=4471 vsize=972 CPUtime=0
/proc/4472/stat : 4472 (apt-get-trendy-) D 4471 4472 4159 34819 4229 4194304 107 0 0 0 0 0 0 0 24 0 1 0 877586517 995328 34 1283457024 134512640 135304128 4287101552 18446744073709551615 4160437476 0 0 0 0 18446744071564252162 0 0 17 0 0 0 0
/proc/4472/statm: 243 34 27 194 0 11 0

[startup+0.12523 s]
/proc/loadavg: 0.84 0.91 0.59 1/43 4472
/proc/meminfo: memFree=594284/1048576 swapFree=2084088/2097144
[pid=4472] ppid=4471 vsize=2584 CPUtime=0
/proc/4472/stat : 4472 (apt-get-trendy-) S 4471 4472 4159 34819 4229 4202496 516 1358 0 0 0 0 0 0 25 0 1 0 877586517 2646016 280 1283457024 134512640 135304128 4287101552 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4472/statm: 646 280 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.205263 s]
/proc/loadavg: 0.84 0.91 0.59 1/43 4472
/proc/meminfo: memFree=594284/1048576 swapFree=2084088/2097144
[pid=4472] ppid=4471 vsize=2584 CPUtime=0
/proc/4472/stat : 4472 (apt-get-trendy-) R 4471 4472 4159 34819 4229 4202496 525 1608 0 3 0 0 0 0 24 0 1 0 877586517 2646016 283 1283457024 134512640 135304128 4287101552 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/4472/statm: 646 283 240 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.305239 s]
/proc/loadavg: 0.84 0.91 0.59 1/43 4472
/proc/meminfo: memFree=594284/1048576 swapFree=2084088/2097144
[pid=4472] ppid=4471 vsize=2584 CPUtime=0.01
/proc/4472/stat : 4472 (apt-get-trendy-) S 4471 4472 4159 34819 4229 4202496 565 1854 0 3 0 0 1 0 24 0 1 0 877586517 2646016 283 1283457024 134512640 135304128 4287101552 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4472/statm: 646 283 240 194 0 32 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2584

[startup+0.714702 s]
/proc/loadavg: 0.84 0.91 0.59 1/43 4472
/proc/meminfo: memFree=594284/1048576 swapFree=2084088/2097144
[pid=4472] ppid=4471 vsize=2584 CPUtime=0.01
/proc/4472/stat : 4472 (apt-get-trendy-) S 4471 4472 4159 34819 4229 4202496 565 1854 0 3 0 0 1 0 24 0 1 0 877586517 2646016 283 1283457024 134512640 135304128 4287101552 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4472/statm: 646 283 240 194 0 32 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2584

[startup+1.51491 s]
/proc/loadavg: 0.84 0.91 0.59 2/45 4483
/proc/meminfo: memFree=555928/1048576 swapFree=2084088/2097144
[pid=4472] ppid=4471 vsize=2584 CPUtime=0.01
/proc/4472/stat : 4472 (apt-get-trendy-) S 4471 4472 4159 34819 4229 4202496 565 1854 0 3 0 0 1 0 24 0 1 0 877586517 2646016 283 1283457024 134512640 135304128 4287101552 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4472/statm: 646 283 240 194 0 32 0
[pid=4483] ppid=4472 vsize=27728 CPUtime=1.27
/proc/4483/stat : 4483 (cudftodeb.nativ) R 4472 4472 4159 34819 4229 4202496 6506 0 6 0 124 3 0 0 25 0 1 0 877586538 28393472 6439 1283457024 134512640 135004320 4294581568 18446744073709551615 134986455 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/4483/statm: 6932 6439 225 121 0 6324 0
Current children cumulated CPU time (s) 1.28
Current children cumulated vsize (KiB) 30312

[startup+3.11535 s]
/proc/loadavg: 0.84 0.91 0.59 2/45 4483
/proc/meminfo: memFree=533856/1048576 swapFree=2084088/2097144
[pid=4472] ppid=4471 vsize=2584 CPUtime=0.01
/proc/4472/stat : 4472 (apt-get-trendy-) S 4471 4472 4159 34819 4229 4202496 565 1854 0 3 0 0 1 0 24 0 1 0 877586517 2646016 283 1283457024 134512640 135304128 4287101552 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4472/statm: 646 283 240 194 0 32 0
[pid=4483] ppid=4472 vsize=58512 CPUtime=2.87
/proc/4483/stat : 4483 (cudftodeb.nativ) R 4472 4472 4159 34819 4229 4202496 14079 0 6 0 279 8 0 0 25 0 1 0 877586538 59916288 14012 1283457024 134512640 135004320 4294581568 18446744073709551615 4159191094 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/4483/statm: 14628 14012 237 121 0 14020 0
Current children cumulated CPU time (s) 2.88
Current children cumulated vsize (KiB) 61096

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

[startup+3.21539 s]
/proc/loadavg: 0.84 0.91 0.59 2/45 4483
/proc/meminfo: memFree=533856/1048576 swapFree=2084088/2097144
[pid=4472] ppid=4471 vsize=2584 CPUtime=0.01
/proc/4472/stat : 4472 (apt-get-trendy-) S 4471 4472 4159 34819 4229 4202496 565 1854 0 3 0 0 1 0 24 0 1 0 877586517 2646016 283 1283457024 134512640 135304128 4287101552 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4472/statm: 646 283 240 194 0 32 0
[pid=4483] ppid=4472 vsize=60248 CPUtime=2.97
/proc/4483/stat : 4483 (cudftodeb.nativ) R 4472 4472 4159 34819 4229 4202496 14501 0 6 0 289 8 0 0 25 0 1 0 877586538 61693952 14434 1283457024 134512640 135004320 4294581568 18446744073709551615 134996501 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/4483/statm: 15062 14434 237 121 0 14454 0
Current children cumulated CPU time (s) 2.98
Current children cumulated vsize (KiB) 62832

[startup+4.80208 s]
/proc/loadavg: 0.85 0.91 0.60 1/45 4491
/proc/meminfo: memFree=553164/1048576 swapFree=2084088/2097144
[pid=4472] ppid=4471 vsize=2592 CPUtime=3.33
/proc/4472/stat : 4472 (apt-get-trendy-) S 4471 4472 4159 34819 4229 4202496 703 19744 0 21 0 0 323 10 18 0 1 0 877586517 2654208 294 1283457024 134512640 135304128 4287101552 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4472/statm: 648 294 249 194 0 34 0
Current children cumulated CPU time (s) 3.33
Current children cumulated vsize (KiB) 2592

[startup+5.20556 s]
/proc/loadavg: 0.85 0.91 0.60 1/45 4491
/proc/meminfo: memFree=553164/1048576 swapFree=2084088/2097144
[pid=4472] ppid=4471 vsize=2592 CPUtime=3.33
/proc/4472/stat : 4472 (apt-get-trendy-) S 4471 4472 4159 34819 4229 4202496 703 19744 0 21 0 0 323 10 18 0 1 0 877586517 2654208 294 1283457024 134512640 135304128 4287101552 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4472/statm: 648 294 249 194 0 34 0
Current children cumulated CPU time (s) 3.33
Current children cumulated vsize (KiB) 2592

[startup+5.60558 s]
/proc/loadavg: 0.85 0.91 0.60 1/45 4493
/proc/meminfo: memFree=531832/1048576 swapFree=2084088/2097144
[pid=4472] ppid=4471 vsize=2592 CPUtime=3.33
/proc/4472/stat : 4472 (apt-get-trendy-) S 4471 4472 4159 34819 4229 4202496 703 19744 0 21 0 0 323 10 18 0 1 0 877586517 2654208 294 1283457024 134512640 135304128 4287101552 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4472/statm: 648 294 249 194 0 34 0
[pid=4493] ppid=4472 vsize=16328 CPUtime=0.46
/proc/4493/stat : 4493 (apt-get) R 4472 4472 4159 34819 4229 4202496 6057 0 153 0 42 4 0 0 18 0 1 0 877586972 16719872 3391 1283457024 134512640 134619611 4288705168 18446744073709551615 4159093047 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/4493/statm: 4082 3391 2952 27 0 443 0
Current children cumulated CPU time (s) 3.79
Current children cumulated vsize (KiB) 18920

Child status: 100
Real time (s): 5.69065
CPU time (s): 3.87624
CPU user time (s): 3.73223
CPU system time (s): 0.144009
CPU usage (%): 68.116
Max. virtual memory (cumulated for all children) (KiB): 104088

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.73223
system time used= 0.144009
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 26622
page faults= 174
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 250
involuntary context switches= 73

runsolver used 0 second user time and 0.004 second system time

The end