Re: [Spyce-users] subprocess & redirect

[Philip S. <ph...@se...>]

On Mar 20, 2006, at 7:12 PM, Philip Semanchuk wrote:

>
> On Mar 20, 2006, at 7:03 PM, Jonathan Ellis wrote:
>
>> Did you try using the native spyce server?  It should work fine there.
>> I wouldn't be surprised if mod_python or something else is screwing  
>> with
>> you.
>
> If by "native spyce server" you mean Spyce proxied behind Apache, then  
> yes, that's how I have it set up. I'm running Apache 2.1.9  under  
> FreeBSD 6.0, FYI.

More clues. First, I used the LiveHTTPHeaders extension for Firefox to  
see what's happening when I hit RedirectTest.spy. Here's the  
conversation that it reports:

----------------------------------------------------------
http://whiskey/RedirectTest.spy

GET /RedirectTest.spy HTTP/1.1
Host: whiskey
User-Agent: Mozilla/5.0 (Macintosh; U; PPC Mac OS X Mach-O; en-US;  
rv:1.8.0.1) Gecko/20060111 Firefox/1.5.0.1
Accept:  
text/xml,application/xml,application/xhtml+xml,text/html;q=0.9,text/ 
plain;q=0.8,image/png,*/*;q=0.5
Accept-Language: en-us,en;q=0.7,sv;q=0.3
Accept-Encoding: gzip,deflate
Accept-Charset: ISO-8859-1,utf-8;q=0.7,*;q=0.7
Keep-Alive: 300
Connection: keep-alive

HTTP/1.x 302 MOVED TEMPORARILY
Date: Tue, 21 Mar 2006 20:27:19 GMT
Status: 302 "MOVED TEMPORARILY"
Content-Type: text/html
X-Spyce: Spyce/www_2.0.3 Python/2.4
Location: http://google.com
Via: 1.1 192.168.0.103
Transfer-Encoding: chunked
----------------------------------------------------------


The interesting thing to note is that the date header on Spyce's  
response is at 27:19 after the hour. The spyce log says that the  
request was received at 27:19 and took 0.0684680938721 seconds to  
process.

Second clue comes from adding a line that writes to a file immediately  
after spawning the subprocess:
     file("/tmp/SpawnComplete.txt", "w").write(time.strftime("%H:%M:%S",  
time.gmtime()))

That happens at the same time (27:19) as the Spyce log says the request  
was received, so Spyce is definitely not getting hung up on the  
spawning of the subprocess.

Based on these clues I'm tempted to conclude that Spyce is generating  
the redirect response immediately but it is not getting returned to the  
browser (for some reason) until the subprocess completes. Any idea why  
this might happen?


Relevant spyce.log section follows.


handler for spy is <unbound method myHTTPhandler.handler_spyce>
localhost.my.domain - - [21/Mar/2006 15:27:19] "GET /RedirectTest.spy  
HTTP/1.1" - -
elapsed to get spycecode: 0.00439715385437
request.load
cache hit (1115213323) for request in  
/usr/local/share/spyce-2.0.3/modules/request.py
request.start
GET variables: {}
POST variables: {}
response.load
cache hit (1113103628) for response in  
/usr/local/share/spyce-2.0.3/modules/response.py
response.start
stdout.load
cache hit (1112993912) for stdout in  
/usr/local/share/spyce-2.0.3/modules/stdout.py
stdout.start
error.load
cache hit (1113883773) for error in  
/usr/local/share/spyce-2.0.3/modules/error.py
error.start
redirect.load
cache hit (1114403437) for redirect in  
/usr/local/share/spyce-2.0.3/modules/redirect.py
redirect.start
elapsed to init wrapper: 0.013818025589
external redirect to http://google.com at the behest of  
/usr/local/www/data-dist/RedirectTest.spy
elapsed to process: 0.0558350086212
redirect.finish
error.finish
stdout.finish
response.finish
request.finish
finished destroy for /usr/local/www/data-dist/RedirectTest.spy
elapsed to finish: 0.0641510486603
total for /RedirectTest.spy was 0.0684680938721
foo: done