sebbacon/alaveteli — Issue #327: Slow postgres queries are hogging server resources
Author: sebbacon
Created: 2012-01-10 09:30:05+00:00
State: open

There are two types of query in particular that are very slow. First, one that takes 124877ms and happens once an hour at about 11 minutes past the hour (and is therefore probably a result of calling `script/alert-comment-on-request` or possibly `script/alert-overdue-requests`:

SELECT "info_requests"."id" AS t0_r0, "info_requests"."title" AS t0_r1, "info_requests"."user_id" AS t0_r2, "info_requests"."public_body_id" AS t0_r3, "info_requests"."created_at" AS t0_r4, "info_requests"."updated_at" AS t0_r5, "info_requests"."described_state" AS t0_r6, "info_requests"."awaiting_description" AS t0_r7, "info_requests"."prominence" AS t0_r8, "info_requests"."url_title" AS t0_r9, "info_requests"."law_used" AS t0_r10, "info_requests"."allow_new_responses_from" AS t0_r11, "info_requests"."handle_rejected_responses" AS t0_r12, "info_requests"."idhash" AS t0_r13, "info_request_events"."id" AS t1_r0, "info_request_events"."info_request_id" AS t1_r1, "info_request_events"."event_type" AS t1_r2, "info_request_events"."params_yaml" AS t1_r3, "info_request_events"."created_at" AS t1_r4, "info_request_events"."described_state" AS t1_r5, "info_request_events"."calculated_state" AS t1_r6, "info_request_events"."last_described_at" AS t1_r7, "info_request_events"."incoming_message_id" AS t1_r8, "info_request_events"."outgoing_message_id" AS t1_r9, "info_request_events"."comment_id" AS t1_r10, "info_request_events"."prominence" AS t1_r11, "user_info_request_sent_alerts"."id" AS t2_r0, "user_info_request_sent_alerts"."user_id" AS t2_r1, "user_info_request_sent_alerts"."info_request_id" AS t2_r2, "user_info_request_sent_alerts"."alert_type" AS t2_r3, "user_info_request_sent_alerts"."info_request_event_id" AS t2_r4 FROM "info_requests" LEFT OUTER JOIN "info_request_events" ON info_request_events.info_request_id = info_requests.id LEFT OUTER JOIN "user_info_request_sent_alerts" ON user_info_request_sent_alerts.info_request_event_id = info_request_events.id WHERE ((select id from info_request_events where event_type = 'comment' and info_request_events.info_request_id = info_requests.id and created_at > '2011-12-08 07:09:03.598233' limit 1) is not null) ORDER BY info_requests.id, info_request_events.created_at

Second, one that typically takes around 2000ms and is much more common, about every minute on average, and is therefore quite likely to be a result of `script/foi-alert-tracks` or (less likely) `script/update-xapian-index`:

SELECT * FROM "incoming_messages" WHERE ("incoming_messages"."id" IN (225865,202627,65742,168714,179156,200285,202628,128177,64128,235870,37839,187424,202629,222249,217840,47338,104686,178106,228415,68511,68532,77930,144577,70550,191731,138579,25379,65057,87888,157082,64552,222255,167000,102682,185218,143087,225776,222256,81883,61056,39535,33492,135531,68219,35383,76758,222258,139852,112120,68221,188685,65832,96500,173898,224410,128366,201869,179741,66985,65776,237546,71436,81111,63330,35069,15333,230494,71975,124298,235587,220551,29846,76073,116700,229592,202625,176492,27798,41049,63333,185588,202626,25075))