From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mp1 ([2001:41d0:2:4a6f::]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) by ms0.migadu.com with LMTPS id 0MqlKKYTi2BP+gAAgWs5BA (envelope-from ) for ; Thu, 29 Apr 2021 22:14:30 +0200 Received: from aspmx1.migadu.com ([2001:41d0:2:4a6f::]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits)) by mp1 with LMTPS id poNiJKYTi2AmYAAAbx9fmQ (envelope-from ) for ; Thu, 29 Apr 2021 20:14:30 +0000 Received: from lists.gnu.org (lists.gnu.org [209.51.188.17]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by aspmx1.migadu.com (Postfix) with ESMTPS id 10DA6A8F3 for ; Thu, 29 Apr 2021 22:14:30 +0200 (CEST) Received: from localhost ([::1]:53374 helo=lists1p.gnu.org) by lists.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1lcD3N-0001z2-69 for larch@yhetil.org; Thu, 29 Apr 2021 16:14:29 -0400 Received: from eggs.gnu.org ([2001:470:142:3::10]:45946) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1lcD3C-0001yu-S5 for guix-devel@gnu.org; Thu, 29 Apr 2021 16:14:18 -0400 Received: from mira.cbaines.net ([212.71.252.8]:38094) by eggs.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1lcD3A-0000u5-RA for guix-devel@gnu.org; Thu, 29 Apr 2021 16:14:18 -0400 Received: from localhost (unknown [IPv6:2a02:8010:68c1:0:8ac0:b4c7:f5c8:7caa]) by mira.cbaines.net (Postfix) with ESMTPSA id D73F627BC7C; Thu, 29 Apr 2021 21:14:12 +0100 (BST) Received: from capella (localhost [127.0.0.1]) by localhost (OpenSMTPD) with ESMTP id 02543810; Thu, 29 Apr 2021 20:14:12 +0000 (UTC) References: <20210428145941.4bd0dd6f@lubrito> <87y2d2e0j4.fsf@cbaines.net> <20210428162030.2cab4106@lubrito> <87v986dvrn.fsf@cbaines.net> User-agent: mu4e 1.4.15; emacs 27.1 From: Christopher Baines To: lubrito@posteo.net Subject: Re: Outreachy: Timeline tasks In-reply-to: Date: Thu, 29 Apr 2021 21:14:10 +0100 Message-ID: <87mttgetm5.fsf@cbaines.net> MIME-Version: 1.0 Content-Type: multipart/signed; boundary="=-=-="; micalg=pgp-sha512; protocol="application/pgp-signature" Received-SPF: pass client-ip=212.71.252.8; envelope-from=mail@cbaines.net; helo=mira.cbaines.net X-Spam_score_int: -18 X-Spam_score: -1.9 X-Spam_bar: - X-Spam_report: (-1.9 / 5.0 requ) BAYES_00=-1.9, SPF_HELO_PASS=-0.001, SPF_PASS=-0.001 autolearn=ham autolearn_force=no X-Spam_action: no action X-BeenThere: guix-devel@gnu.org X-Mailman-Version: 2.1.23 Precedence: list List-Id: "Development of GNU Guix and the GNU System distribution." List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Cc: guix-devel@gnu.org Errors-To: guix-devel-bounces+larch=yhetil.org@gnu.org Sender: "Guix-devel" X-Migadu-Flow: FLOW_IN ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=yhetil.org; s=key1; t=1619727270; h=from:from:sender:sender:reply-to:subject:subject:date:date: message-id:message-id:to:to:cc:cc:mime-version:mime-version: content-type:content-type:in-reply-to:in-reply-to: references:references:list-id:list-help:list-unsubscribe: list-subscribe:list-post; bh=J7kODsEzpJS/hMt/YhvjBpS5Vi2Cua85X+D/GO52avk=; b=YvQj6qJgvGDhlmnpTAr56SXKMVMOiz0Hk35VDlWol5O1n0YZTc8gIHWG+PXfEWvrUvuJ8C B8KdoX7fjU2dkuPtkznVIgzkvT54TpjpTYolQP52TAyvk8bE7sAylYEAsETNfocVna08Dy qBuFBD8++XarqiDk7zystd4+NepJi6Nxy9aTeOXJpkK/bBho5QVTVrWwlPPT6m5zBLkfWc LfEAMet+XMaziaIne+uyh6G4OefUMjnW11AnVgGasvluLgBWQ30mwYyBDAkpuWF/feWv/Y sh77ILqxP4gn+KKIu8bFmW7rV0rOtWBjyoZwd/LHBGH7K2HtP6mZ8XwOm1h9dA== ARC-Seal: i=1; s=key1; d=yhetil.org; t=1619727270; a=rsa-sha256; cv=none; b=koMmzz0yUm4Gb5BQPJ2ESgABJvW+EiDBxCMdXAW//yb+Km49E74t9hIMVgWhCS1VeX7/0r a1MmGhSX56GHvp0vMVXGvzuBUWwMtmq5YKTE9xJkr6xtt8vabGoJf/rj1NelhZQdP17Svs yGgPKCYhzYQlAXxWbLpC3JIyF4ngbQ39uWcJ+7uR8HrIwU/irvhsDPyH84Qmq5hyQ44Gr5 vf+4nthd9VQWYAhDsdEFR7ZzqaM2gQuPwGA7FJ5q3JOuMrplBqs8FwLb1pv1mbIlb2NDjs X3GlVWcMDj+H1YRIrgnszKSykrieFrxtm0sRzGCgY60EKzBrGDHO5givPHMsxA== ARC-Authentication-Results: i=1; aspmx1.migadu.com; dkim=none; dmarc=none; spf=pass (aspmx1.migadu.com: domain of guix-devel-bounces@gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=guix-devel-bounces@gnu.org X-Migadu-Spam-Score: -4.56 Authentication-Results: aspmx1.migadu.com; dkim=none; dmarc=none; spf=pass (aspmx1.migadu.com: domain of guix-devel-bounces@gnu.org designates 209.51.188.17 as permitted sender) smtp.mailfrom=guix-devel-bounces@gnu.org X-Migadu-Queue-Id: 10DA6A8F3 X-Spam-Score: -4.56 X-Migadu-Scanner: scn0.migadu.com X-TUID: lfeJyzxpv0K+ --=-=-= Content-Type: text/plain lubrito@posteo.net writes: > Hi, > > On Wed, 28 Apr 2021 21:00:44 +0100 > Christopher Baines wrote: > > >> I think time is the main thing, since that alone will help to identify >> which are the slow parts. > >> Indeed, simplicity is a good thing to keep in mind. > > I'll keep in mind what you have said, so here are some ideas to > break the tasks. > > Task 1: Add instrumentation to identify the slow parts of processing > new revisions > > - Implementing a chart over time to identify slow parts; Great, can you add more detail to this bit? Given the instrumentation is a really important part, it would be good to have some working ideas for what this chart might look like, and what goes in to making it (like where the data comes from and if and where it's stored). > - Select candidate parts to be analyzed; > - Should this part really be taking all this time? > - Identify if the delay is caused by the code itself or by a > query. > - Prepare a document organizing where each part should > be improved. > Given these don't contribute to the instrumentation, I would see them as part of "Task 2". > Task 2: Improve the performance of these slow parts > > - implementing each improvements. > > This Task 2 is really difficult for me to divide in smaller tasks, I'm > really stuck with ideas. I'd try to set out more of a strategy, so what might be causes of slowness, how would you investigate them, and what are common approaches to making those things faster? > I took a look at one of the logs as you told me, and I found this parts > taking a considerable time: Great :) > - Computing the channel derivations 636s > - Acquiring advisory transaction lock: > loading-new-guix-revision-inserts 2534s * > - Getting derivation lint warnings 975s > - fetching inferior lint warnings 1488s > - Acquiring advisory transaction lock: > loading-new-guix-revision-inserts 3226s * > - Querying the temp-package-metadata 1949s > - Fetching inferior package metadata 2476s > > To pick this parts is what should be facilitated by the chart? > So I would perform the analysis of the task 1 and then the ta I would hope that the "instrumentation" would make finding out what parts are slowest easier, and making it visual information rather than text scattered through the long log will hopefully go a long way towards that. > By the way, I noticed that the ones I marked with * are performed twice. > Why is that? I'd try reading the code to find out. In case you haven't worked with database locks much before, they are being used in this case to allow multiple processes to interact with the database to load different revisions at the same time. The locking is very coarse, so locks can be held for a very long time, so what you're seeing in the log when it's saying it's acquiring a lock, and it takes a long time, is that process was waiting for another process to commit or rollback a transaction in which it was holding that same lock. The technical details that are useful to know: - The locks here apply within transactions - The lock will be released when the transaction commits or rolls back - Advisory locks are user defined locks: https://www.postgresql.org/docs/13/explicit-locking.html#ADVISORY-LOCKS --=-=-= Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQKlBAEBCgCPFiEEPonu50WOcg2XVOCyXiijOwuE9XcFAmCLE5JfFIAAAAAALgAo aXNzdWVyLWZwckBub3RhdGlvbnMub3BlbnBncC5maWZ0aGhvcnNlbWFuLm5ldDNF ODlFRUU3NDU4RTcyMEQ5NzU0RTBCMjVFMjhBMzNCMEI4NEY1NzcRHG1haWxAY2Jh aW5lcy5uZXQACgkQXiijOwuE9XfOLw//bwufC+kRM3eoveOhde+gVZ5Y4aEp8Sva OJ/2qQjHzguv0Qt0z9WcDeTaCv5D2u9t5VcAb5i5Zvhlb1cl8VJK9JVEbC6nB0Vp PbGpcZh2ZqH+20ZFI4D/QfT1KUz8WCMqOvE21xCbCqoClg3hLkY0pA29nEGeOjdY MTtxrrqutrT384Z7Ovj2YmEL2j5lPYH6Kgrm5gUpuxfajcEif6XbVN2cX/G9o7SX L3Sk8sr1rIZ+qDlFMn/2BSPi+M5lXRBAG8uuEm1f/RnZSZ8pPiNnUjDVNOpxXdjs /pTeUrKdoTf5khhOyvsDNdLdKw/c8m8PFQMafhlkcuzMjTIkoFqK+tHz/9p8be/X jedSGJuu7F/nyehP4Gx9CKKVAiKkO5Hr+IWCC292TvjqrU2X/2mGpSCkrt0PaBPH aoP5oKbmLVraCuAdMX7kuvPbmCUqTV1i4VbE6gH49kZkoN7apqt/U4meDQAJsWTH 2CsYtEYBULyIK2Wx81gCNnkTNUuXGkWalx/l/fPOqrz5z6a65ZWFmgoje4UL2OvL Y8XDeQWQh2Ra5CYCKWZV5tSllBRI9wkqPOBV9NPNYO4E0cNvoHZ9ciX1fWORPclb 79WW4851vkKoVHekZ28eUpfll2F7oSY6iYAkNciyHXiXqkr2ouL5he5Cx8ueTVkI vsG6ElslOOc= =gMvv -----END PGP SIGNATURE----- --=-=-=--