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/7266f636-4b23-11df-9e6e-00163e7a6f5e.cudf.debian-dudf.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/debian-dudf//7266f636-4b23-11df-9e6e-00163e7a6f5e.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/7266f636-4b23-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.85 0.98 0.99 2/45 31240
/proc/meminfo: memFree=873152/1048576 swapFree=2077436/2097144
[pid=31232] ppid=31231 vsize=2584 CPUtime=0
/proc/31232/stat : 31232 (apt-get-trendy-) S 31231 31232 4159 34819 4229 4202496 519 1365 0 0 0 0 0 0 25 0 1 0 884210751 2646016 281 1283457024 134512640 135304128 4288226176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31232/statm: 646 281 237 194 0 32 0
[pid=31240] ppid=31232 vsize=372 CPUtime=0
/proc/31240/stat : 31240 (cp) R 31232 31232 4159 34819 4229 4194304 98 0 0 0 0 0 0 0 25 0 1 0 884210752 380928 37 1283457024 134512640 134614052 4291884976 18446744073709551615 4160055655 0 0 0 0 0 0 0 17 0 0 0 0
/proc/31240/statm: 93 37 27 25 0 7 0

[startup+0.19617 s]
/proc/loadavg: 0.85 0.98 0.99 2/45 31240
/proc/meminfo: memFree=873152/1048576 swapFree=2077436/2097144
[pid=31232] ppid=31231 vsize=2584 CPUtime=0
/proc/31232/stat : 31232 (apt-get-trendy-) S 31231 31232 4159 34819 4229 4202496 519 1365 0 0 0 0 0 0 25 0 1 0 884210751 2646016 281 1283457024 134512640 135304128 4288226176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31232/statm: 646 281 237 194 0 32 0
[pid=31240] ppid=31232 vsize=2008 CPUtime=0.01
/proc/31240/stat : 31240 (cp) R 31232 31232 4159 34819 4229 4202496 254 0 0 0 0 1 0 0 24 0 1 0 884210752 2056192 183 1283457024 134512640 134614052 4291884976 18446744073709551615 4294960130 0 0 0 0 0 0 0 17 0 0 0 0
/proc/31240/statm: 502 183 145 25 0 48 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 4592

[startup+0.203841 s]
/proc/loadavg: 0.85 0.98 0.99 2/45 31240
/proc/meminfo: memFree=873152/1048576 swapFree=2077436/2097144
[pid=31232] ppid=31231 vsize=2584 CPUtime=0
/proc/31232/stat : 31232 (apt-get-trendy-) S 31231 31232 4159 34819 4229 4202496 519 1365 0 0 0 0 0 0 25 0 1 0 884210751 2646016 281 1283457024 134512640 135304128 4288226176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31232/statm: 646 281 237 194 0 32 0
[pid=31240] ppid=31232 vsize=2008 CPUtime=0.01
/proc/31240/stat : 31240 (cp) D 31232 31232 4159 34819 4229 4202496 254 0 0 0 0 1 0 0 24 0 1 0 884210752 2056192 183 1283457024 134512640 134614052 4291884976 18446744073709551615 4294960130 0 0 0 0 18446744071564332000 0 0 17 0 0 0 0
/proc/31240/statm: 502 183 145 25 0 48 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 4592

[startup+0.307851 s]
/proc/loadavg: 0.85 0.98 0.99 2/45 31240
/proc/meminfo: memFree=873152/1048576 swapFree=2077436/2097144
[pid=31232] ppid=31231 vsize=2584 CPUtime=0
/proc/31232/stat : 31232 (apt-get-trendy-) S 31231 31232 4159 34819 4229 4202496 519 1365 0 0 0 0 0 0 25 0 1 0 884210751 2646016 281 1283457024 134512640 135304128 4288226176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31232/statm: 646 281 237 194 0 32 0
[pid=31240] ppid=31232 vsize=2008 CPUtime=0.01
/proc/31240/stat : 31240 (cp) R 31232 31232 4159 34819 4229 4202496 254 0 0 0 0 1 0 0 24 0 1 0 884210752 2056192 183 1283457024 134512640 134614052 4291884976 18446744073709551615 4294960130 0 0 0 0 0 0 0 17 0 0 0 0
/proc/31240/statm: 502 183 145 25 0 48 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 4592

