On Mon, May 27, 2019, at 12:05 PM, Sebastian Meinhardt wrote: > Hello, > > given an SQLAlchemy engine `con` (cx_oracle dialect) and a moderately complex > SQLAlchemy selectable object `sql`, the following code will consistently take > ~15 seconds: > > con.execute(sql).fetchall() > > Whereas with the exact same engine and query the following code will only > take a fraction of a second: > > compiled = sql.compile(dialect=con.dialect) > statement = compiled.string > params = compiled.params > con.execute(statement, params).fetchall()
a leading cause of this would be that the statement returns many rows and a large amount of time is spent in processing datatypes for each result row. When you execute the string directly, the metadata about the datatypes present in your SELECT statement are lost and the raw cx_oracle result is returned. the cx_oracle dialect has undergone many changes across recent releases in response to continued major changes in cx_oracle itself in recent months, so it's critical you share the exact version of cx_Oracle in use as well as that of SQLAlchemy. There have been many performance sensitive behaviors changed and re-changed such as: https://docs.sqlalchemy.org/en/13/changelog/changelog_13.html#change-39b6e94b3055af74e4ca5816d0afad01 https://docs.sqlalchemy.org/en/13/changelog/changelog_13.html#change-54fc6a60b98ea236b117f1a22bb56ac7 https://docs.sqlalchemy.org/en/13/changelog/changelog_12.html#change-14756b5be0675946feab88dc7c2d2e41 https://docs.sqlalchemy.org/en/13/changelog/changelog_12.html#change-baa722912078e3ae44490613f8b69f28 plenty of reasons for typing issues to act differently across releases and different cx_oracle versions. Oracle has a pretty developer-unfriendly typing system and cx_Oracle's developer works very hard to allow it to be customizable, however this means it's very open ended and it's been quite difficult to get every edge working correctly without crushing performance problems. > So, apparently something goes horribly wrong when executing an selectable. I > assume that there is something wrong on my side as a general error in > SQLAlchemy in this regard would probably have been noticed. However: How do I > even debug this? In the end, I did trace the problem down to the `do_execute` > function in engine.default: > > def do_execute(self, cursor, statement, parameters, context=None): > cursor.execute(statement, parameters) > use the recipe at https://docs.sqlalchemy.org/en/13/faq/performance.html#code-profiling, for a difference this noticeable it should be fairly straightforward to identify the codepath taking up the time spent in the slow version. > > > > Both of my code examples visit this line of code with the exact same values > for `statement` and `parameters`, though the way they get there is slightly > different and so are the `cursor` and `context` objects. When I try to step > further down in the debugger, the next frame would be `output_type_handler` > in dialects.oracle.cx_oracle. However, the time is already lost before > stepping into that function. That is, just entering this frame takes ~15 > seconds in my first code but is near instantaneous in my second code. > > I do not really know how to continue debugging from this point. Anybody have > any advice or any ideas what might be going on here? The only difference that > looks even remotely relevant to me at that point is that within the `context` > we have a value for `context.compiled` for the first code and None for the > second code. I tried setting it to None in the debugger but that had no > effect on the execution speed. The cursors look both the same to me in both > codes. > > At this point I do not even know what else to look for and would appreciate > any advice how to proceed. After not finding anything in the local context I > would assume the problem is somewhere in some global state but without > intimate knowledge of the inner working of SQLAlchemy I don't think I will be > able to find the root cause. > > -- > SQLAlchemy - > The Python SQL Toolkit and Object Relational Mapper > > http://www.sqlalchemy.org/ > > To post example code, please provide an MCVE: Minimal, Complete, and > Verifiable Example. See http://stackoverflow.com/help/mcve for a full > description. > --- > You received this message because you are subscribed to the Google Groups > "sqlalchemy" group. > To unsubscribe from this group and stop receiving emails from it, send an > email to sqlalchemy+unsubscr...@googlegroups.com. > To post to this group, send email to sqlalchemy@googlegroups.com. > Visit this group at https://groups.google.com/group/sqlalchemy. > To view this discussion on the web visit > https://groups.google.com/d/msgid/sqlalchemy/b6c933f0-5ad5-468d-ba15-ba49e9c3fb55%40googlegroups.com > > <https://groups.google.com/d/msgid/sqlalchemy/b6c933f0-5ad5-468d-ba15-ba49e9c3fb55%40googlegroups.com?utm_medium=email&utm_source=footer>. > For more options, visit https://groups.google.com/d/optout. -- SQLAlchemy - The Python SQL Toolkit and Object Relational Mapper http://www.sqlalchemy.org/ To post example code, please provide an MCVE: Minimal, Complete, and Verifiable Example. See http://stackoverflow.com/help/mcve for a full description. --- You received this message because you are subscribed to the Google Groups "sqlalchemy" group. To unsubscribe from this group and stop receiving emails from it, send an email to sqlalchemy+unsubscr...@googlegroups.com. To post to this group, send email to sqlalchemy@googlegroups.com. Visit this group at https://groups.google.com/group/sqlalchemy. To view this discussion on the web visit https://groups.google.com/d/msgid/sqlalchemy/838a18ec-76c3-4bd5-b237-c9b7bfe8f03e%40www.fastmail.com. For more options, visit https://groups.google.com/d/optout.
