Hi, I'm using Zope 2.6.1b1 (but the same behavior is exhibited by 2.6.0) and IE6 on XP. Before I spend a long time debugging this I thought I'd ask the list: Either IE's cookie handling (doubt it, since I tried this with highly permissive privacy settinngs) or Zope's browser id manager, or Zope's session manager or Zope's transient objects folder is misbehaving. Symptom: Session data is periodically and intermittently lost within a period of time much much shorter than the transient object timeout. To test this I use a single IE window reloading the very same "test.html" ZPT that simply checks for the existance of the key 'foo' in REQUEST.SESSION and reports the result (and sets it to 1 always). Preliminary evidence is that the problem is exacerbated by concurrent request handling. I test this using a windows client that utilizes the WinHTTP COM+ object to generate requests running on a separate machine (no chance of IE stepping on itself). Of possible relevance is that external python methods are invoked to fulfill the WinHTTP generated requests. Any initial hints on where to look? Thanks, Andrew Athan
Further information: By printing request['_ZopeId'] I am able to see that the session ID is being maintained even after the session data disappears (thus, cookies are working fine). The problem is probably NOT in the browser ID manager. By monitoring the transient object folder after setting all timeouts to 0 and using "ab -n 1000 http://localhost:8080/debug_test" to hit my little debug ZPT I see that the number of objects in the transient folder is periodically reset to 0 through no obvious action of my own. Any clues or known bugs here? Andrew Athan -----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 9:49 PM To: zope@zope.org Subject: [Zope] Strange session behavior Hi, I'm using Zope 2.6.1b1 (but the same behavior is exhibited by 2.6.0) and IE6 on XP. Before I spend a long time debugging this I thought I'd ask the list: Either IE's cookie handling (doubt it, since I tried this with highly permissive privacy settinngs) or Zope's browser id manager, or Zope's session manager or Zope's transient objects folder is misbehaving. Symptom: Session data is periodically and intermittently lost within a period of time much much shorter than the transient object timeout. To test this I use a single IE window reloading the very same "test.html" ZPT that simply checks for the existance of the key 'foo' in REQUEST.SESSION and reports the result (and sets it to 1 always). Preliminary evidence is that the problem is exacerbated by concurrent request handling. I test this using a windows client that utilizes the WinHTTP COM+ object to generate requests running on a separate machine (no chance of IE stepping on itself). Of possible relevance is that external python methods are invoked to fulfill the WinHTTP generated requests. Any initial hints on where to look? Thanks, Andrew Athan
Stranger and stranger. When the objects disappear, there is no slew of calls to the deleteScript ... it is looking like the session data manager just goes "poof" A. -----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 10:32 PM To: zope@zope.org Subject: RE: [Zope] Strange session behavior Further information: By printing request['_ZopeId'] I am able to see that the session ID is being maintained even after the session data disappears (thus, cookies are working fine). The problem is probably NOT in the browser ID manager. By monitoring the transient object folder after setting all timeouts to 0 and using "ab -n 1000 http://localhost:8080/debug_test" to hit my little debug ZPT I see that the number of objects in the transient folder is periodically reset to 0 through no obvious action of my own. Any clues or known bugs here? Andrew Athan -----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 9:49 PM To: zope@zope.org Subject: [Zope] Strange session behavior Hi, I'm using Zope 2.6.1b1 (but the same behavior is exhibited by 2.6.0) and IE6 on XP. Before I spend a long time debugging this I thought I'd ask the list: Either IE's cookie handling (doubt it, since I tried this with highly permissive privacy settinngs) or Zope's browser id manager, or Zope's session manager or Zope's transient objects folder is misbehaving. Symptom: Session data is periodically and intermittently lost within a period of time much much shorter than the transient object timeout. To test this I use a single IE window reloading the very same "test.html" ZPT that simply checks for the existance of the key 'foo' in REQUEST.SESSION and reports the result (and sets it to 1 always). Preliminary evidence is that the problem is exacerbated by concurrent request handling. I test this using a windows client that utilizes the WinHTTP COM+ object to generate requests running on a separate machine (no chance of IE stepping on itself). Of possible relevance is that external python methods are invoked to fulfill the WinHTTP generated requests. Any initial hints on where to look? Thanks, Andrew Athan
Hi Andrew, Is it possible that Zope is crashing during the test? Might you try pointing the session data manager at a different transient object container (one not in the temp folder)? On Thu, 2003-01-23 at 22:48, Andrew Athan wrote:
Stranger and stranger. When the objects disappear, there is no slew of calls to the deleteScript ... it is looking like the session data manager just goes "poof"
A.
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 10:32 PM To: zope@zope.org Subject: RE: [Zope] Strange session behavior
Further information:
By printing request['_ZopeId'] I am able to see that the session ID is being maintained even after the session data disappears (thus, cookies are working fine). The problem is probably NOT in the browser ID manager.
By monitoring the transient object folder after setting all timeouts to 0 and using "ab -n 1000 http://localhost:8080/debug_test" to hit my little debug ZPT I see that the number of objects in the transient folder is periodically reset to 0 through no obvious action of my own.
Any clues or known bugs here?
Andrew Athan
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 9:49 PM To: zope@zope.org Subject: [Zope] Strange session behavior
Hi, I'm using Zope 2.6.1b1 (but the same behavior is exhibited by 2.6.0) and IE6 on XP. Before I spend a long time debugging this I thought I'd ask the list:
Either IE's cookie handling (doubt it, since I tried this with highly permissive privacy settinngs) or Zope's browser id manager, or Zope's session manager or Zope's transient objects folder is misbehaving.
Symptom: Session data is periodically and intermittently lost within a period of time much much shorter than the transient object timeout.
To test this I use a single IE window reloading the very same "test.html" ZPT that simply checks for the existance of the key 'foo' in REQUEST.SESSION and reports the result (and sets it to 1 always).
Preliminary evidence is that the problem is exacerbated by concurrent request handling. I test this using a windows client that utilizes the WinHTTP COM+ object to generate requests running on a separate machine (no chance of IE stepping on itself).
Of possible relevance is that external python methods are invoked to fulfill the WinHTTP generated requests.
Any initial hints on where to look?
Thanks, Andrew Athan
Zope is definitely not crashing. The behavior is more apparent when I set the limits in the session data manager (time & # of subobjects) to 0. Strange, since these are supposed to be special values that mean infinity. I bet this is a problem in OOBtree or in the bucketing mechanism of Transience.py A. -----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Chris McDonough Sent: Thursday, January 23, 2003 11:05 PM To: Andrew Athan Cc: zope@zope.org Subject: RE: [Zope] Strange session behavior Hi Andrew, Is it possible that Zope is crashing during the test? Might you try pointing the session data manager at a different transient object container (one not in the temp folder)? On Thu, 2003-01-23 at 22:48, Andrew Athan wrote:
Stranger and stranger. When the objects disappear, there is no slew of calls to the deleteScript ... it is looking like the session data manager just goes "poof"
A.
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 10:32 PM To: zope@zope.org Subject: RE: [Zope] Strange session behavior
Further information:
By printing request['_ZopeId'] I am able to see that the session ID is
being maintained even after the session data disappears (thus, cookies
are working fine). The problem is probably NOT in the browser ID manager.
By monitoring the transient object folder after setting all timeouts to 0 and using "ab -n 1000 http://localhost:8080/debug_test" to hit my
little debug ZPT I see that the number of objects in the transient folder is periodically reset to 0 through no obvious action of my own.
Any clues or known bugs here?
Andrew Athan
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 9:49 PM To: zope@zope.org Subject: [Zope] Strange session behavior
Hi, I'm using Zope 2.6.1b1 (but the same behavior is exhibited by 2.6.0) and IE6 on XP. Before I spend a long time debugging this I thought I'd ask the list:
Either IE's cookie handling (doubt it, since I tried this with highly permissive privacy settinngs) or Zope's browser id manager, or Zope's session manager or Zope's transient objects folder is misbehaving.
Symptom: Session data is periodically and intermittently lost within a period of time much much shorter than the transient object timeout.
To test this I use a single IE window reloading the very same "test.html" ZPT that simply checks for the existance of the key 'foo' in REQUEST.SESSION and reports the result (and sets it to 1 always).
Preliminary evidence is that the problem is exacerbated by concurrent request handling. I test this using a windows client that utilizes the WinHTTP COM+ object to generate requests running on a separate machine (no chance of IE stepping on itself).
Of possible relevance is that external python methods are invoked to fulfill the WinHTTP generated requests.
Any initial hints on where to look?
Thanks, Andrew Athan
_______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev )
How do I "officially" notify Zope maintainers of a possible bug? My theory is that these strange sessioning bugs are in part because _getCurrentBucket() is called by get(x), and sometimes expires objects. However, it expires them without taking into account that we are currently asking for "x". Therefore, given the discrete timeslice behavior of the expiration algorithm, we get prematurely expired because x is in the old slice! A. -----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 11:21 PM To: 'Chris McDonough' Cc: zope@zope.org Subject: RE: [Zope] Strange session behavior Zope is definitely not crashing. The behavior is more apparent when I set the limits in the session data manager (time & # of subobjects) to 0. Strange, since these are supposed to be special values that mean infinity. I bet this is a problem in OOBtree or in the bucketing mechanism of Transience.py A. -----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Chris McDonough Sent: Thursday, January 23, 2003 11:05 PM To: Andrew Athan Cc: zope@zope.org Subject: RE: [Zope] Strange session behavior Hi Andrew, Is it possible that Zope is crashing during the test? Might you try pointing the session data manager at a different transient object container (one not in the temp folder)? On Thu, 2003-01-23 at 22:48, Andrew Athan wrote:
Stranger and stranger. When the objects disappear, there is no slew of calls to the deleteScript ... it is looking like the session data manager just goes "poof"
A.
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 10:32 PM To: zope@zope.org Subject: RE: [Zope] Strange session behavior
Further information:
By printing request['_ZopeId'] I am able to see that the session ID is
being maintained even after the session data disappears (thus, cookies
are working fine). The problem is probably NOT in the browser ID manager.
By monitoring the transient object folder after setting all timeouts to 0 and using "ab -n 1000 http://localhost:8080/debug_test" to hit my
little debug ZPT I see that the number of objects in the transient folder is periodically reset to 0 through no obvious action of my own.
Any clues or known bugs here?
Andrew Athan
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 9:49 PM To: zope@zope.org Subject: [Zope] Strange session behavior
Hi, I'm using Zope 2.6.1b1 (but the same behavior is exhibited by 2.6.0) and IE6 on XP. Before I spend a long time debugging this I thought I'd ask the list:
Either IE's cookie handling (doubt it, since I tried this with highly permissive privacy settinngs) or Zope's browser id manager, or Zope's session manager or Zope's transient objects folder is misbehaving.
Symptom: Session data is periodically and intermittently lost within a period of time much much shorter than the transient object timeout.
To test this I use a single IE window reloading the very same "test.html" ZPT that simply checks for the existance of the key 'foo' in REQUEST.SESSION and reports the result (and sets it to 1 always).
Preliminary evidence is that the problem is exacerbated by concurrent request handling. I test this using a windows client that utilizes the WinHTTP COM+ object to generate requests running on a separate machine (no chance of IE stepping on itself).
Of possible relevance is that external python methods are invoked to fulfill the WinHTTP generated requests.
Any initial hints on where to look?
Thanks, Andrew Athan
_______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev ) _______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev )
On Fri, Jan 24, 2003 at 12:52:47AM -0500, Andrew Athan wrote:
How do I "officially" notify Zope maintainers of a possible bug?
http://collector.zope.org/Zope -- Paul Winkler http://www.slinkp.com
Thanks for tracking this down! I will take a quick look but please do file a collector issue if possible. On Fri, 2003-01-24 at 00:52, Andrew Athan wrote:
How do I "officially" notify Zope maintainers of a possible bug?
My theory is that these strange sessioning bugs are in part because _getCurrentBucket() is called by get(x), and sometimes expires objects. However, it expires them without taking into account that we are currently asking for "x".
Therefore, given the discrete timeslice behavior of the expiration algorithm, we get prematurely expired because x is in the old slice!
A.
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 11:21 PM To: 'Chris McDonough' Cc: zope@zope.org Subject: RE: [Zope] Strange session behavior
Zope is definitely not crashing. The behavior is more apparent when I set the limits in the session data manager (time & # of subobjects) to 0. Strange, since these are supposed to be special values that mean infinity.
I bet this is a problem in OOBtree or in the bucketing mechanism of Transience.py
A.
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Chris McDonough Sent: Thursday, January 23, 2003 11:05 PM To: Andrew Athan Cc: zope@zope.org Subject: RE: [Zope] Strange session behavior
Hi Andrew,
Is it possible that Zope is crashing during the test? Might you try pointing the session data manager at a different transient object container (one not in the temp folder)?
On Thu, 2003-01-23 at 22:48, Andrew Athan wrote:
Stranger and stranger. When the objects disappear, there is no slew of calls to the deleteScript ... it is looking like the session data manager just goes "poof"
A.
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 10:32 PM To: zope@zope.org Subject: RE: [Zope] Strange session behavior
Further information:
By printing request['_ZopeId'] I am able to see that the session ID is
being maintained even after the session data disappears (thus, cookies
are working fine). The problem is probably NOT in the browser ID manager.
By monitoring the transient object folder after setting all timeouts to 0 and using "ab -n 1000 http://localhost:8080/debug_test" to hit my
little debug ZPT I see that the number of objects in the transient folder is periodically reset to 0 through no obvious action of my own.
Any clues or known bugs here?
Andrew Athan
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 9:49 PM To: zope@zope.org Subject: [Zope] Strange session behavior
Hi, I'm using Zope 2.6.1b1 (but the same behavior is exhibited by 2.6.0) and IE6 on XP. Before I spend a long time debugging this I thought I'd ask the list:
Either IE's cookie handling (doubt it, since I tried this with highly permissive privacy settinngs) or Zope's browser id manager, or Zope's session manager or Zope's transient objects folder is misbehaving.
Symptom: Session data is periodically and intermittently lost within a period of time much much shorter than the transient object timeout.
To test this I use a single IE window reloading the very same "test.html" ZPT that simply checks for the existance of the key 'foo' in REQUEST.SESSION and reports the result (and sets it to 1 always).
Preliminary evidence is that the problem is exacerbated by concurrent request handling. I test this using a windows client that utilizes the WinHTTP COM+ object to generate requests running on a separate machine (no chance of IE stepping on itself).
Of possible relevance is that external python methods are invoked to fulfill the WinHTTP generated requests.
Any initial hints on where to look?
Thanks, Andrew Athan
_______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev )
_______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev )
_______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev )
I think there are major bugs with OOBtree. I will do some testing. The ID of interest here is 91303318A0po38A8Exk. Look at the lines marked <><><><><><>. First, the bucket of 913...Exk is given as 1043388140, then 1043388160 and then later it "miraculously" goes back to 104338140. Of course, the object can't be found in the old place and we get hammered. It seems that OOBtree has a bug in which replacing a key in setitem sometimes leaves the old key/value in place. Thus, line 740 in Transience.py index[k]=current Is the culprit. If I replace this with del index[k] index[k]=current Then the bug becomes harder (impossible?) to reproduce. Not all the problems are gone though. With this change, Zope's sessioning runs correctly for a while. Later, I start to get __setitem__ bugs in OOBtree. A. new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 91303318A0po38A8Exk get: called with k=91303318A0po38A8Exk bucket of 91303318A0po38A8Exk is 1043388140 <><><><><><><><><><><><> _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 get: current is 1043388160 get: b was not current, it was 1043388140 <><><><><><><><><><><><> new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 91303318A0po38A8Exk get: called with k=91303318A0po38A8Exk bucket of 91303318A0po38A8Exk is 1043388160 <><><><><><><><><><><><> _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 get: current is 1043388160 new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 64571139A0pogWqRi2Y get: called with k=64571139A0pogWqRi2Y bucket of 91303318A0po38A8Exk is 1043388160 _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 get: current is 1043388160 new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 91303318A0po38A8Exk get: called with k=91303318A0po38A8Exk bucket of 91303318A0po38A8Exk is 1043388140 <><><><><><><><><><><><> _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 get: current is 1043388160 get: 91303318A0po38A8Exk was not found in index bucket (1043388140) ****************************not found! _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 setitem: setting current[91303318A0po38A8Exk]=id: 10433881662107346588, token: 9 1303318A0po38A8Exk, contents: [] &&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&010101010101010101010 new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 64571139A0pogWqRi2Y get: called with k=64571139A0pogWqRi2Y -----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 11:21 PM To: 'Chris McDonough' Cc: zope@zope.org Subject: RE: [Zope] Strange session behavior Zope is definitely not crashing. The behavior is more apparent when I set the limits in the session data manager (time & # of subobjects) to 0. Strange, since these are supposed to be special values that mean infinity. I bet this is a problem in OOBtree or in the bucketing mechanism of Transience.py A. -----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Chris McDonough Sent: Thursday, January 23, 2003 11:05 PM To: Andrew Athan Cc: zope@zope.org Subject: RE: [Zope] Strange session behavior Hi Andrew, Is it possible that Zope is crashing during the test? Might you try pointing the session data manager at a different transient object container (one not in the temp folder)? On Thu, 2003-01-23 at 22:48, Andrew Athan wrote:
Stranger and stranger. When the objects disappear, there is no slew of calls to the deleteScript ... it is looking like the session data manager just goes "poof"
A.
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 10:32 PM To: zope@zope.org Subject: RE: [Zope] Strange session behavior
Further information:
By printing request['_ZopeId'] I am able to see that the session ID is
being maintained even after the session data disappears (thus, cookies
are working fine). The problem is probably NOT in the browser ID manager.
By monitoring the transient object folder after setting all timeouts to 0 and using "ab -n 1000 http://localhost:8080/debug_test" to hit my
little debug ZPT I see that the number of objects in the transient folder is periodically reset to 0 through no obvious action of my own.
Any clues or known bugs here?
Andrew Athan
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 9:49 PM To: zope@zope.org Subject: [Zope] Strange session behavior
Hi, I'm using Zope 2.6.1b1 (but the same behavior is exhibited by 2.6.0) and IE6 on XP. Before I spend a long time debugging this I thought I'd ask the list:
Either IE's cookie handling (doubt it, since I tried this with highly permissive privacy settinngs) or Zope's browser id manager, or Zope's session manager or Zope's transient objects folder is misbehaving.
Symptom: Session data is periodically and intermittently lost within a period of time much much shorter than the transient object timeout.
To test this I use a single IE window reloading the very same "test.html" ZPT that simply checks for the existance of the key 'foo' in REQUEST.SESSION and reports the result (and sets it to 1 always).
Preliminary evidence is that the problem is exacerbated by concurrent request handling. I test this using a windows client that utilizes the WinHTTP COM+ object to generate requests running on a separate machine (no chance of IE stepping on itself).
Of possible relevance is that external python methods are invoked to fulfill the WinHTTP generated requests.
Any initial hints on where to look?
Thanks, Andrew Athan
_______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev ) _______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev )
Thanks again for tracking this. Is there any level of concurrency to these tests? (e.g. are you using "ab -n 1000 -c 10" or are you using "ab -n 1000"?) On Fri, 2003-01-24 at 09:34, Andrew Athan wrote:
I think there are major bugs with OOBtree. I will do some testing.
The ID of interest here is 91303318A0po38A8Exk. Look at the lines marked <><><><><><>. First, the bucket of 913...Exk is given as 1043388140, then 1043388160 and then later it "miraculously" goes back to 104338140. Of course, the object can't be found in the old place and we get hammered.
It seems that OOBtree has a bug in which replacing a key in setitem sometimes leaves the old key/value in place. Thus, line 740 in Transience.py
index[k]=current
Is the culprit. If I replace this with
del index[k] index[k]=current
Then the bug becomes harder (impossible?) to reproduce.
Not all the problems are gone though. With this change, Zope's sessioning runs correctly for a while. Later, I start to get __setitem__ bugs in OOBtree.
A.
new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 91303318A0po38A8Exk get: called with k=91303318A0po38A8Exk bucket of 91303318A0po38A8Exk is 1043388140 <><><><><><><><><><><><> _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 get: current is 1043388160 get: b was not current, it was 1043388140 <><><><><><><><><><><><> new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 91303318A0po38A8Exk get: called with k=91303318A0po38A8Exk bucket of 91303318A0po38A8Exk is 1043388160 <><><><><><><><><><><><> _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 get: current is 1043388160 new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 64571139A0pogWqRi2Y get: called with k=64571139A0pogWqRi2Y bucket of 91303318A0po38A8Exk is 1043388160 _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 get: current is 1043388160 new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 91303318A0po38A8Exk get: called with k=91303318A0po38A8Exk bucket of 91303318A0po38A8Exk is 1043388140 <><><><><><><><><><><><> _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 get: current is 1043388160 get: 91303318A0po38A8Exk was not found in index bucket (1043388140) ****************************not found! _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 setitem: setting current[91303318A0po38A8Exk]=id: 10433881662107346588, token: 9 1303318A0po38A8Exk, contents: [] &&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&010101010101010101010 new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 64571139A0pogWqRi2Y get: called with k=64571139A0pogWqRi2Y
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 11:21 PM To: 'Chris McDonough' Cc: zope@zope.org Subject: RE: [Zope] Strange session behavior
Zope is definitely not crashing. The behavior is more apparent when I set the limits in the session data manager (time & # of subobjects) to 0. Strange, since these are supposed to be special values that mean infinity.
I bet this is a problem in OOBtree or in the bucketing mechanism of Transience.py
A.
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Chris McDonough Sent: Thursday, January 23, 2003 11:05 PM To: Andrew Athan Cc: zope@zope.org Subject: RE: [Zope] Strange session behavior
Hi Andrew,
Is it possible that Zope is crashing during the test? Might you try pointing the session data manager at a different transient object container (one not in the temp folder)?
On Thu, 2003-01-23 at 22:48, Andrew Athan wrote:
Stranger and stranger. When the objects disappear, there is no slew of calls to the deleteScript ... it is looking like the session data manager just goes "poof"
A.
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 10:32 PM To: zope@zope.org Subject: RE: [Zope] Strange session behavior
Further information:
By printing request['_ZopeId'] I am able to see that the session ID is
being maintained even after the session data disappears (thus, cookies
are working fine). The problem is probably NOT in the browser ID manager.
By monitoring the transient object folder after setting all timeouts to 0 and using "ab -n 1000 http://localhost:8080/debug_test" to hit my
little debug ZPT I see that the number of objects in the transient folder is periodically reset to 0 through no obvious action of my own.
Any clues or known bugs here?
Andrew Athan
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 9:49 PM To: zope@zope.org Subject: [Zope] Strange session behavior
Hi, I'm using Zope 2.6.1b1 (but the same behavior is exhibited by 2.6.0) and IE6 on XP. Before I spend a long time debugging this I thought I'd ask the list:
Either IE's cookie handling (doubt it, since I tried this with highly permissive privacy settinngs) or Zope's browser id manager, or Zope's session manager or Zope's transient objects folder is misbehaving.
Symptom: Session data is periodically and intermittently lost within a period of time much much shorter than the transient object timeout.
To test this I use a single IE window reloading the very same "test.html" ZPT that simply checks for the existance of the key 'foo' in REQUEST.SESSION and reports the result (and sets it to 1 always).
Preliminary evidence is that the problem is exacerbated by concurrent request handling. I test this using a windows client that utilizes the WinHTTP COM+ object to generate requests running on a separate machine (no chance of IE stepping on itself).
Of possible relevance is that external python methods are invoked to fulfill the WinHTTP generated requests.
Any initial hints on where to look?
Thanks, Andrew Athan
_______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev )
_______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev ) -- Chris McDonough <chrism@zope.com> Zope Corporation
FWIW, it might be helpful to do two things here so we can make sure we're not finding bugs that may have already been fixed in the latest revisions of BTress and Transience: - Use the latest Transience package from http://cvs.zope.org/Products/Transience/ - Use the latest BTrees package from http://cvs.zope.org/ZODB3/BTrees/ (you'll need to recompile the BTrees package by rerunning "wo_pcgi.py" in the Zope root dir). If you'd be willing to replace your existing packages with these for testing purposes and rerun the tests that you've already run, we could confirm that this is a new bug. Many thanks! - C On Fri, 2003-01-24 at 09:34, Andrew Athan wrote:
I think there are major bugs with OOBtree. I will do some testing.
The ID of interest here is 91303318A0po38A8Exk. Look at the lines marked <><><><><><>. First, the bucket of 913...Exk is given as 1043388140, then 1043388160 and then later it "miraculously" goes back to 104338140. Of course, the object can't be found in the old place and we get hammered.
It seems that OOBtree has a bug in which replacing a key in setitem sometimes leaves the old key/value in place. Thus, line 740 in Transience.py
index[k]=current
Is the culprit. If I replace this with
del index[k] index[k]=current
Then the bug becomes harder (impossible?) to reproduce.
Not all the problems are gone though. With this change, Zope's sessioning runs correctly for a while. Later, I start to get __setitem__ bugs in OOBtree.
A.
new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 91303318A0po38A8Exk get: called with k=91303318A0po38A8Exk bucket of 91303318A0po38A8Exk is 1043388140 <><><><><><><><><><><><> _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 get: current is 1043388160 get: b was not current, it was 1043388140 <><><><><><><><><><><><> new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 91303318A0po38A8Exk get: called with k=91303318A0po38A8Exk bucket of 91303318A0po38A8Exk is 1043388160 <><><><><><><><><><><><> _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 get: current is 1043388160 new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 64571139A0pogWqRi2Y get: called with k=64571139A0pogWqRi2Y bucket of 91303318A0po38A8Exk is 1043388160 _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 get: current is 1043388160 new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 91303318A0po38A8Exk get: called with k=91303318A0po38A8Exk bucket of 91303318A0po38A8Exk is 1043388140 <><><><><><><><><><><><> _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 get: current is 1043388160 get: 91303318A0po38A8Exk was not found in index bucket (1043388140) ****************************not found! _getCurrentBucket: new timeslice (pnow) 1043388160 _roll: roll loser _getCurrentBucket: slices_since (2)<t_slices (3) _getCurrentBucket: available_spares 11 setitem: setting current[91303318A0po38A8Exk]=id: 10433881662107346588, token: 9 1303318A0po38A8Exk, contents: [] &&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&&010101010101010101010 new or existing!!!!!!!!!!!!!!!!<TransientObjectContainer at session_data> new_or_existing called with 64571139A0pogWqRi2Y get: called with k=64571139A0pogWqRi2Y
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 11:21 PM To: 'Chris McDonough' Cc: zope@zope.org Subject: RE: [Zope] Strange session behavior
Zope is definitely not crashing. The behavior is more apparent when I set the limits in the session data manager (time & # of subobjects) to 0. Strange, since these are supposed to be special values that mean infinity.
I bet this is a problem in OOBtree or in the bucketing mechanism of Transience.py
A.
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Chris McDonough Sent: Thursday, January 23, 2003 11:05 PM To: Andrew Athan Cc: zope@zope.org Subject: RE: [Zope] Strange session behavior
Hi Andrew,
Is it possible that Zope is crashing during the test? Might you try pointing the session data manager at a different transient object container (one not in the temp folder)?
On Thu, 2003-01-23 at 22:48, Andrew Athan wrote:
Stranger and stranger. When the objects disappear, there is no slew of calls to the deleteScript ... it is looking like the session data manager just goes "poof"
A.
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 10:32 PM To: zope@zope.org Subject: RE: [Zope] Strange session behavior
Further information:
By printing request['_ZopeId'] I am able to see that the session ID is
being maintained even after the session data disappears (thus, cookies
are working fine). The problem is probably NOT in the browser ID manager.
By monitoring the transient object folder after setting all timeouts to 0 and using "ab -n 1000 http://localhost:8080/debug_test" to hit my
little debug ZPT I see that the number of objects in the transient folder is periodically reset to 0 through no obvious action of my own.
Any clues or known bugs here?
Andrew Athan
-----Original Message----- From: zope-admin@zope.org [mailto:zope-admin@zope.org] On Behalf Of Andrew Athan Sent: Thursday, January 23, 2003 9:49 PM To: zope@zope.org Subject: [Zope] Strange session behavior
Hi, I'm using Zope 2.6.1b1 (but the same behavior is exhibited by 2.6.0) and IE6 on XP. Before I spend a long time debugging this I thought I'd ask the list:
Either IE's cookie handling (doubt it, since I tried this with highly permissive privacy settinngs) or Zope's browser id manager, or Zope's session manager or Zope's transient objects folder is misbehaving.
Symptom: Session data is periodically and intermittently lost within a period of time much much shorter than the transient object timeout.
To test this I use a single IE window reloading the very same "test.html" ZPT that simply checks for the existance of the key 'foo' in REQUEST.SESSION and reports the result (and sets it to 1 always).
Preliminary evidence is that the problem is exacerbated by concurrent request handling. I test this using a windows client that utilizes the WinHTTP COM+ object to generate requests running on a separate machine (no chance of IE stepping on itself).
Of possible relevance is that external python methods are invoked to fulfill the WinHTTP generated requests.
Any initial hints on where to look?
Thanks, Andrew Athan
_______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev )
_______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev )
_______________________________________________ Zope maillist - Zope@zope.org http://lists.zope.org/mailman/listinfo/zope ** No cross posts or HTML encoding! ** (Related lists - http://lists.zope.org/mailman/listinfo/zope-announce http://lists.zope.org/mailman/listinfo/zope-dev ) -- Chris McDonough <chrism@zope.com> Zope Corporation
Andrew Athan wrote at 2003-1-24 09:34 -0500:
... It seems that OOBtree has a bug in which replacing a key in setitem sometimes leaves the old key/value in place. Thus, line 740 in Transience.py
index[k]=current Line like this really seem to confuse the "BTrees" package. For us, they can raise a "KeyError" (reported today in the "zope-dev" and "zodb-dev" mailing lists).
We have successfully replaced the "BTrees" package in our development environment by that from ZODB 3.2a1. On Sunday, we will go into production. I will report whether our problems go away with the new "BTrees" package. Dieter
For those of you who are experiencing sessioning issues, I wanted to report back to the list on my findings: Very strange things can and will begin to happen if you refer to sessions within your standard_error_message, or within any "top level" exception handling code registered with Zope. The cause seems to be in Publish.py. It does an abort(freeme=1) prior to calling the exception handler. This means the exception handler runs outside any transaction (as in, Transaction.py). Apparently this hoses the session machinery, presumably because the index[] and data[] structures are no longer guaranteed to be synchronized to each other (as they are at transaction boundaries). So, to avoid problems, do not refer to session variables within your standard_error_message. The Zope folks are looking at this abort() call; the verdict is out on whether calling abort(freeme=1) before exception handlers are invoked is a bug. Andrew (I've got the bends from diving so deep) Athan PS: I'll be putting various Zope/Python goodies at www.memeplex.com
participants (4)
-
Andrew Athan -
Chris McDonough -
Dieter Maurer -
Paul Winkler