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/rand655e63.cudf.impossible.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/impossible//rand655e63.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/rand655e63.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.06 1.01 1.00 4/41 14173
/proc/meminfo: memFree=756236/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2572 CPUtime=0
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 398 156 0 0 0 0 0 0 18 0 1 0 879901942 2633728 276 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 643 276 235 194 0 29 0
[pid=14173] ppid=14171 vsize=196 CPUtime=0
/proc/14173/stat : 14173 (mkdir) R 14171 14171 4159 34819 4229 4194304 88 0 0 0 0 0 0 0 25 0 1 0 879901942 200704 28 1283457024 134512640 134551716 4293341472 18446744073709551615 4160566051 0 0 0 0 0 0 0 17 0 0 0 0
/proc/14173/statm: 49 28 22 10 0 5 0

[startup+0.180798 s]
/proc/loadavg: 1.06 1.01 1.00 4/41 14173
/proc/meminfo: memFree=756236/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2580 CPUtime=0
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 516 1357 0 0 0 0 0 0 25 0 1 0 879901942 2641920 280 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 645 280 237 194 0 31 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2580

[startup+0.204759 s]
/proc/loadavg: 1.06 1.01 1.00 4/41 14173
/proc/meminfo: memFree=756236/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2580 CPUtime=0
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 516 1357 0 0 0 0 0 0 25 0 1 0 879901942 2641920 280 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 645 280 237 194 0 31 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2580

[startup+0.304768 s]
/proc/loadavg: 1.06 1.01 1.00 4/41 14173
/proc/meminfo: memFree=756236/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2580 CPUtime=0
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 516 1357 0 0 0 0 0 0 25 0 1 0 879901942 2641920 280 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 645 280 237 194 0 31 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2580

[startup+0.711689 s]
/proc/loadavg: 1.06 1.01 1.00 4/41 14173
/proc/meminfo: memFree=756236/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2580 CPUtime=0
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 565 1855 0 0 0 0 0 0 21 0 1 0 879901942 2641920 283 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 645 283 240 194 0 31 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2580

[startup+1.51189 s]
/proc/loadavg: 1.14 1.02 1.00 2/42 14182
/proc/meminfo: memFree=688540/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2580 CPUtime=0
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 565 1855 0 0 0 0 0 0 21 0 1 0 879901942 2641920 283 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 645 283 240 194 0 31 0
[pid=14182] ppid=14171 vsize=24756 CPUtime=1.03
/proc/14182/stat : 14182 (cudftodeb.nativ) R 14171 14171 4159 34819 4229 4202496 5805 0 0 0 99 4 0 0 25 0 1 0 879901989 25350144 5732 1283457024 134512640 135004320 4286646912 18446744073709551615 134950940 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/14182/statm: 6189 5732 225 121 0 5581 0
Current children cumulated CPU time (s) 1.03
Current children cumulated vsize (KiB) 27336

[startup+3.11217 s]
/proc/loadavg: 1.14 1.02 1.00 2/42 14182
/proc/meminfo: memFree=665732/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2580 CPUtime=0
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 565 1855 0 0 0 0 0 0 21 0 1 0 879901942 2641920 283 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 645 283 240 194 0 31 0
[pid=14182] ppid=14171 vsize=58184 CPUtime=2.64
/proc/14182/stat : 14182 (cudftodeb.nativ) R 14171 14171 4159 34819 4229 4202496 14008 0 0 0 256 8 0 0 25 0 1 0 879901989 59580416 13933 1283457024 134512640 135004320 4286646912 18446744073709551615 134946100 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/14182/statm: 14546 13933 225 121 0 13938 0
Current children cumulated CPU time (s) 2.64
Current children cumulated vsize (KiB) 60764

[startup+6.31271 s]
/proc/loadavg: 1.20 1.04 1.01 2/42 14182
/proc/meminfo: memFree=605840/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2580 CPUtime=0
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 565 1855 0 0 0 0 0 0 21 0 1 0 879901942 2641920 283 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 645 283 240 194 0 31 0
[pid=14182] ppid=14171 vsize=116424 CPUtime=5.83
/proc/14182/stat : 14182 (cudftodeb.nativ) R 14171 14171 4159 34819 4229 4202496 28320 0 0 0 568 15 0 0 25 0 1 0 879901989 119218176 28245 1283457024 134512640 135004320 4286646912 18446744073709551615 134817985 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/14182/statm: 29106 28245 236 121 0 28498 0
Current children cumulated CPU time (s) 5.83
Current children cumulated vsize (KiB) 119004

[startup+12.7142 s]
/proc/loadavg: 1.19 1.04 1.01 2/42 14182
/proc/meminfo: memFree=509244/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2580 CPUtime=0
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 565 1855 0 0 0 0 0 0 21 0 1 0 879901942 2641920 283 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 645 283 240 194 0 31 0
[pid=14182] ppid=14171 vsize=182724 CPUtime=12.22
/proc/14182/stat : 14182 (cudftodeb.nativ) R 14171 14171 4159 34819 4229 4202496 44657 0 0 0 1191 31 0 0 25 0 1 0 879901989 187109376 44582 1283457024 134512640 135004320 4286646912 18446744073709551615 134990788 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/14182/statm: 45681 44582 237 121 0 45073 0
Current children cumulated CPU time (s) 12.22
Current children cumulated vsize (KiB) 185304

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

