← Back to team overview

yahoo-eng-team team mailing list archive

[Bug 1395976] [NEW] threads not sharing dataspace

 

Public bug reported:

Hi,

with juno stable code on x64 bit machine (on ubuntu and centos 7)  is
has been observed that threads spawned inside ML2 plugin not sharing the
data space.

To Reproduce the issue investigator can use the below sample ML2 driver
and verify that  producer thread not able to communicate with consumer
thread.

This issue can be circumvented by modifying /etc/neutron/neutron.conf
"api_workers=0" (before process are forked)

This issue is observed only on X64bit machine.(ubuntu 64 bit and centos
7 64bit)

Sample Code:

import threading
from Queue import Queue
import time
import sys
from oslo.config import cfg
from neutron.openstack.common import log as logger
from neutron import context as neutron_context
from neutron.extensions import portbindings
from neutron.plugins.ml2 import db
from neutron.common import constants as n_const
from neutron.plugins.common import constants as p_const
from neutron.plugins.ml2 import driver_api as api

LOG = logger.getLogger(__name__)
MECHANISM_VERSION = 1.0


class my_thread(threading.Thread):
    def __init__ (self):
        LOG.info(_("my_thread init"))
        self._q = Queue()
        self.temp = 10
        threading.Thread.__init__ (self)
        self.setDaemon(True)
        self.setName('session')
        self.start()
    def send(self, msg):
        LOG.info(_('###DEBUG send producer data %s'), msg)
        self.temp +=1
        self._q.put(msg)
        self._q.join()


class count_stuff(my_thread):
    """
        A thread class that will count a number, sleep and output that number
    """
    def __init__ (self):
        super(count_stuff, self).__init__()
        LOG.info(_("count_stuff init"))
 def run(self):
        while True:
            if not self._q.empty():
                data = self._q.get()
                LOG.info(_('###DEBUG run temp = %s'), self.temp)
                LOG.info(_('###DEBUG run consumer data %s'), data)
                self._q.task_done()
            time.sleep(1)

class nos_driver():
   def __init__(self):
       self.myThread = count_stuff()


class BrocadeMechanism(api.MechanismDriver):

    def initialize(self):
        LOG.info(_('init'))
        self.t = nos_driver()
        self.t.myThread.send('init')
        LOG.info(_('Hi I am getting intialzed'))
        self.t.myThread.send('Hi I am getting intialzed')

    def create_network_precommit(self, mech_context):
        self.t.myThread.send('create_network_precommit')

    def create_network_postcommit(self, mech_context):
        self.t.myThread.send('create_network_postcommit')

    def delete_network_precommit(self, mech_context):
        self.t.myThread.send('delete_network_precommit')

    def delete_network_postcommit(self, mech_context):
        self.t.myThread.send('delete_network_postcommit')

    def update_network_precommit(self, mech_context):
        """Noop now, it is left here for future."""
        pass

    def update_network_postcommit(self, mech_context):
        """Noop now, it is left here for future."""

 def create_port_precommit(self, mech_context):
         self.t.myThread.send('create_port_precommit')

    def create_port_postcommit(self, mech_context):
         self.t.myThread.send('create_port_postcommit')

    def delete_port_precommit(self, mech_context):
         self.t.myThread.send('delete_port_precommit')

    def delete_port_postcommit(self, mech_context):
         self.t.myThread.send('delete_port_postcommit')

    def update_port_postcommit(self, mech_context):
         self.t.myThread.send('update_port_postcommit')

    def update_port_precommit(self, mech_context):
         self.t.myThread.send('update_port_precommit')

    def create_subnet_precommit(self, mech_context):
        """Noop now, it is left here for future."""
        LOG.debug(_("create_subnetwork_precommit: called"))

    def create_subnet_postcommit(self, mech_context):
        """Noop now, it is left here for future."""
        LOG.debug(_("create_subnetwork_postcommit: called"))

    def delete_subnet_precommit(self, mech_context):
        """Noop now, it is left here for future."""
        LOG.debug(_("delete_subnetwork_precommit: called"))

    def delete_subnet_postcommit(self, mech_context):
        """Noop now, it is left here for future."""
        LOG.debug(_("delete_subnetwork_postcommit: called"))

    def update_subnet_precommit(self, mech_context):
        """Noop now, it is left here for future."""
        LOG.debug(_("update_subnet_precommit(self: called"))

    def update_subnet_postcommit(self, mech_context):
        """Noop now, it is left here for future."""
        LOG.debug(_("update_subnet_postcommit: called"))


