/ Check-in [cf494b41]
Login

Many hyperlinks are disabled.
Use anonymous login to enable hyperlinks.

Overview
Comment:Update the "tserver" program to report the amount of time spent in COMMIT commands.
Downloads: Tarball | ZIP archive | SQL archive
Timelines: family | ancestors | descendants | both | begin-concurrent-pnu-wal2
Files: files | file ages | folders
SHA3-256: cf494b412c941704ff73b0d100c55eb9bd268ee156db88b3e60512d501689e8e
User & Date: dan 2019-01-04 17:12:28
Wiki:begin-concurrent-pnu-wal2
Context
2019-01-04
19:25
Add the "-external" option to the tserver_test.tcl program.. check-in: ae7c5ed1 user: dan tags: begin-concurrent-pnu-wal2
17:12
Update the "tserver" program to report the amount of time spent in COMMIT commands. check-in: cf494b41 user: dan tags: begin-concurrent-pnu-wal2
2019-01-02
19:46
Merge changes from begin-concurrent-wal2. Also modify the unix-excl shm-locks on this branch so that it is not an error to attempt to release an EXCLUSIVE lock that is not held. check-in: 86685679 user: dan tags: begin-concurrent-pnu-wal2
Changes
Hide Diffs Side-by-Side Diffs Ignore Whitespace Patch

