yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1831009] [NEW] Improper close connection to database leading to mysql/mariadb block connection.

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: puthi <puthi@xxxxxxxx>
Date: Thu, 30 May 2019 04:42:56 -0000
Reply-to: Bug 1831009 <1831009@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Version
=======
Neutron-server: openstack-neutron-13.0.2-1.el7.noarch
Nova: openstack-nova-*-18.2.0-1.el7.noarch
Mariadb: mariadb-server-10.1.20-2.el7.x86_64

Openstack setup:
================
HAproxy => 3 Controllers (nova,neutron,keystone) => Mariadb

Error
=====
As my Openstack cluster grow, more and more people start using the cluster, i start seeing this error everyday now

2019-05-30 10:42:15.695 44938 ERROR oslo_db.sqlalchemy.exc_filters [req-
b6fd59b9-8378-49df-bbf6-de9f9b741490 - - - - -] DBAPIError exception
wrapped from (pymysql.err.InternalError) (1129, u"Host 'xx.xx.xx.xx' is
blocked because of many connection errors; unblock with 'mysqladmin
flush-hosts'") (Background on this error at: http://sqlalche.me/e/2j85):
InternalError: (1129, u"Host 'xx.xx.xx.xx' is blocked because of many
connection errors; unblock with 'mysqladmin flush-hosts'")

This is not necessary happens to only neutron but all of the components
of openstack. And when i turn log_warnings=4 in Mariadb, I can see in
the log of Mariadb as below:


2019-05-27 10:22:04 140078484511488 [Warning] Aborted connection 70834104 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
2019-05-27 10:22:05 140084673243904 [Warning] Aborted connection 70834111 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
2019-05-27 10:22:07 140078500485888 [Warning] Aborted connection 70834211 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
2019-05-27 10:22:07 140078490655488 [Warning] Aborted connection 70834157 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
2019-05-27 10:22:09 140078698322688 [Warning] Aborted connection 70834327 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
2019-05-27 10:22:12 140078715833088 [Warning] Aborted connection 70894166 to db: 'unconnected' user: 'neutron' host: 'controller2' (CLOSE_CONNECTION)
2019-05-27 10:22:13 140078737951488 [Warning] Aborted connection 70834380 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
2019-05-27 10:22:17 140078641797888 [Warning] Aborted connection 70834382 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
2019-05-27 10:22:21 140078581893888 [Warning] Aborted connection 70834436 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
2019-05-27 10:22:22 140078724434688 [Warning] Aborted connection 70834469 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
2019-05-27 10:22:28 140078715833088 [Warning] Aborted connection 70894174 to db: 'unconnected' user: 'unauthenticated' host: 'controller2' (CLOSE_CONNECTION)
2019-05-27 10:22:29 140078715833088 [Warning] Aborted connection 70894177 to db: 'neutron' user: 'neutron' host: 'controller2' (CLOSE_CONNECTION)
...
2019-05-30  7:35:28 140078596025088 [Warning] Aborted connection 72547571 to db: 'nova' user: 'nova' host: 'controller1' (Got an error reading communication packets)
2019-05-30  7:46:54 140078541036288 [Warning] Aborted connection 72552087 to db: 'nova_cell0' user: 'nova' host: 'controller1' (Got an error reading communication packets)
2019-05-30  7:46:57 140078799182592 [Warning] Aborted connection 72552086 to db: 'nova' user: 'nova' host: 'controller1' (Got an error reading communication packets)
2019-05-30  7:47:02 140078738565888 [Warning] Aborted connection 72534613 to db: 'nova_cell0' user: 'nova' host: 'controller1' (Got an error reading communication packets)
2019-05-30  8:31:11 140078638418688 [Warning] Aborted connection 72419897 to db: 'nova' user: 'nova' host: 'controller3' (Got timeout reading communication packets)
2019-05-30  8:36:22 140078791195392 [Warning] Aborted connection 72421900 to db: 'nova' user: 'nova' host: 'controller2' (Got timeout reading communication packets)
2019-05-30  8:46:23 140078624594688 [Warning] Aborted connection 72577413 to db: 'nova_cell0' user: 'nova' host: 'controller1' (Got an error reading communication packets)
2019-05-30  8:46:26 140078716447488 [Warning] Aborted connection 72577414 to db: 'nova' user: 'nova' host: 'controller1' (Got an error reading communication packets)
2019-05-30 10:45:23 140078661151488 [Warning] Aborted connection 72675103 to db: 'neutron' user: 'neutron' host: 'controller3' (Got an error reading communication packets)
2019-05-30 10:45:23 140078672517888 [Warning] Aborted connection 72675137 to db: 'neutron' user: 'neutron' host: 'controller3' (Got an error reading communication packets)
2019-05-30 10:45:23 140078768155392 [Warning] Aborted connection 72674638 to db: 'neutron' user: 'neutron' host: 'controller3' (Got an error reading communication packets)
2019-05-30 10:45:23 140078647327488 [Warning] Aborted connection 72674581 to db: 'neutron' user: 'neutron' host: 'controller3' (Got an error reading communication packets)


I also notice that every times i restart any services (nova/neutron/keystone) i can see that warning "Got an error reading communication packets" appear in Mariadb log. And i think when the connection is properly closed, the Mariadb log will give "CLOSE_CONNECTION" instead of that error. 
So, i wonder if this is a bug in Openstack Rocky version as i don't see this behavior in other version.

** Affects: neutron
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1831009

Title:
  Improper close connection to database leading to mysql/mariadb block
  connection.

Status in neutron:
  New

Bug description:
  Version
  =======
  Neutron-server: openstack-neutron-13.0.2-1.el7.noarch
  Nova: openstack-nova-*-18.2.0-1.el7.noarch
  Mariadb: mariadb-server-10.1.20-2.el7.x86_64

  Openstack setup:
  ================
  HAproxy => 3 Controllers (nova,neutron,keystone) => Mariadb

  Error
  =====
  As my Openstack cluster grow, more and more people start using the cluster, i start seeing this error everyday now

  2019-05-30 10:42:15.695 44938 ERROR oslo_db.sqlalchemy.exc_filters
  [req-b6fd59b9-8378-49df-bbf6-de9f9b741490 - - - - -] DBAPIError
  exception wrapped from (pymysql.err.InternalError) (1129, u"Host
  'xx.xx.xx.xx' is blocked because of many connection errors; unblock
  with 'mysqladmin flush-hosts'") (Background on this error at:
  http://sqlalche.me/e/2j85): InternalError: (1129, u"Host 'xx.xx.xx.xx'
  is blocked because of many connection errors; unblock with 'mysqladmin
  flush-hosts'")

  This is not necessary happens to only neutron but all of the
  components of openstack. And when i turn log_warnings=4 in Mariadb, I
  can see in the log of Mariadb as below:

  
  2019-05-27 10:22:04 140078484511488 [Warning] Aborted connection 70834104 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
  2019-05-27 10:22:05 140084673243904 [Warning] Aborted connection 70834111 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
  2019-05-27 10:22:07 140078500485888 [Warning] Aborted connection 70834211 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
  2019-05-27 10:22:07 140078490655488 [Warning] Aborted connection 70834157 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
  2019-05-27 10:22:09 140078698322688 [Warning] Aborted connection 70834327 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
  2019-05-27 10:22:12 140078715833088 [Warning] Aborted connection 70894166 to db: 'unconnected' user: 'neutron' host: 'controller2' (CLOSE_CONNECTION)
  2019-05-27 10:22:13 140078737951488 [Warning] Aborted connection 70834380 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
  2019-05-27 10:22:17 140078641797888 [Warning] Aborted connection 70834382 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
  2019-05-27 10:22:21 140078581893888 [Warning] Aborted connection 70834436 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
  2019-05-27 10:22:22 140078724434688 [Warning] Aborted connection 70834469 to db: 'nova' user: 'nova' host: 'controller3' (CLOSE_CONNECTION)
  2019-05-27 10:22:28 140078715833088 [Warning] Aborted connection 70894174 to db: 'unconnected' user: 'unauthenticated' host: 'controller2' (CLOSE_CONNECTION)
  2019-05-27 10:22:29 140078715833088 [Warning] Aborted connection 70894177 to db: 'neutron' user: 'neutron' host: 'controller2' (CLOSE_CONNECTION)
  ...
  2019-05-30  7:35:28 140078596025088 [Warning] Aborted connection 72547571 to db: 'nova' user: 'nova' host: 'controller1' (Got an error reading communication packets)
  2019-05-30  7:46:54 140078541036288 [Warning] Aborted connection 72552087 to db: 'nova_cell0' user: 'nova' host: 'controller1' (Got an error reading communication packets)
  2019-05-30  7:46:57 140078799182592 [Warning] Aborted connection 72552086 to db: 'nova' user: 'nova' host: 'controller1' (Got an error reading communication packets)
  2019-05-30  7:47:02 140078738565888 [Warning] Aborted connection 72534613 to db: 'nova_cell0' user: 'nova' host: 'controller1' (Got an error reading communication packets)
  2019-05-30  8:31:11 140078638418688 [Warning] Aborted connection 72419897 to db: 'nova' user: 'nova' host: 'controller3' (Got timeout reading communication packets)
  2019-05-30  8:36:22 140078791195392 [Warning] Aborted connection 72421900 to db: 'nova' user: 'nova' host: 'controller2' (Got timeout reading communication packets)
  2019-05-30  8:46:23 140078624594688 [Warning] Aborted connection 72577413 to db: 'nova_cell0' user: 'nova' host: 'controller1' (Got an error reading communication packets)
  2019-05-30  8:46:26 140078716447488 [Warning] Aborted connection 72577414 to db: 'nova' user: 'nova' host: 'controller1' (Got an error reading communication packets)
  2019-05-30 10:45:23 140078661151488 [Warning] Aborted connection 72675103 to db: 'neutron' user: 'neutron' host: 'controller3' (Got an error reading communication packets)
  2019-05-30 10:45:23 140078672517888 [Warning] Aborted connection 72675137 to db: 'neutron' user: 'neutron' host: 'controller3' (Got an error reading communication packets)
  2019-05-30 10:45:23 140078768155392 [Warning] Aborted connection 72674638 to db: 'neutron' user: 'neutron' host: 'controller3' (Got an error reading communication packets)
  2019-05-30 10:45:23 140078647327488 [Warning] Aborted connection 72674581 to db: 'neutron' user: 'neutron' host: 'controller3' (Got an error reading communication packets)

  
  I also notice that every times i restart any services (nova/neutron/keystone) i can see that warning "Got an error reading communication packets" appear in Mariadb log. And i think when the connection is properly closed, the Mariadb log will give "CLOSE_CONNECTION" instead of that error. 
  So, i wonder if this is a bug in Openstack Rocky version as i don't see this behavior in other version.

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1831009/+subscriptions
Follow ups

[Bug 1831009] Re: Improper close connection to database leading to mysql/mariadb block connection.
From: Brian Haley, 2023-01-24