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/2f690324-4939-11df-9e6e-00163e7a6f5e.cudf.debian-dudf.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/debian-dudf//2f690324-4939-11df-9e6e-00163e7a6f5e.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/2f690324-4939-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: 1.00 1.00 1.00 5/41 15965
/proc/meminfo: memFree=892708/1048576 swapFree=2080272/2097144
[pid=15964] ppid=15963 vsize=2584 CPUtime=0
/proc/15964/stat : 15964 (apt-get-trendy-) S 15963 15964 4159 34819 4229 4202496 517 1358 0 0 0 0 0 0 25 0 1 0 880487149 2646016 281 1283457024 134512640 135304128 4291577520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15964/statm: 646 281 237 194 0 32 0

[startup+0.202853 s]
/proc/loadavg: 1.00 1.00 1.00 5/41 15965
/proc/meminfo: memFree=892708/1048576 swapFree=2080272/2097144
[pid=15964] ppid=15963 vsize=2584 CPUtime=0
/proc/15964/stat : 15964 (apt-get-trendy-) S 15963 15964 4159 34819 4229 4202496 517 1358 0 0 0 0 0 0 25 0 1 0 880487149 2646016 281 1283457024 134512640 135304128 4291577520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15964/statm: 646 281 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.306873 s]
/proc/loadavg: 1.00 1.00 1.00 5/41 15965
/proc/meminfo: memFree=892708/1048576 swapFree=2080272/2097144
[pid=15964] ppid=15963 vsize=2584 CPUtime=0
/proc/15964/stat : 15964 (apt-get-trendy-) S 15963 15964 4159 34819 4229 4202496 517 1358 0 0 0 0 0 0 25 0 1 0 880487149 2646016 281 1283457024 134512640 135304128 4291577520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15964/statm: 646 281 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.406899 s]
/proc/loadavg: 1.00 1.00 1.00 5/41 15965
/proc/meminfo: memFree=892708/1048576 swapFree=2080272/2097144
[pid=15964] ppid=15963 vsize=2584 CPUtime=0.02
/proc/15964/stat : 15964 (apt-get-trendy-) R 15963 15964 4159 34819 4229 4202496 548 1857 0 0 0 0 0 2 23 0 1 0 880487149 2646016 284 1283457024 134512640 135304128 4291577520 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/15964/statm: 646 284 240 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 2584

[startup+0.706968 s]
/proc/loadavg: 1.00 1.00 1.00 5/41 15965
/proc/meminfo: memFree=892708/1048576 swapFree=2080272/2097144
[pid=15964] ppid=15963 vsize=2584 CPUtime=0.02
/proc/15964/stat : 15964 (apt-get-trendy-) S 15963 15964 4159 34819 4229 4202496 566 1857 0 0 0 0 0 2 23 0 1 0 880487149 2646016 284 1283457024 134512640 135304128 4291577520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15964/statm: 646 284 240 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 2584

[startup+1.5071 s]
/proc/loadavg: 1.00 1.00 1.00 2/42 15975
/proc/meminfo: memFree=832020/1048576 swapFree=2080272/2097144
[pid=15964] ppid=15963 vsize=2584 CPUtime=0.02
/proc/15964/stat : 15964 (apt-get-trendy-) S 15963 15964 4159 34819 4229 4202496 566 1857 0 0 0 0 0 2 23 0 1 0 880487149 2646016 284 1283457024 134512640 135304128 4291577520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15964/statm: 646 284 240 194 0 32 0
[pid=15975] ppid=15964 vsize=26064 CPUtime=1.19
/proc/15975/stat : 15975 (cudftodeb.nativ) R 15964 15964 4159 34819 4229 4202496 6084 0 0 0 114 5 0 0 25 0 1 0 880487180 26689536 6011 1283457024 134512640 135004320 4287873936 18446744073709551615 134978748 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/15975/statm: 6516 6011 225 121 0 5908 0
Current children cumulated CPU time (s) 1.21
Current children cumulated vsize (KiB) 28648

[startup+3.10753 s]
/proc/loadavg: 1.00 1.00 1.00 2/42 15975
/proc/meminfo: memFree=812180/1048576 swapFree=2080272/2097144
[pid=15964] ppid=15963 vsize=2584 CPUtime=0.02
/proc/15964/stat : 15964 (apt-get-trendy-) S 15963 15964 4159 34819 4229 4202496 566 1857 0 0 0 0 0 2 23 0 1 0 880487149 2646016 284 1283457024 134512640 135304128 4291577520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15964/statm: 646 284 240 194 0 32 0
[pid=15975] ppid=15964 vsize=53968 CPUtime=2.77
/proc/15975/stat : 15975 (cudftodeb.nativ) R 15964 15964 4159 34819 4229 4202496 12960 0 0 0 267 10 0 0 25 0 1 0 880487180 55263232 12887 1283457024 134512640 135004320 4287873936 18446744073709551615 4294960130 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/15975/statm: 13492 12887 225 121 0 12884 0
Current children cumulated CPU time (s) 2.79
Current children cumulated vsize (KiB) 56552

