AppStats should only be tracking the RPC, not the time it would take to deserialize, so your guess is probably correct. How many entities are you retrieving?
-- Ikai Lan Developer Programs Engineer, Google App Engine plus.ikailan.com | twitter.com/ikai On Wed, Sep 7, 2011 at 11:12 AM, Pol <[email protected]> wrote: > Hi, > > I'm trying to optimize our Python app and have App Stats installed. > > The code to measure (simplified): > > query = db.GqlQuery("SELECT * FROM Event WHERE ANCESTOR IS :1 > ORDER BY max_date DESC", self.user.key()) > if cursor: > query.with_cursor(cursor) > start_time = time.time() > for event in query.fetch(limit): > ... > logging.info("DELTA 1 = %.2f seconds" % (time.time() - > start_time)) > photos = Photo.get(keys) > logging.info("DELTA 2 = %.2f seconds" % (time.time() - > start_time)) > ... > logging.info("DELTA 3 = %.2f seconds" % (time.time() - > start_time)) > > self.write_json_response(...) > > logging.info("DELTA 4 = %.2f seconds" % (time.time() - > start_time)) > > From App Stats: > > @0ms memcache.Get real=5ms api=0ms > @8ms datastore_v3.RunQuery real=89ms api=1387ms > @537ms datastore_v3.Get real=1574ms api=6250ms <--- Photo.get(...) > > From the log: > > 67.169.78.38 - - [07/Sep/2011:11:04:15 -0700] "GET /api/event_list? > keyPhotos=1&limit=150&cursor=E- > ABAOsB8gEIbWF4X2RhdGX6AQkIgK7os5aSiwLsAYICiAFqD3N- > > ZXZlcnBpeC1hbHBoYXJ1CxIEVXNlciIgNWI3NmY0MjhkOGFiMTFlMDgwNWU5YjNmM2U1NDdmMWMMCxIFRXZlbnQiQDlhOWQ4MjljZDhkOTExZTBhZTQ0OWJiMWViNDM3NjUzMTIxNDMxNGVjZmQwNDBjZjlhNDc5YzFmNjFmYmEzNmMMFA== > HTTP/1.1" 200 48637 - "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_6_8) > AppleWebKit/535.1 (KHTML, like Gecko) Chrome/13.0.782.220 Safari/ > 535.1" "everpix-alpha.appspot.com" ms=4175 cpu_ms=10729 > api_cpu_ms=7638 cpm_usd=0.303547 throttle_code=1 > instance=00c61b117c52d19855e6bf84b0977f343fba > I 2011-09-07 11:04:11.609 > DELTA 1 = 0.45 seconds > I 2011-09-07 11:04:15.172 > DELTA 2 = 4.01 seconds > I 2011-09-07 11:04:15.189 > DELTA 3 = 4.03 seconds > I 2011-09-07 11:04:15.254 > DELTA 4 = 4.09 seconds > I 2011-09-07 11:04:15.286 > Saved; key: __appstats__:051100, part: 368 bytes, full: 14629 bytes, > overhead: 0.001 + 0.006; link: > http://everpix-alpha.appspot.com/_ah/stats/details?time=1315418651153 > > And the problem: > > App Stats states that Photo.get(...) took 1574ms while inline > measurements show a much bigger 3.56s? Does App Stats ignore de- > serialization of the entity properties or something? > > - Pol > > -- > You received this message because you are subscribed to the Google Groups > "Google App Engine" group. > To post to this group, send email to [email protected]. > To unsubscribe from this group, send email to > [email protected]. > For more options, visit this group at > http://groups.google.com/group/google-appengine?hl=en. > > -- You received this message because you are subscribed to the Google Groups "Google App Engine" group. To post to this group, send email to [email protected]. To unsubscribe from this group, send email to [email protected]. For more options, visit this group at http://groups.google.com/group/google-appengine?hl=en.
