Improving Satan and Solaris SMF

One of the features of Solaris that we heavily rely on in our production environment at work is Service Management Facility or SMF for short. SMF can start/stop/restart services, track dependencies between services and use that to optimize the boot process and lots more. Often handy in production environment is that SMF keeps track of processes that a particular service started and if a process dies, SMF restarts its services.

One gripe I have with SMF is that its process monitoring capabilities are rather simple. A process associated with a contract (service) must die in order for SMF to get the idea that something is wrong and that the service should be restarted. In practice, more often than not a process gets into a weird state that prevents it from working properly, yet it doesn't die. Failures might include excessive cpu or memory usage or even application level failures that can be detected only by interacting with the application (e.g. http health check). SMF in its current implementation is incapable of detecting these failures. And this is where Satan comes into the play.

Satan a small ruby script that monitors a process and following the Crash-only Software philosophy, kills it when a problem is detected. It then relies on SMF to detect the process death(s) and restart the given service. I fell in love with the simplicity of Satan (which was inspired by God) and started exploring the feasibility of using it to improve the reliability of SMF on our production servers.

Upon a code review of the script, I noticed several things that I wished were implemented differently. Here are some:

• Satan watches processes rather than services as defined via SMF
• One Satan instance is designed to watch many different processes for different services, which adds unnecessary complexity and lacks isolation
• Satan is merciless (what a surprise! :-) ) and uses kill -9 without a warning
• Satan has no test suite!!! :-( (i.e. I must presume that it doesn't work)

Thankfully the source code was out there on GitHub and licensed under BSD license so it was just a matter of a few keystrokes to fork it (open source FTW!). By the time I was done with my changes, there wasn't much of the original source code left, but oh well :-)

I'm happy to present to you http://github.com/IgorMinar/satan for review and comments. The main changes I made are the following:

• One Satan instance watches single SMF service and its one or more processes
• The single service to monitor design allows for automatic monitoring suspension via SMF dependencies while the monitored service is being started, restarted or disabled
• Several bugfixes around how rule failures and recoveries are counted before a service is deemed unhealthy
• At first Satan tries to invoke svcadm restart and only if that doesn't occur within a specified grace period, it uses kill -9 to kill all processes for the given contract (service)
• Satan now has decent RSpec test suite (more on that in my previous post)
• Improved HTTP condition with a timeout setting
• New JVM free heap space condition to monitor those pesky JVM memory leaks
• Extensible design now allows for new monitoring conditions (rules) to be defined outside of the main Satan source code

As always there are more things to improve and extend but, I'm hoping that my Satan fork will be a decent version that will allow us to keep our services running more reliably. If you have suggestions, or comments feel free to leave feedback.

Testing matters, even with shell scripts

A few months ago, we migrated out production environment at work from Solaris 10 to OpenSolaris. We loved the change because it allowed us to take advantage of the latest inventions in Solaris land. All was good and dandy until one day one of our servers ran out of disk space and died. WTH? We have monitoring scripts that alert us long before we get even close to running out of space, yet no alert was issued this time. While investigating the cause of this incident, we found out that our monitoring scripts that work well on Solaris 10, didn't monitor the disk space correctly on OpenSolaris. When I asked our sysadmins if they didn't have any tests for their scripts that could validate their functionality, they laughed at me.

Fast forward a few months. A few days ago I started looking at Satan, to augment the self healing capabilities of Solaris SMF (think initd or launchd on stereoids). At first sight I loved the simplicity of the solution, but one thing that startled me during the code review was that there were no tests for the code, except for some helper scripts that made manual testing a bit less painful. At the same time, I spotted several bugs that would have resulted in an unwanted behavior.

Satan relies on invoking solaris commands from ruby and parsing the output and acting upon it. Thanks to its no BS nature, ruby makes for an excellent choice when it comes to writing programs that interact with the OS by executing commands. There are several ways to do this, but the most popular looks like this:

ps_output = `ps -o pid,pcpu,rss,args -p #{pid}`

All you need to do is to stick the command into backticks and optionally use #{variable} for variable expansion. To get a hold of the output, just assign the return value to a variable.

Now if you stick a piece of code like this in the middle of the ruby script you get something next to untestable:

module PsParser
 def ps(pid)
   out_raw = `ps -o pid,pcpu,rss,args -p #{pid}`
   out = out_raw.split(/\n/)[1].split(/ /).delete_if {|arg| arg == "" or arg.nil? }
   { :pid=>out[0].to_i,
     :cpu=>out[1].to_i,
     :rss=>out[2].to_i*1024,
     :command=>out[3..out.size].join(' ') }
 end
end

With the code structured (or unstructured) like this, you'll never be able to test if the code can parse the output correctly. However if you extract the command execution into a separate method call:

module PsParser
 def ps(pid)
   out = ps_for_pid(pid).split(/\n/)[1].split(/ /).delete_if {|arg| arg == "" or arg.nil? }
   { :pid=>out[0].to_i,
     :cpu=>out[1].to_i,
     :rss=>out[2].to_i*1024,
     :command=>out[3..out.size].join(' ') }
 end

 private
 def ps_for_pid(pid)
   `ps -o pid,pcpu,rss,args -p #{pid}`
 end
end

You can now open the module and redefine the ps_for_pid in your tests like this:

require 'ps_parser'

PS_OUT = {
 1 => "  PID %CPU    RSS ARGS
12790   2.7 707020 java",
 2 => "  PID %CPU    RSS ARGS
12791  92.7 107020 httpd"
}

module PsParser
 def ps_for_pid(pid)
   PS_OUT[pid]
 end
end

And now you can simply call the pid method and check if the fake output stored in PS_OUT is being parsed correctly. The concept is the same as when mocking webservices or other complex classes, but applied to running system command and programs.

To conclude, what makes you more confident about a software you want to rely on. An empty test folder: Or all green results from a test/spec suite?

Configuring Common Access Log Format in GlassFish v2 and v3

For a long time Matthew and I had a dilemma about changing the non-standard access log format used by GlassFish v2 and v3, to the commonly used common or combined format used by Apache.

GlassFish does allow one to specify the access log format, but how this works is not obvious. If one tries to create a formatting string, which should result in one of the Apache access log formats, the resulting output does contain all the specified fields and in the right order, but the field delimiters are not preserved from the formatting string and instead all the fields are quoted and separated by spaces. That's not quite what we want, especially if you plan to feed the logs into a log analyzer that expect the usual Apache syntax.

While getting Confluence wiki to run on GlassFish v3, I fetched the GF source code and since I already had it, I thought that it should be trivial to find out how the Access log format gets processed in GF.

To my big surprise, I found out that there are classes with very suspicious names: CommonAccessLogFormatterImpl, CombinedAccessLogFormatterImpl and DefaultAccessLogFormatterImpl. A minute later I also found this piece of code "hidden" in PEAccessLogValve:

    // Predefined patterns
   private static final String COMMON_PATTERN = "common";
   private static final String COMBINED_PATTERN = "combined";


   ...
   ...


   /**
    * Set the format pattern, first translating any recognized alias.
    *
    * @param p The new pattern
    */
   public void setPattern(String p) {
       if (COMMON_PATTERN.equalsIgnoreCase(p)) {
           formatter = new CommonAccessLogFormatterImpl();
       } else if (COMBINED_PATTERN.equalsIgnoreCase(p)) {
           formatter = new CombinedAccessLogFormatterImpl();
       } else {
           formatter = new DefaultAccessLogFormatterImpl(p, getContainer());
       }
   }

Whoa! So both Apache formats are implemented already and one just needs to know how to "unlock" them. The "common" and "combined" constants looked like the magic keywords to do just that, and sure enough, when one sets either of them as the formatting string, the log will contain the expected output.



You can also use asadmin to make this config change:

asadmin set server.http-service.access-log.format="combined"

After a restart the log now uses the requested format:

0:0:0:0:0:0:0:1%0 - - [21/Dec/2009:07:42:45 -0800] "GET /s/1722/3/_/images/icons/star_grey.gif HTTP/1.1" 304 0
0:0:0:0:0:0:0:1%0 - - [21/Dec/2009:07:42:45 -0800] "GET /images/icons/add_space_32.gif HTTP/1.1" 304 0
0:0:0:0:0:0:0:1%0 - - [21/Dec/2009:07:42:45 -0800] "GET /images/icons/feed_wizard.gif HTTP/1.1" 304 0
0:0:0:0:0:0:0:1%0 - - [21/Dec/2009:07:42:45 -0800] "GET /images/icons/people_directory_32.gif HTTP/1.1" 304 0
0:0:0:0:0:0:0:1%0 - - [21/Dec/2009:07:42:45 -0800] "GET /s/1722/3/_/images/icons/add_12.gif HTTP/1.1" 304 0

Believe it or not, this information is not documented anywhere in the official documentation, and even folks Matthew chatted with on Sun's internal support mailing lists had no clue about it. Ideally the GF documentation and UI should be updated to make changing the access log format as simple as it should be.

Oh btw, open source FTW, when documentation is lacking one can at least read the sources!

Running Confluence on GlassFish v3

Even though Atlassian considers GlassFish to be an unsupported servlet container for Confluence, it is quite easy to use Confluence with GlassFish v2.1. In fact that's the container that I've been using for a long time during my Confluence and Confluence plugin development.

I've been monitoring progress of GlassFish v3 development for several months and noticed that at some point Confluence 2.x and 3.0.x stopped working due to conflicts between different versions of Apache Felix used by both GFv3 and Confluence.

Fortunately Confluence 3.1 now contains Felix v2.x (an upgrade from 1.x), which solves the previously mentioned issues. Excited about the change, I tried to deploy Confluence 3.1 to GFv3 (final) and observed that there are a few more issues that one needs to deal with. I filed these two bugs and one RFE against Confluence and provided patches that anyone can use to get Confluence to run with GFv3:

• SER-144 - Illegal cyclic dependency between LoginFilter and SecurityFilter
• CONF-18093 - DefaultUserProfileService tries to modify an unmodifiable collection (PATCH)
• CONF-18094 - Bundle sun-web.xml with classloader settings required for GlassFish (PATCH)

Once the patches are applied to the Confluence source code, build a war file in the usual way, deploy it to GFv3 and you should be good to go. (There is a harmless exception thrown when Confluence starts, more info, just ignore it)

Oh, and be sure to vote for CONF-6603 to get Atlassian to officially support GlassFish.

Using Mercurial Bisect to Find Bugs

Yesterday I tried to find a regression bug in Grizzly that was preventing grizzly-sendfile from using blocking IO. I knew that the bug was not present in grizzly 1.9.15, but somewhere between that release and the current head someone introduced a changeset that broke things for me. Here is how I found out who that person was.

Grizzly is unfortunately still stuck with subversion, so the only thing (besides complaining) that I can do to make my life easier, is to convert the grizzly svn repo to some sane SCM, such as mercurial. I used hgsvn to convert the svn repo.

Once I had a mercurial repo, I wrote BlockingIoAsyncTest - a JUnit test for the bug. And that was all I needed to run bisect:

$ echo '#!/bin/bash                                                                          
mvn clean test -Dtest=com.sun.grizzly.http.BlockingIoAsyncTest' > test.sh
$ chmod +x test.sh
$ hg bisect --reset #clean repo from any previous bisect run
$ hg bisect --good 375 #specify the last good revision
$ hg bisect --bad tip #specify a known bad revision
Testing changeset 604:82e43b848ae7 (458 changesets remaining, ~8 tests)
517 files updated, 0 files merged, 158 files removed, 0 files unresolved
$ hg bisect --command ./test.sh #run the automated bisect
...
(output from the test)
...
...
...

[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESSFUL
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 9 seconds
[INFO] Finished at: Sat Nov 14 11:41:07 PST 2009
[INFO] Final Memory: 25M/79M
[INFO] ------------------------------------------------------------------------
Changeset 500:983a3fc2debe: good
The first good revision is:
changeset:   501:b5239bf9427b
branch:      code
tag:         svn.3343
user:        jfarcand
date:        Wed Jun 17 17:20:32 2009 -0700
summary:     [svn r3343] Fix for https://grizzly.dev.java.net/issues/show_bug.cgi?id=672

In under two minutes I found out who and with which revision caused all the trouble! Bisect is very useful for large projects, developed by multiple users, where the amount of code and changes is not trivial. Finding regressions in this way can save a lot of time otherwise spent by debugging.

The only caveat I noticed is that you need to create a shell script that is passed in as an argument to the bisect command. It would be a lot easier if I could just specify the maven command directly without the intermediate shell script.

grizzly-sendfile to Become an Official Grizzly Module

After a chat with JFA about grizzly-sendfile's future, I'm pleased to announce today that grizzly-sendfile 0.4 will be the first version of grizzly-sendfile released as an official module of grizzly. This is a huge news for grizzly-sendfile and I believe an equally important news for grizzly and its community.

What this "merger" means for grizzly-sendfile:

• great opportunity to extend the reach
• opportunity to become the default static file handler in Grizzly
• aspiration to become the default static file handler in GlassFish v3
• more testing and QA
• easier and faster access to grizzly developers and contributors

What this "merger" means for grizzly:

• contribution of 1 year of research, development and testing time in the area of static http downloads
• several times better performance and scalability of http static file downloads
• built-in X-Sendfile functionality
• better JMX instrumentation for http downloads
• and more

If you can't wait for 0.4, go and get recently released version 0.3.

This is a great day for both projects! :-)

Project site: http://grizzly-sendfile.kenai.com/

grizzly-sendfile 0.3 is out!

After a few months of late night hacking, grizzly-sendfile 0.3 is finally ready for prime time!

New features include:

• grizzly 1.9.15 compatibility
• glassfish v3b48 compatibility (via an OSGi bundle)
• kick-ass performance and scalability
• grizzly-sendfile-server
• autosendfile mode
• Sendfile Algorithms: new EqualBlockingAlgorithm + improved EqualNonBlockingAlgorithm
• lots of improvements to grizzly-sendfile-benchmark
• maven build system
• lots of smaller improvements and bug fixes

I also started using kenai's JIRA for issue tracking. So feel free to file bugs or RFE's there.

Benchmark & Enjoy!

Project Website The source code The binaries