Hi -- I finally got a chance to put in the profiling and trace callbacks. Very interesting stuff, which I am attempting to analyze. One of the things I am seeing is that none of the SELECT statements that show up in the trace actually are being captured by the Profiling callback. So here are the first six transactions worth of the profiler followed by the trace output, to give you an idea of what I mean:
0 BEGIN TRANSACTION 0 UPDATE C$SimulinkBlockParameters$Block SET P$NAME = ? WHERE OBJID = ? AND MODELID = ? AND STARTGEN = ? 8006394 COMMIT TRANSACTION 0 BEGIN TRANSACTION 0 COMMIT TRANSACTION 0 BEGIN TRANSACTION 0 COMMIT TRANSACTION 0 BEGIN TRANSACTION 0 COMMIT TRANSACTION 0 BEGIN TRANSACTION 0 COMMIT TRANSACTION 0 BEGIN TRANSACTION 0 UPDATE C$SimulinkBlockParameters$Block SET P$NAME = ? WHERE OBJID = ? AND MODELID = ? AND STARTGEN = ? 19030273 COMMIT TRANSACTION SELECT C$SimulinkBlockParameters$Block.OBJID FROM C$SimulinkBlockParameters$Block,DMRDATAMODELS WHERE C$SimulinkBlockParameters$Block.P$ID == 'f14Test:3' AND DMRDATAMODELS.MODELID = C$SimulinkBlockParameters$Block.MODELID AND DMRDATAMODELS.ACTIVEGEN BETWEEN C$SimulinkBlockParameters$Block.STARTGEN AND C$SimulinkBlockParameters$Block.ENDGEN BEGIN TRANSACTION SELECT GENERATION FROM DMRMASTER SELECT C$SimulinkBlockParameters$Block.MODELID,C$SimulinkBlockParameters$Block.CLSID FROM C$SimulinkBlockParameters$Block,DMRDATAMODELS WHERE OBJID = 4173 UPDATE C$SimulinkBlockParameters$Block SET P$NAME = 'Aircraft Dynamics Model' WHERE OBJID = 4173 AND MODELID = 1 AND STARTGEN = 1 COMMIT TRANSACTION SELECT C$SimulinkBlockParameters$Block.P$PARAMETER FROM C$SimulinkBlockParameters$Block,DMRDATAMODELS WHERE OBJID = 4173 AND DMRDATAMODELS.MODELID = C$SimulinkBlockParameters$Block.MODELID AND DMRDATAMODELS.ACTIVEGEN BETWEEN C$SimulinkBlockParameters$Block.STARTGEN AND C$SimulinkBlockParameters$Block.ENDGEN SELECT C$SimulinkBlockParameters$Property.OBJID FROM C$SimulinkBlockParameters$Property,DMRDATAMODELS WHERE C$SimulinkBlockParameters$Property.P$ID == 7 AND C$SimulinkBlockParameters$Property.COLLID == 75 AND DMRDATAMODELS.MODELID = C$SimulinkBlockParameters$Property.MODELID AND DMRDATAMODELS.ACTIVEGEN BETWEEN C$SimulinkBlockParameters$Property.STARTGEN AND C$SimulinkBlockParameters$Property.ENDGEN BEGIN TRANSACTION SELECT GENERATION FROM DMRMASTER SELECT C$SimulinkBlockParameters$Property.P$VALUE FROM C$SimulinkBlockParameters$Property,DMRDATAMODELS WHERE OBJID = 4183 AND DMRDATAMODELS.MODELID = C$SimulinkBlockParameters$Property.MODELID AND DMRDATAMODELS.ACTIVEGEN BETWEEN C$SimulinkBlockParameters$Property.STARTGEN AND C$SimulinkBlockParameters$Property.ENDGEN COMMIT TRANSACTION SELECT C$SimulinkBlockParameters$ValueSpec.MODELID,C$SimulinkBlockParameters$ValueSpec.STARTGEN,C$SimulinkBlockParameters$ValueSpec.CLSID FROM C$SimulinkBlockParameters$ValueSpec,DMRDATAMODELS WHERE OBJID = 4182 AND DMRDATAMODELS.MODELID = C$SimulinkBlockParameters$ValueSpec.MODELID AND DMRDATAMODELS.ACTIVEGEN BETWEEN C$SimulinkBlockParameters$ValueSpec.STARTGEN AND C$SimulinkBlockParameters$ValueSpec.ENDGEN BEGIN TRANSACTION SELECT GENERATION FROM DMRMASTER SELECT C$SimulinkBlockParameters$Property.P$NAME FROM C$SimulinkBlockParameters$Property,DMRDATAMODELS WHERE OBJID = 4183 AND DMRDATAMODELS.MODELID = C$SimulinkBlockParameters$Property.MODELID AND DMRDATAMODELS.ACTIVEGEN BETWEEN C$SimulinkBlockParameters$Property.STARTGEN AND C$SimulinkBlockParameters$Property.ENDGEN COMMIT TRANSACTION BEGIN TRANSACTION SELECT GENERATION FROM DMRMASTER SELECT C$SimulinkBlockParameters$Block.P$NAME FROM C$SimulinkBlockParameters$Block,DMRDATAMODELS WHERE OBJID = 4173 AND DMRDATAMODELS.MODELID = C$SimulinkBlockParameters$Block.MODELID AND DMRDATAMODELS.ACTIVEGEN BETWEEN C$SimulinkBlockParameters$Block.STARTGEN AND C$SimulinkBlockParameters$Block.ENDGEN COMMIT TRANSACTION BEGIN TRANSACTION SELECT GENERATION FROM DMRMASTER SELECT C$SimulinkBlockParameters$IntValue.P$VALUE FROM C$SimulinkBlockParameters$IntValue,DMRDATAMODELS WHERE OBJID = 4182 AND DMRDATAMODELS.MODELID = C$SimulinkBlockParameters$IntValue.MODELID AND DMRDATAMODELS.ACTIVEGEN BETWEEN C$SimulinkBlockParameters$IntValue.STARTGEN AND C$SimulinkBlockParameters$IntValue.ENDGEN COMMIT TRANSACTION SELECT C$SimulinkBlockParameters$Block.OBJID FROM C$SimulinkBlockParameters$Block,DMRDATAMODELS WHERE C$SimulinkBlockParameters$Block.P$ID == 'f14Test:18' AND DMRDATAMODELS.MODELID = C$SimulinkBlockParameters$Block.MODELID AND DMRDATAMODELS.ACTIVEGEN BETWEEN C$SimulinkBlockParameters$Block.STARTGEN AND C$SimulinkBlockParameters$Block.ENDGEN BEGIN TRANSACTION SELECT GENERATION FROM DMRMASTER SELECT C$SimulinkBlockParameters$Block.MODELID,C$SimulinkBlockParameters$Block.CLSID FROM C$SimulinkBlockParameters$Block,DMRDATAMODELS WHERE OBJID = 4860 UPDATE C$SimulinkBlockParameters$Block SET P$NAME = 'Controller' WHERE OBJID = 4860 AND MODELID = 1 AND STARTGEN = 1 COMMIT TRANSACTION A couple questions: Is there any way to be called back for the SELECT statements? I'm guessing that I'm losing a bunch of significant timing information without them. Is that correct? Also I see right away that the person implementing the Sqlite access code is issuing a lot of BEGIN and COMMIT transactions. Are we likely paying a significant price for this? The timing information on the statements themselves is always 0 (presumably less than the significance of the millisecond accuracy discussed in the docs). But might there be other stuff going on that isn't reflected in the measurements that would account for the significant time being spent? Are there any other tools that I should be looking at that will help me supplement the views I am getting from these? I am looking at this trace info and trying to relate operations I am invoking from my higher level code that translate to the patterns observed in the trace. But any more diagnostics I can put into place would be very helpful. Thanks. Mike -----Original Message----- From: sqlite-users-boun...@sqlite.org [mailto:sqlite-users-boun...@sqlite.org] On Behalf Of Richard Hipp Sent: Thursday, October 17, 2013 9:59 AM To: General Discussion of SQLite Database Subject: Re: [sqlite] Trying to figure out how to circumvent sqlite3_win32_mbcs_to_utf8 On Thu, Oct 17, 2013 at 9:37 AM, Mike Clagett <mike.clag...@mathworks.com>wrote: > Hi -- > > Okay. This is helpful. It appears the profiler is not doing such a good > job at name resolution. So I've been looking down a wrong path. However, > there definitely is a problem; whether or not I run the profiler, the app > is taking a huge amount of time to execute. So I don't think the profiler > is causing the problem. Do you have any ideas about how I might be able > to diagnose this? Is there something I can add to the picture to give the > profiler a better chance to resolve the symbols correctly? Or is > there an alternate way to identify the code spots that are adding this > execution time? > This suggests that it isn't really sqlite3_win32_msbc_to_utf8() that is causing the problem. Instead, it is probably some nearby routine like winRead() ro winWrite() - routines that are doing actual file I/O. I'm guessing you have some SQL that is doing a full table scan rather than using an index. The solution is probably just an appropriate CREATE INDEX statement. Consider activating the sqlite3_profile() callback ( http://www.sqlite.org/c3ref/profile.html) in order to see what SQL statements you are running and how long each is taking. That might give a better clue that your profiler. Or activate the sqlite3_trace() callback and use that to capture a script of the SQL you are running. The reply that script using the SQLite command-line shell after activating the ".timer on" command and/or the ".stats on" command to get a better idea of which SQL statement or statements are running slow. Or make use of the sqlite3_stmt_status() API ( http://www.sqlite.org/c3ref/stmt_status.html) to find one which SQL statements are doing full table scan or creating automatic indices, or doing large sorts, etc. > > You mentioned in your first message turning on logging. I've read the > link and am going to do this. But perhaps you could save me some time by > verifying my understanding. I am writing a component that is called from > a larger application. I do not have the opportunity to register > anything at the start of the app (or at least I'm not aware of the > mechanism to do this). My code is being invoked from an internal > application command line long after the app itself has launched. So I would > like to activate error > logging at the initialization of my component. Am I correct to assume > that I can issue this sqlite3_config statement right before I create > my database and that as long as my code is the only code using sqlite, this > will have the desired effect and install my callback? Clarification of > this would be helpful. > Yes, I believe that is correct. Of course, our point of view is that SQLite should be a built-in standard component of Matlab so that a full-blown SQL database engine would be available to all Matlab users without having to load an extension or configure an external server. In that case, error logging could be enabled at application launch. :-) -- D. Richard Hipp d...@sqlite.org _______________________________________________ sqlite-users mailing list sqlite-users@sqlite.org http://sqlite.org:8080/cgi-bin/mailman/listinfo/sqlite-users _______________________________________________ sqlite-users mailing list sqlite-users@sqlite.org http://sqlite.org:8080/cgi-bin/mailman/listinfo/sqlite-users
