Re: [sqlalchemy] Re: slow get query - somes taking 1.5 sec

2011-06-27 Thread Michael Bayer
Fetching a single row and producing objects, even if a chain of eagerly loaded 
many-to-ones, is a relatively cheap operation, and it still sounds like network 
overhead of rows is the main problem.If any columns fetch large binary 
objects or large amounts textual data, that can take a long time over the 
network as well.   The high degree in variability of time spent suggests 
network overhead as well rather than CPU time.

Also, I'd ensure eager loads aren't loading large collections, take off 
unnecessary eager loads, with_polymorphic settings, use innerjoin=True for 
many-to-one eagerloads where the foreign key is NOT NULL.

Hope this helps.




On Jun 26, 2011, at 11:13 PM, nospam wrote:

 Yes, I'm using polymorphic mappers.  It's actually only 1 row -
 querying the object by id.  I have lazy=false for any referenced
 objects to the one I'm querying for.
 
 On Jun 26, 12:16 pm, Michael Bayer mike...@zzzcomputing.com wrote:
 You have a tremendous amount of LEFT OUTER JOINS in there, and its hard to 
 tell but it seems like you're doing lots of with_polymorphic queries as 
 well as lazy='joined' styles of relationships, making for a very 
 cumbersome query.   That it returns the first result quickly (that's your 47 
 msec) but takes a lot longer to actually return rows (thats your .15 sec) 
 suggests it returns a lot of rows.  I'd turn off all the 
 with_polymorphic stuff, as well as not using any lazy='joined' for 
 collections, lazy='subquery' is a better choice for collections but even 
 then, usually better as a query time option rather than a fixed mapping 
 configuration.
 
 On Jun 26, 2011, at 10:25 AM, nospam wrote:
 
 
 
 
 
 I'm seeing a simple get taking a considerable amount of time.
 
 a = session.query(Annotation).get(annotation.id)
 
 This line can take anywhere between 0.15 secs to all the way up to 1.5
 secs ...  The query sqlalchemy produces is below.  If I execute the
 query in pgadmin, it consistently runs in 47 msecs.
 
 Any ideas?
 
 It seems to run longer if I issue the 'get' right after an update and
 another select query.  If I wait a little bit (5 secs), then it seems
 to run closer to the 0.15 secs.
 
 SELECT (SELECT users.username
 FROM users
 WHERE annotations.user_id = users.id) AS created_by, annotations.id AS
 annotations_id, annotations.version AS annotations_version,
 annotations.message AS annotations_message, annotations.image_filename
 AS annotations_image_filename, annotations.user_id AS
 annotations_user_id, annotations.camera_id AS annotations_camera_id,
 annotations.game_id AS annotations_game_id, annotations.item_id AS
 annotations_item_id, annotations.creation_datetime AS
 annotations_creation_datetime, annotations.modified_datetime AS
 annotations_modified_datetime, annotations.camera_datetime AS
 annotations_persistent, anon_1.items_id AS anon_1_items_id,
 anon_1.items_type AS anon_1_items_type, anon_1.items_user_id AS
 anon_1_items_user_id, anon_1.items_game_id AS anon_1_items_game_id,
 anon_1.people_item_id AS anon_1_people_item_id,
 anon_1.vehicles_item_id AS anon_1_vehicles_item_id,
 anon_1.articles_item_id AS anon_1_articles_item_id,
 anon_1.relationships_item_id AS anon_1_relationships_item_id,
 anon_1.relationships_lower_item_id AS
 anon_1_relationships_lower_item_id,
 anon_1.relationships_higher_item_id AS
 anon_1_relationships_higher_item_id, anon_2.attributes_id AS
 anon_2_attributes_id, anon_2.attributes_name AS
 anon_2_attributes_name, anon_2.attributes_type AS
 anon_2_attributes_type, anon_2.attributes_annotation_id AS
 anon_2_attributes_annotation_id, anon_2.attributes_suspicion_level AS
 anon_2_attributes_suspicion_level,
 anon_2.vehicle_attributes_attributes_id AS
 anon_2_vehicle_attributes_attributes_id,
 anon_2.vehicle_attributes_vehicle_make AS
 anon_2_vehicle_attributes_vehicle_model,
 anon_2.relationship_attributes_attributes_id AS
 anon_2_relationship_attributes_attributes_id,
 anon_2.relationship_attributes_action AS
 anon_2_relationship_attributes_action,
 anon_2.police_report_attributes_attributes_id AS
 anon_2_police_report_attributes_attributes_id,
 anon_2.police_report_attributes_first_name AS
 anon_2_article_attributes_attributes_id,
 anon_2.article_attributes_stationary AS
 anon_2.person_attributes_attributes_id AS
 anon_2_person_attributes_attributes_id,
 anon_2.person_attributes_eye_color AS
 anon_2_person_attributes_eye_color,
 anon_2.person_attributes_hair_color AS
 anon_2_person_attributes_hair_color, anon_2.person_attributes_gender
 AS anon_2_person_attributes_gender, anon_2.person_attributes_height AS
 anon_2_person_attributes_height, anon_2.person_attributes_age AS
 anon_2_person_attributes_age, anon_2.person_attributes_build AS
 anon_2_person_attributes_build, anon_2.person_attributes_luggage AS
 anon_2_person_attributes_luggage, anon_2.person_attributes_mobility AS
 anon_2_person_attributes_mobility,
 anon_2.flight_checkin_attributes_attributes_id AS
 anon_2_flight_checkin_attributes_attributes_id,
 

[sqlalchemy] Re: slow get query - somes taking 1.5 sec

