Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1qPRPy-00B1vI-Au for pgsql-hackers@arkaria.postgresql.org; Fri, 28 Jul 2023 17:38:22 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.94.2) (envelope-from ) id 1qPRPw-0001u3-HS for pgsql-hackers@arkaria.postgresql.org; Fri, 28 Jul 2023 17:38:20 +0000 Received: from makus.postgresql.org ([2001:4800:3e1:1::229]) by malur.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1qPRPw-0001sN-7n for pgsql-hackers@lists.postgresql.org; Fri, 28 Jul 2023 17:38:20 +0000 Received: from mail-oo1-xc34.google.com ([2607:f8b0:4864:20::c34]) by makus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256 (Exim 4.94.2) (envelope-from ) id 1qPRPt-0024qx-M7 for pgsql-hackers@postgresql.org; Fri, 28 Jul 2023 17:38:19 +0000 Received: by mail-oo1-xc34.google.com with SMTP id 006d021491bc7-5661e8f4c45so1673443eaf.1 for ; Fri, 28 Jul 2023 10:38:17 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20221208; t=1690565897; x=1691170697; h=in-reply-to:content-disposition:mime-version:references:message-id :subject:cc:to:from:date:from:to:cc:subject:date:message-id:reply-to; bh=EEWpJhVGOU7zHb1ZCOYeumGbkhyp3V5PzWOFY4cjO4s=; b=cVyVuYYE2NteJiFmRsmIQpAFKc6j6wWWVT7H/mObPYI0yLWoLRD6lbGwOli0CyAjeP KSld6740JmXwLnTp4Niw4+b+orv5ZUx4in3BNx3hzX9OFM0/ob5TKAqPKx0pcsSgNmqB 6pcYxAjukjO1PaWZPWpAvg4YK4LPoq5SwJ/DZYxGH0tCJdRBnmWKEL5KxRpguQZU4tTl nhi/czGtFrnKUfyEqBDKjHELqKyFvQ/8xAweAiJJapTbmlCg2+FzQFhJFR1Mi9+0PE8M B91vV0X4NGRBm0htIJV2EmO2uWYPqWlzrRqzfZ/WcfOAERmO21xfLf5Jog7EzXO5M7hh yNYw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20221208; t=1690565897; x=1691170697; h=in-reply-to:content-disposition:mime-version:references:message-id :subject:cc:to:from:date:x-gm-message-state:from:to:cc:subject:date :message-id:reply-to; bh=EEWpJhVGOU7zHb1ZCOYeumGbkhyp3V5PzWOFY4cjO4s=; b=DTcaA5ayptwfAoCU4H5Y8gyQjk+Jroo88b56oVzIjdOui2hL77IXvEweFW5a/IJ8eb muMOyBQCkLyABpfP8oAqScLuET1IF/cvo8U/fqNSDBFI4WjdDrcvz+KGyshJZU5iU0eM U4XCC/WEQNCo3spaA6WhL1LHq7WuM3xLX9oTShRR/hp054QoAnZ2sYntL/KIXnb/94jr ribKMTxjpkaOkzvB4Rz8Dfh9A+8bFlQWC8zoE4otkR5eW/oT8ZrNekOXgRRw+shqzcrD 6pbwVHpPcDBaYibeOptR0hv+MwdDjFxQXQuT48UdpUnj+jdpRURJtWMSpbLawJq7Qb6h +u3A== X-Gm-Message-State: ABy/qLb8SMOgC66ip/XxfR+uOH8fvkqTedf7f5Cb0Gy2uBoQW/+95fY+ CtFtFzy1PKRngg8uTrNNS+8= X-Google-Smtp-Source: APBJJlG5nlr2bf9cgMreaL2skT8ODUjLQ9sLLuub/VThL9oRim6aZ/LOPoUtVXm6btAA9cqw1zz7lA== X-Received: by 2002:a05:6808:354:b0:3a3:6f89:5de1 with SMTP id j20-20020a056808035400b003a36f895de1mr3503510oie.49.1690565896768; Fri, 28 Jul 2023 10:38:16 -0700 (PDT) Received: from nathanxps13 ([50.47.162.83]) by smtp.gmail.com with ESMTPSA id d3-20020a17090ad98300b00262eb0d141esm2842887pjv.28.2023.07.28.10.38.15 (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256); Fri, 28 Jul 2023 10:38:16 -0700 (PDT) Date: Fri, 28 Jul 2023 10:38:14 -0700 From: Nathan Bossart To: Bharath Rupireddy Cc: PostgreSQL-development Subject: Re: add timing information to pg_upgrade Message-ID: <20230728173814.GA3765390@nathanxps13> References: <20230727235134.GA3658499@nathanxps13> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk On Fri, Jul 28, 2023 at 01:10:14PM +0530, Bharath Rupireddy wrote: > How about using INSTR_TIME_SET_CURRENT, INSTR_TIME_SUBTRACT and > INSTR_TIME_GET_MILLISEC macros instead of gettimeofday and explicit > calculations? That seems like a good idea. > + report_status(PG_REPORT, "ok (took %ld ms)", elapsed_ms); > > I think it's okay to just leave it with "ok \t %ld ms", elapsed_ms); > without "took". FWIW, pg_regress does that way, see below: I'm okay with simply adding the time. However, I wonder if we want to switch to seconds, minutes, hours, etc. if the step takes longer. This would add a bit of complexity, but it would improve human readability. Alternatively, we could keep the code simple and machine readable by always using milliseconds. > Just curious, out of all the reported pg_upgrade prep_status()-es, > which ones are taking more time? I haven't done any testing on meaningful workloads yet, but the following show up on an empty cluster: "creating dump of database schemas", "analyzing all rows in the new cluster", "setting next transaction ID and epoch for new cluster", "restoring datbase schemas in the new cluster", and "sync data directory to disk". I imagine the dump, restore, and file-copying steps will stand out once you start adding data. -- Nathan Bossart Amazon Web Services: https://aws.amazon.com