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 1u2XeN-002CSX-IT for pgsql-performance@arkaria.postgresql.org; Wed, 09 Apr 2025 15:47:39 +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 1u2XeL-004VJV-1p for pgsql-performance@arkaria.postgresql.org; Wed, 09 Apr 2025 15:47:37 +0000 Received: from magus.postgresql.org ([2a02:c0:301:0:ffff::29]) by malur.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.94.2) (envelope-from ) id 1u2XeK-004VJM-Fk for pgsql-performance@lists.postgresql.org; Wed, 09 Apr 2025 15:47:37 +0000 Received: from mail-am6eur05on2050.outbound.protection.outlook.com ([40.107.22.50] helo=EUR05-AM6-obe.outbound.protection.outlook.com) by magus.postgresql.org with esmtps (TLS1.3) tls TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 (Exim 4.96) (envelope-from ) id 1u2XeI-004Mgt-1A for pgsql-performance@lists.postgresql.org; Wed, 09 Apr 2025 15:47:36 +0000 ARC-Seal: i=1; a=rsa-sha256; s=arcselector10001; d=microsoft.com; cv=none; b=Ne0eNwzfLUzZu1Hsowo5sqI/Ccon9pze4VxODLx8lMH+Lon6ssm55i+lD5z4c7xD45V0ddAA+ToAo8wNsqCnBpxHkGeeoiOoNVqkW/8OwTbmDiBdyMBm5luKa2rAY929jtkNZU/XgDZIksIM4WZv6e/GE6pRkX2ffwDX+a4d1s2DZjTit4NhOuUNPFXkJK6zDd3z6cNQHlV0t3fhu2E9OxASU9tyu55CW5kpS8Kng3eZD0S9c4/hoaJc2LQ+49iumEDbWm6fmtZtTAH87GmJNuuBYHeEaYp1a5yd+dv8JOxWjlx9F4uyFIM68OpLt89as950Hx3/LZ19CopckDyE1w== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=microsoft.com; s=arcselector10001; h=From:Date:Subject:Message-ID:Content-Type:MIME-Version:X-MS-Exchange-AntiSpam-MessageData-ChunkCount:X-MS-Exchange-AntiSpam-MessageData-0:X-MS-Exchange-AntiSpam-MessageData-1; bh=hZ53+yDCLM1jY34B9eKUvEImvg07+QMQPm/iUFUiz/E=; b=au5JAViPpJlpV+5mHVLU9X3wJtosqWhXJ15981i1h5HiUe7TFPtIr9OdRqgBhUN6h7ncse0Q5/qCNaofA5bDxZKxZ/iKagiyM8Bvx94CKog287Q+PpkEOvg4HNvmM9VPmqpNAeKC2rS0JCtZW8fVwUSTMNRVXb+5yOAvZ3XMG34V9NJKY8zRvBjf2u2pdQ1mrNl5K0ejZKezcT5YhxFYrWvkvpXaGfJA/k6z5w3wvuClU2ngHvXXOkKg93Syb/KhepyBNFHV13k6N4xZITRdGDalHx+uzCz/tF67zGqFCimclbdVjfiR+B7S3pp7e08OoemL2Iu8GVhCiC6U6rRqiw== ARC-Authentication-Results: i=1; mx.microsoft.com 1; spf=pass smtp.mailfrom=sonymusic.com; dmarc=pass action=none header.from=sonymusic.com; dkim=pass header.d=sonymusic.com; arc=none DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=sonymusic.com; s=selector2; h=From:Date:Subject:Message-ID:Content-Type:MIME-Version:X-MS-Exchange-SenderADCheck; bh=hZ53+yDCLM1jY34B9eKUvEImvg07+QMQPm/iUFUiz/E=; b=WAvtyPZsfS5D03/J0hNtJ9Cnn+uBRmDZhT6t8ld4Rkzjgwjh40PDTZMRlMwC5aMKv+wES+s0ZWiLZ//rwYG3Rm5YwGa0qGuA4xNo6krLJFWgC1nI7q7iwe1FJDv37GzxJOgcX9uJI6nk2PXkT5tdLcgEJxNNzqfvOB1xWSGjOC0= Received: from AS8PR02MB10078.eurprd02.prod.outlook.com (2603:10a6:20b:635::16) by GV2PR02MB10046.eurprd02.prod.outlook.com (2603:10a6:150:e0::6) with Microsoft SMTP Server (version=TLS1_2, cipher=TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384) id 15.20.8606.31; Wed, 9 Apr 2025 15:47:32 +0000 Received: from AS8PR02MB10078.eurprd02.prod.outlook.com ([fe80::943b:36f5:a03c:2dbf]) by AS8PR02MB10078.eurprd02.prod.outlook.com ([fe80::943b:36f5:a03c:2dbf%4]) with mapi id 15.20.8606.033; Wed, 9 Apr 2025 15:47:32 +0000 From: "Vitale, Anthony, Sony Music" To: Tom Lane CC: "pgsql-performance@lists.postgresql.org" Subject: RE: Question on what Duration in the log Thread-Topic: Question on what Duration in the log Thread-Index: AdupWdJu7qK2OBciTYGQY3RX/oz9PAABogwAAAGTvSA= Date: Wed, 9 Apr 2025 15:47:32 +0000 Message-ID: References: <196708.1744210924@sss.pgh.pa.us> In-Reply-To: <196708.1744210924@sss.pgh.pa.us> Accept-Language: en-US Content-Language: en-US X-MS-Has-Attach: X-MS-TNEF-Correlator: authentication-results: dkim=none (message not signed) header.d=none;dmarc=none action=none header.from=sonymusic.com; x-ms-publictraffictype: Email x-ms-traffictypediagnostic: AS8PR02MB10078:EE_|GV2PR02MB10046:EE_ x-ms-office365-filtering-correlation-id: 74f40a23-33e1-4826-6be9-08dd777dd731 x-ms-exchange-senderadcheck: 1 x-ms-exchange-antispam-relay: 0 x-microsoft-antispam: BCL:0;ARA:13230040|376014|1800799024|366016|38070700018; x-microsoft-antispam-message-info: =?iso-8859-1?Q?/pZ1mKh+NTmU/oLN/y+aNnIh8rcXV127Bhn3/SFfcYRhNNzio6FWmi5g4l?= =?iso-8859-1?Q?BRiWuTxvuOspZqGFvJI2p7GdvHTyKU8xIo3OH1HRTx49nLJtdqPIJdRl3U?= =?iso-8859-1?Q?rEiy5EN8j1EhfohoPjK02T8AqM/v+Oru+uqWtvNV4nDi/lDgXu7Ev0ojhv?= =?iso-8859-1?Q?N+0dpQvMDu3KZ+LW12UbTFJSC12jDr9PmKcjzZ6IU7WOLLYDSojD28ZW9e?= =?iso-8859-1?Q?59aO7DQnd+qvDIu1qvDYCdS+PcZntv0BAutRKOlxbXTe1HJhlM22dxhsn2?= =?iso-8859-1?Q?z+FoE3PejqfSUBRH7e03EazJQ4lmJzlFB945wWHGScJQdmbQ+dncLLQtyJ?= =?iso-8859-1?Q?41zV2LPebcZ4I96CCrTDLbQr5equCsrLQktXs9I0VskKfEmBnIVlzjeWzB?= =?iso-8859-1?Q?JKIwv4GxJpWhHvab1NwqZ1rrnUgzIjncbnxpmrVclBbO0+RrvME61L39i+?= =?iso-8859-1?Q?Poii5gtTkDmImeQCj2GnzQV3wisoCW7xolYe36lZkCM+DAieDqFkH9QwCc?= =?iso-8859-1?Q?SAZjhxpdQec0x9fwbGNnFRLpZsw54D1ZUKSAJUgVpYnpUNeWk+2kgLW1Ju?= =?iso-8859-1?Q?8ynxw51oM78fa5wsINVpsZTTShBPJ0yXcW4g5AfroYBlUYqyvAHA8IP9Oc?= =?iso-8859-1?Q?qcjqxXtMoFH/PxFjnwhoe4WcBA0v1KUmjMttuoewZ7ljgu7GqtES5xuMLP?= =?iso-8859-1?Q?dJ1CoYEHXrEBgkURCNhSnwp9EDxtvHimLgnKdfddxh49MLC111Vs7xk+wC?= =?iso-8859-1?Q?+vaTS2MBWvLChy0SNZXvxAS5JKeKt0T3xxAOESWebK/EazVXYgXmUMTRjO?= =?iso-8859-1?Q?NYrIipckVC1kgaxwVMbVEvAs6RayGo1ZIh6Q4RSb9OXzgjYrTjswQ8BxnG?= =?iso-8859-1?Q?Dc2mLUAg9D7z/V1vIa3O98RiufR7HqTTKj4RgysPY5ud7iggC/9BsVTRSu?= =?iso-8859-1?Q?+ziFN4zC/OTWS4kHpx1+NSStGUE4t3Bq8/P2HRjiH3HfKSNAaFBwI55XHG?= =?iso-8859-1?Q?hX2AwLROMNYHucDmP2sLj1eXsLsQGG7w271U4lk/7dgWYLOq9aoKWXkqrm?= =?iso-8859-1?Q?u72Z82l8eFJ30exBx7GQQYQFlv2+CFlf5ZC5fVjQ4+f8d2rmcebNwDBSl0?= =?iso-8859-1?Q?iS/volOxf4kUFE5eUDjZj6q3F6cS39lufUo5TabcvSR+DtdE3hbbh/qwHb?= =?iso-8859-1?Q?vCluutpucMeAaw8UYJEe6ACUCJLzhGWFBau7cHhQXEgGK/CAVb8d1yrlit?= =?iso-8859-1?Q?TOg6eNGMddRqoCkBvt4ngDmXN06KGNtYtdlcgETYj9pfAiyPRKh3cYYhV6?= =?iso-8859-1?Q?I+i3yWMglFJtDChlpDSLM3Lc75+17sydmMoOAFywHoc8Z3mEuWPgPoHAyP?= =?iso-8859-1?Q?s6EjtsPgjkM/dstiTRgVA5fKMuprL798XW4OzwpSAncclbNmhsaoEoTfGN?= =?iso-8859-1?Q?ISbLExxDZXnCD7Sqk8+hVoCbMsvmyreYocqbSEZ0yOpiDdUmdfMJlvh15s?= =?iso-8859-1?Q?MOtB7wFis7xqH7Wm6OuJt6Jnkqwv1JLvCj14A9kPhcKg=3D=3D?= x-forefront-antispam-report: CIP:255.255.255.255;CTRY:;LANG:en;SCL:1;SRV:;IPV:NLI;SFV:NSPM;H:AS8PR02MB10078.eurprd02.prod.outlook.com;PTR:;CAT:NONE;SFS:(13230040)(376014)(1800799024)(366016)(38070700018);DIR:OUT;SFP:1101; x-ms-exchange-antispam-messagedata-chunkcount: 1 x-ms-exchange-antispam-messagedata-0: =?iso-8859-1?Q?K580K4i0Y5GNjUlV0z5jJIq/WVBMFT7D/0keFDiYzWucs1Cc5E3HrdRkJM?= =?iso-8859-1?Q?lRu7QWtPicyyfDY7+IxW/HYlwlz9Hy1SfpDdMQ/qOFzp9DBUgB5kTbwiP2?= =?iso-8859-1?Q?w2OdIV3cXi06pohaWsdSwUwT63yzSTwcfbMNkLfIlLYk7LGmR9MufMJ/V+?= =?iso-8859-1?Q?zcy/2jRkx9pEFLiTMw3eIy5kkeSPJg21WYNs6GII6gEaDEUYTEosUf9sK2?= =?iso-8859-1?Q?JGhrfvPoXrO/xmiFW3mz2QPOy9KmUyboHUcg32jsSqmzGv38wzKQ2ToXYx?= =?iso-8859-1?Q?0ris09w8tq6q1ZnURk2FAvU9DnrqC90GT1Pbu+PK+ukO6Dl9BAQBmqQ3U8?= =?iso-8859-1?Q?i6hpkAm9TiMxTNGf4iXayW7YgnhjjK1RWwSJoIK3U1Id4/7MzabSFcmDuN?= =?iso-8859-1?Q?AzipT2WZ/sgkATAOGNTNW2740KkJhZxuvzK8nnB/cl6RWbYpdVQc4tR7cL?= =?iso-8859-1?Q?oTB4B7DMkSBMk6MBTaVkX5IR02u+0DvXsCN4IGnq91Iuy2/IvUlsWNtoiF?= =?iso-8859-1?Q?7OIfrSjlLIWHZpczMClJ0cACeRoLg3KqfPIJH59JXqPlc5xJ3tdmbFuIV0?= =?iso-8859-1?Q?/eo//Ctmkxi5sGhsGcK55/9iQnYJJmhIaZIwehZk6siTHxaPvS0f6A18wu?= =?iso-8859-1?Q?ywfgxViLMXv390KinLXiAfBNVJ78E+oe9SDDXaRojAV2Z0SITu34viVQmf?= =?iso-8859-1?Q?qbsfP5Wsg9jzYRRJ6upJwt/7kVK7DwVtdCGNwUiXvYBj12ljLGMNgczTVL?= =?iso-8859-1?Q?NIggiyOU9+dbRCAWpaKydi1M13m7f9XkAVcO5T00FQbOzxbiohdTrcP0bs?= =?iso-8859-1?Q?rDCT+R0dzQfDG2Gvr75U2fenTb4MzQbgQosDTF7Y3HHBXTMQ145Tum0vjS?= =?iso-8859-1?Q?bLQZA6Ufj775Egimw4IuaxFkn3TZm0QKA5EPtJZNfBc3WyQLtLQLYXPWCI?= =?iso-8859-1?Q?Npm9u+DEgBOYdcw5zx337TCuwLVMemfVqbm/H8C/TyOFSdbRKGZzUZXExR?= =?iso-8859-1?Q?2hxouqzM/4OtcECzDg7IgsUu8VYIzBNRpznp1XISBO+CKSydiPsNH7K0mM?= =?iso-8859-1?Q?H69832cCpeTMcWc5SQY2P1/QofBfsTCfujOEi9ViJH9yIiNEjABybmkvzG?= =?iso-8859-1?Q?rMsArqFiOzcP//frwSO7qWaqnqrU5onEK4CqjuhDm4mnOI4+94J9LWr1jm?= =?iso-8859-1?Q?BUpK263OwZllb1RTPVhuxaI1+Z7rjY+kRQnq5qT5PTQ9BGSlPhJ13Nr1wB?= =?iso-8859-1?Q?bwU1iNu5UrkFeWcnxzP2rX8xpyGhYndyNwNaHrVHtmQgFi8olCnjjGlDp1?= =?iso-8859-1?Q?7D4ICh93ZHfZIjpAfJ82kYuTlgWQNcDZRMbW0qIJkjhe2Qtk79bbiNgUcb?= =?iso-8859-1?Q?VzioVI2vWJBL7lkZFYG0GsfgxqlgE+VkBwMzHrwwzRUaSd3q0So4rqp7h2?= =?iso-8859-1?Q?reAeGzlotP5jOgLQrD08pmIdNYLeWZspSOSvyrpI3TFNCqDw4m7uT07BHd?= =?iso-8859-1?Q?FNFRupETcJ6YiAu9tpp4mkmjw4CXWCPteWW9MwOVLYDsMPRdfaeCfIS71N?= =?iso-8859-1?Q?LuEMhmA2PUOvuI2TuvKTygXKeQ3Rgd9BIZfXtFIDjzuJIAWWU9OQhoqTPi?= =?iso-8859-1?Q?jwxBC5Db2p9SkaH6KdOYJ35N6uy5gRX1298CcxVoWESYK0E5y9O6LxaA?= =?iso-8859-1?Q?=3D=3D?= Content-Type: text/plain; charset="iso-8859-1" Content-Transfer-Encoding: quoted-printable MIME-Version: 1.0 X-OriginatorOrg: sonymusic.com X-MS-Exchange-CrossTenant-AuthAs: Internal X-MS-Exchange-CrossTenant-AuthSource: AS8PR02MB10078.eurprd02.prod.outlook.com X-MS-Exchange-CrossTenant-Network-Message-Id: 74f40a23-33e1-4826-6be9-08dd777dd731 X-MS-Exchange-CrossTenant-originalarrivaltime: 09 Apr 2025 15:47:32.1302 (UTC) X-MS-Exchange-CrossTenant-fromentityheader: Hosted X-MS-Exchange-CrossTenant-id: f0aff3b7-91a5-4aae-af71-c63e1dda2049 X-MS-Exchange-CrossTenant-mailboxtype: HOSTED X-MS-Exchange-CrossTenant-userprincipalname: PgUapBDt15jY3Ha/kAEBipDPAbLJ3RabIteJW2epn2WE7gEnJjN585jcJAYkSHntYOxA4HUEtfOnAy7j9U3Lur2pis0nXIJbbzbB/uP+DbI= X-MS-Exchange-Transport-CrossTenantHeadersStamped: GV2PR02MB10046 List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Archived-At: Precedence: bulk Thanks Tom Perfect. Anthony Vitale =A0 This message is only for the use of the persons(s) to whom it is intended. = It may contain=A0privileged and confidential information within the meaning= of applicable law. If you are not the intended recipient, please do not us= e this information for any purpose, destroy this message and inform the sen= der immediately. The views expressed in this communication may not necessar= ily be the views held by Sony Music Entertainment -----Original Message----- From: Tom Lane =20 Sent: Wednesday, April 9, 2025 11:02 AM To: Vitale, Anthony, Sony Music Cc: pgsql-performance@lists.postgresql.org Subject: Re: Question on what Duration in the log EXTERNAL SENDER "Vitale, Anthony, Sony Music" writes: > In my PG Version 14 log I have set to log the duration of sql (Example of= one log row below). > 2025-04-08 07:31:57 UTC:XXX(55994):XXX:[8949]:LOG: duration: 6555.756=20 > ms execute S_381: {Actual Parameterized Sql executed} This Shows the Exe= cution of a JDBC Server Side Prepared statement (i.e S_381) which took 6.5 = seconds. > When I run the Sql using explain analyze it runs shows an execution=20 > time of 73 ms Planning Time: 0.773 ms Execution Time: 73.578 ms They're not measuring the same thing really, because EXPLAIN isn't counting= the time needed to transmit data to the client. This is not just a matter of network overhead (though that can be substantial) but also the time required to format the values into text. If= you are talking about large values, which I bet you are, there is also the= time needed to fetch them from out-of-line TOAST storage, which is another= thing that doesn't happen in EXPLAIN. Since v17, EXPLAIN has grown a SERIALIZE option that causes it to do everyt= hing except the network transmission, which might be of interest in analyzi= ng this further. regards, tom lane This email originated from outside of Sony Music. Do not click links or op= en attachments unless you recognize the sender and know the content is safe= .