Logs:

Intially before thread launched producer and consumer thread sharing the dataspace.
S,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION _check_effective_sql_mode /usr/lib/python2.7/site-packages/oslo/db/sqlalchemy/session.py:482
2014-11-23 22:44:27.421 30490 INFO neutron.plugins.ml2.drivers.type_vlan [-] VlanTypeDriver initialization complete
2014-11-23 22:44:27.422 30490 INFO neutron.plugins.ml2.managers [-] Initializing mechanism driver 'openvswitch'
2014-11-23 22:44:27.422 30490 INFO neutron.plugins.ml2.managers [-] Initializing mechanism driver 'brocade'
2014-11-23 22:44:27.422 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] init
2014-11-23 22:44:27.423 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] my_thread init
2014-11-23 22:44:27.423 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] count_stuff init
2014-11-23 22:44:27.424 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] ###DEBUG send producer data init
2014-11-23 22:44:28.424 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] ###DEBUG run temp = 11
2014-11-23 22:44:28.424 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] ###DEBUG run consumer data init
2014-11-23 22:44:28.425 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] Hi I am getting intialzed
2014-11-23 22:44:28.425 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] ###DEBUG send producer data Hi I am getting intialzed
2014-11-23 22:44:29.426 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] ###DEBUG run temp = 12
2014-11-23 22:44:29.427 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] ###DEBUG run consumer data Hi I am getting intialzed
2014-11-23 22:44:29.428 30490 INFO neutron.plugins.ml2.plugin [-] Modular L2 Plugin initialization complete

After process forked producer and consumer threads dont communicate and
this leads into all commands hand for eg:'neutron net-create net1'.

