Adding opendatakit-developers@ to this, as the answers could be of interest
to other developers...
The error page: 'you may have exceeded quota' is displayed whenever the
server has an uncaught exception or otherwise returns a 500 error (internal
server error). It could have several causes, but the most likely is an
over-quota error. There is no way to be more specific with this error, as
it is using the static error page to present the error and, by the time you
have an over-quota exception, you can't reliably execute any java code to
diagnose the true cause.
If the appengine dashboard indicates that the app is not over-quota (no red
bars), and that the app is not currently subject to resource throttling
(this will be a small triangular ! warning just below the Billing Status
heading), then you should examine the Logs for the application (from the
appengine Dashboard, click on the 'Logs' link on the left sidebar). Look
first for log entries with Critical or Error entries. If none show up, then
look at warnings. The key warning to look for is the 'your request took
longer than 60 seconds, so AppEngine terminated it' warning. Otherwise,
any error within the ODK Aggregate code should generate a Critical or Error
entry.
···
-------------- As for profiling, I'd be interested in hearing your findings. Profiling AppEngine is problematic because you cannot glean any useful information from running in the development environment. ODK Aggregate is a bit odd in that it does not use Memcache because configuring that on Tomcat would have greatly complicated the installer. Instead, frequently-accessed values are cached within the Java layer and refreshed about every 3-6 seconds.AppEngine performance is definitely limited to what we can do with
BigTables datastores without using any indices beyond the default
one-dimensional indices (this is because our data tables are dynamically
constructed, and there is no Java API to dynamically construct composite
indices). There is very little optimization you can do for AppEngine
datastore interactions because of this -- the limitations are effectively
written into the code.
MySQL and PostgreSQL are much more flexible, and database profiling can be
used to create extra indices as needed to tailor and tune for performance,
and those extra indices will be used by the database to improve query
performance.
Additionally, MySQL and PostgreSQL databases both provide mechanisms for
tracking how many of each type of query or datastore action (insert/delete)
are performed (e.g., CRUD reports, query timing reports). So no
instrumentation is provided on that activity within ODK Aggregate.
AppEngine, however, provides no visibility into things like CRUD reports or
query timing reports.
To remedy that, code within ODK Aggregate periodically emits the equivalent
of a CRUD report (independent of the datastore used). This is a set of log
entries of the form:
2012-12-05 15:03:38.317
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: ---------- 2012-12-05T23:03:38.317+0000 @ 3892 ------------
I 2012-12-05 15:03:38.318
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: TASK_LOCK,0,0,0,0,0
I 2012-12-05 15:03:38.318
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: COST_LOGGING,1,1,0,0,0
I 2012-12-05 15:03:38.318
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: STRING_FIELD_LENGTHS,0,0,0,0,0
I 2012-12-05 15:03:38.318
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit.EXTREMELY_WIDE_FLAT_CORE,0,0,0,0,0
I 2012-12-05 15:03:38.319
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._backend_actions,0,0,6,0,0
I 2012-12-05 15:03:38.319
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._filter_group,0,0,0,0,0
I 2012-12-05 15:03:38.319
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._form_data_model,0,0,0,0,0
I 2012-12-05 15:03:38.319
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._form_info,4,52,0,0,0
I 2012-12-05 15:03:38.320
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._form_info_fileset,0,0,0,0,0
I 2012-12-05 15:03:38.320
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._form_info_manifest_bin,0,0,0,0,0
I 2012-12-05 15:03:38.320
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._form_info_submission_association,0,0,0,0,0
I 2012-12-05 15:03:38.320
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._form_info_xform_bin,22,22,0,0,0
I 2012-12-05 15:03:38.320
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._form_info_xform_blb,0,0,1,0,0
I 2012-12-05 15:03:38.321
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._form_info_xform_ref,1,1,0,0,0
I 2012-12-05 15:03:38.321
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._form_service_cursor,0,0,0,0,0
I 2012-12-05 15:03:38.321
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._fusion_table,0,0,0,0,0
I 2012-12-05 15:03:38.321
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._fusion_table_repeat,0,0,0,0,0
I 2012-12-05 15:03:38.322
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._granted_authority_hierarchy,1,13,0,0,0
I 2012-12-05 15:03:38.322
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._misc_tasks,0,0,0,0,0
I 2012-12-05 15:03:38.322
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._persistent_result_file_bin,0,0,0,0,0
I 2012-12-05 15:03:38.322
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._persistent_results,0,0,0,0,0
I 2012-12-05 15:03:38.322
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._registered_users,1,1,2,0,0
I 2012-12-05 15:03:38.323
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._security_revisions,0,0,7,0,0
I 2012-12-05 15:03:38.323
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._server_preferences,0,0,0,0,0
I 2012-12-05 15:03:38.323
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: opendatakit._user_granted_authority,2,2,0,0,0
I 2012-12-05 15:03:38.323
org.opendatakit.common.persistence.engine.DatastoreAccessMetrics
logUsage: -----------------------------------------
The comma-separated numbers are reset to zero after this report is logged,
and the 5 values correspond to:
- queries issued,
- rows of query results returned,
- count of gets (query by-primary-key),
- count of puts (insert/update),
- counts of deletes
These are reported against each table in the datastore (the string after
logUsage: and before the string of numbers).
They are reported for all datastores, so you should not see any significant
variation in these numbers when migrating from AppEngine to MySQL or
PostgreSQL.
To get the AppEngine-equivalent functionality to a longest-query report on
MySQL or PostgreSQL, there is a cost logging feature within ODK Aggregate
(and only within the AppEngine datastore).
If any query takes longer than the value of the
COST_LOGGING_MEGACYCLE_THRESHOLD in the COST_LOGGING table, then ODK
Aggregate will emit a log message with the query and the time the query
took. These are logged as Warnings to the log, and are the most common
warnings you'll see in the log.
An example of this is:
W 2012-12-05 15:03:39.029
org.opendatakit.common.persistence.engine.gae.ExecutionTimeLogger
intermediateLogging: 000268 intermediate Form.getForms[_form_info]
SELECT * FROM opendatakit._form_info WHERE _URI >=
md5:04f2a292201cba8fac41e968e19636e9 ORDER BY _URI
W 2012-12-05 15:03:39.029
org.opendatakit.common.persistence.engine.gae.ExecutionTimeLogger
wrapUp: 000316 final Form.getForms[_form_info]
The intermediate entry reports that the given query took 000268 units
to complete, and the final reports that the overall time was 000316
units.
By default, the unit threshold for logging long queries is 120 units. You
can use the Datastore Viewer via the appengine dashboard to change that
default up or down, as you see fit.
Mitch
On Tue, Feb 19, 2013 at 9:30 PM, Waylon Brunette wrb@cs.washington.eduwrote:
Amarjeet,****
There is also a timeout if the request takes longer than 60 seconds which
maybe showing up incorrectly as a quota issue. I assume you looked at your
appengine control panel when you got it. ****
Mitch has a bunch of cost logging built in and I don’t know what is
enabled or disabled in the current 1.3 release so I am going to let Mitch
answer the question since he will know what was included in the 1.3 release.
Waylon****
From: Amarjeet Singh [mailto:amarjeet@iiitd.ac.in]
Sent: Tuesday, February 19, 2013 8:21 PM
To: Waylon Brunette
Subject: Appspot quota****
Dear Waylon****
In one of our uses of ODK, we got quota error from appspot. We are sure
that we did not exceed any of the normal quotas.****
I was wondering if you ever received any such error from your other field
studies and what could be the suspected reason.****
We are also thinking of catching the quota exception in ODK and also do
profiling of the application (I was wondering if you are already doing the
same)****
This is all with respect to the released version of ODK.****
Thank you****
--
Best Regards****
Amarjeet Singh, ****
Asst. Professor, IIIT Delhi****
http://www.iiitd.edu.in/~amarjeet/ ****
--
Mitch Sundt
Software Engineer
http://www.OpenDataKit.org http://www.opendatakit.org/
University of Washington
mitchellsundt@gmail.com