Skip to content

Commit 42e067d

Browse files
sjlombardosjlombardo
committed
improvements and extensions to trace logging
1 parent df092f0 commit 42e067d

4 files changed

Lines changed: 181 additions & 50 deletions

File tree

‎src/crypto.c‎

Lines changed: 43 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -55,21 +55,30 @@ static int codec_set_btree_to_codec_pagesize(sqlite3 *db, Db *pDb, codec_ctx *ct
5555
page_sz = sqlcipher_codec_ctx_get_pagesize(ctx);
5656
reserve_sz = sqlcipher_codec_ctx_get_reservesize(ctx);
5757

58+
CODEC_TRACE("codec_set_btree_to_codec_pagesize: sqlite3BtreeSetPageSize() size=%d reserve=%d\n", page_sz, reserve_sz);
59+
60+
CODEC_TRACE_MUTEX("codec_set_btree_to_codec_pagesize: entering database mutex %p\n", db->mutex);
5861
sqlite3_mutex_enter(db->mutex);
62+
CODEC_TRACE_MUTEX("codec_set_btree_to_codec_pagesize: entered database mutex %p\n", db->mutex);
5963
db->nextPagesize = page_sz;
6064

6165
/* before forcing the page size we need to unset the BTS_PAGESIZE_FIXED flag, else
6266
sqliteBtreeSetPageSize will block the change */
6367
pDb->pBt->pBt->btsFlags &= ~BTS_PAGESIZE_FIXED;
64-
CODEC_TRACE(("codec_set_btree_to_codec_pagesize: sqlite3BtreeSetPageSize() size=%d reserve=%d\n", page_sz, reserve_sz));
6568
rc = sqlite3BtreeSetPageSize(pDb->pBt, page_sz, reserve_sz, 0);
69+
70+
CODEC_TRACE("codec_set_btree_to_codec_pagesize: sqlite3BtreeSetPageSize returned %d\n", rc);
71+
72+
CODEC_TRACE_MUTEX("codec_set_btree_to_codec_pagesize: leaving database mutex %p\n", db->mutex);
6673
sqlite3_mutex_leave(db->mutex);
74+
CODEC_TRACE_MUTEX("codec_set_btree_to_codec_pagesize: left database mutex %p\n", db->mutex);
75+
6776
return rc;
6877
}
6978

