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/rand815.sarge.cudf.sarge.log.runsolver ./apt-pbo-trendy-1.0.6 /home/misc2010/data/icse/sarge/rand815.sarge.cudf /home/misc2010/tmp/201012070034/apt-pbo-trendy-1.0.6/rand815.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.89 0.99 1.04 5/45 26283
/proc/meminfo: memFree=853376/1048576 swapFree=2077184/2097144
[pid=26282] ppid=26281 vsize=1676 CPUtime=0
/proc/26282/stat : 26282 (sh) S 26281 26282 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 882967551 1716224 129 1283457024 134512640 134594024 4292521952 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/26282/statm: 419 129 112 20 0 45 0

[startup+0.232662 s]
/proc/loadavg: 0.89 0.99 1.04 5/45 26283
/proc/meminfo: memFree=853376/1048576 swapFree=2077184/2097144
[pid=26282] ppid=26281 vsize=1676 CPUtime=0
/proc/26282/stat : 26282 (sh) S 26281 26282 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 882967551 1716224 129 1283457024 134512640 134594024 4292521952 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/26282/statm: 419 129 112 20 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1676

[startup+0.312693 s]
/proc/loadavg: 0.89 0.99 1.04 5/45 26283
/proc/meminfo: memFree=853376/1048576 swapFree=2077184/2097144
[pid=26282] ppid=26281 vsize=1676 CPUtime=0
/proc/26282/stat : 26282 (sh) S 26281 26282 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 882967551 1716224 129 1283457024 134512640 134594024 4292521952 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/26282/statm: 419 129 112 20 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1676

[startup+0.412718 s]
/proc/loadavg: 0.89 0.99 1.04 5/45 26283
/proc/meminfo: memFree=853376/1048576 swapFree=2077184/2097144
[pid=26282] ppid=26281 vsize=1676 CPUtime=0
/proc/26282/stat : 26282 (sh) S 26281 26282 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 882967551 1716224 129 1283457024 134512640 134594024 4292521952 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/26282/statm: 419 129 112 20 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1676

[startup+0.712817 s]
/proc/loadavg: 0.89 0.99 1.04 5/45 26283
/proc/meminfo: memFree=853376/1048576 swapFree=2077184/2097144
[pid=26282] ppid=26281 vsize=1676 CPUtime=0
/proc/26282/stat : 26282 (sh) S 26281 26282 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 882967551 1716224 129 1283457024 134512640 134594024 4292521952 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/26282/statm: 419 129 112 20 0 45 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 1676

[startup+1.51297 s]
/proc/loadavg: 0.89 0.99 1.04 2/47 26288
/proc/meminfo: memFree=827548/1048576 swapFree=2077184/2097144
[pid=26282] ppid=26281 vsize=1676 CPUtime=0
/proc/26282/stat : 26282 (sh) S 26281 26282 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 882967551 1716224 129 1283457024 134512640 134594024 4292521952 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/26282/statm: 419 129 112 20 0 45 0
[pid=26284] ppid=26282 vsize=8348 CPUtime=0.04
/proc/26284/stat : 26284 (apt-pbo) S 26282 26282 4159 34819 4229 4202496 1608 412 0 0 2 2 0 0 25 0 1 0 882967552 8548352 1421 1283457024 134512640 135744540 4294320320 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/26284/statm: 2087 1421 646 301 0 820 0
[pid=26287] ppid=26284 vsize=15060 CPUtime=1.45
/proc/26287/stat : 26287 (cudftodeb.nativ) R 26284 26282 4159 34819 4229 4202496 5733 0 0 0 131 14 0 0 25 0 1 0 882967557 15421440 3401 1283457024 134512640 135029684 4288936960 18446744073709551615 134876208 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/26287/statm: 3765 3401 258 127 0 3148 0
Current children cumulated CPU time (s) 1.49
Current children cumulated vsize (KiB) 25084

[startup+3.10679 s]
/proc/loadavg: 0.90 0.99 1.04 1/48 26296
/proc/meminfo: memFree=832540/1048576 swapFree=2077184/2097144
[pid=26282] ppid=26281 vsize=1676 CPUtime=0
/proc/26282/stat : 26282 (sh) S 26281 26282 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 882967551 1716224 129 1283457024 134512640 134594024 4292521952 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/26282/statm: 419 129 112 20 0 45 0
[pid=26284] ppid=26282 vsize=15456 CPUtime=2.15
/proc/26284/stat : 26284 (apt-pbo) S 26282 26282 4159 34819 4229 4202496 3996 11793 0 82 9 3 175 28 18 0 1 0 882967552 15826944 3161 1283457024 134512640 135744540 4294320320 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/26284/statm: 3864 3161 2075 301 0 1136 0
Current children cumulated CPU time (s) 2.15
Current children cumulated vsize (KiB) 17132
heavy processes:

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

