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/rand95e48b.cudf.difficult.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/difficult//rand95e48b.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/rand95e48b.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.02 1.02 1.00 2/44 1076
/proc/meminfo: memFree=749116/1048576 swapFree=2077616/2097144
[pid=1076] ppid=1074 vsize=3020 CPUtime=0
/proc/1076/stat : 1076 (runsolver) D 1074 1076 4159 34819 4229 4202560 72 0 0 0 0 0 0 0 25 0 1 0 884726742 3092480 93 1283457024 134512640 134586868 4289768544 18446744073709551615 4294960130 0 0 0 24578 18446744071564332000 0 0 17 0 0 0 0
/proc/1076/statm: 755 93 62 19 0 53 0

[startup+0.115895 s]
/proc/loadavg: 1.02 1.02 1.00 2/44 1076
/proc/meminfo: memFree=749116/1048576 swapFree=2077616/2097144
[pid=1076] ppid=1074 vsize=2584 CPUtime=0
/proc/1076/stat : 1076 (apt-get-trendy-) S 1074 1076 4159 34819 4229 4202496 506 1358 0 0 0 0 0 0 25 0 1 0 884726742 2646016 279 1283457024 134512640 135304128 4290035056 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1076/statm: 646 279 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.207852 s]
/proc/loadavg: 1.02 1.02 1.00 2/44 1076
/proc/meminfo: memFree=749116/1048576 swapFree=2077616/2097144
[pid=1076] ppid=1074 vsize=2584 CPUtime=0
/proc/1076/stat : 1076 (apt-get-trendy-) S 1074 1076 4159 34819 4229 4202496 506 1358 0 0 0 0 0 0 25 0 1 0 884726742 2646016 279 1283457024 134512640 135304128 4290035056 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1076/statm: 646 279 237 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.307865 s]
/proc/loadavg: 1.02 1.02 1.00 2/44 1076
/proc/meminfo: memFree=749116/1048576 swapFree=2077616/2097144
[pid=1076] ppid=1074 vsize=2584 CPUtime=0
/proc/1076/stat : 1076 (apt-get-trendy-) S 1074 1076 4159 34819 4229 4202496 552 1853 0 3 0 0 0 0 23 0 1 0 884726742 2646016 282 1283457024 134512640 135304128 4290035056 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1076/statm: 646 282 240 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+0.71178 s]
/proc/loadavg: 1.02 1.02 1.00 2/44 1076
/proc/meminfo: memFree=749116/1048576 swapFree=2077616/2097144
[pid=1076] ppid=1074 vsize=2584 CPUtime=0
/proc/1076/stat : 1076 (apt-get-trendy-) S 1074 1076 4159 34819 4229 4202496 552 1853 0 3 0 0 0 0 23 0 1 0 884726742 2646016 282 1283457024 134512640 135304128 4290035056 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1076/statm: 646 282 240 194 0 32 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2584

[startup+1.51195 s]
/proc/loadavg: 1.02 1.02 1.00 2/46 1087
/proc/meminfo: memFree=706036/1048576 swapFree=2077616/2097144
[pid=1076] ppid=1074 vsize=2584 CPUtime=0
/proc/1076/stat : 1076 (apt-get-trendy-) S 1074 1076 4159 34819 4229 4202496 552 1853 0 3 0 0 0 0 23 0 1 0 884726742 2646016 282 1283457024 134512640 135304128 4290035056 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1076/statm: 646 282 240 194 0 32 0
[pid=1087] ppid=1076 vsize=27056 CPUtime=1.14
/proc/1087/stat : 1087 (cudftodeb.nativ) R 1076 1076 4159 34819 4229 4202496 6345 0 11 0 110 4 0 0 25 0 1 0 884726772 27705344 6283 1283457024 134512640 135004320 4287502960 18446744073709551615 134948154 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/1087/statm: 6764 6283 225 121 0 6156 0
Current children cumulated CPU time (s) 1.14
Current children cumulated vsize (KiB) 29640

[startup+3.11241 s]
/proc/loadavg: 1.02 1.02 1.00 2/46 1087
/proc/meminfo: memFree=683096/1048576 swapFree=2077616/2097144
[pid=1076] ppid=1074 vsize=2584 CPUtime=0
/proc/1076/stat : 1076 (apt-get-trendy-) S 1074 1076 4159 34819 4229 4202496 552 1853 0 3 0 0 0 0 23 0 1 0 884726742 2646016 282 1283457024 134512640 135304128 4290035056 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1076/statm: 646 282 240 194 0 32 0
[pid=1087] ppid=1076 vsize=61656 CPUtime=2.74
/proc/1087/stat : 1087 (cudftodeb.nativ) R 1076 1076 4159 34819 4229 4202496 14818 0 11 0 269 5 0 0 25 0 1 0 884726772 63135744 14756 1283457024 134512640 135004320 4287502960 18446744073709551615 134996501 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/1087/statm: 15414 14756 236 121 0 14806 0
Current children cumulated CPU time (s) 2.74
Current children cumulated vsize (KiB) 64240

