From mboxrd@z Thu Jan 1 00:00:00 1970 From: Mark H Weaver Subject: bug#19806: substitute-binary --query busy for 36 minutes with no output Date: Sat, 07 Feb 2015 13:14:31 -0500 Message-ID: <87d25l37y0.fsf@netris.org> Mime-Version: 1.0 Content-Type: text/plain Return-path: Received: from eggs.gnu.org ([2001:4830:134:3::10]:58183) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1YK9uM-0004Ww-8F for bug-guix@gnu.org; Sat, 07 Feb 2015 13:15:07 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1YK9uJ-00080y-1e for bug-guix@gnu.org; Sat, 07 Feb 2015 13:15:06 -0500 Received: from debbugs.gnu.org ([140.186.70.43]:45544) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1YK9uI-00080n-VG for bug-guix@gnu.org; Sat, 07 Feb 2015 13:15:02 -0500 Received: from Debian-debbugs by debbugs.gnu.org with local (Exim 4.80) (envelope-from ) id 1YK9uI-0008Tu-Lg for bug-guix@gnu.org; Sat, 07 Feb 2015 13:15:02 -0500 Sender: "Debbugs-submit" Resent-Message-ID: Received: from eggs.gnu.org ([2001:4830:134:3::10]:58137) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1YK9tq-0004Oo-PU for bug-guix@gnu.org; Sat, 07 Feb 2015 13:14:35 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1YK9tn-0007md-KE for bug-guix@gnu.org; Sat, 07 Feb 2015 13:14:34 -0500 Received: from world.peace.net ([50.252.239.5]:38987) by eggs.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1YK9tn-0007l7-Fz for bug-guix@gnu.org; Sat, 07 Feb 2015 13:14:31 -0500 List-Id: Bug reports for GNU Guix List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Errors-To: bug-guix-bounces+gcggb-bug-guix=m.gmane.org@gnu.org Sender: bug-guix-bounces+gcggb-bug-guix=m.gmane.org@gnu.org To: 19806@debbugs.gnu.org While updating my profile with "guix package -c1 -u", "substitute-binary --query" hung for 36 minutes with ~90% CPU utilization without any active network connections and without printing any output. Here was the relevant excerpt from 'ps auxwwf' after about 30 minutes of CPU time: --8<---------------cut here---------------start------------->8--- USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND [...] root 23061 0.0 0.0 5804 1248 ? Ss 12:29 0:00 /gnu/store/538qidv49w2v942502yqmv0fz187xd9z-guix-0.8.1.f1082ec/bin/guix-daemon --build-users-group guixbuild --cores=1 --max-jobs=1 root 23087 33.3 0.2 10384 4444 ? Ss 12:30 11:44 \_ /gnu/store/538qidv49w2v942502yqmv0fz187xd9z-guix-0.8.1.f1082ec/bin/guix-daemon 23079 guixbuild --cores=1 --max-jobs=1 root 23120 87.9 58.2 1294632 1198688 ? Sl 12:30 30:25 \_ /gnu/store/122jv790mv2mlnylbrbzav65vghbw93n-guile-2.0.11/bin/guile --no-auto-compile /gnu/store/538qidv49w2v942502yqmv0fz187xd9z-guix-0.8.1.f1082ec/bin/guix substitute-binary --query root 23211 0.0 0.0 0 0 ? Zs 12:30 0:00 \_ [guix] --8<---------------cut here---------------end--------------->8--- Looking at the nginx logs on hydra, I see that it downloaded a single nar file (for paredit) very soon after starting up, and then didn't download anything else from hydra until ~36 minutes later, when it downloaded /nix-cache-info and then a narinfo file. It then proceeded to do several grafting operations locally. The 'guix package' command I'm running is v0.8.1-90-g710f3ce, and the 'guix-daemon' and substitute binary is guix-0.8.1.f1082ec. Any ideas what it was doing during those 36 silent minutes? Mark