2011-06-26 Thread nospam
Yes, I'm using polymorphic mappers.  It's actually only 1 row -
querying the object by id.  I have lazy=false for any referenced
objects to the one I'm querying for.

On Jun 26, 12:16 pm, Michael Bayer mike...@zzzcomputing.com wrote:
 You have a tremendous amount of LEFT OUTER JOINS in there, and its hard to 
 tell but it seems like you're doing lots of with_polymorphic queries as 
 well as lazy='joined' styles of relationships, making for a very cumbersome 
 query.   That it returns the first result quickly (that's your 47 msec) but 
 takes a lot longer to actually return rows (thats your .15 sec) suggests it 
 returns a lot of rows.      I'd turn off all the with_polymorphic stuff, as 
 well as not using any lazy='joined' for collections, lazy='subquery' is a 
 better choice for collections but even then, usually better as a query time 
 option rather than a fixed mapping configuration.

 On Jun 26, 2011, at 10:25 AM, nospam wrote:





  I'm seeing a simple get taking a considerable amount of time.

  a = session.query(Annotation).get(annotation.id)

  This line can take anywhere between 0.15 secs to all the way up to 1.5
  secs ...  The query sqlalchemy produces is below.  If I execute the
  query in pgadmin, it consistently runs in 47 msecs.

  Any ideas?

  It seems to run longer if I issue the 'get' right after an update and
  another select query.  If I wait a little bit (5 secs), then it seems
  to run closer to the 0.15 secs.

  SELECT (SELECT users.username
  FROM users
  WHERE annotations.user_id = users.id) AS created_by, annotations.id AS
  annotations_id, annotations.version AS annotations_version,
  annotations.message AS annotations_message, annotations.image_filename
  AS annotations_image_filename, annotations.user_id AS
  annotations_user_id, annotations.camera_id AS annotations_camera_id,
  annotations.game_id AS annotations_game_id, annotations.item_id AS
  annotations_item_id, annotations.creation_datetime AS
  annotations_creation_datetime, annotations.modified_datetime AS
  annotations_modified_datetime, annotations.camera_datetime AS
  annotations_persistent, anon_1.items_id AS anon_1_items_id,
  anon_1.items_type AS anon_1_items_type, anon_1.items_user_id AS
  anon_1_items_user_id, anon_1.items_game_id AS anon_1_items_game_id,
  anon_1.people_item_id AS anon_1_people_item_id,
  anon_1.vehicles_item_id AS anon_1_vehicles_item_id,
  anon_1.articles_item_id AS anon_1_articles_item_id,
  anon_1.relationships_item_id AS anon_1_relationships_item_id,
  anon_1.relationships_lower_item_id AS
  anon_1_relationships_lower_item_id,
  anon_1.relationships_higher_item_id AS
  anon_1_relationships_higher_item_id, anon_2.attributes_id AS
  anon_2_attributes_id, anon_2.attributes_name AS
  anon_2_attributes_name, anon_2.attributes_type AS
  anon_2_attributes_type, anon_2.attributes_annotation_id AS
  anon_2_attributes_annotation_id, anon_2.attributes_suspicion_level AS
  anon_2_attributes_suspicion_level,
  anon_2.vehicle_attributes_attributes_id AS
  anon_2_vehicle_attributes_attributes_id,
  anon_2.vehicle_attributes_vehicle_make AS
  anon_2_vehicle_attributes_vehicle_model,
  anon_2.relationship_attributes_attributes_id AS
  anon_2_relationship_attributes_attributes_id,
  anon_2.relationship_attributes_action AS
  anon_2_relationship_attributes_action,
  anon_2.police_report_attributes_attributes_id AS
  anon_2_police_report_attributes_attributes_id,
  anon_2.police_report_attributes_first_name AS
  anon_2_article_attributes_attributes_id,
  anon_2.article_attributes_stationary AS
  anon_2.person_attributes_attributes_id AS
  anon_2_person_attributes_attributes_id,
  anon_2.person_attributes_eye_color AS
  anon_2_person_attributes_eye_color,
  anon_2.person_attributes_hair_color AS
  anon_2_person_attributes_hair_color, anon_2.person_attributes_gender
  AS anon_2_person_attributes_gender, anon_2.person_attributes_height AS
  anon_2_person_attributes_height, anon_2.person_attributes_age AS
  anon_2_person_attributes_age, anon_2.person_attributes_build AS
  anon_2_person_attributes_build, anon_2.person_attributes_luggage AS
  anon_2_person_attributes_luggage, anon_2.person_attributes_mobility AS
  anon_2_person_attributes_mobility,
  anon_2.flight_checkin_attributes_attributes_id AS
  anon_2_flight_checkin_attributes_attributes_id,
  anon_2.flight_checkin_attributes_airline AS
  anon_2_flight_checkin_attributes_start_datetime_of_flight,
  anon_2.flight_checkin_attributes_end_datetime_of_flight AS
  anon_2_flight_checkin_attributes_end_datetime_of_flight,
  anon_2.flight_checkin_attributes_first_name AS
  anon_2_flight_checkin_attributes_first_name,
  anon_2.flight_checkin_attributes_last_name AS
  anon_2_lpr_attributes_attributes_id,
  anon_2.lpr_attributes_start_datetime AS
  anon_2_lpr_attributes_start_datetime,
  anon_2.lpr_attributes_end_datetime AS
  anon_2_lpr_attributes_end_datetime,
  anon_2.lpr_attributes_license_plate AS
  anon_2_lpr_attributes_license_plate,