Path: csiph.com!v102.xanadu-bbs.net!xanadu-bbs.net!feeder.erje.net!eu.feeder.erje.net!newsfeed.xs4all.nl!newsfeed4.news.xs4all.nl!xs4all!post.news.xs4all.nl!not-for-mail Return-Path: X-Original-To: python-list@python.org Delivered-To: python-list@mail.python.org X-Spam-Status: OK 0.000 X-Spam-Evidence: '*H*': 1.00; '*S*': 0.00; 'python.': 0.02; 'scripts': 0.03; 'interpreter': 0.05; 'output': 0.05; 'cache': 0.07; 'debug': 0.07; 'debugging': 0.07; 'desirable.': 0.07; 'great.': 0.07; 'branching': 0.09; 'debugging.': 0.09; 'executed': 0.09; 'executes': 0.09; 'function,': 0.09; 'indeed,': 0.09; 'latter': 0.09; 'optimizing': 0.09; 'output,': 0.09; 'statements': 0.09; 'cc:addr:python-list': 0.11; 'python': 0.11; 'project,': 0.12; 'useful,': 0.14; "wouldn't": 0.14; '(when': 0.16; 'adjusted': 0.16; 'eliminating': 0.16; 'example)': 0.16; 'fine.': 0.16; 'loops': 0.16; 'manageable': 0.16; 'quantum': 0.16; "would've": 0.16; 'wrote:': 0.18; 'trying': 0.19; 'unlike': 0.19; 'seems': 0.21; '(the': 0.22; '8bit%:5': 0.22; 'memory': 0.22; 'example': 0.22; 'email addr:gmail.com>': 0.22; 'cc:addr:python.org': 0.22; 'print': 0.22; 'certainly': 0.24; 'ph.d.': 0.24; 'subject:problem': 0.24; '\xa0if': 0.24; 'mon,': 0.24; '---': 0.24; 'cc:2**0': 0.24; '>': 0.26; 'second': 0.26; 'certain': 0.27; 'header:In-Reply-To:1': 0.27; 'tried': 0.27; 'point': 0.28; 'function': 0.29; 'specifically': 0.29; 'generally': 0.29; 'mode': 0.30; 'statement': 0.30; 'message-id:@mail.gmail.com': 0.30; "i'm": 0.30; "skip:' 10": 0.31; 'clock': 0.31; 'overhead': 0.31; 'quite': 0.32; 'candidate': 0.34; "i'd": 0.34; 'problem': 0.35; 'subject:with': 0.35; 'except': 0.35; 'but': 0.35; 'received:google.com': 0.35; 'add': 0.35; 'there': 0.35; 'instances': 0.36; 'tight': 0.36; 'useful': 0.36; 'should': 0.36; 'seconds': 0.37; 'application': 0.37; 'too': 0.37; 'step': 0.37; 'being': 0.38; 'sometimes': 0.38; 'easiest': 0.38; 'jason': 0.38; 'needed': 0.38; 'skip:- 10': 0.38; 'pm,': 0.38; 'rather': 0.38; 'anything': 0.39; 'enough': 0.39; 'university': 0.39; 'skip:u 10': 0.60; 'duration': 0.60; 'ian': 0.60; 'subject:"': 0.60; 'most': 0.60; 'simply': 0.61; "you're": 0.61; 'first': 0.61; 'times': 0.62; 'such': 0.63; 'subject:The': 0.64; 'more': 0.64; 'to:addr:gmail.com': 0.65; 'worth': 0.66; 'here': 0.66; 'minutes': 0.67; 'optimized': 0.68; 'business': 0.70; 'florida': 0.78; 'potentially': 0.81; "'dead'": 0.84; '200k': 0.84; ':).': 0.84; 'ambiguous': 0.84; 'calls,': 0.84; 'improvement': 0.84; 'upset': 0.84; 'deactivated': 0.91; 'doubling': 0.91; '2013': 0.98 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20120113; h=mime-version:in-reply-to:references:date:message-id:subject:from:to :cc:content-type; bh=rFPMnkDchTDN5LfRlt3NQ3N3WDWjRZWDLAGk5O54tFM=; b=lNU51FOZCpX27sNSTD0fN551H/NrCAS9XZSnV0XaC3ZbTobt9ND0RqYgiG20EQyxAF ywHA2BIW5kFLiFY4AV81O6Ys/eth8wunXYJzscV8/xC2EMF6MqZ/NIdRQcOIRMdMw6sS +Dr10asmXOp76ElURQlwfYvpHJwJIgJft3LxLy95KVHhDr4ATVqs2Rudj9hY29rRj5/g 0MWwb0WHfRr8MO1ivISOoX5jG3YcNPg/U+7V5FLdTQH4LV2aDjYDDaN77zxRoxUWwQOw kOLBXbUw9A/318ReDNblH2TaKJQQdGukB6a+GCqh692wc3/vxjqSttsCxP20Qn+JGHVK wpXQ== MIME-Version: 1.0 X-Received: by 10.50.127.211 with SMTP id ni19mr8827543igb.93.1370286589088; Mon, 03 Jun 2013 12:09:49 -0700 (PDT) In-Reply-To: References: <687dea63-84da-4c45-9366-cb5a10665d1f@googlegroups.com> Date: Mon, 3 Jun 2013 15:09:48 -0400 Subject: Re: PyWart: The problem with "print" From: Jason Swails To: Ian Kelly Content-Type: multipart/alternative; boundary=089e013c5aee621b4904de44b50e Cc: Python X-BeenThere: python-list@python.org X-Mailman-Version: 2.1.15 Precedence: list List-Id: General discussion list for the Python programming language List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , Newsgroups: comp.lang.python Message-ID: Lines: 159 NNTP-Posting-Host: 2001:888:2000:d::a6 X-Trace: 1370286598 news.xs4all.nl 15887 [2001:888:2000:d::a6]:58530 X-Complaints-To: abuse@xs4all.nl Xref: csiph.com comp.lang.python:46803 --089e013c5aee621b4904de44b50e Content-Type: text/plain; charset=ISO-8859-1 On Mon, Jun 3, 2013 at 1:12 PM, Ian Kelly wrote: > On Sun, Jun 2, 2013 at 6:16 PM, Jason Swails > wrote: > > I'm actually with RR in terms of eliminating the overhead involved with > > 'dead' function calls, since there are instances when optimizing in > Python > > is desirable. I actually recently adjusted one of my own scripts to > > eliminate branching and improve data layout to achieve a 1000-fold > > improvement in efficiency (~45 minutes to 0.42 s. for one example) --- > all > > in pure Python. The first approach was unacceptable, the second is fine. > > For comparison, if I add a 'deactivated' debugprint call into the inner > loop > > (executed 243K times in this particular test), then the time of the > > double-loop step that I optimized takes 0.73 seconds (nearly doubling the > > duration of the whole step). > > It seems to me that your problem here wasn't that the time needed for > the deactivated debugprint was too great. Your problem was that a > debugprint that executes 243K times in 0.73 seconds is going to > generate far too much output to be useful, and it had no business > being there in the first place. *Reasonably* placed debugprints are > generally not going to be a significant time-sink for the application > when disabled. Well in 'debug' mode I wouldn't use an example that executed the loop 200K times -- I'd find one that executed a manageable couple dozen, maybe. When 'disabled,' the print statement won't do anything except consume clock cycles and potentially displace useful cache (the latter being the more harmful, since most applications are bound by the memory bus). It's better to eliminate this dead call when you're not in 'debugging' mode. (When active, it certainly would've taken more than 0.73 seconds) Admittedly such loops should be tight enough that debugging statements inside the inner loop are generally unnecessary, but perhaps not always. But unlike RR, who suggests some elaborate interpreter-wide, ambiguous ignore-rule to squash out all of these functions, I'm simply suggesting that sometimes it's worth commenting-out debug print calls instead of 'just leaving them there because you won't notice the cost' :). > The easiest way to eliminate these 'dead' calls is to simply comment-out > the > > print call, but I would be quite upset if the interpreter tried to > outsmart > > me and do it automagically as RR seems to be suggesting. > > Indeed, the print function is for general output, not specifically for > debugging. If you have the global print deactivation that RR is > suggesting, then what you have is no longer a print function, but a > misnamed debug function. > Exactly. I was just trying to make the point that it is -occasionally- worth spending the time to comment-out certain debug calls rather than leaving 'dead' function calls in certain places. All the best, Jason -- Jason M. Swails Quantum Theory Project, University of Florida Ph.D. Candidate 352-392-4032 --089e013c5aee621b4904de44b50e Content-Type: text/html; charset=ISO-8859-1 Content-Transfer-Encoding: quoted-printable