[startup+0.710916 s]
/proc/loadavg: 0.85 0.98 0.99 2/45 31240
/proc/meminfo: memFree=873152/1048576 swapFree=2077436/2097144
[pid=31232] ppid=31231 vsize=2584 CPUtime=0.02
/proc/31232/stat : 31232 (apt-get-trendy-) S 31231 31232 4159 34819 4229 4202496 568 1865 0 0 0 0 0 2 22 0 1 0 884210751 2646016 284 1283457024 134512640 135304128 4288226176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31232/statm: 646 284 240 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 2584

[startup+1.5111 s]
/proc/loadavg: 0.86 0.98 0.99 2/46 31243
/proc/meminfo: memFree=814572/1048576 swapFree=2077436/2097144
[pid=31232] ppid=31231 vsize=2584 CPUtime=0.02
/proc/31232/stat : 31232 (apt-get-trendy-) S 31231 31232 4159 34819 4229 4202496 568 1865 0 0 0 0 0 2 22 0 1 0 884210751 2646016 284 1283457024 134512640 135304128 4288226176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31232/statm: 646 284 240 194 0 32 0
[pid=31243] ppid=31232 vsize=25252 CPUtime=1.17
/proc/31243/stat : 31243 (cudftodeb.nativ) R 31232 31232 4159 34819 4229 4202496 5929 0 0 0 116 1 0 0 25 0 1 0 884210785 25858048 5855 1283457024 134512640 135004320 4291217088 18446744073709551615 134948024 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/31243/statm: 6313 5855 225 121 0 5705 0
Current children cumulated CPU time (s) 1.19
Current children cumulated vsize (KiB) 27836

[startup+3.11153 s]
/proc/loadavg: 0.86 0.98 0.99 2/46 31243
/proc/meminfo: memFree=793864/1048576 swapFree=2077436/2097144
[pid=31232] ppid=31231 vsize=2584 CPUtime=0.02
/proc/31232/stat : 31232 (apt-get-trendy-) S 31231 31232 4159 34819 4229 4202496 568 1865 0 0 0 0 0 2 22 0 1 0 884210751 2646016 284 1283457024 134512640 135304128 4288226176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31232/statm: 646 284 240 194 0 32 0
[pid=31243] ppid=31232 vsize=54224 CPUtime=2.75
/proc/31243/stat : 31243 (cudftodeb.nativ) R 31232 31232 4159 34819 4229 4202496 13015 0 0 0 271 4 0 0 25 0 1 0 884210785 55525376 12936 1283457024 134512640 135004320 4291217088 18446744073709551615 134949674 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/31243/statm: 13556 12936 225 121 0 12948 0
Current children cumulated CPU time (s) 2.77
Current children cumulated vsize (KiB) 56808

[startup+6.31241 s]
/proc/loadavg: 0.87 0.98 0.99 2/46 31243
/proc/meminfo: memFree=736204/1048576 swapFree=2077436/2097144
[pid=31232] ppid=31231 vsize=2584 CPUtime=0.02
/proc/31232/stat : 31232 (apt-get-trendy-) S 31231 31232 4159 34819 4229 4202496 568 1865 0 0 0 0 0 2 22 0 1 0 884210751 2646016 284 1283457024 134512640 135304128 4288226176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31232/statm: 646 284 240 194 0 32 0
[pid=31243] ppid=31232 vsize=110268 CPUtime=5.95
/proc/31243/stat : 31243 (cudftodeb.nativ) R 31232 31232 4159 34819 4229 4202496 26825 0 0 0 586 9 0 0 25 0 1 0 884210785 112914432 26746 1283457024 134512640 135004320 4291217088 18446744073709551615 134996501 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/31243/statm: 27567 26746 237 121 0 26959 0
Current children cumulated CPU time (s) 5.97
Current children cumulated vsize (KiB) 112852

