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/randa45895.cudf.difficult.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/difficult//randa45895.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/randa45895.cudf.difficult.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.00 1.00 1.00 1/41 2122
/proc/meminfo: memFree=705440/1048576 swapFree=2080276/2097144
[pid=2114] ppid=2113 vsize=2584 CPUtime=0
/proc/2114/stat : 2114 (apt-get-trendy-) S 2113 2114 4159 34819 4229 4202496 516 1365 0 0 0 0 0 0 25 0 1 0 884966629 2646016 281 1283457024 134512640 135304128 4289611024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2114/statm: 646 281 237 194 0 32 0
[pid=2122] ppid=2114 vsize=2004 CPUtime=0
/proc/2122/stat : 2122 (cp) D 2114 2114 4159 34819 4229 4202496 239 0 0 0 0 0 0 0 25 0 1 0 884966630 2052096 168 1283457024 134512640 134614052 4289353056 18446744073709551615 4294960130 0 0 0 0 18446744071564252162 0 0 17 0 0 0 0
/proc/2122/statm: 501 168 139 25 0 47 0

[startup+0.193892 s]
/proc/loadavg: 1.00 1.00 1.00 1/41 2122
/proc/meminfo: memFree=705440/1048576 swapFree=2080276/2097144
[pid=2114] ppid=2113 vsize=2584 CPUtime=0
/proc/2114/stat : 2114 (apt-get-trendy-) S 2113 2114 4159 34819 4229 4202496 516 1365 0 0 0 0 0 0 25 0 1 0 884966629 2646016 281 1283457024 134512640 135304128 4289611024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2114/statm: 646 281 237 194 0 32 0
[pid=2122] ppid=2114 vsize=2004 CPUtime=0.01
/proc/2122/stat : 2122 (cp) D 2114 2114 4159 34819 4229 4202496 254 0 0 0 0 1 0 0 24 0 1 0 884966630 2052096 183 1283457024 134512640 134614052 4289353056 18446744073709551615 4294960130 0 0 0 0 18446744071564332000 0 0 17 0 0 0 0
/proc/2122/statm: 501 183 145 25 0 47 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 4588

[startup+0.20589 s]
/proc/loadavg: 1.00 1.00 1.00 1/41 2122
/proc/meminfo: memFree=705440/1048576 swapFree=2080276/2097144
[pid=2114] ppid=2113 vsize=2584 CPUtime=0
/proc/2114/stat : 2114 (apt-get-trendy-) S 2113 2114 4159 34819 4229 4202496 516 1365 0 0 0 0 0 0 25 0 1 0 884966629 2646016 281 1283457024 134512640 135304128 4289611024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2114/statm: 646 281 237 194 0 32 0
[pid=2122] ppid=2114 vsize=2004 CPUtime=0.01
/proc/2122/stat : 2122 (cp) D 2114 2114 4159 34819 4229 4202496 254 0 0 0 0 1 0 0 24 0 1 0 884966630 2052096 183 1283457024 134512640 134614052 4289353056 18446744073709551615 4294960130 0 0 0 0 18446744071564252162 0 0 17 0 0 0 0
/proc/2122/statm: 501 183 145 25 0 47 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 4588

[startup+0.312944 s]
/proc/loadavg: 1.00 1.00 1.00 1/41 2122
/proc/meminfo: memFree=705440/1048576 swapFree=2080276/2097144
[pid=2114] ppid=2113 vsize=2584 CPUtime=0.02
/proc/2114/stat : 2114 (apt-get-trendy-) S 2113 2114 4159 34819 4229 4202496 564 1865 0 0 0 0 0 2 23 0 1 0 884966629 2646016 284 1283457024 134512640 135304128 4289611024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2114/statm: 646 284 240 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 2584

[startup+0.713032 s]
/proc/loadavg: 1.00 1.00 1.00 1/41 2122
/proc/meminfo: memFree=705440/1048576 swapFree=2080276/2097144
[pid=2114] ppid=2113 vsize=2584 CPUtime=0.02
/proc/2114/stat : 2114 (apt-get-trendy-) S 2113 2114 4159 34819 4229 4202496 564 1865 0 0 0 0 0 2 23 0 1 0 884966629 2646016 284 1283457024 134512640 135304128 4289611024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2114/statm: 646 284 240 194 0 32 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 2584

[startup+1.51321 s]
/proc/loadavg: 1.00 1.00 1.00 2/42 2125
/proc/meminfo: memFree=659792/1048576 swapFree=2080276/2097144
[pid=2114] ppid=2113 vsize=2584 CPUtime=0.02
/proc/2114/stat : 2114 (apt-get-trendy-) S 2113 2114 4159 34819 4229 4202496 564 1865 0 0 0 0 0 2 23 0 1 0 884966629 2646016 284 1283457024 134512640 135304128 4289611024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2114/statm: 646 284 240 194 0 32 0
[pid=2125] ppid=2114 vsize=30780 CPUtime=1.27
/proc/2125/stat : 2125 (cudftodeb.nativ) R 2114 2114 4159 34819 4229 4202496 7283 0 3 0 127 0 0 0 25 0 1 0 884966651 31518720 7212 1283457024 134512640 135004320 4293727488 18446744073709551615 4158817869 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/2125/statm: 7695 7212 225 121 0 7087 0
Current children cumulated CPU time (s) 1.29
Current children cumulated vsize (KiB) 33364

