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/201012061533/apt-get-paranoid-1.0/rand835640.cudf.impossible.log.runsolver ./apt-get-paranoid-1.0 /home/misc2010/data/2010/impossible//rand835640.cudf /home/misc2010/tmp/201012061533/apt-get-paranoid-1.0/rand835640.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.33 1.24 1.19 5/46 23655
/proc/meminfo: memFree=753436/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2580 CPUtime=0
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 516 1361 0 0 0 0 0 0 18 0 1 0 876094551 2641920 280 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 645 280 237 194 0 31 0
[pid=23655] ppid=23647 vsize=364 CPUtime=0.01
/proc/23655/stat : 23655 (cp) R 23647 23647 2059 34821 2220 4194304 97 0 0 0 0 1 0 0 25 0 1 0 876094552 372736 37 1283457024 134512640 134614052 4292837552 18446744073709551615 4160343268 0 0 0 0 0 0 0 17 0 0 0 0
/proc/23655/statm: 91 37 28 25 0 5 0

[startup+0.209203 s]
/proc/loadavg: 1.33 1.24 1.19 5/46 23655
/proc/meminfo: memFree=753436/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2580 CPUtime=0.06
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 565 1860 0 0 0 0 0 6 25 0 1 0 876094551 2641920 283 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 645 283 240 194 0 31 0
Current children cumulated CPU time (s) 0.06
Current children cumulated vsize (KiB) 2580

[startup+0.309221 s]
/proc/loadavg: 1.33 1.24 1.19 5/46 23655
/proc/meminfo: memFree=753436/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2580 CPUtime=0.06
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 565 1860 0 0 0 0 0 6 25 0 1 0 876094551 2641920 283 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 645 283 240 194 0 31 0
Current children cumulated CPU time (s) 0.06
Current children cumulated vsize (KiB) 2580

[startup+0.409236 s]
/proc/loadavg: 1.33 1.24 1.19 5/46 23655
/proc/meminfo: memFree=753436/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2580 CPUtime=0.06
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 565 1860 0 0 0 0 0 6 25 0 1 0 876094551 2641920 283 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 645 283 240 194 0 31 0
Current children cumulated CPU time (s) 0.06
Current children cumulated vsize (KiB) 2580

[startup+0.709285 s]
/proc/loadavg: 1.33 1.24 1.19 5/46 23655
/proc/meminfo: memFree=753436/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2580 CPUtime=0.06
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 565 1860 0 0 0 0 0 6 25 0 1 0 876094551 2641920 283 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 645 283 240 194 0 31 0
Current children cumulated CPU time (s) 0.06
Current children cumulated vsize (KiB) 2580

[startup+1.50943 s]
/proc/loadavg: 1.33 1.24 1.19 2/47 23658
/proc/meminfo: memFree=701940/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2580 CPUtime=0.06
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 565 1860 0 0 0 0 0 6 25 0 1 0 876094551 2641920 283 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 645 283 240 194 0 31 0
[pid=23658] ppid=23647 vsize=33432 CPUtime=1.44
/proc/23658/stat : 23658 (cudftodeb.nativ) R 23647 23647 2059 34821 2220 4202496 7945 0 0 0 136 8 0 0 25 0 1 0 876094558 34234368 7872 1283457024 134512640 135004320 4288273424 18446744073709551615 134996501 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/23658/statm: 8358 7872 225 121 0 7750 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 36012

[startup+3.11026 s]
/proc/loadavg: 1.30 1.24 1.19 2/47 23658
/proc/meminfo: memFree=679620/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2580 CPUtime=0.06
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 565 1860 0 0 0 0 0 6 25 0 1 0 876094551 2641920 283 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 645 283 240 194 0 31 0
[pid=23658] ppid=23647 vsize=65124 CPUtime=3.04
/proc/23658/stat : 23658 (cudftodeb.nativ) R 23647 23647 2059 34821 2220 4202496 15719 0 0 0 292 12 0 0 25 0 1 0 876094558 66686976 15644 1283457024 134512640 135004320 4288273424 18446744073709551615 134828072 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/23658/statm: 16281 15644 225 121 0 15673 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 67704

[startup+6.31059 s]
/proc/loadavg: 1.30 1.24 1.19 2/47 23658
/proc/meminfo: memFree=618488/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2580 CPUtime=0.06
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 565 1860 0 0 0 0 0 6 25 0 1 0 876094551 2641920 283 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 645 283 240 194 0 31 0
[pid=23658] ppid=23647 vsize=122372 CPUtime=6.23
/proc/23658/stat : 23658 (cudftodeb.nativ) R 23647 23647 2059 34821 2220 4202496 29805 0 0 0 605 18 0 0 25 0 1 0 876094558 125308928 29730 1283457024 134512640 135004320 4288273424 18446744073709551615 4159930424 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/23658/statm: 30593 29730 236 121 0 29985 0
Current children cumulated CPU time (s) 6.29
Current children cumulated vsize (KiB) 124952

[startup+12.7121 s]
/proc/loadavg: 1.26 1.23 1.19 2/47 23658
/proc/meminfo: memFree=533052/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2580 CPUtime=0.06
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 565 1860 0 0 0 0 0 6 25 0 1 0 876094551 2641920 283 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 645 283 240 194 0 31 0
[pid=23658] ppid=23647 vsize=97160 CPUtime=12.63
/proc/23658/stat : 23658 (cudftodeb.nativ) R 23647 23647 2059 34821 2220 4202496 44412 0 0 0 1228 35 0 0 25 0 1 0 876094558 99491840 23536 1283457024 134512640 135004320 4288273424 18446744073709551615 134860867 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/23658/statm: 24290 23536 237 121 0 23682 0
Current children cumulated CPU time (s) 12.69
Current children cumulated vsize (KiB) 99740

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

