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/randfa4522.cudf.impossible.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/impossible//randfa4522.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/randfa4522.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.16 1.06 1.01 2/40 3652
/proc/meminfo: memFree=810512/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2556 CPUtime=0
/proc/3652/stat : 3652 (apt-get-trendy-) R 3651 3652 4159 34819 4229 4202496 320 0 0 0 0 0 0 0 25 0 1 0 885142517 2617344 234 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 0 4 65536 0 0 0 17 0 0 0 0
/proc/3652/statm: 639 234 198 194 0 25 0

[startup+0.161387 s]
/proc/loadavg: 1.16 1.06 1.01 2/40 3652
/proc/meminfo: memFree=810512/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2580 CPUtime=0
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 508 1360 0 0 0 0 0 0 25 0 1 0 885142517 2641920 279 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 645 279 237 194 0 31 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2580

[startup+0.205399 s]
/proc/loadavg: 1.16 1.06 1.01 2/40 3652
/proc/meminfo: memFree=810512/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2580 CPUtime=0
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 508 1360 0 0 0 0 0 0 25 0 1 0 885142517 2641920 279 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 645 279 237 194 0 31 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2580

[startup+0.305415 s]
/proc/loadavg: 1.16 1.06 1.01 2/40 3652
/proc/meminfo: memFree=810512/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2580 CPUtime=0
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 508 1360 0 0 0 0 0 0 25 0 1 0 885142517 2641920 279 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 645 279 237 194 0 31 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2580

[startup+0.706921 s]
/proc/loadavg: 1.16 1.06 1.01 2/40 3652
/proc/meminfo: memFree=810512/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2580 CPUtime=0.02
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 555 1860 0 0 0 0 0 2 21 0 1 0 885142517 2641920 282 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 645 282 240 194 0 31 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 2580

[startup+1.50705 s]
/proc/loadavg: 1.16 1.06 1.01 2/42 3663
/proc/meminfo: memFree=741308/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2580 CPUtime=0.02
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 555 1860 0 0 0 0 0 2 21 0 1 0 885142517 2641920 282 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 645 282 240 194 0 31 0
[pid=3663] ppid=3652 vsize=25992 CPUtime=1.08
/proc/3663/stat : 3663 (cudftodeb.nativ) R 3652 3652 4159 34819 4229 4202496 6110 0 0 0 105 3 0 0 25 0 1 0 885142559 26615808 6037 1283457024 134512640 135004320 4293296352 18446744073709551615 134996567 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/3663/statm: 6498 6037 225 121 0 5890 0
Current children cumulated CPU time (s) 1.1
Current children cumulated vsize (KiB) 28572

[startup+3.1073 s]
/proc/loadavg: 1.16 1.06 1.01 2/42 3663
/proc/meminfo: memFree=718244/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2580 CPUtime=0.02
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 555 1860 0 0 0 0 0 2 21 0 1 0 885142517 2641920 282 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 645 282 240 194 0 31 0
[pid=3663] ppid=3652 vsize=59668 CPUtime=2.68
/proc/3663/stat : 3663 (cudftodeb.nativ) R 3652 3652 4159 34819 4229 4202496 14399 0 0 0 256 12 0 0 25 0 1 0 885142559 61100032 14324 1283457024 134512640 135004320 4293296352 18446744073709551615 134986420 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/3663/statm: 14917 14324 225 121 0 14309 0
Current children cumulated CPU time (s) 2.7
Current children cumulated vsize (KiB) 62248

[startup+6.3078 s]
/proc/loadavg: 1.15 1.06 1.01 2/42 3663
/proc/meminfo: memFree=659096/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2580 CPUtime=0.02
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 555 1860 0 0 0 0 0 2 21 0 1 0 885142517 2641920 282 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 645 282 240 194 0 31 0
[pid=3663] ppid=3652 vsize=117660 CPUtime=5.86
/proc/3663/stat : 3663 (cudftodeb.nativ) R 3652 3652 4159 34819 4229 4202496 28646 0 0 0 567 19 0 0 25 0 1 0 885142559 120483840 28571 1283457024 134512640 135004320 4293296352 18446744073709551615 4159973629 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/3663/statm: 29415 28571 236 121 0 28807 0
Current children cumulated CPU time (s) 5.88
Current children cumulated vsize (KiB) 120240

[startup+12.7095 s]
/proc/loadavg: 1.14 1.06 1.01 2/42 3663
/proc/meminfo: memFree=562508/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2580 CPUtime=0.02
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 555 1860 0 0 0 0 0 2 21 0 1 0 885142517 2641920 282 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 645 282 240 194 0 31 0
[pid=3663] ppid=3652 vsize=182752 CPUtime=12.24
/proc/3663/stat : 3663 (cudftodeb.nativ) R 3652 3652 4159 34819 4229 4202496 44665 0 0 0 1192 32 0 0 25 0 1 0 885142559 187138048 44590 1283457024 134512640 135004320 4293296352 18446744073709551615 134991123 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/3663/statm: 45688 44590 237 121 0 45080 0
Current children cumulated CPU time (s) 12.26
Current children cumulated vsize (KiB) 185332

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

[startup+12.8096 s]
/proc/loadavg: 1.14 1.06 1.01 2/42 3663
/proc/meminfo: memFree=562508/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2580 CPUtime=0.02
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 555 1860 0 0 0 0 0 2 21 0 1 0 885142517 2641920 282 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 645 282 240 194 0 31 0
[pid=3663] ppid=3652 vsize=182752 CPUtime=12.34
/proc/3663/stat : 3663 (cudftodeb.nativ) R 3652 3652 4159 34819 4229 4202496 44667 0 0 0 1202 32 0 0 25 0 1 0 885142559 187138048 44591 1283457024 134512640 135004320 4293296352 18446744073709551615 4158862885 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/3663/statm: 45688 44591 237 121 0 45080 0
Current children cumulated CPU time (s) 12.36
Current children cumulated vsize (KiB) 185332

