Re: [openstack-dev] [neutron] InvalidRequestError: This session is in 'prepared' state; no further SQL can be emitted within this transaction.

2016-01-12 Thread Koteswar
I tried rollback but still it didn't work. This issue is reproduced
sometimes only when
1. neutron port created
2. enable fixed looping in conf, stop neutron and start
3. delete neutron port

and looping interval is very lesss say 20 secs.
source code where it fails:
--
def get_bnp_neutron_port(context, neutron_port_id):
"""Get bnp neutron port that matches neutron_port_id."""
try:
query = context.session.query(models.BNPNeutronPort)
port_map = query.filter_by(neutron_port_id=neutron_port_id).one()
except exc.NoResultFound:
LOG.error(_LE('no port map found with id: %s'), port_map)
return
except Exception as e:
LOG.error("BNP Exception: %s", e)
context.session.rollback()
return
return port_map

trace:
-
2016-01-12 07:00:54.421 ERROR
baremetal_network_provisioning.db.bm_nw_provision_db
[req-79c61136-2f15-40b6-a0c7-074848d87d6e admin
1395aaf0481f4bc9b8fbbe555fe1] BNP Exception: This se
ssion is in 'prepared' state; no further SQL can be emitted within this
transaction.
2016-01-12 07:00:54.421 ERROR oslo_db.sqlalchemy.exc_filters
[req-79c61136-2f15-40b6-a0c7-074848d87d6e admin
1395aaf0481f4bc9b8fbbe555fe1] DB exception wrapped.
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters Traceback
(most recent call last):
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters   File
"/usr/local/lib/python2.7/dist-packages/sqlalchemy/engine/base.py", line
668, in _rollback_impl
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters
self.engine.dialect.do_rollback(self.connection)
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters   File
"/usr/local/lib/python2.7/dist-packages/sqlalchemy/dialects/mysql/base.py",
line 2519, in do_rollback
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters
dbapi_connection.rollback()
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters   File
"/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 724,
in rollback
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters
self._read_ok_packet()
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters   File
"/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 698,
in _read_ok_packet
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters pkt =
self._read_packet()
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters   File
"/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 895,
in _read_packet
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters
packet_header = self._read_bytes(4)
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters   File
"/usr/local/lib/python2.7/dist-packages/pymysql/connections.py", line 912,
in _read_bytes
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters data =
self._rfile.read(num_bytes)
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters RuntimeError:
reentrant call inside <_io.BufferedReader name=3>
2016-01-12 07:00:54.421 TRACE oslo_db.sqlalchemy.exc_filters
2016-01-12 07:00:54.433 ERROR neutron.plugins.ml2.managers
[req-79c61136-2f15-40b6-a0c7-074848d87d6e admin
1395aaf0481f4bc9b8fbbe555fe1] Mechanism driver 'hp' failed in
delete_port_pr
ecommit


On Mon, Jan 11, 2016 at 7:39 PM, Koteswar  wrote:

> thanks a lot. I will try this.
>
> On Mon, Jan 11, 2016 at 7:26 PM, Mike Bayer  wrote:
>
>>
>>
>> On 01/11/2016 03:58 AM, Koteswar wrote:
>> > Hi All,
>> >
>> >
>> >
>> > In my mechanism driver, I am reading/writing into sql db in a fixed
>> > interval looping call. Sometimes I get the following error when I stop
>> > and start neutron server
>> >
>> > InvalidRequestError: This session is in 'prepared' state; no further SQL
>> > can be emitted within this transaction.
>> >
>> >
>> >
>> > I am using context.session.query() for add, delete, update and get.
>> > Please help me if any one resolved an issue like this.
>>
>> the stack trace is unfortunately re-thrown from the ml2.managers code
>> without retaining the original traceback; use this form to reraise with
>> original tb:
>>
>> exc_info = sys.exc_info()
>> raise type(e), e, exc_info[2]
>>
>> There's likely helpers somewhere in oslo that do this.
>>
>> The cause of this error is that a transaction commit is failing, the
>> error is being caught and this same Session is being used again without
>> rollback called first.   The code below illustrates the problem and how
>> to solve.
>>
>> from sqlalchemy import create_engine
>> from sqlalchemy.orm import Session
>>
>>
>> e = create_engine("sqlite://")
>>
>> s = Session(e)
>>
>>
>> conn = s.connection()
>>
>>
>> def boom():
>> raise Exception("sqlite commit failed")
>>
>> # "break" connection.commit(),
>> # so that the commit fails
>> conn.connection.commit = boom
>> try:
>> # fail
>> s.commit()
>> except Exception, e:
>> # uncomment this to fix 

