Date: Mon, 1 Apr 2019 18:33:03 -0300
From: Alvaro Herrera <alvherre@2ndquadrant.com>
To: Rahila Syed <rahila.syed@2ndquadrant.com>
Cc: Andres Freund <andres@anarazel.de>, Robert Haas <robertmhaas@gmail.com>,
	Simon Riggs <simon@2ndquadrant.com>,
	Pg Hackers <pgsql-hackers@lists.postgresql.org>,
	David Fetter <david@fetter.org>,
	Pavan Deolasee <pavan.deolasee@gmail.com>,
	Amit Langote <Langote_Amit_f8@lab.ntt.co.jp>
Subject: Re: monitoring CREATE INDEX [CONCURRENTLY]
Message-ID: <20190401213303.GA26854@alvherre.pgsql>
MIME-Version: 1.0
Content-Type: text/plain; charset=iso-8859-1
Content-Disposition: inline
Content-Transfer-Encoding: 8bit
In-Reply-To: 
 <CAOajBXRSqA4hDDJRov+gmYxJNocULphv-PO74JRwQEWGrYcjfA@mail.gmail.com>
User-Agent: Mutt/1.9.4 (2018-02-28)
Precedence: bulk

On 2019-Apr-02, Rahila Syed wrote:

> 1.  FWIW, below results for CIC show that blocks_done does not become equal
> to blocks_total at the end of the phase or it processes last 800 blocks so
> fast that
> the update is not visible in less than 1 secs interval.

Yeah, I noticed this too and decided it's not fixable, nor it's
desirable to spend a lot of effort in getting it perfectly accurate -- I
mean, we could introduce locking or sleeping to get the results we want,
but do we really want to make the index building process slower just to
report those block numbers.

Anyway, I think this effect is caused by parallel btree building: those
final blocks are scanned by a worker process, and the leader didn't get
the latest block number scanned.  If you set
max_parallel_maintenance_workers to 0, the effect disappears.

(I used \watch 0.01 to see even faster progress updates; even in that
case the final batch of block numbers is not seen in the updates.  The
btree build code is stupidly fast.)

> 2. However in case of partitioned tables, the following difference in
> blocks_done versus blocks_total at the end of phase is notably high for the
> first partition . Subsequent partitions show negligible difference.
> Partition 1:
> Mon Mar 25 14:27:57 IST 2019
>   pid  | datid | datname  | relid |           phase            |
> lockers_total | lockers_done | current_locker_pid | blocks_total |
> blocks_done | tuples_total | tuples_done | partitions_total |
> partitions_done
> -------+-------+----------+-------+----------------------------+---------------+--------------+--------------------+--------------+-------------+--------------+-------------+------------------+-----------------
>  10630 | 13533 | postgres | 16394 | building index: table scan
> |             0 |            0 |                  0 |       381342 |
> 221233 |            0 |           0 |                3 |               0
> (1 row)

Hmm, in my tests with partitioned tables, I never noticed such a large
discrepancy.  I'm going to have another look.  800 blocks scanned by
workers I can believe, but 160000 sounds a bit too much.

> 3. Sorry for nitpicking, I think following phase name can be made more
> consistent with the others.
> The non-am specific phase for scanning a table is named as scan heap while
> am-specific one is named as table scan.
> Can we use heap for am-specific one as well since heap is used elsewhere in
> progress reporting too?

Hmm, I'd rather go the other way and use "table" everywhere rather than
heap, since we've been getting a lot of stuff done for table AMs.

> 4. -       scan = table_beginscan_parallel(btspool->heap,
> ParallelTableScanFromBTShared(btshared));
> +       scan = table_beginscan_parallel(btspool->heap,
> +
> ParallelTableScanFromBTShared(btshared));
> 
> Is this change required?

Yes, for my OCD.

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services