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/rand0695fb.cudf.impossible.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/impossible//rand0695fb.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/rand0695fb.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.30 1.08 0.82 5/44 5213
/proc/meminfo: memFree=801576/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2580 CPUtime=0
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 508 1359 0 0 0 0 0 0 25 0 1 0 877650538 2641920 279 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 645 279 237 194 0 31 0

[startup+0.113554 s]
/proc/loadavg: 1.30 1.08 0.82 5/44 5213
/proc/meminfo: memFree=801576/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2580 CPUtime=0
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 508 1359 0 0 0 0 0 0 25 0 1 0 877650538 2641920 279 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 645 279 237 194 0 31 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2580

[startup+0.205609 s]
/proc/loadavg: 1.30 1.08 0.82 5/44 5213
/proc/meminfo: memFree=801576/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2580 CPUtime=0
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 508 1359 0 0 0 0 0 0 25 0 1 0 877650538 2641920 279 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 645 279 237 194 0 31 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2580

[startup+0.305572 s]
/proc/loadavg: 1.30 1.08 0.82 5/44 5213
/proc/meminfo: memFree=801576/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2580 CPUtime=0
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 508 1359 0 0 0 0 0 0 25 0 1 0 877650538 2641920 279 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 645 279 237 194 0 31 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2580

[startup+0.711525 s]
/proc/loadavg: 1.30 1.08 0.82 5/44 5213
/proc/meminfo: memFree=801576/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2580 CPUtime=0.01
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 555 1859 0 0 0 0 0 1 22 0 1 0 877650538 2641920 282 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 645 282 240 194 0 31 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2580

[startup+1.51174 s]
/proc/loadavg: 1.30 1.08 0.82 2/45 5223
/proc/meminfo: memFree=732012/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2580 CPUtime=0.01
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 555 1859 0 0 0 0 0 1 22 0 1 0 877650538 2641920 282 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 645 282 240 194 0 31 0
[pid=5223] ppid=5212 vsize=26736 CPUtime=1.11
/proc/5223/stat : 5223 (cudftodeb.nativ) R 5212 5212 4159 34819 4229 4202496 6274 0 0 0 108 3 0 0 25 0 1 0 877650578 27377664 6201 1283457024 134512640 135004320 4294306256 18446744073709551615 134986572 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/5223/statm: 6684 6201 225 121 0 6076 0
Current children cumulated CPU time (s) 1.12
Current children cumulated vsize (KiB) 29316

[startup+3.1121 s]
/proc/loadavg: 1.30 1.08 0.82 2/45 5223
/proc/meminfo: memFree=708948/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2580 CPUtime=0.01
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 555 1859 0 0 0 0 0 1 22 0 1 0 877650538 2641920 282 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 645 282 240 194 0 31 0
[pid=5223] ppid=5212 vsize=60164 CPUtime=2.7
/proc/5223/stat : 5223 (cudftodeb.nativ) R 5212 5212 4159 34819 4229 4202496 14515 0 0 0 264 6 0 0 25 0 1 0 877650578 61607936 14440 1283457024 134512640 135004320 4294306256 18446744073709551615 134829355 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/5223/statm: 15041 14440 225 121 0 14433 0
Current children cumulated CPU time (s) 2.71
Current children cumulated vsize (KiB) 62744

[startup+6.31419 s]
/proc/loadavg: 1.27 1.08 0.82 2/45 5223
/proc/meminfo: memFree=652040/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2580 CPUtime=0.01
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 555 1859 0 0 0 0 0 1 22 0 1 0 877650538 2641920 282 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 645 282 240 194 0 31 0
[pid=5223] ppid=5212 vsize=115180 CPUtime=5.86
/proc/5223/stat : 5223 (cudftodeb.nativ) R 5212 5212 4159 34819 4229 4202496 28052 0 0 0 572 14 0 0 25 0 1 0 877650578 117944320 27977 1283457024 134512640 135004320 4294306256 18446744073709551615 134526368 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/5223/statm: 28795 27977 236 121 0 28187 0
Current children cumulated CPU time (s) 5.87
Current children cumulated vsize (KiB) 117760

[startup+12.7062 s]
/proc/loadavg: 1.25 1.08 0.82 2/45 5223
/proc/meminfo: memFree=555816/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2580 CPUtime=0.01
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 555 1859 0 0 0 0 0 1 22 0 1 0 877650538 2641920 282 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 645 282 240 194 0 31 0
[pid=5223] ppid=5212 vsize=182720 CPUtime=12.23
/proc/5223/stat : 5223 (cudftodeb.nativ) R 5212 5212 4159 34819 4229 4202496 44657 0 0 0 1198 25 0 0 25 0 1 0 877650578 187105280 44582 1283457024 134512640 135004320 4294306256 18446744073709551615 134945091 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/5223/statm: 45680 44582 237 121 0 45072 0
Current children cumulated CPU time (s) 12.24
Current children cumulated vsize (KiB) 185300

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

[startup+12.8062 s]
/proc/loadavg: 1.25 1.08 0.82 2/45 5223
/proc/meminfo: memFree=555816/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2580 CPUtime=0.01
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 555 1859 0 0 0 0 0 1 22 0 1 0 877650538 2641920 282 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 645 282 240 194 0 31 0
[pid=5223] ppid=5212 vsize=182720 CPUtime=12.33
/proc/5223/stat : 5223 (cudftodeb.nativ) R 5212 5212 4159 34819 4229 4202496 44657 0 0 0 1208 25 0 0 25 0 1 0 877650578 187105280 44582 1283457024 134512640 135004320 4294306256 18446744073709551615 134990652 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/5223/statm: 45680 44582 237 121 0 45072 0
Current children cumulated CPU time (s) 12.34
Current children cumulated vsize (KiB) 185300

