Here's a strange one!

[Joshua Smith]

I got a couple exceptions in my log like this:

Invalid string key ag5tzxnvbnn0cmvhbwluz3ivcximu2vzc2lvbk1vzgvsgj3p1aim.

The sequence of events that led up to this is really interesting (note that I've concluded there is nothing that GAE did wrong here, it's just that I figured y'all might find this of interest):

1) User connects up to my app and we create a "Session" object with this key:

Starting Sesssion ag5tZXNvbnN0cmVhbWluZ3IVCxIMU2Vzc2lvbk1vZGVsGMDh1AIM

2) We then redirect the user to a test page where we confirm that they have decent bandwidth, that they have Java, etc:

/test?session=ag5t…etc.

So the next thing in the access log should be a query of that page, right?  Nope.

3) The next thing that IP queries is the thing it would be sent to if the test passed, except with a different session key.  My guess is that the browser had a cached copy of the test page, and ignored the fact that the ? parameter of this request was different. And, furthermore, if you compare those two keys, you can probably guess that the browser lowercased the old session key that it had.

So we have a browser (or possibly a proxy server) that is caching pages without looking at the whole URL, and lowercasing URLs.

How can this possibly work on the modern web???

Anyone care to guess the user agent string?

Yup, you called it:

"Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1)" 

The IP resolves to a residential service provider in Japan.

Yikes.

-Joshua

[Simon Knott]

Those session keys are actually slightly different - I don't know whether that was just a copy/paste error.

[Joshua Smith]

The session keys are different because the browser is trying to connect to an old session. That's why I see two errors:

1) A cache that is ignoring the part of the URL after ?

2) A cache that is lowercasing the part of the URL after ?

On Aug 5, 2011, at 11:53 AM, Simon Knott wrote:

Those session keys are actually slightly different - I don't know whether that was just a copy/paste error.

--
You received this message because you are subscribed to the Google Groups "Google App Engine" group.
To view this discussion on the web visit https://groups.google.com/d/msg/google-appengine/-/xTEBXp_nguAJ.
To post to this group, send email to google-a...@googlegroups.com.
To unsubscribe from this group, send email to google-appengi...@googlegroups.com.
For more options, visit this group at http://groups.google.com/group/google-appengine?hl=en.

[Simon Knott]

Ah sorry, sluggish Friday afternoon reading! 

Can you tell how long the session keys are being cached for?  Those combined errors could have serious consequences for any GET requests!  As you say, how it can possibly work is baffling.

[Joshua Smith]

On Aug 5, 2011, at 12:23 PM, Simon Knott wrote:

Can you tell how long the session keys are being cached for?

Excellent question. To figure that out, I need to deduce what that session key really was.

ag5tZXNvbnN0cmVhbWluZ3IVCxIMU2Vzc2lvbk1vZGVsGMDh1AIM

ag5tzxnvbnn0cmvhbwluz3ivcximu2vzc2lvbk1vzgvsgj3p1aim

Comparing the keys, it appears that the only differences other than capitalization are j3p vs. MDh

If we assume the suffix has not changed, we see there are 4 possible capitalizations for the j & p, and of these, only 1 is a real session key.

Various things (such as bandwidth test results) match between that session key and the connect URL hit, so I'm quite certain I found the session key which had been cached.

The real session was created Aug. 4, 2011, 8:04 p.m. and this weird event happened at  Aug. 4, 2011, 10:54 p.m.

So it appears that the cached copy was just under 3 hours old.

But it gets stranger! I log the user IP in the session, and the IP of the cached session was initiated from Calgary, Canada, whereas the strange event was initiated from either Japan or San Jose (IP geo databases disagree about where this IP really is).

And the original session had this UA:

Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; .NET CLR 1.1.4322; .NET CLR 2.0.50727; InfoPath.2; .NET4.0C; .NET4.0E; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729)

That's nothing like the browser that exhibited the weird behavior.

Proxy server maybe?

The more I look into this, the stranger it gets.

-Joshua

[Robert Kluin]

Maybe someone IMed there buddy in Japan a link to your app?

The changing of query params case would be a pretty serious concern.
Looks like it is time to use key.id() :)

> --
> You received this message because you are subscribed to the Google Groups
> "Google App Engine" group.

[Joshua Smith]

Good guess, but nope, because the first connection to my server wasn't to that lowercased copy of an old URL, but rather to the proper entry point URL. It's like they started in a new series of transactions and then in the middle, switched and started replaying (incorrectly) an old series of transactions.

Although using key.id() would have not run into the lowercase error, it just would have run into a more bizarre issue, because it was reusing an old session, who's resources had already been returned to the free pool. I think I prefer the error I got!

-Joshua

[Robert Kluin]

Yeah the lower case thing is really strange. All I can think is that
it was IE6... who knows what type of bizarre stuff it might do.

[JH]

I have seen errors before in my app where IE6 was requesting urls with
keys inbedded, however the keys were all lower case. It is rare but I
have seen it. I had just written it off as some fluke.

On Aug 5, 2:12 pm, Robert Kluin <robert.kl...@gmail.com> wrote:
> Yeah the lower case thing is really strange.  All I can think is that
> it was IE6... who knows what type of bizarre stuff it might do.
>
>
>
>
>
>
>
> On Fri, Aug 5, 2011 at 14:57, Joshua Smith <JoshuaESm...@charter.net> wrote:
> > Good guess, but nope, because the first connection to my server wasn't to that lowercased copy of an old URL, but rather to the proper entry point URL.  It's like they started in a new series of transactions and then in the middle, switched and started replaying (incorrectly) an old series of transactions.
>
> > Although using key.id() would have not run into the lowercase error, it just would have run into a more bizarre issue, because it was reusing an old session, who's resources had already been returned to the free pool.  I think I prefer the error I got!
>
> > -Joshua
>
> > On Aug 5, 2011, at 2:47 PM, Robert Kluin wrote:
>
> >> Maybe someone IMed there buddy in Japan a link to your app?
>
> >> The changing of query params case would be a pretty serious concern.
> >> Looks like it is time to use key.id()  :)
>

> >> For more options, visit this group athttp://groups.google.com/group/google-appengine?hl=en.