Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.84_2) (envelope-from ) id 1dkryq-0003ar-MB for pgsql-performance@arkaria.postgresql.org; Thu, 24 Aug 2017 13:15:28 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.84_2) (envelope-from ) id 1dkryp-0000dZ-En for pgsql-performance@arkaria.postgresql.org; Thu, 24 Aug 2017 13:15:27 +0000 Received: from makus.postgresql.org ([2001:4800:1501:1::229]) by malur.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA384:256) (Exim 4.84_2) (envelope-from ) id 1dkryo-0000cx-CT for pgsql-performance@postgresql.org; Thu, 24 Aug 2017 13:15:26 +0000 Received: from mail-wm0-x236.google.com ([2a00:1450:400c:c09::236]) by makus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.84_2) (envelope-from ) id 1dkryk-0005Cf-2g for pgsql-performance@postgresql.org; Thu, 24 Aug 2017 13:15:24 +0000 Received: by mail-wm0-x236.google.com with SMTP id p30so5111128wmi.0 for ; Thu, 24 Aug 2017 06:15:21 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:from:date:message-id:subject:to; bh=qRkSGfo0Di3UsbNdJ5oQ+HnNsWoK3sT5Xu7LULM30dw=; b=iCZXTBhegb/xlcs+qPz0nO5mr/bs4kZY0QxpDFl6cl6w8lpEay+NoLkzrKe4lHhuS9 GfvWXRAI+RhsvhJRspUa70m2aAXUeCtwIvtHSMU7+JGx6WqDgd8UciRYdWMG1a2+rTw8 8AogY2kmmp/q9DiaRDgU6cLwsnjoEhWuUxWrsL52oMh2ZMtaNGGOE9FniF4c4ie1JiIn z0D6xZEMhCjymvRy2rVCa9DigIj+lh2afcAbkRSA31jdWZvJj0zVXEn9fFOpbp+joDG9 Z9qUqc3e394egNi1OEJoTxFf6pfQvGdU1YMDhNl7tQxhrIQGwORF97/K3PZyU53mB1hb BuIw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:from:date:message-id:subject:to; bh=qRkSGfo0Di3UsbNdJ5oQ+HnNsWoK3sT5Xu7LULM30dw=; b=Zu0LUSe/bPk37cmBcdo1xvRwXhDZ0O8HynySxP4VYZ4vcPZhkWmkhFXaOfyC8pFS8M 2MsQ9x2b9Fgtw3L32JmuO3rUiINjphgRxy6YUyUZjVRCfTZXGQvvbk4xFu9y5IkVi37s G6TG27I1Gx9w2TI6IgDgKkRdBHPj+82x4F1d0MJx07kXSSRnwKjjxKRuVRaSgcdicLtE AYBKrwQ934D8ZetldOZCGniju2KG4jhyfC9M0LAAbZHXnrosR9BfCzdxQVW/XqvDzM0v IWCTzYPnitdlzY8EvZ6/1uC8OFHBF1cvARyB6k/tyo0ktvJZQuQsXM8n9/kg2W55DbDL dQqQ== X-Gm-Message-State: AHYfb5jNKkMR2V83ESc5t8Sd580r1Q4Hi7z4eahe/F9FZvS4RRvVFXj3 /BXcIt2sgDAImyatKed/yTIvMcxFuhukoPk= X-Received: by 10.28.54.169 with SMTP id y41mr3852467wmh.30.1503580520168; Thu, 24 Aug 2017 06:15:20 -0700 (PDT) MIME-Version: 1.0 Received: by 10.28.184.85 with HTTP; Thu, 24 Aug 2017 06:15:19 -0700 (PDT) From: Mariel Cherkassky Date: Thu, 24 Aug 2017 16:15:19 +0300 Message-ID: Subject: printing results of query to file in different times To: pgsql-performance@postgresql.org Content-Type: multipart/alternative; boundary="001a11431554cbc3c905577f9e24" List-Archive: List-Help: List-ID: List-Owner: List-Post: List-Subscribe: List-Unsubscribe: X-Mailing-List: pgsql-performance Precedence: bulk Sender: pgsql-performance-owner@postgresql.org --001a11431554cbc3c905577f9e24 Content-Type: text/plain; charset="UTF-8" I'm trying to understand what postgresql doing in an issue that I'm having. Our app team wrote a function that runs with a cursor over the results of a query and via the utl_file func they write some columns to a file. I dont understand why, but postgresql write the data into the file in the fs in parts. I mean that it runs the query and it takes time to get back results and when I see that the results back postgresql write to file the data and then suddenly stops for X minutes. After those x minutes it starts again to write the data and it continues that way until its done. The query returns total *100* rows. I want to understand why it stops suddenly. There arent any locks in the database during this operation. my function looks like that : func(a,b,c...) cursor cr for select ab,c,d,e..... begin raise notice - 'starting loop time - %',timeofday(); for cr_record in cr Raise notice 'print to file - '%',timeofday(); utl_file.write(file,cr_record) end loop end I see the log of the running the next output : starting loop 16:00 print to file : 16:03 print to file : 16:03 print to file : 16:07 print to file : 16:07 print to file : 16:07 print to file : 16:010 ...... Can somebody explain to me this kind of behavior ? Why is it taking some much time to write and in different minutes after the query already been executed and finished ? Mybe I'm getting from the cursor only part of the rows ? --001a11431554cbc3c905577f9e24 Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
I'm trying to under= stand what postgresql doing in an issue that I'm having. Our app team w= rote a function that runs with a cursor over the results of a query and via= the utl_file func they write some columns to a file. I dont understand why= , but postgresql write the data into the file in the fs in parts. I mean th= at it runs the query and it takes time to get back results and when I see t= hat the results back postgresql write to file the data and then suddenly st= ops for X minutes. After those x minutes it starts again to write the data = and it continues that way until its done. The query returns total 100 rows. I want to underst= and why it stops suddenly. There arent any locks in the database during thi= s operation.

my function look= s like that :=C2=A0

func(a,b,c...)

cursor cr for

s= elect ab,c,d,e.....

begin

raise notice - 'starting loop time - %',tim= eofday();

=C2=A0for cr_record in cr

=C2=A0 =C2=A0 Raise notice 'print t= o file - '%',timeofday();

= =C2=A0 =C2=A0 utl_file.write(file,cr_reco= rd)

=C2=A0end loop

end

I see the log of the running the next output :=C2=A0=

starting loop 16:00

print to file : 16:03

print to file : 16= :03

print to file : 16:07

print to file : 16:07

print to file : 16:07

print to file : 16:010

......



Can somebody explain to me this kind of behavior ? Why is= it taking some much time to write and in different minutes after the query= already been executed and finished ? Mybe I'm getting from the cursor = only part of the rows ?


--001a11431554cbc3c905577f9e24--