Okay I'll answer myself: In the SQlite 3.6.0 source code you get this:
// 3.6.0 (vdbeapi.c) #ifndef SQLITE_OMIT_TRACE /* Invoke the profile callback if there is one */ if( rc!=SQLITE_ROW && db->xProfile && !db->init.busy && p->nOp>0 && p->aOp[0].opcode==OP_Trace && p->aOp[0].p4.z!=0 ){ // if not SQLITE_ROW double rNow; u64 elapseTime; sqlite3OsCurrentTime(db->pVfs, &rNow); elapseTime = (rNow - (int)rNow)*3600.0*24.0*1000000000.0 - p->startTime; db->xProfile(db->pProfileArg, p->aOp[0].p4.z, elapseTime); // trigger the profile callback } #endif // end 3.6.0 Same kind of thing for the last amalgamation (3070602): // line 60620 in sqlite3.c /* Invoke the profile callback if there is one */ if( rc!=SQLITE_ROW && db->xProfile && !db->init.busy && p->zSql ){ // if not SQLITE_ROW sqlite3_int64 iNow; sqlite3OsCurrentTimeInt64(db->pVfs, &iNow); db->xProfile(db->pProfileArg, p->zSql, (iNow - p->startTime)*1000000); // trigger the profile callback } So you get it, if the step is returning SQLITE_ROW, we'll never get the profile callback triggered. Then it's not my fault. I thought I was doing something wrong here, and that my base could be corrupted. It would be worth mentioning this into the documentation though, because it's quite scary to see only 1 perf trace when you perform 10s of SELECTs. Also, I didn't dive in the code, but is there a reason to filter these? I guess it is to *not* trigger the callback multiple times (if you do multiple calls to step()). But then would it be more relevant to perform this callback trigger in the finalize() statement? (keeping the timing measures in the step(), of course). Cheers, Guillaume On Thu, May 5, 2011 at 10:38 AM, Guillaume B <guitre...@gmail.com> wrote: > Hey guys, > > I'm trying to use the sqlite3_profile() function to monitor the delays > of the requests I make in my application. > I can see some of the statements in my trace, but it seems that not > all the statements trigger the callback. > > Some context informations first: > - sqlite3 is in version 3.6.0, running on an SH4 platform under linux > - the code is in C/C++ and uses the sqlite3 API with the "v2" statements > > My typical code flow is something like that: > > - prepare a SELECT query > - sqlite3_step(), make sure it returns SQLITE_ROW (I expect to get one > record, and only one) > - finalize() > > In this mode, I never see the callback triggered, or just in erroneous > queries. > I actually narrowed down that the callback is only called when > sqlite3_step() *doesn't* return SQLITE_ROW, but rather SQLITE_DONE, > which means it didn't find any record and is finished. > > Problem is, I only need to get one record out of the query, so I never > call step() after my SQLITE_ROW again to make the function return > SQLITE_DONE. > > My questions now: > > - Is the profiling callback triggered only when reaching the end of > the query (<=> sqlite3_step() returns "DONE") ? > > - If yes, is it normal? Timing the request time should only be a > matter on stepping once, since the whole query gets passed to the > sqlite engine and successive steps should hit a cache or something > (i'm extrapolating there...)? > Or does the sqlite3 C API proceeds by... steps and then computes the > total amount of time spent in successive sqlite3_step() calls? > > - Then wouldn't it be more convenient to place the callback trigger > when one finalizes the query? So that even if we don't get all the > records from the query (<=> don't call step() until we hit > SQLITE_DONE), we still get a timing? > > Thanks to whoever answers :) > _______________________________________________ > 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