• Rails Logging Tips Feb 24, 2007

    Posted by Mike Naberezny in Ruby

    In this article, we’ll take a look at how to use the logging facilities built into Rails and then share a few tips:

    Accessing the Rails Logger

    Rails automatically sets up logging to a file in the log/ directory using Logger from the Ruby Standard Library. Do not confuse this with Log4r, a completely different library. The logfile will be named corresponding to your environment, e.g. log/development.log.

    To log a message from either a controller or a model, access the Rails logger instance with the logger method:

    class HomeController < ActionController::Base
  def index
    logger.info 'informational message'
  end
end

    From outside a controller or model, you can pass the logger instance or access it with the constant RAILS_DEFAULT_LOGGER.

    Log Levels

    In the snippet above, a message is logged at the INFO level by calling a method of the same name (info).

    The levels available on the logger are (in ascending order): debug, info, warn, error, and fatal.

    Ruby's Logger supports masking levels so the types of messages recorded in the log can be controlled. By default, Rails will log all levels (debug and higher) in every environment except production. In the production environment, it will only log info and higher. This behavior can be changed in the configuration for each environment.

    Filtering Sensitive Parameters

    When Rails receives a request, ActionController logs the request parameters. This is very handy for debugging but sometimes it's not desirable to have certain parameters, such as passwords, stored as plain text in the log.

    Rails 1.2 introduced the filter_parameter_logging class method to remedy this:

    class ApplicationController < ActionController::Base
  filter_parameter_logging :password
end

    The above will cause any parameter name matching /password/i to have its value replaced with [FILTERED] in the log. To filter multiple parameters, simply add them as extra arguments to filter_parameter_logging by separating them with commas. For other uses of filter_parameter_logging, see the ActionController documentation.

    Note: it's important to remember that filter_parameter_logging will only filter ActionController request information. The parameters could still appear in any SQL queries being logged by ActiveRecord. However, SQL queries are not logged in the production environment by default.

    Creating Audit Logs

    Sometimes logging is required but putting the messages in the Rails log isn't desirable. One such case is when keeping a separate logfile for auditing is a business requirement.

    To create an audit log, simply create a new instance of Logger and pass it a File instance for your own logfile.

    One possible source of confusion is the formatting of the log message due to a patch Rails makes to Logger. This can be seen when using irb as opposed to script/console:

    $ irb
