| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-09-23 | |||
| 18:47:57 | sean-k-mooney | i have not checked devstack but yes | |
| 18:48:16 | sean-k-mooney | i think tha tdoes systemctl stop devstack@n=* effectivly | |
| 18:48:45 | dansmith | right | |
| 18:49:03 | sean-k-mooney | ya it does https://github.com/openstack/devstack/blob/master/lib/nova#L1047-L1059 | |
| 18:49:49 | mriedem | Sep 22 00:37:32.126839 ubuntu-bionic-ovh-gra1-0011664420 systemd[1]: Stopped Devstack devstack@n-sch.service. | |
| 18:49:53 | mriedem | Sep 22 00:45:55.359862 ubuntu-bionic-ovh-gra1-0011664420 systemd[1]: Started Devstack devstack@n-sch.service. | |
| 18:50:42 | dansmith | mriedem: do we even stop/start mysql in grenade during the upgrade? | |
| 18:50:44 | mriedem | Sep 22 00:37:27.786606 ubuntu-bionic-ovh-gra1-0011664420 nova-scheduler[25563]: INFO oslo_service.service [None req-91e88f0d-9b5c-4cb7-a5e9-e7309f922832 None None] Caught SIGTERM, stopping children | |
| 18:50:46 | mriedem | yeah not a HUP | |
| 18:50:54 | mriedem | dansmith: pretty sure we don't | |
| 18:51:21 | dansmith | mriedem: yeah, so, pretty weird that it connects and works once and then times out later, because it's not like we restart mysql after that point or something | |
| 18:51:35 | dansmith | mriedem: so I wonder if we're actually doing something other than what we think | |
| 18:51:48 | dansmith | and since we don't log a trace there we don't know where it's actually timing out | |
| 18:52:46 | openstackgerrit | Dustin Cowles proposed openstack/nova-specs master: Spec: Provider config YAML file https://review.opendev.org/680471 | |
| 18:59:17 | openstackgerrit | Matt Riedemann proposed openstack/nova master: Log CellTimeout traceback in scatter_gather_cells https://review.opendev.org/684118 | |
| 18:59:18 | mriedem | dansmith: thinking like this? ^ | |
| 19:00:13 | dansmith | mriedem: yeah, I mean we kinda specifically decided not to explode there so we're tolerant of transient failures | |
| 19:00:26 | dansmith | I wonder if we should log debug with exc_info=True and warning without or something | |
| 19:00:31 | dansmith | but yeah, something | |
| 19:01:01 | mriedem | was thinking about passing down a kwarg to scatter_gather_cells to tell it what to do, but that's probably icky | |
| 19:01:12 | mriedem | trace_on_timeout = kwargs.pop('trace_on_timeout', False) | |
| 19:01:27 | dansmith | yeah, I don't like that | |
| 19:02:03 | dansmith | I love **kwargs behavior in python, but hate kwargs.pop('arg', None) abuses of it | |
| 19:02:09 | dansmith | which is why we can't have nice things in other languages :) | |
| 19:05:20 | dansmith | mriedem: so you just need to recheck that a few times to get a repro on it yeah? | |
| 19:06:26 | mriedem | maybe if we get lucky http://status.openstack.org/elastic-recheck/#1844929 | |
| 19:06:53 | mriedem | it mostly only shows up on certain node providers | |
| 19:07:00 | mriedem | so if i hit a rax node i likely won't see it | |
| 19:07:10 | mriedem | and only grenade jobs for some reason | |
| 19:07:15 | mriedem | something getting f'ed up in restarts | |
| 19:07:23 | sean-k-mooney | mriedem: which node providers? | |
| 19:07:31 | mriedem | fort nebula and ovh | |
| 19:07:54 | dansmith | mriedem: you should put that in the bug | |
| 19:07:56 | sean-k-mooney | we can target fort nebula using a specific node pool lable | |
| 19:08:00 | dansmith | so people can know and don't have to ask | |
| 19:08:04 | sean-k-mooney | im not sure about ovh | |
| 19:08:28 | mriedem | dansmith: from the bug, "It also appears to only show up on fortnebula and OVH nodes, primarily fortnebula." | |
| 19:08:34 | sean-k-mooney | but we coudl try and repoducice it via FN if you thing that was useful | |
| 19:08:38 | dansmith | mriedem: I know :) | |
| 19:08:44 | mriedem | i see what you did there | |
| 19:09:00 | dansmith | haha | |
| 19:11:20 | hemna | so I still can't seem to run tox -epy27 on anything less than stable/rocky | |
| 19:11:24 | hemna | queens and pike both fail | |
| 19:11:35 | hemna | http://paste.openstack.org/show/778953/ | |
| 19:11:56 | hemna | 6444 failures, all the same type of failure. sqlalchemy.exc.NoSuchTableError: migration_tmp | |
| 19:12:11 | dansmith | hemna: clean your local directory | |
| 19:12:16 | hemna | I did | |
| 19:12:21 | donnyd | Is this job CPU bound? | |
| 19:12:22 | hemna | nuked all pyc files and .tox | |
| 19:12:27 | dansmith | er, well, maybe not with that _tmp prefix | |
| 19:12:44 | dansmith | hemna: yeah, normally that comes from stale migration pycs but I think this is something else | |
| 19:14:23 | mriedem | looking a bit further between the n-sch restart and the timeout, verify_instance works | |
| 19:14:23 | mriedem | 2019-09-22 00:47:29.331 | Instance 44d7efdc-c048-4dca-8b4b-3d518321eddd is in cell: cell1 (8acfb79b-2e40-4e1c-bc3d-d404dac6db90) | |
| 19:14:52 | mriedem | donnyd: i think any job running nova and neutron is CPU bound :) | |
| 19:15:41 | donnyd | Yea that is not a strength of FN | |
| 19:16:51 | sean-k-mooney | mriedem: i assume you have seen the https://c0c3548b65f303ef6c0e-9dc5526a72bde5cc52e2c616e6a483fd.ssl.cf5.rackcdn.com/682061/5/check/grenade-heat/79209ac/logs/screen-n-cond.txt.gz i assume those are a result of the timeout | |
| 19:17:20 | mriedem | what, NoValidHost? yes that's the user visible failure | |
| 19:17:34 | sean-k-mooney | ya | |
| 19:17:51 | mriedem | the scheduler asks placement for providers for a build request, it gives back 1, we ask the cell db for the compute node for that one by uuid, timeout and then run an empty list of hosts through the filters | |
| 19:18:12 | sean-k-mooney | donnyd: well for jobs that actully enable nested vert/kvm FN is proably faster then the qemu based jobs | |
| 19:19:44 | openstackgerrit | Eric Fried proposed openstack/nova master: doc: attaching virtual persistent memory to guests https://review.opendev.org/680300 | |
| 19:19:45 | sean-k-mooney | mriedem: ya i notice the timestamp in the conductor log was after the timeout. | |
| 19:19:47 | donnyd | sean-k-mooney: for that case.. and anything with heavy IO should fly in FN - I am curious if the jobs that are failing on FN are related in any way to ipv6 | |
| 19:20:30 | dansmith | donnyd: could be, as we might be initiating a connection when this fails, | |
| 19:20:37 | dansmith | which might be network-related | |
| 19:20:50 | mriedem | i didn't think grenade jobs were doing anything with ipv6 | |
| 19:21:33 | sean-k-mooney | donnyd: where you thinking about the reduced mtu | |
| 19:21:36 | dansmith | well, maybe not, but just saying, if something network-y is the difference, that could explain flakiness | |
| 19:22:11 | donnyd | I was thinking more about the other one where the node loses contact when the ipv6 public side network is created | |
| 19:22:43 | donnyd | I recently tried to help that out by lowering my RA's so when it does it will pick it back up in time | |
| 19:23:00 | sean-k-mooney | the vms are dual stack vms right. they get a public ipv6 and private ipv4 address | |
| 19:23:11 | donnyd | correct sean-k-mooney | |
| 19:23:35 | sean-k-mooney | in that case ill check what ip we actully use for devstack | |
| 19:23:50 | donnyd | The mtu was lowered to 1450 | |
| 19:23:58 | donnyd | not sure what the other providers are set at | |
| 19:24:03 | sean-k-mooney | we are using the ipv4 addres | |
| 19:24:13 | sean-k-mooney | 192.168.48.93 in this case | |
| 19:24:42 | openstackgerrit | Merged openstack/nova master: Get pci_devices from _list_devices https://review.opendev.org/680674 | |
| 19:24:53 | donnyd | can we replicate this job on a test instance that doesn't get kilt | |
| 19:25:20 | sean-k-mooney | we can always ask infra to hold the node | |
| 19:25:38 | donnyd | So we can go poke around and see what the real issue is.. if its just FN failing this job then it must be FN related... | |
| 19:25:49 | dansmith | donnyd: it's not just FN | |
| 19:26:01 | sean-k-mooney | donnyd: its also failing on both of the ovh clouds | |
| 19:26:07 | dansmith | and for this, it matters what is in the cell mapping, not what is in the config file, just FYI | |
| 19:26:48 | donnyd | so it only succeeds on rax then? | |
| 19:27:06 | donnyd | what about limestone or vexxhost? | |
| 19:27:25 | donnyd | i think limestone is setup like FN with ipv6 | |
| 19:28:08 | sean-k-mooney | this is the logstash link for elastic search http://logstash.openstack.org/#/dashboard/file/logstash.json?query=message:%5C%22Timed%20out%20waiting%20for%20response%20from%20cell%5C%22%20AND%20tags:%5C%22screen-n-sch.txt%5C%22%20AND%20voting:1&from=864000s | |
| 19:28:10 | donnyd | And I think maybe using the custom labels will make sure you can schedule the job to a provider known to fail.. | |
| 19:29:29 | mriedem | this would be right around the time where we hit the scheduler for a tempest test to create a server and the timeout happens 1 minute after that | |
| 19:29:29 | mriedem | https://zuul.opendev.org/t/openstack/build/d53346210978403f888b85b82b2fe0c7/log/logs/syslog.txt.gz#8269 | |
| 19:29:45 | mriedem | idk if the netlink messages in there could be an issue | |
| 19:29:54 | sean-k-mooney | mriedem: i just realised im looking at a single node greade-heat job which has the same issue | |
| 19:31:44 | openstackgerrit | Merged openstack/nova master: [Trivial]Remove unused helper should_switch_to_postcopy https://review.opendev.org/679177 | |
| 19:31:50 | openstackgerrit | Merged openstack/nova master: [Trivial]Removed unused helper _extract_query_params https://review.opendev.org/679174 | |
| 19:32:29 | mriedem | looks like those syslog messages are 'normal' | |
| 19:32:46 | dansmith | mriedem: yeah probably not related to this | |
| 19:33:19 | dansmith | I dunno if OVS uses netlink for any datapath stuff, but in general, it's for setup of networking stuff, | |
| 19:33:30 | dansmith | not related to moving actual packets | |
| 19:33:46 | dansmith | although I guess if those indicated failure to set something up, then maybe, but.. | |