oaeproject/Hilary — pull request #878 by mrvisser (2014-04-28 21:35:55+00:00)
Title: Intermittent Test Failure: Tenant Creation and Configuration

I caught an intermittent failure, the error was that a user was attempted to be created as anonymous but recaptcha was enabled. Log snippet:

```
[2014-04-28T19:43:54.876Z] INFO: oae-authentication/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: Enabling strategy (tenant=private1-ekOVYjVPa, strategy=signed, passportStrategyName=private1-ekOVYjVPa-signed)
[2014-04-28T19:43:54.877Z] TRACE: oae-cassandra/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: Executed cassandra query. (rows=[])
query: SELECT "configKey", "value", WRITETIME("value") FROM "Config" WHERE "tenantAlias" = ?
--
parameters: [
"private1-ekOVYjVPa"
]
[2014-04-28T19:43:54.876Z] INFO: oae-authentication/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: Refreshed authentication strategies for tenant
tenant: {
"alias": "private1-ekOVYjVPa",
"displayName": "private1-ekOVYjVPa",
"host": "private1-ekovyjvpa",
"active": true,
"deleted": false,
"isGlobalAdminServer": false
}
[2014-04-28T19:43:54.937Z] TRACE: oae-cassandra/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: Executed cassandra query.
query: BEGIN BATCH
UPDATE "Config" SET "value" = ? WHERE "tenantAlias" = ? AND "configKey" = ?;
APPLY BATCH;
--
parameters: [
"false",
"private1-ekOVYjVPa",
"oae-principals/recaptcha/enabled"
]
[2014-04-28T19:43:54.879Z] INFO: oae-authentication/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: Enabling strategy (tenant=private1-ekOVYjVPa, strategy=local, passportStrategyName=private1-ekOVYjVPa-local)
[2014-04-28T19:43:54.938Z] TRACE: request-log/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: REST Request complete (body=OK)
[2014-04-28T19:43:54.879Z] INFO: oae-authentication/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: Enabling strategy (tenant=private1-ekOVYjVPa, strategy=signed, passportStrategyName=private1-ekOVYjVPa-signed)
[2014-04-28T19:43:54.938Z] TRACE: request-log/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: Performing REST request (url=/api/user/create, method=POST)
restCtx: {
"host": "http://localhost:2001",
"hostHeader": "private1-ekOVYjVPa",
"cookieJar": {
"_jar": {
"store": {
"idx": {}
}
}
},
"strictSSL": true
}
--
data: {
"username": "administrator",
"password": "administrator",
"displayName": "Tenant Administrator"
}
[2014-04-28T19:43:54.879Z] INFO: oae-authentication/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: Refreshed authentication strategies for tenant
tenant: {
"alias": "private1-ekOVYjVPa",
"displayName": "private1-ekOVYjVPa",
"host": "private1-ekovyjvpa",
"active": true,
"deleted": false,
"isGlobalAdminServer": false
}
[2014-04-28T19:43:54.948Z] TRACE: oae-cassandra/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: Executed cassandra query.
query: SELECT "configKey", "value", WRITETIME("value") FROM "Config" WHERE "tenantAlias" = ?
--
parameters: [
"private1-ekOVYjVPa"
]
--
rows: [
{
"0": {
"name": "configKey",
"value": "oae-principals/recaptcha/enabled",
"timestamp_micro": 1398714234948764,
"timestamp": "2014-04-28T19:43:54.948Z",
"ttl": null
},
"1": {
"name": "value",
"value": "false",
"timestamp_micro": 1398714234948823,
"timestamp": "2014-04-28T19:43:54.948Z",
"ttl": null
},
"2": {
"name": "writetime(value)",
"value": 1398714234825000,
"timestamp_micro": 1398714234948865,
"timestamp": "2014-04-28T19:43:54.948Z",
"ttl": null
},
"key": "",
"_map": {
"configKey": 0,
"value": 1,
"writetime(value)": 2
},
"_schema": {
"name_types": {
"writetime(value)": "UTF8Type",
"value": "UTF8Type",
"configKey": "UTF8Type"
},
"value_types": {
"writetime(value)": "org.apache.cassandra.db.marshal.LongType",
"value": "org.apache.cassandra.db.marshal.UTF8Type",
"configKey": "org.apache.cassandra.db.marshal.UTF8Type"
},
"default_name_type": "UTF8Type",
"default_value_type": "UTF8Type"
},
"length": 3,
"count": 3
}
]
[2014-04-28T19:43:54.951Z] INFO: oae-authentication/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: Enabling strategy (tenant=private1-ekOVYjVPa, strategy=local, passportStrategyName=private1-ekOVYjVPa-local)
[2014-04-28T19:43:54.951Z] INFO: oae-authentication/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: Enabling strategy (tenant=private1-ekOVYjVPa, strategy=signed, passportStrategyName=private1-ekOVYjVPa-signed)
[2014-04-28T19:43:54.951Z] INFO: oae-authentication/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: Refreshed authentication strategies for tenant
tenant: {
"alias": "private1-ekOVYjVPa",
"displayName": "private1-ekOVYjVPa",
"host": "private1-ekovyjvpa",
"active": true,
"deleted": false,
"isGlobalAdminServer": false
}
[2014-04-28T19:43:55.025Z] ERROR: request-log/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: An error occurred sending a REST request (body="Invalid reCaptcha token")
err: {
"code": 400,
"msg": "Invalid reCaptcha token"
}
[2014-04-28T19:43:55.035Z] INFO: before-tests/10449 on testing-worker-linux-3-2-29832-linux-12-23959175: Finishing test "verify discussion share permissions"
```

I *think* what happened was:

1. In `oae-tests/lib/util.js#createTenantWithAdmin` we create a tenant
2. This triggers an `oae-config` event in `oae-tenants/lib/api.js` that will asynchronously load the tenant config and that fun stuff
3. In `oae-tests/lib/util.js#createTenantWithAdmin` we proceed to disable recaptcha VIA config update and also listen for the tenant's config event

There is probably a race condition right there where it is possible for the "wait" portion of the updateConfigAndWait to catch the tenant creation's config event and proceed before the configuration has been refreshed with recaptcha disabled, thereby trying to create a user anonymously with recaptcha enabled.

I'll submit a PR for a `TenantsTestUtil.createTenantAndWait` method to squash this one. Hopefully it works.