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-pbo-trendy-1.0.6/rand915.sarge.cudf.sarge.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/icse/sarge/rand915.sarge.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/rand915.sarge.cudf.sarge.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: 0.96 1.00 0.99 5/45 28799
/proc/meminfo: memFree=854376/1048576 swapFree=2077628/2097144
[pid=28798] ppid=28797 vsize=1680 CPUtime=0
/proc/28798/stat : 28798 (sh) R 28797 28798 4159 34819 4229 4202496 206 0 0 0 0 0 0 0 25 0 1 0 883587338 1720320 127 1283457024 134512640 134594024 4293974336 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/28798/statm: 420 127 110 20 0 46 0
[pid=28799] ppid=28798 vsize=1680 CPUtime=0
/proc/28799/stat : 28799 (sh) R 28798 28798 4159 34819 4229 4202560 0 0 0 0 0 0 0 0 25 0 1 0 883587338 1720320 17 1283457024 134512640 134594024 4293974336 18446744073709551615 4294960130 0 0 0 2 0 0 0 17 0 0 0 0
/proc/28799/statm: 420 17 0 20 0 46 0

[startup+0.124299 s]
/proc/loadavg: 0.96 1.00 0.99 5/45 28799
/proc/meminfo: memFree=854376/1048576 swapFree=2077628/2097144
[pid=28798] ppid=28797 vsize=1680 CPUtime=0.01
/proc/28798/stat : 28798 (sh) S 28797 28798 4159 34819 4229 4202496 221 175 0 0 0 1 0 0 25 0 1 0 883587338 1720320 129 1283457024 134512640 134594024 4293974336 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28798/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 1680

[startup+0.204321 s]
/proc/loadavg: 0.96 1.00 0.99 5/45 28799
/proc/meminfo: memFree=854376/1048576 swapFree=2077628/2097144
[pid=28798] ppid=28797 vsize=1680 CPUtime=0.01
/proc/28798/stat : 28798 (sh) S 28797 28798 4159 34819 4229 4202496 221 175 0 0 0 1 0 0 25 0 1 0 883587338 1720320 129 1283457024 134512640 134594024 4293974336 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28798/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 1680

[startup+0.304353 s]
/proc/loadavg: 0.96 1.00 0.99 5/45 28799
/proc/meminfo: memFree=854376/1048576 swapFree=2077628/2097144
[pid=28798] ppid=28797 vsize=1680 CPUtime=0.01
/proc/28798/stat : 28798 (sh) S 28797 28798 4159 34819 4229 4202496 221 175 0 0 0 1 0 0 25 0 1 0 883587338 1720320 129 1283457024 134512640 134594024 4293974336 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28798/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 1680

[startup+0.704475 s]
/proc/loadavg: 0.96 1.00 0.99 5/45 28799
/proc/meminfo: memFree=854376/1048576 swapFree=2077628/2097144
[pid=28798] ppid=28797 vsize=1680 CPUtime=0.01
/proc/28798/stat : 28798 (sh) S 28797 28798 4159 34819 4229 4202496 221 175 0 0 0 1 0 0 25 0 1 0 883587338 1720320 129 1283457024 134512640 134594024 4293974336 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28798/statm: 420 129 112 20 0 46 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 1680

[startup+1.50466 s]
/proc/loadavg: 0.96 1.00 0.99 2/47 28804
/proc/meminfo: memFree=829044/1048576 swapFree=2077628/2097144
[pid=28798] ppid=28797 vsize=1680 CPUtime=0.01
/proc/28798/stat : 28798 (sh) S 28797 28798 4159 34819 4229 4202496 221 175 0 0 0 1 0 0 25 0 1 0 883587338 1720320 129 1283457024 134512640 134594024 4293974336 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28798/statm: 420 129 112 20 0 46 0
[pid=28801] ppid=28798 vsize=8352 CPUtime=0.04
/proc/28801/stat : 28801 (apt-pbo) S 28798 28798 4159 34819 4229 4202496 1609 412 0 0 2 2 0 0 25 0 1 0 883587338 8552448 1421 1283457024 134512640 135744540 4289166288 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28801/statm: 2088 1421 646 301 0 821 0
[pid=28804] ppid=28801 vsize=15060 CPUtime=1.44
/proc/28804/stat : 28804 (cudftodeb.nativ) R 28801 28798 4159 34819 4229 4202496 5733 0 0 0 121 23 0 0 25 0 1 0 883587343 15421440 3401 1283457024 134512640 135029684 4294437184 18446744073709551615 134862243 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/28804/statm: 3765 3401 258 127 0 3148 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 25092

[startup+3.10397 s]
/proc/loadavg: 0.96 1.00 0.99 2/48 28812
/proc/meminfo: memFree=843424/1048576 swapFree=2077628/2097144
[pid=28798] ppid=28797 vsize=1680 CPUtime=0.01
/proc/28798/stat : 28798 (sh) S 28797 28798 4159 34819 4229 4202496 221 175 0 0 0 1 0 0 25 0 1 0 883587338 1720320 129 1283457024 134512640 134594024 4293974336 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28798/statm: 420 129 112 20 0 46 0
[pid=28801] ppid=28798 vsize=15460 CPUtime=2.18
/proc/28801/stat : 28801 (apt-pbo) S 28798 28798 4159 34819 4229 4202496 3994 11794 0 82 8 4 168 38 18 0 1 0 883587338 15831040 3161 1283457024 134512640 135744540 4289166288 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28801/statm: 3865 3161 2075 301 0 1137 0
Current children cumulated CPU time (s) 2.19
Current children cumulated vsize (KiB) 17140
heavy processes:

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

