Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtp (Exim 4.84_2) (envelope-from ) id 1dnOYW-0002A1-46 for pgsql-performance@arkaria.postgresql.org; Thu, 31 Aug 2017 12:26:44 +0000 Received: from localhost ([127.0.0.1] helo=postgresql.org) by malur.postgresql.org with smtp (Exim 4.84_2) (envelope-from ) id 1dnOYV-0002HE-FE for pgsql-performance@arkaria.postgresql.org; Thu, 31 Aug 2017 12:26:43 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA384:256) (Exim 4.84_2) (envelope-from ) id 1dnOYU-0002DO-4Z for pgsql-performance@postgresql.org; Thu, 31 Aug 2017 12:26:42 +0000 Received: from mail-wm0-x233.google.com ([2a00:1450:400c:c09::233]) by magus.postgresql.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_CBC_SHA1:256) (Exim 4.84_2) (envelope-from ) id 1dnOYR-000408-04 for pgsql-performance@postgresql.org; Thu, 31 Aug 2017 12:26:41 +0000 Received: by mail-wm0-x233.google.com with SMTP id f127so3724520wmf.1 for ; Thu, 31 Aug 2017 05:26:38 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:subject:from:in-reply-to:date:cc:message-id:references :to; bh=mVAlJPYS4KgJFr1V4VluVbD9K7CnaI4M4/pa59rz3CU=; b=FjCmZ+fPnc5PRwUnAk1k6LCWE0D67B2lEJu++zgmJfWfTrijH/OttpLTLvzpWxrYxc /UY7JY/exNsx1k8TZbUyQj9n+hXTTx7cV31zuMZtNdgYbP04mouEQd2803nd3Ax3otD1 /mTicKuAAopgFLgFoLNb+Hv+U1rv4hQN1YOHLih6hBDHXO8Qf879xeiULtaoFxKpcI41 o8ZFE9611zHCCI7H1HL/gouYUcB5jCEU/FHtsCVI+A3qJPzoQ0bQo5fkiegLR7R6lfDv 57uf2N28CLHTKvoPk5j2bIJyXweACpaYp4FJWeuPaRbSj3yGetFmIGf0DptJ+RKw7oVa +jJw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:subject:from:in-reply-to:date:cc :message-id:references:to; bh=mVAlJPYS4KgJFr1V4VluVbD9K7CnaI4M4/pa59rz3CU=; b=qSCm5b7fQiYEBW/OfL5KfjWweNBL7E5H9XzlmruEy5hzgbbImmLL+jBb0TIJwZdRW3 BECu4qLuOelqG+fuinEc69UzKpY8avZcQXGKsCbW37F3vyzqn6Y8ebMQN83vZlf3RMj+ FvKXo7clyVJyMVClrh/o7KwN8Yx19l7cZEMy8q+kWDAsmA67lrBzxR3jNPZHQSJjfu6c g6eq4gUJtXGo4z9RgFnjI7nLFAkaHpOwQKNut1Ff4di+uLuDtcRnSFepmYNz71qhL3G8 llq33wpKZdTp6lrkUCAn7oRSEAIWqxIpo8RNd1HYaeQS/CAzkk/YjHfnfjqfnEdFXoMG G7wA== X-Gm-Message-State: AHYfb5ixYOqWlIUGF6HPJWTJrB4jTrjG45Fq+kkaXK93p7eAdeteitNK zFbutIN5FTpRAg== X-Google-Smtp-Source: ADKCNb7zdQ+5anY1DBANHeDWwjSM6FF40zz26/3USF6OJyv8iWUn4EesxL28zzYXB1W6ZOSlby1/FA== X-Received: by 10.80.139.210 with SMTP id n18mr1457499edn.190.1504182397617; Thu, 31 Aug 2017 05:26:37 -0700 (PDT) Received: from ip-192-168-0-196.eu-west-1.compute.internal (87-99-37-65.internetia.net.pl. [87.99.37.65]) by smtp.gmail.com with ESMTPSA id k34sm34252edc.2.2017.08.31.05.26.35 (version=TLS1 cipher=ECDHE-RSA-AES128-SHA bits=128/128); Thu, 31 Aug 2017 05:26:36 -0700 (PDT) Content-Type: multipart/alternative; boundary="Apple-Mail=_0315B62E-1688-4D69-A51C-670AD6D8A516" Mime-Version: 1.0 (Mac OS X Mail 9.3 \(3124\)) Subject: Re: printing results of query to file in different times From: Roman Konoval In-Reply-To: Date: Thu, 31 Aug 2017 14:26:34 +0200 Cc: pgsql-performance@postgresql.org Message-Id: References: To: Mariel Cherkassky X-Mailer: Apple Mail (2.3124) 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 --Apple-Mail=_0315B62E-1688-4D69-A51C-670AD6D8A516 Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=us-ascii Can you show explain with analyze and buffers options for your query? Regards, Roman Konoval rkonoval@gmail.com > On Aug 24, 2017, at 15:15, Mariel Cherkassky = wrote: >=20 > 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. >=20 > my function looks like that :=20 >=20 > func(a,b,c...) >=20 > cursor cr for >=20 > select ab,c,d,e..... >=20 > begin >=20 > raise notice - 'starting loop time - %',timeofday(); >=20 > for cr_record in cr >=20 > Raise notice 'print to file - '%',timeofday(); >=20 > utl_file.write(file,cr_record) >=20 > end loop >=20 > end >=20 > I see the log of the running the next output :=20 >=20 > starting loop 16:00 >=20 > print to file : 16:03 >=20 > print to file : 16:03 >=20 > print to file : 16:07 >=20 > print to file : 16:07 >=20 > print to file : 16:07 >=20 > print to file : 16:010 >=20 > ...... >=20 >=20 >=20 >=20 >=20 > 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 ? >=20 >=20 --Apple-Mail=_0315B62E-1688-4D69-A51C-670AD6D8A516 Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=us-ascii
Can you show explain with analyze and buffers = options for your query?

Regards,
Roman Konoval
rkonoval@gmail.com



On Aug 24, 2017, at 15:15, Mariel Cherkassky <mariel.cherkassky@gmail.com> wrote:

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 = ?



= --Apple-Mail=_0315B62E-1688-4D69-A51C-670AD6D8A516--