Any chance you've got macro caching enabled on some macros that shouldn't have it?

Start by setting macro cache time to 0 and see if the problem continues. If not, systematically add caching to your macros. Depending on what a macro does you'll want to set the cache time low or high, ensure that macro caching is unique to each page, and/or unique to each logged in website visitor.

Let us know what you find out.

cheers,
doug.

Doug, thanks for your quick reply, nah, I think I'm ok with the cache settings. At least so far I understand'em:

In page template I have this macro that displays name of the logged in member:

                    <umbraco:Macro Alias="MemberLoggedInDynamic" runat="server"></umbraco:Macro>

And the macro MemberLoggedInDynamic has Cache period 0, cache by page Check, cache personalized Check.

For what I understand that should protect user content from being shared?

Regards

Jonas

Could be something on IIS perhaps? *searching*

If you have macro cache period = 0 then there's no macro caching going on in umbraco. In which case it doesn't matter what you set for the checkboxes since the macro isn't cached.

So that sounds good, at least to be sure the issue isn't obscured by caching output.

The next question would be... what's in the MemberLoggedInDynamic macro? Maybe there's something in there? Is it xslt or .net?

How are you logging in website visitors? And are you using the umbraco members or another membership provider?

More info will help!

cheers,
doug.

Caching is a rather big chapter...

I have the default output caching set by IIS7. Enable cahe checked and Enable kernel cache checked. Shouldnt be?

I'm using umbraco members, and MemberLoggedInDynamic is a Xslt-macro using umbraco.library:IsLoggedOn() and umbraco.library:GetCurrentMember().

Cheers

When I have a look at the screen dump I got from the user I see that the url is pointing at the right page, but content is from another one:

Browser url is www.oursite.com/public/this-page

Page content and page header is www.oursite.com/members/that-page

Ouch

The only log row around the time in question is this (which I dont think have anything to do with this problem, but I dont understand what scripts/mhref means here).

id    userId    NodeId    Datestamp    logHeader    logComment
251457    0    -1    2010-03-15 10:45:48.060    NotFound    scripts/mhref= (from 'http://www.oursite.com/public/yet-another-page')

I wonder if that is a sign of an error that I find MemberLoggedInDynamic in the "Cache browser" in Umbraco Developer section, under System.Xml.Xsl.XslCompiledTransform. MemberLoggedInDynamic should never be cachef afaiu?

Interesting... I've done this sort of thing and not had this problem.

I don't think it is IIS7 related (though that's always a possibility I suppose) so let's continue with umbraco for a few more checks/tests.

Don't worry about the Cache browser... umbraco compiles every xslt macro when you save it. If you want to know if your macro is actively using a cached version of the output add ?umbDebugShowTrace=true to the querystring and you'll get full trace output. A cached macro will say it is cached and have few lines of output in the trace. An uncached macro will show a lot of lines in the trace output.

What is interesting is that the content is the wrong content. Maybe there's something else on the template of that page, or another macro is pulling data to display?

Check the ?umbDebugShowTrace=true output to see what macros are called... might give you some insight.

If it all boils down to one macro that returns the wrong information... can we see more of the macro?

Hang in there, we'll get this resolved!

cheers,
doug.

I see the requests in IIS log, but do not get any wiser from that. Both requests come from the same IP (they are on the same Lan). No further info I can use there. First User B request, and the line after the User A request.

What on earth makes IIS think it should serv User A the requested page from User B?

"We'll get this resolved!" thanks, hope so.

I'm having a look at the trace and I see this line for the macro in question:

umbracoMacro    Macro loaded from cache (ID: 195, Member Logged In Dynamic)    0,932146683447198    0,000084
renderMacro    Rendering started (macro: Member Logged In Dynamic, type: 1, cacheRate: 0)    0,932172105672648    0,000025

Is that okay, cacheRate 0 should be good, right?

There are quite some other macros as well. Two of them handle member information, both of them have Cache period 0. But User A was not even logged in, so the erroneous caching seems to take place before / outside of umbraco. No?

Cheers

The other macros are about serving page parts content, navigations, advertisments and stuff like that.

Correct, cacheRate 0 means "no caching" of the macro.

It may be time to back up... waaaay up, and try again with very simple samples to make something work and then compare what works with what doesn't.

