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/rand7b4167.cudf.difficult.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/difficult//rand7b4167.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/rand7b4167.cudf.difficult.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.04 1.06 1.01 2/45 29222
/proc/meminfo: memFree=643176/1048576 swapFree=2077628/2097144
[pid=29214] ppid=29213 vsize=2580 CPUtime=0
/proc/29214/stat : 29214 (apt-get-trendy-) S 29213 29214 4159 34819 4229 4202496 506 1359 0 0 0 0 0 0 25 0 1 0 883635268 2641920 279 1283457024 134512640 135304128 4291075696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29214/statm: 645 279 237 194 0 31 0
[pid=29222] ppid=29214 vsize=2008 CPUtime=0
/proc/29222/stat : 29222 (cp) D 29214 29214 4159 34819 4229 4202496 238 0 0 0 0 0 0 0 25 0 1 0 883635269 2056192 168 1283457024 134512640 134614052 4294400560 18446744073709551615 4294960130 0 0 0 0 18446744071564252162 0 0 17 0 0 0 0
/proc/29222/statm: 502 168 139 25 0 48 0

[startup+0.184335 s]
/proc/loadavg: 1.04 1.06 1.01 2/45 29222
/proc/meminfo: memFree=643176/1048576 swapFree=2077628/2097144
[pid=29214] ppid=29213 vsize=2580 CPUtime=0
/proc/29214/stat : 29214 (apt-get-trendy-) S 29213 29214 4159 34819 4229 4202496 506 1359 0 0 0 0 0 0 25 0 1 0 883635268 2641920 279 1283457024 134512640 135304128 4291075696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29214/statm: 645 279 237 194 0 31 0
[pid=29222] ppid=29214 vsize=2008 CPUtime=0
/proc/29222/stat : 29222 (cp) D 29214 29214 4159 34819 4229 4202496 253 0 0 0 0 0 0 0 24 0 1 0 883635269 2056192 183 1283457024 134512640 134614052 4294400560 18446744073709551615 4294960130 0 0 0 0 18446744071564332000 0 0 17 0 0 0 0
/proc/29222/statm: 502 183 145 25 0 48 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 4588

[startup+0.204336 s]
/proc/loadavg: 1.04 1.06 1.01 2/45 29222
/proc/meminfo: memFree=643176/1048576 swapFree=2077628/2097144
[pid=29214] ppid=29213 vsize=2580 CPUtime=0
/proc/29214/stat : 29214 (apt-get-trendy-) S 29213 29214 4159 34819 4229 4202496 506 1359 0 0 0 0 0 0 25 0 1 0 883635268 2641920 279 1283457024 134512640 135304128 4291075696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29214/statm: 645 279 237 194 0 31 0
[pid=29222] ppid=29214 vsize=2008 CPUtime=0
/proc/29222/stat : 29222 (cp) D 29214 29214 4159 34819 4229 4202496 253 0 0 0 0 0 0 0 24 0 1 0 883635269 2056192 183 1283457024 134512640 134614052 4294400560 18446744073709551615 4294960130 0 0 0 0 18446744071564332000 0 0 17 0 0 0 0
/proc/29222/statm: 502 183 145 25 0 48 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 4588

[startup+0.304323 s]
/proc/loadavg: 1.04 1.06 1.01 2/45 29222
/proc/meminfo: memFree=643176/1048576 swapFree=2077628/2097144
[pid=29214] ppid=29213 vsize=2580 CPUtime=0
/proc/29214/stat : 29214 (apt-get-trendy-) S 29213 29214 4159 34819 4229 4202496 552 1858 0 0 0 0 0 0 23 0 1 0 883635268 2641920 282 1283457024 134512640 135304128 4291075696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29214/statm: 645 282 240 194 0 31 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2580

[startup+0.704591 s]
/proc/loadavg: 1.04 1.06 1.01 2/45 29222
/proc/meminfo: memFree=643176/1048576 swapFree=2077628/2097144
[pid=29214] ppid=29213 vsize=2580 CPUtime=0
/proc/29214/stat : 29214 (apt-get-trendy-) S 29213 29214 4159 34819 4229 4202496 552 1858 0 0 0 0 0 0 23 0 1 0 883635268 2641920 282 1283457024 134512640 135304128 4291075696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29214/statm: 645 282 240 194 0 31 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2580

