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/randa223c3.cudf.impossible.log.runsolver ./apt-get-paranoid-1.0 /home/misc2010/data/2010/impossible//randa223c3.cudf /home/misc2010/tmp/201012061533/apt-get-paranoid-1.0/randa223c3.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.55 1.29 1.20 5/46 29236
/proc/meminfo: memFree=773852/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2576 CPUtime=0
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 398 156 0 0 0 0 0 0 25 0 1 0 876466398 2637824 276 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 644 276 235 194 0 30 0

[startup+0.207584 s]
/proc/loadavg: 1.55 1.29 1.20 5/46 29236
/proc/meminfo: memFree=773852/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2584 CPUtime=0.04
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 565 1859 0 0 0 0 0 4 25 0 1 0 876466398 2646016 283 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 646 283 240 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 2584

[startup+0.315317 s]
/proc/loadavg: 1.55 1.29 1.20 5/46 29236
/proc/meminfo: memFree=773852/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2584 CPUtime=0.04
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 565 1859 0 0 0 0 0 4 25 0 1 0 876466398 2646016 283 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 646 283 240 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 2584

[startup+0.405331 s]
/proc/loadavg: 1.55 1.29 1.20 5/46 29236
/proc/meminfo: memFree=773852/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2584 CPUtime=0.04
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 565 1859 0 0 0 0 0 4 25 0 1 0 876466398 2646016 283 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 646 283 240 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 2584

[startup+0.705401 s]
/proc/loadavg: 1.55 1.29 1.20 5/46 29236
/proc/meminfo: memFree=773852/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2584 CPUtime=0.04
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 565 1859 0 0 0 0 0 4 25 0 1 0 876466398 2646016 283 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 646 283 240 194 0 32 0
Current children cumulated CPU time (s) 0.04
Current children cumulated vsize (KiB) 2584

[startup+1.50554 s]
/proc/loadavg: 1.55 1.29 1.20 2/47 29246
/proc/meminfo: memFree=722984/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2584 CPUtime=0.04
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 565 1859 0 0 0 0 0 4 25 0 1 0 876466398 2646016 283 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 646 283 240 194 0 32 0
[pid=29246] ppid=29235 vsize=32940 CPUtime=1.43
/proc/29246/stat : 29246 (cudftodeb.nativ) R 29235 29235 2059 34821 2220 4202496 7825 0 0 0 137 6 0 0 25 0 1 0 876466406 33730560 7752 1283457024 134512640 135004320 4290213344 18446744073709551615 134978732 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/29246/statm: 8235 7752 225 121 0 7627 0
Current children cumulated CPU time (s) 1.47
Current children cumulated vsize (KiB) 35524

[startup+3.10599 s]
/proc/loadavg: 1.55 1.29 1.20 2/47 29246
/proc/meminfo: memFree=700540/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2584 CPUtime=0.04
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 565 1859 0 0 0 0 0 4 25 0 1 0 876466398 2646016 283 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 646 283 240 194 0 32 0
[pid=29246] ppid=29235 vsize=64632 CPUtime=3.03
/proc/29246/stat : 29246 (cudftodeb.nativ) R 29235 29235 2059 34821 2220 4202496 15584 0 0 0 292 11 0 0 25 0 1 0 876466406 66183168 15509 1283457024 134512640 135004320 4290213344 18446744073709551615 134959995 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/29246/statm: 16158 15509 225 121 0 15550 0
Current children cumulated CPU time (s) 3.07
Current children cumulated vsize (KiB) 67216

[startup+6.30653 s]
/proc/loadavg: 1.51 1.28 1.20 2/47 29246
/proc/meminfo: memFree=638788/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2584 CPUtime=0.04
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 565 1859 0 0 0 0 0 4 25 0 1 0 876466398 2646016 283 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 646 283 240 194 0 32 0
[pid=29246] ppid=29235 vsize=122872 CPUtime=6.22
/proc/29246/stat : 29246 (cudftodeb.nativ) R 29235 29235 2059 34821 2220 4202496 29912 0 0 0 603 19 0 0 25 0 1 0 876466406 125820928 29837 1283457024 134512640 135004320 4290213344 18446744073709551615 134945048 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/29246/statm: 30718 29837 236 121 0 30110 0
Current children cumulated CPU time (s) 6.26
Current children cumulated vsize (KiB) 125456

[startup+12.7089 s]
/proc/loadavg: 1.47 1.28 1.20 2/47 29246
/proc/meminfo: memFree=551864/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2584 CPUtime=0.04
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 565 1859 0 0 0 0 0 4 25 0 1 0 876466398 2646016 283 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 646 283 240 194 0 32 0
[pid=29246] ppid=29235 vsize=97160 CPUtime=12.6
/proc/29246/stat : 29246 (cudftodeb.nativ) R 29235 29235 2059 34821 2220 4202496 44596 0 0 0 1231 29 0 0 25 0 1 0 876466406 99491840 23537 1283457024 134512640 135004320 4290213344 18446744073709551615 134863789 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/29246/statm: 24290 23537 237 121 0 23682 0
Current children cumulated CPU time (s) 12.64
Current children cumulated vsize (KiB) 99744

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

[startup+12.9089 s]
/proc/loadavg: 1.47 1.28 1.20 2/47 29246
/proc/meminfo: memFree=551864/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2584 CPUtime=0.04
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 565 1859 0 0 0 0 0 4 25 0 1 0 876466398 2646016 283 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 646 283 240 194 0 32 0
[pid=29246] ppid=29235 vsize=97160 CPUtime=12.8
/proc/29246/stat : 29246 (cudftodeb.nativ) R 29235 29235 2059 34821 2220 4202496 44596 0 0 0 1251 29 0 0 25 0 1 0 876466406 99491840 23537 1283457024 134512640 135004320 4290213344 18446744073709551615 134868896 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/29246/statm: 24290 23537 237 121 0 23682 0
Current children cumulated CPU time (s) 12.84
Current children cumulated vsize (KiB) 99744

