优化日志打印
diff --git a/dubbo/client.py b/dubbo/client.py
index 44bd8a1..74afee3 100644
--- a/dubbo/client.py
+++ b/dubbo/client.py
@@ -31,6 +31,8 @@
if not zk_register and not host:
raise RegisterException('zk_register和host至少需要填入一个')
+ logger.debug('Created client, interface={}, version={}'.format(interface, version))
+
self.__interface = interface
self.__version = version
self.__dubbo_version = dubbo_version
@@ -73,8 +75,14 @@
'method': method,
'arguments': args
}
- # logger.debug(request_param)
+
+ logger.debug('Start request, host={}, params={}'.format(host, request_param))
+ start_time = time.time()
result = connection_pool.get(host, request_param, timeout)
+ cost_time = int((time.time() - start_time) * 1000)
+ logger.debug('Finish request, host={}, params={}'.format(host, request_param))
+ logger.debug('Request invoked, host={}, params={}, result={}, cost={}ms, timeout={}s'.format(
+ host, request_param, result, cost_time, timeout))
return result
@@ -159,13 +167,13 @@
interface = path.split('/')[2]
providers = self.zk.get_children(path, watch=self._watch_children)
- logger.debug('{} providers: {}'.format(interface, providers))
providers = filter(lambda provider: provider['scheme'] == 'dubbo', map(parse_url, providers))
if not providers:
logger.debug('no providers for interface {}'.format(interface))
self.hosts[interface] = []
return
self.hosts[interface] = map(lambda provider: provider['host'], providers)
+ logger.debug('{} providers: {}'.format(interface, self.hosts[interface]))
def _watch_configurators(self, event):
"""
@@ -184,8 +192,10 @@
conf = {}
for configurator in configurators:
conf[configurator['host']] = configurator['fields'].get('weight', 100)
+ logger.debug('{} configurators: {}'.format(interface, conf))
self.weights[interface] = conf
else:
+ logger.debug('No configurator for interface {}')
self.weights[interface] = {}
def _register_consumer(self, providers):
@@ -218,6 +228,7 @@
params.append('{0}={1}'.format(key, value))
consumer += '&'.join(params)
+ logger.debug('Create consumer {}'.format(fields))
consumer_path = DUBBO_ZK_CONSUMERS.format(fields['interface'])
self.zk.ensure_path(consumer_path)
self.zk.create_async(consumer_path + '/' + quote(consumer, safe=''), ephemeral=True)
diff --git a/dubbo/common/util.py b/dubbo/common/util.py
index 3c7515d..60cbd23 100644
--- a/dubbo/common/util.py
+++ b/dubbo/common/util.py
@@ -6,6 +6,10 @@
from sys import platform, maxsize
from urlparse import urlparse, unquote, parse_qsl
+import logging
+
+logger = logging.getLogger('dubbo')
+
ip = None
heartbeat_id = 0
invoke_id = 0
@@ -59,6 +63,7 @@
try:
sock.connect(('8.8.8.8', 80))
ip = sock.getsockname()[0]
+ logger.debug('Current IP Address: {}'.format(ip))
finally:
sock.close()
return ip
diff --git a/dubbo/connection/connections.py b/dubbo/connection/connections.py
index 75d8cae..e5a016c 100644
--- a/dubbo/connection/connections.py
+++ b/dubbo/connection/connections.py
@@ -53,8 +53,8 @@
event = threading.Event()
self.conn_events[invoke_id] = event
# 发送数据
- logger.debug('Request has been send for request id {}'.format(invoke_id))
conn.write(request_data)
+ logger.debug('Waiting response, invoke_id={}, timeout={}, host={}'.format(invoke_id, timeout, host))
event.wait(timeout)
del self.conn_events[invoke_id]
@@ -125,20 +125,20 @@
next_read_type 下一次读取需要读取的数据类型
invoke_id 此次调用的id
"""
+ host = conn.remote_host()
# 关闭连接
if not data:
- host = conn.remote_host()
logger.debug('{} closed by remote server'.format(host))
self._delete_connection(conn)
return 0, 0, 0
- logger.debug('Receive data type {} and invoke id {}'.format(data_type, invoke_id))
# 响应的头部
if data_type == 1:
- logger.debug('Head has been received with invoke id {}'.format(unpack('!q', data[4:12])[0]))
+ logger.debug('received response head with invoke_id={}, host={}'.format(unpack('!q', data[4:12])[0], host))
return self._parse_head(data, conn)
# 错误的响应体
elif data_type == 2:
+ logger.debug('received error response body with invoke_id={}, host={}'.format(invoke_id, host))
res = Response(data)
error = res.read_next()
self.results[invoke_id] = DubboResponseException('\n{}'.format(error))
@@ -146,6 +146,7 @@
return DEFAULT_READ_PARAMS
# 正常的响应体
elif data_type == 3:
+ logger.debug('received normal response body with invoke_id={}, host={}'.format(invoke_id, host))
self._parse_response(invoke_id, data)
return DEFAULT_READ_PARAMS
@@ -212,6 +213,7 @@
self.results[invoke_id] = e
finally:
self.conn_events[invoke_id].set() # 唤醒请求线程
+ logger.debug('Event set, invoked_id={}'.format(invoke_id))
@staticmethod
def _parse_error(res):
@@ -261,10 +263,10 @@
# 未达到最大的超时次数，超时次数+1且发送心跳包
else:
self.client_heartbeats[host] += 1
- invoke_id = list(bytearray(pack('!q', get_invoke_id())))
- req = CLI_HEARTBEAT_REQ_HEAD + invoke_id + CLI_HEARTBEAT_TAIL
+ invoke_id = get_invoke_id()
+ req = CLI_HEARTBEAT_REQ_HEAD + list(bytearray(pack('!q', invoke_id))) + CLI_HEARTBEAT_TAIL
conn.write(bytearray(req))
- logger.debug('Head has been send for request id {}'.format(invoke_id))
+ logger.debug('Send ❤ request for invoke_id {}, host={}'.format(invoke_id, host))
class SelectConnectionPool(BaseConnectionPool):
