一知半解用ruby开发 log的变化

http://jack.iteye.com/blog/257232前面一篇写的带流水了，这次专选一个主题。

  ROR有debug功能，但是从未用过。但是开发过程中，总要看下运行环节中某些函数的调用是否正确，怎么办呢。

   最开始的哪会，也就是刚刚学习ROR哪会，输出运行中间过程都是老实的用logger.info，logger.debug这些的。不过用了段时间，总觉得用的不爽。这几个函数用于输出文本还行，要直接看数据库的查询结果，Hash的值这些都不方便。于是开始用p函数。

  项目中类似

  p test
  p User.find(1)
  p my_hash

开始逐渐增多。慢慢越来越多，p的输出结果和顺序都是看代码的执行顺序的，到了一定程度，一执行代码屏幕上出现好几十甚至好几百的p函数输出结果。 最终，我需要的输出结果被淹没在p的海洋中，怎么也找不到了。
 
   怎么办，加分割吧。然后代码就变成这样了

  p "............................"
  p User.find(1)
  p "............................"

  嗯，这下子好找很多了。好吧，我知道这个只是五十步笑百步。于是又有了下面的写法

  
p "class user line 100"
  p User.find(1)
  p "out info #{info}"

  嘿嘿，治标不治本的写法，不过出现这样的情况，也是项目逐渐变大过程中的一部分，在一定规模下面，上面的这些都行。至于多少规模，各自感觉吧。

  然后呢，开始有了质的变化，因为输出太多，有些时候需要输出，有的时候不需要，这样就需要控制p的执行。于是有一个函数写成了这样的

 def do_some_action(id=nil,info="",debug=false)
   p info if debug
   end

现在查下整个项目代码，也就只有一个函数写成这样的，通过输入参数来控制p的输出。为啥只有一个，我现在也有点想不起来了。 不过至少比起上面的写法，进步了不少了吧。

过了段时间之后，又改进了写法。

def debug(d=true)
      @debug = d 
    end

    def log(str)
      ActionController::Base.logger.debug str if ActionController::Base.logger && (ActionController::Base.logger.debug? || @debug)
      p str if ActionController::Base.logger && (ActionController::Base.logger.debug? || @debug)
end

通过debug函数来控制是否需要输出全部的log，然后在通过log函数来同时输出到log文件和console
这个写法最终也没有完全推广开，就是一个主文件中用了下。

  到目前为止，项目中有3种不同的运行log输出方式了。最终这些都完全被淘汰了，上面的这些办法过渡阶段用用还行，多了实在头痛。
 

  最终需要知道某些变量的值之外，还要知道在那个文件的哪一行等一些辅助信息，这样才能快速定位，修改。

  通过je上各位的提示，最终版本的log输出函数写成了这样的

  

def debug_print(str)
  #return
  call =  caller[0].split("/")
  tmp = call[call.size-1]
  log =  tmp + "::"  + str.to_s
  ActionController::Base.logger.debug log if ActionController::Base.logger && (ActionController::Base.logger.debug? || @debug)
  p log if ActionController::Base.logger && (ActionController::Base.logger.debug? || @debug)
end

通过这个，可以输出类似这样的信息

引用

"application.rb:491:in `authorize'::authorize"
"application.rb:520:in `get'::session id=3"

当然上面的这个函数还是有缺陷的，还是有改进的余地的。这个不说。
自从把代码中的前三种log输出方法通通换成 debug_print之后，这样舒服多了，需要的信息一目了然。出错位置也很清晰了。

不过还是有不太满意的，随着代码运行过程中千百次的调用debug_print，整体运行速度下降了好多。 某个页面带debug_print执行，5秒，不执行debug_print 1秒不到。相差甚大。还好真正上线的时候，可以随时调整debug_print的内容，这样就没事了。

log的事情基本上是完了，下次考虑写下项目中配置文件的变化，如何从YAML到DSL的。



  

评论

1 楼 trace 2008-10-25  

为什么不用debugger方法呢，在terminal里调试还是满方便的啊