[startup+12.7047 s]
/proc/loadavg: 1.04 1.02 1.00 2/46 31253
/proc/meminfo: memFree=732816/1048576 swapFree=2077436/2097144
[pid=31232] ppid=31231 vsize=2592 CPUtime=8.99
/proc/31232/stat : 31232 (apt-get-trendy-) S 31231 31232 4159 34819 4229 4202496 703 34268 0 1 0 0 873 26 18 0 1 0 884210751 2654208 295 1283457024 134512640 135304128 4288226176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31232/statm: 648 295 249 194 0 34 0
[pid=31253] ppid=31232 vsize=101452 CPUtime=1.25
/proc/31253/stat : 31253 (apt-get) D 31232 31232 4159 34819 4229 4202496 6530 0 363 0 121 4 0 0 18 0 1 0 884211787 103886848 6817 1283457024 134512640 134619611 4291276032 18446744073709551615 4294960130 0 0 4096 134217728 18446744071696460772 0 0 17 0 0 0 0
/proc/31253/statm: 25363 6817 6764 27 0 57 0
Current children cumulated CPU time (s) 10.24
Current children cumulated vsize (KiB) 104044

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

[startup+12.8126 s]
/proc/loadavg: 1.04 1.02 1.00 2/46 31253
/proc/meminfo: memFree=732816/1048576 swapFree=2077436/2097144
[pid=31232] ppid=31231 vsize=2592 CPUtime=8.99
/proc/31232/stat : 31232 (apt-get-trendy-) S 31231 31232 4159 34819 4229 4202496 703 34268 0 1 0 0 873 26 18 0 1 0 884210751 2654208 295 1283457024 134512640 135304128 4288226176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31232/statm: 648 295 249 194 0 34 0
[pid=31253] ppid=31232 vsize=31604 CPUtime=1.33
/proc/31253/stat : 31253 (apt-get) R 31232 31232 4159 34819 4229 4202496 13102 0 363 0 127 6 0 0 18 0 1 0 884211787 32362496 6980 1283457024 134512640 134619611 4291276032 18446744073709551615 4159903076 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/31253/statm: 7901 6980 6385 27 0 599 0
Current children cumulated CPU time (s) 10.32
Current children cumulated vsize (KiB) 34196

[startup+13.0062 s]
/proc/loadavg: 1.04 1.02 1.00 2/46 31253
/proc/meminfo: memFree=732816/1048576 swapFree=2077436/2097144
[pid=31232] ppid=31231 vsize=2592 CPUtime=8.99
/proc/31232/stat : 31232 (apt-get-trendy-) S 31231 31232 4159 34819 4229 4202496 703 34268 0 1 0 0 873 26 18 0 1 0 884210751 2654208 295 1283457024 134512640 135304128 4288226176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/31232/statm: 648 295 249 194 0 34 0
[pid=31253] ppid=31232 vsize=30384 CPUtime=1.53
/proc/31253/stat : 31253 (apt-get) R 31232 31232 4159 34819 4229 4202496 13259 0 363 0 145 8 0 0 18 0 1 0 884211787 31113216 6743 1283457024 134512640 134619611 4291276032 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/31253/statm: 7596 6743 6452 27 0 294 0
Current children cumulated CPU time (s) 10.52
Current children cumulated vsize (KiB) 32976

Child status: 100
Real time (s): 13.0132
CPU time (s): 10.5367
CPU user time (s): 10.1926
CPU system time (s): 0.344021
CPU usage (%): 80.969
Max. virtual memory (cumulated for all children) (KiB): 117564

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 10.1926
system time used= 0.344021
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 48243
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= 411
involuntary context switches= 218

runsolver used 0 second user time and 0 second system time

The end