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/rand835640.cudf.impossible.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/impossible//rand835640.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-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.16 1.04 1.00 3/44 27427
/proc/meminfo: memFree=809304/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2536 CPUtime=0
/proc/27427/stat : 27427 (apt-get-trendy-) R 27426 27427 4159 34819 4229 4194304 156 0 0 0 0 0 0 0 25 0 1 0 883133360 2596864 80 1283457024 134512640 135304128 4288465904 18446744073709551615 4160326820 0 0 0 0 0 0 0 17 0 0 0 0
/proc/27427/statm: 634 80 63 194 0 16 0

[startup+0.131777 s]
/proc/loadavg: 1.16 1.04 1.00 3/44 27427
/proc/meminfo: memFree=809304/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2584 CPUtime=0.01
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 516 1361 0 0 0 0 0 1 25 0 1 0 883133360 2646016 280 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 646 280 237 194 0 32 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2584

[startup+0.207789 s]
/proc/loadavg: 1.16 1.04 1.00 3/44 27427
/proc/meminfo: memFree=809304/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2584 CPUtime=0.01
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 516 1361 0 0 0 0 0 1 25 0 1 0 883133360 2646016 280 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 646 280 237 194 0 32 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2584

[startup+0.307782 s]
/proc/loadavg: 1.16 1.04 1.00 3/44 27427
/proc/meminfo: memFree=809304/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2584 CPUtime=0.01
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 516 1361 0 0 0 0 0 1 25 0 1 0 883133360 2646016 280 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 646 280 237 194 0 32 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2584

[startup+0.70503 s]
/proc/loadavg: 1.16 1.04 1.00 3/44 27427
/proc/meminfo: memFree=809304/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2584 CPUtime=0.02
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 565 1860 0 0 0 0 0 2 22 0 1 0 883133360 2646016 283 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 646 283 240 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 2584

[startup+1.50522 s]
/proc/loadavg: 1.16 1.04 1.00 2/46 27438
/proc/meminfo: memFree=740124/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2584 CPUtime=0.02
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 565 1860 0 0 0 0 0 2 22 0 1 0 883133360 2646016 283 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 646 283 240 194 0 32 0
[pid=27438] ppid=27427 vsize=25996 CPUtime=1.08
/proc/27438/stat : 27438 (cudftodeb.nativ) R 27427 27427 4159 34819 4229 4202496 6103 0 0 0 104 4 0 0 25 0 1 0 883133401 26619904 6030 1283457024 134512640 135004320 4292917376 18446744073709551615 134945200 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27438/statm: 6499 6030 225 121 0 5891 0
Current children cumulated CPU time (s) 1.1
Current children cumulated vsize (KiB) 28580

[startup+3.10558 s]
/proc/loadavg: 1.16 1.04 1.00 2/46 27438
/proc/meminfo: memFree=717060/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2584 CPUtime=0.02
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 565 1860 0 0 0 0 0 2 22 0 1 0 883133360 2646016 283 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 646 283 240 194 0 32 0
[pid=27438] ppid=27427 vsize=59920 CPUtime=2.69
/proc/27438/stat : 27438 (cudftodeb.nativ) R 27427 27427 4159 34819 4229 4202496 14432 0 0 0 257 12 0 0 25 0 1 0 883133401 61358080 14357 1283457024 134512640 135004320 4292917376 18446744073709551615 134946192 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27438/statm: 14980 14357 225 121 0 14372 0
Current children cumulated CPU time (s) 2.71
Current children cumulated vsize (KiB) 62504

[startup+6.30644 s]
/proc/loadavg: 1.15 1.04 1.00 2/46 27438
/proc/meminfo: memFree=657540/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2584 CPUtime=0.02
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 565 1860 0 0 0 0 0 2 22 0 1 0 883133360 2646016 283 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 646 283 240 194 0 32 0
[pid=27438] ppid=27427 vsize=117668 CPUtime=5.88
/proc/27438/stat : 27438 (cudftodeb.nativ) R 27427 27427 4159 34819 4229 4202496 28608 0 0 0 572 16 0 0 25 0 1 0 883133401 120492032 28533 1283457024 134512640 135004320 4292917376 18446744073709551615 4159805603 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27438/statm: 29417 28533 236 121 0 28809 0
Current children cumulated CPU time (s) 5.9
Current children cumulated vsize (KiB) 120252

[startup+12.7081 s]
/proc/loadavg: 1.13 1.04 1.00 2/46 27438
/proc/meminfo: memFree=562316/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2584 CPUtime=0.02
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 565 1860 0 0 0 0 0 2 22 0 1 0 883133360 2646016 283 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 646 283 240 194 0 32 0
[pid=27438] ppid=27427 vsize=181732 CPUtime=12.27
/proc/27438/stat : 27438 (cudftodeb.nativ) R 27427 27427 4159 34819 4229 4202496 44412 0 0 0 1203 24 0 0 25 0 1 0 883133401 186093568 44337 1283457024 134512640 135004320 4292917376 18446744073709551615 4158694947 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27438/statm: 45433 44337 237 121 0 44825 0
Current children cumulated CPU time (s) 12.29
Current children cumulated vsize (KiB) 184316

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

