Rule/sequence weirdness

I have some processes that create data. Other processes run by cron
periodically take that data and insert it into appropriate tables in
a 7.4.1 database.

In some cases the delay from process end to insert seems excessive so
I'm trying to track the problem with a rule that creates a log record
every time a record is inserted into the main table.

Unfortunately the sequences are not being updated as I would wish.

Here's the scoop:

I want to monitor inserts to table "foo":
guid: integer not null default nextval('public.guid'::text)
end_time: integer
...

The inserts will be logged into table "foo_latelog"
guid: integer
inserttime: timestamp without time zone default now()
end_time: timestamp without time zone

Rule foo_late_rule inserts the data:
  ON INSERT TO foo DO
      INSERT INTO foo_latelog (guid, end_time)
      VALUES (new.guid, (new.end_time)::abstime)

I expected the guid to match. Unfortunately there are no matching
guids between the two tables. It appears that the sequence is being
called twice so the guid in the log table is one greater than the
guid in the main table.

Did I miss something in my rule logic or is this a bug?

Cheers,
Steve