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/rand7902a8.cudf.impossible.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/impossible//rand7902a8.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/rand7902a8.cudf.impossible.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.03 1.04 1.03 4/47 21882
/proc/meminfo: memFree=806288/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2576 CPUtime=0
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 419 356 0 0 0 0 0 0 18 0 1 0 881888790 2637824 277 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 644 277 235 194 0 30 0
[pid=21882] ppid=21879 vsize=2576 CPUtime=0
/proc/21882/stat : 21882 (apt-get-trendy-) R 21879 21879 4159 34819 4229 4202560 20 0 0 0 0 0 0 0 25 0 1 0 881888791 2637824 57 1283457024 134512640 135304128 4287791952 18446744073709551615 135192088 0 65538 4 65536 0 0 0 17 0 0 0 0
/proc/21882/statm: 644 57 14 194 0 30 0

[startup+0.165436 s]
/proc/loadavg: 1.03 1.04 1.03 4/47 21882
/proc/meminfo: memFree=806288/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2584 CPUtime=0
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 519 1361 0 0 0 0 0 0 25 0 1 0 881888790 2646016 281 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 646 281 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.205471 s]
/proc/loadavg: 1.03 1.04 1.03 4/47 21882
/proc/meminfo: memFree=806288/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2584 CPUtime=0
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 519 1361 0 0 0 0 0 0 25 0 1 0 881888790 2646016 281 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 646 281 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.305447 s]
/proc/loadavg: 1.03 1.04 1.03 4/47 21882
/proc/meminfo: memFree=806288/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2584 CPUtime=0
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 519 1361 0 0 0 0 0 0 25 0 1 0 881888790 2646016 281 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 646 281 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.705491 s]
/proc/loadavg: 1.03 1.04 1.03 4/47 21882
/proc/meminfo: memFree=806288/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2584 CPUtime=0
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 519 1361 0 0 0 0 0 0 25 0 1 0 881888790 2646016 281 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 646 281 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+1.50477 s]
/proc/loadavg: 1.03 1.04 1.03 2/48 21890
/proc/meminfo: memFree=745544/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2584 CPUtime=0.01
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 568 1860 0 0 0 0 0 1 18 0 1 0 881888790 2646016 284 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 646 284 240 194 0 32 0
[pid=21890] ppid=21879 vsize=18312 CPUtime=0.7
/proc/21890/stat : 21890 (cudftodeb.nativ) R 21879 21879 4159 34819 4229 4202496 4157 0 0 0 70 0 0 0 22 0 1 0 881888870 18751488 4083 1283457024 134512640 135004320 4286673552 18446744073709551615 134945035 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/21890/statm: 4578 4083 225 121 0 3970 0
Current children cumulated CPU time (s) 0.71
Current children cumulated vsize (KiB) 20896

[startup+3.10517 s]
/proc/loadavg: 1.03 1.04 1.03 2/48 21890
/proc/meminfo: memFree=722232/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2584 CPUtime=0.01
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 568 1860 0 0 0 0 0 1 18 0 1 0 881888790 2646016 284 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 646 284 240 194 0 32 0
[pid=21890] ppid=21879 vsize=50500 CPUtime=2.3
/proc/21890/stat : 21890 (cudftodeb.nativ) R 21879 21879 4159 34819 4229 4202496 12133 0 0 0 227 3 0 0 25 0 1 0 881888870 51712000 12059 1283457024 134512640 135004320 4286673552 18446744073709551615 134996501 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/21890/statm: 12625 12059 225 121 0 12017 0
Current children cumulated CPU time (s) 2.31
Current children cumulated vsize (KiB) 53084
heavy processes:

[startup+6.30584 s]
/proc/loadavg: 1.11 1.05 1.04 2/48 21890
/proc/meminfo: memFree=662588/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2584 CPUtime=0.01
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 568 1860 0 0 0 0 0 1 18 0 1 0 881888790 2646016 284 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 646 284 240 194 0 32 0
[pid=21890] ppid=21879 vsize=109532 CPUtime=5.49
/proc/21890/stat : 21890 (cudftodeb.nativ) R 21879 21879 4159 34819 4229 4202496 26626 0 0 0 543 6 0 0 25 0 1 0 881888870 112160768 26552 1283457024 134512640 135004320 4286673552 18446744073709551615 134943996 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/21890/statm: 27383 26552 225 121 0 26775 0
Current children cumulated CPU time (s) 5.5
Current children cumulated vsize (KiB) 112116

[startup+12.7083 s]
/proc/loadavg: 1.10 1.05 1.04 2/48 21890
/proc/meminfo: memFree=562272/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2584 CPUtime=0.01
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 568 1860 0 0 0 0 0 1 18 0 1 0 881888790 2646016 284 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 646 284 240 194 0 32 0
[pid=21890] ppid=21879 vsize=181756 CPUtime=11.89
/proc/21890/stat : 21890 (cudftodeb.nativ) R 21879 21879 4159 34819 4229 4202496 44419 0 0 0 1173 16 0 0 25 0 1 0 881888870 186118144 44345 1283457024 134512640 135004320 4286673552 18446744073709551615 134868890 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/21890/statm: 45439 44345 237 121 0 44831 0
Current children cumulated CPU time (s) 11.9
Current children cumulated vsize (KiB) 184340

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

