| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-10-17 | |||
| 09:15:10 | sean-k-mooney | ok so its getting to the schduler then | |
| 09:15:43 | sean-k-mooney | infact if its created the allcoation its pass the filters and selected the host | |
| 09:16:18 | sean-k-mooney | so its failing somethime beetween the schduler retruning to the conductor and the conductor callign the compute node | |
| 09:17:02 | bauzas | sean-k-mooney: that's not my understanding from what eandersson said by "I only see the compute in placement" | |
| 09:17:43 | sean-k-mooney | oh i may have misread that | |
| 09:17:47 | bauzas | eandersson: no GET logs on https://docs.openstack.org/api-ref/placement/?expanded=list-allocation-candidates-detail#list-allocation-candidates ? | |
| 09:18:03 | eandersson | I see build_and_run_instance hit the compute | |
| 09:18:16 | bauzas | WTF | |
| 09:18:20 | eandersson | when capturing a rabbitmq message | |
| 09:18:27 | eandersson | received by the compute | |
| 09:19:09 | bauzas | but no logs ? | |
| 09:19:21 | bauzas | I suspect your log factory not working then :D | |
| 09:19:29 | bauzas | that's... crazy | |
| 09:21:26 | eandersson | bauzas, talking about compute or conductor? | |
| 09:22:08 | bauzas | I frankly don't know what to say, I'm just lost | |
| 09:22:25 | eandersson | like look at the conductor https://zuul.opendev.org/t/openstack/build/9a820944e63e409cb8dbf5b83931263e/log/logs/screen-n-cond.txt.gz | |
| 09:22:29 | eandersson | and search for INFO | |
| 09:22:31 | bauzas | you're seeing only logs on api service, but you just told you're able to see a build call to compute | |
| 09:22:32 | eandersson | You'll find like 5 logs | |
| 09:22:58 | eandersson | https://zuul.opendev.org/t/openstack/build/d34ddb7bd62148968c33f4fe8f348e8b/log/controller/logs/screen-n-super-cond.txt.gz | |
| 09:23:29 | eandersson | I am not sure what you are talking about to be honest. | |
| 09:23:55 | eandersson | https://zuul.opendev.org/t/openstack/build/d34ddb7bd62148968c33f4fe8f348e8b/log/controller/logs/screen-n-sch.txt.gz | |
| 09:24:01 | eandersson | This is the scheduler, again search for INFO | |
| 09:24:05 | eandersson | you'll find like zero entries | |
| 09:24:44 | eandersson | We have 1k compute nodes, and enabling debug would be very... spammy | |
| 09:25:04 | eandersson | but unfortunately INFO does not provide a ton of logs outside of API | |
| 09:27:24 | bauzas | eandersson: as I proposed you, can you please do some 'nova instance-action-list' stuff to get more knowledge ? | |
| 09:27:39 | bauzas | but I understand your point, INFO logs aren't talkative | |
| 09:28:02 | bauzas | I thought we fixed that in Newton (or sometimes around it) | |
| 09:28:22 | eandersson | Is that the same as openstack server even list? | |
| 09:28:29 | eandersson | *event | |
| 09:29:02 | eandersson | because os-instance-actions just shows me the request id, server id, action and start time | |
| 09:29:16 | eandersson | let me check the body | |
| 09:33:58 | sean-k-mooney | bauzas: ya looking at the conductor logs for the gate jobs the non debug version is not very useful | |
| 09:34:08 | sean-k-mooney | we likely should make https://zuul.opendev.org/t/openstack/build/df644e9fdde346f2813e6220312a9ca5/log/controller/logs/screen-n-super-cond.txt.gz#867 info level | |
| 09:35:11 | eandersson | I enabled debug | |
| 09:35:40 | eandersson | > [instance: x] Selected host: compute1031; Selected node: compute1031; ; Alternates: [] schedule_and_build_instances | |
| 09:35:48 | bauzas | eandersson: I checked and events are shown by default if you are on Pike and above when you call out instance-action API | |
| 09:35:49 | eandersson | > Re-scheduling is disabled. populate_retry | |
| 09:36:08 | bauzas | eandersson: but you need to login with admin creds | |
| 09:36:22 | bauzas | https://docs.openstack.org/api-ref/compute/?expanded=show-server-action-details-detail#id170 | |
| 09:36:52 | bauzas | anyway, gotta run, | |
| 09:36:54 | bauzas | \o | |
| 09:37:21 | eandersson | http://paste.openstack.org/show/EUjnd5TWftogxGIVaSNP/ | |
| 09:37:25 | eandersson | This is the last log line | |
| 09:37:35 | eandersson | from the conductor / scheduler | |
| 09:38:13 | eandersson | yea bauzas nothing interesting in the events | |
| 09:39:06 | eandersson | Everything looks to be scheduled fine | |
| 09:39:21 | sean-k-mooney | right that is the last log for the instace we expect to see in the conductor log | |
| 09:39:54 | sean-k-mooney | well unless there is an error | |
| 09:40:00 | eandersson | no errors in the logs | |
| 09:40:08 | eandersson | :'( | |
| 09:40:36 | sean-k-mooney | and nothing in the compute agent long in debug either | |
| 09:40:41 | sean-k-mooney | it just disappars? | |
| 09:40:48 | eandersson | I pasted some logs early on | |
| 09:41:00 | sean-k-mooney | you captured the rpc right beign recived | |
| 09:41:03 | eandersson | let me check again | |
| 09:41:14 | sean-k-mooney | oh ill scroll back | |
| 09:45:26 | tssurya | eandersson: what's the exact boot request you are making ? | |
| 09:45:47 | sean-k-mooney | i dont see the logs for the compute scrolling back unfortunetly. | |
| 09:46:08 | eandersson | sean-k-mooney, I think the logs we discussed were things like | |
| 09:46:14 | eandersson | > instance x has been scheduled to this compute host | |
| 09:47:02 | eandersson | Let me enable even more debug logs | |
| 09:47:57 | sean-k-mooney | ah am you can re disable debug on the conductor/schduler since we are pretty sure its getting to the compute node at this point right | |
| 09:48:14 | eandersson | Yea already disabled | |
| 09:48:18 | eandersson | generates a lot of logs :p | |
| 09:48:59 | sean-k-mooney | for 200 servers with all servceince in debug i belive its something like 30GB a day in uncompressed logs | |
| 09:49:23 | sean-k-mooney | thats what kolla-ansibel said in there configuration docs in anycase | |
| 09:49:42 | eandersson | hehe well that is without kubernetes, octavia etc hitting your apis constantly | |
| 09:49:50 | eandersson | plus all other automation | |
| 09:50:19 | sean-k-mooney | right you would really want log rotate to be working well if you use debug always | |
| 09:51:17 | sean-k-mooney | we shoudl try to have more of a blance however. e.g. make info more useful without being just spam | |
| 09:52:06 | eandersson | On compute I see a message being received, but nothing more | |
| 09:52:29 | eandersson | > DEBUG oslo_messaging._drivers.amqpdriver [-] received reply msg_id: ad3b7ccda9944e9e87f497f4401aa0b4 __call__ | |
| 09:52:57 | sean-k-mooney | ok so its not building the libvirt xml or plugging any ports | |
| 09:53:09 | sean-k-mooney | its just reciving it | |
| 09:53:14 | eandersson | yea | |
| 09:53:28 | sean-k-mooney | did you also check with the instance uuid | |
| 09:53:34 | eandersson | I bet this compute is bust, but everything seems fine (including already existing vms) | |
| 09:53:39 | eandersson | yea | |
| 09:53:59 | eandersson | I do get some logs with the instance id | |
| 09:54:06 | eandersson | but it's just the ones I posted earlier | |
| 09:54:20 | sean-k-mooney | ok | |
| 09:54:22 | eandersson | > Instance ... has been scheduled to this compute host, the scheduler has made an allocation against this compute node but the instance has yet to start. Skipping heal of allocation: ... | |
| 09:54:46 | sean-k-mooney | right that is the periodic task | |
| 09:55:04 | sean-k-mooney | that make sure the resouce useage on the host matches what we expect | |
| 09:55:44 | sean-k-mooney | that is normal to see between when the host has been selected in the db as the target for the instnace and the vm starting | |
| 09:57:34 | eandersson | Anyway bed time. It's 3AM. | |
| 09:57:51 | eandersson | Thanks for helping sean-k-mooney and gibi | |
| 09:58:08 | sean-k-mooney | eandersson: o/ get some rest | |
| 10:32:24 | openstackgerrit | Brin Zhang proposed openstack/python-novaclient master: Add functional test for migration-list in v2.80 https://review.opendev.org/688635 | |
| 10:33:31 | openstackgerrit | Merged openstack/nova stable/queens: Fix 'has_calls' method calls in unit tests https://review.opendev.org/677378 | |
| 10:42:09 | gibi | it is only me or the powervm unit tests started failing on master? | |
| 10:44:29 | gibi | AttributeError: 'DiGraph' object has no attribute 'node' | |
| 10:47:55 | gibi | https://702b7e8f253d29e679a6-2fe3f6c342189909aad5220492fb4721.ssl.cf1.rackcdn.com/688387/5/check/openstack-tox-cover/2c6410c/testr_results.html.gz | |
| 10:48:51 | gibi | http://logstash.openstack.org/#dashboard/file/logstash.json?query=message%3A%5C%22AttributeError%3A%20'DiGraph'%20object%20has%20no%20attribute%20'node'%5C%22&from=7d | |
| 10:48:59 | gibi | there are plenty of hits not just in nova | |
| 10:50:01 | gibi | only affecting python 3.x jobs not the 2.7 jobs | |
| 10:55:04 | jkulik | https://github.com/networkx/networkx/commit/6b1ce03f485076d39994e8d624bbf6ca82466eb9#diff-027182481aebf9ad0dda6ca00714653aR95 seems to be the cause | |
| 10:56:00 | jkulik | seems like there's no upper version requirement defined in the taskflow library for python3 https://opendev.org/openstack/taskflow/src/branch/master/requirements.txt#L24 | |