Main | February 2008 »

6 posts from January 2008

01/27/2008

Second Place!

Well, things can only go downhill from here but today typing in the search phrase "allsorts and notions" into the Google Search bar in my browser, I get a second place listing--ahead of the sewing sites!! Take that all you quilters, tailors, and cobblers! IT'S ON!!

Someone might be wondering why I chose the name "allsorts and notions" for the site. It's because it was the name of a store that sold trinkets, baubles, and other useful doodads in a novel I remember reading when I was a lot younger. The problem is, I can't remember what the name of the novel was and would like to provide credit to the writer. I think it was a Peter Straub novel but I read it about 20 years ago. The name of the store stuck with me all these years.

Logging in Apache for IIS Admins

One of the nice things about IIS is that you don't need to worry about log file rotation. "Out of the box", this is handled for you. New log files are rotated on a nightly basis.

By default, apache logging is a bit different. One file "access_log" is created that contains all of the requests made to the site. "error_log" contains all the server errors. These files can get to be quite large, which makes looking for stuff when you really need to difficult. Setting up log file rotation is fairly straightforward however and if you're loading mod_logio, you can get some interesting additional logging options.

If you open up your httpd.conf, scroll down to the logging section. You'll see something like the following:
# ErrorLog: The location of the error log file.
# If you do not specify an ErrorLog directive within a <VirtualHost>
# container, error messages relating to that virtual host will be
# logged here. If you *do* define an error logfile for a <VirtualHost>
# container, that host's errors will be logged there and not here.
#
ErrorLog logs/error_log
#
# LogLevel: Control the number of messages logged to the error_log.
# Possible values include: debug, info, notice, warn, error, crit,
# alert, emerg.
#
LogLevel warn

<IfModule log_config_module>
#
# The following directives define some format nicknames for use with
# a CustomLog directive (see below).
#
LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" combined
LogFormat "%h %l %u %t \"%r\" %>s %b" common

<IfModule logio_module>
# You need to enable mod_logio.c to use %I and %O
LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\  " %I %O" combinedio
</IfModule>

#
# The location and format of the access logfile (Common Logfile Format).
# If you do not define any access logfiles within a <VirtualHost>
# container, they will be logged here. Contrariwise, if you *do*
# define per-<VirtualHost> access logfiles, transactions will be
# logged therein and *not* in this file.
#
CustomLog logs/access_log common
#
# If you prefer a logfile with access, agent, and referer information
# (Combined Logfile Format) you can use the following directive.
#
#CustomLog logs/access_log combined

</IfModule>

The common log file format doesn't give you the user-agent or the referring web site, which most folks find pretty useful. The user-agent for the most part is the browser type and version that was used to access the site. Referral is the link used on someone else's site to get to your own, which could also be the search engine link that someone clicked to get to your site. The combined log file format will give you the data from the common log format plus the user-agent and the referral. If mod_logio is loaded, the defaults will give you a couple of additional data points in your log, %I and %O. %I logs how many bytes the client sent and %O logs the number of bytes that the server sent in the reply.

The first change you should make is to change that CustomLog directive to utilize combinedio from common.

Then, in the LogFormat directive line belonging to the combinedio log file type, make the following changes/additions:

Change the %h to %a. %h logs the hostname if someone mistakenly sets the HostnameLookups directive to "On", which can be a real performance killer. %a logs the IP Address of the client always regardless of whether Hostname Lookups are being performed. Adding %S after the %a will give you the client's source port, which could be useful in debugging as well as distinguishing multiple users coming in over the same IP. Add an %s in front of the %>s. %s provides the HTTP Status code before any redirect is processed. Adding a %T after the %b will give you the time in seconds it took to fulfill the request. If you want to display microseconds instead, change (or add) it to %D instead. Below is the new, improved combinedio log file type:
LogFormat "%a %l %u %t \"%r\" %s %>s %b %T \"%{Referer}i\" \"%{User-Agent}i\" %I %O" combinedio

This final section will deal (finally!) with log file rotation. Move up to the ErrorLog directive.
Change:
ErrorLog logs/error_log     
to:
ErrorLog "|bin/rotatelogs logs/error.log.%Y-%m-%d-%H_%M_%S 86400"     
Move down to the CustomLog directive and change:
CustomLog logs/access_log combinedio     
to:
CustomLog "|bin/rotatelogs logs/access.log.%Y-%m-%d-%H_%M_%S 86400" combinedio 
rotatelogs is a built-in program that does what it looks like it does and the format of the ErrorLog and CustomLog directives will place a time- and datestamp at the end of the log file name and creates a new log file over at midnight (GMT). Restart apache and you will have rotating logs similar to IIS's built-in functionality but you will also enjoy a few additional items that IIS's w3c-extended does not provide. A future post will deal with things you can do to prune what gets logged in order to keep those log file sizes down so that you can actually look through them and find stuff.

mod_jk times out on initial connections

If you come across a message similar to the following in your mod_jk logs and you know your apache server is up and your upstream tomcat server is up, I think I have the reason.

[Date/Time] [4994:52144] [error]
ajp_connection_tcp_get_message::jk_ajp_common.c (961): Can't receive the
response message from tomcat, network problems or tomcat is down
(10.X.X.X:8009), err=-110

[Date/Time] [4994:52144] [error]
ajp_get_reply::jk_ajp_common.c (1531): Tomcat is down or refused
connection. No response has been sent to the client (yet)

Conditions

An apache web server is in your DMZ. A firewall separates your web server from your tomcat (or jboss) application server. Web server connects to tomcat via mod_jk. After a period of site inactivity, you timeout on the initial load of the web application's default page. If you refresh the page, the browser loads the page normally.

Probable Cause

This is probably happening because the firewall is severing the ajp13 connection between mod_jk and tomcat. This is not a problem with the firewall, however, but is likely due to configuration defaults in mod_jk's workers.properties and in the tomcat server's server.xml.

A default workers.properties entry looks something like this:

worker.ajp13.port=8009
worker.ajp13.host=localhost
worker.ajp13.type=ajp13

The default values for the ajp13 connector in tomcat's server.xml are the following:

<!-- Define an AJP 1.3 Connector on port 8009 -->
<Connector port="8009" protocol="AJP/1.3" redirectPort="8443" />

There are several things that should be added to both files in order to deal with firewalls that terminate idle sessions. By default, mod_jk keeps all ajp13 connections open indefinitely but it does not send keepalives across the tcp session to the tomcat server. If that connection is idle, it will remain open. Firewalls however do not like idle sessions and after a period of inactivity, will sever that connection. This is why the initial connection to the application might hang. ajp13 will hand the connection off to a tcp connection that is currently open but the firewall has killed that connection, resulting in the error messages above and the time out at the browser.

In workers.properties, add the following bolded parameters for each worker:

worker.ajp13.port=8009
worker.ajp13.host=localhost
worker.ajp13.type=ajp13
worker.ajp13.socket_keepalive=True
worker.ajp13.connection_pool_timeout=600

"socket_keepalive" will send keepalives across the ajp13 session to tomcat. "connection_pool_timeout" will close the ajp13 session after 10 minutes of inactivity.

In server.xml on the tomcat ajp13 connector section, add the following in bold

<!-- Define an AJP 1.3 Connector on port 8009 -->
<Connector port="8009" protocol="AJP/1.3" redirectPort="8443"
connectionTimeout="600000" />

"connectionTimeout" will close any open, idle connections after a period of 10 minutes as well.