The Chainsaw Infanticide Logger Manuever

Discussion in 'Ruby' started by Zed A. Shaw, Aug 24, 2005.

  1. Zed A. Shaw

    Zed A. Shaw Guest

    One of the things that's really great about agile languages is they give you the power to do anything. One of the most horrible things about agile languages is they give every other idiot the same power to stab you in the back with a rusty pitchfork.

    I needed to do some simple logging. I made a Logger class and started writing to it. Hmm, my log messages sometimes have a format and sometimes they don't. Nothing I do fixes this.

    Three hours later and half my sanity, I start to snoop through the libraries I've included, and I find this wonderfully horrible gem:

    Not only does this code re-open a class to do something that could *just as easily be done with subclassing*, but the author also TURNS OFF DOCUMENTATION with :nodoc: so that nobody knows about it. Great! So much for Principle Of Least Surprise. This is more like Principle Of Most Heinous Arsenic Injection.

    I then trolled through a few more projects and found that this is common practice. The glue project does it. Glue even goes so far as to re-open the Logger class *just so it can turn it into a singleton*. Great Buddha the insanity is everywhere!

    What's wrong with you people? This is the absolute worst thing I've ever experienced in any language I've used. I thought having magic AspectJ crap silently move my code was bad. At least that stuff was documented and I could optionally turn it off. This can only be fixed with leprechaun backflips into a pool of jello while covered in chocolate. Translation: it can't be fixed easily and I shouldn't have to "fix" it since I didn't break it.

    -- Please, think of the children before you re-open their parent with a damn chainsaw. --

    I only re-open a class after I've tried every other option like subclassing, wrapping, etc. If nothing else works or is too much effort for the modification, then I DOCUMENT THE HELL out of my modification and try desperately to localize the change so that it doesn't hurt anyone else.

    Alright, rant off. Please stop doing this. My appologies if I hurt anyone's feelings.

    Zed A. Shaw
    Zed A. Shaw, Aug 24, 2005
    1. Advertisements

  2. On Aug 23, 2005, at 10:06 PM, Zed A. Shaw wrote:
    [... snip an awesome tirade...]

    ROFLMAO. Well written :)

    "Principle Of Most Heinous Arsenic Injection"...*giggle*

    Thanks for the laugh. I agree with your sentiments, and the way
    you've written them.
    Gavin Kistner, Aug 24, 2005
    1. Advertisements

  3. Zed A. Shaw

    James Britt Guest

    James Britt, Aug 24, 2005
  4. Zedas, here's concept as discussed in #ruby-lang... Take note that I've
    reopened Logger. :p

    class Logger
    # Dictate the way in which this logger should format the messages
    # it displays. This method requires a block. The block should return
    # formatted strings given severity, timestamp, msg, progname.
    # Useless example:
    # logger =
    # logger.format do |severity, timestamp, msg, progname|
    # "#{progname}@#{timestamp} - #{severity}::#{msg}"
    # end
    def format(&format_proc)
    raise 'feed me a block dude' unless format_proc
    @format_proc = format_proc

    # hackish use of *args, give me some love
    def format_message(*args)
    @format_proc ?*args) : super(*args)
    Nicholas Seckar, Aug 24, 2005
  5. Zed A. Shaw

    Eric Hodel Guest

    Oh? You think that's bad?

    There's also this gem sitting right next to it.

    def silence_warnings
    old_verbose, $VERBOSE = $VERBOSE, nil
    $VERBOSE = old_verbose

    So that things like this can be done:

    silence_warnings { Customer ="Customer", :name) }

    instead of doing something simple like:

    unless defined? Customer
    Customer = "Customer", :name
    Eric Hodel, Aug 24, 2005
  6. Zed A. Shaw

    David Brady Guest


    I don't understand. This is a feature of agile languages, not a
    defect. Leaving the door open for chainsaw-wielding maniacs also leaves
    the door open for gifted neurosurgeons.

    I understand your frustration, and I feel your pain. But I am left with
    a critical question:

    Where were your unit tests?

    Admittedly, silence_warnings might not be testable. You might have to
    code review that to catch it. But then again, if *your* unit tests all
    pass, then silence_warnings shouldn't affect you--especially if you test
    the failure cases and assert that warnings were returned. Logger
    integrity, however, should be straightforward.

    I don't mean to come across like a heartless jerk or a TDD zealot. I am
    neither. I am just looking at your pain and thinking, "why does this
    have to hurt?"

    David Brady, Aug 24, 2005
  7. Zed A. Shaw

    Bill Kelly Guest

    I was bitten recently by a change to the CGI module. I don't
    think I can get to quite the same level of moral outrage on this
    one because by comparison what I ran afoul of seems more like what
    one would expect to be a legitimate leveraging of the Power of Ruby,
    even in a library context: no global classes or constants were
    being opened or modified. Something that I used to convert to a
    String instance, was now still a String, but its singleton class had
    been extended with additional features. Including some accompanying
    instance variables, which is the part that bit me.

    My code was littered with cgi['some_parameter'].to_s
    because I'd long ago learned that CGI returned something as
    a parameter value that acted like a String, but wasn't really.
    I added the .to_s when fetching CGI parameters, because the values
    I fetch eventually end up in objects which are serialized out to
    a flat-file database with YAML.

    A recent change to CGI that was--probably--for most intents and
    purposes at least as good or better than the way it used to work
    was apparently to make cgi['some_parameter'] now return a genuine
    String - but one that had been extended with extra features.
    Unfortunately, this had the effect of turning my .to_s calls into
    no-op's. This had the ultimately semi-harmless but alarming and
    baffling result of my database files beginning to show signs of
    very strange bloat: objects that used to appear as simple strings
    in the YAML, were now complex dumps of objects that included the
    string value, but also these ancillary CGI parameters that were
    hitchhiking on these extended String objects CGI was now returning
    as parameter values.

    I think it took me at least an hour and a half to track down the
    cause. (Seemed like an eternity because I was working under a

    To fix it, I did decide to open the String class with, well maybe
    a small set of electric hedge trimmers. But I'm only dealing with
    my private application here. If it were a library I were writing,
    I'd go to prodigious lengths to try to not modify the global behavior
    of Ruby. My cheesy application-level fix:

    class String
    # %%BWK -- this is a kludge to work around the CGI module extending
    # String objects fetched from its parameters with some
    # extra instance variables, which cause really verbose YAML
    # to be output.
    # I already was doing to_s on everything I fetched from
    # the CGI parameters, thinking that was enough to give me
    # a String without any extra baggage. This kludge forces
    # my assumption to be a true one.
    def to_s

    I'm not entirely sure what point I'm driving toward - because
    really what CGI is doing seems to me in general like a pretty
    reasonable use of Ruby. . . And yet it _bit_ me in a similar way to
    what you reported about the Logger Maneuver.

    I guess in general, Library Authors Take Note: Getting tricky in
    your library can end up playing a trick on your users.


    Bill Kelly, Aug 24, 2005
  8. Zed A. Shaw

    Jeff Wood Guest

    My feelings are in-line with the review of Dave's session as OSCON @


    Classes are open: in Ruby, you can always add methods, attributes,
    etc. to existing classes. For example, you can add an encrypt() method
    to the String class. Isn't this dangerous? What if someone changes the
    logic of + for math expressions. No, because if one of your
    programmers overrides methods that breaks things - you take them out
    in the parking lot and beat them with a rubber hose! The language
    shouldn't prohibit us from doing powerful things.

    ---END QUOTE---

    You shouldn't be afraid of having power. That's why you have tests.
    You do have tests, right? ... right??? ... RIGHT !!?!?!?!??!


    "So long, and thanks for all the fish"

    Jeff Wood
    Jeff Wood, Aug 24, 2005
  9. Zed A. Shaw

    Bill Kelly Guest

    Dudes, I do have tests. How in blazes would you write a test
    to catch the problem I described? (Please show your work. :)
    And why would you ever think to do so?

    It's not being afraid of having power. In my own applications,
    I'll exploit any and every cool capability of Ruby I feel like.

    But when I personally write a module I view as a library I'd
    like others to find useful, I take a decidedly more conservative
    approach - deliberately.

    Do you not consider libraries and applications different, where
    Ruby's beloved Openness is concerned?


    Bill Kelly, Aug 24, 2005
  10. Zed A. Shaw

    Jeff Wood Guest

    The truely iterative & testing-complete way to build software is to
    design and implement your tests before you write your code. When all
    of your tests pass, you're done...

    ... If you built your system like that, you should have tests for each
    and every action on your classes ... and the first time somebody elses
    modifications has an affect on your functionality and expected output,
    you should know about it.


    "So long, and thanks for all the fish"

    Jeff Wood
    Jeff Wood, Aug 24, 2005
  11. Zed A. Shaw

    Jeff Wood Guest


    To answer "how/why would you test this"... you should have tests in
    place for your logging functionality. The second something doesn't
    come out right, you know that something is marring the system.=20
    Debugging starts by walking the source of the packages you are using
    and watching for references to the modified functionality... It's not
    that hard to track down.

    Anyways, that's what I do ... it works for me. As far as posting
    example code ... sorry, some companies don't let ya do that.


    "So long, and thanks for all the fish"

    Jeff Wood
    Jeff Wood, Aug 24, 2005
  12. I think the real problem is when this is done in released code. If
    you're going to extend code, extend it cleanly -- IMO.

    Austin Ziegler *
    * Alternate:
    Austin Ziegler, Aug 24, 2005
  13. As Alexander mentioned, the point of the email was not that he couldn't detect
    it, it's that there's nothing he can do about it short of extending the Logger
    class *again* to make it do what he wants.

    Unit tests detect the problem, they don't solve it. Since the OP controls
    neither the logger package nor the glue package, his choices are limited.

    Plus, I'll second Alexander's assertion that you should never have to include
    unit tests to verify that classes work as advertised. That's the package
    author's job, and a programmer's job not to screw with their behavior,
    especially not classes in core and/or stdlib. The alternative is a horribly
    slippery slope.


    Daniel Berger, Aug 24, 2005
  14. Violence is surely the road to enlightenment,
    Nikolai Weibull, Aug 24, 2005
  15. Zed A. Shaw

    Jeff Wood Guest

    Ok, my set of tests for my application would include asserting that if
    a given piece of functionality is going to cause a log message to
    occur, that I validate the residual log files do contain the log
    entries I expected as I expected them to be formatted. If they don't=20
    then the application/library doesn't meet it's spec and/or
    requirements. It's a bug and it needs to be resolved.

    So, you would then have a front-row seat if something was affecting
    the logger output.

    And no, I don't believe there is any difference between building a
    library and building an application ... it's all code that needs to be
    tested and made sure it functions completely as designed.

    I hope that answers you sufficiently.


    "So long, and thanks for all the fish"

    Jeff Wood
    Jeff Wood, Aug 24, 2005
  16. Zed A. Shaw

    Eric Hodel Guest

    I don't understand why I'm supposed to test a standard library I'm
    using. Usually I read the documentation and expect it to work that
    way, but maybe I'm crazy.
    Right now, silence_warnings is only used in the library's test code,
    but that doesn't mean it won't get abused and start wrapping things
    that *should* give warnings. (Of course, the library in question is
    so completely -w unsafe, the warnings would be lost in a pages of

    The way silence_warnings is used is the real problem. Ruby already
    has a perfectly good method of doing exactly what silence_warnings
    was written to accomplish (two of them, in fact!).
    You would think that, until one library decides to go ahead and break
    it. The library where these were found has at least a handful of
    places where you can find questionable software engineering practices.
    It hurts because the library decided to us in the middle of a
    minefield without a map.
    Eric Hodel, Aug 24, 2005
  17. Zed A. Shaw

    David Brady Guest

    I find that the hardest tests to write are the ones that I overlooked
    because I am unaware of my blind spots.

    Until I read your post, I thought like you did--that to_s flattened an
    object into a chunk of text. But now I see that it doesn't. It doesn't
    even return a String object! It returns an object that behaves--dare I
    say quacks?--like a String.

    Another assumption you may be making--and once I state it, the test for
    it should become obvious--is that YAML should output pleasingly human
    readable text, even if it loses the ability to correctly restore objects.

    I know, I know. There exists in business the concept of "approprately
    incorrect". You are using YAML to produce "appropriately incorrect" files.

    The behavior you want is "take a Stringlike object, and emit pleasingly
    simplified text". That's easily testable. Take your CGI object, have
    YAML dump it, then open the YAML file manually and see that the text is
    correct. Or build a CGI object, then build an equivalent object using
    Strings, output them to different files and then assert that there is no
    difference between the files. The second method may seem more robust,
    because it lets you not care how YAML stores Strings... but that's the
    rabbit that led us down this hole in the first place. Use the first
    method, because you don't care if YAML stores CGI the same as a String,
    you care that the output is pleasing to read. If YAML changes the way
    it stores String, you'll want this test to break. Your app should
    shriek until you have verified that the new format is pleasant.

    Once you have a regression test in place, you will be able to remove the
    hack to String#to_s and know when your application is fixed. A good
    alternative to your hack, perhaps, is to replace YAML with a dumper of
    your own devising that transforms Stringlike-->String on save/reload.
    Perhaps even a child class of YAML, whose only override is something like:

    obj = if obj.respond_to? :to_str && obj.class != String

    I haven't learned how to see my blind spots yet. I could not have
    prevented this bug from happening. But having happened, I can
    immediately write a test that verifies that it is fixed, and that future
    revisions to CGI, YAML, and even String will be regression tested
    against this bug.


    David Brady, Aug 24, 2005
  18. Zed A. Shaw

    David Brady Guest

    Me either. I thought Logger was your own code. I agree that you
    shouldn't have to unit test a library that you trust.

    If it's just Logger that's crap, then you can shrug and decide not to
    trust the library and respond accordingly. But you're right, that Ruby
    allows other programmers to open a library you trust and bash it into
    untrustworthiness. That's a real problem that should be considered.

    Is the following legal unit test code?

    def test_no_messing_with_trusted_libraries
    require 'logger'
    assert_nothing_raised( require 'suspect_module', "Hey! Somebody's
    mucking with the logger module!" )

    You're right, you shouldn't HAVE to run that test.

    David Brady, Aug 24, 2005
  19. Zed A. Shaw

    Jeff Wood Guest

    I'm not saying you need to test Logger ... I'm simply stating that you
    should be asserting ALL of the behaviors you design into your

    What if logger isn't even being called ??? or any of a number of
    situations like that... Simply verifying that the application behaves
    in all ways as designed/required isn't "testing Logger".


    "So long, and thanks for all the fish"

    Jeff Wood
    Jeff Wood, Aug 24, 2005
  20. Zed A. Shaw

    Bill Kelly Guest

    Hi David,

    Thanks for your thoughtful reply.

    Yes - agreed.
    Hmm... Actually my assumption (or hope) would be that YAML always
    be able to write out objects that it can correctly restore. My
    reason for wanting my application to be serializing "real" simple
    strings isn't really tied, I think, to any assumptions about how
    YAML itself should behave.

    But yes, I want my *application* to, using YAML, output simple
    strings that are not only pleasingly human readable, but also
    compact*. I have no problem with YAML doing exactly what I've
    asked it to. I just didn't realize I was feeding it complex
    singleton String instances with "extra" instance variables.

    (*) The compactness is desirable for performance reasons:
    I'm already splitting my databases via hashing into 4093 sub-
    files, so each component file of the database can be loaded/saved
    quickly enough. YAML Ain't Mercurial Lightning... ? ;)
    I'm not sure I agree. I'm using YAML to accurately serialize my
    data. It's my fault for feeding it unexpectedly complex data.
    One test I had in mind was,

    assert( cgi['something'].to_s.to_yaml ==['something'].to_s).to_yaml )

    ...but that test does rely on my modified String#to_s behavior.

    One complication is that, for the time being, my application needs
    to run on systems with the 1.8.1 CGI behavior (which returns a
    parameter value as a non-String-object that quacks like a String),
    and the 1.8.2 CGI behavior (which returns a paramater value as a
    genuine String instance whose singleton class happens to have been
    extend'ed with a module that includes some bonus instance variables.)

    So far, my String#to_s hack still seems like a reasonable enough
    way to enforce the behavior I need in my current application. (But
    again, I'd NOT take this hack approach if I were writing a library.)

    So, given my String#to_s hack, I think the above assert() should
    cover the specific problem I was having.

    A more direct approach might have been for me to open the CGI class
    and replace CGI#[] so that it returned simple String instances, not
    complex extend'ed ones. (Again, something I'd consider for my app,
    but not for a library.)

    I'm not sure if more general tests involving YAML and Strings would
    help, since I don't *really* want to change YAML's behavior - I just
    want to not accidentally feed it complex objects.


    Bill Kelly, Aug 24, 2005
    1. Advertisements

Ask a Question

Want to reply to this thread or ask your own question?

You'll need to choose a username for the site, which only take a couple of moments (here). After that, you can post your question and our members will help you out.