Log why we are stopping

This commit is contained in:
Thomas Adamcik 2011-07-12 03:29:04 +02:00
parent b5c6bc0442
commit b9286fb9ee
2 changed files with 43 additions and 19 deletions

View File

@ -10,6 +10,7 @@ from pykka.registry import ActorRegistry
from mopidy.utils.log import indent
# FIXME setup logger with extra={...}
logger = logging.getLogger('mopidy.utils.server')
class ShouldRetrySocketCall(Exception):
@ -134,11 +135,14 @@ class Connection(object):
self.enable_recv()
self.enable_timeout()
def stop(self):
def stop(self, reason, level=logging.DEBUG):
logger.log(level, reason)
self.actor_ref.stop()
self.disable_timeout()
self.disable_recv()
self.disable_send()
try:
self.sock.close()
except socket.error:
@ -188,18 +192,18 @@ class Connection(object):
def recv_callback(self, fd, flags):
if flags & (gobject.IO_ERR | gobject.IO_HUP):
self.stop()
self.stop(u'Bad client flags: %s' % flags)
return True
try:
data = self.sock.recv(4096)
except socket.error as e:
if e.errno not in (errno.EWOULDBLOCK, errno.EINTR):
self.stop()
self.stop(u'Unexpected client error: %s' % e)
return True
if not data:
self.stop()
self.stop(u'Client most likely disconnected.')
else:
self.actor_ref.send_one_way({'received': data})
return True
@ -217,16 +221,14 @@ class Connection(object):
self.disable_send()
except socket.error as e:
if e.errno not in (errno.EWOULDBLOCK, errno.EINTR):
#self.log_error(e) # FIXME log error
self.stop()
self.stop(u'Unexpected client error: %s' % e)
finally:
self.send_lock.release()
return True
def timeout_callback(self):
#self.log_timeout() # FIXME log this
return self.stop()
return self.stop(u'Client timeout out after %s seconds' % self.timeout)
class LineProtocol(ThreadingActor):

View File

@ -2,6 +2,7 @@ import errno
import gobject
import socket
import unittest
import logging
from mock import patch, sentinel, Mock
from mopidy.utils import network
@ -244,7 +245,7 @@ class ConnectionTest(unittest.TestCase):
self.mock.actor_ref = Mock()
self.mock.sock = Mock(spec=socket.SocketType)
network.Connection.stop(self.mock)
network.Connection.stop(self.mock, sentinel.reason)
self.mock.disable_timeout.assert_called_once_with()
self.mock.disable_recv.assert_called_once_with()
self.mock.disable_timeout.assert_called_once_with()
@ -253,7 +254,7 @@ class ConnectionTest(unittest.TestCase):
self.mock.actor_ref = Mock()
self.mock.sock = Mock(spec=socket.SocketType)
network.Connection.stop(self.mock)
network.Connection.stop(self.mock, sentinel.reason)
self.mock.sock.close.assert_called_once_with()
def test_stop_closes_socket_error(self):
@ -261,16 +262,35 @@ class ConnectionTest(unittest.TestCase):
self.mock.sock = Mock(spec=socket.SocketType)
self.mock.sock.close.side_effect = socket.error()
network.Connection.stop(self.mock)
network.Connection.stop(self.mock, sentinel.reason)
self.mock.sock.close.assert_called_once_with()
def test_stop_stops_actor(self):
self.mock.actor_ref = Mock()
self.mock.sock = Mock(spec=socket.SocketType)
network.Connection.stop(self.mock)
network.Connection.stop(self.mock, sentinel.reason)
self.mock.actor_ref.stop.assert_called_once_with()
@patch.object(network.logger, 'log', new=Mock())
def test_stop_logs_reason(self):
self.mock.actor_ref = Mock()
self.mock.sock = Mock(spec=socket.SocketType)
network.Connection.stop(self.mock, sentinel.reason)
network.logger.log.assert_called_once_with(
logging.DEBUG, sentinel.reason)
@patch.object(network.logger, 'log', new=Mock())
def test_stop_logs_reason_with_level(self):
self.mock.actor_ref = Mock()
self.mock.sock = Mock(spec=socket.SocketType)
network.Connection.stop(self.mock, sentinel.reason,
level=sentinel.level)
network.logger.log.assert_called_once_with(
sentinel.level, sentinel.reason)
@patch.object(gobject, 'io_add_watch', new=Mock())
def test_enable_recv_registers_with_gobject(self):
self.mock.recv_id = None
@ -421,17 +441,17 @@ class ConnectionTest(unittest.TestCase):
def test_recv_callback_respects_io_err(self):
self.assertTrue(network.Connection.recv_callback(self.mock,
sentinel.fd, gobject.IO_IN | gobject.IO_ERR))
self.mock.stop.assert_called_once_with()
self.assertEqual(1, self.mock.stop.call_count)
def test_recv_callback_respects_io_hup(self):
self.assertTrue(network.Connection.recv_callback(self.mock,
sentinel.fd, gobject.IO_IN | gobject.IO_HUP))
self.mock.stop.assert_called_once_with()
self.assertEqual(1, self.mock.stop.call_count)
def test_recv_callback_respects_io_hup_and_io_err(self):
self.assertTrue(network.Connection.recv_callback(self.mock,
sentinel.fd, gobject.IO_IN | gobject.IO_HUP | gobject.IO_ERR))
self.mock.stop.assert_called_once_with()
self.assertEqual(1, self.mock.stop.call_count)
def test_recv_callback_gets_data(self):
self.mock.sock = Mock(spec=socket.SocketType)
@ -449,7 +469,7 @@ class ConnectionTest(unittest.TestCase):
self.assertTrue(network.Connection.recv_callback(
self.mock, sentinel.fd, gobject.IO_IN))
self.mock.stop.assert_called_once_with()
self.assertEqual(1, self.mock.stop.call_count)
def test_recv_callback_recoverable_error(self):
self.mock.sock = Mock(spec=socket.SocketType)
@ -465,7 +485,7 @@ class ConnectionTest(unittest.TestCase):
self.assertTrue(network.Connection.recv_callback(
self.mock, sentinel.fd, gobject.IO_IN))
self.mock.stop.assert_called_once_with()
self.assertEqual(1, self.mock.stop.call_count)
@SkipTest
def test_send_callback_respects_flags(self):
@ -537,8 +557,10 @@ class ConnectionTest(unittest.TestCase):
self.mock.sock.send.side_effect = socket.error()
self.assertTrue(network.Connection.send_callback(
self.mock, sentinel.fd, gobject.IO_IN))
self.mock.stop.assert_called_once_with()
self.assertEqual(1, self.mock.stop.call_count)
def test_timeout_callback(self):
self.mock.timeout = 10
network.Connection.timeout_callback(self.mock)
self.mock.stop.assert_called_once_with()
self.assertEqual(1, self.mock.stop.call_count)