[startup+1.50488 s]
/proc/loadavg: 1.04 1.06 1.01 2/46 29225
/proc/meminfo: memFree=598536/1048576 swapFree=2077628/2097144
[pid=29214] ppid=29213 vsize=2580 CPUtime=0
/proc/29214/stat : 29214 (apt-get-trendy-) S 29213 29214 4159 34819 4229 4202496 552 1858 0 0 0 0 0 0 23 0 1 0 883635268 2641920 282 1283457024 134512640 135304128 4291075696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29214/statm: 645 282 240 194 0 31 0
[pid=29225] ppid=29214 vsize=30032 CPUtime=1.28
/proc/29225/stat : 29225 (cudftodeb.nativ) R 29214 29214 4159 34819 4229 4202496 7073 0 0 0 123 5 0 0 25 0 1 0 883635290 30752768 7000 1283457024 134512640 135004320 4291016368 18446744073709551615 134949961 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/29225/statm: 7508 7000 225 121 0 6900 0
Current children cumulated CPU time (s) 1.28
Current children cumulated vsize (KiB) 32612

[startup+3.1053 s]
/proc/loadavg: 1.04 1.06 1.01 2/46 29225
/proc/meminfo: memFree=575844/1048576 swapFree=2077628/2097144
[pid=29214] ppid=29213 vsize=2580 CPUtime=0
/proc/29214/stat : 29214 (apt-get-trendy-) S 29213 29214 4159 34819 4229 4202496 552 1858 0 0 0 0 0 0 23 0 1 0 883635268 2641920 282 1283457024 134512640 135304128 4291075696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29214/statm: 645 282 240 194 0 31 0
[pid=29225] ppid=29214 vsize=64388 CPUtime=2.87
/proc/29225/stat : 29225 (cudftodeb.nativ) R 29214 29214 4159 34819 4229 4202496 15508 0 0 0 277 10 0 0 25 0 1 0 883635290 65933312 15435 1283457024 134512640 135004320 4291016368 18446744073709551615 4160190489 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/29225/statm: 16097 15435 236 121 0 15489 0
Current children cumulated CPU time (s) 2.87
Current children cumulated vsize (KiB) 66968

[startup+6.30473 s]
/proc/loadavg: 1.04 1.06 1.01 2/46 29225
/proc/meminfo: memFree=514216/1048576 swapFree=2077628/2097144
[pid=29214] ppid=29213 vsize=2588 CPUtime=5.54
/proc/29214/stat : 29214 (apt-get-trendy-) S 29213 29214 4159 34819 4229 4202496 632 25957 0 0 0 0 532 22 20 0 1 0 883635268 2650112 285 1283457024 134512640 135304128 4291075696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29214/statm: 647 285 241 194 0 33 0
Current children cumulated CPU time (s) 5.54
Current children cumulated vsize (KiB) 2588

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

[startup+6.40474 s]
/proc/loadavg: 1.04 1.06 1.01 2/46 29225
/proc/meminfo: memFree=514216/1048576 swapFree=2077628/2097144
[pid=29214] ppid=29213 vsize=2588 CPUtime=5.54
/proc/29214/stat : 29214 (apt-get-trendy-) S 29213 29214 4159 34819 4229 4202496 632 25957 0 0 0 0 532 22 20 0 1 0 883635268 2650112 285 1283457024 134512640 135304128 4291075696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29214/statm: 647 285 241 194 0 33 0
Current children cumulated CPU time (s) 5.54
Current children cumulated vsize (KiB) 2588

[startup+8.00482 s]
/proc/loadavg: 1.04 1.06 1.01 1/46 29235
/proc/meminfo: memFree=545104/1048576 swapFree=2077628/2097144
[pid=29214] ppid=29213 vsize=2588 CPUtime=5.78
/proc/29214/stat : 29214 (apt-get-trendy-) S 29213 29214 4159 34819 4229 4202496 686 28465 0 1 0 0 554 24 18 0 1 0 883635268 2650112 293 1283457024 134512640 135304128 4291075696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29214/statm: 647 293 249 194 0 33 0
[pid=29235] ppid=29214 vsize=101452 CPUtime=0.85
/proc/29235/stat : 29235 (apt-get) D 29214 29214 4159 34819 4229 4202496 4909 0 264 0 77 8 0 0 19 0 1 0 883635940 103886848 5098 1283457024 134512640 134619611 4291388208 18446744073709551615 4294960130 0 0 4096 134217728 18446744071696460772 0 0 17 0 0 0 0
/proc/29235/statm: 25363 5098 5045 27 0 57 0
Current children cumulated CPU time (s) 6.63
Current children cumulated vsize (KiB) 104040