irb(main):001:0> require 'logger'
=> true
irb(main):002:0> Logger.new(STDOUT).info('message')
I, [2007-02-24T09:45:51.236763 #557]  INFO -- : message

    $ script/console
Loading development environment.
>> Logger.new(STDOUT).info('message')
message

    As you can see, the message formatting is lost when run in the Rails environment. To format a log message when using Rails, create your own Logger subclass and implement the format_message method:

    class AuditLogger < Logger
  def format_message(severity, timestamp, progname, msg)
    "#{timestamp.to_formatted_s(:db)} #{severity} #{msg}\n"
  end
end

    To use the new AuditLogger, instantiate it with a File instance:

    logfile = File.open('/path/to/audit.log', 'a')
audit_log = AuditLogger.new(logfile)

    Your new log is now ready to use by calling methods on it like audit_log.info 'message'.

    One important point to remember is that the logfile object does not implicitly flush to the file by default. This means that your code must call logfile.flush for the data to be written out. Alternatively, you can set logfile.sync = true to turn on implicit flushing.

    ActiveRecord Logging on the Console

    When debugging your applications with script/console, it can be very useful to see the SQL output of your ActiveRecord queries. One way to do this is to use tail -f on your logfile.

    However, this isn't very convenient and shows all other log information as well. An easier way that can be done directly from script/console is to enter this line:

    ActiveRecord::Base.logger = Logger.new(STDOUT)

    This will cause the queries to be displayed immediately on the console as you interact with your ActiveRecord objects with method calls like Article.find :all.

    ActionController Logging on the Console

    Just like with ActiveRecord above, you can also redirect ActionController's log output to the console when using script/console:

    ActionController::Base.logger = Logger.new(STDOUT)

    You can then observe ActionController activities when using using using the app object on the console, such as app.get '/'. For a brief tutorial on using app, see this post on Mike Clark's weblog.

    Firebug Console

    Firebug is a popular extension for the Firefox browser that provides a number of useful capabilities, with a Javascript console being among them. The console is accessed by console.log('message') in Javascript.

    This means that any Rails view emitting this little Javascript call between <script> tags can write to the Firebug console.

    It also means that any RJS template can write to the Firebug console for debugging:

    page.call 'console.log', 'informational message'

    This can be very useful for logging debug information during AJAX requests where a popup from alert() isn't desirable.

  • Easier XML-RPC for PHP 5 Feb 19, 2007

    Posted by Mike Naberezny in PHP

    A few weeks ago, I rewrote the Zend XML-RPC client. After fixing some bugs and writing a test suite, I made some enhancements and usability improvements. You can learn more about the new XML-RPC client from its documentation. Here it is in a nutshell:

    Calling Remote Methods

    The new XML-RPC client has always functioned similarly to many existing PHP implementations, providing a call() method:

    $c = new Zend_XmlRpc_Client('http://framework.zend.com/xmlrpc');
echo $c->call('test.sayHello');

    The call() instance method accepts an optional parameter with an array of parameters to marshal to the remote method. These may be native PHP types or PHP objects representing XML-RPC types. The latter is useful for the XML-RPC datatypes that do not map directly to PHP equivalents, such as base64.

    Server Proxy Objects

    The above usage works fine for many purposes but could read easier and gets tedious after many method calls. One of the few advantages of serializing method calls with a protocol like XML-RPC or SOAP is that with a little extra work in the client libraries, the remote service can be exposed in a way that’s very close to a native PHP object. This is where the server proxy comes in.

    In the above example of test.sayHello(), the remote sayHello() method is in the XML-RPC pseudo-namespace test. We can use the new XML-RPC client’s getProxy() method to get a proxy to this remote namespace and then use it similarly to a normal PHP object.

    $c = new Zend_XmlRpc_Client('http://framework.zend.com/xmlrpc');

$test = $c->getProxy('test');
echo $test->sayHello();

    Namespaces may be nested to any depth so the XML-RPC method foo.bar.baz() becomes $foo->bar->baz().

    Faults

    Faults resulting from the remote method call are automatically thrown as PHP exceptions. XML-RPC fault responses are thrown as Zend_XmlRpc_FaultException and transport errors are thrown as Zend_XmlRpc_HttpException. If this is not desirable for some reason, a doRequest() method provides a way to work with request and response objects directly.

    Update: This post was featured on PHPDeveloper.org.

  • Best Practices of PHP Development Oct 30, 2006

    Posted by Mike Naberezny in PHP,Testing

    Slides from my ZendCon 2006 session are now available:

    It is a new, three hour talk that I developed and presented together with Matthew Weier O’Phinney. This is the second opportunity that Matthew and I have had to team up for a session at ZendCon and it was a great time again.

    Update: You might also like to check out the updated presentation that we gave at ZendCon 2008.

  • Introducing Zend Framework Oct 24, 2006

    Posted by Mike Naberezny in PHP

    The April 2006 issue of php|architect magazine featured my article, “Introducing Zend Framework“. It can now be downloaded in PDF format. Thanks to php|architect for making it available for free.

  • DC PHP Conference Slides Oct 20, 2006

    Posted by Mike Naberezny in PHP

    Slides from my DC PHP Conference talks are now available:

    Special thanks to my friends Chuck Hagenbuch, Matthew Weier-O’Phinney, and Paul M. Jones for their feedback and help preparing the talks.

  • Pragmatic Studio Training Oct 14, 2006

    Posted by Mike Naberezny in Ruby

    Earlier this week, I attended the Pragmatic Studio Rails Training in Dallas, TX. The course is taught by Dave Thomas and Mike Clark. Both are talented, motivational trainers and the course material is top notch.

    As I’m more used to sitting on the trainers’ side of the table, it was obvious to me they’d taken a great deal of care to develop the material. Having read the Agile Web Development book, I thought the course did a great job of tying those concepts together and filling in the gaps left by the print.

    Since I’ve already built several Rails applications, I took the training with the intention of solidifying my foundation of Rails and Ruby fundamentals. I feel that I definitely achieved that goal. While the course was suitable for most beginners, there was enough sprinkling of tricks, idioms, opinion, and humor to keep participants of most skill levels engaged.

    The training was highly oriented towards exercises and labs. For the most part, everyone was able to work at their own pace. Novices got the help they needed while more experienced users didn’t get bored. I was also pleased that the course material was current and at least touched on some of the newer features in Rails such as ActiveResource and more advanced topics like deploying with Capistrano.

    Overall, it was a great experience and I’m looking forward to attending more training courses offered by Pragmatic Studio in the future.

  • Custom Rescue Templates for Rails Oct 9, 2006

    Posted by Mike Naberezny in Ruby

    Ruby on Rails provides a nice feature for development that displays neatly formatted error screens when an exception is raised. This screen is very convenient because it can usually show the line number where the error occurred, different views of the backtrace, and other useful troubleshooting data including the environment, session, and request/response objects. Having this information is not only useful but provides a feeling of stability and more graceful error handling compared to something like PHP’s raw errors (enhanceable by xdebug).

    The default Ruby on Rails error screens are very functional but are also quite plain. Some Rails developers, particularly those working on teams, may wish to tailor them to provide consistent styling with their application or to display additional application-specific information for the development environment.

    The Rails error screens are generated by views bundled inside ActionController called rescue templates. David recently committed my first patch to Edge Rails in changeset 5243. Now, creating your own custom rescue templates is very straightforward.

    Begin by copying the default rescue templates to a new directory under app/views in your Rails project. I recommend app/views/rescues. The rescue templates are found in ActionController, which is under vendor/rails for projects on Edge Rails or that have frozen Rails.

    $ mkdir app/views/rescues
$ cp vendor/rails/actionpack/lib/action_controller/templates/rescues/* \
    app/views/rescues

    Next, add the following snippet to your ApplicationController:

    protected
  def rescues_path(template_name)
    "#{template_root}/rescues/#{template_name}.rhtml"
  end

    The templates will now be taken from your app/views/rescues directory and can be modified to taste. To test, browse to any action that will raise an exception.

    As of Rails 1.1.6, the instructions above will only work on Edge Rails but will work in the next stable version. See the ticket for more information to patch 1.1.6 and earlier versions.

    You are encouraged to read the API documentation for ActionController::Rescue to understand how and when the rescue templates are rendered. It is important to note that for security, the rescue templates should never be shown to the public and thus only ever rendered when a request is considered local.

    Update: This tutorial was featured on Riding Rails, the Ruby on Rails weblog.

    Update: These instructions work with the stable release of Rails since 1.2.

    Update: As of changeset 6120, template_root is now view_paths.first

  • Upcoming Talks Sep 11, 2006

    Posted by Mike Naberezny in PHP,Ruby

    The nice folks behind the DC PHP Conference asked me to put out a note to let you know I’ll be speaking there, so here’s a bit about the talks I’ll be giving and other events I’ll be attending in the next couple of months:

    DC PHP Conference (Oct 18-20)

    • PHP Intranet Web Services is a new talk that is geared to fit into the conference’s theme of “integration with the federal government”. PHP is an excellent glue language for integrating web services and legacy applications on intranets and there are a host of libraries available to help. We’ll explore some of these options and talk about the unique aspects of developing PHP-based services behind corporate firewalls.
    • Getting Started with Zend Framework will give developers a jumpstart on developing with the Zend Framework. A brief introduction will include installation, an architectural overview, comparing it with alternatives, and explaining its process and online resources. We’ll then dive right into some of the more useful components through examples with sample code. I’ve been around the Zend Framework longer than most so feel free to bring all of your questions for Q&A and code for possible hacking sprints later.

    Zend/PHP Conference 2006 (Oct 30 – Nov 2)

    • Best Practices of PHP Development will be an extensive three-hour tutorial session. Matthew and I had such a good time speaking at the last Zend conference that we’re doing it together again this year with a new tutorial session. We’ve both been working as professional PHP developers for many years and this is our chance to share some of the PHP development and deployment tricks we’ve learned along the way.

    Other Events

    Since starting my own consulting business, I’ve also been having a great time doing quite a bit of Ruby on Rails development in addition to my usual Python and PHP programming and training. As I dip into Ruby more, I’ll be attending the Pragmatic Studio (Oct 9-11) and also the Rails Edge Conference (Nov 16-18).

    If you’re headed to any of these events, contact me if you’d like to meet up or if you have any requests for the talks.

  • Tcl Syntax Highlighting for TextMate Sep 2, 2006

    Posted by Mike Naberezny in Tcl

    I first discovered TextMate early this year when I began working with Ruby on Rails. Since then, it’s become my editor of choice and I use it for editing all of my Python and Ruby code.

    One of my customer projects has required me to work extensively with their custom Expect scripts so I have spent a good amount of time programming Tcl lately. Unfortunately, TextMate doesn’t ship with Tcl support out of the box.

    Lars Pind created an OpenACS Tcl bundle for use with the OpenACS framework but lost the files during a server move.

    While it’s not linked from the TextMate website, there is a bundle in the Subversion repository and its Tcl syntax highlighting works quite well. Installation is simple:

    $ svn --username anon --password anon export \
http://macromates.com/svn/Bundles/trunk/Bundles/Tcl.tmbundle/

$ mate Tcl.tmbundle

    For Expect users: The Tcl bundle won’t recognize Expect (.exp) files by default. After opening an .exp file, choose Tcl from the Language dropdown in the editor window. Expect files will now open with Tcl syntax highlighting. While Expect keywords like send_user won’t be highlighted, all standard Tcl keywords will be.

  • Zend Framework Tutorial Published May 2, 2006

    Posted by Mike Naberezny in PHP

    The April 2006 issue of php|architect is now available. This issue marks my first appearance in their pages with the cover article, “Introducing Zend Framework”.

    In the article, I begin by introducing Zend’s motivations for creating a framework and how it relates to their PHP Collaboration Project. More information on these topics can be found on the Zend Framework website. I then dive into a tutorial where I take a business scenario and show how the components included in the Zend Framework can be put to work.

    The article demonstrates a workflow where invoice data is retrieved from a web service, an invoice in PDF format is then built from that data, and finally the resultant file is emailed to a customer. The components Zend_XmlRpc_Client, Zend_Pdf, Zend_Mail, and Zend_Search_Lucene are explored along the way.

    I’d like to thank the team at php|architect for such a professional and enjoyable experience getting the article to print.

    Update: The article is now available for free download in PDF format here.