Rev 15: Add latency measurement. in file:///v/home/vila/.bazaar/plugins/transportstats/
Vincent Ladeuil
v.ladeuil+lp at free.fr
Mon Oct 8 10:46:17 BST 2007
At file:///v/home/vila/.bazaar/plugins/transportstats/
------------------------------------------------------------
revno: 15
revision-id: v.ladeuil+lp at free.fr-20071008094616-okycd9tkn2wocjwj
parent: v.ladeuil+lp at free.fr-20071007195240-cf3yoc88xn9sb2ty
committer: Vincent Ladeuil <v.ladeuil+lp at free.fr>
branch nick: transportstats
timestamp: Mon 2007-10-08 11:46:16 +0200
message:
Add latency measurement.
* tests/blackbox.py:
(TestTsDisplay.test_display): Relax the test.
* stats.py:
Rename the stat format and the associated classes. Add latency to
the formats
(Stats.collect): Renamed from nb_bytes_read. Also calculate
request # and average latency.
* decorator.py:
(StatsCollector): Add latency support (with a custom definition of
latency...).
(StatsCollector.readv): Create two distinct stats, one for the
method itsself, one for each (offset, length).
* commands.py:
(cmd_ts_display.run): Add number of requests and average latency.
* TODO:
Add results (a dedicated file or benchmark tests may be more
appropriate). Add main modification to each result before
forgetting what they were.
modified:
TODO todo-20070929082541-nqthugj4zxx7hufy-1
commands.py commands.py-20070927123419-zy82qayy9xzwxvzi-1
decorator.py decorator.py-20070926152401-52kuiex1mu755ajk-1
serialize.py serialize.py-20071005112454-5v72oa7pqcdhjytc-1
stats.py stats.py-20070928061304-7i3r2h4gg6rbi03e-1
tests/blackbox.py blackbox.py-20070930083839-9pz5gsxwefw4i294-1
tests/test_serialize.py test_serialize.py-20071005112455-vl4skuw4krtlt4rx-1
-------------- next part --------------
=== modified file 'TODO'
--- a/TODO 2007-10-07 19:52:40 +0000
+++ b/TODO 2007-10-08 09:46:16 +0000
@@ -128,7 +128,7 @@
-rw-r--r-- 1 vila vila 4441317 2007-09-30 15:41 .transport_stats_for_bzr
Bytes read: 68289613
-- revision 13:
+- revision 13: (share unique strings for base and relpath)
bzr branch stats+http+urllib://bazaar.launchpad.net/~bzr/bzr.webdav/webdav/
Branched 40 revision(s).
-rw-r--r-- 1 vila vila 5378 2007-10-07 16:16 .transport_stats_for_bzr
@@ -139,7 +139,7 @@
-rw-r--r-- 1 vila vila 1328776 2007-10-07 16:23 .transport_stats_for_bzr
Bytes read: 69083460
-- revision 14
+- revision 14 (replace method names by indices)
bzr branch stats+http+urllib://bazaar.launchpad.net/~bzr/bzr.webdav/webdav/ -r 40
Branched 40 revision(s).
-rw-r--r-- 1 vila vila 4157 2007-10-07 18:36 .transport_stats_for_bzr
@@ -148,3 +148,17 @@
Branched 2892 revision(s).
-rw-r--r-- 1 vila vila 969647 2007-10-07 18:41 .transport_stats_for_bzr
Bytes read: 69083460
+
+- revision 15 (add latency)
+ bzr branch stats+http+urllib://bazaar.launchpad.net/~bzr/bzr.webdav/webdav/ -r 40
+Branched 40 revision(s).
+-rw-r--r-- 1 vila vila 4271 2007-10-08 10:47 .transport_stats_for_bzr
+# requests: 36
+Bytes read: 189785
+Average latency: 48ms
+ bzr branch stats+http+urllib://bazaar-vcs.org/bzr/bzr.dev/ -r 2892
+Branched 2892 revision(s).
+-rw-r--r-- 1 vila vila 1006481 2007-10-08 10:52 .transport_stats_for_bzr
+# requests: 6776
+Bytes read: 69090135
+Average latency: 37ms
=== modified file 'commands.py'
--- a/commands.py 2007-09-30 13:24:51 +0000
+++ b/commands.py 2007-10-08 09:46:16 +0000
@@ -57,5 +57,9 @@
from bzrlib.plugins.transportstats import stats
mystats = stats.get_stats()
mystats.start_exploiting()
- print 'Bytes read: %d' % mystats.nb_bytes_read()
+ (requests, bytes_read, avg_latency) = mystats.collect()
+ print '# requests: %d' % requests
+ print 'Bytes read: %d' % bytes_read
+ # FIXME: It may be more appropriate to divide by 2 as ping does.
+ print 'Average latency: %dms' % avg_latency
mystats.stop_exploiting()
=== modified file 'decorator.py'
--- a/decorator.py 2007-10-07 14:15:30 +0000
+++ b/decorator.py 2007-10-08 09:46:16 +0000
@@ -26,6 +26,7 @@
from cStringIO import StringIO
import tempfile
+import time
from bzrlib.lazy_import import lazy_import
lazy_import(globals(), """
@@ -38,6 +39,11 @@
"""A decorator that collect statistics.
This is requested via the 'stats+' prefix to get_transport().
+
+ Latency is represented with an unsigned short number of miliseconds. Above
+ the minute latencies are considered pathological enough to be ignored. The
+ latency measured here represents an estimate of the time between request
+ sending and response receiving.
"""
def __init__(self, url, _decorated=None):
@@ -45,10 +51,18 @@
super(StatsCollector, self).__init__(url, _decorated)
self._stats = stats.get_stats()
self._stats.start_collecting()
+ self.__start_time = 0
def __collect(self, name, *args):
self._stats.write_stat(name, self.base, *args)
+ def __start(self):
+ self.__start_time = time.time()
+
+ def __latency(self):
+ latency = int((time.time() - self.__start_time) * 1000)
+ return min(65535, latency)
+
@classmethod
def _get_url_prefix(self):
"""Stats transport decorators are invoked via 'stats+'"""
@@ -56,30 +70,37 @@
def has(self, relpath):
"""See Transport.has()."""
- self.__collect('has', relpath)
- return self._decorated.has(relpath)
+ self.__start()
+ ret = self._decorated.has(relpath)
+ self.__collect('Transport_has', relpath, self.__latency())
+ return ret
def get(self, relpath):
"""See Transport.get()."""
+ self.__start()
file = self._decorated.get(relpath)
+ latency = self.__latency()
temp_file = tempfile.TemporaryFile()
- temp_file.write(file.read())
- nb_bytes = temp_file.tell()
+ nb_bytes = self._pump(file, temp_file)
temp_file.seek(0)
file.close()
- self.__collect('get', relpath, nb_bytes)
+ self.__collect('Transport_get', relpath, nb_bytes, latency)
return temp_file
def get_bytes(self, relpath):
"""See Transport.get_bytes()."""
+ self.__start()
bytes = self._decorated.get_bytes(relpath)
- self.__collect('get_bytes', relpath, len(bytes))
+ self.__collect('Transport_get_bytes', relpath, len(bytes),
+ self.__latency())
return bytes
def readv(self, relpath, offsets):
"""See Transport.readv()."""
+ self.__start()
+ first = True
# FIXME: There are two problems here, we don't really collect neither
# the transactions with a remote server nor the real bytes
# transmitted. Specific implementations need to be defined for the
@@ -88,13 +109,18 @@
# http; 3 - remote). For now we collect only data "visible" at this API
# level which provides a rough estimate (1 transaction, n bytes read).
for (pos, data) in self._decorated.readv(relpath, offsets):
- self.__collect('readv', relpath, pos, len(data))
+ if first:
+ self.__collect('Transport_readv', relpath, self.__latency())
+ first = False
+ self.__collect('Transport_readv__offset', relpath, pos, len(data))
yield pos, data
def stat(self, relpath):
"""See Transport.stat()."""
- self.__collect('stat', relpath)
- return self._decorated.stat(relpath)
+ self.__start()
+ ret = self._decorated.stat(relpath)
+ self.__collect('Transport_stat', relpath, self.__latency())
+ return ret
=== modified file 'serialize.py'
--- a/serialize.py 2007-10-07 19:52:40 +0000
+++ b/serialize.py 2007-10-08 09:46:16 +0000
@@ -30,8 +30,8 @@
class UnsignedByte(FormatSpecifier):
- def pack(self, file, byte):
- file.write(struct.pack('>B', byte))
+ def pack(self, file, value):
+ file.write(struct.pack('>B', value))
def unpack(self, file):
(lg,) = struct.unpack('>B', file.read(1))
@@ -40,8 +40,8 @@
class UnsignedShort(FormatSpecifier):
- def pack(self, file, byte):
- file.write(struct.pack('>H', byte))
+ def pack(self, file, value):
+ file.write(struct.pack('>H', value))
def unpack(self, file):
(lg,) = struct.unpack('>H', file.read(2))
@@ -50,8 +50,8 @@
class UnsignedLong(FormatSpecifier):
- def pack(self, file, byte):
- file.write(struct.pack('>L', byte))
+ def pack(self, file, value):
+ file.write(struct.pack('>L', value))
def unpack(self, file):
(lg,) = struct.unpack('>L', file.read(4))
=== modified file 'stats.py'
--- a/stats.py 2007-10-07 19:52:40 +0000
+++ b/stats.py 2007-10-08 09:46:16 +0000
@@ -48,45 +48,60 @@
def __init__(self, base):
StatsPart.__init__(self)
self.base = base
-
-
-class _has_stat(TransportStatsPart):
-
- def __init__(self, base, relpath):
- super(self.__class__, self).__init__(base)
- self.relpath = relpath
-
-
-class _get_stat(TransportStatsPart):
-
- def __init__(self, base, relpath, bytes_read):
- super(self.__class__, self).__init__(base)
- self.relpath = relpath
- self.bytes_read = bytes_read
-
-
-class _get_bytes_stat(TransportStatsPart):
-
- def __init__(self, base, relpath, bytes_read):
- super(self.__class__, self).__init__(base)
- self.relpath = relpath
- self.bytes_read = bytes_read
-
-
-class _readv_stat(TransportStatsPart):
+ self.requests = 1
+
+# FIXME: __init__ methods should really be generated from format
+class _Transport_has_stat(TransportStatsPart):
+
+ def __init__(self, base, relpath, latency):
+ super(self.__class__, self).__init__(base)
+ self.relpath = relpath
+ self.relpath = latency
+
+
+class _Transport_get_stat(TransportStatsPart):
+
+ def __init__(self, base, relpath, bytes_read, latency):
+ super(self.__class__, self).__init__(base)
+ self.relpath = relpath
+ self.bytes_read = bytes_read
+ self.relpath = latency
+
+
+class _Transport_get_bytes_stat(TransportStatsPart):
+
+ def __init__(self, base, relpath, bytes_read, latency):
+ super(self.__class__, self).__init__(base)
+ self.relpath = relpath
+ self.bytes_read = bytes_read
+ self.relpath = latency
+
+
+class _Transport_readv_stat(TransportStatsPart):
+
+ def __init__(self, base, relpath, latency):
+ super(self.__class__, self).__init__(base)
+ self.relpath = relpath
+ self.latency = latency
+
+
+class _Transport_readv__offset_stat(TransportStatsPart):
def __init__(self, base, relpath, offset, bytes_read):
super(self.__class__, self).__init__(base)
self.relpath = relpath
self.offset = offset
self.bytes_read = bytes_read
-
-
-class _stat_stat(TransportStatsPart):
-
- def __init__(self, base, relpath):
+ # Special case, this stat is part of a request, not a request itself
+ self.requests = 0
+
+
+class _Transport_stat_stat(TransportStatsPart):
+
+ def __init__(self, base, relpath, latency):
super(self.__class__, self).__init__(base)
self.relpath = relpath
+ self.relpath = latency
class StatsRegistry(registry.Registry):
@@ -120,11 +135,18 @@
# Shortcut
register_stat = stats_registry.register
-register_stat('has', '%(base)us%(relpath)us')
-register_stat('get', '%(base)us%(relpath)us%(bytes_read)L')
-register_stat('get_bytes', '%(base)us%(relpath)us%(bytes_read)L')
-register_stat('readv', '%(base)us%(relpath)us%(offset)L%(bytes_read)L')
-register_stat('stat', '%(base)us%(relpath)us')
+register_stat('Transport_has',
+ '%(base)us%(relpath)us%(latency)H')
+register_stat('Transport_get',
+ '%(base)us%(relpath)us%(bytes_read)L%(latency)H')
+register_stat('Transport_get_bytes',
+ '%(base)us%(relpath)us%(bytes_read)L%(latency)H')
+register_stat('Transport_readv',
+ '%(base)us%(relpath)us%(latency)H')
+register_stat('Transport_readv__offset',
+ '%(base)us%(relpath)us%(offset)L%(bytes_read)L')
+register_stat('Transport_stat',
+ '%(base)us%(relpath)us%(latency)H')
class Stats(object):
@@ -223,14 +245,23 @@
args = stat_format.unpack(file)
yield stat_class(*args)
- def nb_bytes_read(self):
+ def collect(self):
+ requests = 0
bytes_read = 0
+ latency_count = 0
+ total_latency = 0
for stat in self:
try:
bytes_read += stat.bytes_read
except:
pass
- return bytes_read
+ try:
+ total_latency += stat.latency
+ latency_count += 1
+ except:
+ pass
+ requests += stat.requests
+ return requests, bytes_read, (total_latency / latency_count)
_stats = None
=== modified file 'tests/blackbox.py'
--- a/tests/blackbox.py 2007-09-30 10:27:21 +0000
+++ b/tests/blackbox.py 2007-10-08 09:46:16 +0000
@@ -59,10 +59,10 @@
class TestTsDisplay(TestWithStatsFile):
- def test_display_bytes_read(self):
+ def test_display(self):
self._decorated_bzr_branch()
out = self.run_bzr('ts-display')[0]
- self.assertStartsWith(out, 'Bytes read: ')
+ self.assertContainsRe(out, 'Bytes read: ')
class TestTsReset(tests.TestCase):
=== modified file 'tests/test_serialize.py'
--- a/tests/test_serialize.py 2007-10-07 14:15:30 +0000
+++ b/tests/test_serialize.py 2007-10-08 09:46:16 +0000
@@ -23,6 +23,10 @@
serialize,
)
+
+# TODO: More tests on invalid inputs and the associated errors (roughly around
+# not enough bytes to read, no space left on device, out of range values)
+
class TestFormat(tests.TestCase):
def _is_invalid(self, fmt):
More information about the bazaar-commits
mailing list