Received: from localhost (maia-2.hub.org [200.46.204.187]) by postgresql.org (Postfix) with ESMTP id C18929FB666 for ; Wed, 6 Jun 2007 16:28:56 -0300 (ADT) Received: from postgresql.org ([200.46.204.71]) by localhost (mx1.hub.org [200.46.204.187]) (amavisd-maia, port 10024) with ESMTP id 39731-04 for ; Wed, 6 Jun 2007 16:28:21 -0300 (ADT) X-Greylist: delayed 00:07:18.646821 by SQLgrey-1.7.5 Received: from py-out-1112.google.com (py-out-1112.google.com [64.233.166.183]) by postgresql.org (Postfix) with ESMTP id F3FBE9FA66A for ; Wed, 6 Jun 2007 16:28:23 -0300 (ADT) Received: by py-out-1112.google.com with SMTP id p76so561373pyb for ; Wed, 06 Jun 2007 12:28:20 -0700 (PDT) DKIM-Signature: a=rsa-sha1; c=relaxed/relaxed; d=googlemail.com; s=beta; h=domainkey-signature:received:received:message-id:date:user-agent:mime-version:to:subject:content-type:content-transfer-encoding:from; b=Q60KMYRJKjoFHJVCeY/jmo7EKFb1p/KiERJWjoUbYcpIhW8B5KJ6PbNPD/P8JJWZFipr3+VuqvmI8EeV6i7WrAkN345iotPAc7GjDhIVzniNJ04zKNZXxFKV18ah31mk9KQD4wM9Yc0sWOUEoEVbr9kF8Zvd/2/IZv/jp3uad+8= DomainKey-Signature: a=rsa-sha1; c=nofws; d=googlemail.com; s=beta; h=received:message-id:date:user-agent:mime-version:to:subject:content-type:content-transfer-encoding:from; b=qflmi0n1MHyjR5OhIPtxk9Fy08K/YJ5ige9OCbb+sCMsy/p34NWMPIlPqE7hQUFUCrvtoz6BENtMHthf7wK5GRjD+Ke6osIc8ixDUxVHp9WvWXE2Gwz/z92blkZMTBtdThmVikboick8taE15R7C5+PBRFkCQZH3hsYWSQek1xk= Received: by 10.35.91.10 with SMTP id t10mr1462117pyl.1181157663238; Wed, 06 Jun 2007 12:21:03 -0700 (PDT) Received: from ?172.25.0.30? ( [41.245.179.78]) by mx.google.com with ESMTP id v66sm5598845pyh.2007.06.06.12.21.01; Wed, 06 Jun 2007 12:21:02 -0700 (PDT) Message-ID: <46670916.9090505@gmail.com> Date: Wed, 06 Jun 2007 21:20:54 +0200 User-Agent: Thunderbird 1.5.0.12 (X11/20070604) MIME-Version: 1.0 To: pgsql-performance@postgresql.org Subject: VERY slow queries at random Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit From: Gunther Mayer X-Virus-Scanned: Maia Mailguard 1.0.1 X-Archive-Number: 200706/102 X-Sequence-Number: 25135 Hi there, We run a small ISP with a FreeBSD/freeradius/postgresql 8.2.4 backend and 200+ users. Authentication happens via UAM/hotspot and I see a lot of authorisation and accounting packets that are handled via PL/PGSQL functions directly in the database. Everything seems to work 100% except that a few times a day I see Jun 6 10:41:31 caligula postgres[57347]: [4-1] radiususer: LOG: duration: 19929.291 ms statement: SELECT fn_accounting_start(...) in my logs. I'm logging slow queries with log_min_duration_statement = 500 in my postgresql.conf. Sometimes another query runs equally slow or even slower (I've seen 139 seconds!!!) a few minutes before or after as well, but then everything is back to normal. Even though I haven't yet indexed my data I know that the system is performant because my largest table (the accounting one) only has 5000+ rows, the entire database is only a few MB's and I have plenty of memory (2GB), shared_buffers = 100MB and max_fsm_pages = 179200. Also from briefly enabling log_parser_stats = on log_planner_stats = on log_executor_stats = on I saw that most queries are 100% satisfied from cache so the disk doesn't even get hit. Finally, the problem seems unrelated to load because it happens at 4am just as likely as at peak traffic time. What the heck could cause such erratic behaviour? I suspect some type of resource problem but what and how could I dig deeper? Gunther