Re: Devstack Installation Fails with Internal Server Error (HTTP 500)
I had tried to send this earlier with devstack output attached without thinking about the large size of the text. Sorry :( On Thu Jun 16 2022 16:56:21 GMT-0700 (Pacific Daylight Time), Dan Smith <dms@danplanet.com> wrote:
It looks like copies of this may be getting repeatedly concatenated into the plugin variable:
https://opendev.org/openstack/devstack/src/commit/44d07f300150f7297773a21503...
I don't think that's actually happening. If it was, restarting glance wouldn't help (as Melanie indicated) and it also should never really work. I was thinking that was more likely an artifact of the error message or something. Looking at the config files, they seem right. For example:
https://zuul.opendev.org/t/openstack/build/ff5a7a6fc87840579b102b244f28200f/...
I didn't notice this before but before things error with glance, other projects had no problem loading the dbcounter plugin, keystone-manage:
+lib/keystone:init_keystone:484 /usr/local/bin/keystone-manage --config-file /etc/keystone/keystone.conf db_sync INFO dbcounter [-] Registered counter for database keystone DEBUG oslo_db.sqlalchemy.engines [-] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_ENGINE_SUBSTITUTION {{(pid=371448) _check_effective_sql_mode /usr/local/lib/python3.8/dist-packages/oslo_db/sqlalchemy/engines.py:314}} DEBUG dbcounter [-] [371448] Writer thread running {{(pid=371448) stat_writer /usr/local/lib/python3.8/dist-packages/dbcounter.py:99}}
Yet glance fails to load it during two separate glance-manage calls:
+lib/glance:init_glance:489 /usr/local/bin/glance-manage --config-file /etc/glance/glance-api.conf db_sync CRITICAL glance [-] Unhandled error: sqlalchemy.exc.NoSuchModuleError: Can't load plugin: sqlalchemy.plugins:dbcounterplugin=dbcounterplugin=dbcounter [...] +lib/glance:init_glance:492 /usr/local/bin/glance-manage --config-file /etc/glance/glance-api.conf db_load_metadefs CRITICAL glance [-] Unhandled error: sqlalchemy.exc.NoSuchModuleError: Can't load plugin: sqlalchemy.plugins:dbcounterplugin=dbcounterplugin=dbcounter
Then cinder-manage loads it fine:
+lib/cinder:init_cinder:440 /usr/local/bin/cinder-manage --config-file /etc/cinder/cinder.conf db sync INFO dbcounter [-] Registered counter for database cinder DEBUG oslo_db.sqlalchemy.engines [-] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_ENGINE_SUBSTITUTION {{(pid=391785) _check_effective_sql_mode /usr/local/lib/python3.8/dist-packages/oslo_db/sqlalchemy/engines.py:314}} DEBUG dbcounter [-] [391785] Writer thread running {{(pid=391785) stat_writer /usr/local/lib/python3.8/dist-packages/dbcounter.py:99}}
Then nova-manage:
+lib/nova:init_nova:843 /usr/local/bin/nova-manage --config-file /etc/nova/nova.conf api_db sync Modules with known eventlet monkey patching issues were imported prior to eventlet monkey patching: urllib3. This warning can usually be ignored if the caller is only importing and not executing nova code. INFO dbcounter [-] Registered counter for database nova_api DEBUG dbcounter [-] [394510] Writer thread running {{(pid=394510) stat_writer /usr/local/lib/python3.8/dist-packages/dbcounter.py:99}} [...] INFO dbcounter [-] Registered counter for database nova_cell0 DEBUG dbcounter [-] [394520] Writer thread running {{(pid=394520) stat_writer /usr/local/lib/python3.8/dist-packages/dbcounter.py:99}} [...] INFO dbcounter [-] Registered counter for database nova_cell1 DEBUG dbcounter [-] [394531] Writer thread running {{(pid=394531) stat_writer /usr/local/lib/python3.8/dist-packages/dbcounter.py:99}}
Finally glance fails to load the plugin in the g-api service when an image upload is requested:
+functions:_upload_image:121 openstack --os-cloud=devstack-admin --os-region-name=RegionOne image create cirros-0.5.2-x86_64-disk --public --container-format bare --disk-format qcow2 --property hw_rng_model=virtio /usr/lib/python3/dist-packages/secretstorage/dhcrypto.py:15: CryptographyDeprecationWarning: int_from_bytes is deprecated, use int.from_bytes instead from cryptography.utils import int_from_bytes /usr/lib/python3/dist-packages/secretstorage/util.py:19: CryptographyDeprecationWarning: int_from_bytes is deprecated, use int.from_bytes instead from cryptography.utils import int_from_bytes HttpException: 500: Server Error for url: http://192.168.42.11/image/v2/images, The server has either erred or is incapable of performing the requested operation.: 500 Internal Server Error
With this ^ I realized that restarting g-api might not have been a good indicator of anything resolving because in this example the plugin load failure occurs while checking quota for an inbound request. I'm not sure whether services load the dbcounter passively when they start or if it's only when database accesses are initiated. I also don't understand how or why one project can't load the plugin but the rest can. And I wonder whether it's a coincidence that it was glance in the two examples we have so far. -melwitt
On Fri, Jun 17, 2022 at 7:37 AM melanie witt <melwittt@gmail.com> wrote:
I had tried to send this earlier with devstack output attached without thinking about the large size of the text. Sorry :(
On Thu Jun 16 2022 16:56:21 GMT-0700 (Pacific Daylight Time), Dan Smith <dms@danplanet.com> wrote:
It looks like copies of this may be getting repeatedly concatenated into the plugin variable:
https://opendev.org/openstack/devstack/src/commit/44d07f300150f7297773a21503...
I don't think that's actually happening. If it was, restarting glance wouldn't help (as Melanie indicated) and it also should never really work. I was thinking that was more likely an artifact of the error message or something. Looking at the config files, they seem right. For example:
https://zuul.opendev.org/t/openstack/build/ff5a7a6fc87840579b102b244f28200f/...
I didn't notice this before but before things error with glance, other projects had no problem loading the dbcounter plugin, keystone-manage:
+lib/keystone:init_keystone:484 /usr/local/bin/keystone-manage --config-file /etc/keystone/keystone.conf db_sync INFO dbcounter [-] Registered counter for database keystone DEBUG oslo_db.sqlalchemy.engines [-] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_ENGINE_SUBSTITUTION {{(pid=371448) _check_effective_sql_mode /usr/local/lib/python3.8/dist-packages/oslo_db/sqlalchemy/engines.py:314}} DEBUG dbcounter [-] [371448] Writer thread running {{(pid=371448) stat_writer /usr/local/lib/python3.8/dist-packages/dbcounter.py:99}}
Yet glance fails to load it during two separate glance-manage calls:
+lib/glance:init_glance:489 /usr/local/bin/glance-manage --config-file /etc/glance/glance-api.conf db_sync CRITICAL glance [-] Unhandled error: sqlalchemy.exc.NoSuchModuleError: Can't load plugin: sqlalchemy.plugins:dbcounterplugin=dbcounterplugin=dbcounter [...] +lib/glance:init_glance:492 /usr/local/bin/glance-manage --config-file /etc/glance/glance-api.conf db_load_metadefs CRITICAL glance [-] Unhandled error: sqlalchemy.exc.NoSuchModuleError: Can't load plugin: sqlalchemy.plugins:dbcounterplugin=dbcounterplugin=dbcounter
Then cinder-manage loads it fine:
+lib/cinder:init_cinder:440 /usr/local/bin/cinder-manage --config-file /etc/cinder/cinder.conf db sync INFO dbcounter [-] Registered counter for database cinder DEBUG oslo_db.sqlalchemy.engines [-] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_ENGINE_SUBSTITUTION {{(pid=391785) _check_effective_sql_mode /usr/local/lib/python3.8/dist-packages/oslo_db/sqlalchemy/engines.py:314}} DEBUG dbcounter [-] [391785] Writer thread running {{(pid=391785) stat_writer /usr/local/lib/python3.8/dist-packages/dbcounter.py:99}}
Then nova-manage:
+lib/nova:init_nova:843 /usr/local/bin/nova-manage --config-file /etc/nova/nova.conf api_db sync Modules with known eventlet monkey patching issues were imported prior to eventlet monkey patching: urllib3. This warning can usually be ignored if the caller is only importing and not executing nova code. INFO dbcounter [-] Registered counter for database nova_api DEBUG dbcounter [-] [394510] Writer thread running {{(pid=394510) stat_writer /usr/local/lib/python3.8/dist-packages/dbcounter.py:99}} [...] INFO dbcounter [-] Registered counter for database nova_cell0 DEBUG dbcounter [-] [394520] Writer thread running {{(pid=394520) stat_writer /usr/local/lib/python3.8/dist-packages/dbcounter.py:99}} [...] INFO dbcounter [-] Registered counter for database nova_cell1 DEBUG dbcounter [-] [394531] Writer thread running {{(pid=394531) stat_writer /usr/local/lib/python3.8/dist-packages/dbcounter.py:99}}
Finally glance fails to load the plugin in the g-api service when an image upload is requested:
+functions:_upload_image:121 openstack --os-cloud=devstack-admin --os-region-name=RegionOne image create cirros-0.5.2-x86_64-disk --public --container-format bare --disk-format qcow2 --property hw_rng_model=virtio /usr/lib/python3/dist-packages/secretstorage/dhcrypto.py:15: CryptographyDeprecationWarning: int_from_bytes is deprecated, use int.from_bytes instead from cryptography.utils import int_from_bytes /usr/lib/python3/dist-packages/secretstorage/util.py:19: CryptographyDeprecationWarning: int_from_bytes is deprecated, use int.from_bytes instead from cryptography.utils import int_from_bytes HttpException: 500: Server Error for url: http://192.168.42.11/image/v2/images, The server has either erred or is incapable of performing the requested operation.: 500 Internal Server Error
With this ^ I realized that restarting g-api might not have been a good indicator of anything resolving because in this example the plugin load failure occurs while checking quota for an inbound request. I'm not sure whether services load the dbcounter passively when they start or if it's only when database accesses are initiated.
I also don't understand how or why one project can't load the plugin but the rest can. And I wonder whether it's a coincidence that it was glance in the two examples we have so far.
-melwitt
I was hitting with the same error but as a workaround so far Dan (Smith) suggested a re-stack with "MYSQL_GATHER_PERFORMANCE=False" and it worked. This setting will avoid trying to load that plugin
- abhishekk
participants (2)
-
Abhishek Kekane
-
melanie witt