/ 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 Unified Diffs Ignore Whitespace Patch

Changes to tool/tserver.c.

198
199
200
201
202
203
204



205
206
207
208
209
210
211
212
213
214
215
...
234
235
236
237
238
239
240

241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259

260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276

277
278
279
280
281
282
283
...
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
...
332
333
334
335
336
337
338
339
340
341
342


343
344
345
346
347
348
349
    nTail = nSql - (zTail-zSql);
    rc = send_message(p, "ok (%d SQL statements)\n", p->nPrepare);
  }

  return rc;
}




static sqlite3_int64 get_timer(void){
  struct timeval t;
  gettimeofday(&t, 0);
  return ((sqlite3_int64)t.tv_usec / 1000) + ((sqlite3_int64)t.tv_sec * 1000);
}

static void clear_sql(ClientCtx *p){
  int j;
  for(j=0; j<p->nPrepare; j++){
    sqlite3_finalize(p->aPrepare[j].pStmt);
  }
................................................................................
}

static int handle_run_command(ClientCtx *p){
  int i, j;
  int nBusy = 0;
  sqlite3_int64 t0 = get_timer();
  sqlite3_int64 t1 = t0;

  int nT1 = 0;
  int nTBusy1 = 0;
  int rc = SQLITE_OK;

  pthread_mutex_lock(&g.ckpt_mutex);
  g.nRun++;
  pthread_mutex_unlock(&g.ckpt_mutex);


  for(j=0; (p->nRepeat<=0 || j<p->nRepeat) && rc==SQLITE_OK; j++){
    sqlite3_int64 t2;

    for(i=0; i<p->nPrepare && rc==SQLITE_OK; i++){
      sqlite3_stmt *pStmt = p->aPrepare[i].pStmt;

      /* If the MUTEX flag is set, grab g.commit_mutex before executing
      ** the SQL statement (which is always "COMMIT" in this case). */
      if( p->aPrepare[i].flags & TSERVER_CLIENTSQL_MUTEX ){
        sqlite3_mutex_enter(g.commit_mutex);

      }

      /* Execute the statement */
      if( p->aPrepare[i].flags & TSERVER_CLIENTSQL_INTEGRITY ){
        sqlite3_step(pStmt);
        if( sqlite3_stricmp("ok", sqlite3_column_text(pStmt, 0)) ){
          send_message(p, "error - integrity_check failed: %s\n", 
              sqlite3_column_text(pStmt, 0)
          );
        }
        sqlite3_reset(pStmt);
      }
      while( sqlite3_step(pStmt)==SQLITE_ROW );
      rc = sqlite3_reset(pStmt);

      /* Relinquish the g.commit_mutex mutex if required. */
      if( p->aPrepare[i].flags & TSERVER_CLIENTSQL_MUTEX ){

        sqlite3_mutex_leave(g.commit_mutex);
      }

      if( (rc & 0xFF)==SQLITE_BUSY ){
        if( sqlite3_get_autocommit(p->db)==0 ){
          sqlite3_exec(p->db, "ROLLBACK", 0, 0, 0);
        }
................................................................................
        send_message(p, "error - %s (eec=%d)\n", sqlite3_errmsg(p->db),
            sqlite3_extended_errcode(p->db)
        );
      }
    }

    t2 = get_timer();
    if( t2>=(t1+1000) ){
      int nMs = (t2 - t1);
      int nDone = (j+1 - nBusy - nT1);

      rc = send_message(
          p, "(%d done @ %d per second, %d busy)\n", 
          nDone, (1000*nDone + nMs/2) / nMs, nBusy - nTBusy1
          );
      t1 = t2;
      nT1 = j+1 - nBusy;
      nTBusy1 = nBusy;
      if( p->nSecond>0 && (p->nSecond*1000)<=t1-t0 ) break;
    }

    /* Global checkpoint handling. */
    if( g.nThreshold>0 ){
      pthread_mutex_lock(&g.ckpt_mutex);
      if( rc==SQLITE_OK && g.bCkptRequired ){
        if( g.nWait==g.nRun-1 ){
................................................................................
      if( rc==SQLITE_BUSY ) rc = SQLITE_OK;
      assert( rc==SQLITE_OK );
      p->bClientCkptRequired = 0;
    }
  }

  if( rc==SQLITE_OK ){
    int nMs = (int)(get_timer() - t0);
    send_message(p, "ok (%d/%d SQLITE_BUSY)\n", nBusy, j);
    if( p->nRepeat<=0 ){
      send_message(p, "### ok %d busy %d ms %d\n", j-nBusy, nBusy, nMs);


    }
  }
  clear_sql(p);

  pthread_mutex_lock(&g.ckpt_mutex);
  g.nRun--;
  pthread_mutex_unlock(&g.ckpt_mutex);







>
>
>



|







 







>







<











>





|











>







 







|
|
|


|
|
|



|







 







|


|
>
>







198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
...
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251

252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
...
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
...
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
    nTail = nSql - (zTail-zSql);
    rc = send_message(p, "ok (%d SQL statements)\n", p->nPrepare);
  }

  return rc;
}

/*
** Return a micro-seconds resolution timer.
*/
static sqlite3_int64 get_timer(void){
  struct timeval t;
  gettimeofday(&t, 0);
  return (sqlite3_int64)t.tv_usec + ((sqlite3_int64)t.tv_sec * 1000000);
}

static void clear_sql(ClientCtx *p){
  int j;
  for(j=0; j<p->nPrepare; j++){
    sqlite3_finalize(p->aPrepare[j].pStmt);
  }
................................................................................
}

static int handle_run_command(ClientCtx *p){
  int i, j;
  int nBusy = 0;
  sqlite3_int64 t0 = get_timer();
  sqlite3_int64 t1 = t0;
  sqlite3_int64 tCommit = 0;
  int nT1 = 0;
  int nTBusy1 = 0;
  int rc = SQLITE_OK;

  pthread_mutex_lock(&g.ckpt_mutex);
  g.nRun++;
  pthread_mutex_unlock(&g.ckpt_mutex);


  for(j=0; (p->nRepeat<=0 || j<p->nRepeat) && rc==SQLITE_OK; j++){
    sqlite3_int64 t2;

    for(i=0; i<p->nPrepare && rc==SQLITE_OK; i++){
      sqlite3_stmt *pStmt = p->aPrepare[i].pStmt;

      /* If the MUTEX flag is set, grab g.commit_mutex before executing
      ** the SQL statement (which is always "COMMIT" in this case). */
      if( p->aPrepare[i].flags & TSERVER_CLIENTSQL_MUTEX ){
        sqlite3_mutex_enter(g.commit_mutex);
        tCommit -= get_timer();
      }

      /* Execute the statement */
      if( p->aPrepare[i].flags & TSERVER_CLIENTSQL_INTEGRITY ){
        sqlite3_step(pStmt);
        if( sqlite3_stricmp("ok", (const char*)sqlite3_column_text(pStmt, 0)) ){
          send_message(p, "error - integrity_check failed: %s\n", 
              sqlite3_column_text(pStmt, 0)
          );
        }
        sqlite3_reset(pStmt);
      }
      while( sqlite3_step(pStmt)==SQLITE_ROW );
      rc = sqlite3_reset(pStmt);

      /* Relinquish the g.commit_mutex mutex if required. */
      if( p->aPrepare[i].flags & TSERVER_CLIENTSQL_MUTEX ){
        tCommit += get_timer();
        sqlite3_mutex_leave(g.commit_mutex);
      }

      if( (rc & 0xFF)==SQLITE_BUSY ){
        if( sqlite3_get_autocommit(p->db)==0 ){
          sqlite3_exec(p->db, "ROLLBACK", 0, 0, 0);
        }
................................................................................
        send_message(p, "error - %s (eec=%d)\n", sqlite3_errmsg(p->db),
            sqlite3_extended_errcode(p->db)
        );
      }
    }

    t2 = get_timer();
    if( t2>=(t1+1000000) ){
      sqlite3_int64 nUs = (t2 - t1);
      sqlite3_int64 nDone = (j+1 - nBusy - nT1);

      rc = send_message(
          p, "(%d done @ %lld per second, %d busy)\n", 
          (int)nDone, (1000000*nDone + nUs/2) / nUs, nBusy - nTBusy1
      );
      t1 = t2;
      nT1 = j+1 - nBusy;
      nTBusy1 = nBusy;
      if( p->nSecond>0 && ((sqlite3_int64)p->nSecond*1000000)<=t1-t0 ) break;
    }

    /* Global checkpoint handling. */
    if( g.nThreshold>0 ){
      pthread_mutex_lock(&g.ckpt_mutex);
      if( rc==SQLITE_OK && g.bCkptRequired ){
        if( g.nWait==g.nRun-1 ){
................................................................................
      if( rc==SQLITE_BUSY ) rc = SQLITE_OK;
      assert( rc==SQLITE_OK );
      p->bClientCkptRequired = 0;
    }
  }

  if( rc==SQLITE_OK ){
    int nMs = (get_timer() - t0) / 1000;
    send_message(p, "ok (%d/%d SQLITE_BUSY)\n", nBusy, j);
    if( p->nRepeat<=0 ){
      send_message(p, "### ok %d busy %d ms %d commit-ms %d\n", 
          j-nBusy, nBusy, nMs, (int)(tCommit / 1000)
      );
    }
  }
  clear_sql(p);

  pthread_mutex_lock(&g.ckpt_mutex);
  g.nRun--;
  pthread_mutex_unlock(&g.ckpt_mutex);

Changes to tool/tserver_test.tcl.

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







|







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