| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-05-16 | |||
| 18:21:38 | dansmith | ... print(len(threading.enumerate())) | |
| 18:21:38 | dansmith | sean-k-mooney: >>> def func2(): | |
| 18:21:39 | dansmith | test | |
| 18:21:40 | dansmith | 1 | |
| 18:21:48 | dansmith | sean-k-mooney: only one thread running from inside the thread function | |
| 18:21:53 | dansmith | so it's sequential | |
| 18:22:44 | dansmith | the test came from another thread I spawned first (like your example) which hadn't been waited on | |
| 18:22:53 | dansmith | normally enumerate() returns one for the main thread all the time, | |
| 18:23:08 | dansmith | so 1 means it didn't spawn something else for func2() | |
| 18:24:33 | dansmith | so one thing we could do in the interim is, | |
| 18:24:53 | dansmith | provide a knob to let them avoid the monkeypatch without having to actually patch the code, if they prefer synchronous behavior | |
| 18:25:22 | dansmith | that isn't too terrible for people with just the default two cells, and the rest of the people who don't suffer from this can continue to do what we do today | |
| 18:26:21 | melwitt | I think that's already available in the form of an env variable. which is what this tripleo patch is proposing to turn off monkey patching https://review.opendev.org/#/c/657168/1/deployment/nova/nova-api-container-puppet.yaml | |
| 18:26:38 | dansmith | melwitt: ah even better :) | |
| 18:27:00 | sean-k-mooney | dansmith: it is concurrent however | |
| 18:27:03 | sean-k-mooney | if i do | |
| 18:27:06 | sean-k-mooney | >>> def func(): | |
| 18:27:08 | sean-k-mooney | ... eventlet.greenthread.sleep(10) | |
| 18:27:10 | sean-k-mooney | ... global i | |
| 18:27:12 | sean-k-mooney | ... i+=1 | |
| 18:27:14 | sean-k-mooney | ... print(i) | |
| 18:27:16 | sean-k-mooney | ... | |
| 18:27:18 | sean-k-mooney | >>> i = 0 | |
| 18:27:20 | sean-k-mooney | >>> gt = eventlet.greenthread.spawn(func) | |
| 18:27:22 | sean-k-mooney | >>> gt = eventlet.greenthread.spawn(func) | |
| 18:27:24 | sean-k-mooney | >>> gt = eventlet.greenthread.spawn(func) | |
| 18:27:26 | sean-k-mooney | >>> gt = eventlet.greenthread.spawn(func) | |
| 18:27:28 | sean-k-mooney | >>> gt.wait() | |
| 18:27:30 | sean-k-mooney | it does not take 40 secods to print | |
| 18:27:50 | dansmith | sean-k-mooney: because you're using eventlet's sleep right? | |
| 18:27:58 | sean-k-mooney | yes | |
| 18:28:12 | imacdonn | mnaser (if still awake?), dansmith, sean-k-mooney: log from the failure-to-reconnect case: http://paste.openstack.org/show/751486/ | |
| 18:28:24 | dansmith | that does't mean it's concurrent, that means it's warping time for you :) | |
| 18:31:59 | mnaser | Looks like conductor yoking our | |
| 18:32:05 | mnaser | Timing out | |
| 18:32:31 | mnaser | I’ve seen really weird behaviour thy usually gets resolved by deleting every single queue in the vhost | |
| 18:33:34 | sean-k-mooney | dansmith: well in anycase i think we now now why its working if you dont monkeypatch | |
| 18:33:53 | dansmith | yup, as expected | |
| 18:33:54 | sean-k-mooney | there it concurant of fully synconous i dont know | |
| 18:35:51 | dansmith | sean-k-mooney: run this and tell me what you think :) https://pastebin.com/XHV9t9cM | |
| 18:36:01 | imacdonn | mnaser: this happens when the monkey patching is used in combination with a wsgi container ... and doesn't happen otherwise | |
| 18:36:32 | dansmith | sean-k-mooney: one single wait, but it clearly runs them in order, and blocking calls block everything | |
| 18:36:43 | melwitt | imacdonn: not sure what else to try other than a python2 devstack test maybe, to try and pinpoint what is the difference in your env vs the others. mnaser, are you running stein under py3 or py2? | |
| 18:37:28 | imacdonn | melwitt: yeah, thought about py2 devstack too | |
| 18:40:59 | sean-k-mooney | yes it took 53 seconds | |
| 18:41:04 | sean-k-mooney | but https://pastebin.com/QN5L7yDY took 5 | |
| 18:41:20 | sean-k-mooney | time.sleep will suppend the thread | |
| 18:41:44 | sean-k-mooney | eventlet.greenthread.sleep shoudl yeild to the next coroutine | |
| 18:41:52 | dansmith | sean-k-mooney: ah I see what you mean.. we will still get *interleaving* but not actual concurrency | |
| 18:42:15 | dansmith | sean-k-mooney: meaning we're not running multiple concurrent threads, but we will interleave their execution when they do stuff that calls into eventlet | |
| 18:42:20 | sean-k-mooney | we will get concurrency but not parrallisium | |
| 18:42:36 | sean-k-mooney | yes | |
| 18:42:42 | dansmith | sean-k-mooney: the thing I think you're missing is that if we haven't monkeypatched, then all our IO is blocking and so the first thing will be like time.sleep() andnot like eventlet.sleep() | |
| 18:43:20 | dansmith | first thing meaning first bit of IO | |
| 18:44:14 | sean-k-mooney | ya i was onding if we could import eventlet.green or somting | |
| 18:44:16 | sean-k-mooney | https://eventlet.net/doc/patching.html#import-green | |
| 18:44:38 | sean-k-mooney | our use a contex manger to patch or jsut the socket lib | |
| 18:45:12 | dansmith | I think that gets us further into the mixing paradigms state and confusion abounds, IMHO | |
| 18:45:25 | sean-k-mooney | ya perhaps | |
| 18:45:51 | sean-k-mooney | so we orginally merged the new scater gather stuff that used eventlests without monkey patching | |
| 18:46:09 | sean-k-mooney | then we noticed we were not monkeypatch and mdbooth fixed that | |
| 18:46:22 | dansmith | *for api running under wsgi | |
| 18:46:23 | sean-k-mooney | and we strated to see these uwsgi errors | |
| 18:46:31 | sean-k-mooney | ya | |
| 18:48:01 | sean-k-mooney | so setting the env var would allow people to go back to the un monkeypatched versions under wsgi with no code change but its nolonger paralle | |
| 18:48:11 | dansmith | exactly | |
| 18:48:36 | sean-k-mooney | although in that case uwsgi/apache would still provde its own concurancy | |
| 18:49:06 | dansmith | sean-k-mooney: between requests, but not between cells | |
| 18:49:14 | dansmith | cells would still be sequential | |
| 18:49:19 | sean-k-mooney | yes | |
| 18:49:44 | sean-k-mooney | im just thinking about what people can do as a workaound in the short term | |
| 18:50:04 | sean-k-mooney | e.g. what can people do that hit this in production | |
| 18:50:06 | dansmith | people being the 1.9 people we know that are having this problem right? :) | |
| 18:51:13 | sean-k-mooney | well i think the only reason that we are not seeing this in osp is because hte kolla container use the console-script in the container instead of running under wsgi | |
| 18:51:28 | sean-k-mooney | so i think that is why we are not hitting it downstream | |
| 18:51:47 | sean-k-mooney | but i dont know what other deployment tools default too | |
| 18:52:04 | dansmith | well, we got the vexxhost data that they're reconnecting properly | |
| 18:52:18 | sean-k-mooney | in osa | |
| 18:52:23 | sean-k-mooney | *with | |
| 18:52:24 | dansmith | so they're clearly seeing the same threading behavior, but not suffering | |
| 18:52:25 | dansmith | i.e. they're getting the best of both worlds | |
| 18:59:23 | sean-k-mooney | perhaps its because they are installing the nova api under uwsgi and not mod_wsgi | |
| 18:59:52 | sean-k-mooney | imacdonn: what are you running the nova-api with? | |
| 19:00:45 | imacdonn | sean-k-mooney: uWSGI ... I've also reproduced the heartbeats not happening with mod_wsgi, but I can't say if I've seen the failure to "establish a new connection and move on" in that case | |
| 19:01:39 | sean-k-mooney | we know that uwsgi and mod_wsgi handel the lifetime of there python interperters diffrently so model level variable are reinitalised in uwsgi but are not in mod_wsgi becuase it reuses the interpreter when the app is reloaded an uwisg does not | |
| 19:01:54 | sean-k-mooney | *module level | |
| 19:02:45 | sean-k-mooney | imacdonn: if the wsgi app dies and is restarted by uwsgi it will return to a clean state | |
| 19:03:11 | sean-k-mooney | in the mod_wsgi case it will reuse the interperter and maybe that impact the reconnection | |
| 19:03:16 | sean-k-mooney | that is a strech however | |
| 19:03:48 | sean-k-mooney | we are seeing it not reconnect on mod_wsgi correct? | |
| 19:04:05 | imacdonn | I don't see any evidence of the app dying and being restarted | |
| 19:04:50 | melwitt | sean-k-mooney: we're not sure what the common denominator is for not reconnecting and 500ing, I think | |
| 19:05:18 | melwitt | I have a python2 devstack, going to check whether it reconnects | |
| 19:05:20 | sean-k-mooney | if it was you would see nova print it config again and all the other start up stuff so if you are not seeing that its proably not happening then | |
| 19:05:43 | sean-k-mooney | ok that is testing with uwsgi then | |
| 19:05:49 | imacdonn | yeah .. the 504 error seems to be caused by an RPC timeout following the reconnect ... don't yet know why I'm seeing that where others are not | |
| 19:06:31 | sean-k-mooney | do we have any periodic task that could be keeping it alive? | |
| 19:06:39 | imacdonn | I can't say I've reproduced the RPC timeout with mod_wsgi - was focused on the absence of heartbeats before | |
| 19:07:08 | dansmith | sean-k-mooney: if you read the backscroll, it has been reprod with both | |
| 19:07:30 | imacdonn | I'm not able to reproduce the RPC timeout with py2 devstack either | |