[startup+12.8143 s]
/proc/loadavg: 1.19 1.04 1.01 2/42 14182
/proc/meminfo: memFree=509244/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2580 CPUtime=0
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 565 1855 0 0 0 0 0 0 21 0 1 0 879901942 2641920 283 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 645 283 240 194 0 31 0
[pid=14182] ppid=14171 vsize=182724 CPUtime=12.32
/proc/14182/stat : 14182 (cudftodeb.nativ) R 14171 14171 4159 34819 4229 4202496 44657 0 0 0 1201 31 0 0 25 0 1 0 879901989 187109376 44582 1283457024 134512640 135004320 4286646912 18446744073709551615 4159252005 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/14182/statm: 45681 44582 237 121 0 45073 0
Current children cumulated CPU time (s) 12.32
Current children cumulated vsize (KiB) 185304

[startup+16.0057 s]
/proc/loadavg: 1.19 1.04 1.01 1/42 14190
/proc/meminfo: memFree=630956/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2588 CPUtime=13.97
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 704 49793 0 1 0 0 1347 50 19 0 1 0 879901942 2650112 294 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 647 294 249 194 0 33 0
Current children cumulated CPU time (s) 13.97
Current children cumulated vsize (KiB) 2588

[startup+17.6095 s]
/proc/loadavg: 1.25 1.05 1.01 2/42 14192
/proc/meminfo: memFree=599432/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2588 CPUtime=13.97
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 704 49793 0 1 0 0 1347 50 19 0 1 0 879901942 2650112 294 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 647 294 249 194 0 33 0
[pid=14192] ppid=14171 vsize=101452 CPUtime=1.67
/proc/14192/stat : 14192 (apt-get) R 14171 14171 4159 34819 4229 4202496 8162 0 463 0 164 3 0 0 25 0 1 0 879903532 103886848 8549 1283457024 134512640 134619611 4290216512 18446744073709551615 4159573505 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/14192/statm: 25363 8549 8496 27 0 57 0
Current children cumulated CPU time (s) 15.64
Current children cumulated vsize (KiB) 104040

[startup+19.206 s]
/proc/loadavg: 1.25 1.05 1.01 1/42 14192
/proc/meminfo: memFree=555448/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2588 CPUtime=13.97
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 704 49793 0 1 0 0 1347 50 19 0 1 0 879901942 2650112 294 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 647 294 249 194 0 33 0
[pid=14192] ppid=14171 vsize=101452 CPUtime=2.06
/proc/14192/stat : 14192 (apt-get) D 14171 14171 4159 34819 4229 4202496 9364 0 535 0 196 10 0 0 18 0 1 0 879903532 103886848 9823 1283457024 134512640 134619611 4290216512 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/14192/statm: 25363 9823 9770 27 0 57 0
Current children cumulated CPU time (s) 16.03
Current children cumulated vsize (KiB) 104040

[startup+20.0142 s]
/proc/loadavg: 1.25 1.05 1.01 2/42 14192
/proc/meminfo: memFree=552480/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2588 CPUtime=13.97
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 704 49793 0 1 0 0 1347 50 19 0 1 0 879901942 2650112 294 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 647 294 249 194 0 33 0
[pid=14192] ppid=14171 vsize=44408 CPUtime=2.46
/proc/14192/stat : 14192 (apt-get) R 14171 14171 4159 34819 4229 4202496 19062 0 535 0 232 14 0 0 18 0 1 0 879903532 45473792 10056 1283457024 134512640 134619611 4290216512 18446744073709551615 4156947274 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/14192/statm: 11102 10056 9292 27 0 789 0
Current children cumulated CPU time (s) 16.43
Current children cumulated vsize (KiB) 46996

[startup+20.2143 s]
/proc/loadavg: 1.25 1.05 1.01 2/42 14192
/proc/meminfo: memFree=552480/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2588 CPUtime=13.97
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 704 49793 0 1 0 0 1347 50 19 0 1 0 879901942 2650112 294 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 647 294 249 194 0 33 0
[pid=14192] ppid=14171 vsize=44408 CPUtime=2.66
/proc/14192/stat : 14192 (apt-get) R 14171 14171 4159 34819 4229 4202496 19062 0 535 0 252 14 0 0 18 0 1 0 879903532 45473792 10056 1283457024 134512640 134619611 4290216512 18446744073709551615 4159683792 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/14192/statm: 11102 10056 9292 27 0 789 0
Current children cumulated CPU time (s) 16.63
Current children cumulated vsize (KiB) 46996

[startup+20.3143 s]
/proc/loadavg: 1.25 1.05 1.01 2/42 14192
/proc/meminfo: memFree=552480/1048576 swapFree=2076380/2097144
[pid=14171] ppid=14170 vsize=2588 CPUtime=13.97
/proc/14171/stat : 14171 (apt-get-trendy-) S 14170 14171 4159 34819 4229 4202496 704 49793 0 1 0 0 1347 50 19 0 1 0 879901942 2650112 294 1283457024 134512640 135304128 4293769472 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/14171/statm: 647 294 249 194 0 33 0
[pid=14192] ppid=14171 vsize=44408 CPUtime=2.76
/proc/14192/stat : 14192 (apt-get) R 14171 14171 4159 34819 4229 4202496 19064 0 535 0 262 14 0 0 18 0 1 0 879903532 45473792 10058 1283457024 134512640 134619611 4290216512 18446744073709551615 4159684070 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/14192/statm: 11102 10058 9294 27 0 789 0
Current children cumulated CPU time (s) 16.73
Current children cumulated vsize (KiB) 46996

Child status: 100
Real time (s): 20.3846
CPU time (s): 16.8131
CPU user time (s): 16.161
CPU system time (s): 0.65204
CPU usage (%): 82.4793
Max. virtual memory (cumulated for all children) (KiB): 185304

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 16.161
system time used= 0.65204
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 69580
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= 503
involuntary context switches= 309

runsolver used 0 second user time and 0 second system time

The end