[startup+16.1136 s]
/proc/loadavg: 1.43 1.27 1.20 2/47 29256
/proc/meminfo: memFree=672292/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2592 CPUtime=13.93
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 705 49737 0 1 0 0 1351 42 19 0 1 0 876466398 2654208 294 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 648 294 249 194 0 34 0
[pid=29256] ppid=29235 vsize=101452 CPUtime=0.72
/proc/29256/stat : 29256 (apt-get) R 29235 29235 2059 34821 2220 4202496 4567 0 245 0 71 1 0 0 21 0 1 0 876467934 103886848 4736 1283457024 134512640 134619611 4294948480 18446744073709551615 4159972982 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/29256/statm: 25363 4736 4683 27 0 57 0
Current children cumulated CPU time (s) 14.65
Current children cumulated vsize (KiB) 104044

[startup+17.7047 s]
/proc/loadavg: 1.43 1.27 1.20 1/47 29256
/proc/meminfo: memFree=599928/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2592 CPUtime=13.93
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 705 49737 0 1 0 0 1351 42 19 0 1 0 876466398 2654208 294 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 648 294 249 194 0 34 0
[pid=29256] ppid=29235 vsize=101452 CPUtime=1.98
/proc/29256/stat : 29256 (apt-get) D 29235 29235 2059 34821 2220 4202496 9310 0 532 0 191 7 0 0 23 0 1 0 876467934 103886848 9766 1283457024 134512640 134619611 4294948480 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/29256/statm: 25363 9766 9713 27 0 57 0
Current children cumulated CPU time (s) 15.91
Current children cumulated vsize (KiB) 104044

[startup+18.5047 s]
/proc/loadavg: 1.43 1.27 1.20 1/47 29256
/proc/meminfo: memFree=599928/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2592 CPUtime=13.93
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 705 49737 0 1 0 0 1351 42 19 0 1 0 876466398 2654208 294 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 648 294 249 194 0 34 0
[pid=29256] ppid=29235 vsize=101452 CPUtime=2.01
/proc/29256/stat : 29256 (apt-get) D 29235 29235 2059 34821 2220 4202496 9363 0 535 0 193 8 0 0 18 0 1 0 876467934 103886848 9822 1283457024 134512640 134619611 4294948480 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/29256/statm: 25363 9822 9769 27 0 57 0
Current children cumulated CPU time (s) 15.94
Current children cumulated vsize (KiB) 104044

[startup+19.3048 s]
/proc/loadavg: 1.39 1.27 1.19 1/47 29256
/proc/meminfo: memFree=599128/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2592 CPUtime=13.93
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 705 49737 0 1 0 0 1351 42 19 0 1 0 876466398 2654208 294 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 648 294 249 194 0 34 0
[pid=29256] ppid=29235 vsize=44408 CPUtime=2.36
/proc/29256/stat : 29256 (apt-get) R 29235 29235 2059 34821 2220 4202496 19061 0 535 0 227 9 0 0 18 0 1 0 876467934 45473792 10056 1283457024 134512640 134619611 4294948480 18446744073709551615 4159931602 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/29256/statm: 11102 10056 9292 27 0 789 0
Current children cumulated CPU time (s) 16.29
Current children cumulated vsize (KiB) 47000

[startup+19.5049 s]
/proc/loadavg: 1.39 1.27 1.19 1/47 29256
/proc/meminfo: memFree=599128/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2592 CPUtime=13.93
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 705 49737 0 1 0 0 1351 42 19 0 1 0 876466398 2654208 294 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 648 294 249 194 0 34 0
[pid=29256] ppid=29235 vsize=44408 CPUtime=2.56
/proc/29256/stat : 29256 (apt-get) R 29235 29235 2059 34821 2220 4202496 19061 0 535 0 247 9 0 0 18 0 1 0 876467934 45473792 10056 1283457024 134512640 134619611 4294948480 18446744073709551615 4159837321 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/29256/statm: 11102 10056 9292 27 0 789 0
Current children cumulated CPU time (s) 16.49
Current children cumulated vsize (KiB) 47000

[startup+19.6049 s]
/proc/loadavg: 1.39 1.27 1.19 1/47 29256
/proc/meminfo: memFree=599128/1048576 swapFree=2078780/2097144
[pid=29235] ppid=29234 vsize=2592 CPUtime=13.93
/proc/29235/stat : 29235 (apt-get-paranoi) S 29234 29235 2059 34821 2220 4202496 705 49737 0 1 0 0 1351 42 19 0 1 0 876466398 2654208 294 1283457024 134512640 135304128 4294941200 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/29235/statm: 648 294 249 194 0 34 0
[pid=29256] ppid=29235 vsize=44408 CPUtime=2.66
/proc/29256/stat : 29256 (apt-get) R 29235 29235 2059 34821 2220 4202496 19061 0 535 0 257 9 0 0 18 0 1 0 876467934 45473792 10056 1283457024 134512640 134619611 4294948480 18446744073709551615 4160329851 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/29256/statm: 11102 10056 9292 27 0 789 0
Current children cumulated CPU time (s) 16.59
Current children cumulated vsize (KiB) 47000

Child status: 100
Real time (s): 19.6332
CPU time (s): 16.633
CPU user time (s): 16.109
CPU system time (s): 0.524032
CPU usage (%): 84.7189
Max. virtual memory (cumulated for all children) (KiB): 185056

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 16.109
system time used= 0.524032
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 69522
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= 206
involuntary context switches= 356

runsolver used 0.008 second user time and 0.004 second system time

The end