[startup+3.21399 s]
/proc/loadavg: 0.96 1.00 0.99 2/48 28817
/proc/meminfo: memFree=830580/1048576 swapFree=2077628/2097144
[pid=28798] ppid=28797 vsize=1680 CPUtime=0.01
/proc/28798/stat : 28798 (sh) S 28797 28798 4159 34819 4229 4202496 221 175 0 0 0 1 0 0 25 0 1 0 883587338 1720320 129 1283457024 134512640 134594024 4293974336 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28798/statm: 420 129 112 20 0 46 0
[pid=28801] ppid=28798 vsize=15460 CPUtime=2.2
/proc/28801/stat : 28801 (apt-pbo) R 28798 28798 4159 34819 4229 4202496 3994 11794 0 82 8 6 168 38 18 0 1 0 883587338 15831040 3161 1283457024 134512640 135744540 4289166288 18446744073709551615 4294960130 0 0 128 0 0 0 0 17 0 0 0 0
/proc/28801/statm: 3865 3161 2075 301 0 1137 0
[pid=28814] ppid=28801 vsize=2576 CPUtime=0
/proc/28814/stat : 28814 (apt-get.sh) S 28801 28798 4159 34819 4229 4202496 459 489 0 0 0 0 0 0 18 0 1 0 883587614 2637824 277 1283457024 134512640 135304128 4287166688 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28814/statm: 644 277 235 194 0 30 0
[pid=28817] ppid=28814 vsize=10680 CPUtime=0.4
/proc/28817/stat : 28817 (apt-get) R 28814 28798 4159 34819 4229 4202496 2147 0 0 0 31 9 0 0 25 0 1 0 883587614 10936320 2073 1283457024 134512640 134649604 4289647456 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/28817/statm: 2670 2073 1772 34 0 299 0
Current children cumulated CPU time (s) 2.61
Current children cumulated vsize (KiB) 30396

[startup+3.40401 s]
/proc/loadavg: 0.96 1.00 0.99 3/48 28817
/proc/meminfo: memFree=830332/1048576 swapFree=2077628/2097144
[pid=28798] ppid=28797 vsize=1680 CPUtime=0.01
/proc/28798/stat : 28798 (sh) S 28797 28798 4159 34819 4229 4202496 221 175 0 0 0 1 0 0 25 0 1 0 883587338 1720320 129 1283457024 134512640 134594024 4293974336 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28798/statm: 420 129 112 20 0 46 0
[pid=28801] ppid=28798 vsize=15460 CPUtime=2.21
/proc/28801/stat : 28801 (apt-pbo) S 28798 28798 4159 34819 4229 4202496 3994 11794 0 82 8 7 168 38 18 0 1 0 883587338 15831040 3161 1283457024 134512640 135744540 4289166288 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/28801/statm: 3865 3161 2075 301 0 1137 0
[pid=28814] ppid=28801 vsize=2576 CPUtime=0
/proc/28814/stat : 28814 (apt-get.sh) S 28801 28798 4159 34819 4229 4202496 459 489 0 0 0 0 0 0 18 0 1 0 883587614 2637824 277 1283457024 134512640 135304128 4287166688 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/28814/statm: 644 277 235 194 0 30 0
[pid=28817] ppid=28814 vsize=10680 CPUtime=0.58
/proc/28817/stat : 28817 (apt-get) R 28814 28798 4159 34819 4229 4202496 2149 0 0 0 45 13 0 0 25 0 1 0 883587614 10936320 2075 1283457024 134512640 134649604 4289647456 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/28817/statm: 2670 2075 1772 34 0 299 0
Current children cumulated CPU time (s) 2.8
Current children cumulated vsize (KiB) 30396

[startup+3.50404 s]
/proc/loadavg: 0.96 1.00 0.99 3/48 28817
/proc/meminfo: memFree=830332/1048576 swapFree=2077628/2097144
[pid=28798] ppid=28797 vsize=1680 CPUtime=0.01
/proc/28798/stat : 28798 (sh) S 28797 28798 4159 34819 4229 4202496 221 175 0 0 0 1 0 0 25 0 1 0 883587338 1720320 129 1283457024 134512640 134594024 4293974336 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/28798/statm: 420 129 112 20 0 46 0
[pid=28801] ppid=28798 vsize=15992 CPUtime=2.89
/proc/28801/stat : 28801 (apt-pbo) R 28798 28798 4159 34819 4229 4202496 4204 14907 0 82 8 8 220 53 18 0 1 0 883587338 16375808 3297 1283457024 134512640 135744540 4289166288 18446744073709551615 4294960130 0 0 128 0 0 0 0 17 0 0 0 0
/proc/28801/statm: 3998 3297 2078 301 0 1270 0
Current children cumulated CPU time (s) 2.9
Current children cumulated vsize (KiB) 17672

Child status: 0
Real time (s): 3.53667
CPU time (s): 2.91618
CPU user time (s): 2.29214
CPU system time (s): 0.624039
CPU usage (%): 82.4555
Max. virtual memory (cumulated for all children) (KiB): 65356

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 2.29214
system time used= 0.624039
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 19851
page faults= 82
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 17933
involuntary context switches= 17911

runsolver used 0 second user time and 0 second system time

The end