Subject: | Sessions break with MYAPP_DEBUG=1 |
Date: | Tue, 20 Apr 2010 19:22:45 +0200 |
To: | bug-Catalyst-Plugin-Session-State-URI [...] rt.cpan.org |
From: | Alexander Wuerstlein <arw [...] arw.name> |
Catalyst::Plugin::Session::State::URI behaves weirdly when debugging is
active, for example in the test-server.
Steps to reproduce:
either do
- with the CPAN distribution do REWRITINGTESTAPP_DEBUG=1 make test
or
- with the test application included in the distribution, execute
REWRITINGTESTAPP_DEBUG=1 perl -It/lib -Ilib -MCatalyst::ScriptRunner
-e'Catalyst::ScriptRunner->run(q{RewritingTestApp}, q{Server})'
- visit http://localhost:3000/first_request
- click the links
- result: counter does not increase
- expected result: counter should increase
Disabling MYAPP_DEBUG or using C::P::S::State::Cookie helps.
A partial log of a failed testing session as described in the steps to
reproduce is attached below.
Greetings,
Alexander Wuerstlein.
[...]
not ok 45 - session exists
# Failed test 'session exists'
# at t/lib/RewritingTestApp/Controller/URI.pm line 31.
not ok 46 - counter is OK
# Failed test 'counter is OK'
# at t/lib/RewritingTestApp/Controller/URI.pm line 33.
# got: '1'
# expected: '2'
[info] *** Request 23 (1.000/s) [9766] [Tue Apr 20 17:14:37 2010] ***
[debug] "GET" request for "second_request/-/1eb493b98285b8846d76eae05b708bfe79ba3fd2" from "131.188.30.89"
[debug] Found sessionid "1eb493b98285b8846d76eae05b708bfe79ba3fd2" in uri path
[debug] Path is "second_request"
[debug] Created session "622e110f02b958eb1864a93feaf5d73de520d61e"
[debug] rewriting response elements to include session id
[debug] Rewriting HTML body with the token parser
[debug] Restored session "1eb493b98285b8846d76eae05b708bfe79ba3fd2"
[debug] Response Code: 200; Content-Type: text/html; Content-Length: 292
[info] Request took 0.007768s (128.733/s)
.------------------------------------------------------------+-----------.
| Action | Time |
+------------------------------------------------------------+-----------+
| /uri/second_request | 0.002104s |
| -> /uri/add_some_html | 0.000232s |
'------------------------------------------------------------+-----------'
not ok 47 - session exists
# Failed test 'session exists'
# at t/lib/RewritingTestApp/Controller/URI.pm line 31.
not ok 48 - counter is OK
# Failed test 'counter is OK'
# at t/lib/RewritingTestApp/Controller/URI.pm line 33.
# got: '1'
# expected: '2'
[info] *** Request 24 (1.000/s) [9766] [Tue Apr 20 17:14:38 2010] ***
[debug] "GET" request for "second_request/-/622e110f02b958eb1864a93feaf5d73de520d61e" from "131.188.30.89"
[debug] Found sessionid "622e110f02b958eb1864a93feaf5d73de520d61e" in uri path
[debug] Path is "second_request"
[debug] Created session "9592e0417459d30ccb76c685a2df15ee4b120a99"
[debug] rewriting response elements to include session id
[debug] Rewriting HTML body with the token parser
[debug] Restored session "622e110f02b958eb1864a93feaf5d73de520d61e"
[debug] Response Code: 200; Content-Type: text/html; Content-Length: 292
[info] Request took 0.008113s (123.259/s)
.------------------------------------------------------------+-----------.
| Action | Time |
+------------------------------------------------------------+-----------+
| /uri/second_request | 0.002304s |
| -> /uri/add_some_html | 0.000309s |
'------------------------------------------------------------+-----------'
not ok 49 - session exists
# Failed test 'session exists'
# at t/lib/RewritingTestApp/Controller/URI.pm line 31.
not ok 50 - counter is OK
# Failed test 'counter is OK'
# at t/lib/RewritingTestApp/Controller/URI.pm line 33.
# got: '1'
# expected: '2'
[info] *** Request 25 (0.962/s) [9766] [Tue Apr 20 17:14:40 2010] ***
[debug] "GET" request for "second_request/-/9592e0417459d30ccb76c685a2df15ee4b120a99" from "131.188.30.89"
[debug] Found sessionid "9592e0417459d30ccb76c685a2df15ee4b120a99" in uri path
[debug] Path is "second_request"
[debug] Created session "97da1f147c7bc094e8374415c724da1df77d9c2f"
[debug] rewriting response elements to include session id
[debug] Rewriting HTML body with the token parser
[debug] Restored session "9592e0417459d30ccb76c685a2df15ee4b120a99"
[debug] Response Code: 200; Content-Type: text/html; Content-Length: 292
[info] Request took 0.007831s (127.698/s)
.------------------------------------------------------------+-----------.
| Action | Time |
+------------------------------------------------------------+-----------+
| /uri/second_request | 0.002118s |
| -> /uri/add_some_html | 0.000227s |
'------------------------------------------------------------+-----------'
[...]