On Mon, Jun 3, 2013 at 1:1= 2 PM, Ian Kelly <ian.g.kelly@gmail.com> wrote:
On Sun, Jun 2, 2013 at 6:16 PM, Jason Swails <jason.swails@gmail.com= > wrote:
> I'm actually with RR in terms of eliminating the overhead involved= with
> 'dead' function calls, since there are instances when optimizi= ng in Python
> is desirable. =A0I actually recently adjusted one of my own scripts to=
> eliminate branching and improve data layout to achieve a 1000-fold
> improvement in efficiency (~45 minutes to 0.42 s. for one example) ---= all
> in pure Python. =A0The first approach was unacceptable, the second is = fine.
> For comparison, if I add a 'deactivated' debugprint call into = the inner loop
> (executed 243K times in this particular test), then the time of the > double-loop step that I optimized takes 0.73 seconds (nearly doubling = the
> duration of the whole step).

It seems to me that your problem here wasn't that the time needed for the deactivated debugprint was too great. Your problem was that a
debugprint that executes 243K times in 0.73 seconds is going to
generate far too much output to be useful, and it had no business
being there in the first place. =A0*Reasonably* placed debugprints are
generally not going to be a significant time-sink for the application
when disabled.

Well in 'debug' mode I wouldn't use an example that executed = the loop 200K times -- I'd find one that executed a manageable couple d= ozen, maybe. =A0When 'disabled,' the print statement won't do a= nything except consume clock cycles and potentially displace useful cache (= the latter being the more harmful, since most applications are bound by the= memory bus). =A0It's better to eliminate this dead call when you'r= e not in 'debugging' mode. =A0(When active, it certainly would'= ve taken more than 0.73 seconds)=A0Admittedly such loops should be tight en= ough that debugging statements inside the inner loop are generally unnecess= ary, but perhaps not always.=A0

But unlike RR, who suggests some elaborate interpreter-wide, ambiguous= ignore-rule to squash out all of these functions, I'm simply suggestin= g that sometimes it's worth commenting-out debug print calls instead of= 'just leaving them there because you won't notice the cost' :)= .

> The easiest way to eliminate these 'dead' calls is to simply c= omment-out the
> print call, but I would be quite upset if the interpreter tried to out= smart
> me and do it automagically as RR seems to be suggesting.

Indeed, the print function is for general output, not specifically for
debugging. =A0If you have the global print deactivation that RR is
suggesting, then what you have is no longer a print function, but a
misnamed debug function.

Exactly. =A0I was just trying to make the point that it is = -occasionally- worth spending the time to comment-out certain debug calls r= ather than leaving 'dead' function calls in certain places.

All the best,
Jason

--
Jason M. Swails
Quantum Theory Project,
Univer= sity of Florida
Ph.D. Candidate
352-392-4032
--089e013c5aee621b4904de44b50e--