def __init__(self, clock):
self.clock = clock
self.last_received_command = self.clock.time_msec()
self.last_sent_command = 0
self.time_we_closed = None # When we requested the connection be closed
self.received_ping = False # Have we reecived a ping from the other side
self.state = ConnectionStates.CONNECTING
self.name = "anon" # The name sent by a client.
self.conn_id = random_string(5) # To dedupe in case of name clashes.
# List of pending commands to send once we've established the connection
self.pending_commands = []
# The LoopingCall for sending pings.
self._send_ping_loop = None
self.inbound_commands_counter = CounterMetric(
"inbound_commands",
labels=["command"],
)
self.outbound_commands_counter = CounterMetric(
"outbound_commands",
labels=["command"],
)
def __init__(self, clock):
self.clock = clock
self.last_received_command = self.clock.time_msec()
self.last_sent_command = 0
self.time_we_closed = None # When we requested the connection be closed
self.received_ping = False # Have we reecived a ping from the other side
self.state = ConnectionStates.CONNECTING
self.name = "anon" # The name sent by a client.
self.conn_id = random_string(5) # To dedupe in case of name clashes.
# List of pending commands to send once we've established the connection
self.pending_commands = []
# The LoopingCall for sending pings.
self._send_ping_loop = None
self.inbound_commands_counter = CounterMetric(
"inbound_commands", labels=["command"],
)
self.outbound_commands_counter = CounterMetric(
"outbound_commands", labels=["command"],
)
def test_scalar(self):
counter = CounterMetric("scalar")
self.assertEquals(counter.render(), [
'scalar 0',
])
counter.inc()
self.assertEquals(counter.render(), [
'scalar 1',
])
counter.inc_by(2)
self.assertEquals(counter.render(), ['scalar 3'])
def test_vector(self):
counter = CounterMetric("vector", labels=["method"])
# Empty counter doesn't yet know what values it has
self.assertEquals(counter.render(), [])
counter.inc("GET")
self.assertEquals(counter.render(), [
'vector{method="GET"} 1',
])
counter.inc("GET")
counter.inc("PUT")
self.assertEquals(counter.render(), [
'vector{method="GET"} 2',
'vector{method="PUT"} 1',
])
def test_scalar(self):
counter = CounterMetric("scalar")
self.assertEquals(counter.render(), [
'scalar 0',
])
counter.inc()
self.assertEquals(counter.render(), [
'scalar 1',
])
counter.inc_by(2)
self.assertEquals(counter.render(), [
'scalar 3'
])
def test_vector(self):
counter = CounterMetric("vector", labels=["method"])
# Empty counter doesn't yet know what values it has
self.assertEquals(counter.render(), [])
counter.inc("GET")
self.assertEquals(counter.render(), [
'vector{method="GET"} 1',
])
counter.inc("GET")
counter.inc("PUT")
self.assertEquals(counter.render(), [
'vector{method="GET"} 2',
'vector{method="PUT"} 1',
])
# Check that passing too few values errors
self.assertRaises(ValueError, counter.inc)
def test_vector(self):
counter = CounterMetric("vector", labels=["method"])
# Empty counter doesn't yet know what values it has
self.assertEquals(counter.render(), [])
counter.inc("GET")
self.assertEquals(counter.render(), [
'vector{method="GET"} 1',
])
counter.inc("GET")
counter.inc("PUT")
self.assertEquals(counter.render(), [
'vector{method="GET"} 2',
'vector{method="PUT"} 1',
])
def test_vector(self):
counter = CounterMetric("vector", labels=["method"])
# Empty counter doesn't yet know what values it has
self.assertEquals(counter.render(), [])
counter.inc("GET")
self.assertEquals(counter.render(), [
'vector{method="GET"} 1',
])
counter.inc("GET")
counter.inc("PUT")
self.assertEquals(counter.render(), [
'vector{method="GET"} 2',
'vector{method="PUT"} 1',
])
# Check that passing too few values errors
self.assertRaises(ValueError, counter.inc)
class BaseReplicationStreamProtocol(LineOnlyReceiver):
"""Base replication protocol shared between client and server.
Reads lines (ignoring blank ones) and parses them into command classes,
asserting that they are valid for the given direction, i.e. server commands
are only sent by the server.
On receiving a new command it calls `on_<COMMAND_NAME>` with the parsed
command.
It also sends `PING` periodically, and correctly times out remote connections
(if they send a `PING` command)
"""
delimiter = b'\n'
VALID_INBOUND_COMMANDS = [] # Valid commands we expect to receive
VALID_OUTBOUND_COMMANDS = [] # Valid commans we can send
max_line_buffer = 10000
def __init__(self, clock):
self.clock = clock
self.last_received_command = self.clock.time_msec()
self.last_sent_command = 0
self.time_we_closed = None # When we requested the connection be closed
self.received_ping = False # Have we reecived a ping from the other side
self.state = ConnectionStates.CONNECTING
self.name = "anon" # The name sent by a client.
self.conn_id = random_string(5) # To dedupe in case of name clashes.
# List of pending commands to send once we've established the connection
self.pending_commands = []
# The LoopingCall for sending pings.
self._send_ping_loop = None
self.inbound_commands_counter = CounterMetric(
"inbound_commands",
labels=["command"],
)
self.outbound_commands_counter = CounterMetric(
"outbound_commands",
labels=["command"],
)
def connectionMade(self):
logger.info("[%s] Connection established", self.id())
self.state = ConnectionStates.ESTABLISHED
connected_connections.append(self) # Register connection for metrics
self.transport.registerProducer(self,
True) # For the *Producing callbacks
self._send_pending_commands()
# Starts sending pings
self._send_ping_loop = self.clock.looping_call(self.send_ping, 5000)
# Always send the initial PING so that the other side knows that they
# can time us out.
self.send_command(PingCommand(self.clock.time_msec()))
def send_ping(self):
"""Periodically sends a ping and checks if we should close the connection
due to the other side timing out.
"""
now = self.clock.time_msec()
if self.time_we_closed:
if now - self.time_we_closed > PING_TIMEOUT_MS:
logger.info(
"[%s] Failed to close connection gracefully, aborting",
self.id())
self.transport.abortConnection()
else:
if now - self.last_sent_command >= PING_TIME:
self.send_command(PingCommand(now))
if self.received_ping and now - self.last_received_command > PING_TIMEOUT_MS:
logger.info(
"[%s] Connection hasn't received command in %r ms. Closing.",
self.id(), now - self.last_received_command)
self.send_error("ping timeout")
def lineReceived(self, line):
"""Called when we've received a line
"""
if line.strip() == "":
# Ignore blank lines
return
line = line.decode("utf-8")
cmd_name, rest_of_line = line.split(" ", 1)
if cmd_name not in self.VALID_INBOUND_COMMANDS:
logger.error("[%s] invalid command %s", self.id(), cmd_name)
self.send_error("invalid command: %s", cmd_name)
return
self.last_received_command = self.clock.time_msec()
self.inbound_commands_counter.inc(cmd_name)
cmd_cls = COMMAND_MAP[cmd_name]
try:
cmd = cmd_cls.from_line(rest_of_line)
except Exception as e:
logger.exception("[%s] failed to parse line %r: %r", self.id(),
cmd_name, rest_of_line)
self.send_error("failed to parse line for %r: %r (%r):" %
(cmd_name, e, rest_of_line))
return
# Now lets try and call on_<CMD_NAME> function
try:
getattr(self, "on_%s" % (cmd_name, ))(cmd)
except Exception:
logger.exception("[%s] Failed to handle line: %r", self.id(), line)
def close(self):
logger.warn("[%s] Closing connection", self.id())
self.time_we_closed = self.clock.time_msec()
self.transport.loseConnection()
self.on_connection_closed()
def send_error(self, error_string, *args):
"""Send an error to remote and close the connection.
"""
self.send_command(ErrorCommand(error_string % args))
self.close()
def send_command(self, cmd, do_buffer=True):
"""Send a command if connection has been established.
Args:
cmd (Command)
do_buffer (bool): Whether to buffer the message or always attempt
to send the command. This is mostly used to send an error
message if we're about to close the connection due our buffers
becoming full.
"""
if self.state == ConnectionStates.CLOSED:
logger.debug("[%s] Not sending, connection closed", self.id())
return
if do_buffer and self.state != ConnectionStates.ESTABLISHED:
self._queue_command(cmd)
return
self.outbound_commands_counter.inc(cmd.NAME)
string = "%s %s" % (
cmd.NAME,
cmd.to_line(),
)
if "\n" in string:
raise Exception("Unexpected newline in command: %r", string)
self.sendLine(string.encode("utf-8"))
self.last_sent_command = self.clock.time_msec()
def _queue_command(self, cmd):
"""Queue the command until the connection is ready to write to again.
"""
logger.debug("[%s] Queing as conn %r, cmd: %r", self.id(), self.state,
cmd)
self.pending_commands.append(cmd)
if len(self.pending_commands) > self.max_line_buffer:
# The other side is failing to keep up and out buffers are becoming
# full, so lets close the connection.
# XXX: should we squawk more loudly?
logger.error("[%s] Remote failed to keep up", self.id())
self.send_command(ErrorCommand("Failed to keep up"),
do_buffer=False)
self.close()
def _send_pending_commands(self):
"""Send any queued commandes
"""
pending = self.pending_commands
self.pending_commands = []
for cmd in pending:
self.send_command(cmd)
def on_PING(self, line):
self.received_ping = True
def on_ERROR(self, cmd):
logger.error("[%s] Remote reported error: %r", self.id(), cmd.data)
def pauseProducing(self):
"""This is called when both the kernel send buffer and the twisted
tcp connection send buffers have become full.
We don't actually have any control over those sizes, so we buffer some
commands ourselves before knifing the connection due to the remote
failing to keep up.
"""
logger.info("[%s] Pause producing", self.id())
self.state = ConnectionStates.PAUSED
def resumeProducing(self):
"""The remote has caught up after we started buffering!
"""
logger.info("[%s] Resume producing", self.id())
self.state = ConnectionStates.ESTABLISHED
self._send_pending_commands()
def stopProducing(self):
"""We're never going to send any more data (normally because either
we or the remote has closed the connection)
"""
logger.info("[%s] Stop producing", self.id())
self.on_connection_closed()
def connectionLost(self, reason):
logger.info("[%s] Replication connection closed: %r", self.id(),
reason)
if isinstance(reason, Failure):
connection_close_counter.inc(reason.type.__name__)
else:
connection_close_counter.inc(reason.__class__.__name__)
try:
# Remove us from list of connections to be monitored
connected_connections.remove(self)
except ValueError:
pass
# Stop the looping call sending pings.
if self._send_ping_loop and self._send_ping_loop.running:
self._send_ping_loop.stop()
self.on_connection_closed()
def on_connection_closed(self):
logger.info("[%s] Connection was closed", self.id())
self.state = ConnectionStates.CLOSED
self.pending_commands = []
if self.transport:
self.transport.unregisterProducer()
def __str__(self):
return "ReplicationConnection<name=%s,conn_id=%s,addr=%s>" % (
self.name,
self.conn_id,
self.addr,
)
def id(self):
return "%s-%s" % (self.name, self.conn_id)
class BaseReplicationStreamProtocol(LineOnlyReceiver):
"""Base replication protocol shared between client and server.
Reads lines (ignoring blank ones) and parses them into command classes,
asserting that they are valid for the given direction, i.e. server commands
are only sent by the server.
On receiving a new command it calls `on_<COMMAND_NAME>` with the parsed
command.
It also sends `PING` periodically, and correctly times out remote connections
(if they send a `PING` command)
"""
delimiter = b'\n'
VALID_INBOUND_COMMANDS = [] # Valid commands we expect to receive
VALID_OUTBOUND_COMMANDS = [] # Valid commans we can send
max_line_buffer = 10000
def __init__(self, clock):
self.clock = clock
self.last_received_command = self.clock.time_msec()
self.last_sent_command = 0
self.time_we_closed = None # When we requested the connection be closed
self.received_ping = False # Have we reecived a ping from the other side
self.state = ConnectionStates.CONNECTING
self.name = "anon" # The name sent by a client.
self.conn_id = random_string(5) # To dedupe in case of name clashes.
# List of pending commands to send once we've established the connection
self.pending_commands = []
# The LoopingCall for sending pings.
self._send_ping_loop = None
self.inbound_commands_counter = CounterMetric(
"inbound_commands", labels=["command"],
)
self.outbound_commands_counter = CounterMetric(
"outbound_commands", labels=["command"],
)
def connectionMade(self):
logger.info("[%s] Connection established", self.id())
self.state = ConnectionStates.ESTABLISHED
connected_connections.append(self) # Register connection for metrics
self.transport.registerProducer(self, True) # For the *Producing callbacks
self._send_pending_commands()
# Starts sending pings
self._send_ping_loop = self.clock.looping_call(self.send_ping, 5000)
# Always send the initial PING so that the other side knows that they
# can time us out.
self.send_command(PingCommand(self.clock.time_msec()))
def send_ping(self):
"""Periodically sends a ping and checks if we should close the connection
due to the other side timing out.
"""
now = self.clock.time_msec()
if self.time_we_closed:
if now - self.time_we_closed > PING_TIMEOUT_MS:
logger.info(
"[%s] Failed to close connection gracefully, aborting", self.id()
)
self.transport.abortConnection()
else:
if now - self.last_sent_command >= PING_TIME:
self.send_command(PingCommand(now))
if self.received_ping and now - self.last_received_command > PING_TIMEOUT_MS:
logger.info(
"[%s] Connection hasn't received command in %r ms. Closing.",
self.id(), now - self.last_received_command
)
self.send_error("ping timeout")
def lineReceived(self, line):
"""Called when we've received a line
"""
if line.strip() == "":
# Ignore blank lines
return
line = line.decode("utf-8")
cmd_name, rest_of_line = line.split(" ", 1)
if cmd_name not in self.VALID_INBOUND_COMMANDS:
logger.error("[%s] invalid command %s", self.id(), cmd_name)
self.send_error("invalid command: %s", cmd_name)
return
self.last_received_command = self.clock.time_msec()
self.inbound_commands_counter.inc(cmd_name)
cmd_cls = COMMAND_MAP[cmd_name]
try:
cmd = cmd_cls.from_line(rest_of_line)
except Exception as e:
logger.exception(
"[%s] failed to parse line %r: %r", self.id(), cmd_name, rest_of_line
)
self.send_error(
"failed to parse line for %r: %r (%r):" % (cmd_name, e, rest_of_line)
)
return
# Now lets try and call on_<CMD_NAME> function
try:
getattr(self, "on_%s" % (cmd_name,))(cmd)
except Exception:
logger.exception("[%s] Failed to handle line: %r", self.id(), line)
def close(self):
logger.warn("[%s] Closing connection", self.id())
self.time_we_closed = self.clock.time_msec()
self.transport.loseConnection()
self.on_connection_closed()
def send_error(self, error_string, *args):
"""Send an error to remote and close the connection.
"""
self.send_command(ErrorCommand(error_string % args))
self.close()
def send_command(self, cmd, do_buffer=True):
"""Send a command if connection has been established.
Args:
cmd (Command)
do_buffer (bool): Whether to buffer the message or always attempt
to send the command. This is mostly used to send an error
message if we're about to close the connection due our buffers
becoming full.
"""
if self.state == ConnectionStates.CLOSED:
logger.debug("[%s] Not sending, connection closed", self.id())
return
if do_buffer and self.state != ConnectionStates.ESTABLISHED:
self._queue_command(cmd)
return
self.outbound_commands_counter.inc(cmd.NAME)
string = "%s %s" % (cmd.NAME, cmd.to_line(),)
if "\n" in string:
raise Exception("Unexpected newline in command: %r", string)
self.sendLine(string.encode("utf-8"))
self.last_sent_command = self.clock.time_msec()
def _queue_command(self, cmd):
"""Queue the command until the connection is ready to write to again.
"""
logger.debug("[%s] Queing as conn %r, cmd: %r", self.id(), self.state, cmd)
self.pending_commands.append(cmd)
if len(self.pending_commands) > self.max_line_buffer:
# The other side is failing to keep up and out buffers are becoming
# full, so lets close the connection.
# XXX: should we squawk more loudly?
logger.error("[%s] Remote failed to keep up", self.id())
self.send_command(ErrorCommand("Failed to keep up"), do_buffer=False)
self.close()
def _send_pending_commands(self):
"""Send any queued commandes
"""
pending = self.pending_commands
self.pending_commands = []
for cmd in pending:
self.send_command(cmd)
def on_PING(self, line):
self.received_ping = True
def on_ERROR(self, cmd):
logger.error("[%s] Remote reported error: %r", self.id(), cmd.data)
def pauseProducing(self):
"""This is called when both the kernel send buffer and the twisted
tcp connection send buffers have become full.
We don't actually have any control over those sizes, so we buffer some
commands ourselves before knifing the connection due to the remote
failing to keep up.
"""
logger.info("[%s] Pause producing", self.id())
self.state = ConnectionStates.PAUSED
def resumeProducing(self):
"""The remote has caught up after we started buffering!
"""
logger.info("[%s] Resume producing", self.id())
self.state = ConnectionStates.ESTABLISHED
self._send_pending_commands()
def stopProducing(self):
"""We're never going to send any more data (normally because either
we or the remote has closed the connection)
"""
logger.info("[%s] Stop producing", self.id())
self.on_connection_closed()
def connectionLost(self, reason):
logger.info("[%s] Replication connection closed: %r", self.id(), reason)
if isinstance(reason, Failure):
connection_close_counter.inc(reason.type.__name__)
else:
connection_close_counter.inc(reason.__class__.__name__)
try:
# Remove us from list of connections to be monitored
connected_connections.remove(self)
except ValueError:
pass
# Stop the looping call sending pings.
if self._send_ping_loop and self._send_ping_loop.running:
self._send_ping_loop.stop()
self.on_connection_closed()
def on_connection_closed(self):
logger.info("[%s] Connection was closed", self.id())
self.state = ConnectionStates.CLOSED
self.pending_commands = []
if self.transport:
self.transport.unregisterProducer()
def __str__(self):
return "ReplicationConnection<name=%s,conn_id=%s,addr=%s>" % (
self.name, self.conn_id, self.addr,
)
def id(self):
return "%s-%s" % (self.name, self.conn_id)
