sqlalchemy日志显示的请求比postgres日志慢

Question

这是我的炼金术代码，它不断地轮询一些数据：

start_time = datetime.now()
query = Controller.query
sid = request.args.get('sid', "", type=str)
if sid:
    safe_sid = sanitize_user_input(sid, escape="/")
    query = query.filter(Controller.sid.startswith(safe_sid, escape="/"))
else:
    query = query.filter(Controller.sid != None)
if 'name' in request.args:
    query = query.name_like(request.args['name'])
head = request.args.get('head', 0, type=int)
if head == 1:
    query = query.head_only()
query = query.options(joinedload('monitors'), joinedload('maintenance'))
query = query.order_by(Controller.id)
controllers = query.all()
logger.info('controllers/ delta after query: {}'.format(str(datetime.now()-start_time)))

它在日志中显示以下时间：

2015-07-12T01:16:34 controllers/ delta after query: 0:00:00.850631
2015-07-12T01:16:37 controllers/ delta after query: 0:00:00.859993

所以基本上是900毫秒

然而，当我查看postgres日志时，我看到的值要小得多：

2015-07-12 01:16:33.400 EDT >LOG:  duration: 136.405 ms  statement:
SELECT controller.sid AS controller_sid, controller.id AS controller_id,
    controller.type AS controller_type, controller.name AS controller_name,
    controller.description AS controller_description, controller.address AS controller_address,
    controller.last_response AS controller_last_response, controller.gis_id AS controller_gis_id,
    controller.tag AS controller_tag, controller.parent_id AS controller_parent_id,
    controller.rdp_id AS controller_rdp_id, controller.root_node_id AS controller_root_node_id,
    asuno_roles_1.id AS asuno_roles_1_id, asuno_roles_1.slug AS asuno_roles_1_slug,
    asuno_roles_1.name AS asuno_roles_1_name, asuno_roles_1.description AS asuno_roles_1_description,
    asuno_users_1.id AS asuno_users_1_id, asuno_users_1.name AS asuno_users_1_name,
    asuno_users_1.username AS asuno_users_1_username, asuno_users_1.password_hash AS asuno_users_1_password_hash,
    asuno_users_1.active AS asuno_users_1_active, rdp_dispatcher_1.user_id AS rdp_dispatcher_1_user_id,
    rdp_dispatcher_1.rdp_id AS rdp_dispatcher_1_rdp_id, maintenance_1.id AS maintenance_1_id,
    maintenance_1.date_from AS maintenance_1_date_from, maintenance_1.date_to AS maintenance_1_date_to,
    maintenance_1.reason AS maintenance_1_reason, maintenance_1.controller_id AS maintenance_1_controller_id,
    maintenance_1.user_id AS maintenance_1_user_id, controller_monitor_1.id AS controller_monitor_1_id,
    controller_monitor_1.sid AS controller_monitor_1_sid,
    controller_monitor_1.node_type AS controller_monitor_1_node_type,
    controller_monitor_1.name AS controller_monitor_1_name,
    controller_monitor_1.tag AS controller_monitor_1_tag,
    controller_monitor_1.denotation AS controller_monitor_1_denotation,
    controller_monitor_1.alias AS controller_monitor_1_alias,
    controller_monitor_1.controller_id AS controller_monitor_1_controller_id,
    controller_monitor_1.value AS controller_monitor_1_value,
    controller_monitor_1.silent AS controller_monitor_1_silent,
    controller_monitor_1.last_reading_timestamp AS controller_monitor_1_last_reading_timestamp,
    controller_monitor_1.payload AS controller_monitor_1_payload

FROM controller LEFT OUTER JOIN maintenance AS maintenance_1 ON controller.id = maintenance_1.controller_id 
    AND maintenance_1.date_from <= TIMEZONE('utc', CURRENT_TIMESTAMP) 
    AND maintenance_1.date_to >= TIMEZONE('utc', CURRENT_TIMESTAMP) 
    LEFT OUTER JOIN asuno_users AS asuno_users_1 ON asuno_users_1.id = maintenance_1.user_id
    LEFT OUTER JOIN (roles_users AS roles_users_1 
    JOIN asuno_roles AS asuno_roles_1 ON asuno_roles_1.id = roles_users_1.role_id) 
    ON asuno_users_1.id = roles_users_1.user_id 
    LEFT OUTER JOIN rdp_dispatcher AS rdp_dispatcher_1 ON asuno_users_1.id = rdp_dispatcher_1.user_id 
    LEFT OUTER JOIN controller_monitor AS controller_monitor_1 ON controller.id = controller_monitor_1.controller_id


WHERE (controller.sid LIKE 'obekty-no:artiukhinoi' || '%' ESCAPE '/') 
    AND controller.parent_id IS NULL ORDER BY controller.id, maintenance_1.date_from

额外的600米是从哪里来的