More features in JacobSix. Rolling through the sprint.

I have spent a large amount of time optimizing the site as much as possible given the GAE limitations and recent slowdown.  What I mean by recent slowdown is the exceedingly long response times that happen.  This is not all the time, but enough to become annoying.  A request that typically takes 300ms to complete is taking 20 seconds in some cases.  Using Google App Engine is both a blessing and a curse.  You get many benefits but also are at the mercy of the Google Infrastructure.  Could be anything between point A and B.  So, I cannot pin the blame entirely on Google.  Maybe something in the network.  Who knows.

Besides performance improvements, I have also added Action Filtering to the "All Actions" page and "All Closed Actions" page.  I'll be creating screencasts soon to demo some of these features and guide people through the site.  It is not a complex application (that was the point), but some of the features are not completely obvious (let me know if this is not the case, I'll be happy to hear this).  From the All Actions page, there is a little arrow button next to the refresh button at the top right of the listing.  Clicking this will expand the filter options.  You can filter by assigned, group, and priority.  This is a combined filter.  So, choosing assigned and priority will filter on both, not either.

Have fun with the feature and let me know other filters you want to see.  I will add due date filtering (between this date and that date).  That one is in the list.

Posted via web from bvelasquez's posterous

Where is the slowdown in my GAE App?

Click here to download:

profile_helper.py (1 KB)

Recently I noticed JacobSix not performing very well.  Requests would take a long time sometimes, not always.  Well, I think that's the nature of GAE and you cannot expect consistent response times even from the same exact request doing the same amount of work.  Sometimes it takes 300ms, sometimes 3000ms for the same request.  Well, I wanted to make sure it was not something I injected into the code to cause the slowdown so I wanted to time each section of of the request to find out how long it is taking to complete that section.

I created a Profiler class in Python to do just this.  You simply create an instance of the Profiler class.

self.profiler = Profiler(name="Project Controller", enabled=True)

To start profiling a section of code, you call the start() method:

self.profiler.start()

This marks the start time at UTC Now.

To mark a section, you call the mark() method.

self.profiler.mark('BEFORE FETCH') ... some code here self.profiler.mark('AFTER FETCH')

When you are done timing, you can call the stop() method:

self.profiler.stop() self.profiler.report()

The report() method outputs the results of the timing to logging.info() so you can check it in your logs.  Here is an example output:

======PROFILE REPORT Project Controller====== 09-03 05:00PM 12.837 Mark - Name - Between - Accumulatve 09-03 05:00PM 12.837 0 - BEFORE FETCH - 0ms - 0ms 09-03 05:00PM 12.837 1 - AFTER FETCH - 10ms - 10ms 09-03 05:00PM 12.837 2 - BEFORE JSON - 0ms - 10ms 09-03 05:00PM 12.838 3 - AFTER JSON - 0ms - 10ms 09-03 05:00PM 12.838 4 - BEFORE RENDER - 0ms - 10ms 09-03 05:00PM 12.838 5 - AFTER RENDER - 0ms - 10ms 09-03 05:00PM 12.838 ============================== 09-03 05:00PM 12.838 TOTAL TIME: 0:00:00.010875 (10ms) 09-03 05:00PM 12.838 ======END PROFILE REPORT======

The report shows you each mark with the description given when you called the mark() method.  Next it shows you the time between each mark section.  The first mark is showing you how long (in ms) it took between the starting time and the mark time.  The next mark shows you how long between mark 0 and 1 and so on.  The accumulative time is just that.  Finally, the total time shows you how long it took between the start() and stop() calls.

There may be better ways out there, but this is what I came up with real fast.  I've attached the source if you want it.  Maybe messy, but I had to put it together quick to test some sections of my code out.  I have some improvements in mind.

GAE definitely forces you to be efficient.  In my case, it turns out that most of the processing was in generating the JSON of the results and very little time was in the FETCH.  However, this is not consistent.  Sometimes, it seems to take GAE much longer to both FETCH and access the memcache.

Posted via email from bvelasquez's posterous

Another deployment of JacobSix

I'm up again until midnight working on JacobSix.  This will catch up to me soon and I'll definitely crash and burn for a few days.  Going to sleep at midnight and waking at 5:00 AM with the boys is taking its toll.  However, the positive side is that JacobSix is getting better every day.  I worked all night working out bugs with the Invitation workflow.  A major mess, but I think I have it cleaned up.  There were quite a few other issues that I cleaned up tonight.  For example, the "More Charts" was broken if you are filtering on "With Milestones."  Turns out, GAE cannot do "__KEY__" only queries with an inequality filter ( != ).

Another bit of work is to try to increase performance in many of the Datastore queries.  I just don't think it's my issue after looking at the logs and seeing so many inconsistent numbers coming from GAE.  On one request, the processing time is 300ms.  Immediately after, the same exact query comes back as 2000ms.  I don't get it.  I did clean up the indexes, which may help a bit since half of them were not in use.

There's a ton more work to be done to handle errors a bit better.  I'll probably take a step back and clean things up before moving into the next half of this sprint.

If you tried JacobSix and like it, leave me a comment.

Posted via web from bvelasquez's posterous

More new features at JacobSix

Burned the midnight oil the last night and added the final two features of the "More" tab at JacobSix.  Notes and Links.  

Notes provides a simple WYSIWYG interface allowing HTML markup text entries.  You can pretty much put any HTML in the note and they are listed in order of update time.  The Notes keep a history of previous versions, which will eventually be exposed so you can rollback changes or view an older version.  For now, it's just a great way to keep information about a project.  Because it accepts HTML, you can embed iframes, which means video or any other embed that's out there.  I haven't tested the dangers of this, which I'm sure are many.  So for now, we'll give it a try and restrict the HTML later if necessary.

Links provides a place to keep any URL you want to save.  Bookmarks or Favorites basically.  However, like TaPingYa (the messaging application), the Links will be collected automatically from around the project.  So, if you post a message to the Project that has a URL, it will automatically be saved in your Links.  You can delete these later if you want.  This just makes it easy to see all those URL's that get posted in various places.  The auto collection is not complete yet, but soon.

I also added some logic to check the state of Google App Engine.  The service goes down for maintenance now and then, so JacobSix needs to handle this better.  I put some code in place to deal with this, but messed up the logic so it didn't go down so well.  Next time!

Posted via web from bvelasquez's posterous