[startup+16.008 s]
/proc/loadavg: 1.12 1.05 1.01 1/42 3671
/proc/meminfo: memFree=684652/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2672 CPUtime=13.88
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 727 49810 0 1 0 0 1340 48 18 0 1 0 885142517 2736128 314 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 668 314 249 194 0 54 0
Current children cumulated CPU time (s) 13.88
Current children cumulated vsize (KiB) 2672

[startup+19.2066 s]
/proc/loadavg: 1.11 1.05 1.01 2/42 3673
/proc/meminfo: memFree=609648/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2672 CPUtime=13.88
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 727 49810 0 1 0 0 1340 48 18 0 1 0 885142517 2736128 314 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 668 314 249 194 0 54 0
[pid=3673] ppid=3652 vsize=101464 CPUtime=2.03
/proc/3673/stat : 3673 (apt-get) D 3652 3652 4159 34819 4229 4202496 9363 0 535 0 193 10 0 0 18 0 1 0 885144077 103899136 9823 1283457024 134512640 134619611 4292393360 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/3673/statm: 25366 9823 9769 27 0 60 0
Current children cumulated CPU time (s) 15.91
Current children cumulated vsize (KiB) 104136

[startup+20.0107 s]
/proc/loadavg: 1.11 1.05 1.01 2/42 3673
/proc/meminfo: memFree=606300/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2672 CPUtime=13.88
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 727 49810 0 1 0 0 1340 48 18 0 1 0 885142517 2736128 314 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 668 314 249 194 0 54 0
[pid=3673] ppid=3652 vsize=44444 CPUtime=2.64
/proc/3673/stat : 3673 (apt-get) R 3652 3652 4159 34819 4229 4202496 19058 0 535 0 252 12 0 0 18 0 1 0 885144077 45510656 10054 1283457024 134512640 134619611 4292393360 18446744073709551615 4159863335 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/3673/statm: 11111 10054 9290 27 0 798 0
Current children cumulated CPU time (s) 16.52
Current children cumulated vsize (KiB) 47116

[startup+20.4108 s]
/proc/loadavg: 1.11 1.05 1.01 2/42 3673
/proc/meminfo: memFree=606300/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2672 CPUtime=13.88
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 727 49810 0 1 0 0 1340 48 18 0 1 0 885142517 2736128 314 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 668 314 249 194 0 54 0
[pid=3673] ppid=3652 vsize=44444 CPUtime=3.04
/proc/3673/stat : 3673 (apt-get) R 3652 3652 4159 34819 4229 4202496 19058 0 535 0 292 12 0 0 19 0 1 0 885144077 45510656 10054 1283457024 134512640 134619611 4292393360 18446744073709551615 4157242181 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/3673/statm: 11111 10054 9290 27 0 798 0
Current children cumulated CPU time (s) 16.92
Current children cumulated vsize (KiB) 47116

[startup+20.6109 s]
/proc/loadavg: 1.11 1.05 1.01 2/42 3673
/proc/meminfo: memFree=606300/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2672 CPUtime=13.88
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 727 49810 0 1 0 0 1340 48 18 0 1 0 885142517 2736128 314 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 668 314 249 194 0 54 0
[pid=3673] ppid=3652 vsize=44444 CPUtime=3.23
/proc/3673/stat : 3673 (apt-get) R 3652 3652 4159 34819 4229 4202496 19099 0 535 0 311 12 0 0 19 0 1 0 885144077 45510656 10095 1283457024 134512640 134619611 4292393360 18446744073709551615 4160059825 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/3673/statm: 11111 10095 9292 27 0 798 0
Current children cumulated CPU time (s) 17.11
Current children cumulated vsize (KiB) 47116

[startup+20.7109 s]
/proc/loadavg: 1.11 1.05 1.01 2/42 3673
/proc/meminfo: memFree=606300/1048576 swapFree=2080268/2097144
[pid=3652] ppid=3651 vsize=2672 CPUtime=13.88
/proc/3652/stat : 3652 (apt-get-trendy-) S 3651 3652 4159 34819 4229 4202496 727 49810 0 1 0 0 1340 48 18 0 1 0 885142517 2736128 314 1283457024 134512640 135304128 4289584384 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/3652/statm: 668 314 249 194 0 54 0
[pid=3673] ppid=3652 vsize=44832 CPUtime=3.33
/proc/3673/stat : 3673 (apt-get) R 3652 3652 4159 34819 4229 4202496 19152 0 535 0 321 12 0 0 19 0 1 0 885144077 45907968 10148 1283457024 134512640 134619611 4292393360 18446744073709551615 4159963270 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/3673/statm: 11208 10148 9294 27 0 895 0
Current children cumulated CPU time (s) 17.21
Current children cumulated vsize (KiB) 47504

Child status: 100
Real time (s): 20.7773
CPU time (s): 17.2971
CPU user time (s): 16.673
CPU system time (s): 0.624039
CPU usage (%): 83.2499
Max. virtual memory (cumulated for all children) (KiB): 185332

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 16.673
system time used= 0.624039
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 69708
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= 576
involuntary context switches= 338

runsolver used 0 second user time and 0 second system time

The end