[startup+8.40485 s]
/proc/loadavg: 1.04 1.06 1.01 1/46 29235
/proc/meminfo: memFree=545104/1048576 swapFree=2077628/2097144
[pid=29214] ppid=29213 vsize=2588 CPUtime=5.78
/proc/29214/stat : 29214 (apt-get-trendy-) S 29213 29214 4159 34819 4229 4202496 686 28465 0 1 0 0 554 24 18 0 1 0 883635268 2650112 293 1283457024 134512640 135304128 4291075696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29214/statm: 647 293 249 194 0 33 0
[pid=29235] ppid=29214 vsize=101452 CPUtime=0.88
/proc/29235/stat : 29235 (apt-get) D 29214 29214 4159 34819 4229 4202496 4950 0 266 0 79 9 0 0 18 0 1 0 883635940 103886848 5141 1283457024 134512640 134619611 4291388208 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/29235/statm: 25363 5141 5088 27 0 57 0
Current children cumulated CPU time (s) 6.66
Current children cumulated vsize (KiB) 104040

[startup+8.60485 s]
/proc/loadavg: 1.04 1.06 1.01 1/46 29235
/proc/meminfo: memFree=545104/1048576 swapFree=2077628/2097144
[pid=29214] ppid=29213 vsize=2588 CPUtime=5.78
/proc/29214/stat : 29214 (apt-get-trendy-) S 29213 29214 4159 34819 4229 4202496 686 28465 0 1 0 0 554 24 18 0 1 0 883635268 2650112 293 1283457024 134512640 135304128 4291075696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29214/statm: 647 293 249 194 0 33 0
[pid=29235] ppid=29214 vsize=24684 CPUtime=0.91
/proc/29235/stat : 29235 (apt-get) R 29214 29214 4159 34819 4229 4202496 8168 0 266 0 81 10 0 0 18 0 1 0 883635940 25276416 3626 1283457024 134512640 134619611 4291388208 18446744073709551615 4159823618 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/29235/statm: 6171 3626 3088 27 0 542 0
Current children cumulated CPU time (s) 6.69
Current children cumulated vsize (KiB) 27272

[startup+8.71398 s]
/proc/loadavg: 1.04 1.06 1.01 1/46 29235
/proc/meminfo: memFree=545104/1048576 swapFree=2077628/2097144
[pid=29214] ppid=29213 vsize=2588 CPUtime=5.78
/proc/29214/stat : 29214 (apt-get-trendy-) S 29213 29214 4159 34819 4229 4202496 686 28465 0 1 0 0 554 24 18 0 1 0 883635268 2650112 293 1283457024 134512640 135304128 4291075696 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29214/statm: 647 293 249 194 0 33 0
[pid=29235] ppid=29214 vsize=24684 CPUtime=1.02
/proc/29235/stat : 29235 (apt-get) R 29214 29214 4159 34819 4229 4202496 9918 0 266 0 92 10 0 0 18 0 1 0 883635940 25276416 5376 1283457024 134512640 134619611 4291388208 18446744073709551615 4159722666 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/29235/statm: 6171 5376 4838 27 0 542 0
Current children cumulated CPU time (s) 6.8
Current children cumulated vsize (KiB) 27272

Child status: 100
Real time (s): 8.77025
CPU time (s): 6.88843
CPU user time (s): 6.52441
CPU system time (s): 0.364022
CPU usage (%): 78.5432
Max. virtual memory (cumulated for all children) (KiB): 104088

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 6.52441
system time used= 0.364022
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 39206
page faults= 267
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 281
involuntary context switches= 158

runsolver used 0 second user time and 0 second system time

The end