From unknown Sat Aug 16 19:18:15 2025 X-Loop: help-debbugs@gnu.org Subject: bug#43588: cuirass: Slow SQL queries. Resent-From: Mathieu Othacehe Original-Sender: "Debbugs-submit" Resent-CC: bug-guix@gnu.org Resent-Date: Thu, 24 Sep 2020 11:50:01 +0000 Resent-Message-ID: Resent-Sender: help-debbugs@gnu.org X-GNU-PR-Message: report 43588 X-GNU-PR-Package: guix X-GNU-PR-Keywords: To: 43588@debbugs.gnu.org X-Debbugs-Original-To: bug-guix@gnu.org Received: via spool by submit@debbugs.gnu.org id=B.160094816023238 (code B ref -1); Thu, 24 Sep 2020 11:50:01 +0000 Received: (at submit) by debbugs.gnu.org; 24 Sep 2020 11:49:20 +0000 Received: from localhost ([127.0.0.1]:38776 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1kLPkW-00062i-AS for submit@debbugs.gnu.org; Thu, 24 Sep 2020 07:49:20 -0400 Received: from lists.gnu.org ([209.51.188.17]:56938) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1kLPkR-00062N-4N for submit@debbugs.gnu.org; Thu, 24 Sep 2020 07:49:18 -0400 Received: from eggs.gnu.org ([2001:470:142:3::10]:45566) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1kLPkQ-00009h-C0 for bug-guix@gnu.org; Thu, 24 Sep 2020 07:49:14 -0400 Received: from fencepost.gnu.org ([2001:470:142:3::e]:59531) by eggs.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1kLPkQ-0007rF-2z for bug-guix@gnu.org; Thu, 24 Sep 2020 07:49:14 -0400 Received: from [2a01:e0a:19b:d9a0:b888:25b1:7546:eb44] (port=36550 helo=cervin) by fencepost.gnu.org with esmtpsa (TLS1.2:RSA_AES_256_CBC_SHA1:256) (Exim 4.82) (envelope-from ) id 1kLPkP-0001q8-FX for bug-guix@gnu.org; Thu, 24 Sep 2020 07:49:13 -0400 From: Mathieu Othacehe Date: Thu, 24 Sep 2020 13:49:11 +0200 Message-ID: <878scz75u0.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/27.1 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain X-Spam-Score: -2.3 (--) X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Hello, I just added SQL queries logging to Cuirass. I also adapted the Guix shepherd service accordingly and deployed it on berlin. The results are already interesting: --8<---------------cut here---------------start------------->8--- SELECT E.id, E.status, E.timestamp, E.checkouttime, E.evaltime, B.total, B.succeeded, B.failed, B.scheduled FROM (SELECT id, status, timestamp, checkouttime, evaltime FROM Evaluations WHERE (id='16009' )) E LEFT JOIN (SELECT rowid, evaluation, SUM(status=0) as succeeded, SUM(status>0) as failed, SUM(status<0) as scheduled, SUM(status>-100) as total FROM Builds GROUP BY evaluation) B ON B.evaluation=E.id ORDER BY E.id ASC 95.38 SELECT E.id, E.status, E.timestamp, E.checkouttime, E.evaltime, B.total, B.succeeded, B.failed, B.scheduled FROM (SELECT id, status, timestamp, checkouttime, evaltime FROM Evaluations WHERE (id='5407' )) E LEFT JOIN (SELECT rowid, evaluation, SUM(status=0) as succeeded, SUM(status>0) as failed, SUM(status<0) as scheduled, SUM(status>-100) as total FROM Builds GROUP BY evaluation) B ON B.evaluation=E.id ORDER BY E.id ASC 65.88 SELECT E.id, E.status, E.timestamp, E.checkouttime, E.evaltime, B.total, B.succeeded, B.failed, B.scheduled FROM (SELECT id, status, timestamp, checkouttime, evaltime FROM Evaluations WHERE (id='8255' )) E LEFT JOIN (SELECT rowid, evaluation, SUM(status=0) as succeeded, SUM(status>0) as failed, SUM(status<0) as scheduled, SUM(status>-100) as total FROM Builds GROUP BY evaluation) B ON B.evaluation=E.id ORDER BY E.id ASC 86.23 --8<---------------cut here---------------end--------------->8--- Those three queries that originate from "db-get-evaluation-summary" procedure take more than 1 minute to run (65.88, 86.23 and 95.38 seconds). Even if concurrent database reading is permitted, the number of database workers is finite and some of the observed infamous "504" errors are the result of database worker starvation. If you want to help me optimize those queries, you can have a look to "/var/log/cuirass-sql.log" and "/var/log/cuirass-web-sql.log" on berlin, or request those files. Thanks, Mathieu -- https://othacehe.org From unknown Sat Aug 16 19:18:15 2025 MIME-Version: 1.0 X-Mailer: MIME-tools 5.505 (Entity 5.505) X-Loop: help-debbugs@gnu.org From: help-debbugs@gnu.org (GNU bug Tracking System) To: Mathieu Othacehe Subject: bug#43588: closed (Re: bug#43588: cuirass: Slow SQL queries.) Message-ID: References: <87eemldh4i.fsf@gnu.org> <878scz75u0.fsf@gnu.org> X-Gnu-PR-Message: they-closed 43588 X-Gnu-PR-Package: guix Reply-To: 43588@debbugs.gnu.org Date: Mon, 28 Sep 2020 16:03:02 +0000 Content-Type: multipart/mixed; boundary="----------=_1601308982-5453-1" This is a multi-part message in MIME format... ------------=_1601308982-5453-1 Content-Disposition: inline Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset="utf-8" Your bug report #43588: cuirass: Slow SQL queries. which was filed against the guix package, has been closed. The explanation is attached below, along with your original report. If you require more details, please reply to 43588@debbugs.gnu.org. --=20 43588: http://debbugs.gnu.org/cgi/bugreport.cgi?bug=3D43588 GNU Bug Tracking System Contact help-debbugs@gnu.org with problems ------------=_1601308982-5453-1 Content-Type: message/rfc822 Content-Disposition: inline Content-Transfer-Encoding: 7bit Received: (at 43588-done) by debbugs.gnu.org; 28 Sep 2020 16:02:36 +0000 Received: from localhost ([127.0.0.1]:53819 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1kMvbo-0001P0-Ab for submit@debbugs.gnu.org; Mon, 28 Sep 2020 12:02:36 -0400 Received: from eggs.gnu.org ([209.51.188.92]:50526) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1kMvbl-0001Oi-H9 for 43588-done@debbugs.gnu.org; Mon, 28 Sep 2020 12:02:34 -0400 Received: from fencepost.gnu.org ([2001:470:142:3::e]:46372) by eggs.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1kMvbe-0003cO-GY for 43588-done@debbugs.gnu.org; Mon, 28 Sep 2020 12:02:27 -0400 Received: from [2a01:e0a:19b:d9a0:d549:2a8f:de3b:c9c0] (port=39312 helo=cervin) by fencepost.gnu.org with esmtpsa (TLS1.2:RSA_AES_256_CBC_SHA1:256) (Exim 4.82) (envelope-from ) id 1kMvbc-0005Yy-3i for 43588-done@debbugs.gnu.org; Mon, 28 Sep 2020 12:02:24 -0400 From: Mathieu Othacehe To: 43588-done@debbugs.gnu.org Subject: Re: bug#43588: cuirass: Slow SQL queries. References: <878scz75u0.fsf@gnu.org> Date: Mon, 28 Sep 2020 18:02:21 +0200 In-Reply-To: <878scz75u0.fsf@gnu.org> (Mathieu Othacehe's message of "Thu, 24 Sep 2020 13:49:11 +0200") Message-ID: <87eemldh4i.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/27.1 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: 43588-done X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Hello, > SELECT E.id, E.status, E.timestamp, E.checkouttime, E.evaltime, B.total, B.succeeded, B.failed, B.scheduled FROM (SELECT id, status, timestamp, checkouttime, evaltime FROM Evaluations WHERE (id='8255' )) E LEFT JOIN (SELECT rowid, evaluation, SUM(status=0) as succeeded, SUM(status>0) as failed, SUM(status<0) as scheduled, SUM(status>-100) as total FROM Builds GROUP BY evaluation) B ON B.evaluation=E.id ORDER BY E.id ASC 86.23 Turns out those queries are really slow because they are doing full scans of the Builds table. Using "EXPLAIN QUERY PLAN" shows that this is caused by the "GROUP BY" in the "B" sub-query. Running the above query takes around 3 seconds right now. I think that it took 86.23 seconds because the WAL file contained a lot of temporary data, slowing down the whole query. I ran a "PRAGMA wal_checkpoint(FULL)" as those queries were started to slow down and observed an immediate improvement. Anyway, the real problem here is just highlighted by the WAL file usage. Those queries can really go faster. I rewrote them and added a few indexes with 0ffcb80ebbaa2b177f03548035a2ef21ae7ac41d. They now take less than 1ms, which should very much improve the web browsing experience as well as decrease the database worker starvation. Thanks, Mathieu -- https://othacehe.org ------------=_1601308982-5453-1 Content-Type: message/rfc822 Content-Disposition: inline Content-Transfer-Encoding: 7bit Received: (at submit) by debbugs.gnu.org; 24 Sep 2020 11:49:20 +0000 Received: from localhost ([127.0.0.1]:38776 helo=debbugs.gnu.org) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1kLPkW-00062i-AS for submit@debbugs.gnu.org; Thu, 24 Sep 2020 07:49:20 -0400 Received: from lists.gnu.org ([209.51.188.17]:56938) by debbugs.gnu.org with esmtp (Exim 4.84_2) (envelope-from ) id 1kLPkR-00062N-4N for submit@debbugs.gnu.org; Thu, 24 Sep 2020 07:49:18 -0400 Received: from eggs.gnu.org ([2001:470:142:3::10]:45566) by lists.gnu.org with esmtps (TLS1.2:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.90_1) (envelope-from ) id 1kLPkQ-00009h-C0 for bug-guix@gnu.org; Thu, 24 Sep 2020 07:49:14 -0400 Received: from fencepost.gnu.org ([2001:470:142:3::e]:59531) by eggs.gnu.org with esmtp (Exim 4.90_1) (envelope-from ) id 1kLPkQ-0007rF-2z for bug-guix@gnu.org; Thu, 24 Sep 2020 07:49:14 -0400 Received: from [2a01:e0a:19b:d9a0:b888:25b1:7546:eb44] (port=36550 helo=cervin) by fencepost.gnu.org with esmtpsa (TLS1.2:RSA_AES_256_CBC_SHA1:256) (Exim 4.82) (envelope-from ) id 1kLPkP-0001q8-FX for bug-guix@gnu.org; Thu, 24 Sep 2020 07:49:13 -0400 From: Mathieu Othacehe To: bug-guix@gnu.org Subject: cuirass: Slow SQL queries. Date: Thu, 24 Sep 2020 13:49:11 +0200 Message-ID: <878scz75u0.fsf@gnu.org> User-Agent: Gnus/5.13 (Gnus v5.13) Emacs/27.1 (gnu/linux) MIME-Version: 1.0 Content-Type: text/plain X-Spam-Score: -2.3 (--) X-Debbugs-Envelope-To: submit X-BeenThere: debbugs-submit@debbugs.gnu.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: debbugs-submit-bounces@debbugs.gnu.org Sender: "Debbugs-submit" X-Spam-Score: -3.3 (---) Hello, I just added SQL queries logging to Cuirass. I also adapted the Guix shepherd service accordingly and deployed it on berlin. The results are already interesting: --8<---------------cut here---------------start------------->8--- SELECT E.id, E.status, E.timestamp, E.checkouttime, E.evaltime, B.total, B.succeeded, B.failed, B.scheduled FROM (SELECT id, status, timestamp, checkouttime, evaltime FROM Evaluations WHERE (id='16009' )) E LEFT JOIN (SELECT rowid, evaluation, SUM(status=0) as succeeded, SUM(status>0) as failed, SUM(status<0) as scheduled, SUM(status>-100) as total FROM Builds GROUP BY evaluation) B ON B.evaluation=E.id ORDER BY E.id ASC 95.38 SELECT E.id, E.status, E.timestamp, E.checkouttime, E.evaltime, B.total, B.succeeded, B.failed, B.scheduled FROM (SELECT id, status, timestamp, checkouttime, evaltime FROM Evaluations WHERE (id='5407' )) E LEFT JOIN (SELECT rowid, evaluation, SUM(status=0) as succeeded, SUM(status>0) as failed, SUM(status<0) as scheduled, SUM(status>-100) as total FROM Builds GROUP BY evaluation) B ON B.evaluation=E.id ORDER BY E.id ASC 65.88 SELECT E.id, E.status, E.timestamp, E.checkouttime, E.evaltime, B.total, B.succeeded, B.failed, B.scheduled FROM (SELECT id, status, timestamp, checkouttime, evaltime FROM Evaluations WHERE (id='8255' )) E LEFT JOIN (SELECT rowid, evaluation, SUM(status=0) as succeeded, SUM(status>0) as failed, SUM(status<0) as scheduled, SUM(status>-100) as total FROM Builds GROUP BY evaluation) B ON B.evaluation=E.id ORDER BY E.id ASC 86.23 --8<---------------cut here---------------end--------------->8--- Those three queries that originate from "db-get-evaluation-summary" procedure take more than 1 minute to run (65.88, 86.23 and 95.38 seconds). Even if concurrent database reading is permitted, the number of database workers is finite and some of the observed infamous "504" errors are the result of database worker starvation. If you want to help me optimize those queries, you can have a look to "/var/log/cuirass-sql.log" and "/var/log/cuirass-web-sql.log" on berlin, or request those files. Thanks, Mathieu -- https://othacehe.org ------------=_1601308982-5453-1--