From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from lists.gentoo.org (pigeon.gentoo.org [208.92.234.80]) by finch.gentoo.org (Postfix) with ESMTP id 47F1C138A1F for ; Sun, 26 Jan 2014 15:32:56 +0000 (UTC) Received: from pigeon.gentoo.org (localhost [127.0.0.1]) by pigeon.gentoo.org (Postfix) with SMTP id 2C54BE0C69; Sun, 26 Jan 2014 15:32:52 +0000 (UTC) Received: from faith.eroen.eu (faith.eroen.eu [178.79.147.241]) by pigeon.gentoo.org (Postfix) with ESMTP id D2163E0C4A for ; Sun, 26 Jan 2014 15:32:50 +0000 (UTC) Received: from falcon.eroen.eu (unknown [10.10.0.26]) by faith.eroen.eu (Postfix) with ESMTP id 59B0D2402E for ; Sun, 26 Jan 2014 15:38:08 +0000 (GMT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=falcon.eroen.eu; s=faith; t=1390750692; bh=ZTZ8IbIIYik00GL/wFWrpTH1LuG8lctvApk82NZOHlc=; h=Date:From:To:Subject:In-Reply-To:References; b=x7XoPsYJsZwRqR+5EyEQNspi8qSo0S79Quvm3VrZS64iyt4+HfNwTpDfYYLMujnPA rUYsLrGwDnelgSdmnyz0jAhBDfr7uCVgNABmAoIFxzqaUwkcbuFEjWUCimg8+zFeGY VrUuA0uvcXb5FSfi4mzty5uB+Z3mI3Suy2koXs/w= Date: Sun, 26 Jan 2014 16:32:38 +0100 From: eroen To: gentoo-user@lists.gentoo.org Subject: [gentoo-user] Re: Portage performance dropped considerably Message-ID: <20140126163238.20bca0ce@falcon.eroen.eu> In-Reply-To: References: X-Mailer: Claws Mail 3.9.3 (GTK+ 2.24.22; x86_64-pc-linux-gnu) Precedence: bulk List-Post: List-Help: List-Unsubscribe: List-Subscribe: List-Id: Gentoo Linux mail X-BeenThere: gentoo-user@lists.gentoo.org Reply-to: gentoo-user@lists.gentoo.org MIME-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha1; boundary="Sig_/Y9PuO+oHa9PCAHjSkF8/ZyV"; protocol="application/pgp-signature" X-Archives-Salt: b65613d4-da77-4758-bc30-675a4ee13167 X-Archives-Hash: 974af544f0c7b31e66adb190ef201b22 --Sig_/Y9PuO+oHa9PCAHjSkF8/ZyV Content-Type: multipart/mixed; boundary="MP_/+dT4cwBWA2GoPd8aCZR_BUw" --MP_/+dT4cwBWA2GoPd8aCZR_BUw Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: quoted-printable Content-Disposition: inline On Sun, 26 Jan 2014 07:09:49 -0800, Greg Turner wrote: >It would help if there were some decent way to get some statistics >about where portage is spending all its time (especially, I suspect, >within the bash code, but the python level would also be interesting >to analyse). Anyone know of a good way of doing that? http://permalink.gmane.org/gmane.linux.gentoo.devel/89518 Also, the attached patch to portage (works with 2.2.7 and 2.2.8 at least, that too by TomWij) makes portage print out some more information on what part of dependency resolution currently takes place, without all the noise from --debug. --=20 eroen --MP_/+dT4cwBWA2GoPd8aCZR_BUw Content-Type: text/x-patch Content-Transfer-Encoding: quoted-printable Content-Disposition: attachment; filename=emerg.resolv.time_print.patch index 7b77edc..cfd7025 100644 --- a/pym/_emerge/depgraph.py +++ b/pym/_emerge/depgraph.py @@ -86,6 +86,10 @@ if sys.hexversion >=3D 0x3000000: else: _unicode =3D unicode =20 +from time import gmtime, strftime +def time_print(message): + print("\n%s: %s " % (strftime("%Y-%m-%d %H:%M:%S", gmtime()), message), = end=3D"") + class _scheduler_graph_config(object): def __init__(self, trees, pkg_cache, graph, mergelist): self.trees =3D trees @@ -1585,6 +1589,10 @@ class depgraph(object): self._spinner_update() while dep_stack: dep =3D dep_stack.pop() +# try: +# time_print(" Processing: %s" % dep.cpv) +# except AttributeError: +# pass if isinstance(dep, Package): if not self._add_pkg_deps(dep, allow_unsatisfied=3Dallow_unsatisfied): @@ -2106,6 +2114,7 @@ class depgraph(object): for dep_root, dep_string, dep_priority in deps: if not dep_string: continue +# time_print(" Reducing: %s" % dep_string) if debug: writemsg_level("\nParent: %s\n" % (pkg,), noiselevel=3D-1, level=3Dlogging.DEBUG) @@ -2154,6 +2163,8 @@ class depgraph(object): if not dep_string: continue =20 +# time_print(" Disjunct: %s" % dep_string) + if not self._add_pkg_dep_string( pkg, dep_root, dep_priority, dep_string, allow_unsatisfied): @@ -3005,6 +3016,7 @@ class depgraph(object): virtuals =3D pkgsettings.getvirtuals() args =3D self._dynamic_config._initial_arg_list[:] =20 + time_print("Adding root packages") for arg in self._expand_set_args(args, add_to_digraph=3DTrue): for atom in arg.pset.getAtoms(): self._spinner_update() @@ -3116,20 +3128,24 @@ class depgraph(object): =20 # Now that the root packages have been added to the graph, # process the dependencies. + time_print("Processing dependencies") if not self._create_graph(): return 0, myfavorites =20 + time_print("Checking for slot conflicts") try: self.altlist() except self._unknown_internal_error: return False, myfavorites =20 + time_print("Checking for blocker conflicts") if (self._dynamic_config._slot_collision_info and not self._accept_blocker_conflicts()) or \ (self._dynamic_config._allow_backtracking and "slot conflict" in self._dynamic_config._backtrack_infos): return False, myfavorites =20 + time_print("Checking for rebuild triggers") if self._rebuild.trigger_rebuilds(): backtrack_infos =3D self._dynamic_config._backtrack_infos config =3D backtrack_infos.setdefault("config", {}) @@ -3138,12 +3154,14 @@ class depgraph(object): self._dynamic_config._need_restart =3D True return False, myfavorites =20 + time_print("Checking if restart is needed") if "config" in self._dynamic_config._backtrack_infos and \ ("slot_operator_mask_built" in self._dynamic_config._backtrack_infos["c= onfig"] or "slot_operator_replace_installed" in self._dynamic_config._backtrack_in= fos["config"]) and \ self.need_restart(): return False, myfavorites =20 + time_print("Checking if we have to prune rebuilds") if not self._dynamic_config._prune_rebuilds and \ self._dynamic_config._slot_operator_replace_installed and \ self._get_missed_updates(): @@ -3161,10 +3179,12 @@ class depgraph(object): self._dynamic_config._need_restart =3D True return False, myfavorites =20 + time_print("Checking if restart is needed") if self.need_restart(): # want_restart_for_use_change triggers this return False, myfavorites =20 + time_print("Checking for parameters that change behavior") if "--fetchonly" not in self._frozen_config.myopts and \ "--buildpkgonly" in self._frozen_config.myopts: graph_copy =3D self._dynamic_config.digraph.copy() @@ -3188,6 +3208,7 @@ class depgraph(object): =20 digraph_nodes =3D self._dynamic_config.digraph.nodes =20 + time_print("Checking for changes that are needed") if any(x in digraph_nodes for x in self._dynamic_config._needed_unstable_keywords) or \ any(x in digraph_nodes for x in @@ -3200,6 +3221,7 @@ class depgraph(object): self._dynamic_config._success_without_autounmask =3D True return False, myfavorites =20 + time_print("Done resolving!") # We're true here unless we are missing binaries. return (True, myfavorites) =20 @@ -5851,21 +5873,25 @@ class depgraph(object): root_config.root]["root_config"] =3D root_config =20 def _resolve_conflicts(self): - + time_print ("Trying to accept blocker conflicts ") if "complete" not in self._dynamic_config.myparams and \ self._dynamic_config._allow_backtracking and \ self._dynamic_config._slot_collision_nodes and \ not self._accept_blocker_conflicts(): self._dynamic_config.myparams["complete"] =3D True =20 + time_print ("Resolving slot conflicts for complete graph ") if not self._complete_graph(): raise self._unknown_internal_error() =20 + time_print ("Processing slot conflicts ") self._process_slot_conflicts() =20 if self._dynamic_config._allow_backtracking: + time_print ("Triggering slot operator reinstalls ") self._slot_operator_trigger_reinstalls() =20 + time_print ("Validating blockers ") if not self._validate_blockers(): # Blockers don't trigger the _skip_restart flag, since # backtracking may solve blockers when it solves slot @@ -7883,7 +7909,7 @@ def _spinner_start(spinner, myopts): spinner.update =3D spinner.update_quiet =20 if show_spinner: - portage.writemsg_stdout("Calculating dependencies ") + portage.writemsg_stdout("%s: Calculating dependencies " % strftime("%Y-= %m-%d %H:%M:%S", gmtime())) =20 def _spinner_stop(spinner): if spinner is None or \ --MP_/+dT4cwBWA2GoPd8aCZR_BUw-- --Sig_/Y9PuO+oHa9PCAHjSkF8/ZyV Content-Type: application/pgp-signature; name=signature.asc Content-Disposition: attachment; filename=signature.asc -----BEGIN PGP SIGNATURE----- Version: GnuPG v2.0.22 (GNU/Linux) iQEcBAEBAgAGBQJS5SqWAAoJELSISlJWmwxLlzIH/2cXgfVmJt+jFL8eWu1tNn5H Jdq/qzJKgcpQ40E+F9KdlTZDwom00mutyLE2JDYxKekw9AJwDdqAsGJfqmaNMyhc Tlj4dq3PWfo4Eru4WaeoKEw/sSbW5WJ1G04lJpBfWQyNNBR9lu15isrd2Ap2/OTi Br+M9nl+uaVPYEl6dE8XY7kbz0oVDpNdCWwWM9OMTtscmjSBRPkkyHwjuyNI2/Kg GPEql12yJNnf09KfLhChLcTuRe2YHsL/Vc1Ihj9EwUAUYePMhrP92GsyUP43LcND bnMyx6018qteZb1XqhNBcURu0Z7NFFGxQV0AF42IUar0CxEuZYpobknBQMY57FE= =QEaN -----END PGP SIGNATURE----- --Sig_/Y9PuO+oHa9PCAHjSkF8/ZyV--