[startup+6.30847 s]
/proc/loadavg: 1.00 1.00 1.00 2/42 15975
/proc/meminfo: memFree=755520/1048576 swapFree=2080272/2097144
[pid=15964] ppid=15963 vsize=2584 CPUtime=0.02
/proc/15964/stat : 15964 (apt-get-trendy-) S 15963 15964 4159 34819 4229 4202496 566 1857 0 0 0 0 0 2 23 0 1 0 880487149 2646016 284 1283457024 134512640 135304128 4291577520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15964/statm: 646 284 240 194 0 32 0
[pid=15975] ppid=15964 vsize=109736 CPUtime=5.97
/proc/15975/stat : 15975 (cudftodeb.nativ) R 15964 15964 4159 34819 4229 4202496 26636 0 0 0 586 11 0 0 25 0 1 0 880487180 112369664 26563 1283457024 134512640 135004320 4287873936 18446744073709551615 134943783 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/15975/statm: 27434 26563 237 121 0 26826 0
Current children cumulated CPU time (s) 5.99
Current children cumulated vsize (KiB) 112320

[startup+12.7076 s]
/proc/loadavg: 1.00 1.00 1.00 2/42 15985
/proc/meminfo: memFree=758760/1048576 swapFree=2080272/2097144
[pid=15964] ppid=15963 vsize=2592 CPUtime=9.78
/proc/15964/stat : 15964 (apt-get-trendy-) S 15963 15964 4159 34819 4229 4202496 706 40796 0 1 0 0 945 33 18 0 1 0 880487149 2654208 295 1283457024 134512640 135304128 4291577520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15964/statm: 648 295 249 194 0 34 0
[pid=15985] ppid=15964 vsize=101456 CPUtime=1.15
/proc/15985/stat : 15985 (apt-get) D 15964 15964 4159 34819 4229 4202496 6261 0 346 0 109 6 0 0 19 0 1 0 880488248 103890944 6530 1283457024 134512640 134619611 4286709920 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/15985/statm: 25364 6530 6477 27 0 58 0
Current children cumulated CPU time (s) 10.93
Current children cumulated vsize (KiB) 104048

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

[startup+12.9076 s]
/proc/loadavg: 1.00 1.00 1.00 2/42 15985
/proc/meminfo: memFree=758760/1048576 swapFree=2080272/2097144
[pid=15964] ppid=15963 vsize=2592 CPUtime=9.78
/proc/15964/stat : 15964 (apt-get-trendy-) S 15963 15964 4159 34819 4229 4202496 706 40796 0 1 0 0 945 33 18 0 1 0 880487149 2654208 295 1283457024 134512640 135304128 4291577520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15964/statm: 648 295 249 194 0 34 0
[pid=15985] ppid=15964 vsize=101456 CPUtime=1.23
/proc/15985/stat : 15985 (apt-get) D 15964 15964 4159 34819 4229 4202496 6515 0 362 0 115 8 0 0 18 0 1 0 880488248 103890944 6800 1283457024 134512640 134619611 4286709920 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/15985/statm: 25364 6800 6747 27 0 58 0
Current children cumulated CPU time (s) 11.01
Current children cumulated vsize (KiB) 104048

[startup+13.3077 s]
/proc/loadavg: 1.00 1.00 1.00 1/42 15985
/proc/meminfo: memFree=751728/1048576 swapFree=2080272/2097144
[pid=15964] ppid=15963 vsize=2592 CPUtime=9.78
/proc/15964/stat : 15964 (apt-get-trendy-) S 15963 15964 4159 34819 4229 4202496 706 40796 0 1 0 0 945 33 18 0 1 0 880487149 2654208 295 1283457024 134512640 135304128 4291577520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15964/statm: 648 295 249 194 0 34 0
[pid=15985] ppid=15964 vsize=101456 CPUtime=1.23
/proc/15985/stat : 15985 (apt-get) D 15964 15964 4159 34819 4229 4202496 6515 0 362 0 115 8 0 0 18 0 1 0 880488248 103890944 6800 1283457024 134512640 134619611 4286709920 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/15985/statm: 25364 6800 6747 27 0 58 0
Current children cumulated CPU time (s) 11.01
Current children cumulated vsize (KiB) 104048

[startup+13.712 s]
/proc/loadavg: 1.00 1.00 1.00 1/42 15985
/proc/meminfo: memFree=751728/1048576 swapFree=2080272/2097144
[pid=15964] ppid=15963 vsize=2592 CPUtime=9.78
/proc/15964/stat : 15964 (apt-get-trendy-) S 15963 15964 4159 34819 4229 4202496 706 40796 0 1 0 0 945 33 18 0 1 0 880487149 2654208 295 1283457024 134512640 135304128 4291577520 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/15964/statm: 648 295 249 194 0 34 0
[pid=15985] ppid=15964 vsize=31556 CPUtime=1.43
/proc/15985/stat : 15985 (apt-get) R 15964 15964 4159 34819 4229 4202496 13110 0 362 0 133 10 0 0 18 0 1 0 880488248 32313344 7003 1283457024 134512640 134619611 4286709920 18446744073709551615 4160037958 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/15985/statm: 7889 7003 6409 27 0 599 0
Current children cumulated CPU time (s) 11.21
Current children cumulated vsize (KiB) 34148

Child status: 100
Real time (s): 13.8009
CPU time (s): 11.3047
CPU user time (s): 10.8647
CPU system time (s): 0.440027
CPU usage (%): 81.9131
Max. virtual memory (cumulated for all children) (KiB): 148800

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 10.8647
system time used= 0.440027
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 54742
page faults= 363
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 408
involuntary context switches= 217

runsolver used 0 second user time and 0.012 second system time

The end