1. For now, turn off all caching in IIS. We can turn it on again later but this will rule out IIS being the culprit.
2. Clear the browser cache (using firebug, web dev toolbar, whatever tool your browser supports). We want to be 100% sure there's nothing cached on the browser itself.
3. Make a new template called 'debug' with the very simplest html in it (use no master template, just put in something like this:

4. <html>
   <body>
       <h1>debug page</h1>
       <p>Macro output shown below</p>
       <!-- insert your macro here -->
   </body>
   </html>

6. Add your macro to this template
7. Request a page using the ?altTemplate=debug querystring; this will force the page to be rendered with your 'debug' template instead of the default template, bypassing all kinds of code, macros, etc. 

Do you get the proper output for your page with the IIS caching disabled?

With the very simple template and one macro-only?

Does it matter what browser you use? Or which computer(s) on your LAN?

cheers,
doug.

Yes, sorry Dough, I was not clear in my first post, this only happens occasionally. Fun eh? I will get back later today, disabling cache in IIS.

Doug. I have disabled IIS caching now. I just have to sit and wait for random user reports here, since I haven't found out a way to reproduce the error myself.

Not-logged-in User A got another response than she asked for, a one that belonged to logged-in-User B. On another computer on the same lan. It's not the first time this happens, they have reported the same twice before. (In a period of months). I am taking this bit by bit with every clue I get. Do you have any suggestions on how to add more logging / debugging or a way to trigger the error? I'm thinking of running automated load / stress tests.

Regards

Jonas

That is such a tough situation to debug since it happens so infrequently!

Here's a crazy thought... does it happen when the site is or has recently been particularly busy? If so, perhaps a memory problem with your macro or an extension that normally gets cleared by an app_pool recycle before it reaches a critical stage? Or perhaps a timing issue?

Load testing is a good idea. While the site is being load tested, see if you can reproduce the problem.

Can't think of what you might log beyond what would normally appear in the umbracoLog table and the server's event viewer.

Maybe someone else has an idea?

Keep us posted of your progress.

cheers,
doug.

Hi again!

The site is never very busy, couple of hundred users a day.

Can you elaborate a bit about "timing issue"?

We're running with IIS caching off now. And we will also move the server to better hw, for other reasons.

I really need to know what's happening here and I must try to find a way to reproduce and debug. I'll keep posting, and most happy listening to all suggestions on how to find out whats going on. 

Regards

Jonas

Hello,

this still keeps bugging us, now even after I moved to another server, disabled output caching in IIS, and changed a control that was using the XsltResult-control to ordinary xslt macro - with 0 caching. And now we are certain that the bug occurs everywhere, not only on two computers on the same Lan.

Sometimes a user gets another users start-page from the member section.

I will add lots of logging stuff now to pinpoint this down to the smallest bits.

Regards

Jonas

That's great news... wider reproducability while simplifying the environment!

Looking forward to hear what you find out.

cheers,
doug.

Hi, you asked "How are you logging in website visitors? And are you using the umbraco members or another membership provider?"

Actually thats what I must look at in detail now. I noticed that one is supposed to use Asp net membership provider. I am using depreceated(?) umbraco membership api - calls. Time to create a new login / logout control perhaps? (I do not use the asp:control because it doesnt render the html I like).

Regards

Jonas

Hi again!

The umbraco.library:RequestForm seem to cache the request form values, impossible, right?

This is the start of my Xslt-macro that gets the form post's:

    <xsl:variable name="submitUserName" select="umbraco.library:RequestForm('username')"/>
    <xsl:variable name="submitPassword" select="umbraco.library:RequestForm('password')"/>
    <xsl:variable name="submitSend" select="umbraco.library:RequestForm('submit-login')"/>
    <xsl:choose>
      <xsl:when test="$submitSend=''">
        <xsl:call-template name="notLoggedInFormView"/>
      </xsl:when>
      <xsl:otherwise>
        <xsl:variable name="tryLogin" select="umbPrg:tryLoginMembershipProvider($submitUserName, $submitPassword, $loginRedirect)"/>

The beginning of umbPrg:tryLoginMembershipProvider now writes a log row and looks like this

    Public Shared Function tryLoginMembershipProvider(ByVal username As String, ByVal password As String, ByVal optionalRedirectToUrl As String) As String
        umbraco.BusinessLogic.Log.Add(LogTypes.Custom, New umbraco.BusinessLogic.User(0), -1, "Member logging in: (" & username & "," & password & ") from " & System.Web.HttpContext.Current.Request.UserHostAddress.ToString())
        If Membership.ValidateUser(username, password) Then

So, in the first row I have added a log row that writes form username and password + ip-address from the client. And now the strange thing in then log I find

id userId  NodeId  Datestamp   logHeader   logComment
255162  0   -1  2010-03-18 15:38:22.793 Custom  Member logging in: (usera,password) from 217.13.xx.xx
255160  0   -1  2010-03-18 15:34:10.193 Custom  Member logging in: (usera,password) from 81.224.xx.xx

Seems like the same user has logged in from two different computers, 4 minutes apart, but rather the other request was from quite another person and should ofcourse not be logged in with the first request credentials.

The bug-hunt continues...

Here's one possible troublemaker,

I have a control called setPageExpiresNow on each member page, which should handle the possibility that the users might navigate back with their browser after logging out. It should disable caching in the browser (at least that was my intention). But reading a bit more I think it might just have done the opposite?

Here's the article I did not read good enough to start with:

http://msdn.microsoft.com/en-us/library/y18he7cw.aspx

And here's my code:

Response.Cache.SetExpires(DateTime.Now.AddSeconds(1));
Response.Cache.SetCacheability(HttpCacheability.Public);
Response.Cache.SetValidUntilExpires(true);

And it worked when I tried. But reading a bit more I think I misunderstood the whole thing.

"Public Sets Cache-Control: public to specify that the response is cacheable by clients and shared (proxy) caches."

I changed to NoCache to disable caching here aswell. But still - why should it ever cache with expiration set to 1 second? If the page is cached somewhere it must be somewhere where the clock is not same as the server. I am pretty sure that there's no proxies between the server and the people on the Lan where this problem occured most times. And its the request, not the response that seems to be cached... Sometimes the server handle old form data, from another request...

To be continued...

The problem might have been solved, no problems during the whole day, the xslt logger helped, a better login control, and that removed page expiration cache.

Not seen the problem since the change. I consider it fixed. Thanks for your technical and moral support Doug :-)

Cheers

Jonas

is working on a reply...