[startup+3.11361 s]
/proc/loadavg: 1.00 1.00 1.00 2/42 2125
/proc/meminfo: memFree=637472/1048576 swapFree=2080276/2097144
[pid=2114] ppid=2113 vsize=2584 CPUtime=0.02
/proc/2114/stat : 2114 (apt-get-trendy-) S 2113 2114 4159 34819 4229 4202496 564 1865 0 0 0 0 0 2 23 0 1 0 884966629 2646016 284 1283457024 134512640 135304128 4289611024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2114/statm: 646 284 240 194 0 32 0
[pid=2125] ppid=2114 vsize=65628 CPUtime=2.88
/proc/2125/stat : 2125 (cudftodeb.nativ) R 2114 2114 4159 34819 4229 4202496 15855 0 3 0 284 4 0 0 25 0 1 0 884966651 67203072 15784 1283457024 134512640 135004320 4293727488 18446744073709551615 4159966202 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/2125/statm: 16407 15784 236 121 0 15799 0
Current children cumulated CPU time (s) 2.9
Current children cumulated vsize (KiB) 68212

[startup+6.30627 s]
/proc/loadavg: 1.00 1.00 1.00 2/42 2125
/proc/meminfo: memFree=576472/1048576 swapFree=2080276/2097144
[pid=2114] ppid=2113 vsize=2592 CPUtime=5.5
/proc/2114/stat : 2114 (apt-get-trendy-) S 2113 2114 4159 34819 4229 4202496 648 25899 0 3 0 0 534 16 22 0 1 0 884966629 2654208 287 1283457024 134512640 135304128 4289611024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2114/statm: 648 287 241 194 0 34 0
Current children cumulated CPU time (s) 5.5
Current children cumulated vsize (KiB) 2592

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

[startup+6.40626 s]
/proc/loadavg: 1.00 1.00 1.00 2/42 2125
/proc/meminfo: memFree=576472/1048576 swapFree=2080276/2097144
[pid=2114] ppid=2113 vsize=2592 CPUtime=5.5
/proc/2114/stat : 2114 (apt-get-trendy-) S 2113 2114 4159 34819 4229 4202496 648 25899 0 3 0 0 534 16 22 0 1 0 884966629 2654208 287 1283457024 134512640 135304128 4289611024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2114/statm: 648 287 241 194 0 34 0
Current children cumulated CPU time (s) 5.5
Current children cumulated vsize (KiB) 2592

[startup+8.00636 s]
/proc/loadavg: 1.08 1.02 1.01 1/42 2135
/proc/meminfo: memFree=606864/1048576 swapFree=2080276/2097144
[pid=2114] ppid=2113 vsize=2672 CPUtime=5.74
/proc/2114/stat : 2114 (apt-get-trendy-) S 2113 2114 4159 34819 4229 4202496 741 28412 0 4 0 0 556 18 18 0 1 0 884966629 2736128 315 1283457024 134512640 135304128 4289611024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2114/statm: 668 315 249 194 0 54 0
[pid=2135] ppid=2114 vsize=101464 CPUtime=0.85
/proc/2135/stat : 2135 (apt-get) D 2114 2114 4159 34819 4229 4202496 4912 0 264 0 81 4 0 0 19 0 1 0 884967306 103899136 5100 1283457024 134512640 134619611 4286979472 18446744073709551615 4294960130 0 0 4096 134217728 18446744071696460772 0 0 17 0 0 0 0
/proc/2135/statm: 25366 5100 5046 27 0 60 0
Current children cumulated CPU time (s) 6.59
Current children cumulated vsize (KiB) 104136

[startup+8.81584 s]
/proc/loadavg: 1.08 1.02 1.01 2/42 2135
/proc/meminfo: memFree=604576/1048576 swapFree=2080276/2097144
[pid=2114] ppid=2113 vsize=2672 CPUtime=5.74
/proc/2114/stat : 2114 (apt-get-trendy-) S 2113 2114 4159 34819 4229 4202496 741 28412 0 4 0 0 556 18 18 0 1 0 884966629 2736128 315 1283457024 134512640 135304128 4289611024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2114/statm: 668 315 249 194 0 54 0
[pid=2135] ppid=2114 vsize=24696 CPUtime=1.01
/proc/2135/stat : 2135 (apt-get) R 2114 2114 4159 34819 4229 4202496 9930 0 267 0 97 4 0 0 18 0 1 0 884967306 25288704 5390 1283457024 134512640 134619611 4286979472 18446744073709551615 4160029549 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/2135/statm: 6174 5390 4851 27 0 545 0
Current children cumulated CPU time (s) 6.75
Current children cumulated vsize (KiB) 27368

[startup+9.01628 s]
/proc/loadavg: 1.08 1.02 1.01 2/42 2135
/proc/meminfo: memFree=604576/1048576 swapFree=2080276/2097144
[pid=2114] ppid=2113 vsize=2672 CPUtime=5.74
/proc/2114/stat : 2114 (apt-get-trendy-) S 2113 2114 4159 34819 4229 4202496 741 28412 0 4 0 0 556 18 18 0 1 0 884966629 2736128 315 1283457024 134512640 135304128 4289611024 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/2114/statm: 668 315 249 194 0 54 0
[pid=2135] ppid=2114 vsize=25000 CPUtime=1.2
/proc/2135/stat : 2135 (apt-get) R 2114 2114 4159 34819 4229 4202496 10035 0 268 0 116 4 0 0 18 0 1 0 884967306 25600000 5454 1283457024 134512640 134619611 4286979472 18446744073709551615 4160009709 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/2135/statm: 6250 5454 4863 27 0 621 0
Current children cumulated CPU time (s) 6.94
Current children cumulated vsize (KiB) 27672

Child status: 100
Real time (s): 9.08238
CPU time (s): 7.02844
CPU user time (s): 6.79242
CPU system time (s): 0.236014
CPU usage (%): 77.3854
Max. virtual memory (cumulated for all children) (KiB): 104136

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 6.79242
system time used= 0.236014
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 39204
page faults= 272
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 283
involuntary context switches= 156

runsolver used 0 second user time and 0 second system time

The end