[startup+19.2156 s]
/proc/loadavg: 1.21 1.08 0.82 2/45 5233
/proc/meminfo: memFree=672492/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2588 CPUtime=14.22
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 688 49798 0 1 0 0 1379 43 18 0 1 0 877650538 2650112 293 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 647 293 249 194 0 33 0
[pid=5233] ppid=5212 vsize=101456 CPUtime=0.66
/proc/5233/stat : 5233 (apt-get) R 5212 5212 4159 34819 4229 4202496 4272 0 227 0 66 0 0 0 20 0 1 0 877652377 103890944 4424 1283457024 134512640 134619611 4288047136 18446744073709551615 4159151410 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/5233/statm: 25364 4424 4371 27 0 58 0
Current children cumulated CPU time (s) 14.88
Current children cumulated vsize (KiB) 104044

[startup+22.407 s]
/proc/loadavg: 1.21 1.08 0.82 1/45 5233
/proc/meminfo: memFree=600904/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2588 CPUtime=14.22
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 688 49798 0 1 0 0 1379 43 18 0 1 0 877650538 2650112 293 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 647 293 249 194 0 33 0
[pid=5233] ppid=5212 vsize=101456 CPUtime=2.02
/proc/5233/stat : 5233 (apt-get) D 5212 5212 4159 34819 4229 4202496 9364 0 535 0 194 8 0 0 18 0 1 0 877652377 103890944 9824 1283457024 134512640 134619611 4288047136 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/5233/statm: 25364 9824 9771 27 0 58 0
Current children cumulated CPU time (s) 16.24
Current children cumulated vsize (KiB) 104044

[startup+24.0143 s]
/proc/loadavg: 1.21 1.08 0.82 1/45 5233
/proc/meminfo: memFree=601096/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2588 CPUtime=14.22
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 688 49798 0 1 0 0 1379 43 18 0 1 0 877650538 2650112 293 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 647 293 249 194 0 33 0
[pid=5233] ppid=5212 vsize=44076 CPUtime=2.15
/proc/5233/stat : 5233 (apt-get) R 5212 5212 4159 34819 4229 4202496 18882 0 535 0 203 12 0 0 18 0 1 0 877652377 45133824 9926 1283457024 134512640 134619611 4288047136 18446744073709551615 4156753072 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/5233/statm: 11019 9926 9225 27 0 706 0
Current children cumulated CPU time (s) 16.37
Current children cumulated vsize (KiB) 46664

[startup+24.8045 s]
/proc/loadavg: 1.20 1.08 0.82 2/45 5233
/proc/meminfo: memFree=597872/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2588 CPUtime=14.22
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 688 49798 0 1 0 0 1379 43 18 0 1 0 877650538 2650112 293 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 647 293 249 194 0 33 0
[pid=5233] ppid=5212 vsize=44848 CPUtime=2.94
/proc/5233/stat : 5233 (apt-get) R 5212 5212 4159 34819 4229 4202496 19153 0 535 0 282 12 0 0 19 0 1 0 877652377 45924352 10147 1283457024 134512640 134619611 4288047136 18446744073709551615 4159161837 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/5233/statm: 11212 10147 9293 27 0 899 0
Current children cumulated CPU time (s) 17.16
Current children cumulated vsize (KiB) 47436

[startup+25.0046 s]
/proc/loadavg: 1.20 1.08 0.82 2/45 5233
/proc/meminfo: memFree=597872/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2588 CPUtime=14.22
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 688 49798 0 1 0 0 1379 43 18 0 1 0 877650538 2650112 293 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 647 293 249 194 0 33 0
[pid=5233] ppid=5212 vsize=44848 CPUtime=3.14
/proc/5233/stat : 5233 (apt-get) R 5212 5212 4159 34819 4229 4202496 19153 0 535 0 302 12 0 0 19 0 1 0 877652377 45924352 10147 1283457024 134512640 134619611 4288047136 18446744073709551615 4159163500 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/5233/statm: 11212 10147 9293 27 0 899 0
Current children cumulated CPU time (s) 17.36
Current children cumulated vsize (KiB) 47436

[startup+25.1046 s]
/proc/loadavg: 1.20 1.08 0.82 2/45 5233
/proc/meminfo: memFree=597872/1048576 swapFree=2084088/2097144
[pid=5212] ppid=5211 vsize=2588 CPUtime=14.22
/proc/5212/stat : 5212 (apt-get-trendy-) S 5211 5212 4159 34819 4229 4202496 688 49798 0 1 0 0 1379 43 18 0 1 0 877650538 2650112 293 1283457024 134512640 135304128 4290121088 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/5212/statm: 647 293 249 194 0 33 0
[pid=5233] ppid=5212 vsize=44848 CPUtime=3.24
/proc/5233/stat : 5233 (apt-get) R 5212 5212 4159 34819 4229 4202496 19153 0 535 0 312 12 0 0 19 0 1 0 877652377 45924352 10147 1283457024 134512640 134619611 4288047136 18446744073709551615 4159249653 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/5233/statm: 11212 10147 9293 27 0 899 0
Current children cumulated CPU time (s) 17.46
Current children cumulated vsize (KiB) 47436

Child status: 100
Real time (s): 25.1308
CPU time (s): 17.4931
CPU user time (s): 16.9251
CPU system time (s): 0.568035
CPU usage (%): 69.6081
Max. virtual memory (cumulated for all children) (KiB): 185300

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 16.9251
system time used= 0.568035
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 69660
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= 540
involuntary context switches= 329

runsolver used 0 second user time and 0.012 second system time

The end