| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-05-03 | |||
| 15:26:43 | bauzas | dansmith: mriedem: FWIW, most of the Upstream Training attendees previously were trying to look at devstack and provide a change against a project | |
| 15:27:24 | bauzas | dansmith: mriedem: now that the Institute doesn't really provide devstack, I think they just want to have some technical discussions :) | |
| 15:29:01 | openstackgerrit | Gábor Antal proposed openstack/nova master: Transform aggregate.add_host notification https://review.openstack.org/396210 | |
| 15:31:41 | mriedem | dansmith: i've wondered the same, and i saw the cinder etherpad at one point | |
| 15:31:45 | mriedem | but can't find it now | |
| 15:32:29 | mordred | efried: nice! looking now | |
| 15:35:05 | mriedem | smcginnis: where is your guys' cinder onboarding etherpad? | |
| 15:35:12 | mriedem | kevinbenton: ^ do you guys have one? | |
| 15:35:36 | giuseppe1992 | Hello all!!! | |
| 15:38:12 | openstackgerrit | Gábor Antal proposed openstack/nova master: Transform aggregate.add_host notification https://review.openstack.org/396210 | |
| 15:38:53 | mordred | efried: oh - also - I'm making the patch to keystoneauth right now to deal with teh service type list - so hopefully we can make a follow up soon to your patch to consume that .. | |
| 15:39:31 | openstackgerrit | Mathieu Gagné proposed openstack/nova master: Add ability to signal and perform online volume size change https://review.openstack.org/454322 | |
| 15:41:45 | mordred | efried: patch looks mostly great on first read - excellent work -I've got a few nitpicky things I'll leave in just a bit | |
| 15:44:34 | openstackgerrit | Gábor Antal proposed openstack/nova master: Transform aggregate.remove_host notification https://review.openstack.org/396211 | |
| 15:45:23 | smcginnis | mriedem: I dont believe we have an etherpad for that. | |
| 15:47:51 | efried | mordred Roger that, and thanks. | |
| 15:48:11 | efried | mordred Please add me to that service type list patch once it's up. | |
| 15:48:42 | mordred | will do! | |
| 15:49:35 | efried | mordred I will certainly do that, for whatever it's worth. I still have your ML threads awaiting deeper dives. | |
| 15:54:41 | jaypipes | mriedem: works for me. I'll be on IRC all day of course. | |
| 15:55:00 | jaypipes | mriedem: well, after around 9:30am EDT... it's Thursday morning golf before that. :) | |
| 15:56:03 | mriedem | ooo this looks like a new fun gate bug http://logs.openstack.org/73/461473/3/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/a277636/logs/screen-n-cpu.txt.gz#_May_02_17_49_07_771248 | |
| 15:57:08 | jaypipes | mriedem, sdague: are we still seeing issues with the live-migration jobs? | |
| 15:57:18 | mriedem | jaypipes: no | |
| 15:57:27 | mriedem | cells v1 job is the main failure right now | |
| 15:59:12 | dansmith | FWIW, it looks like my job is going to pass without journal usage | |
| 15:59:13 | dansmith | I'm not sure that makes sense | |
| 15:59:22 | dansmith | I was hoping to just get the rest of my debug with that hack, | |
| 15:59:36 | dansmith | but I suppose it's possible that it's occasionally causing us to deadlock something | |
| 15:59:46 | dansmith | I'll recheck a few times to see if I just got uber lucky this time | |
| 16:07:50 | sdague | dansmith: ok, cool | |
| 16:08:02 | sdague | I did one more tweak on my general patch, once that's passes, I'll get that in | |
| 16:08:11 | dansmith | sdague: that "okay cool" was for the rechecking right? | |
| 16:08:16 | dansmith | I was not expecting it to actually make it pass | |
| 16:08:24 | dansmith | I was expecting it to let me see my own debug for the real failure | |
| 16:08:49 | sdague | yes, for rechecking | |
| 16:09:16 | sdague | ok, so someone that understands more about eventlet than might be needed to understand why this fails | |
| 16:11:02 | sdague | https://github.com/systemd/python-systemd/blob/c06c5d401d60ae9175367be0797a6c2b562ac5ba/systemd/journal.py#L412-L457 is the function we're calling into | |
| 16:11:54 | sdague | https://github.com/systemd/python-systemd/blob/c06c5d401d60ae9175367be0797a6c2b562ac5ba/systemd/_journal.c which I goes into native code | |
| 16:12:17 | sdague | jaypipes so presumably related to the same reason gRPC doesn't work | |
| 16:15:41 | mriedem | melwitt: ^ see in that first link to journal.py "MESSAGE must be a string and will be sent as UTF-8 to the journal." | |
| 16:16:03 | jaypipes | sdague: maybe, not sure though. the grpc vs. eventlet thing was around how grpc's generated python code doesn't play well with monkey-patched envs | |
| 16:17:01 | sdague | jaypipes: potentially similar issue? | |
| 16:17:09 | mriedem | sdague: was it intentional to enable syslog handler to put all of the service logs into syslog? because syslog is huge now, and basically unusable in a browser | |
| 16:17:26 | mriedem | http://logs.openstack.org/73/461473/3/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/a277636/logs/syslog.txt.gz | |
| 16:17:31 | jaypipes | sdague: maybe. I'm no eventlet expert though :( perhaps worth asking vstinner or dims to take a look into it. | |
| 16:17:46 | jaypipes | sdague: or perhaps one of the swift folks? | |
| 16:17:50 | sdague | mriedem: we didn't enable the syslog handler | |
| 16:17:54 | sdague | this is the journal | |
| 16:18:26 | sdague | mriedem: this is what things under systemd look like, we can trim what ends up in the extracted syslog.txt | |
| 16:18:29 | openstackgerrit | melanie witt proposed openstack/nova master: WIP Use six.text_type() when logging Instance object https://review.openstack.org/461912 | |
| 16:18:46 | mriedem | sdague: i thought this did something | |
| 16:18:47 | mriedem | https://github.com/openstack/oslo.log/commit/391635475a5877c2078856b5c3a7d2929682764a | |
| 16:18:49 | sdague | mriedem: https://github.com/openstack-infra/devstack-gate/blob/87a9ef290fa371862f30702497238fffdfdfe8fe/functions.sh#L647-L649 | |
| 16:19:06 | sdague | mriedem: nope, unrelated | |
| 16:19:36 | dansmith | sdague: don't we have a global log lock or something? | |
| 16:20:01 | dansmith | that was the reason why logging in the db api was so problematic I think | |
| 16:20:17 | dansmith | we wouldn't have deadlocks in the same way here I think, but it could still be a problem | |
| 16:20:20 | melwitt | mriedem: okay. I wrote a better commit message to explain what I was seeing in local debugging. the ContextFormatter tries to convert every message to unicode, it was failing on the Instance object, and I found to convert it properly I had to specify the encoding to six.text_type() | |
| 16:20:32 | dansmith | we can't really hold any locks while making a native call or we're going to cause problems | |
| 16:23:28 | sdague | dansmith: I didn't think we did | |
| 16:23:31 | sdague | at least not in our code | |
| 16:23:48 | dansmith | not in nova, but I thought oslo.logging did or something | |
| 16:23:57 | sdague | oslo.logging is really thin | |
| 16:24:02 | dansmith | I didn't follow that whole thing way back then | |
| 16:24:11 | sdague | I don't think there is any locking there | |
| 16:24:38 | dansmith | okay, well, the problem was that we'd do a database thing, which would grab a lock in mysql, then do a logging statement, which would grab a lock, | |
| 16:24:45 | dansmith | and if the opposite was happening elsewhere, we'd deadlock | |
| 16:25:14 | dansmith | not sure how that would have happened if it wasn't a lock in oslo.logging or python. | |
| 16:25:19 | sdague | there is nothing that looks like a lock in oslo.logging | |
| 16:25:24 | dansmith | maybe logging to a file in python does a flock on the log file? | |
| 16:25:37 | sdague | maybe, but we're not doing that here | |
| 16:25:50 | dansmith | no, I know, | |
| 16:26:03 | dansmith | I'm just trying to point to something similar that may be happening | |
| 16:26:05 | melwitt | mriedem: this is where I saw it blowing up https://github.com/openstack/oslo.log/blob/3ee14a1/oslo_log/formatters.py#L83-L93 | |
| 16:26:28 | dansmith | with making a native call that could block | |
| 16:27:17 | sdague | dansmith: yeh | |
| 16:27:50 | sdague | so this eventually turns into a C sendmsg to push things over the unix domain socket for systemd | |
| 16:28:11 | sdague | anyway, I'm going to drop the debug thread here, as I'm over my depth on what bits of eventlet would make it weird | |
| 16:29:44 | mriedem | melwitt: here https://github.com/openstack/oslo.log/blob/3ee14a1/oslo_log/formatters.py#L89 ? | |
| 16:30:28 | melwitt | mriedem: eh, I'm not sure how I saw that locally now that I think about it. it's not the same as what we see in the gate | |
| 16:31:02 | sdague | melwitt: in the gate isn't it that we're sending it an Instance Object | |
| 16:31:14 | sdague | it's implicitly turning it into a string with __repr__ | |
| 16:31:23 | sdague | and that is the thing that might be encoded weird? | |
| 16:31:45 | sdague | melwitt: at least, your work around seemed to imply that | |
| 16:31:52 | clarkb | the journald write is blocking I think | |
| 16:31:55 | melwitt | sdague: yeah. and then at the log message format() step it blows up but I don't know exactly how | |
| 16:31:59 | clarkb | but I don't know that it will hold a lock | |
| 16:32:17 | sdague | clarkb: I don't know, the man pages say it's thread safe | |
| 16:32:31 | sdague | which could mean locks in there | |
| 16:32:44 | sdague | it also keeps monotonic time (or can) which makes me wonder | |
| 16:32:46 | dansmith | or locks in journald that cause that call to block | |
| 16:32:53 | dansmith | even if not locks in the sending code | |
| 16:32:54 | sdague | but, it's a whole research bit on it's own | |
| 16:34:02 | clarkb | dansmith: well that call can block regardless of locks | |
| 16:34:11 | clarkb | because its a synchronous write | |
| 16:34:38 | dansmith | yeah | |
| 16:34:45 | melwitt | mriedem, sdague: in the gate it blows up here https://github.com/python/cpython/blob/master/Lib/logging/__init__.py#L338 | |
| 16:35:47 | sdague | melwitt: right | |
| 16:36:14 | sdague | but one of those args is an Instance | |