[mod_python] Reloading PSP sometimes shows old pages

On Mon, Mar 30, 2009 at 05:09:08PM +1100, Graham Dumpleton wrote:
> 2009/3/30 Mike Mueller <mike at subfocal.net>:
> > The URL has no query string, it's just http://host:81/~mike/test/page.psp.
> > No POST parameters or anything, a very simple page.
> >
> > No proxy.  Browser is on the same host as Apache.  As I said in the
> > first email, no caching in Apache, as far as I can tell.  (I grepped
> > around the config files looking for any caching that might've been
> > enabled by default, and came up empty.)
> >
> > The more I play with it, the more I think it may just be Firefox that
> > sucks.  The bouncing-between-versions only happens in it.  I thought
> > Opera had it because the first time I loaded my page in Opera, I got an
> > old version (several versions prior) of the page.  That was before
> > changing MaxRequestsPerChild.  But I haven't seen that in Opera since.
> >
> > Opera's only problem is that reload doesn't always update to latest...
> > sometimes I have to navigate away and come back, or it'll keep showing
> > me the version it has loaded.  (I've tried various combos of shift,
> > ctrl+shift, etc. while clicking reload).
> >
> > Also, after a certain length of time (a minute or two?), both browsers
> > simply load the latest version, with no weird old versions appearing.
> >
> > This is frustrating.
> 
> All I can suggest is that log using req.log_error() from the PSP page
> and include in the response of the page, both the date/time and the
> process ID.
> 
> Logging will help to verify if page actually being processed. It being
> in the page should make it easier to verify that data is actually
> changing or not. If that part of data changes but remainder of page
> doesn't then would have to be a caching issue with mod_python and
> MaxRequestsPerChild isn't working.
> 
> See if that shows any pattern. Logically every request should have a
> different date/time and pid if MaxRequestsPerChild is set to 1.
> 
> Graham

Thanks for all the help.  I'm still confused. :)

I printed the request time, the mtime, and the PID on every page.  The
result looks like this:

Request time: Mon Mar 30 00:00:00 2009
Modify time:  Wed Dec 31 00:00:00 1969
PID:          6379

That's req.request_time and req.mtime passed through datetime's ctime()
function.  (i.e. datetime.date.fromtimestamp(req.mtime).ctime()). I'm
not sure if it indicates a problem, or if the request object simply
doesn't bother filling in the times correctly.

For example, the PSP documentation says:
> When a file is used as the source, the code object resulting from the
> specified file is stored in a memory cache keyed on file name and file
> modification time. The cache is global to the Python interpreter.
> Therefore, unless the file modification time changes, the file is
> parsed and resulting code is compiled only once per interpreter. 

Is it possible that this incorrect mtime is affecting PSP's internal
page caching algorithm?

By the way, the resulting behavior after this change is:
F5 F5 F5 -> keeps showing the same PID.  Hit F5 thirty times and the PID
jumps up a couple times, 6379, 6388, 6401, and then stays at 6401 for a
while.  If I go 'touch' the common.psp source file, it doesn't seem to
cause Firefox or Opera to see a new page.  They keep seeing the old one
for some arbitrary period of time.

-- 
Mike Mueller
mike at subfocal.net