Index churn on initial idle

[kofalt]

If you boot the API and make no requests, you'll see index-creation churn in the logs:

15:47:01 scitran.api config.py  151:INFO Initializing database, creating indexes
15:47:01 scitran.api config.py  174:INFO Persisting configuration

15:55:01 scitran.api config.py  151:INFO Initializing database, creating indexes
15:55:01 scitran.api config.py  174:INFO Persisting configuration

15:56:01 scitran.api config.py  151:INFO Initializing database, creating indexes
15:56:01 scitran.api config.py  174:INFO Persisting configuration

It's pretty clear that config.initialize_db should only ever be called once.

[gsfr]

Hmm, curious. What's wrong with this logic? Something wrong in 177-178?

@nagem @rentzso Any ideas?

[rentzso]

@kofalt can you give us the full API log?
Was it a fresh start or the application was stopped and restarted?

[rentzso]

Some useful information would be which config item was requested and also the traceback.
Some logs inside the get_item method should help.

[kofalt]

Fresh start, but I don't have a 100% success rate. My initial theory was that it churns until a single request hits it, but I don't know about that anymore. My guess now is that we've got a race condition or the worker threads/processes aren't aware of each other's state.

I am doing some clean resets to try & get you a full API log. Will report back if I get one.

[kofalt]

Reproduced: https://gist.github.com/kofalt/7971dd1d644f9319945e

It looks like I was slightly mistaken. The first few requests are triggering the repetition, presumably once per python worker, or similar. It would seem that we'll want to move this logic to wherever is before uwsgi forks off the workers, or maybe use some uwsgi features to ensure same.

[gsfr]

Yup, that makes sense now. Not a race condition, but __config_persisted is a thread/process-local variable, so the db currently get's initialized once per uwsgi worker. We should probably use the db itself to determine whether is has been initialized, which will likely lead to a race condition, but that seems more acceptable than willfully initializing once per worker. Certainly a bug right now, but not a high priority one.

I'd like to keep this logic inside of our app, and not tie it to our execution environment.

@nagem Please work on a patch when you get a chance.

[rentzso]

This could be a good place to start:
http://uwsgi-docs.readthedocs.org/en/latest/Caching.html
or this
http://uwsgi-docs.readthedocs.org/en/latest/WebCaching.html

[kofalt]

Just a bump to mention that I can reliable reproduce this with my test cases, which hit the API heavily in parallel:

17:43:47 config.py:202 Initializing database, creating indexes
17:43:47 config.py:202 Initializing database, creating indexes
17:43:47 config.py:202 Initializing database, creating indexes
17:43:47 config.py:202 Initializing database, creating indexes
17:43:47 config.py:202 Initializing database, creating indexes
17:43:47 config.py:202 Initializing database, creating indexes
17:43:47 config.py:202 Initializing database, creating indexes
17:43:47 config.py:242 Persisting configuration
17:43:47 config.py:242 Persisting configuration
17:43:47 config.py:242 Persisting configuration
17:43:47 config.py:242 Persisting configuration
17:43:47 config.py:242 Persisting configuration
17:43:47 config.py:242 Persisting configuration
17:43:47 GET /api/does-not-exist => generated 67 bytes in 21 msecs (404)
...