[startup+12.8083 s]
/proc/loadavg: 1.10 1.05 1.04 2/48 21890
/proc/meminfo: memFree=562272/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2584 CPUtime=0.01
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 568 1860 0 0 0 0 0 1 18 0 1 0 881888790 2646016 284 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 646 284 240 194 0 32 0
[pid=21890] ppid=21879 vsize=181756 CPUtime=11.99
/proc/21890/stat : 21890 (cudftodeb.nativ) R 21879 21879 4159 34819 4229 4202496 44419 0 0 0 1183 16 0 0 25 0 1 0 881888870 186118144 44345 1283457024 134512640 135004320 4286673552 18446744073709551615 134996781 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/21890/statm: 45439 44345 237 121 0 44831 0
Current children cumulated CPU time (s) 12
Current children cumulated vsize (KiB) 184340

[startup+16.0064 s]
/proc/loadavg: 1.09 1.05 1.04 1/48 21898
/proc/meminfo: memFree=680820/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2592 CPUtime=13.54
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 646 47064 0 0 0 0 1330 24 21 0 1 0 881888790 2654208 287 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 648 287 241 194 0 34 0
[pid=21894] ppid=21879 vsize=101500 CPUtime=0.41
/proc/21894/stat : 21894 (apt-get) D 21879 21879 4159 34819 4229 4202496 553 1681 1 0 0 0 37 4 23 0 1 0 881890226 103936000 422 1283457024 134512640 134619611 4289104640 18446744073709551615 4294960130 0 0 4096 134217728 18446744071696460772 0 0 17 0 0 0 0
/proc/21894/statm: 25375 422 374 27 0 69 0
Current children cumulated CPU time (s) 13.95
Current children cumulated vsize (KiB) 104092

[startup+19.2066 s]
/proc/loadavg: 1.08 1.05 1.04 1/48 21900
/proc/meminfo: memFree=605376/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2596 CPUtime=14.03
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 704 49573 0 1 0 0 1372 31 18 0 1 0 881888790 2658304 296 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 649 296 249 194 0 35 0
[pid=21900] ppid=21879 vsize=101452 CPUtime=2.03
/proc/21900/stat : 21900 (apt-get) R 21879 21879 4159 34819 4229 4202496 9351 0 534 0 190 13 0 0 18 0 1 0 881890426 103886848 9809 1283457024 134512640 134619611 4292883472 18446744073709551615 4159876417 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/21900/statm: 25363 9809 9756 27 0 57 0
Current children cumulated CPU time (s) 16.06
Current children cumulated vsize (KiB) 104048

[startup+20.0067 s]
/proc/loadavg: 1.08 1.05 1.04 2/48 21900
/proc/meminfo: memFree=604700/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2596 CPUtime=14.03
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 704 49573 0 1 0 0 1372 31 18 0 1 0 881888790 2658304 296 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 649 296 249 194 0 35 0
[pid=21900] ppid=21879 vsize=101452 CPUtime=2.04
/proc/21900/stat : 21900 (apt-get) D 21879 21879 4159 34819 4229 4202496 9365 0 535 0 190 14 0 0 18 0 1 0 881890426 103886848 9824 1283457024 134512640 134619611 4292883472 18446744073709551615 4294960130 0 0 4096 134217728 18446744071696460772 0 0 17 0 0 0 0
/proc/21900/statm: 25363 9824 9771 27 0 57 0
Current children cumulated CPU time (s) 16.07
Current children cumulated vsize (KiB) 104048

[startup+20.415 s]
/proc/loadavg: 1.08 1.05 1.04 2/48 21900
/proc/meminfo: memFree=604700/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2596 CPUtime=14.03
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 704 49573 0 1 0 0 1372 31 18 0 1 0 881888790 2658304 296 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 649 296 249 194 0 35 0
[pid=21900] ppid=21879 vsize=44408 CPUtime=2.44
/proc/21900/stat : 21900 (apt-get) R 21879 21879 4159 34819 4229 4202496 19057 0 535 0 229 15 0 0 18 0 1 0 881890426 45473792 10050 1283457024 134512640 134619611 4292883472 18446744073709551615 4159890080 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/21900/statm: 11102 10050 9286 27 0 789 0
Current children cumulated CPU time (s) 16.47
Current children cumulated vsize (KiB) 47004

[startup+20.6151 s]
/proc/loadavg: 1.08 1.05 1.04 2/48 21900
/proc/meminfo: memFree=604700/1048576 swapFree=2072372/2097144
[pid=21879] ppid=21878 vsize=2596 CPUtime=14.03
/proc/21879/stat : 21879 (apt-get-trendy-) S 21878 21879 4159 34819 4229 4202496 704 49573 0 1 0 0 1372 31 18 0 1 0 881888790 2658304 296 1283457024 134512640 135304128 4287791952 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/21879/statm: 649 296 249 194 0 35 0
[pid=21900] ppid=21879 vsize=44408 CPUtime=2.64
/proc/21900/stat : 21900 (apt-get) R 21879 21879 4159 34819 4229 4202496 19057 0 535 0 249 15 0 0 18 0 1 0 881890426 45473792 10050 1283457024 134512640 134619611 4292883472 18446744073709551615 4160289020 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/21900/statm: 11102 10050 9286 27 0 789 0
Current children cumulated CPU time (s) 16.67
Current children cumulated vsize (KiB) 47004

Child status: 100
Real time (s): 20.7022
CPU time (s): 16.765
CPU user time (s): 16.285
CPU system time (s): 0.48003
CPU usage (%): 80.982
Max. virtual memory (cumulated for all children) (KiB): 184340

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 16.285
system time used= 0.48003
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 69353
page faults= 536
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 502
involuntary context switches= 276

runsolver used 0 second user time and 0 second system time

The end