Re: [openstack-dev] [neutron] InvalidRequestError: This session is in 'prepared' state; no further SQL can be emitted within this transaction.

2016-01-11 Thread Koteswar
vendor specific mech driver code, where I am doing some read/write to sql.

def _create_port(self, port): switchports = port['port']['switchports']
LOG.debug(_LE("_create_port switch: %s"), port) network_id = port['port']['
network_id'] subnets = db.get_subnets_by_network(self.context, network_id)
if not subnets: LOG.error("Subnet not found for the network")
self._raise_ml2_error(wexc.HTTPNotFound,
'create_port') for switchport in switchports: switch_mac_id = switchport['
switch_id'] port_id = switchport['port_id'] bnp_switch =
db.get_bnp_phys_switch_by_mac(self.context, switch_mac_id) # check for port
and switch level existence if not bnp_switch: LOG.error(_LE("No physical
switch found '%s' "), switch_mac_id) self._raise_ml2_error(wexc.HTTPNotFound,
'create_port') phys_port = db.get_bnp_phys_port(self.context, bnp_switch.id,
port_id) if not phys_port: LOG.error(_LE("No physical port found for '%s' "),
phys_port) self._raise_ml2_error(wexc.HTTPNotFound, 'create_port') if
bnp_switch.status != constants.SWITCH_STATUS['enable']: LOG.error(_LE("Physical
switch is not Enabled '%s' "), bnp_switch.status)
self._raise_ml2_error(wexc.HTTPBadRequest,
'create_port')

On Mon, Jan 11, 2016 at 2:47 PM, Anna Kamyshnikova <
akamyshnik...@mirantis.com> wrote:

> Hi!
>
> Can you point what mechanism driver is this or the piece of code that give
> this error?
>
> On Mon, Jan 11, 2016 at 11:58 AM, Koteswar  wrote:
>
>> Hi All,
>>
>>
>>
>> In my mechanism driver, I am reading/writing into sql db in a fixed
>> interval looping call. Sometimes I get the following error when I stop and
>> start neutron server
>>
>> InvalidRequestError: This session is in 'prepared' state; no further SQL
>> can be emitted within this transaction.
>>
>>
>>
>> I am using context.session.query() for add, delete, update and get.
>> Please help me if any one resolved an issue like this.
>>
>>
>>
>> Full trace is as follows:
>>
>> 2016-01-06 15:33:21.799 [01;31mERROR neutron.plugins.ml2.managers
>> [[01;36mreq-d940a1b6-253a-43d2-b5ff-6c784c8a520f [00;36madmin
>> 83b5358da62a407f88155f447966356f[01;31m] [01;35m[01;31mMechanism driver
>> 'hp' failed in create_port_precommit[00m
>>
>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>> [01;35m[00mTraceback (most recent call last):
>>
>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>> [01;35m[00m  File "/opt/stack/neutron/neutron/plugins/ml2/managers.py",
>> line 394, in _call_on_drivers
>>
>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>> [01;35m[00mgetattr(driver.obj, method_name)(context)
>>
>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>> [01;35m[00m  File
>> "/usr/local/lib/python2.7/dist-packages/baremetal_network_provisioning/ml2/mechanism_hp.py",
>> line 67, in create_port_precommit
>>
>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>> [01;35m[00mraise e
>>
>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>> [01;35m[00mInvalidRequestError: This session is in 'prepared' state; no
>> further SQL can be emitted within this transaction.
>>
>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>> [01;35m[00m
>>
>> 2016-01-06 15:33:21.901 [01;31mERROR neutron.api.v2.resource
>> [[01;36mreq-d940a1b6-253a-43d2-b5ff-6c784c8a520f [00;36madmin
>> 83b5358da62a407f88155f447966356f[01;31m] [01;35m[01;31mcreate failed[00m
>>
>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>> [01;35m[00mTraceback (most recent call last):
>>
>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
>> File "/opt/stack/neutron/neutron/api/v2/resource.py", line 83, in resource
>>
>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>> [01;35m[00mresult = method(request=request, **args)
>>
>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
>> File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 146, in
>> wrapper
>>
>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>> [01;35m[00mectxt.value = e.inner_exc
>>
>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
>> File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line
>> 195, in __exit__
>>
>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>> [01;35m[00msix.reraise(self.type_, self.value, self.tb)
>>
>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
>> File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 136, in
>> wrapper
>>
>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>> [01;35m[00mreturn f(*args, **kwargs)
>>
>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
>> File "/opt/stack/neutron/neutron/api/v2/base.py", line 516, in create
>>
>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>> [01;35m[00mobj = do_create(body)
>>
>> [01;31m2016-01-06 

[openstack-dev] [neutron] InvalidRequestError: This session is in 'prepared' state; no further SQL can be emitted within this transaction.

2016-01-11 Thread Koteswar
Hi All,



In my mechanism driver, I am reading/writing into sql db in a fixed
interval looping call. Sometimes I get the following error when I stop and
start neutron server

InvalidRequestError: This session is in 'prepared' state; no further SQL
can be emitted within this transaction.



I am using context.session.query() for add, delete, update and get. Please
help me if any one resolved an issue like this.



Full trace is as follows:

2016-01-06 15:33:21.799 [01;31mERROR neutron.plugins.ml2.managers
[[01;36mreq-d940a1b6-253a-43d2-b5ff-6c784c8a520f [00;36madmin
83b5358da62a407f88155f447966356f[01;31m] [01;35m[01;31mMechanism driver
'hp' failed in create_port_precommit[00m

[01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
[01;35m[00mTraceback (most recent call last):

[01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
[01;35m[00m  File "/opt/stack/neutron/neutron/plugins/ml2/managers.py",
line 394, in _call_on_drivers

[01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
[01;35m[00mgetattr(driver.obj, method_name)(context)

[01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
[01;35m[00m  File
"/usr/local/lib/python2.7/dist-packages/baremetal_network_provisioning/ml2/mechanism_hp.py",
line 67, in create_port_precommit

[01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
[01;35m[00mraise e

[01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
[01;35m[00mInvalidRequestError: This session is in 'prepared' state; no
further SQL can be emitted within this transaction.

[01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
[01;35m[00m

2016-01-06 15:33:21.901 [01;31mERROR neutron.api.v2.resource
[[01;36mreq-d940a1b6-253a-43d2-b5ff-6c784c8a520f [00;36madmin
83b5358da62a407f88155f447966356f[01;31m] [01;35m[01;31mcreate failed[00m

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
[01;35m[00mTraceback (most recent call last):

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
File "/opt/stack/neutron/neutron/api/v2/resource.py", line 83, in resource

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
result = method(request=request, **args)

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 146, in
wrapper

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
ectxt.value = e.inner_exc

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line
195, in __exit__

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
six.reraise(self.type_, self.value, self.tb)

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 136, in
wrapper

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
return f(*args, **kwargs)

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
File "/opt/stack/neutron/neutron/api/v2/base.py", line 516, in create

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
obj = do_create(body)

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
File "/opt/stack/neutron/neutron/api/v2/base.py", line 498, in do_create

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
request.context, reservation.reservation_id)

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line
195, in __exit__

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
six.reraise(self.type_, self.value, self.tb)

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
File "/opt/stack/neutron/neutron/api/v2/base.py", line 491, in do_create

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
return obj_creator(request.context, **kwargs)

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 146, in
wrapper

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
ectxt.value = e.inner_exc

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line
195, in __exit__

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
six.reraise(self.type_, self.value, self.tb)

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 136, in
wrapper

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
return f(*args, **kwargs)

[01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
File 

Re: [openstack-dev] [neutron] InvalidRequestError: This session is in 'prepared' state; no further SQL can be emitted within this transaction.

2016-01-11 Thread Anna Kamyshnikova
Hi!

Can you point what mechanism driver is this or the piece of code that give
this error?

On Mon, Jan 11, 2016 at 11:58 AM, Koteswar  wrote:

> Hi All,
>
>
>
> In my mechanism driver, I am reading/writing into sql db in a fixed
> interval looping call. Sometimes I get the following error when I stop and
> start neutron server
>
> InvalidRequestError: This session is in 'prepared' state; no further SQL
> can be emitted within this transaction.
>
>
>
> I am using context.session.query() for add, delete, update and get. Please
> help me if any one resolved an issue like this.
>
>
>
> Full trace is as follows:
>
> 2016-01-06 15:33:21.799 [01;31mERROR neutron.plugins.ml2.managers
> [[01;36mreq-d940a1b6-253a-43d2-b5ff-6c784c8a520f [00;36madmin
> 83b5358da62a407f88155f447966356f[01;31m] [01;35m[01;31mMechanism driver
> 'hp' failed in create_port_precommit[00m
>
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00mTraceback (most recent call last):
>
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00m  File "/opt/stack/neutron/neutron/plugins/ml2/managers.py",
> line 394, in _call_on_drivers
>
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00mgetattr(driver.obj, method_name)(context)
>
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00m  File
> "/usr/local/lib/python2.7/dist-packages/baremetal_network_provisioning/ml2/mechanism_hp.py",
> line 67, in create_port_precommit
>
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00mraise e
>
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00mInvalidRequestError: This session is in 'prepared' state; no
> further SQL can be emitted within this transaction.
>
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00m
>
> 2016-01-06 15:33:21.901 [01;31mERROR neutron.api.v2.resource
> [[01;36mreq-d940a1b6-253a-43d2-b5ff-6c784c8a520f [00;36madmin
> 83b5358da62a407f88155f447966356f[01;31m] [01;35m[01;31mcreate failed[00m
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mTraceback (most recent call last):
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
> File "/opt/stack/neutron/neutron/api/v2/resource.py", line 83, in resource
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mresult = method(request=request, **args)
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
> File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 146, in
> wrapper
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mectxt.value = e.inner_exc
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
> File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line
> 195, in __exit__
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00msix.reraise(self.type_, self.value, self.tb)
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
> File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 136, in
> wrapper
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mreturn f(*args, **kwargs)
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
> File "/opt/stack/neutron/neutron/api/v2/base.py", line 516, in create
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mobj = do_create(body)
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
> File "/opt/stack/neutron/neutron/api/v2/base.py", line 498, in do_create
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mrequest.context, reservation.reservation_id)
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
> File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line
> 195, in __exit__
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00msix.reraise(self.type_, self.value, self.tb)
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
> File "/opt/stack/neutron/neutron/api/v2/base.py", line 491, in do_create
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mreturn obj_creator(request.context, **kwargs)
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
> File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 146, in
> wrapper
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mectxt.value = e.inner_exc
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource [01;35m[00m
> File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line
> 195, in __exit__
>
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00m

Re: [openstack-dev] [neutron] InvalidRequestError: This session is in 'prepared' state; no further SQL can be emitted within this transaction.

2016-01-11 Thread Kevin Benton
Is 'self.context' used to handle other requests as well? I would suggest
generating a new context (neutron.context.get_admin_context()) for each
fixed interval looping call to ensure you aren't sharing a DB session with
another thread.

On Mon, Jan 11, 2016 at 2:26 AM, Koteswar  wrote:

> vendor specific mech driver code, where I am doing some read/write to sql.
>
> def _create_port(self, port): switchports = port['port']['switchports']
> LOG.debug(_LE("_create_port switch: %s"), port) network_id = port['port'][
> 'network_id'] subnets = db.get_subnets_by_network(self.context,
> network_id) if not subnets: LOG.error("Subnet not found for the network")
> self._raise_ml2_error(wexc.HTTPNotFound, 'create_port') for switchport in
> switchports: switch_mac_id = switchport['switch_id'] port_id = switchport[
> 'port_id'] bnp_switch = db.get_bnp_phys_switch_by_mac(self.context,
> switch_mac_id) # check for port and switch level existence if not
> bnp_switch: LOG.error(_LE("No physical switch found '%s' "),
> switch_mac_id) self._raise_ml2_error(wexc.HTTPNotFound, 'create_port')
> phys_port = db.get_bnp_phys_port(self.context, bnp_switch.id, port_id) if
> not phys_port: LOG.error(_LE("No physical port found for '%s' "),
> phys_port) self._raise_ml2_error(wexc.HTTPNotFound, 'create_port') if
> bnp_switch.status != constants.SWITCH_STATUS['enable']: 
> LOG.error(_LE("Physical
> switch is not Enabled '%s' "), bnp_switch.status) 
> self._raise_ml2_error(wexc.HTTPBadRequest,
> 'create_port')
>
> On Mon, Jan 11, 2016 at 2:47 PM, Anna Kamyshnikova <
> akamyshnik...@mirantis.com> wrote:
>
>> Hi!
>>
>> Can you point what mechanism driver is this or the piece of code that
>> give this error?
>>
>> On Mon, Jan 11, 2016 at 11:58 AM, Koteswar  wrote:
>>
>>> Hi All,
>>>
>>>
>>>
>>> In my mechanism driver, I am reading/writing into sql db in a fixed
>>> interval looping call. Sometimes I get the following error when I stop and
>>> start neutron server
>>>
>>> InvalidRequestError: This session is in 'prepared' state; no further SQL
>>> can be emitted within this transaction.
>>>
>>>
>>>
>>> I am using context.session.query() for add, delete, update and get.
>>> Please help me if any one resolved an issue like this.
>>>
>>>
>>>
>>> Full trace is as follows:
>>>
>>> 2016-01-06 15:33:21.799 [01;31mERROR neutron.plugins.ml2.managers
>>> [[01;36mreq-d940a1b6-253a-43d2-b5ff-6c784c8a520f [00;36madmin
>>> 83b5358da62a407f88155f447966356f[01;31m] [01;35m[01;31mMechanism driver
>>> 'hp' failed in create_port_precommit[00m
>>>
>>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>>> [01;35m[00mTraceback (most recent call last):
>>>
>>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>>> [01;35m[00m  File "/opt/stack/neutron/neutron/plugins/ml2/managers.py",
>>> line 394, in _call_on_drivers
>>>
>>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>>> [01;35m[00mgetattr(driver.obj, method_name)(context)
>>>
>>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>>> [01;35m[00m  File
>>> "/usr/local/lib/python2.7/dist-packages/baremetal_network_provisioning/ml2/mechanism_hp.py",
>>> line 67, in create_port_precommit
>>>
>>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>>> [01;35m[00mraise e
>>>
>>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>>> [01;35m[00mInvalidRequestError: This session is in 'prepared' state; no
>>> further SQL can be emitted within this transaction.
>>>
>>> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
>>> [01;35m[00m
>>>
>>> 2016-01-06 15:33:21.901 [01;31mERROR neutron.api.v2.resource
>>> [[01;36mreq-d940a1b6-253a-43d2-b5ff-6c784c8a520f [00;36madmin
>>> 83b5358da62a407f88155f447966356f[01;31m] [01;35m[01;31mcreate failed[00m
>>>
>>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>>> [01;35m[00mTraceback (most recent call last):
>>>
>>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>>> [01;35m[00m  File "/opt/stack/neutron/neutron/api/v2/resource.py", line 83,
>>> in resource
>>>
>>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>>> [01;35m[00mresult = method(request=request, **args)
>>>
>>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>>> [01;35m[00m  File "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py",
>>> line 146, in wrapper
>>>
>>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>>> [01;35m[00mectxt.value = e.inner_exc
>>>
>>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>>> [01;35m[00m  File
>>> "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 195,
>>> in __exit__
>>>
>>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>>> [01;35m[00msix.reraise(self.type_, self.value, self.tb)
>>>
>>> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
>>> [01;35m[00m  File 

Re: [openstack-dev] [neutron] InvalidRequestError: This session is in 'prepared' state; no further SQL can be emitted within this transaction.

2016-01-11 Thread Mike Bayer


On 01/11/2016 03:58 AM, Koteswar wrote:
> Hi All,
> 
>  
> 
> In my mechanism driver, I am reading/writing into sql db in a fixed
> interval looping call. Sometimes I get the following error when I stop
> and start neutron server
> 
> InvalidRequestError: This session is in 'prepared' state; no further SQL
> can be emitted within this transaction.
> 
>  
> 
> I am using context.session.query() for add, delete, update and get.
> Please help me if any one resolved an issue like this.

the stack trace is unfortunately re-thrown from the ml2.managers code
without retaining the original traceback; use this form to reraise with
original tb:

exc_info = sys.exc_info()
raise type(e), e, exc_info[2]

There's likely helpers somewhere in oslo that do this.

The cause of this error is that a transaction commit is failing, the
error is being caught and this same Session is being used again without
rollback called first.   The code below illustrates the problem and how
to solve.

from sqlalchemy import create_engine
from sqlalchemy.orm import Session


e = create_engine("sqlite://")

s = Session(e)


conn = s.connection()


def boom():
raise Exception("sqlite commit failed")

# "break" connection.commit(),
# so that the commit fails
conn.connection.commit = boom
try:
# fail
s.commit()
except Exception, e:
# uncomment this to fix the error
# s.rollback()
pass
finally:
boom = False


# prepared state error
s.connection()

> 
>  
> 
> Full trace is as follows:
> 
> 2016-01-06 15:33:21.799 [01;31mERROR neutron.plugins.ml2.managers
> [[01;36mreq-d940a1b6-253a-43d2-b5ff-6c784c8a520f [00;36madmin
> 83b5358da62a407f88155f447966356f[01;31m] [01;35m[01;31mMechanism driver
> 'hp' failed in create_port_precommit[00m
> 
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00mTraceback (most recent call last):
> 
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00m  File "/opt/stack/neutron/neutron/plugins/ml2/managers.py",
> line 394, in _call_on_drivers
> 
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00mgetattr(driver.obj, method_name)(context)
> 
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00m  File
> "/usr/local/lib/python2.7/dist-packages/baremetal_network_provisioning/ml2/mechanism_hp.py",
> line 67, in create_port_precommit
> 
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00mraise e
> 
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00mInvalidRequestError: This session is in 'prepared' state; no
> further SQL can be emitted within this transaction.
> 
> [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> [01;35m[00m
> 
> 2016-01-06 15:33:21.901 [01;31mERROR neutron.api.v2.resource
> [[01;36mreq-d940a1b6-253a-43d2-b5ff-6c784c8a520f [00;36madmin
> 83b5358da62a407f88155f447966356f[01;31m] [01;35m[01;31mcreate failed[00m
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mTraceback (most recent call last):
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00m  File "/opt/stack/neutron/neutron/api/v2/resource.py", line
> 83, in resource
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mresult = method(request=request, **args)
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00m  File
> "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 146, in
> wrapper
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mectxt.value = e.inner_exc
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00m  File
> "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line
> 195, in __exit__
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00msix.reraise(self.type_, self.value, self.tb)
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00m  File
> "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 136, in
> wrapper
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mreturn f(*args, **kwargs)
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00m  File "/opt/stack/neutron/neutron/api/v2/base.py", line 516,
> in create
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mobj = do_create(body)
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00m  File "/opt/stack/neutron/neutron/api/v2/base.py", line 498,
> in do_create
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00mrequest.context, reservation.reservation_id)
> 
> [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> [01;35m[00m  File
> "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line
> 195, in __exit__
> 
> [01;31m2016-01-06 

Re: [openstack-dev] [neutron] InvalidRequestError: This session is in 'prepared' state; no further SQL can be emitted within this transaction.

2016-01-11 Thread Koteswar
thanks a lot. I will try this.

On Mon, Jan 11, 2016 at 7:26 PM, Mike Bayer  wrote:

>
>
> On 01/11/2016 03:58 AM, Koteswar wrote:
> > Hi All,
> >
> >
> >
> > In my mechanism driver, I am reading/writing into sql db in a fixed
> > interval looping call. Sometimes I get the following error when I stop
> > and start neutron server
> >
> > InvalidRequestError: This session is in 'prepared' state; no further SQL
> > can be emitted within this transaction.
> >
> >
> >
> > I am using context.session.query() for add, delete, update and get.
> > Please help me if any one resolved an issue like this.
>
> the stack trace is unfortunately re-thrown from the ml2.managers code
> without retaining the original traceback; use this form to reraise with
> original tb:
>
> exc_info = sys.exc_info()
> raise type(e), e, exc_info[2]
>
> There's likely helpers somewhere in oslo that do this.
>
> The cause of this error is that a transaction commit is failing, the
> error is being caught and this same Session is being used again without
> rollback called first.   The code below illustrates the problem and how
> to solve.
>
> from sqlalchemy import create_engine
> from sqlalchemy.orm import Session
>
>
> e = create_engine("sqlite://")
>
> s = Session(e)
>
>
> conn = s.connection()
>
>
> def boom():
> raise Exception("sqlite commit failed")
>
> # "break" connection.commit(),
> # so that the commit fails
> conn.connection.commit = boom
> try:
> # fail
> s.commit()
> except Exception, e:
> # uncomment this to fix the error
> # s.rollback()
> pass
> finally:
> boom = False
>
>
> # prepared state error
> s.connection()
>
> >
> >
> >
> > Full trace is as follows:
> >
> > 2016-01-06 15:33:21.799 [01;31mERROR neutron.plugins.ml2.managers
> > [[01;36mreq-d940a1b6-253a-43d2-b5ff-6c784c8a520f [00;36madmin
> > 83b5358da62a407f88155f447966356f[01;31m] [01;35m[01;31mMechanism driver
> > 'hp' failed in create_port_precommit[00m
> >
> > [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> > [01;35m[00mTraceback (most recent call last):
> >
> > [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> > [01;35m[00m  File "/opt/stack/neutron/neutron/plugins/ml2/managers.py",
> > line 394, in _call_on_drivers
> >
> > [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> > [01;35m[00mgetattr(driver.obj, method_name)(context)
> >
> > [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> > [01;35m[00m  File
> >
> "/usr/local/lib/python2.7/dist-packages/baremetal_network_provisioning/ml2/mechanism_hp.py",
> > line 67, in create_port_precommit
> >
> > [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> > [01;35m[00mraise e
> >
> > [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> > [01;35m[00mInvalidRequestError: This session is in 'prepared' state; no
> > further SQL can be emitted within this transaction.
> >
> > [01;31m2016-01-06 15:33:21.799 TRACE neutron.plugins.ml2.managers
> > [01;35m[00m
> >
> > 2016-01-06 15:33:21.901 [01;31mERROR neutron.api.v2.resource
> > [[01;36mreq-d940a1b6-253a-43d2-b5ff-6c784c8a520f [00;36madmin
> > 83b5358da62a407f88155f447966356f[01;31m] [01;35m[01;31mcreate failed[00m
> >
> > [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> > [01;35m[00mTraceback (most recent call last):
> >
> > [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> > [01;35m[00m  File "/opt/stack/neutron/neutron/api/v2/resource.py", line
> > 83, in resource
> >
> > [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> > [01;35m[00mresult = method(request=request, **args)
> >
> > [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> > [01;35m[00m  File
> > "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 146, in
> > wrapper
> >
> > [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> > [01;35m[00mectxt.value = e.inner_exc
> >
> > [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> > [01;35m[00m  File
> > "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line
> > 195, in __exit__
> >
> > [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> > [01;35m[00msix.reraise(self.type_, self.value, self.tb)
> >
> > [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> > [01;35m[00m  File
> > "/usr/local/lib/python2.7/dist-packages/oslo_db/api.py", line 136, in
> > wrapper
> >
> > [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> > [01;35m[00mreturn f(*args, **kwargs)
> >
> > [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> > [01;35m[00m  File "/opt/stack/neutron/neutron/api/v2/base.py", line 516,
> > in create
> >
> > [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> > [01;35m[00mobj = do_create(body)
> >
> > [01;31m2016-01-06 15:33:21.901 TRACE neutron.api.v2.resource
> > [01;35m[00m  File "/opt/stack/neutron/neutron/api/v2/base.py", line 498,
> >