Author Archive

How to capture httplib2 debug in a threaded app

Sunday, August 29th, 2010

A couple months ago I blogged about my frustration with httplib logging. Andrew Dalke left a comment suggesting that I should replace sys.stdout, something I hadn't considered as a possibility. His suggestion sent me googling, which turned up this old email from Guido. Add threading.local and we have a solution!

What we need is a duck-typed replacement for sys.stdout that behaves like a writeable file, but also provides the ability to capture to thread-local storage. One of the ways to use threading.local is to subclass it. An instance of this subclass will have per-thread attributes, even if the instance itself is common to multiple threads.

Since StringIO intentionally doesn't implement isatty(), we need to make sure that gets passed through to the underlying file (we do this by catching the exception in getattr). And since we like seeing HTTP transactions when we're debugging, we include a writethrough mode that provides simultaneous capture and print.

import cStringIO, threading

class LocalCapturingWriter(threading.local):
    def __init__(self, fp, writethrough=False):
        self.__dict__['_fp'] = fp
        self.__dict__['_stringio'] = None
        self.__dict__['_writethrough'] = writethrough

    def start_capture(self):
        self.__dict__['_stringio'] = cStringIO.StringIO()

    def stop_capture(self):
        v = self._stringio.getvalue()
        self._stringio.close()
        self.__dict__['_stringio'] = None
        return v

    def write(self, s):
        if self._stringio:
            result = self._stringio.write(s)
        if not self._stringio or self._writethrough:
            result = self._fp.write(s)
        return result

    def __getattr__(self, name):
        if self._stringio is not None:
            try:
                return getattr(self._stringio, name)
            except:
                pass
        return getattr(self._fp, name)

    def __setattr__(self, name, value):
        if self._stringio:
            setattr(self._stringio, name, value)
        if not self._stringio or self._writethrough:
            setattr(self._fp, name, value)

And here's how to use it. First, the global settings:

import httplib2, sys

httplib2.debuglevel = 1

sys.stdout = LocalCapturingWriter(sys.stdout)

Then the code that runs in a thread to capture the debugging output. This will work as expected even in multiple threads simultaneously.

sys.stdout.start_capture()
try:
    response, content = \
        httplib2.Http().request("http://n01se.net")
finally:
    debug_trace = sys.stdout.stop_capture()

# Note that httplib2 doesn't include the content in its
# debug output.
debug_trace += "content: %r\n" % content

We're now using this in our Django app, with a custom Exception class (to hold the captured trace) and middleware that knows to look for it. The end result is that every time an exception occurs due to a problem talking to a backend server, the exception email includes the httplib2 trace. Yeah!

P.S. I wrote this entry less than a week after my previous entry, but then went on vacation and never managed to get it posted. Sorry for the delay...

Python’s httplib uses print for debugging. Oh, it hurts…

Sunday, July 4th, 2010

At work we have a production site that uses httplib (via httplib2) on the server to communicate with internal servers using a RESTful API. When something doesn't work as expected in this process, we like to know about it, so our app sends email with the exception traceback and whatever relevant data we can pull together.

One of the pieces of data I'd like to add to the email is the conversation between our server and the internal servers. On a development server, this is easy: Set httplib2.debuglevel=1 and watch the HTTP conversations scroll past on stdout.

On a staging or production server, one quickly discovers a crippling mistake made by the httplib authors: the library uses Python's "print" for debugging!

If the application were single-threaded, we could capture the trace by temporarily redirecting sys.stdout to an instance of StringIO (maybe using a context manager). Sure, it's more load on the server to capture the debug on every transaction, but I'll gladly pay that price for the hours we'll save when something goes wrong and we have the ability to debug it.

But it doesn't matter, because we haven't this option. Our app is multi-threaded and sys.stdout is global. We would have to serialize our HTTP transactions to prevent traces from being mixed together. Or fork to isolate sys.stdout. These aren't realistic approaches.

