| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2018-01-25 | |||
| 21:38:26 | mriedem | yeah | |
| 21:39:35 | melwitt | okay. I was wondering if it could be related to the stable branch cells v1 job 100% fails. libvirt is getting "connection broke" as though something is holding up the tpool and never letting it continue | |
| 21:39:55 | melwitt | (I noticed all the libvirt calls go through eventlet.tpool) | |
| 21:40:12 | melwitt | but the "cannot switch to a different thread" isn't in the logs anywhere | |
| 21:41:11 | melwitt | I've been investigating it but haven't figured out anything yet | |
| 21:41:58 | dansmith | the libvirt driver uses native threads properly | |
| 21:42:08 | dansmith | so it should be fine unless something has regressed (or was never right) | |
| 21:42:40 | dansmith | the connection issue with libvirt almost always means libvirtd crashed, | |
| 21:42:51 | dansmith | which happens a lot more than it should | |
| 21:43:59 | melwitt | yeah. in this case it hasn't crashed. it's as if something held it up so long that the connection dropped from not getting keepalive, or something like that | |
| 21:44:19 | Roamer` | melwitt, what OS is this happening on? Could it be the Ubuntu py27/eventlet problem? http://lists.openstack.org/pipermail/openstack-dev/2018-January/126580.html | |
| 21:44:34 | melwitt | I was wondering if any other library also using eventlet could have made it so it never switches back to the libvirt driver | |
| 21:44:46 | dansmith | melwitt: why do you say it hasn't crashed? | |
| 21:45:25 | melwitt | dansmith: because from syslog and libvirtd I couldn't find any crashing. unless I totally don't know what I'm looking at, which is possible | |
| 21:45:45 | dansmith | melwitt: link? | |
| 21:45:46 | melwitt | Roamer`: it's ubuntu xenial. and that's what I was wondering, but I'm still grasping at straws at this point | |
| 21:46:34 | melwitt | dansmith: here's an example from recently http://logs.openstack.org/04/536904/3/check/legacy-tempest-dsvm-cells/13aacfc/logs/screen-n-cpu.txt.gz#_2018-01-25_19_06_13_271 | |
| 21:50:24 | dansmith | hmm, empty journal on that one? | |
| 21:50:25 | dansmith | that's weird | |
| 21:51:26 | melwitt | I feel like I've seen that before | |
| 21:52:56 | dansmith | yeah, libvirtd doesn't look like it was restarted across that connection failure boundary | |
| 21:52:58 | mriedem | interestingly, it's the first guest to be created it looks like http://logs.openstack.org/04/536904/3/check/legacy-tempest-dsvm-cells/13aacfc/logs/libvirt/qemu/instance-0000000a.txt.gz | |
| 21:53:17 | dansmith | this would be the first time I've ever seen that symptom not associated with a crash | |
| 21:53:34 | dansmith | so I still feel a little doubtful, but it's certainly not as glaring as normal | |
| 21:53:41 | mriedem | makes me think of this https://review.openstack.org/#/c/526748/ | |
| 21:53:50 | mriedem | where guestfs on the first bring up runs in a tpool | |
| 21:53:56 | mriedem | to get the guestfs capabilities | |
| 21:54:14 | dansmith | so I wonder if it's something like qemu crashes and the libvirt thread we're talking to exits or something | |
| 21:54:23 | melwitt | yeah, that's kinda how I found that patch of yours mriedem | |
| 21:54:48 | dansmith | the journal should have dmesg in it to capture any segv | |
| 21:55:07 | dansmith | but we don't have qemu logs otherwise | |
| 21:55:10 | melwitt | I wonder if the journal collection on the jobs has been busted this whole time | |
| 21:55:32 | melwitt | or is it not always empty? | |
| 21:55:51 | dansmith | it wasn't busted a month or so ago | |
| 21:55:52 | melwitt | I haven't tried to look at it before | |
| 21:55:56 | melwitt | oh okay | |
| 21:56:24 | dansmith | I expect it would be in syslog too, but it's clearer in the journal | |
| 21:57:25 | melwitt | I didn't see anything that looked like crashing in syslog http://logs.openstack.org/04/536904/3/check/legacy-tempest-dsvm-cells/13aacfc/logs/syslog.txt.gz | |
| 21:57:38 | dansmith | 2018-01-25 19:06:13.215+0000: 3732: error : virKeepAliveTimerInternal:143 : internal error: connection closed due to keepalive timeout | |
| 21:57:45 | dansmith | is right before you get it in nova | |
| 21:59:13 | melwitt | where do you see that? libvirtd.log? | |
| 21:59:27 | dansmith | I think this is all in a separate thread in nova so it shouldn't be that nova is hung up and unable to do the keepalive bit, unless it's just system starvation of some sort | |
| 21:59:30 | dansmith | yeah, libvirt | |
| 21:59:50 | melwitt | damn | |
| 22:00:06 | dansmith | and nova is doing stuff milliseconds before that, so it's not hung I don't think | |
| 22:00:51 | dansmith | oh yeah in the nova log: | |
| 22:00:52 | dansmith | 2018-01-25 19:06:13.224 16016 INFO nova.virt.libvirt.driver [req-ea2c4c13-3bbe-4b35-a2b3-84976c11fc4b - -] Connection event '0' reason 'Connection to libvirt lost' | |
| 22:01:08 | dansmith | that's the real thread detecting the connection close | |
| 22:01:20 | dansmith | oooh, but | |
| 22:01:49 | dansmith | 2018-01-25 19:06:09.554 16016 DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: 9ebc51b2583b4f4da811e951e41068c9 __call__ /usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py:407 | |
| 22:01:50 | dansmith | 2018-01-25 19:06:13.218 16016 DEBUG nova.virt.libvirt.firewall [req-733b7704-8aa3-45a5-8798-67eab246baf8 tempest-InstanceActionsV221TestJSON-176157016 tempest-InstanceActionsV221TestJSON-176157016] Cannot find UUID for filter 'nova-instance-instance-0000000d-fa163e269665': 'Cannot recv data: Connection reset by peer' _get_filter_uuid /opt/stack/new/nova/nova/virt/libvirt/firewall.py:254 | |
| 22:02:00 | dansmith | that is five seconds apart with nothing in between | |
| 22:02:48 | openstackgerrit | Jim Rollenhagen proposed openstack/nova master: Add functional tests for virt driver get_traits() method https://review.openstack.org/538047 | |
| 22:02:58 | melwitt | hm | |
| 22:03:04 | dansmith | meh, I dunno, looking around that I don't think that's anything related to being stuck though | |
| 22:03:14 | dansmith | because that's the exact instant libvirt logs its message | |
| 22:06:48 | openstackgerrit | Jim Rollenhagen proposed openstack/nova master: Add functional tests for virt driver get_traits() method https://review.openstack.org/538047 | |
| 22:08:40 | jackie-truong | dansmit, mriedem: re: git commands | |
| 22:08:52 | jroll | mriedem: ^ see my comment there, fairly certain some of this traits stack is somewhat broken. probably fine to land as drivers aren't using it yet, but ya know. | |
| 22:09:12 | jackie-truong | i want to add a /new/ file (test_trusted_certs.py) to a patch in the middle of my patch stack | |
| 22:09:47 | jackie-truong | checking out the top of the patch stack, then adding and committing the file results in the file being added to the top patch | |
| 22:09:52 | mriedem | efried: https://gist.github.com/jimrollenhagen/384077e2ed606ee84051cb4a7f66c51c | |
| 22:10:08 | mriedem | jackie-truong: git rebase -i master | |
| 22:10:10 | dansmith | jackie-truong: right, so git rebase -i master, edit the middle patch, git add path/to/file, git commit --amend -a | |
| 22:10:14 | mriedem | jackie-truong: edit the commit you want to add the file to, | |
| 22:10:20 | mriedem | create said file, | |
| 22:10:22 | mriedem | git add <file> | |
| 22:10:25 | mriedem | git rebase --continue | |
| 22:11:06 | jackie-truong | ah, i rarely actually edit commits when rebasing from master. got it, thanks again | |
| 22:11:09 | efried | mriedem VMX ain't a standard trait, or a valid CUSTOM_ one. | |
| 22:11:22 | efried | jroll ^ | |
| 22:11:24 | mriedem | efried: it's in os-traits | |
| 22:11:29 | jroll | ^ | |
| 22:12:24 | mriedem | oh wait | |
| 22:12:25 | mriedem | i see | |
| 22:12:28 | mriedem | jroll: he's right | |
| 22:12:29 | efried | HW_CPU_X86_VMX ? | |
| 22:12:39 | mriedem | yeah, the traits are generated from their directory structure within os-traits | |
| 22:12:44 | jroll | oh gdi | |
| 22:12:54 | mriedem | https://docs.openstack.org/os-traits/latest/user/index.html | |
| 22:15:54 | jroll | mriedem: efried: that did it, now I feel dumb, thanks :) | |
| 22:16:08 | mriedem | don't feel dumb | |
| 22:16:16 | efried | For not understanding the bizarre architecture of os-traits? Yeah, what mriedem said. | |
| 22:16:30 | mriedem | ironicclient change is 85 in the gate | |
| 22:16:44 | efried | I always just GET /traits from the API to find my testable traits. | |
| 22:17:29 | efried | Because you'll also get tripped up by this one at some point in the future: Your compute's os-traits may not be the same as the placement server's os-traits. | |
| 22:18:35 | efried | which is why https://github.com/openstack/nova/blob/master/nova/scheduler/client/report.py#L1005-L1009 | |
| 22:22:13 | openstackgerrit | Jackie Truong proposed openstack/nova master: Reduce complexity of _from_db_object https://review.openstack.org/537728 | |
| 22:22:14 | openstackgerrit | Jackie Truong proposed openstack/nova master: Add trusted_certs to instance_extra https://review.openstack.org/537897 | |
| 22:22:14 | openstackgerrit | Jackie Truong proposed openstack/nova master: Add trusted_certs object https://review.openstack.org/489408 | |
| 22:22:15 | openstackgerrit | Jackie Truong proposed openstack/nova master: Implement certificate_utils https://review.openstack.org/479949 | |
| 22:22:15 | openstackgerrit | Jackie Truong proposed openstack/nova master: Add trusted_image_certificates to REST API https://review.openstack.org/486204 | |
| 22:25:17 | dansmith | woot | |
| 22:25:50 | dansmith | I shall gaze upon thy patches upon my return from a brief respite | |
| 22:25:51 | mriedem | melwitt: this makes me think about the eventlet/python thing in the ML https://review.openstack.org/#/c/537811/1 | |
| 22:26:10 | jackie-truong | *\o/* | |
| 22:26:29 | melwitt | are those pom poms? | |
| 22:28:05 | melwitt | mriedem: interesting | |
| 22:29:55 | melwitt | seems like it could be related. nothing makes too much sense so far, only cells v1 job is getting constant libvirt keepalive timeouts, starting about 10 days ago, and only on stable | |
| 22:30:10 | melwitt | pike and ocata | |