| NobodyCam | droped a localhost connection | 00:00 |
|---|---|---|
| adam_g | that pasted log fails horribly in the beginning, but ive seen other failures where it eventually recovers and picks up resources. i have a local devstack up where im hitting it horribly similar to whats pasted above | 00:00 |
| devananda | http://logs.openstack.org/94/138294/7/check/check-tempest-dsvm-ironic-pxe_ssh/e3124f6/logs/screen-n-cpu.txt.gz?level=INFO | 00:01 |
| devananda | 2014-12-05 10:12:39.294 30427 ERROR nova.compute.manager [-] No compute node record for host devstack-trusty-hpcloud-b3-3337487 | 00:01 |
| *** Masahiro has joined #openstack-ironic | 00:01 | |
| devananda | a full minute before the first one of these | 00:01 |
| devananda | 2014-12-05 10:13:39.490 30427 AUDIT nova.compute.resource_tracker [-] Auditing locally available compute resources | 00:01 |
| openstackgerrit | OpenStack Proposal Bot proposed openstack/ironic: Updated from global requirements https://review.openstack.org/139762 | 00:02 |
| jroll | which doesn't actually find any resources | 00:03 |
| jroll | this must be a networking thing | 00:03 |
| jroll | http://logs.openstack.org/94/138294/7/check/check-tempest-dsvm-ironic-pxe_ssh/e3124f6/logs/screen-ir-api.txt.gz?level=INFO | 00:03 |
| jroll | some requests are getting through ok, though | 00:04 |
| *** Masahiro has quit IRC | 00:05 | |
| devananda | yup | 00:05 |
| devananda | look at the timestamps | 00:05 |
| adam_g | hmm | 00:06 |
| devananda | in devstacklog.txt, it starts creating ironic at 10:10:46 | 00:06 |
| devananda | and finishes about 3 minutes later | 00:06 |
| devananda | sorry, not ironic -- dib | 00:06 |
| devananda | 2014-12-05 10:10:46.623 | ++ init_ironic | 00:07 |
| devananda | 2014-12-05 10:11:04.720 | ++ ramdisk-image-create ubuntu deploy-ironic -o /opt/stack/new/devstack/files/ir-deploy-pxe_ssh | 00:07 |
| adam_g | i believe those dropped connections are the n-cpu periodics | 00:08 |
| adam_g | ncpu comes up configured for ironic before devstack sets up ironic/creates ramdisk | 00:09 |
| devananda | 2014-12-05 10:13:01.834 | WARNING: urllib3.connectionpool HttpConnectionPool is full, discarding connection: 127.0.0.1 | 00:09 |
| devananda | that's showing up in devstacklog, when it is trying to upload the images to glance | 00:09 |
| adam_g | 2014-12-05 10:15:01.821 30427 DEBUG nova.openstack.common.periodic_task [-] Running periodic task ComputeManager.update_available_resource run_periodic_tasks | 00:10 |
| adam_g | 2014-12-05 10:15:01.936 31500 INFO urllib3.connectionpool [-] Resetting dropped connection: 127.0.0.1 | 00:10 |
| adam_g | devananda, interesting, im showing the same message locally: WARNING: urllib3.connectionpool HttpConnectionPool is full, discarding connection: 127.0.0.1 | 00:11 |
| adam_g | anywhere openstack client is used | 00:11 |
| devananda | interesting | 00:12 |
| *** romcheg has quit IRC | 00:12 | |
| jroll | fyi, fun virt driver bug https://review.openstack.org/#/c/139767/ | 00:12 |
| devananda | maybe a red herring? | 00:12 |
| adam_g | todo images | 00:12 |
| adam_g | it sounds like a red herring, yeah | 00:12 |
| devananda | 2014-12-05 10:13:20.119 | ++ enroll_nodes | 00:13 |
| devananda | back to timestamps, nova's running a full 3 minutes before Ironic has any nodes enrolled | 00:13 |
| adam_g | devananda, that should be fine | 00:13 |
| devananda | so if tempest is keying nova tests off of "is nova available" -- yup. they're going to fail | 00:13 |
| devananda | hm. why is that ok? | 00:14 |
| adam_g | devananda, because devstack's enroll_nodes() polls hypervisor-stats for an expected node count before exiting | 00:14 |
| adam_g | the issue im seeing in gate and locally is that | 00:14 |
| devananda | 2014-12-05 10:17:20.310 | ++ die 515 'Nova hypervisor-stats did not register at least 3 nodes' | 00:14 |
| adam_g | devananda, sorry, that log is a bad example -- it totally failed hard in the beginning | 00:15 |
| adam_g | one sec, i can point to a different failure | 00:15 |
| devananda | oh | 00:15 |
| devananda | k k | 00:15 |
| adam_g | but the symptoms im seeing: ironic returns the enrolled nodes to nova at during a later periodic task sync, nova counts the nodes in its hypervisor count, but ironic returns power_state=None for them so their resources are skipped by nova | 00:16 |
| adam_g | and looking at the conductor logs, im seeing it stuck waiting for a reservation (presumably trying to validate its power status) | 00:16 |
| adam_g | http://logs.openstack.org/29/139329/3/check/check-tempest-dsvm-ironic-parallel-nv/8811be4/logs/screen-n-cpu.txt.gz#_2014-12-05_16_57_26_345 | 00:16 |
| devananda | after that i'm getting food. and probably a drink | 00:16 |
| *** harlowja_ has quit IRC | 00:17 | |
| adam_g | i can patch devstack to also poll for other hypervisor resources, but this seems like a new issue we've not seen before | 00:17 |
| adam_g | so to my original question, given a 'Attempting to reserve node' message, is it possible to see what task currently has that node reserved? | 00:18 |
| adam_g | also, does it make sense to update that message and change '... to reserve node $N' to '... to reserve node $UUID'? | 00:19 |
| jroll | adam_g: "Attempting to reserve node" is logged even when the reservation is successful | 00:20 |
| jroll | I believe | 00:20 |
| adam_g | yea, i just realized that :) | 00:21 |
| adam_g | tho im used to seeing some output of the reserving task after | 00:21 |
| devananda | adam_g: any where we're logging a node ID, we should be logging the UUID instead | 00:21 |
| jroll | right, I agree something is weird | 00:21 |
| adam_g | devananda, cool, ill put up a patch | 00:22 |
| jroll | devananda: you should review this and make sure I'm not doing anything dumb | 00:22 |
| jroll | https://review.openstack.org/#/c/139767 | 00:22 |
| devananda | jroll: then i'll look later. right now, i'm inclined to do dumb things | 00:24 |
| jroll | ha | 00:25 |
| jroll | right on, thanks | 00:25 |
| *** davideagnello has quit IRC | 00:25 | |
| NobodyCam | oh agent question do I need to set swift_endpoint_url=? | 00:29 |
| devananda | adam_g: that error is 2 seconds before the local host SSH key is added | 00:29 |
| devananda | 2014-12-05 16:57:28.043 | ++ ironic_ssh_check /opt/stack/data/ironic/ssh_keys/ironic_key 23.253.237.43 22 stack 10 | 00:29 |
| adam_g | devananda, interesting, nice catch | 00:31 |
| devananda | yea, we should probably be ensuring that the SSH power driver can access localhost before we start ironic-conductor | 00:31 |
| devananda | not 3 minutes later | 00:31 |
| devananda | heh | 00:31 |
| devananda | 2014-12-05 16:57:27.980 | ++ ssh-keygen -q -t rsa -P '' -f /opt/stack/data/ironic/ssh_keys/ironic_key | 00:31 |
| devananda | but | 00:32 |
| devananda | 2014-12-05 16:54:06.119 2733 INFO ironic.common.driver_factory [-] Loaded the following drivers: ['fake', 'pxe_ssh', 'pxe_ipmitool'] | 00:32 |
| devananda | adam_g: that sounds like it could produce the problem you're seeing | 00:32 |
| devananda | though, damn, there should be some logging about it :( | 00:32 |
| *** harlowja has joined #openstack-ironic | 00:32 | |
| adam_g | devananda, yeah--stepping through this locally now and im not seeing any logging from the conductor tasks being output anywhere | 00:32 |
| devananda | https://github.com/openstack/ironic/blob/master/ironic/conductor/manager.py#L854 | 00:34 |
| devananda | try adding something there | 00:34 |
| adam_g | yeah, thats where i'm at | 00:34 |
| devananda | oh hah! | 00:35 |
| devananda | think i found it | 00:35 |
| devananda | def _do_sync_power_state | 00:35 |
| devananda | try: task.driver.power.validate | 00:35 |
| devananda | except (...): return | 00:35 |
| devananda | there's no logging at all if it fails the validate check | 00:35 |
| devananda | for a node which as no previous power state | 00:35 |
| devananda | that was intentional, under the assumption that newly added nodes might not be manageable yet (eg, if they fail a basic validate check) | 00:36 |
| devananda | and operators don't need to see a WARNING for that | 00:36 |
| adam_g | *** MissingParameterValue: Node 1cf7e486-8882-45e8-9465-5259e43ea2f2 does not have any port associated with it. | 00:36 |
| adam_g | is the exception im hitting there | 00:36 |
| adam_g | thats my own fault (i was clearing the node inventory and recreating, but forgot about ports) | 00:37 |
| devananda | https://github.com/openstack/ironic/blob/master/ironic/drivers/modules/ssh.py#L326 | 00:38 |
| devananda | it's actually checking to see if the keyfile is present on the host | 00:38 |
| devananda | which, for the first ~3 minutes, it's not | 00:38 |
| devananda | since devstack didn't create it yet | 00:38 |
| devananda | so the SSH driver is probably raising InvalidParameterValue from .validate() | 00:38 |
| devananda | and that's getting ignored in the sync_power_state loop | 00:38 |
| adam_g | that makes sense | 00:39 |
| NobodyCam | nice catch devananda :) | 00:39 |
| *** david-lyle is now known as david-lyle_afk | 00:39 | |
| adam_g | need to refactor devstack a bit | 00:39 |
| adam_g | or, at least lib/ironic | 00:39 |
| devananda | the part that's off here is devstack starting ironic and enrolling nodes, 3 minutes before creating the key that ironic needs | 00:39 |
| devananda | to manage those nodes | 00:40 |
| devananda | ok - time for food! | 00:40 |
| devananda | $2 tacos! | 00:41 |
| adam_g | devananda, yeah--the ssh stuff needs to split away from things that need ironic api to be up | 00:42 |
| adam_g | have a good one! | 00:42 |
| NobodyCam | night devananda | 00:46 |
| adam_g | devstack change simpler than expected https://review.openstack.org/#/c/139770/1 | 00:55 |
| JayF | I'll take a look | 00:56 |
| JayF | nice fix adam_g, ty | 00:58 |
| adam_g | JayF, thanks devananda for finding that, i totally overlooked that :) | 00:58 |
| *** Masahiro has joined #openstack-ironic | 01:02 | |
| *** Masahiro has quit IRC | 01:06 | |
| *** jerryz has joined #openstack-ironic | 01:09 | |
| *** alexpilotti has quit IRC | 01:20 | |
| *** marcoemorais has quit IRC | 01:43 | |
| *** Marga_ has quit IRC | 01:57 | |
| *** Marga_ has joined #openstack-ironic | 01:57 | |
| *** ryanpetrello has joined #openstack-ironic | 01:58 | |
| *** Marga_ has quit IRC | 02:02 | |
| openstackgerrit | Merged openstack/ironic-python-agent: Workflow documentation is now in infra-manual https://review.openstack.org/139330 | 02:08 |
| *** pensu has joined #openstack-ironic | 02:28 | |
| *** jerryz has quit IRC | 02:47 | |
| *** jerryz has joined #openstack-ironic | 02:47 | |
| *** Masahiro has joined #openstack-ironic | 02:50 | |
| *** Masahiro has quit IRC | 02:55 | |
| *** lazy_prince has quit IRC | 03:27 | |
| *** Shrews has quit IRC | 03:29 | |
| *** Haomeng has quit IRC | 03:40 | |
| *** Haomeng has joined #openstack-ironic | 03:42 | |
| *** Masahiro has joined #openstack-ironic | 03:51 | |
| *** Masahiro has quit IRC | 03:56 | |
| openstackgerrit | ZhiQiang Fan proposed openstack/ironic: rename oslo.concurrency to oslo_concurrency https://review.openstack.org/139782 | 04:21 |
| *** achanda has joined #openstack-ironic | 04:27 | |
| *** achanda has quit IRC | 04:43 | |
| *** achanda has joined #openstack-ironic | 04:44 | |
| *** Marga_ has joined #openstack-ironic | 04:45 | |
| *** Marga_ has quit IRC | 04:45 | |
| *** Marga_ has joined #openstack-ironic | 04:46 | |
| *** killer_prince has joined #openstack-ironic | 05:16 | |
| *** killer_prince is now known as lazy_prince | 05:16 | |
| *** achanda has quit IRC | 05:29 | |
| *** achanda has joined #openstack-ironic | 05:30 | |
| *** achanda has quit IRC | 05:35 | |
| *** Masahiro has joined #openstack-ironic | 05:40 | |
| *** Masahiro has quit IRC | 05:45 | |
| *** achanda has joined #openstack-ironic | 05:45 | |
| *** achanda has quit IRC | 05:47 | |
| openstackgerrit | Shivanand Tendulker proposed openstack/ironic-specs: Ironic Management Interfaces to support UEFI Secure Boot https://review.openstack.org/135845 | 06:06 |
| *** pcrews has quit IRC | 06:30 | |
| *** pcrews has joined #openstack-ironic | 06:31 | |
| *** harlowja is now known as harlowja_away | 06:52 | |
| *** Masahiro has joined #openstack-ironic | 07:29 | |
| *** rushiagr_away is now known as rushiagr | 07:31 | |
| *** Masahiro has quit IRC | 07:33 | |
| *** andreykurilin_ has joined #openstack-ironic | 08:41 | |
| *** pensu has quit IRC | 08:46 | |
| *** andreykurilin_ has quit IRC | 08:51 | |
| *** shakamunyi has joined #openstack-ironic | 08:51 | |
| *** shakamunyi has quit IRC | 08:51 | |
| *** Masahiro has joined #openstack-ironic | 09:18 | |
| *** Masahiro has quit IRC | 09:22 | |
| *** rushiagr is now known as rushiagr_away | 09:54 | |
| openstackgerrit | ZhiQiang Fan proposed openstack/ironic: rename oslo.concurrency to oslo_concurrency https://review.openstack.org/139782 | 10:01 |
| *** rushiagr_away is now known as rushiagr | 10:10 | |
| *** andreykurilin_ has joined #openstack-ironic | 10:19 | |
| *** romcheg has joined #openstack-ironic | 10:33 | |
| *** Masahiro has joined #openstack-ironic | 11:06 | |
| *** Masahiro has quit IRC | 11:11 | |
| *** andreykurilin_ has quit IRC | 11:15 | |
| *** andreykurilin_ has joined #openstack-ironic | 11:15 | |
| *** romcheg has quit IRC | 11:25 | |
| *** Marga_ has quit IRC | 11:32 | |
| *** andreykurilin_ has quit IRC | 12:14 | |
| *** lazy_prince has quit IRC | 12:30 | |
| *** alexpilotti has joined #openstack-ironic | 12:43 | |
| *** bradjones has quit IRC | 12:44 | |
| *** bradjones has joined #openstack-ironic | 12:47 | |
| *** Masahiro has joined #openstack-ironic | 12:55 | |
| *** Masahiro has quit IRC | 12:59 | |
| *** rushiagr is now known as rushiagr_away | 13:14 | |
| *** rushiagr_away is now known as rushiagr | 13:20 | |
| *** killer_prince has joined #openstack-ironic | 13:53 | |
| *** killer_prince is now known as lazy_prince | 13:53 | |
| *** lazy_prince has quit IRC | 14:16 | |
| *** killer_prince has joined #openstack-ironic | 14:26 | |
| *** killer_prince is now known as lazy_prince | 14:27 | |
| *** jerryz_ has joined #openstack-ironic | 14:39 | |
| *** jerryz has quit IRC | 14:43 | |
| *** Masahiro has joined #openstack-ironic | 14:44 | |
| *** Masahiro has quit IRC | 14:49 | |
| *** rushiagr is now known as rushiagr_away | 14:54 | |
| *** ryanpetrello has quit IRC | 15:04 | |
| *** lazy_prince has quit IRC | 15:10 | |
| -openstackstatus- NOTICE: [reminder] gerrit will be offline for 30 minutes starting at 16:00 utc for project renames | 15:20 | |
| openstackgerrit | Arata Notsu proposed openstack/ironic: Correct vmware ssh power manager https://review.openstack.org/139810 | 15:22 |
| *** killer_prince has joined #openstack-ironic | 15:44 | |
| *** killer_prince is now known as lazy_prince | 15:44 | |
| NobodyCam | morning Ironic | 15:49 |
| *** Shrews has joined #openstack-ironic | 15:58 | |
| -openstackstatus- NOTICE: gerrit will be offline for 30 minutes while we rename a few projects. eta 16:30 utc | 16:03 | |
| *** ChanServ changes topic to "gerrit will be offline for 30 minutes while we rename a few projects. eta 16:30 utc" | 16:03 | |
| *** jerryz_ has quit IRC | 16:16 | |
| *** Masahiro has joined #openstack-ironic | 16:20 | |
| *** achanda has joined #openstack-ironic | 16:23 | |
| *** Masahiro has quit IRC | 16:25 | |
| *** andreykurilin_ has joined #openstack-ironic | 16:31 | |
| *** openstackgerrit has quit IRC | 16:45 | |
| *** openstackgerrit has joined #openstack-ironic | 16:46 | |
| *** ChanServ changes topic to "Bare Metal Provisioning | Status: http://bit.ly/ironic-whiteboard | Docs: http://docs.openstack.org/developer/ironic/ | Bugs: https://bugs.launchpad.net/ironic" | 16:50 | |
| *** pensu has joined #openstack-ironic | 16:54 | |
| *** rushiagr_away is now known as rushiagr | 17:30 | |
| *** achanda has quit IRC | 17:38 | |
| openstackgerrit | Arata Notsu proposed openstack/ironic: Correct vmware ssh power manager https://review.openstack.org/139810 | 17:46 |
| *** romcheg has joined #openstack-ironic | 18:01 | |
| *** ryanpetrello has joined #openstack-ironic | 18:03 | |
| *** Masahiro has joined #openstack-ironic | 18:09 | |
| *** Masahiro has quit IRC | 18:13 | |
| *** shakamunyi has joined #openstack-ironic | 18:23 | |
| *** ryanpetrello has quit IRC | 18:49 | |
| *** igordcard has joined #openstack-ironic | 18:54 | |
| *** ryanpetrello has joined #openstack-ironic | 18:54 | |
| *** igordcard has quit IRC | 18:55 | |
| *** andreykurilin_ has quit IRC | 19:12 | |
| *** ryanpetrello has quit IRC | 19:15 | |
| *** romcheg has quit IRC | 19:17 | |
| *** pensu has quit IRC | 19:18 | |
| *** ryanpetrello has joined #openstack-ironic | 19:20 | |
| *** romcheg has joined #openstack-ironic | 19:20 | |
| *** ryanpetrello has quit IRC | 19:31 | |
| *** ryanpetrello has joined #openstack-ironic | 19:37 | |
| *** romcheg has quit IRC | 19:40 | |
| *** ryanpetrello has quit IRC | 19:49 | |
| *** ryanpetrello has joined #openstack-ironic | 19:53 | |
| *** romcheg has joined #openstack-ironic | 19:58 | |
| *** Masahiro has joined #openstack-ironic | 19:58 | |
| *** ryanpetrello has quit IRC | 19:58 | |
| *** Masahiro has quit IRC | 20:02 | |
| *** andreykurilin_ has joined #openstack-ironic | 20:21 | |
| *** Marga_ has joined #openstack-ironic | 20:31 | |
| *** igordcard has joined #openstack-ironic | 20:35 | |
| *** shakamunyi has quit IRC | 20:55 | |
| *** rushiagr is now known as rushiagr_away | 21:17 | |
| *** krtaylor has quit IRC | 21:21 | |
| *** krtaylor has joined #openstack-ironic | 21:27 | |
| *** Masahiro has joined #openstack-ironic | 21:47 | |
| *** Masahiro has quit IRC | 21:51 | |
| *** romcheg has quit IRC | 22:05 | |
| *** romcheg has joined #openstack-ironic | 22:24 | |
| *** Marga_ has quit IRC | 22:37 | |
| *** toabctl has quit IRC | 23:05 | |
| *** toabctl has joined #openstack-ironic | 23:07 | |
| *** ekarlso- has quit IRC | 23:07 | |
| *** ryanpetrello has joined #openstack-ironic | 23:12 | |
| *** vdrok has quit IRC | 23:21 | |
| *** andreykurilin_ has quit IRC | 23:22 | |
| *** vdrok has joined #openstack-ironic | 23:22 | |
| *** andreykurilin_ has joined #openstack-ironic | 23:22 | |
| *** Masahiro has joined #openstack-ironic | 23:35 | |
| *** Marga_ has joined #openstack-ironic | 23:38 | |
| *** Masahiro has quit IRC | 23:39 | |
| *** igordcard has quit IRC | 23:42 | |
| *** Marga_ has quit IRC | 23:43 | |
| *** ryanpetrello has quit IRC | 23:53 | |
| *** ryanpetrello has joined #openstack-ironic | 23:53 | |
Generated by irclog2html.py 2.14.0 by Marius Gedminas - find it at mg.pov.lt!