[startup+12.8081 s]
/proc/loadavg: 1.13 1.04 1.00 2/46 27438
/proc/meminfo: memFree=562316/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2584 CPUtime=0.02
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 565 1860 0 0 0 0 0 2 22 0 1 0 883133360 2646016 283 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 646 283 240 194 0 32 0
[pid=27438] ppid=27427 vsize=97164 CPUtime=12.37
/proc/27438/stat : 27438 (cudftodeb.nativ) R 27427 27427 4159 34819 4229 4202496 44412 0 0 0 1211 26 0 0 25 0 1 0 883133401 99495936 23536 1283457024 134512640 135004320 4292917376 18446744073709551615 134848515 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/27438/statm: 24291 23536 237 121 0 23683 0
Current children cumulated CPU time (s) 12.39
Current children cumulated vsize (KiB) 99748

[startup+16.0099 s]
/proc/loadavg: 1.12 1.04 1.00 1/46 27446
/proc/meminfo: memFree=683840/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2592 CPUtime=13.88
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 700 49552 0 1 0 0 1346 42 18 0 1 0 883133360 2654208 294 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 648 294 249 194 0 34 0
Current children cumulated CPU time (s) 13.88
Current children cumulated vsize (KiB) 2592

[startup+17.6102 s]
/proc/loadavg: 1.12 1.04 1.00 2/46 27448
/proc/meminfo: memFree=649204/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2592 CPUtime=13.88
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 700 49552 0 1 0 0 1346 42 18 0 1 0 883133360 2654208 294 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 648 294 249 194 0 34 0
[pid=27448] ppid=27427 vsize=101456 CPUtime=1.83
/proc/27448/stat : 27448 (apt-get) R 27427 27427 4159 34819 4229 4202496 8957 0 511 0 176 7 0 0 25 0 1 0 883134933 103890944 9393 1283457024 134512640 134619611 4293059824 18446744073709551615 4157266897 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/27448/statm: 25364 9393 9340 27 0 58 0
Current children cumulated CPU time (s) 15.71
Current children cumulated vsize (KiB) 104048

[startup+19.205 s]
/proc/loadavg: 1.11 1.03 1.00 2/46 27448
/proc/meminfo: memFree=608712/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2592 CPUtime=13.88
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 700 49552 0 1 0 0 1346 42 18 0 1 0 883133360 2654208 294 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 648 294 249 194 0 34 0
[pid=27448] ppid=27427 vsize=101456 CPUtime=2.02
/proc/27448/stat : 27448 (apt-get) D 27427 27427 4159 34819 4229 4202496 9362 0 535 0 185 17 0 0 18 0 1 0 883134933 103890944 9822 1283457024 134512640 134619611 4293059824 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/27448/statm: 25364 9822 9769 27 0 58 0
Current children cumulated CPU time (s) 15.9
Current children cumulated vsize (KiB) 104048

[startup+19.6138 s]
/proc/loadavg: 1.11 1.03 1.00 2/46 27448
/proc/meminfo: memFree=608712/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2592 CPUtime=13.88
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 700 49552 0 1 0 0 1346 42 18 0 1 0 883133360 2654208 294 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 648 294 249 194 0 34 0
[pid=27448] ppid=27427 vsize=44076 CPUtime=2.28
/proc/27448/stat : 27448 (apt-get) R 27427 27427 4159 34819 4229 4202496 18917 0 535 0 209 19 0 0 18 0 1 0 883134933 45133824 9963 1283457024 134512640 134619611 4293059824 18446744073709551615 4159669001 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/27448/statm: 11019 9963 9262 27 0 706 0
Current children cumulated CPU time (s) 16.16
Current children cumulated vsize (KiB) 46668

[startup+19.8138 s]
/proc/loadavg: 1.11 1.03 1.00 2/46 27448
/proc/meminfo: memFree=605240/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2592 CPUtime=13.88
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 700 49552 0 1 0 0 1346 42 18 0 1 0 883133360 2654208 294 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 648 294 249 194 0 34 0
[pid=27448] ppid=27427 vsize=44412 CPUtime=2.48
/proc/27448/stat : 27448 (apt-get) R 27427 27427 4159 34819 4229 4202496 19060 0 535 0 229 19 0 0 18 0 1 0 883134933 45477888 10056 1283457024 134512640 134619611 4293059824 18446744073709551615 4159669741 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/27448/statm: 11103 10056 9292 27 0 790 0
Current children cumulated CPU time (s) 16.36
Current children cumulated vsize (KiB) 47004

[startup+19.9138 s]
/proc/loadavg: 1.11 1.03 1.00 2/46 27448
/proc/meminfo: memFree=605240/1048576 swapFree=2077036/2097144
[pid=27427] ppid=27426 vsize=2592 CPUtime=13.88
/proc/27427/stat : 27427 (apt-get-trendy-) S 27426 27427 4159 34819 4229 4202496 700 49552 0 1 0 0 1346 42 18 0 1 0 883133360 2654208 294 1283457024 134512640 135304128 4288465904 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/27427/statm: 648 294 249 194 0 34 0
[pid=27448] ppid=27427 vsize=44412 CPUtime=2.58
/proc/27448/stat : 27448 (apt-get) R 27427 27427 4159 34819 4229 4202496 19060 0 535 0 239 19 0 0 18 0 1 0 883134933 45477888 10056 1283457024 134512640 134619611 4293059824 18446744073709551615 4159672166 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/27448/statm: 11103 10056 9292 27 0 790 0
Current children cumulated CPU time (s) 16.46
Current children cumulated vsize (KiB) 47004

Child status: 100
Real time (s): 19.986
CPU time (s): 16.545
CPU user time (s): 15.917
CPU system time (s): 0.628039
CPU usage (%): 82.7833
Max. virtual memory (cumulated for all children) (KiB): 184316

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 15.917
system time used= 0.628039
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 69332
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= 547
involuntary context switches= 315

runsolver used 0 second user time and 0 second system time

The end