This sort of unfortunate shortcoming is to be expected in add-on libraries. After all, part of the reason they're not included with Python is that they don't necessarily meet the quality requirements of the core distribution. But I'm taken off-guard to find such an obvious shortcoming in the Python standard library. One of the things I'd hope to assume by using the standard library is a trust in the quality of the implementation, but a discovery like this forces me to question that assumption.

I'm pretty new to Python, so maybe I'm missing something. Is httplib a particularly poor example of the Python standard library? The existence of httplib2 seems to imply that (and also seems to imply that it's hard to get problems fixed in the core distribution). Maybe I need to find an add-on networking library that ignores httplib entirely...?

a common css mistake

Friday, May 14th, 2010

I'm playing with febootstrap this evening, part of a continuing migration away from Ubuntu toward Debian and Fedora. I googled my way to Rich's febootstrap page. On my browser, it looks like this:

The problem is that the page's css has the following rules:

h1, h2, h3, h4 {
  color: #333;
}

pre {
  background-color: #fcfcfc;
}

Both these rules assume the usual black-on-white color scheme, but I'm using a gtk theme with a dark background and light foreground, which firefox respects. (Chromium doesn't have the issue because it enforces black-on-white defaults regardless of the gtk theme. I'm not sure how I feel about that; it fixes the problem but at the expense of ignoring my theme.)

This isn't to say anything bad about febootstrap, of course. I'm thrilled that somebody has finally written for Fedora what the excellent debootstrap has been providing for Debian and Ubuntu users for years! But I've come across this mistake enough times that Rich's site drew the unlucky number. ;-)

daemonizing bash

Tuesday, April 20th, 2010

Before we jump into this, let's be clear about intent: There are better languages for writing daemons than bash. Honestly, any other language is probably a better choice. Writing a daemon implies that you're writing a sufficiently complex program that bash is already the wrong language, with or without daemonization!

But if you find yourself in the unfortunate position of needing to daemonize an existing bash program, and you'd rather put off rewriting it in a more suitable language, keep reading! I found myself in that position recently and kept some notes.

Daemonizing a process consists of two primary tasks: forking to the background to return control to the shell, and preventing undesirable interaction between the process and the host. Rich Stevens enumerated the steps in his classic Advanced Programming in the UNIX Environment. Here's my summary of his formula with implementation notes for bash.

  1. Call fork (to guarantee the child is not a process group leader, necessary for setsid) and have the parent exit (to allow control to return to the shell).

    Forking in bash is a simple matter of putting a command in the background using "&". To put a sequence of commands in the background, use a subshell: "( commands ) &". Note that bash doesn't provide any method for the child process to continue the same execution path as the parent, so the entirety of the child must be contained in the subshell. The easiest way to do this is implement the child as a bash function: "childfunc &".

  2. Call setsid to create a new session so the child has no controlling terminal. This simultaneously prevents the child from gaining access to the controlling terminal (using /dev/tty) and protects the child from signals originating from the controlling terminal (HUP and INT, for example).

    Bash provides no method to call the setsid syscall for the current process. We have two less-than-ideal alternatives:

    1. The util-linux-ng package provides an external setsid command but this daemonizes an external command rather than the currently running script. It also makes collecting the PID of the child tricky because the setsid command will fork internally.

      Having said all that, if your application allows you to use the setsid command, it's a good choice because bash can't otherwise fully protect against the child process opening /dev/tty. It's still a good idea to redirect std* to prevent stray output to the terminal.

    2. Lacking the setsid syscall, there are steps we can take to partially protect the child process from the effects of the controlling terminal:
      1. Redirect std* to files or /dev/null
      2. Guard against HUP and INT by signal handler in child
      3. Guard against HUP by disown -h in parent

      Unfortunately without setsid there is no way to guard completely against a subchild opening /dev/tty until the terminal emulator exits, then /dev/tty will become unavailable.

  3. Change working directory to / to prevent the daemon from holding a mounted filesystem open.

    Bash is good at this. :-)

  4. Set umask to 0 to clear file mode creation mask.

    I have to admit that I can't understand the point of this, in bash or any other language. It seems to me that the child will either set its umask explicitly before creating files, or it will set individual file permissions explicitly, or it will fall back on the caller's umask. In the last case, I want my inherited umask, not the wide-open zero.

    If anybody wants to explain a good reason for step 4, I'm all ears... Until then, it's commented out in my implementation below.

  5. Close unneeded file descriptors.

    This step is fun in bash using eval and brace expansion...