[startup+6.30424 s]
/proc/loadavg: 1.01 1.02 1.00 2/46 1087
/proc/meminfo: memFree=619112/1048576 swapFree=2077616/2097144
[pid=1076] ppid=1074 vsize=2592 CPUtime=5.55
/proc/1076/stat : 1076 (apt-get-trendy-) S 1074 1076 4159 34819 4229 4202496 632 25879 0 14 0 1 541 13 22 0 1 0 884726742 2654208 285 1283457024 134512640 135304128 4290035056 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1076/statm: 648 285 241 194 0 34 0
Current children cumulated CPU time (s) 5.55
Current children cumulated vsize (KiB) 2592

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

[startup+6.40422 s]
/proc/loadavg: 1.01 1.02 1.00 2/46 1087
/proc/meminfo: memFree=619112/1048576 swapFree=2077616/2097144
[pid=1076] ppid=1074 vsize=2592 CPUtime=5.55
/proc/1076/stat : 1076 (apt-get-trendy-) S 1074 1076 4159 34819 4229 4202496 632 25879 0 14 0 1 541 13 22 0 1 0 884726742 2654208 285 1283457024 134512640 135304128 4290035056 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1076/statm: 648 285 241 194 0 34 0
Current children cumulated CPU time (s) 5.55
Current children cumulated vsize (KiB) 2592

[startup+8.00435 s]
/proc/loadavg: 1.01 1.02 1.00 2/46 1097
/proc/meminfo: memFree=672080/1048576 swapFree=2077616/2097144
[pid=1076] ppid=1074 vsize=2592 CPUtime=5.79
/proc/1076/stat : 1076 (apt-get-trendy-) S 1074 1076 4159 34819 4229 4202496 686 28373 0 26 0 1 560 18 18 0 1 0 884726742 2654208 293 1283457024 134512640 135304128 4290035056 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1076/statm: 648 293 249 194 0 34 0
[pid=1097] ppid=1076 vsize=101456 CPUtime=0.86
/proc/1097/stat : 1097 (apt-get) D 1076 1076 4159 34819 4229 4202496 4911 0 264 0 82 4 0 0 22 0 1 0 884727451 103890944 5099 1283457024 134512640 134619611 4288317520 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/1097/statm: 25364 5099 5046 27 0 58 0
Current children cumulated CPU time (s) 6.65
Current children cumulated vsize (KiB) 104048

[startup+8.80439 s]
/proc/loadavg: 1.01 1.02 1.00 1/46 1097
/proc/meminfo: memFree=647924/1048576 swapFree=2077616/2097144
[pid=1076] ppid=1074 vsize=2592 CPUtime=5.79
/proc/1076/stat : 1076 (apt-get-trendy-) S 1074 1076 4159 34819 4229 4202496 686 28373 0 26 0 1 560 18 18 0 1 0 884726742 2654208 293 1283457024 134512640 135304128 4290035056 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1076/statm: 648 293 249 194 0 34 0
[pid=1097] ppid=1076 vsize=101456 CPUtime=0.87
/proc/1097/stat : 1097 (apt-get) D 1076 1076 4159 34819 4229 4202496 4949 0 266 0 82 5 0 0 18 0 1 0 884727451 103890944 5139 1283457024 134512640 134619611 4288317520 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/1097/statm: 25364 5139 5086 27 0 58 0
Current children cumulated CPU time (s) 6.66
Current children cumulated vsize (KiB) 104048

[startup+9.0125 s]
/proc/loadavg: 1.01 1.02 1.00 1/46 1097
/proc/meminfo: memFree=647924/1048576 swapFree=2077616/2097144
[pid=1076] ppid=1074 vsize=2592 CPUtime=5.79
/proc/1076/stat : 1076 (apt-get-trendy-) S 1074 1076 4159 34819 4229 4202496 686 28373 0 26 0 1 560 18 18 0 1 0 884726742 2654208 293 1283457024 134512640 135304128 4290035056 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1076/statm: 648 293 249 194 0 34 0
[pid=1097] ppid=1076 vsize=24688 CPUtime=1
/proc/1097/stat : 1097 (apt-get) R 1076 1076 4159 34819 4229 4202496 9914 0 266 0 95 5 0 0 18 0 1 0 884727451 25280512 5373 1283457024 134512640 134619611 4288317520 18446744073709551615 4159628022 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/1097/statm: 6172 5373 4835 27 0 543 0
Current children cumulated CPU time (s) 6.79
Current children cumulated vsize (KiB) 27280

Child status: 100
Real time (s): 9.10226
CPU time (s): 6.89643
CPU user time (s): 6.64042
CPU system time (s): 0.256016
CPU usage (%): 75.7661
Max. virtual memory (cumulated for all children) (KiB): 104096

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 6.64041
system time used= 0.256016
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 39109
page faults= 292
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 351
involuntary context switches= 133

runsolver used 0 second user time and 0.004 second system time

The end