7079
static int codec_set_pass_key(sqlite3* db, int nDb, const void *zKey, int nKey, int for_ctx) {
7180
struct Db *pDb = &db->aDb[nDb];
72-
CODEC_TRACE(("codec_set_pass_key: entered db=%p nDb=%d zKey=%s nKey=%d for_ctx=%d\n", db, nDb, (char *)zKey, nKey, for_ctx));
81+
CODEC_TRACE("codec_set_pass_key: entered db=%p nDb=%d zKey=%s nKey=%d for_ctx=%d\n", db, nDb, (char *)zKey, nKey, for_ctx);
7382
if(pDb->pBt) {
7483
codec_ctx *ctx;
7584
sqlite3pager_get_codec(pDb->pBt->pBt->pPager, (void **) &ctx);
@@ -88,7 +97,7 @@ int sqlcipher_codec_pragma(sqlite3* db, int iDb, Parse *pParse, const char *zLef
8897
sqlite3pager_get_codec(pDb->pBt->pBt->pPager, (void **) &ctx);
8998
}
9099

91-
CODEC_TRACE(("sqlcipher_codec_pragma: entered db=%p iDb=%d pParse=%p zLeft=%s zRight=%s ctx=%p\n", db, iDb, pParse, zLeft, zRight, ctx));
100+
CODEC_TRACE("sqlcipher_codec_pragma: entered db=%p iDb=%d pParse=%p zLeft=%s zRight=%s ctx=%p\n", db, iDb, pParse, zLeft, zRight, ctx);
92101

93102
if( sqlite3StrICmp(zLeft, "cipher_fips_status")== 0 && !zRight ){
94103
if(ctx) {
@@ -300,7 +309,7 @@ void* sqlite3Codec(void *iCtx, void *data, Pgno pgno, int mode) {
300309
unsigned char *pData = (unsigned char *) data;
301310
void *buffer = sqlcipher_codec_ctx_get_data(ctx);
302311
void *kdf_salt = sqlcipher_codec_ctx_get_kdf_salt(ctx);
303-
CODEC_TRACE(("sqlite3Codec: entered pgno=%d, mode=%d, page_sz=%d\n", pgno, mode, page_sz));
312+
CODEC_TRACE("sqlite3Codec: entered pgno=%d, mode=%d, page_sz=%d\n", pgno, mode, page_sz);
304313

305314
/* call to derive keys if not present yet */
306315
if((rc = sqlcipher_codec_key_derive(ctx)) != SQLITE_OK) {
@@ -310,7 +319,7 @@ void* sqlite3Codec(void *iCtx, void *data, Pgno pgno, int mode) {
310319

311320
if(pgno == 1) offset = FILE_HEADER_SZ; /* adjust starting pointers in data page for header offset on first page*/
312321

313-
CODEC_TRACE(("sqlite3Codec: switch mode=%d offset=%d\n", mode, offset));
322+
CODEC_TRACE("sqlite3Codec: switch mode=%d offset=%d\n", mode, offset);
314323
switch(mode) {
315324
case 0: /* decrypt */
316325
case 2:
@@ -349,7 +358,7 @@ void sqlite3FreeCodecArg(void *pCodecArg) {
349358
int sqlite3CodecAttach(sqlite3* db, int nDb, const void *zKey, int nKey) {
350359
struct Db *pDb = &db->aDb[nDb];
351360

352-
CODEC_TRACE(("sqlite3CodecAttach: entered nDb=%d zKey=%s, nKey=%d\n", nDb, (char *)zKey, nKey));
361+
CODEC_TRACE("sqlite3CodecAttach: entered db=%p, nDb=%d zKey=%s, nKey=%d\n", db, nDb, (char *)zKey, nKey);
353362

354363

355364
if(nKey && zKey && pDb->pBt) {
@@ -358,35 +367,48 @@ int sqlite3CodecAttach(sqlite3* db, int nDb, const void *zKey, int nKey) {
358367
sqlite3_file *fd = sqlite3Pager_get_fd(pPager);
359368
codec_ctx *ctx;
360369

370+
CODEC_TRACE("sqlite3CodecAttach: calling sqlcipher_activate()\n");
361371
sqlcipher_activate(); /* perform internal initialization for sqlcipher */
362372

373+
CODEC_TRACE_MUTEX("sqlite3CodecAttach: entering database mutex %p\n", db->mutex);
363374
sqlite3_mutex_enter(db->mutex);
375+
CODEC_TRACE_MUTEX("sqlite3CodecAttach: entered database mutex %p\n", db->mutex);
364376

365377
/* point the internal codec argument against the contet to be prepared */
378+
CODEC_TRACE("sqlite3CodecAttach: calling sqlcipher_codec_ctx_init()\n");
366379
rc = sqlcipher_codec_ctx_init(&ctx, pDb, pDb->pBt->pBt->pPager, fd, zKey, nKey);
367380

368381
if(rc != SQLITE_OK) {
369382
/* initialization failed, do not attach potentially corrupted context */
383+
CODEC_TRACE("sqlite3CodecAttach: context initialization failed with rc=%d\n", rc);
384+
CODEC_TRACE_MUTEX("sqlite3CodecAttach: leaving database mutex %p (early return on rc=%d)\n", db->mutex, rc);
370385
sqlite3_mutex_leave(db->mutex);
386+
CODEC_TRACE_MUTEX("sqlite3CodecAttach: left database mutex %p (early return on rc=%d)\n", db->mutex, rc);
371387
return rc;
372388
}
373389

390+
CODEC_TRACE("sqlite3CodecAttach: calling sqlite3pager_sqlite3PagerSetCodec()\n");
374391
sqlite3pager_sqlite3PagerSetCodec(sqlite3BtreePager(pDb->pBt), sqlite3Codec, NULL, sqlite3FreeCodecArg, (void *) ctx);
375392

393+
CODEC_TRACE("sqlite3CodecAttach: calling codec_set_btree_to_codec_pagesize()\n");
376394
codec_set_btree_to_codec_pagesize(db, pDb, ctx);
377395

378396
/* force secure delete. This has the benefit of wiping internal data when deleted
379397
and also ensures that all pages are written to disk (i.e. not skipped by
380398
sqlite3PagerDontWrite optimizations) */
399+
CODEC_TRACE("sqlite3CodecAttach: calling sqlite3BtreeSecureDelete()\n");
381400
sqlite3BtreeSecureDelete(pDb->pBt, 1);
382401

383402
/* if fd is null, then this is an in-memory database and
384403
we dont' want to overwrite the AutoVacuum settings
385404
if not null, then set to the default */
386405
if(fd != NULL) {
406+
CODEC_TRACE("sqlite3CodecAttach: calling sqlite3BtreeSetAutoVacuum()\n");
387407
sqlite3BtreeSetAutoVacuum(pDb->pBt, SQLITE_DEFAULT_AUTOVACUUM);
388408
}
409+
CODEC_TRACE_MUTEX("sqlite3CodecAttach: leaving database mutex %p\n", db->mutex);
389410
sqlite3_mutex_leave(db->mutex);
411+
CODEC_TRACE_MUTEX("sqlite3CodecAttach: left database mutex %p\n", db->mutex);
390412
}
391413
return SQLITE_OK;
392414
}
@@ -410,12 +432,12 @@ static int sqlcipher_find_db_index(sqlite3 *db, const char *zDb) {
410432
}
411433

412434
int sqlite3_key(sqlite3 *db, const void *pKey, int nKey) {
413-
CODEC_TRACE(("sqlite3_key entered: db=%p pKey=%s nKey=%d\n", db, (char *)pKey, nKey));
435+
CODEC_TRACE("sqlite3_key entered: db=%p pKey=%s nKey=%d\n", db, (char *)pKey, nKey);
414436
return sqlite3_key_v2(db, "main", pKey, nKey);
415437
}
416438

417439
int sqlite3_key_v2(sqlite3 *db, const char *zDb, const void *pKey, int nKey) {
418-
CODEC_TRACE(("sqlite3_key_v2: entered db=%p zDb=%s pKey=%s nKey=%d\n", db, zDb, (char *)pKey, nKey));
440+
CODEC_TRACE("sqlite3_key_v2: entered db=%p zDb=%s pKey=%s nKey=%d\n", db, zDb, (char *)pKey, nKey);
419441
/* attach key if db and pKey are not null and nKey is > 0 */
420442
if(db && pKey && nKey) {
421443
int db_index = sqlcipher_find_db_index(db, zDb);
@@ -425,7 +447,7 @@ int sqlite3_key_v2(sqlite3 *db, const char *zDb, const void *pKey, int nKey) {
425447
}
426448

427449
int sqlite3_rekey(sqlite3 *db, const void *pKey, int nKey) {
428-
CODEC_TRACE(("sqlite3_rekey entered: db=%p pKey=%s nKey=%d\n", db, (char *)pKey, nKey));
450+
CODEC_TRACE("sqlite3_rekey entered: db=%p pKey=%s nKey=%d\n", db, (char *)pKey, nKey);
429451
return sqlite3_rekey_v2(db, "main", pKey, nKey);
430452
}
431453

@@ -440,11 +462,11 @@ int sqlite3_rekey(sqlite3 *db, const void *pKey, int nKey) {
440462
** 3. If there is a key present, re-encrypt the database with the new key
441463
*/
442464
int sqlite3_rekey_v2(sqlite3 *db, const char *zDb, const void *pKey, int nKey) {
443-
CODEC_TRACE(("sqlite3_rekey_v2: entered db=%p zDb=%s pKey=%s, nKey=%d\n", db, zDb, (char *)pKey, nKey));
465+
CODEC_TRACE("sqlite3_rekey_v2: entered db=%p zDb=%s pKey=%s, nKey=%d\n", db, zDb, (char *)pKey, nKey);
444466
if(db && pKey && nKey) {
445467
int db_index = sqlcipher_find_db_index(db, zDb);
446468
struct Db *pDb = &db->aDb[db_index];
447-
CODEC_TRACE(("sqlite3_rekey_v2: database pDb=%p db_index:%d\n", pDb, db_index));
469+
CODEC_TRACE("sqlite3_rekey_v2: database pDb=%p db_index:%d\n", pDb, db_index);
448470
if(pDb->pBt) {
449471
codec_ctx *ctx;
450472
int rc, page_count;
@@ -456,11 +478,13 @@ int sqlite3_rekey_v2(sqlite3 *db, const char *zDb, const void *pKey, int nKey) {
456478

457479
if(ctx == NULL) {
458480
/* there was no codec attached to this database, so this should do nothing! */
459-
CODEC_TRACE(("sqlite3_rekey_v2: no codec attached to db, exiting\n"));
481+
CODEC_TRACE("sqlite3_rekey_v2: no codec attached to db, exiting\n");
460482
return SQLITE_OK;
461483
}
462484

485+
CODEC_TRACE_MUTEX("sqlite3_rekey_v2: entering database mutex %p\n", db->mutex);
463486
sqlite3_mutex_enter(db->mutex);
487+
CODEC_TRACE_MUTEX("sqlite3_rekey_v2: entered database mutex %p\n", db->mutex);
464488

465489
codec_set_pass_key(db, db_index, pKey, nKey, CIPHER_WRITE_CTX);
466490

@@ -480,25 +504,27 @@ int sqlite3_rekey_v2(sqlite3 *db, const char *zDb, const void *pKey, int nKey) {
480504
if(rc == SQLITE_OK) {
481505
sqlite3PagerUnref(page);
482506
} else {
483-
CODEC_TRACE(("sqlite3_rekey_v2: error %d occurred writing page %d\n", rc, pgno));
507+
CODEC_TRACE("sqlite3_rekey_v2: error %d occurred writing page %d\n", rc, pgno);
484508
}
485509
} else {
486-
CODEC_TRACE(("sqlite3_rekey_v2: error %d occurred getting page %d\n", rc, pgno));
510+
CODEC_TRACE("sqlite3_rekey_v2: error %d occurred getting page %d\n", rc, pgno);
487511
}
488512
}
489513
}
490514

491515
/* if commit was successful commit and copy the rekey data to current key, else rollback to release locks */
492516
if(rc == SQLITE_OK) {
493-
CODEC_TRACE(("sqlite3_rekey_v2: committing\n"));
517+
CODEC_TRACE("sqlite3_rekey_v2: committing\n");
494518
rc = sqlite3BtreeCommit(pDb->pBt);
495519
sqlcipher_codec_key_copy(ctx, CIPHER_WRITE_CTX);
496520
} else {
497-
CODEC_TRACE(("sqlite3_rekey_v2: rollback\n"));
521+
CODEC_TRACE("sqlite3_rekey_v2: rollback\n");
498522
sqlite3BtreeRollback(pDb->pBt, SQLITE_ABORT_ROLLBACK, 0);
499523
}
500524

525+
CODEC_TRACE_MUTEX("sqlite3_rekey_v2: leaving database mutex %p\n", db->mutex);
501526
sqlite3_mutex_leave(db->mutex);
527+
CODEC_TRACE_MUTEX("sqlite3_rekey_v2: left database mutex %p\n", db->mutex);
502528
}
503529
return SQLITE_OK;
504530
}
@@ -507,7 +533,7 @@ int sqlite3_rekey_v2(sqlite3 *db, const char *zDb, const void *pKey, int nKey) {
507533

508534
void sqlite3CodecGetKey(sqlite3* db, int nDb, void **zKey, int *nKey) {
509535
struct Db *pDb = &db->aDb[nDb];
510-
CODEC_TRACE(("sqlite3CodecGetKey: entered db=%p, nDb=%d\n", db, nDb));
536+
CODEC_TRACE("sqlite3CodecGetKey: entered db=%p, nDb=%d\n", db, nDb);
511537
if( pDb->pBt ) {
512538
codec_ctx *ctx;
513539
sqlite3pager_get_codec(pDb->pBt->pBt->pPager, (void **) &ctx);

‎src/crypto.h‎

Lines changed: 19 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -100,11 +100,28 @@
100100
#define CIPHER_MAX_KEY_SZ 64
101101
#endif
102102

103+
#ifdef __ANDROID__
104+
#include <android/log.h>
105+
#endif
106+
107+
#ifdef CODEC_DEBUG_MUTEX
108+
#ifdef __ANDROID__
109+
#define CODEC_TRACE_MUTEX(...) {__android_log_print(ANDROID_LOG_DEBUG, "sqlcipher", __VA_ARGS__);}
110+
#else
111+
#define CODEC_TRACE_MUTEX(...) {fprintf(stderr, __VA_ARGS__);fflush(stderr);}
112+
#endif
113+
#else
114+
#define CODEC_TRACE_MUTEX(...)
115+
#endif
103116

104117
#ifdef CODEC_DEBUG
105-
#define CODEC_TRACE(X) {printf X;fflush(stdout);}
118+
#ifdef __ANDROID__
119+
#define CODEC_TRACE(...) {__android_log_print(ANDROID_LOG_DEBUG, "sqlcipher", __VA_ARGS__);}
120+
#else
121+
#define CODEC_TRACE(...) {fprintf(stderr, __VA_ARGS__);fflush(stderr);}
122+
#endif
106123
#else
107-
#define CODEC_TRACE(X)
124+
#define CODEC_TRACE(...)
108125
#endif
109126

110127
#ifdef CODEC_DEBUG_PAGEDATA

0 commit comments

Comments
 (0)