Pyramid_tm reason for ROLLBACK

134 views
Skip to first unread message

Srikanth Bemineni

unread,
Oct 6, 2017, 1:02:07 AM10/6/17
to pylons-discuss
Hi,

Whenever a sqlalchemy commit fails, the transaction will be automatically rolled back. When this does happen the pyramid_tm which commits the transaction should print the message with the reason for rollback.

We get one simple message from sqlalchemy. Most of the times we need to guess the reason for the rollback. 

2017-10-05 23:56:29,072 INFO  [sqlalchemy.engine.base.Engine:699][b'uWSGIWorker1Core0'] ROLLBACK

Is there way I can see the error , with the reason for roll back ?

Srikanth B.

Mikko Ohtamaa

unread,
Oct 6, 2017, 4:07:47 AM10/6/17
to pylons-...@googlegroups.com
Hi Srikanth,

Are you using PostgreSQL? Does the transaction fail because of concurrent transactions reading or writing same data?

Usually there should be something like this written in the logs:

sqlalchemy.exc.OperationalError: (raised as a result of Query-invoked autoflush; consider using a session.no_autoflush block if this flush is occurring prematurely)

(psycopg2.extensions.TransactionRollbackError) could not serialize access due to read/write dependencies among transactions

-Mikko

--
You received this message because you are subscribed to the Google Groups "pylons-discuss" group.
To unsubscribe from this group and stop receiving emails from it, send an email to pylons-discuss+unsubscribe@googlegroups.com.
To post to this group, send email to pylons-discuss@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/pylons-discuss/2fc1209f-f677-4fbe-a572-05517c9e5462%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.



--

Srikanth Bemineni

unread,
Oct 6, 2017, 9:33:24 AM10/6/17
to pylons-discuss
Hi,

I am using Mysql. This is one single insert into a table and its failing for some reason. I am not able to predict the reason for the failure. sqlalchemy just prints ROLLBACK.

INSERT INTO group_message_22f9b36c (group_id, group_topic_id, score, user_id, uname, msg, created_at, updated_at) VALUES (%s, %s, %s, %s, %s, %s, %s, %s)
2017-10-06 00:44:40,883 INFO  [sqlalchemy.engine.base.Engine:1143][b'uWSGIWorker2Core0'] (11, 1, 0, 6, 'sammy', 'sdfsdf', datetime.datetime(2017, 10, 6, 5, 44, 40, 880935), datetime.datetime(2017, 10, 6, 5, 44, 40, 880935))
2017-10-06 00:44:40,897 INFO  [sqlalchemy.engine.base.Engine:699][b'uWSGIWorker2Core0'] ROLLBACK


On Friday, October 6, 2017 at 3:07:47 AM UTC-5, Mikko Ohtamaa wrote:
Hi Srikanth,

Are you using PostgreSQL? Does the transaction fail because of concurrent transactions reading or writing same data?

Usually there should be something like this written in the logs:

sqlalchemy.exc.OperationalError: (raised as a result of Query-invoked autoflush; consider using a session.no_autoflush block if this flush is occurring prematurely)

(psycopg2.extensions.TransactionRollbackError) could not serialize access due to read/write dependencies among transactions

-Mikko
On 6 October 2017 at 08:02, Srikanth Bemineni <bemineni...@gmail.com> wrote:
Hi,

Whenever a sqlalchemy commit fails, the transaction will be automatically rolled back. When this does happen the pyramid_tm which commits the transaction should print the message with the reason for rollback.

We get one simple message from sqlalchemy. Most of the times we need to guess the reason for the rollback. 

2017-10-05 23:56:29,072 INFO  [sqlalchemy.engine.base.Engine:699][b'uWSGIWorker1Core0'] ROLLBACK

Is there way I can see the error , with the reason for roll back ?

Srikanth B.

--
You received this message because you are subscribed to the Google Groups "pylons-discuss" group.
To unsubscribe from this group and stop receiving emails from it, send an email to pylons-discus...@googlegroups.com.
To post to this group, send email to pylons-...@googlegroups.com.

Mike Orr

unread,
Oct 6, 2017, 1:09:17 PM10/6/17
to pylons-...@googlegroups.com
Do you have the 'sqlalchemy.engine' logger set to 'WARN'? I do and I
get messages like Mikko Ohtamaa gets. I'm not sure the transaction
manager is the right place to log these things because it doesn't know
what's wrong, only that an exception occurred. It wouldn't be able to
print the SQL command and parameters, for instance. And if you weren't
using the transaction manager, you wouldn't get the errors if it was
logging them.