With those notes in-hand, here's my implementation. There are two
functions here, "daemonize" for an external command using setsid,
"daemonize-job" for a function in the running script.

# redirect tty fds to /dev/null
redirect-std() {
    [[ -t 0 ]] && exec </dev/null
    [[ -t 1 ]] && exec >/dev/null
    [[ -t 2 ]] && exec 2>/dev/null
}

# close all non-std* fds
close-fds() {
    eval exec {3..255}\>\&-
}

# full daemonization of external command with setsid
daemonize() {
    (                   # 1. fork
        redirect-std    # 2.1. redirect stdin/stdout/stderr before setsid
        cd /            # 3. ensure cwd isn't a mounted fs
        # umask 0       # 4. umask (leave this to caller)
        close-fds       # 5. close unneeded fds
        exec setsid "$@"
    ) &
}

# daemonize without setsid, keeps the child in the jobs table
daemonize-job() {
    (                   # 1. fork
        redirect-std    # 2.2.1. redirect stdin/stdout/stderr
        trap '' 1 2     # 2.2.2. guard against HUP and INT (in child)
        cd /            # 3. ensure cwd isn't a mounted fs
        # umask 0       # 4. umask (leave this to caller)
        close-fds       # 5. close unneeded fds
        if [[ $(type -t "$1") != file ]]; then
            "$@"
        else
            exec "$@"
        fi
    ) &
    disown -h $!       # 2.2.3. guard against HUP (in parent)
}

clock trick

Wednesday, March 10th, 2010

I bought a Sony "Dream Machine" Clock Radio about a year ago and have liked it except for one problem: even when the brightness is set to "low", it's still too bright for my taste. Each night I have to rotate the clock away from me on the nightstand so I can fall asleep.

This morning I applied Insta-Cling Windshield Strip Professional Tint Film to the front and I think it's not bad for $4.88 and a few minutes with an x-acto knife!

Here's the before/after ("before" courtesy of Amazon since I didn't think of taking a photo):

http://agriffis.n01se.net/blog-images/clock-before-after.jpg

weechat, nopaste and tagver

Monday, February 22nd, 2010

This weekend I switched from irssi to weechat. The main reason I switched away from irssi was to gain support for protocols other than IRC. On the way to weechat, I tried Pidgin but I was immediately frustrated by two things.

First, I really love running my IM client in screen. I move regularly between three machines and I want persistent connectivity despite changing work context. Screen has provided that beautifully over the years and I don't know of any truly comparable technology for graphical programs.

Second, Pidgin seems to be barely customizable. For example, how would you like your timestamps? You have three choices:

  • (HH:MM:SS)
  • occasional iChat-style interruptions
  • no timestamps

The Pidgin FAQ calls out plugins to customize timestamps but they're woefully underpowered. What I want is to supply a strftime-style format string: %H:%M. It seems preposterous to me that Pidgin wouldn't provide this capability, so maybe I'm just missing it?

In any case, irssi and weechat both make this and other customizations easy. It took about one minute to find and change the setting in weechat:

/set weechat.look.buffer_time_format "%H:%M"

Once I got weechat running, I found to my chagrin that I'd imagined weechat's support for other protocols. The front page mentions Jabber but it's still a work in progress; there's no stable support for anything other than IRC.

I was saved by bitlbee, a standalone server that gateways IM protocols (XMPP/Jabber, MSN Messenger, Yahoo! Messenger, AIM and ICQ) to IRC. Installing and configuring bitlbee took all of five minutes since it's in Ubuntu and there's a super-easy quickstart guide.