Logs:
d_segment /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/helpers.py:130
2014-11-23 22:45:45.725 30512 INFO neutron.plugins.ml2.db [req-018d1af2-674a-4921-a964-1c6c52eab6cb None] Added segment 915aeae4-17c1-4171-8870-e97817a91869 of type vlan for network 3c5b4592-9bb4-48b8-bfe4-01143b864114
2014-11-23 22:45:45.731 30512 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [req-018d1af2-674a-4921-a964-1c6c52eab6cb None] ###DEBUG send producer data create_network_precommit
2014-11-23 22:45:54.155 30515 DEBUG neutron.context [req-ba6f1f69-8515-4add-bdb8-028b3d8d5c91 None] Arguments dropped when creating context: {u'project_name': None, u'tenant': None} __init__ /usr/lib/python2.7/site-packages/neutron/context.py:83
2014-11-23 22:45:54.575 30516 DEBUG neutron.context [req-81c50124-db35-4d92-8e92-c10ca970f40e None] Arguments dropped when creating context: {u'project_name': None, u'tenant': None} __init__ /usr/lib/python2.7/site-packages/neutron/context.py:83
2014-11-23 22:45:56.316 30513 DEBUG neutron.context [req-f8ea5da2-1355-48dc-8dc7-f967968daca7 None] Arguments dropped when creating context: {u'project_name': None, u'tenant': None} __init__ /usr/lib/python2.7/site-packages/neutron/context.py:83
2014-11-23 22:46:24.156 30514 DEBUG neutron.context [req-ba6f1f69-851

** Affects: neutron
     Importance: Undecided
         Status: New

** Attachment added: "mechanism_brocade.py"
   https://bugs.launchpad.net/bugs/1395976/+attachment/4267291/+files/mechanism_brocade.py

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

Title:
  threads not sharing dataspace

Status in OpenStack Neutron (virtual network service):
  New

Bug description:
  Hi,

  with juno stable code on x64 bit machine (on ubuntu and centos 7)  is
  has been observed that threads spawned inside ML2 plugin not sharing
  the data space.

  To Reproduce the issue investigator can use the below sample ML2
  driver and verify that  producer thread not able to communicate with
  consumer thread.

  This issue can be circumvented by modifying /etc/neutron/neutron.conf
  "api_workers=0" (before process are forked)

  This issue is observed only on X64bit machine.(ubuntu 64 bit and
  centos 7 64bit)

  Sample Code:

  import threading
  from Queue import Queue
  import time
  import sys
  from oslo.config import cfg
  from neutron.openstack.common import log as logger
  from neutron import context as neutron_context
  from neutron.extensions import portbindings
  from neutron.plugins.ml2 import db
  from neutron.common import constants as n_const
  from neutron.plugins.common import constants as p_const
  from neutron.plugins.ml2 import driver_api as api

  LOG = logger.getLogger(__name__)
  MECHANISM_VERSION = 1.0

  
  class my_thread(threading.Thread):
      def __init__ (self):
          LOG.info(_("my_thread init"))
          self._q = Queue()
          self.temp = 10
          threading.Thread.__init__ (self)
          self.setDaemon(True)
          self.setName('session')
          self.start()
      def send(self, msg):
          LOG.info(_('###DEBUG send producer data %s'), msg)
          self.temp +=1
          self._q.put(msg)
          self._q.join()

  
  class count_stuff(my_thread):
      """
          A thread class that will count a number, sleep and output that number
      """
      def __init__ (self):
          super(count_stuff, self).__init__()
          LOG.info(_("count_stuff init"))
   def run(self):
          while True:
              if not self._q.empty():
                  data = self._q.get()
                  LOG.info(_('###DEBUG run temp = %s'), self.temp)
                  LOG.info(_('###DEBUG run consumer data %s'), data)
                  self._q.task_done()
              time.sleep(1)

  class nos_driver():
     def __init__(self):
         self.myThread = count_stuff()

  
  class BrocadeMechanism(api.MechanismDriver):

      def initialize(self):
          LOG.info(_('init'))
          self.t = nos_driver()
          self.t.myThread.send('init')
          LOG.info(_('Hi I am getting intialzed'))
          self.t.myThread.send('Hi I am getting intialzed')

      def create_network_precommit(self, mech_context):
          self.t.myThread.send('create_network_precommit')

      def create_network_postcommit(self, mech_context):
          self.t.myThread.send('create_network_postcommit')

      def delete_network_precommit(self, mech_context):
          self.t.myThread.send('delete_network_precommit')

      def delete_network_postcommit(self, mech_context):
          self.t.myThread.send('delete_network_postcommit')

      def update_network_precommit(self, mech_context):
          """Noop now, it is left here for future."""
          pass

      def update_network_postcommit(self, mech_context):
          """Noop now, it is left here for future."""

   def create_port_precommit(self, mech_context):
           self.t.myThread.send('create_port_precommit')

      def create_port_postcommit(self, mech_context):
           self.t.myThread.send('create_port_postcommit')

      def delete_port_precommit(self, mech_context):
           self.t.myThread.send('delete_port_precommit')

      def delete_port_postcommit(self, mech_context):
           self.t.myThread.send('delete_port_postcommit')

      def update_port_postcommit(self, mech_context):
           self.t.myThread.send('update_port_postcommit')

      def update_port_precommit(self, mech_context):
           self.t.myThread.send('update_port_precommit')

      def create_subnet_precommit(self, mech_context):
          """Noop now, it is left here for future."""
          LOG.debug(_("create_subnetwork_precommit: called"))

      def create_subnet_postcommit(self, mech_context):
          """Noop now, it is left here for future."""
          LOG.debug(_("create_subnetwork_postcommit: called"))

      def delete_subnet_precommit(self, mech_context):
          """Noop now, it is left here for future."""
          LOG.debug(_("delete_subnetwork_precommit: called"))

      def delete_subnet_postcommit(self, mech_context):
          """Noop now, it is left here for future."""
          LOG.debug(_("delete_subnetwork_postcommit: called"))

      def update_subnet_precommit(self, mech_context):
          """Noop now, it is left here for future."""
          LOG.debug(_("update_subnet_precommit(self: called"))

      def update_subnet_postcommit(self, mech_context):
          """Noop now, it is left here for future."""
          LOG.debug(_("update_subnet_postcommit: called"))


  Logs:

  Intially before thread launched producer and consumer thread sharing the dataspace.
  S,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION _check_effective_sql_mode /usr/lib/python2.7/site-packages/oslo/db/sqlalchemy/session.py:482
  2014-11-23 22:44:27.421 30490 INFO neutron.plugins.ml2.drivers.type_vlan [-] VlanTypeDriver initialization complete
  2014-11-23 22:44:27.422 30490 INFO neutron.plugins.ml2.managers [-] Initializing mechanism driver 'openvswitch'
  2014-11-23 22:44:27.422 30490 INFO neutron.plugins.ml2.managers [-] Initializing mechanism driver 'brocade'
  2014-11-23 22:44:27.422 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] init
  2014-11-23 22:44:27.423 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] my_thread init
  2014-11-23 22:44:27.423 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] count_stuff init
  2014-11-23 22:44:27.424 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] ###DEBUG send producer data init
  2014-11-23 22:44:28.424 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] ###DEBUG run temp = 11
  2014-11-23 22:44:28.424 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] ###DEBUG run consumer data init
  2014-11-23 22:44:28.425 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] Hi I am getting intialzed
  2014-11-23 22:44:28.425 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] ###DEBUG send producer data Hi I am getting intialzed
  2014-11-23 22:44:29.426 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] ###DEBUG run temp = 12
  2014-11-23 22:44:29.427 30490 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [-] ###DEBUG run consumer data Hi I am getting intialzed
  2014-11-23 22:44:29.428 30490 INFO neutron.plugins.ml2.plugin [-] Modular L2 Plugin initialization complete

  After process forked producer and consumer threads dont communicate
  and this leads into all commands hand for eg:'neutron net-create
  net1'.

  Logs:
  d_segment /usr/lib/python2.7/site-packages/neutron/plugins/ml2/drivers/helpers.py:130
  2014-11-23 22:45:45.725 30512 INFO neutron.plugins.ml2.db [req-018d1af2-674a-4921-a964-1c6c52eab6cb None] Added segment 915aeae4-17c1-4171-8870-e97817a91869 of type vlan for network 3c5b4592-9bb4-48b8-bfe4-01143b864114
  2014-11-23 22:45:45.731 30512 INFO neutron.plugins.ml2.drivers.brocade.mechanism_brocade [req-018d1af2-674a-4921-a964-1c6c52eab6cb None] ###DEBUG send producer data create_network_precommit
  2014-11-23 22:45:54.155 30515 DEBUG neutron.context [req-ba6f1f69-8515-4add-bdb8-028b3d8d5c91 None] Arguments dropped when creating context: {u'project_name': None, u'tenant': None} __init__ /usr/lib/python2.7/site-packages/neutron/context.py:83
  2014-11-23 22:45:54.575 30516 DEBUG neutron.context [req-81c50124-db35-4d92-8e92-c10ca970f40e None] Arguments dropped when creating context: {u'project_name': None, u'tenant': None} __init__ /usr/lib/python2.7/site-packages/neutron/context.py:83
  2014-11-23 22:45:56.316 30513 DEBUG neutron.context [req-f8ea5da2-1355-48dc-8dc7-f967968daca7 None] Arguments dropped when creating context: {u'project_name': None, u'tenant': None} __init__ /usr/lib/python2.7/site-packages/neutron/context.py:83
  2014-11-23 22:46:24.156 30514 DEBUG neutron.context [req-ba6f1f69-851

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


Follow ups

References