Webservers, Webmail & Diagnosing AFS Problems
Tracy J. Di Marco White
Iowa State University
26,000 active student accounts
10,000 active staff and faculty accounts
1 GB default quota
quota rental at 0.56¢ / 100MB / day ($1.70/GB/month),
$1 minimum bill
- individual class sections can request a 50MB volume at no cost
- departmental units can request a 50MB volume at no cost
- student organizations share a 30GB volume, at no cost
- virtual web hosting available at $5/month/250MB for student
organizations, or $25/month/1GB for non-student organizations
- additional volumes available by buying quota for them
Iowa State University Web presence
www.iastate.edu
- round robin pool
- 3 Digital Unix Alphas, Transarc AFS & OpenAFS
- 1 NetBSD PC, Arla
- all content served out of AFS
- Iowa State University Relations
- departmental and class web pages
- 8 million hits per week, average, Spring 2006 semester
Iowa State University Web presence
www.public.iastate.edu
- round robin pool
- 2 Digital Unix Alphas, OpenAFS
- 2 NetBSD PCs, Arla
- all content served out of AFS
- includes cgi support
- virtual hosts
- username.public.iastate.edu
- volumename.public.iastate.edu
- all active accounts can have a web page here
- rented or class volume web pages also available here
- 3.5 million hits per week, average, Spring 2006 semester
Iowa State University Web presence
webmail.iastate.edu
- load balanced pool
- mail popped into AFS, served from AFS
- 22 RHEL PCs, OpenAFS
- 24,723 unique logins per week, average, Spring 2006 semester
- 3,373,270 hits in a representative week into afs
- switched to Pubcookie controlled access
- 3,994,212 hits in a representative week into afs after switch
Iowa State University Web presence
webdev.its.iastate.edu
- departmental virtual web hosting
- php scripting
- mysql database service
- 3,686,765 hits per week, average, Spring 2006 semester
Iowa State University AFS Servers
Fileservers
- 4 Digital Unix servers, running Transarc AFS
random end user disks, unraided, annual fees for disk attachment &
backup
- 5 Solaris servers, running OpenAFS 1.2.11
1 with 125GB, 4 with 600GB afs partition space
- 5 NetBSD servers, running OpenAFS latest stable
2 with 1.4TB, 3 with 1.8TB afs partition space
DB servers
- 3 Digital Unix servers, running OpenAFS 1.2.13
The Problem
We have a lot of highly visible stuff in AFS
- For some reason, people notice when the orientation site is not
responding
...or, well, www.iastate.edu.
- and not being able to get to mail? out of the question.
Monitoring
- We use hobbit for monitoring
- When the http connections on the various web servers start going red
en masse... it's usually an afs server problem
- So I added "rxdebug $HOST 7000 -noconn -rxstats" to my afs monitoring
script, and started alerting on too many calls waiting for a thread.
- It was also simple to have all the numbers rxstats generates fed into
an rrd, so pretty graphs are available, although calls waiting for a thread
is the only one monitored
Log files
- FileLog & FileLog.prev most useful, SalvageLog also useful
- SIGTSTP can be used on fileserver to raise the debugging level
kill -TSTP PID
- once sets debugging level to 1
- twice sets debugging level to 5
- three times sets debugging level to 25
- four times sets debugging level to 125
- five times sets debugging level to 525
kill -HUP PID
- resets the debugging level to 0
Sometimes you can find incidental bugs this way, like an unsigned int
that should really be afs_uint32 (thanks to developer help)
Core files & Dumping other information
Creating a core dump
- even when your server hasn't crashed and created a core file, it
can be very useful to make it create a core dump with gcore. The
process stays running, and can be shut down nicely if necessary, and
hey, you get a core file to do debugging with
- fileserver core files contain your KeyFile, so handle with care
- we used gdb on a fileserver core file to find an overflow of the
host table causing an overwrite of the variable that contains the
path to KeyFile, among other things (again thanks to developer help)
SIGXCPU will create client.dump, hosts.dump & callback.dump
- lists all hosts/clients and attributes about them
Gathering data for use in debugging
tcpdump
- 'tcpdump -v -s 1500 port 7001 and host (client IP)'
- ports vary, depending on what you're looking for
- 7000 is the fileserver port
- 7001 is the callbacks to cache manager port
- 7002 is the protection (pt) database
- 7003 is the volume location (vl) database
- 7004 is the kerberos authentication (ka) service
- 7005 is the volume management (volser) server
Gathering data for use in debugging
- 'xstat_fs_test -fsname server -collID 1 -onceonly' dumps rx information
and other statistics
- 'rxdebug server 7000' provides information on the rpc status of the
server
- 'rxdebug client 7001' provides information on which servers the client
is talking to
- 'pstack PID' is a Solaris command that prints a hex & symbolic stack trace
for each lwp in a process
- 'cmdebug' provides information on the cache manager
rxdebug against a client has helped to determine when a new OpenAFS client
was talking to an old Transarc AFS server, which was causing it to throw away
its tokens.
cmdebug against a client has helped to determine that a particular
volume was causing problems, leading us to notice that a disk had failed,
when the operating system hadn't noticed yet
Gathering data for use in debugging
'rxdebug server 7000' will contain information about connected clients
Connection from host 10.10.201.116, port 7001, Cuid b27eaca6/11a81228
serial 406, natMTU 1260, security index 0, client conn
call 0: # 203, state dally, mode: receiving, flags: receive_done
call 1: # 0, state not initialized
call 2: # 0, state not initialized
call 3: # 0, state not initialized
- the port being 7001 may mean the client is not behind a NAT
- Cuid is the connection id number for the RPC request
- serial is the serial number of the last packet sent
- natMTU of 1260 tells me this is a Windows client
- security index is the type of authentication, 0 being no auth
- usually only call 0 is used, unless the system is under heavy load
Gathering data for use in debugging
% rxdebug 10.10.201.116 7001 -version
Trying 10.10.201.116 (port 7001):
AFS version: OpenAFS1.4.0008
- This verifies that it is a Windows client (version number layout)
% cmdebug -server 10.10.201.116 -addr
UUID: 1f404ac9-ab91-40e2-a7-94-3d416440dd45
Host interfaces:
10.10.201.116, netmask 255.255.255.0, MTU 1260
Capabilities:
Error Translation
- Since the IP address contacted is in the list of reported addresses,
it is not likely this machine is behind a NAT
Gathering data for use in debugging
Connection from host 10.10.154.207, port 25796, Cuid b27eaca6/11a99280
serial 2, natMTU 1260, security index 0, client conn
call 0: # 1, state dally, mode: receiving, flags: receive_done
call 1: # 0, state not initialized
call 2: # 0, state not initialized
call 3: # 0, state not initialized
- the port is 25796, and it not being 7001 or one of the other normal afs
ports indicates the client likely is behind a NAT
- Odd port numbers can also mean more than one client behind a NAT,
Arla or OpenAFS for Windows on a machine where 7001/udp is already in use, or
a connection from a tool, rather than a client
- If a client is behind a NAT, the version can be queried either from
a machine behind the same NAT or the server listing the client
- clients behind a NAT often cannot be queried from the server, as
timeouts are short
Further information about rxdebug
"state" describes the state of the connection.
- active - the call is currently active
- dally - the connection is idle/waiting
- precall - initialized but before call
"mode" describes the mode of the connection.
- eof - completed
- error - an error has been received
- receiving - actively receiving data
- sending - actively sending data
- unknown - none of the above
further information about rxdebug
"flags" describe the flags of the connection
- reader_wait - the reader is waiting for the next packet from
the sender
- receive_done - the process has finished receiving packets
- wait_packets - corresponds to ``waiting_for_packets''
described above
- waiting_for_process - the RPC is waiting to be serviced
- window_alloc - the RPC is waiting for the first window on a
connection
- window_send - an entire window full of packets has been
sent, but none have been acknowledged. The
sender stops and waits for an acknowledgment.
This is rudimentary flow control.
information about cmdebug
- cmdebug is very useful for debugging cache manager problems
- by default, cmdebug returns nothing or displays locks helds if everything
is running normally
- cmdebug may show cache entries if there are problems, or -long will also
display cache entries
Links to more information
Thanks
I would not have learned nearly as much, nor had most of these problems
solved, without the help of, and instructions from:
- Russ Allbery
- Jeffrey Altman
- Derrick Brashear
- Chaskiel Grundman
- Jeffrey Hutzelman
And of course, everyone who works on AFS has my thanks for their
continued work.
Questions?