Odd on-update inconsistency

I'm having trouble understanding something I saw in my data from
yesterday involving an inconsistency between values in a table and its
associated rule-updated log table.

For application debugging purposes (effectiveness of web double-submit
suppression) we have a rule that creates an entry in a log table
whenever the table we are watching is updated:

Rule:
foo_update_rule AS ON UPDATE TO foo DO
INSERT INTO foo_updatelog (old_f1, new_f1, old_f2, new_f2...)
VALUES (old.f1, new.f1, old.f2, new.f2...)

Where foo is:
Column   |            Type             |   Modifiers
----------+-----------------------------+---------------
r1        | character varying(30)       |
r2        | character varying(30)       |
...

And foo_updatelog is:
 Column   |            Type             |   Modifiers
-----------+-----------------------------+---------------
updatetime | timestamp without time zone | default now()
old_r1     | character varying(30)       |
new_r1     | character varying(30)       |
...

Normally this works well to give us the info we need, but this morning I
found my table showing f1 equal to 4 and my most recent log entries
showing:

       updatetime         | old_f1 | new_f1
---------------------------+--------+--------
2008-11-25 17:33:45.537564 | 2      | 3
2008-11-25 17:33:45.539737 | 2      | 3

(The field f1 is a counter - the update query casts the varchar(30) to
int, adds one, and casts the result back to varchar(30) due to an
unfortunate current requirement on the application side.)

I was able to verify that this is a legitimately trapped double-submit
but I don't understand why the update log is showing a count of 2->3
twice instead of 2->3 then 3->4 like it typically would.

This database is still in 7.4.x land (I know, we're working on it) so if
it is related to a known issue I didn't find in subsequent release
notes, my apologies. I didn't find anything in the logs that would
explain it.

Any ideas?

Cheers,
Steve