[startup+3.30683 s]
/proc/loadavg: 0.90 0.99 1.04 2/48 26301
/proc/meminfo: memFree=829704/1048576 swapFree=2077184/2097144
[pid=26282] ppid=26281 vsize=1676 CPUtime=0
/proc/26282/stat : 26282 (sh) S 26281 26282 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 882967551 1716224 129 1283457024 134512640 134594024 4292521952 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/26282/statm: 419 129 112 20 0 45 0
[pid=26284] ppid=26282 vsize=15456 CPUtime=2.17
/proc/26284/stat : 26284 (apt-pbo) S 26282 26282 4159 34819 4229 4202496 3996 11793 0 82 10 4 175 28 18 0 1 0 882967552 15826944 3161 1283457024 134512640 135744540 4294320320 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0
/proc/26284/statm: 3864 3161 2075 301 0 1136 0
[pid=26298] ppid=26284 vsize=2580 CPUtime=0
/proc/26298/stat : 26298 (apt-get.sh) S 26284 26282 4159 34819 4229 4202496 461 489 0 0 0 0 0 0 18 0 1 0 882967842 2641920 277 1283457024 134512640 135304128 4289428272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26298/statm: 645 277 235 194 0 31 0
[pid=26301] ppid=26298 vsize=10680 CPUtime=0.36
/proc/26301/stat : 26301 (apt-get) R 26298 26282 4159 34819 4229 4202496 2142 0 0 0 32 4 0 0 25 0 1 0 882967842 10936320 2068 1283457024 134512640 134649604 4292335136 18446744073709551615 4158781232 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/26301/statm: 2670 2068 1772 34 0 299 0
Current children cumulated CPU time (s) 2.53
Current children cumulated vsize (KiB) 30392

[startup+3.50687 s]
/proc/loadavg: 0.90 0.99 1.04 2/48 26301
/proc/meminfo: memFree=829456/1048576 swapFree=2077184/2097144
[pid=26282] ppid=26281 vsize=1676 CPUtime=0
/proc/26282/stat : 26282 (sh) S 26281 26282 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 882967551 1716224 129 1283457024 134512640 134594024 4292521952 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/26282/statm: 419 129 112 20 0 45 0
[pid=26284] ppid=26282 vsize=15456 CPUtime=2.2
/proc/26284/stat : 26284 (apt-pbo) R 26282 26282 4159 34819 4229 4202496 3996 11793 0 82 10 7 175 28 18 0 1 0 882967552 15826944 3161 1283457024 134512640 135744540 4294320320 18446744073709551615 4294960130 0 0 128 0 0 0 0 17 0 0 0 0
/proc/26284/statm: 3864 3161 2075 301 0 1136 0
[pid=26298] ppid=26284 vsize=2580 CPUtime=0
/proc/26298/stat : 26298 (apt-get.sh) S 26284 26282 4159 34819 4229 4202496 461 489 0 0 0 0 0 0 18 0 1 0 882967842 2641920 277 1283457024 134512640 135304128 4289428272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26298/statm: 645 277 235 194 0 31 0
[pid=26301] ppid=26298 vsize=10680 CPUtime=0.52
/proc/26301/stat : 26301 (apt-get) R 26298 26282 4159 34819 4229 4202496 2149 0 0 0 46 6 0 0 25 0 1 0 882967842 10936320 2075 1283457024 134512640 134649604 4292335136 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/26301/statm: 2670 2075 1772 34 0 299 0
Current children cumulated CPU time (s) 2.72
Current children cumulated vsize (KiB) 30392

[startup+3.60689 s]
/proc/loadavg: 0.90 0.99 1.04 2/48 26301
/proc/meminfo: memFree=829456/1048576 swapFree=2077184/2097144
[pid=26282] ppid=26281 vsize=1676 CPUtime=0
/proc/26282/stat : 26282 (sh) S 26281 26282 4159 34819 4229 4202496 221 174 0 0 0 0 0 0 25 0 1 0 882967551 1716224 129 1283457024 134512640 134594024 4292521952 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0
/proc/26282/statm: 419 129 112 20 0 45 0
[pid=26284] ppid=26282 vsize=15456 CPUtime=2.2
/proc/26284/stat : 26284 (apt-pbo) R 26282 26282 4159 34819 4229 4202496 3996 11793 0 82 10 7 175 28 18 0 1 0 882967552 15826944 3161 1283457024 134512640 135744540 4294320320 18446744073709551615 135099953 0 0 128 0 0 0 0 17 0 0 0 0
/proc/26284/statm: 3864 3161 2075 301 0 1136 0
[pid=26298] ppid=26284 vsize=2580 CPUtime=0
/proc/26298/stat : 26298 (apt-get.sh) S 26284 26282 4159 34819 4229 4202496 461 489 0 0 0 0 0 0 18 0 1 0 882967842 2641920 277 1283457024 134512640 135304128 4289428272 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/26298/statm: 645 277 235 194 0 31 0
[pid=26301] ppid=26298 vsize=10680 CPUtime=0.62
/proc/26301/stat : 26301 (apt-get) R 26298 26282 4159 34819 4229 4202496 2150 0 0 0 52 10 0 0 25 0 1 0 882967842 10936320 2076 1283457024 134512640 134649604 4292335136 18446744073709551615 4294960130 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/26301/statm: 2670 2076 1772 34 0 299 0
Current children cumulated CPU time (s) 2.82
Current children cumulated vsize (KiB) 30392

Child status: 0
Real time (s): 3.67887
CPU time (s): 2.90018
CPU user time (s): 2.38415
CPU system time (s): 0.516032
CPU usage (%): 78.8334
Max. virtual memory (cumulated for all children) (KiB): 65348

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 2.38415
system time used= 0.516032
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 19854
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= 18023
involuntary context switches= 17996

runsolver used 0 second user time and 0.012 second system time

The end