The Chainsaw Infanticide Logger Manuever

ruby-talk
1

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:

http://rafb.net/paste/results/0vADxJ56.html

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!

http://rafb.net/paste/results/yXNJvv50.html

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
http://www.zedshaw.com/

2

[... snip an awesome tirade...]

ROFLMAO. Well written :slight_smile:

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

Thanks for the laugh. I agree with your sentiments, and the way you've written them.

···

On Aug 23, 2005, at 10:06 PM, Zed A. Shaw wrote:

3

Zed A. Shaw wrote:
...

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

I take it you first tried to contact the author of the offending code before ranting in public?

James

···

--

http://www.ruby-doc.org - The Ruby Documentation Site
http://www.rubyxml.com - News, Articles, and Listings for Ruby & XML
http://www.rubystuff.com - The Ruby Store for Ruby Stuff
http://www.jamesbritt.com - Playing with Better Toys

4

Zedas, here's concept as discussed in #ruby-lang... Take note that I've reopened Logger. :stuck_out_tongue:

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.new
   # 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
   end

   # hackish use of *args, give me some love
   def format_message(*args)
     @format_proc ? @format_proc.call(*args) : super(*args)
   end
end

5

Oh? You think that's bad?

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

def silence_warnings
   old_verbose, $VERBOSE = $VERBOSE, nil
   begin
     yield
   ensure
     $VERBOSE = old_verbose
   end
end

So that things like this can be done:

silence_warnings { Customer = Struct.new("Customer", :name) }

instead of doing something simple like:

unless defined? Customer
   Customer = Struct.new "Customer", :name
end

···

On 23 Aug 2005, at 21:06, Zed A. Shaw wrote:

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:

http://rafb.net/paste/results/0vADxJ56.html

--
Eric Hodel - drbrain@segment7.net - http://segment7.net
FEC2 57F1 D465 EB15 5D6E 7C11 332A 551C 796C 9F04

6

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!

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
deadline.)

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
    String.new(self)
  end
end

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.

Regards,

Bill

···

From: "Zed A. Shaw" <zedshaw@zedshaw.com>

7

Could all these problems be solved by a require_into_namespace?

Say you have a library which modifies core classes. What if those
modifications existed only inside the library's namespace, so that
they don't leak into the rest of the application?

With a require_into_namespace (or better: require 'foo.rb', :namespace
=> 'bar') it would be the responsibility of the person doing the
require to put things in a namespace, rather than the original library
author, so you get your safety but keep your freedom.

Or is that totally impossible from an internals perspective?

Douglas

···

On 8/24/05, Zed A. Shaw <zedshaw@zedshaw.com> wrote:

Glue even goes so far as to re-open the Logger class *just so it can turn it into a singleton*.

8

Guys,

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?"

-dB

···

--
David Brady
ruby_talk@shinybit.com
I'm feeling really surreal today... OR AM I?

9

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

---QUOTE---

   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 !!?!?!?!??!

j.

···

On 8/24/05, Bill Kelly <billk@cts.com> wrote:

From: "Zed A. Shaw" <zedshaw@zedshaw.com>
>
> 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!

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
deadline.)

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
    String.new(self)
  end
end

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.

Regards,

Bill

--
"So long, and thanks for all the fish"

Jeff Wood

10

Douglas,

Matz brought the very ting up in his presentation on Ruby 2 some time
ago. So he's thinking about it, but I suspect it is hard to do. Also
I'm not sure if namespace is the appropriate term. Isn't "scope" the
better term?

But to answer your question. Yes, that would certainly help alot.
Although I can see the next argument now....

    XYZ made all these great changes to ABC lib but hide it all in a
scopespace!
    Come on! What good are all the changes if we can't use em :wink:

T.

11

Douglas Livingstone ha scritto:

Glue even goes so far as to re-open the Logger class *just so it can turn it into a singleton*.

Could all these problems be solved by a require_into_namespace?

