Heisenbug
Locked
 
|
Hi,
I've hit a really strange problem that I'm struggling to characterise. The debugger is behaving in a way that I can't understand within callback for a WAFileUploadTag element. The problematic lines read:
saveUploadedImageAndRenderResponse: anImageFile | destinationDirectory productDirectory urlFilePath fileName title file |
title := self titleCallback value. productDirectory := IZProject pathNameFromTitle: title.
destinationDirectory := IZConstants uploadedFilesPathRoot, productDirectory, '/'.
I find that the assignment to productDirectory "productDirectory := IZProject pathNameFromTitle: title." isn't being called when an assignment on a subsequent line assigns from a method call.
It really doesn't make any sense to me so I've made a screen recording http://www.getitmade.com/GemstoneHeisenbug/GemstoneHeisenbug.html
So far I've characterised the problem: * The problematic assignment only appears to occur when running with Swazoo both in the debugger and running normally, that is I haven't been able to reproduce from a normally running FastCGI setup.
* I've re-created the method and typed from scratch in case there were some hidden characters causing strange behaviour * I can fix the problem by adding extra assignments and Gemstone appears to skip over every other assignment.
Any thoughts - has anyone else seen anything like this? Cheers Nick |
|
Hi NIck,
Fascinating problem; excellent screen recording. It certainly seems like something is wrong. I have no idea what is happening but do have a couple questions. What version of GemStone are you running? What version of GemTools? Have you verified that the problem exists when you are not single-stepping (e.g., an explicit halt after the productDirectory assignment)? Next, what is happening in the methods being called (#'titleCallback' and #'pathNameFromTitle:')? What is below this method on the stack (GsProcess stackReportToLevel: 100)? James On Nov 3, 2010, at 3:57 AM, Nick Ager wrote: Hi, I've hit a really strange problem that I'm struggling to characterise. The debugger is behaving in a way that I can't understand within callback for a WAFileUploadTag element. The problematic lines read: saveUploadedImageAndRenderResponse: anImageFile | destinationDirectory productDirectory urlFilePath fileName title file | title := self titleCallback value. productDirectory := IZProject pathNameFromTitle: title. destinationDirectory := IZConstants uploadedFilesPathRoot, productDirectory, '/'. I find that the assignment to productDirectory "productDirectory := IZProject pathNameFromTitle: title." isn't being called when an assignment on a subsequent line assigns from a method call. It really doesn't make any sense to me so I've made a screen recording http://www.getitmade.com/GemstoneHeisenbug/GemstoneHeisenbug.html So far I've characterised the problem: * The problematic assignment only appears to occur when running with Swazoo both in the debugger and running normally, that is I haven't been able to reproduce from a normally running FastCGI setup. * I've re-created the method and typed from scratch in case there were some hidden characters causing strange behaviour * I can fix the problem by adding extra assignments and Gemstone appears to skip over every other assignment. Any thoughts - has anyone else seen anything like this? Cheers Nick |
|
|
In reply to this post by Nick
Hey Nick,
Well, I'm not able to play the video, so I'm in the dark on this one... Dale On 11/03/2010 03:57 AM, Nick Ager wrote: > Hi, > > I've hit a really strange problem that I'm struggling to characterise. > The debugger is behaving in a way that I can't understand within > callback for a WAFileUploadTag element. The problematic lines read: > > saveUploadedImageAndRenderResponse: anImageFile > | destinationDirectory productDirectory urlFilePath fileName title file | > title := self titleCallback value. > productDirectory := IZProject pathNameFromTitle: title. > destinationDirectory := IZConstants uploadedFilesPathRoot, > productDirectory, '/'. > > I find that the assignment to productDirectory "productDirectory := > IZProject pathNameFromTitle: title." isn't being called when an > assignment on a subsequent line assigns from a method call. > > It really doesn't make any sense to me so I've made a screen recording > http://www.getitmade.com/GemstoneHeisenbug/GemstoneHeisenbug.html > > So far I've characterised the problem: > > * The problematic assignment only appears to occur when running with > Swazoo both in the debugger and running normally, that is I haven't been > able to reproduce from a normally running FastCGI setup. > * I've re-created the method and typed from scratch in case there were > some hidden characters causing strange behaviour > * I can fix the problem by adding extra assignments and Gemstone appears > to skip over every other assignment. > > Any thoughts - has anyone else seen anything like this? > > Cheers > > Nick > > |
|
|
Nick,
Until I find a way to view the video, would you share the editted method that "works"... Dale On 11/03/2010 09:37 AM, Dale Henrichs wrote: > Hey Nick, > > Well, I'm not able to play the video, so I'm in the dark on this one... > > Dale > > On 11/03/2010 03:57 AM, Nick Ager wrote: >> Hi, >> >> I've hit a really strange problem that I'm struggling to characterise. >> The debugger is behaving in a way that I can't understand within >> callback for a WAFileUploadTag element. The problematic lines read: >> >> saveUploadedImageAndRenderResponse: anImageFile >> | destinationDirectory productDirectory urlFilePath fileName title file | >> title := self titleCallback value. >> productDirectory := IZProject pathNameFromTitle: title. >> destinationDirectory := IZConstants uploadedFilesPathRoot, >> productDirectory, '/'. >> >> I find that the assignment to productDirectory "productDirectory := >> IZProject pathNameFromTitle: title." isn't being called when an >> assignment on a subsequent line assigns from a method call. >> >> It really doesn't make any sense to me so I've made a screen recording >> http://www.getitmade.com/GemstoneHeisenbug/GemstoneHeisenbug.html >> >> So far I've characterised the problem: >> >> * The problematic assignment only appears to occur when running with >> Swazoo both in the debugger and running normally, that is I haven't been >> able to reproduce from a normally running FastCGI setup. >> * I've re-created the method and typed from scratch in case there were >> some hidden characters causing strange behaviour >> * I can fix the problem by adding extra assignments and Gemstone appears >> to skip over every other assignment. >> >> Any thoughts - has anyone else seen anything like this? >> >> Cheers >> >> Nick >> >> > |
|
|
In reply to this post by Nick
Nick,
One more uninformed observation ... when single stepping in the debugger, the variable assignment and step point are not in synch ... In other words, sometimes the variable value does not show up in the debugger window until I've stepped to one step point after the assignment ... Dale On 11/03/2010 03:57 AM, Nick Ager wrote: > Hi, > > I've hit a really strange problem that I'm struggling to characterise. > The debugger is behaving in a way that I can't understand within > callback for a WAFileUploadTag element. The problematic lines read: > > saveUploadedImageAndRenderResponse: anImageFile > | destinationDirectory productDirectory urlFilePath fileName title file | > title := self titleCallback value. > productDirectory := IZProject pathNameFromTitle: title. > destinationDirectory := IZConstants uploadedFilesPathRoot, > productDirectory, '/'. > > I find that the assignment to productDirectory "productDirectory := > IZProject pathNameFromTitle: title." isn't being called when an > assignment on a subsequent line assigns from a method call. > > It really doesn't make any sense to me so I've made a screen recording > http://www.getitmade.com/GemstoneHeisenbug/GemstoneHeisenbug.html > > So far I've characterised the problem: > > * The problematic assignment only appears to occur when running with > Swazoo both in the debugger and running normally, that is I haven't been > able to reproduce from a normally running FastCGI setup. > * I've re-created the method and typed from scratch in case there were > some hidden characters causing strange behaviour > * I can fix the problem by adding extra assignments and Gemstone appears > to skip over every other assignment. > > Any thoughts - has anyone else seen anything like this? > > Cheers > > Nick > > |
|
|
Nick,
I've finally seen the video and it does apear that you are observing an oddity in the behavior of the debugger itself and not the code ... as I mentioned, I have seen this and have attributed it to oddities related to the step points (the points at which the debugger will stop execution). I have noticed that in the cases where a temp value is nil an additional step will cause the value to appear with the correct value ... With the GemStone 3.0 beta/release coming up I will be making a pass through the debugger taking a closer look at issues like these (there are other subtle behavior issues that I've noticed in GemStone 3.0) and if it turns out that the fix can be backported to 2.x I will do so ... Dale On 11/03/2010 09:46 AM, Dale Henrichs wrote: > Nick, > > One more uninformed observation ... when single stepping in the > debugger, the variable assignment and step point are not in synch ... In > other words, sometimes the variable value does not show up in the > debugger window until I've stepped to one step point after the > assignment ... > > Dale > > > On 11/03/2010 03:57 AM, Nick Ager wrote: >> Hi, >> >> I've hit a really strange problem that I'm struggling to characterise. >> The debugger is behaving in a way that I can't understand within >> callback for a WAFileUploadTag element. The problematic lines read: >> >> saveUploadedImageAndRenderResponse: anImageFile >> | destinationDirectory productDirectory urlFilePath fileName title file | >> title := self titleCallback value. >> productDirectory := IZProject pathNameFromTitle: title. >> destinationDirectory := IZConstants uploadedFilesPathRoot, >> productDirectory, '/'. >> >> I find that the assignment to productDirectory "productDirectory := >> IZProject pathNameFromTitle: title." isn't being called when an >> assignment on a subsequent line assigns from a method call. >> >> It really doesn't make any sense to me so I've made a screen recording >> http://www.getitmade.com/GemstoneHeisenbug/GemstoneHeisenbug.html >> >> So far I've characterised the problem: >> >> * The problematic assignment only appears to occur when running with >> Swazoo both in the debugger and running normally, that is I haven't been >> able to reproduce from a normally running FastCGI setup. >> * I've re-created the method and typed from scratch in case there were >> some hidden characters causing strange behaviour >> * I can fix the problem by adding extra assignments and Gemstone appears >> to skip over every other assignment. >> >> Any thoughts - has anyone else seen anything like this? >> >> Cheers >> >> Nick >> >> > |
|
|
In reply to this post by James Foster-8
Hi James,
Fascinating problem; excellent screen recording. It certainly seems like something is wrong. I have no idea what is happening but do have a couple questions. What version of GemStone are you running? I'm using Gemstone 2.4.4.1 What version of GemTools?
1.0-beta.8.3 Have you verified that the problem exists when you are not single-stepping (e.g., an explicit halt after the productDirectory assignment)? I just tried running the code with an explicit halt after the productDirectory assignment and the problem didn't appear. This is odd as when I run without any breakpoints using Swazoo the code didn't work.
Next, what is happening in the methods being called (#'titleCallback' and #'pathNameFromTitle:')? #titleCallback is simply returns an instance varibable which contains a block which evaluates to the title. pathNameFromTitle: title ^ title select: [:char| PRPath validCharacters includes: char]
What is below this method on the stack (GsProcess stackReportToLevel: 100)? 1 IZUIProjectFileUploader >> saveUploadedImageAndRenderResponse: @6 line 6 [GsMethod OOP 241717249] 2 ComplexBlock in IZUIProjectFileUploader >> renderMainFormOn: @4 line 6 [GsMethod OOP 248756481]
3 ComplexBlock in ExecutableBlock >> valueWithPossibleArguments: @12 line 8 [GsMethod OOP 103525889] 4 WAValueCallback >> evaluateWithArgument: @4 line 3 [GsMethod OOP 137624065] 5 WACallback >> evaluateWithFieldValues: @5 line 2 [GsMethod OOP 134048769]
6 ComplexBlock in WACallbackRegistry >> handle: @16 line 10 [GsMethod OOP 134066945] 7 Collection >> do: @5 line 10 [GsMethod OOP 1547777] 8 WACallbackRegistry >> handle: @17 line 9 [GsMethod OOP 134066945]
9 ComplexBlock in WAActionPhaseContinuation >> runCallbacks @7 line 4 [GsMethod OOP 164423425] 10 ExceptionHandler >> doTryBlock: @9 line 7 [GsMethod OOP 10065409] 11 ExceptionHandler >> try:on:do: @15 line 18 [GsMethod OOP 10062081]
12 ComplexBlock in ExecutableBlock >> on:do: @2 line 8 [GsMethod OOP 9005057] 13 WARenderLoopContinuation >> withNotificationHandlerDo: @3 line 2 [GsMethod OOP 164478721] 14 ComplexVCBlock in WAActionPhaseContinuation >> runCallbacks @8 line 3 [GsMethod OOP 164423425]
15 ComplexBlock in ExecutableBlock >> ensure: @4 line 11 [GsMethod OOP 2304001] 16 ComplexVCBlock in ExecutableBlock >> ensure: @6 line 11 [GsMethod OOP 2304001] 17 WAActionPhaseContinuation >> runCallbacks @18 line 6 [GsMethod OOP 164423425]
18 WAActionPhaseContinuation >> handleRequest @1 line 2 [GsMethod OOP 164422657] 19 ComplexBlock in WASessionContinuation >> basicValue @3 line 2 [GsMethod OOP 163978241] 20 ExceptionHandler >> doTryBlock: @9 line 7 [GsMethod OOP 10065409]
21 ExceptionHandler >> try:on:do: @15 line 18 [GsMethod OOP 10062081] 22 ComplexBlock in ExecutableBlock >> on:do: @2 line 8 [GsMethod OOP 9005057] 23 WASessionContinuation >> withUnregisteredHandlerDo: @7 line 3 [GsMethod OOP 163979521]
24 WASessionContinuation >> basicValue @4 line 2 [GsMethod OOP 163978241] 25 WASessionContinuation >> value @3 line 5 [GsMethod OOP 163980033] 26 WASession >> handleFiltered: @14 line 10 [GsMethod OOP 164857345]
27 IZSession >> handleFiltered: @12 line 10 [GsMethod OOP 221216513] 28 WARequestFilter >> handleFiltered: @2 line 4 [GsMethod OOP 137039361] 29 ComplexBlock in PRContextFilter >> handleFiltered: @3 line 2 [GsMethod OOP 204900353]
30 ExceptionHandler >> doTryBlock: @9 line 7 [GsMethod OOP 10065409] 31 ExceptionHandler >> try:on:do: @15 line 18 [GsMethod OOP 10062081] 32 ComplexBlock in ExecutableBlock >> on:do: @2 line 8 [GsMethod OOP 9005057]
33 PRCurrentContext class >> use:during: @4 line 2 [GsMethod OOP 192300801] 34 PRContextFilter >> handleFiltered: @4 line 2 [GsMethod OOP 204900353] 35 ComplexBlock in WARequestHandler >> handle: @4 line 4 [GsMethod OOP 137145089]
36 ExceptionHandler >> doTryBlock: @9 line 7 [GsMethod OOP 10065409] 37 ExceptionHandler >> try:on:do: @15 line 18 [GsMethod OOP 10062081] 38 ComplexBlock in ExecutableBlock >> on:do: @2 line 8 [GsMethod OOP 9005057]
39 WADynamicVariable class >> use:during: @4 line 4 [GsMethod OOP 133975041] 40 ComplexBlock in WARequestContext >> push:while: @4 line 5 [GsMethod OOP 136689665] 41 ComplexBlock in ExecutableBlock >> ensure: @4 line 11 [GsMethod OOP 2304001]
42 ComplexBlock in ExecutableBlock >> ensure: @6 line 11 [GsMethod OOP 2304001] 43 WARequestContext >> push:while: @7 line 6 [GsMethod OOP 136689665] 44 WARequestHandler >> handle: @5 line 4 [GsMethod OOP 137145089]
45 WASession >> handle: @10 line 11 [GsMethod OOP 164859393] 46 WARegistry >> dispatch:to: @1 line 5 [GsMethod OOP 137438721] 47 WARegistry >> handleKeyed:with: @2 line 5 [GsMethod OOP 137440513]
48 WARegistry >> handleFiltered: @33 line 19 [GsMethod OOP 137436161] 49 WAApplication >> handleFiltered: @5 line 5 [GsMethod OOP 164386817] 50 WARequestFilter >> handleFiltered: @2 line 4 [GsMethod OOP 137039361]
51 ComplexBlock in WAExceptionFilter >> handleFiltered: @3 line 3 [GsMethod OOP 133952513] 52 ExceptionHandler >> doTryBlock: @9 line 7 [GsMethod OOP 10065409] 53 ExceptionHandler >> try:on:do: @15 line 18 [GsMethod OOP 10062081]
54 ComplexBlock in ExecutableBlock >> on:do: @2 line 8 [GsMethod OOP 9005057] 55 WAExceptionHandler >> handleExceptionsDuring: @8 line 3 [GsMethod OOP 135931905] 56 WAExceptionHandler class >> handleExceptionsDuring:context: @2 line 2 [GsMethod OOP 137652993]
57 WAExceptionFilter >> handleFiltered: @4 line 3 [GsMethod OOP 133952513] 58 ComplexBlock in WARequestHandler >> handle: @4 line 4 [GsMethod OOP 137145089] 59 ExceptionHandler >> doTryBlock: @9 line 7 [GsMethod OOP 10065409]
60 ExceptionHandler >> try:on:do: @15 line 18 [GsMethod OOP 10062081] 61 ComplexBlock in ExecutableBlock >> on:do: @2 line 8 [GsMethod OOP 9005057] 62 WADynamicVariable class >> use:during: @4 line 4 [GsMethod OOP 133975041]
63 ComplexBlock in WARequestContext >> push:while: @4 line 5 [GsMethod OOP 136689665] 64 ComplexBlock in ExecutableBlock >> ensure: @4 line 11 [GsMethod OOP 2304001] 65 ComplexBlock in ExecutableBlock >> ensure: @6 line 11 [GsMethod OOP 2304001]
66 WARequestContext >> push:while: @7 line 6 [GsMethod OOP 136689665] 67 WARequestHandler >> handle: @5 line 4 [GsMethod OOP 137145089] 68 WADispatcher >> handleFiltered:named: @7 line 5 [GsMethod OOP 133926913]
69 WADispatcher >> handleFiltered: @7 line 6 [GsMethod OOP 133928449] 70 ComplexBlock in WARequestHandler >> handle: @4 line 4 [GsMethod OOP 137145089] 71 ExceptionHandler >> doTryBlock: @9 line 7 [GsMethod OOP 10065409]
72 ExceptionHandler >> try:on:do: @15 line 18 [GsMethod OOP 10062081] 73 ComplexBlock in ExecutableBlock >> on:do: @2 line 8 [GsMethod OOP 9005057] 74 WADynamicVariable class >> use:during: @4 line 4 [GsMethod OOP 133975041]
75 ComplexBlock in WARequestContext >> push:while: @4 line 5 [GsMethod OOP 136689665] 76 ComplexBlock in ExecutableBlock >> ensure: @4 line 11 [GsMethod OOP 2304001] 77 ComplexBlock in ExecutableBlock >> ensure: @6 line 11 [GsMethod OOP 2304001]
78 WARequestContext >> push:while: @7 line 6 [GsMethod OOP 136689665] 79 WARequestHandler >> handle: @5 line 4 [GsMethod OOP 137145089] 80 ComplexBlock in WAServerAdaptor >> handleRequest: @4 line 4 [GsMethod OOP 134580481]
81 ExceptionHandler >> doTryBlock: @9 line 7 [GsMethod OOP 10065409] 82 ExceptionHandler >> try:on:do: @15 line 18 [GsMethod OOP 10062081] 83 ComplexBlock in ExecutableBlock >> on:do: @2 line 8 [GsMethod OOP 9005057]
84 WAServerAdaptor >> handleRequest: @6 line 5 [GsMethod OOP 134580481] 85 WAServerAdaptor >> handle: @1 line 4 [GsMethod OOP 134579201] 86 ComplexBlock in WAServerAdaptor >> process: @5 line 6 [GsMethod OOP 134577409]
87 ComplexBlock in ExecutableBlock >> ensure: @4 line 11 [GsMethod OOP 2304001] 88 ComplexBlock in ExecutableBlock >> ensure: @6 line 11 [GsMethod OOP 2304001] 89 WAServerAdaptor >> process: @9 line 7 [GsMethod OOP 134577409]
90 ComplexBlock in WAGsSwazooAdaptor >> process: @3 line 6 [GsMethod OOP 165955841] 91 ComplexBlock in GRGemStonePlatform >> seasideProcessRequestWithRetry:resultBlock: @12 line 11 [GsMethod OOP 130485249]
92 ExceptionHandler >> doTryBlock: @9 line 7 [GsMethod OOP 10065409] 93 ExceptionHandler >> try:on:do: @15 line 18 [GsMethod OOP 10062081] 94 ComplexBlock in ExecutableBlock >> on:do: @2 line 8 [GsMethod OOP 9005057]
95 ComplexVCBlock in GRGemStonePlatform >> seasideProcessRequestWithRetry:resultBlock: @18 line 12 [GsMethod OOP 130485249] 96 ComplexBlock in ExecutableBlock >> ensure: @4 line 11 [GsMethod OOP 2304001]
97 ComplexVCBlock in ExecutableBlock >> ensure: @6 line 11 [GsMethod OOP 2304001] 98 TransientRecursionLock >> critical: @15 line 8 [GsMethod OOP 21159937] 99 GRGemStonePlatform >> seasideProcessRequestWithRetry:resultBlock: @43 line 5 [GsMethod OOP 130485249]
100 ComplexBlock in GRGemStonePlatform >> seasideProcessRequest:adaptor:resultBlock: @7 line 9 [GsMethod OOP 130485505] Cheers Nick |
|
|
In reply to this post by Dale Henrichs
Hi Dale,
Apologies for challenging your computer's codec support - but thanks for persevering. Until I find a way to view the video, would you share the editted method that "works"... First here is the method where alternate assignments are ignored:
------ saveUploadedImageAndRenderResponse: anImageFile | destinationDirectory productDirectory urlFilePath fileName title file | title := self titleCallback value. productDirectory := IZProject pathNameFromTitle: title.
destinationDirectory := IZConstants uploadedFilesPathRoot, productDirectory, '/'.
------- here is the method with superfluous assignments that skips the superfluous assignments but executes the assignments I'm interested in: ----
saveUploadedImageAndRenderResponse: anImageFile | destinationDirectory productDirectory urlFilePath fileName title file | title := self titleCallback value. productDirectory := IZProject pathNameFromTitle: title.
title := nil. destinationDirectory := IZConstants uploadedFilesPathRoot, productDirectory, '/'.
title := nil. ---- Cheers Nick |
|
|
Nick,
So we've explained the debugger behavior, but not the runtime problem? That one seems to be the oddity... Dale On 11/03/2010 01:03 PM, Nick Ager wrote: > Hi Dale, > > Apologies for challenging your computer's codec support - but thanks for > persevering. > > Until I find a way to view the video, would you share the editted > method that "works"... > > > First here is the method where alternate assignments are ignored: > > ------ > saveUploadedImageAndRenderResponse: anImageFile > | destinationDirectory productDirectory urlFilePath fileName title file | > title := self titleCallback value. > productDirectory := IZProject pathNameFromTitle: title. > destinationDirectory := IZConstants uploadedFilesPathRoot, > productDirectory, '/'. > ------- > > here is the method with superfluous assignments that skips the > superfluous assignments but executes the assignments I'm interested in: > > ---- > saveUploadedImageAndRenderResponse: anImageFile > | destinationDirectory productDirectory urlFilePath fileName title file | > title := self titleCallback value. > productDirectory := IZProject pathNameFromTitle: title. > title := nil. > destinationDirectory := IZConstants uploadedFilesPathRoot, > productDirectory, '/'. > title := nil. > > ---- > > Cheers > > Nick |
«
Return to GLASS
|
1 view|%1 views
| Free forum by Nabble | Edit this page |