| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-05-15 | |||
| 16:39:45 | openstackgerrit | Matt Riedemann proposed openstack/nova stable/rocky: Add functional confirm_migration_error test https://review.opendev.org/658834 | |
| 16:39:46 | mriedem | ganso: ^ | |
| 16:44:40 | ganso | mriedem: thanks! will rebase on top | |
| 16:45:09 | ganso | mriedem: oh you already rebased | |
| 16:45:11 | ganso | mriedem: thanks! | |
| 16:45:30 | imacdonn | mriedem: pls add https://review.opendev.org/#/c/653065/ to your tab queue for revisit? I have a feeling that the issue with the functional tests has something to do with sqlalchemy sessions, or something, but may be off on the wrong track | |
| 16:45:47 | imacdonn | (if there's a sqlalchemy guru available for a consult, that might work too) | |
| 16:45:56 | weshay | kashyap ping.. looking to add the qemu-agent rpm to nova, I think that would be on a container and not bm.. not sure also wanted to verify w/ you which container that rpm should be installed on | |
| 16:46:23 | weshay | kashyap context is: nova.exception.QemuGuestAgentNotEnabled: QEMU guest agent is not enabled | |
| 16:46:31 | weshay | https://bugs.launchpad.net/tripleo/+bug/1824315 | |
| 16:46:32 | openstack | Launchpad bug 1824315 in tripleo "periodic fedora28 standalone job failing at test_volume_boot_pattern" [Critical,In progress] - Assigned to Quique Llorente (quiquell) | |
| 16:47:21 | weshay | melwitt maybe you would know? ^ | |
| 16:50:07 | melwitt | weshay: the qemu guest agent is something that would have to be installed on the guest, which is currently not done as part of any CI that I'm aware of | |
| 16:50:40 | weshay | melwitt ok.. some folks were saying the container but the bm makes more sense to me | |
| 16:50:54 | melwitt | that is, if you create a nova instance, you'd then have to install the qemu guest agent on that guest after it comes up | |
| 16:52:06 | melwitt | but I'm wondering why it should be needed | |
| 16:52:42 | dansmith | if they're trying to do something that requires it, like quiesce disks (I think) | |
| 16:53:04 | melwitt | weshay: that error message is just saying it's going to skip quiescing the instance bc the guest agent isn't present, but it shouldn't fail the job because of that I don't think | |
| 16:53:34 | weshay | melwitt it does not fail consistently, maybe 1/10 times | |
| 16:53:43 | weshay | maybe this is a red herring | |
| 16:54:08 | dansmith | if it's failing on the guest agent really not being there 1/10 times, I'd suspect the guest isn't booting fully 1/10 times or something like that | |
| 16:54:24 | melwitt | weshay: ok. I don't think this is the root cause of the failure because AFAICT it's just skipping that. it should say that every time I think | |
| 16:55:09 | melwitt | dansmith: I don't think any CI installs the guest agent, at least I was not aware of any | |
| 16:55:26 | openstackgerrit | Merged openstack/python-novaclient master: Cap sphinx for py2 and drop keyring dependency https://review.opendev.org/659202 | |
| 16:55:26 | dansmith | melwitt: if they are using a fedora guest... | |
| 16:55:44 | melwitt | dansmith: fedora guest has it by default? | |
| 16:56:01 | weshay | dansmith ya.. we this in fedora deployments.. but w/ cirros guest | |
| 16:56:07 | dansmith | melwitt: no idea, I'm just saying, different from a cirros guest | |
| 16:56:09 | dansmith | okay | |
| 16:56:26 | dansmith | the bug shows a big stack trace.. melwitt you think we're logging that trace just while checking the skip? | |
| 16:56:50 | melwitt | oh. yeah, anecdotally I've not had the qemu guest agent come with any cloud image, like centos for example I've used | |
| 16:56:59 | melwitt | dansmith: I think so, opening up the code to confirm | |
| 16:57:31 | dansmith | okay we should not be logging a trace for a check thing, amirite? | |
| 16:58:04 | melwitt | should not, no. I see a LOG.info for it but no re-raise, so not yet sure what's going on | |
| 16:58:26 | dansmith | that's why I'm wondering if we're actually leaking the exception out and not just skipping | |
| 16:58:58 | melwitt | yeah, let's see, the trace is happening in the driver, so that must be where | |
| 16:59:08 | melwitt | there's no re-raise in compute/api, I meant | |
| 17:06:41 | cdent | efried: is ocata nova still an active concern? there's a logging buglet in the reasource tracker + report client that can be pretty misleading but the issue goes away with pike (or maybe queens) | |
| 17:09:19 | cdent | (goes away with pike, just checked) | |
| 17:16:29 | melwitt | weshay: on your latest comment on LP, the log shows the code continuing on to do the volume snapshot http://logs.openstack.org/84/655684/2/check/tripleo-ci-fedora-28-standalone/eda3002/logs/undercloud/var/log/containers/nova/nova-api.log.txt.gz#_2019-05-13_16_03_50_120 so I think that trace is unrelated | |
| 17:17:03 | melwitt | weshay: I don't yet find how that trace is getting logged (it shouldn't be logged), so I'm still looking for how that's happening | |
| 17:17:34 | weshay | k k.. thanks.. so melwitt we're saying it's a red herring and the problem is elsewhere right? | |
| 17:17:43 | weshay | confirming that I guess | |
| 17:18:47 | melwitt | weshay: right. the logging of the trace is bad and I'll have to find how that's occurring to remove it, but AFAICS the code is continuing on after skipping the quiesce and shouldn't affect the pass/fail of the CI | |
| 17:19:23 | melwitt | "Creating snapshot from volume" | |
| 17:19:59 | weshay | k | |
| 17:20:04 | weshay | arxcruz ^ | |
| 17:20:15 | melwitt | I'll look at the rest of those logs to see if I can tell where it's failing | |
| 17:22:20 | melwitt | weshay: looking at the test results of that run, the test_volume_boot_pattern passed but test_network_basic_ops failed due to a ssh timeout http://logs.openstack.org/84/655684/2/check/tripleo-ci-fedora-28-standalone/eda3002/logs/tempest.html.gz | |
| 17:22:56 | weshay | aye | |
| 17:23:24 | weshay | ya.. probably not same thing | |
| 17:23:36 | weshay | paste happy | |
| 17:23:39 | weshay | I guess | |
| 17:24:11 | melwitt | definitely not in this particular run. that run ^ failed because of a ssh timeout and test_volume_boot_pattern passed with the log trace | |
| 17:24:39 | tssurya | mriedem: trivial doc change: https://review.opendev.org/#/c/659067/ | |
| 17:32:28 | openstackgerrit | Merged openstack/os-resource-classes master: Replace git.openstack.org URLs with opendev.org URLs https://review.opendev.org/658519 | |
| 17:47:45 | mriedem | cdent: ocata is in extended maintenance meaning we can fix things if we want, but if it's not a big deal then meh | |
| 17:50:05 | mriedem | i thought VIO was off ocata (and pike for that matter)? | |
| 17:51:28 | cdent | there are lots of supported customers back on ocata, and a few that are -2 or -4 releases from that.... | |
| 17:51:57 | mriedem | just tell those banks to upgrade | |
| 17:52:30 | mriedem | do you know if there was a specific fix in pike that fixes it? or was it some big refactor we wouldn't want to backport? | |
| 17:52:36 | mriedem | if it's something dumb easy and backports cleanly than whatever | |
| 17:53:17 | cdent | there was a refactor: the introduction of _ensure_resource_provider | |
| 17:53:47 | mriedem | well then that's probably not something we'll want to backport to ocata at this point | |
| 17:53:53 | cdent | quite | |
| 18:16:51 | openstackgerrit | Merged openstack/nova master: [Trivial doc change] Admin can overwrite the locked_reason of an owner https://review.opendev.org/659067 | |
| 19:08:52 | melwitt | mriedem: wondering if you might know anything about this... is it known or expected that the traceback will become part of the printed exception object when that exception occurred on the other side of an rpc call? example http://logs.openstack.org/72/650172/14/check/tempest-full-py3/61914af/controller/logs/screen-n-api.txt.gz#_May_08_08_52_36_106235 | |
| 19:09:41 | melwitt | in nova/compute/api.py, we're catching the exception and logging the exception object, which I thought should normally only contain the short message and not the traceback. but the traceback seems to also be part of that | |
| 19:10:48 | melwitt | I looked at exception_wrapper (from our @wrap_exception decorator) and expected_exceptions in oslo.messaging and didn't see how they could be adding the traceback. I wanted to ask you in case you've seen this before and already know what's going on | |
| 19:18:06 | mriedem | i want to say it's a thing in oslo.log if there is an exception in scope | |
| 19:19:00 | mriedem | which is what this is, it's logging the exception within an except block | |
| 19:19:45 | melwitt | hm, I think I found where it's added in oslo.messaging https://github.com/openstack/oslo.messaging/blob/40c25c2bde6d2f5a756e7169060b7ce389caf174/oslo_messaging/_drivers/common.py#L212 | |
| 19:20:08 | mriedem | remember this? https://github.com/openstack/oslo.log/commit/a63438cb5b12e2a6973fb0e1b0b9ebce2f8116b6#diff-e121e929b5792521de104c2db0d14d94 | |
| 19:20:17 | mriedem | oh, so, | |
| 19:20:21 | melwitt | if I'm understanding this code right, when oslo.messaging deserializes an exception, it tacks on the traceback to the normal message | |
| 19:20:26 | mriedem | if it's an rpc call, which this is, we need to use expected_exceptions on the compute manager method | |
| 19:20:28 | mriedem | are we doing that? | |
| 19:20:31 | melwitt | we are | |
| 19:21:01 | melwitt | https://github.com/openstack/nova/blob/master/nova/compute/manager.py#L8513 | |
| 19:21:46 | melwitt | oh hah, I forgot about that commit. reading.. | |
| 19:22:25 | mriedem | so my guess is it's related to that magic stuff oslo.log does when you're logging from within an except block | |
| 19:22:30 | mriedem | even if you're not passing exc_info=True | |
| 19:25:08 | melwitt | thanks, this gives me more to look into | |
| 19:25:14 | mriedem | https://github.com/openstack/oslo.log/blob/master/oslo_log/formatters.py#L120 should handle that i'd think, but idk | |
| 19:25:28 | mriedem | light up the doug signal | |
| 19:30:41 | melwitt | yeah... I don't think this has to do with the error summary (I'm having trouble remembering what that is, even with seeing the old commit). but rather that if we catch a remote exception, the 'message' attribute of the object is going to contain the traceback, so if we don't want to log a traceback, we can't be doing "LOG.info('stuff %s', exp)" | |
| 19:31:05 | melwitt | this log line is explicitly doing that | |
| 19:39:38 | efried | cdent: pike just went em, so I'm not sure how much attention we are (or should be) paying to ocata at this point. Probably only security vulnerabilities, kind of thing. | |
| 20:45:49 | mriedem | i'm still fixing shit back in pike so yeah it's still active-ish | |
| 20:46:40 | dansmith | is it easier to land things in pike than master? | |
| 20:46:48 | dansmith | because based on master these days, I'm guessing so | |
| 20:47:48 | artom | What's the company cores policy on stable stuff? | |
| 20:48:09 | artom | So for instance, would Mel be allowed to +W https://review.opendev.org/#/c/657125/ ? | |
| 21:04:16 | openstackgerrit | melanie witt proposed openstack/nova master: Stop logging traceback when skipping quiesce https://review.opendev.org/659374 | |
| 21:12:14 | melwitt | mriedem: now I know what format_message() is for ^ and also I found this, from 6 years ago https://github.com/openstack/nova/commit/86031940b313532606449c400bca64707be1797a | |
| 21:16:27 | mriedem | oh geez | |
| 21:16:34 | melwitt | yeah xD | |
| 21:16:47 | mriedem | if we should always be using format_message(), shouldn't we override __str__ or __repr__ or something for NovaExceptions? | |
| 21:17:50 | melwitt | I _think_ that the exception type for remote exceptions is actually generated dynamically by oslo.messaging, | |
| 21:18:15 | melwitt | *_Remote exceptions, and it overrides __str__ and __unicode__ to have the traceback in it | |