[startup+12.9121 s]
/proc/loadavg: 1.26 1.23 1.19 2/47 23658
/proc/meminfo: memFree=533052/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2580 CPUtime=0.06
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 565 1860 0 0 0 0 0 6 25 0 1 0 876094551 2641920 283 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 645 283 240 194 0 31 0
[pid=23658] ppid=23647 vsize=97160 CPUtime=12.83
/proc/23658/stat : 23658 (cudftodeb.nativ) R 23647 23647 2059 34821 2220 4202496 44412 0 0 0 1248 35 0 0 25 0 1 0 876094558 99491840 23536 1283457024 134512640 135004320 4288273424 18446744073709551615 134852323 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/23658/statm: 24290 23536 237 121 0 23682 0
Current children cumulated CPU time (s) 12.89
Current children cumulated vsize (KiB) 99740

[startup+16.1142 s]
/proc/loadavg: 1.26 1.23 1.19 2/47 23668
/proc/meminfo: memFree=648108/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2588 CPUtime=13.95
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 705 49552 0 1 0 0 1339 56 18 0 1 0 876094551 2650112 294 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 647 294 249 194 0 33 0
[pid=23668] ppid=23647 vsize=101452 CPUtime=0.89
/proc/23668/stat : 23668 (apt-get) R 23647 23647 2059 34821 2220 4202496 5306 0 289 0 86 3 0 0 22 0 1 0 876096070 103886848 5520 1283457024 134512640 134619611 4290343504 18446744073709551615 4157565466 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/23668/statm: 25363 5520 5467 27 0 57 0
Current children cumulated CPU time (s) 14.84
Current children cumulated vsize (KiB) 104040

[startup+17.7062 s]
/proc/loadavg: 1.24 1.23 1.19 1/47 23668
/proc/meminfo: memFree=580124/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2588 CPUtime=13.95
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 705 49552 0 1 0 0 1339 56 18 0 1 0 876094551 2650112 294 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 647 294 249 194 0 33 0
[pid=23668] ppid=23647 vsize=101452 CPUtime=1.99
/proc/23668/stat : 23668 (apt-get) R 23647 23647 2059 34821 2220 4202496 9309 0 532 0 186 13 0 0 21 0 1 0 876096070 103886848 9766 1283457024 134512640 134619611 4290343504 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/23668/statm: 25363 9766 9713 27 0 57 0
Current children cumulated CPU time (s) 15.94
Current children cumulated vsize (KiB) 104040

[startup+18.5063 s]
/proc/loadavg: 1.24 1.23 1.19 1/47 23668
/proc/meminfo: memFree=580124/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2588 CPUtime=13.95
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 705 49552 0 1 0 0 1339 56 18 0 1 0 876094551 2650112 294 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 647 294 249 194 0 33 0
[pid=23668] ppid=23647 vsize=101452 CPUtime=2.03
/proc/23668/stat : 23668 (apt-get) D 23647 23647 2059 34821 2220 4202496 9362 0 535 0 188 15 0 0 18 0 1 0 876096070 103886848 9822 1283457024 134512640 134619611 4290343504 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/23668/statm: 25363 9822 9769 27 0 57 0
Current children cumulated CPU time (s) 15.98
Current children cumulated vsize (KiB) 104040

[startup+19.3082 s]
/proc/loadavg: 1.24 1.23 1.19 1/47 23668
/proc/meminfo: memFree=579448/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2588 CPUtime=13.95
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 705 49552 0 1 0 0 1339 56 18 0 1 0 876094551 2650112 294 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 647 294 249 194 0 33 0
[pid=23668] ppid=23647 vsize=44408 CPUtime=2.38
/proc/23668/stat : 23668 (apt-get) R 23647 23647 2059 34821 2220 4202496 19058 0 535 0 220 18 0 0 18 0 1 0 876096070 45473792 10054 1283457024 134512640 134619611 4290343504 18446744073709551615 4160369671 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/23668/statm: 11102 10054 9290 27 0 789 0
Current children cumulated CPU time (s) 16.33
Current children cumulated vsize (KiB) 46996

[startup+19.5083 s]
/proc/loadavg: 1.24 1.23 1.19 1/47 23668
/proc/meminfo: memFree=579448/1048576 swapFree=2078744/2097144
[pid=23647] ppid=23646 vsize=2588 CPUtime=13.95
/proc/23647/stat : 23647 (apt-get-paranoi) S 23646 23647 2059 34821 2220 4202496 705 49552 0 1 0 0 1339 56 18 0 1 0 876094551 2650112 294 1283457024 134512640 135304128 4293683424 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/23647/statm: 647 294 249 194 0 33 0
[pid=23668] ppid=23647 vsize=44408 CPUtime=2.58
/proc/23668/stat : 23668 (apt-get) R 23647 23647 2059 34821 2220 4202496 19060 0 535 0 240 18 0 0 18 0 1 0 876096070 45473792 10056 1283457024 134512640 134619611 4290343504 18446744073709551615 4159967508 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/23668/statm: 11102 10056 9292 27 0 789 0
Current children cumulated CPU time (s) 16.53
Current children cumulated vsize (KiB) 46996

Child status: 100
Real time (s): 19.5954
CPU time (s): 16.629
CPU user time (s): 15.869
CPU system time (s): 0.760047
CPU usage (%): 84.8621
Max. virtual memory (cumulated for all children) (KiB): 184308

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 15.869
system time used= 0.760047
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 69338
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= 257
involuntary context switches= 390

runsolver used 0.008 second user time and 0 second system time

The end