I haven't seen an error like Mikko's but I occasionally get errors
like 'Integrity error: duplicate primary key' , or something when the
database server auto-upgrades itself and restarts. I haven't seen any
'psycopg2' error; maybe I need to configure its logger.

If you're using autoincrement primary keys and you're manually
inserting the ID into another table, you may have to insert a manual
'session.flush()' to generate the key. Otherwise if you do
'secondtable.first_id = firsttable.id' you'll get None which may cause
a null violation in the second table.


On Fri, Oct 6, 2017 at 6:33 AM, Srikanth Bemineni
> https://groups.google.com/d/msgid/pylons-discuss/6d62ae3a-ee7f-42ec-b88a-2610d47d9164%40googlegroups.com.
>
> For more options, visit https://groups.google.com/d/optout.



--
Mike Orr <slugg...@gmail.com>

Srikanth Bemineni

unread,
Oct 6, 2017, 3:19:48 PM10/6/17
to pylons-discuss
Hi,

My current log level is INFO, and I have changed it to DEBUG, but still no error messages. I do have an auto increment primary key, but the example I am executing is one single insert command. I also do have a DBSession.flush() after including the object into DBsession.

INSERT INTO group_message_22f9b36c (group_id, group_topic_id, score, user_id, uname, msg, created_at, updated_at) VALUES (%s, %s, %s, %s, %s, %s, %s, %s)
2017-10-06 00:44:40,883 INFO  [sqlalchemy.engine.base.Engine:1143][b'uWSGIWorker2Core0'] (11, 1, 0, 6, 'sammy', 'sdfsdf', datetime.datetime(2017, 10, 6, 5, 44, 40, 880935), datetime.datetime(2017, 10, 6, 5, 44, 40, 880935))

I tried to execute the statement directly on Mysql workbench and it works fine and a row does get inserted into the table. 

Is there any way i can see the sqlalchemy session commit error ?

Srikanth B

Michael Merickel

unread,
Oct 6, 2017, 4:24:17 PM10/6/17
to Pylons
If you have successfully set the sqlalchemy.* loggers to DEBUG you should be seeing tons of output. Ensure that you've configured the level on the correct loggers. For example, the pyramid cookiecutters ship with a separate config for sqlalchemy that overrides the default root logger level.

- Michael

To unsubscribe from this group and stop receiving emails from it, send an email to pylons-discuss+unsubscribe@googlegroups.com.
To post to this group, send email to pylons-discuss@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/pylons-discuss/15b2a17c-4f8d-462f-91bb-a87c66576f50%40googlegroups.com.

Srikanth Bemineni

unread,
Oct 6, 2017, 11:25:43 PM10/6/17
to pylons-discuss
Hi,

I narrowed down the problem to transaction not getting committed. I am seeing this problem where the viewcallable renders json instead of a mako template. The views that are rendering mako template are working fine and the transaction is getting committed.
@view_config(route_name='groupmessage_create',
                 renderer='json',
                 decorator=(isLogged,
                                   GroupHelper.check_group_membership(True),
                                   GroupTopicHelper.check_topic_exists_json))
def groupmessage_create(self):
    # returns a json object
    DBsession.add(msg)
    DBSession.flush()
    return {...JSON...}

Jonathan Vanasco

unread,
Oct 7, 2017, 12:28:08 AM10/7/17
to pylons-discuss
The error is most likely in your Pyramid code.  If SqlAlchemy failed, there would be a SqlAlchemy error logged.  Your example shows SqlAlchemy completing an INSERT, but then being instructed to ROLLBACK by the transaction manager.  You should increase your Pyramid logging levels.

Between your code example and error patterns, I would guess the exception is being raised in the JSON renderer.  Most likely that is because you're using the stock JSON renderer, which doesn't support most common Python and SqlAlchemy datatypes (such as datetime, decimals, etc).

I suggest you look more closely at your exception logging, and run some tests to see if the active JSON encoder can handle your datatypes. 

Srikanth Bemineni

unread,
Oct 7, 2017, 5:27:12 PM10/7/17
to pylons-discuss
Hi,

I was able to figure out the reason, it was due to a missing return statement from the one of the decorators, which in turn was returning blank response to execview tween
enabling 
pyramid.debug_notfound = false
pyramid.debug_routematch = false

Gave me some clues in figuring out the issue.

Srikanth B
Reply all
Reply to author
Forward
0 new messages