Of course this means that I could have stayed on irssi! But weechat seems to be a worthy replacement. It has a built in nicklist which has always been missing from irssi. It handles filtering better than irssi; whereas irssi's /ignore discards information, weechat's /filter simply hides it and you can toggle filtered text with alt+=. That means I can filter more aggressively because I don't have to worry about irretrievably missing something important.

We are, after all, searching for signal. (And good luck finding it in this post.)

One thing I liked from my brief experience with pidgin was libnotify alerts. You know, that little box that pops up so you don't need to keep your IM client on the screen at all times:

http://agriffis.n01se.net/blog-images/libnotify-chuck.png

There's a weechat notify script that provides this functionality but it had some bugs. No problem, fixed them, then tried to submit my update to the site. The upload form suggests using pastebin, so I broke out my own nopaste tool and...

It failed. Where I expected to get a link, I got nothing! It seems Pastebin.com recently switched to a custom httpd:

$ curl -I http://pastebin.com/
HTTP/1.1 200 OK
Content-Type: text/html; charset=iso-8859-1
Date: Mon, 22 Feb 2010 20:37:36 GMT
Server: TorrentFly.org Custom Httpd

Curl sees "HTTP/1.1" and tries to be polite by using the 100-continue Expect request-header field. Unfortunately the TorrentFly.org Custom Httpd doesn't grok the request and halts the transaction with 417 (Expectation Failed).

Fine, it's an easy fix to force HTTP/1.0 and work around the broken server:

--- a/nopaste
+++ b/nopaste
@@ -52,7 +52,7 @@ main() {

 docurl() {
     declare u
-    u=$(curl --silent --show-error -o /dev/null -w "%{redirect_url}\n" \
+    u=$(curl -0 --silent --show-error -o /dev/null -w "%{redirect_url}\n" \
         --form-string "poster=$opt_nick" --form-string "format=$opt_language" \
         --form-string "expiry=$expire" \
         ${opt_parent:+--form-string "parent_pid=$opt_parent"} \

This reminded me that nopaste should be in externally-available source control so I created a github project for it. This is the first time I've used github to publish a project of my own and I can only say: Wow, that was easy.

I thought it would also be nice to publish proper releases of nopaste. In the past I've simply provided the individual file with a version number appended. Since I'm using git, I should be able to do something nifty with tags, right?

Enter tagver, a script to generate a "meaningful" version number based on tags, revisions and dirt. I've re-invented this wheel a few times, for example adding mercurial support to setlocalversion, but this is the first time I've made it a project in its own right.

Using tagver I released tarballs and an rpm for nopaste version 2.3 containing this trivial fix. You can find them both at http://agriffis.n01se.net/nopaste. I'm not really satisfied with the Makefile that calls tagver, but it'll do for now, at least until I look into integrating tagver into an autotools-driven distribution. Or cmake or scons or cons or whatever...

Live migration to RAID-1

Sunday, November 8th, 2009

I've blogged about using md with lvm before. This weekend I came to appreciate it even more when I migrated a live system from single disk to RAID-1 without needing to unmount or reboot. Here's the overview of the steps I used:

  1. Create a RAID-1 on the second disk (sdb). It's initially degraded, meaning that even though we're accessing it as md0, there's only one disk in the array.
  2. Migrate data from the first disk (sda) to the newly-created md0.
  3. Now that sda is freed up, add it to the array to make it a mirror.

Reviewing my system inventory, I have two 500G disks but I'm only using one of them, hosting logical volumes for root, swap, four nfsroots, and two (running) KVM virtual machines. Apart from the large partition holding the logical volumes, I also have a couple small partitions for Windows 7 (I don't actually use it but it's there in case I need to call for warranty support). The other disk is blank and idle. I installed it some time back when I had the machine powered off, though I could have attached it with eSATA to avoid even that interruption.

Here's the partition table from that first disk:

$ sudo parted /dev/sda
(parted) unit kB
(parted) print
Model: ATA WDC WD5000AAKS-6 (scsi)
Disk /dev/sda: 500107862kB
Sector size (logical/physical): 512B/512B
Partition Table: msdos

Number  Start       End          Size         Type      File system  Flags
 1      1049kB      6443500kB    6442451kB    primary   ntfs         boot
 2      6443500kB   46443500kB   40000000kB   primary   ntfs
 3      46448156kB  47443415kB   995259kB     primary   ext3
 4      47443415kB  500105249kB  452661834kB  extended
 5      47443447kB  500105249kB  452661802kB  logical                lvm

and here's the volume groups and logical volumes, annotated a bit:

$ sudo vgs
  VG   #PV #LV #SN Attr   VSize   VFree
  vg0    1  10   0 wz--n- 421.57G 250.40G

$ sudo lvs
LV         VG   Attr   LSize
jabberwock vg0  -wi-ao  9.31G  # host root filesystem
swap       vg0  -wi-ao  1.86G  # host swap
jubjub     vg0  -wi-ao 20.00G  # jubjub VM disk
agriffis   vg0  -wi-ao 50.00G  # my $HOME, jubjub VM second disk
oliva      vg0  -wi-a- 20.00G  # oliva VM disk
amg        vg0  -wi-a- 50.00G  # Amy's $HOME, oliva VM second disk
nord       vg0  -wi-ao  5.00G  # thin client nfsroot
sud        vg0  -wi-ao  5.00G  # thin client nfsroot
parmigiano vg0  -wi-ao  5.00G  # thin client nfsroot
romano     vg0  -wi-ao  5.00G  # thin client nfsroot

For the partition listing, I used units of kB because that makes it easier to be sure the partitions are exactly the same size when I apply them to the second disk. I'll initially create the RAID-1 with only sdb5 (a degraded array), then later I'll add sda5 to md0 to make it a mirror. For this reason, it's important that the two partitions that will eventually make up md0 are exactly the same size.

Here's the application of that partition table to the second disk. Note I'm not going to actually use the first few partitions there, but I create them anyway for the sake of symmetry:

$ sudo parted /dev/sdb
(parted) unit kB
(parted) mklabel msdos
(parted) mkpart primary  1049kB     6443500kB
(parted) mkpart primary  6443500kB  46443500kB
(parted) mkpart primary  46448156kB 47443415kB
(parted) mkpart extended 47443415kB 500105249kB
(parted) mkpart logical  47443447kB 500105249kB
(parted) set 5 raid on
(parted) print
Model: ATA ST3500418AS (scsi)
Disk /dev/sdb: 500107862kB
Sector size (logical/physical): 512B/512B
Partition Table: msdos

Number  Start       End          Size         Type      File system  Flags
 1      1049kB      6443500kB    6442451kB    primary
 2      6443500kB   46443500kB   40000000kB   primary
 3      46448156kB  47443415kB   995259kB     primary
 4      47443415kB  500105249kB  452661834kB  extended               lba
 5      47443447kB  500105249kB  452661802kB  logical                raid

Now create the RAID-1 and extend the volume group to it:

$ sudo mdadm --create /dev/md0 --level=1 --raid-devices=2 /dev/sdb5 missing
$ sudo pvcreate /dev/md0
$ sudo vgextend vg0 /dev/md0

Move the data hosted on sda5 to md0. Note pvmove reports an error, but when I try to continue the operation, it reports that it's already done, so I don't think this is a real problem:

$ sudo pvmove /dev/sda5 /dev/md0
/dev/sda5: Moved: 99.9%
ABORTING: Can't find mirror LV in vg0 for /dev/sda5

$ sudo pvmove /dev/sda5 /dev/md0
No data to move for vg0

Now remove sda5 from the volume group and add it to md0:

$ sudo vgreduce vg0 /dev/sda5
$ sudo pvremove /dev/sda5
$ sudo parted /dev/sda set 5 lvm off set 5 raid on
$ sudo mdadm /dev/md0 --add /dev/sda5

And see that it's working:

$ cat /proc/mdstat
Personalities : [raid1]
md0 : active raid1 sda5[2] sdb5[0]
      442052416 blocks [2/1] [U_]
      [>....................]  recovery =  0.0% (288512/442052416)
      finish=153.1min speed=48085K/sec

Finally, add the info to the mdadm config and regenerate the initrd to make sure md0 is found when the system eventually reboots. I found that I had to remove the "metadata" tag from the generated config line, YMMV:

$ sudo mdadm --detail --scan | sudo tee -a /etc/mdadm/mdadm.conf
ARRAY /dev/md0 level=raid1 num-devices=2 metadata=00.90 UUID=4aa66439:62c76598:cb06150d:d44aeb51
$ sudo vim /etc/mdadm/mdadm.conf  # to remove "metadata=00.90"
$ sudo update-initramfs -u -k all

All this without any interruption to the system operation!

SHA1 broken by US Government

Tuesday, July 7th, 2009

...but not in the way you might expect. One of us noisers (Gerry Leach) tried to use the Argonne National Laboratory's implementation of SHA1 to double-check his own computations. What he found was a bit of a surprise, to say the least...

Given the input string 1316798755 the above site returns DA39A3EE5E6B4BD3255BFEF95601890AFD879. One wouldn't normally question this result, coming from a national laboratory, except that it didn't match Gerry's local tests, nor does it match mine:

$ echo -n 1316798755 | sha1sum | tr '[:lower:]' '[:upper:]'
A897C3B9E5A64D609A1D7DB3D1D7F4C03C3F00A1  -

Bob Bell quickly pointed out the similarity of the site's computation to the SHA1 of the empty string:

$ sha1sum </dev/null | tr '[:lower:]' '[:upper:]'
DA39A3EE5E6B4B0D3255BFEF95601890AFD80709  -
DA39A3EE5E6B4BD3255BFEF95601890AFD879 (output from ANL)

After a few more tests, Bob enumerated the issues with the site's computation:

  • First, it strips any non-alpha characters from the input, including digits and whitespace.
  • Then it converts lowercase input to uppercase, so the result for "foobar" is the same as the result for "FOOBAR", but even so the final answer is wrong because...
  • It prints the result as a string of bytes using %X instead of %02X, so the output drops leading zeroes in the hex representation of each byte.

I wonder what Argonne is doing with this particular calculator... Dare we hope for... nothing?

Firefox profiles on Ubuntu

Tuesday, June 10th, 2008

Running multiple simultaneous Firefox profiles is broken on Ubuntu. It works fine on Debian and Gentoo, among others. I don't know if the Ubuntu maintainer is refusing to fix it on the basis that it's an upstream problem, or if they just haven't looked at what the other distros are doing...

Anyway, it's pretty easy to fix with a /usr/local/bin/firefox wrapper:

#!/bin/bash
[[ " $*" == *" -P"* ]] && export MOZ_NO_REMOTE=1
exec /usr/bin/firefox "$@"

This prevents the binary from attempting to contact the running instance, which allows the -P and -ProfileManager options to work.

using the reStructuredText plugin for WordPress

Thursday, May 15th, 2008

The first thing I did after migrating content from our old blog was to install the reStructuredText WordPress plugin. The second thing I did was convert a few entries to use it. And the third thing, well, the third thing was to spend a couple hours trying to figure out why it insisted on rendering headings as <h1> instead of <h3> even though I had set $rst2html_options = '--initial-header-level=3 --no-doc-title ...'.

Finally found it! $rst2html_options is global but the rendering function was using an unitialized local value. Here's the patch:

--- rest.php.old 2008-05-15 08:14:52.000000000 -0700
+++ rest.php     2008-05-15 08:15:00.000000000 -0700
@@ -76,6 +76,7 @@
  */
 function reST($text) {
   global $rst2html;
+  global $rst2html_options;
   global $cachedir;
   global $usepipes;
   global $tmpdir;

I'll try to get this upstream, but the launchpad project doesn't provide any contact information and claims it doesn't use a bug database. Best I've been able to figure out so far is to leave a comment here.