IMHO this problems could be sloved by just running ruby by default with $VERBOSE=true:
C:\Documents and Settings\gabriele>irb -r ubygems
irb(main):001:0> $VERBOSE=true
=> true
irb(main):002:0> require 'glue/logger'
c:/Program Files/ruby/lib/ruby/gems/1.8/gems/glue-0.22.0/lib/glue/logger.rb:154:
  warning: method redefined; discarding old format_message
=> true

:wink:

···

On 8/24/05, Zed A. Shaw <zedshaw@zedshaw.com> wrote:

12

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

Dudes, I do have tests. How in blazes would you write a test
to catch the problem I described? (Please show your work. :slight_smile:
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?

Regards,

Bill

···

From: "Jeff Wood" <jeff.darklight@gmail.com>

13

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

···

On 8/24/05, Jeff Wood <jeff.darklight@gmail.com> wrote:

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

--
Austin Ziegler * halostatue@gmail.com
               * Alternate: austin@halostatue.ca

14

Jeff Wood wrote:

---QUOTE---

   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---

Violence is surely the road to enlightenment,
        nikolai

···

--
Nikolai Weibull: now available free of charge at http://bitwi.se/\!
Born in Chicago, IL USA; currently residing in Gothenburg, Sweden.
main(){printf(&linux["\021%six\012\0"],(linux)["have"]+"fun"-97);}

15

Guys,

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?

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.

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.

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 noise.)

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!).

Logger integrity, however, should be straightforward.

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.

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?"

It hurts because the library decided to us in the middle of a minefield without a map.

···

On 24 Aug 2005, at 08:53, David Brady wrote:

--
Eric Hodel - drbrain@segment7.net - http://segment7.net
FEC2 57F1 D465 EB15 5D6E 7C11 332A 551C 796C 9F04

16

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.

j.

···

On 8/24/05, Bill Kelly <billk@cts.com> wrote:

From: "Jeff Wood" <jeff.darklight@gmail.com>
>
> You shouldn't be afraid of having power. That's why you have tests.
> You do have tests, right? ... right??? ... RIGHT !!?!?!?!??!

Dudes, I do have tests. How in blazes would you write a test
to catch the problem I described? (Please show your work. :slight_smile:
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?

Regards,

Bill

--
"So long, and thanks for all the fish"

Jeff Wood

17

So,

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.
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.

j.

···

On 8/24/05, Bill Kelly <billk@cts.com> wrote:

From: "Jeff Wood" <jeff.darklight@gmail.com>
>
> You shouldn't be afraid of having power. That's why you have tests.
> You do have tests, right? ... right??? ... RIGHT !!?!?!?!??!

Dudes, I do have tests. How in blazes would you write a test
to catch the problem I described? (Please show your work. :slight_smile:
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?

Regards,

Bill

--
"So long, and thanks for all the fish"

Jeff Wood

18

Eric Hodel wrote:

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.

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'
    Logger.freeze
    assert_nothing_raised( require 'suspect_module', "Hey! Somebody's mucking with the logger module!" )
end

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

-dB

···

--
David Brady
ruby_talk@shinybit.com
I'm feeling really surreal today... OR AM I?

19

Austin Ziegler said:

···

On 8/24/05, Jeff Wood <jeff.darklight@gmail.com> wrote:

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

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

Well said.

It is probably worth having a public discussion on the meaning of "extend
cleanly".

--
-- Jim Weirich jim@weirichhouse.org http://onestepback.org
-----------------------------------------------------------------
"Beware of bugs in the above code; I have only proved it correct,
not tried it." -- Donald Knuth (in a memo to Peter van Emde Boas)

20

Eric Hodel ha scritto:

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!).

talking about silence_warning in tests.. I actually found the need to silence some warnings in test code recently and was thinking about adding it myself.
What methods are already in ruby to get a "no warnign zone" in cases where I know there are warnings that are not important, and still keep em in the rest of the code?