Changes to tool/tserver.c.

   198    198       nTail = nSql - (zTail-zSql);
   199    199       rc = send_message(p, "ok (%d SQL statements)\n", p->nPrepare);
   200    200     }
   201    201   
   202    202     return rc;
   203    203   }
   204    204   
          205  +/*
          206  +** Return a micro-seconds resolution timer.
          207  +*/
   205    208   static sqlite3_int64 get_timer(void){
   206    209     struct timeval t;
   207    210     gettimeofday(&t, 0);
   208         -  return ((sqlite3_int64)t.tv_usec / 1000) + ((sqlite3_int64)t.tv_sec * 1000);
          211  +  return (sqlite3_int64)t.tv_usec + ((sqlite3_int64)t.tv_sec * 1000000);
   209    212   }
   210    213   
   211    214   static void clear_sql(ClientCtx *p){
   212    215     int j;
   213    216     for(j=0; j<p->nPrepare; j++){
   214    217       sqlite3_finalize(p->aPrepare[j].pStmt);
   215    218     }
................................................................................
   234    237   }
   235    238   
   236    239   static int handle_run_command(ClientCtx *p){
   237    240     int i, j;
   238    241     int nBusy = 0;
   239    242     sqlite3_int64 t0 = get_timer();
   240    243     sqlite3_int64 t1 = t0;
          244  +  sqlite3_int64 tCommit = 0;
   241    245     int nT1 = 0;
   242    246     int nTBusy1 = 0;
   243    247     int rc = SQLITE_OK;
   244    248   
   245    249     pthread_mutex_lock(&g.ckpt_mutex);
   246    250     g.nRun++;
   247    251     pthread_mutex_unlock(&g.ckpt_mutex);
   248         -
   249    252   
   250    253     for(j=0; (p->nRepeat<=0 || j<p->nRepeat) && rc==SQLITE_OK; j++){
   251    254       sqlite3_int64 t2;
   252    255   
   253    256       for(i=0; i<p->nPrepare && rc==SQLITE_OK; i++){
   254    257         sqlite3_stmt *pStmt = p->aPrepare[i].pStmt;
   255    258   
   256    259         /* If the MUTEX flag is set, grab g.commit_mutex before executing
   257    260         ** the SQL statement (which is always "COMMIT" in this case). */
   258    261         if( p->aPrepare[i].flags & TSERVER_CLIENTSQL_MUTEX ){
   259    262           sqlite3_mutex_enter(g.commit_mutex);
          263  +        tCommit -= get_timer();
   260    264         }
   261    265   
   262    266         /* Execute the statement */
   263    267         if( p->aPrepare[i].flags & TSERVER_CLIENTSQL_INTEGRITY ){
   264    268           sqlite3_step(pStmt);
   265         -        if( sqlite3_stricmp("ok", sqlite3_column_text(pStmt, 0)) ){
          269  +        if( sqlite3_stricmp("ok", (const char*)sqlite3_column_text(pStmt, 0)) ){
   266    270             send_message(p, "error - integrity_check failed: %s\n", 
   267    271                 sqlite3_column_text(pStmt, 0)
   268    272             );
   269    273           }
   270    274           sqlite3_reset(pStmt);
   271    275         }
   272    276         while( sqlite3_step(pStmt)==SQLITE_ROW );
   273    277         rc = sqlite3_reset(pStmt);
   274    278   
   275    279         /* Relinquish the g.commit_mutex mutex if required. */
   276    280         if( p->aPrepare[i].flags & TSERVER_CLIENTSQL_MUTEX ){
          281  +        tCommit += get_timer();
   277    282           sqlite3_mutex_leave(g.commit_mutex);
   278    283         }
   279    284   
   280    285         if( (rc & 0xFF)==SQLITE_BUSY ){
   281    286           if( sqlite3_get_autocommit(p->db)==0 ){
   282    287             sqlite3_exec(p->db, "ROLLBACK", 0, 0, 0);
   283    288           }
................................................................................
   289    294           send_message(p, "error - %s (eec=%d)\n", sqlite3_errmsg(p->db),
   290    295               sqlite3_extended_errcode(p->db)
   291    296           );
   292    297         }
   293    298       }
   294    299   
   295    300       t2 = get_timer();
   296         -    if( t2>=(t1+1000) ){
   297         -      int nMs = (t2 - t1);
   298         -      int nDone = (j+1 - nBusy - nT1);
          301  +    if( t2>=(t1+1000000) ){
          302  +      sqlite3_int64 nUs = (t2 - t1);
          303  +      sqlite3_int64 nDone = (j+1 - nBusy - nT1);
   299    304   
   300    305         rc = send_message(
   301         -          p, "(%d done @ %d per second, %d busy)\n", 
   302         -          nDone, (1000*nDone + nMs/2) / nMs, nBusy - nTBusy1
   303         -          );
          306  +          p, "(%d done @ %lld per second, %d busy)\n", 
          307  +          (int)nDone, (1000000*nDone + nUs/2) / nUs, nBusy - nTBusy1
          308  +      );
   304    309         t1 = t2;
   305    310         nT1 = j+1 - nBusy;
   306    311         nTBusy1 = nBusy;
   307         -      if( p->nSecond>0 && (p->nSecond*1000)<=t1-t0 ) break;
          312  +      if( p->nSecond>0 && ((sqlite3_int64)p->nSecond*1000000)<=t1-t0 ) break;
   308    313       }
   309    314   
   310    315       /* Global checkpoint handling. */
   311    316       if( g.nThreshold>0 ){
   312    317         pthread_mutex_lock(&g.ckpt_mutex);
   313    318         if( rc==SQLITE_OK && g.bCkptRequired ){
   314    319           if( g.nWait==g.nRun-1 ){
................................................................................
   332    337         if( rc==SQLITE_BUSY ) rc = SQLITE_OK;
   333    338         assert( rc==SQLITE_OK );
   334    339         p->bClientCkptRequired = 0;
   335    340       }
   336    341     }
   337    342   
   338    343     if( rc==SQLITE_OK ){
   339         -    int nMs = (int)(get_timer() - t0);
          344  +    int nMs = (get_timer() - t0) / 1000;
   340    345       send_message(p, "ok (%d/%d SQLITE_BUSY)\n", nBusy, j);
   341    346       if( p->nRepeat<=0 ){
   342         -      send_message(p, "### ok %d busy %d ms %d\n", j-nBusy, nBusy, nMs);
          347  +      send_message(p, "### ok %d busy %d ms %d commit-ms %d\n", 
          348  +          j-nBusy, nBusy, nMs, (int)(tCommit / 1000)
          349  +      );
   343    350       }
   344    351     }
   345    352     clear_sql(p);
   346    353   
   347    354     pthread_mutex_lock(&g.ckpt_mutex);
   348    355     g.nRun--;
   349    356     pthread_mutex_unlock(&g.ckpt_mutex);

Changes to tool/tserver_test.tcl.

   147    147   #
   148    148   #   tserver_start
   149    149   #   tserver_stop
   150    150   #
   151    151   set ::tserver {}
   152    152   proc tserver_start {} {
   153    153     global O
   154         -  set cmd "|$O(-tserver) -vfs unix "
          154  +  set cmd "|$O(-tserver) -vfs unix-excl "
   155    155     if {$O(-mode)=="wal2"} {
   156    156       append cmd " -walautocheckpoint 0 "
   157    157     }
   158    158     append cmd "$O(-database)"
   159    159     set ::tserver [open $cmd]
   160    160     fconfigure $::tserver -blocking 0
   161    161     fileevent $::tserver readable tserver_data