Skip to content

Commit 1f3e378

Browse files
sjlombardosjlombardo
committed
significantly expand logging of error conditions
1 parent 58b3acc commit 1f3e378

File tree

3 files changed

+217
-64
lines changed

3 files changed

+217
-64
lines changed

‎src/crypto.c‎

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -80,8 +80,14 @@ static int codec_set_pass_key(sqlite3* db, int nDb, const void *zKey, int nKey,
8080
if(pDb->pBt) {
8181
codec_ctx *ctx = (codec_ctx*) sqlite3PagerGetCodec(pDb->pBt->pBt->pPager);
8282

83-
if(ctx) return sqlcipher_codec_ctx_set_pass(ctx, zKey, nKey, for_ctx);
83+
if(ctx) {
84+
return sqlcipher_codec_ctx_set_pass(ctx, zKey, nKey, for_ctx);
85+
} else {
86+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "codec_set_pass_key: error ocurred fetching codec from pager on db %d", nDb);
87+
return SQLITE_ERROR;
88+
}
8489
}
90+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "codec_set_pass_key: no btree present on db %d", nDb);
8591
return SQLITE_ERROR;
8692
}
8793

@@ -924,6 +930,7 @@ int sqlite3_key_v2(sqlite3 *db, const char *zDb, const void *pKey, int nKey) {
924930
int db_index = sqlcipher_find_db_index(db, zDb);
925931
return sqlite3CodecAttach(db, db_index, pKey, nKey);
926932
}
933+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlite3_key_v2: no key provided");
927934
return SQLITE_ERROR;
928935
}
929936

@@ -1009,6 +1016,7 @@ int sqlite3_rekey_v2(sqlite3 *db, const char *zDb, const void *pKey, int nKey) {
10091016
}
10101017
return SQLITE_OK;
10111018
}
1019+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlite3_rekey_v2: no key provided");
10121020
return SQLITE_ERROR;
10131021
}
10141022

‎src/crypto_impl.c‎

Lines changed: 40 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -511,15 +511,9 @@ static int sqlcipher_cipher_ctx_cmp(cipher_ctx *c1, cipher_ctx *c2) {
511511

512512
sqlcipher_log(SQLCIPHER_LOG_DEBUG, "sqlcipher_cipher_ctx_cmp: entered \
513513
c1=%p c2=%p \
514-
c1->pass_sz=%d c2->pass_sz=%d \
515-
c1->pass=%p c2->pass=%p \
516-
c1->pass=%s c2->pass=%s \
517-
sqlcipher_memcmp=%d \
514+
sqlcipher_memcmp(c1->pass, c2_pass)=%d \
518515
are_equal=%d",
519516
c1, c2,
520-
c1->pass_sz, c2->pass_sz,
521-
c1->pass, c2->pass,
522-
c1->pass, c2->pass,
523517
(c1->pass == NULL || c2->pass == NULL)
524518
? -1 : sqlcipher_memcmp(
525519
(const unsigned char*)c1->pass,
@@ -724,6 +718,7 @@ int sqlcipher_codec_ctx_set_plaintext_header_size(codec_ctx *ctx, int size) {
724718
return SQLITE_OK;
725719
}
726720
ctx->plaintext_header_sz = -1;
721+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlcipher_codec_ctx_set_plaintext_header_size: attempt to set invalid plantext_header_size %d", size);
727722
return SQLITE_ERROR;
728723
}
729724

@@ -812,7 +807,10 @@ static int sqlcipher_codec_ctx_init_kdf_salt(codec_ctx *ctx) {
812807
sqlcipher_log(SQLCIPHER_LOG_DEBUG, "sqlcipher_codec_ctx_init_kdf_salt: obtaining salt");
813808
if(fd == NULL || fd->pMethods == 0 || sqlite3OsRead(fd, ctx->kdf_salt, ctx->kdf_salt_sz, 0) != SQLITE_OK) {
814809
sqlcipher_log(SQLCIPHER_LOG_DEBUG, "sqlcipher_codec_ctx_init_kdf_salt: unable to read salt from file header, generating random");
815-
if(ctx->provider->random(ctx->provider_ctx, ctx->kdf_salt, ctx->kdf_salt_sz) != SQLITE_OK) return SQLITE_ERROR;
810+
if(ctx->provider->random(ctx->provider_ctx, ctx->kdf_salt, ctx->kdf_salt_sz) != SQLITE_OK) {
811+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlcipher_codec_ctx_init_kdf_salt: error retrieving random bytes from provider");
812+
return SQLITE_ERROR;
813+
}
816814
}
817815
ctx->need_kdf_salt = 0;
818816
return SQLITE_OK;
@@ -824,6 +822,7 @@ int sqlcipher_codec_ctx_set_kdf_salt(codec_ctx *ctx, unsigned char *salt, int si
824822
ctx->need_kdf_salt = 0;
825823
return SQLITE_OK;
826824
}
825+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlcipher_codec_ctx_set_kdf_salt: attempt to set salt of incorrect size %d", size);
827826
return SQLITE_ERROR;
828827
}
829828

@@ -1074,12 +1073,12 @@ int sqlcipher_page_cipher(codec_ctx *ctx, int for_ctx, Pgno pgno, int mode, int
10741073
hmac_out = out + size + ctx->iv_sz;
10751074
out_start = out; /* note the original position of the output buffer pointer, as out will be rewritten during encryption */
10761075

1077-
sqlcipher_log(SQLCIPHER_LOG_DEBUG, "codec_cipher:entered pgno=%d, mode=%d, size=%d", pgno, mode, size);
1078-
CODEC_HEXDUMP("codec_cipher: input page data", in, page_sz);
1076+
sqlcipher_log(SQLCIPHER_LOG_DEBUG, "sqlcipher_page_cipher: entered pgno=%d, mode=%d, size=%d", pgno, mode, size);
1077+
CODEC_HEXDUMP("sqlcipher_page_cipher: input page data", in, page_sz);
10791078

10801079
/* the key size should never be zero. If it is, error out. */
10811080
if(ctx->key_sz == 0) {
1082-
sqlcipher_log(SQLCIPHER_LOG_ERROR, "codec_cipher: error possible context corruption, key_sz is zero for pgno=%d", pgno);
1081+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlcipher_page_cipher: error possible context corruption, key_sz is zero for pgno=%d", pgno);
10831082
goto error;
10841083
}
10851084

@@ -1092,43 +1091,43 @@ int sqlcipher_page_cipher(codec_ctx *ctx, int for_ctx, Pgno pgno, int mode, int
10921091

10931092
if((ctx->flags & CIPHER_FLAG_HMAC) && (mode == CIPHER_DECRYPT) && !ctx->skip_read_hmac) {
10941093
if(sqlcipher_page_hmac(ctx, c_ctx, pgno, in, size + ctx->iv_sz, hmac_out) != SQLITE_OK) {
1095-
sqlcipher_log(SQLCIPHER_LOG_ERROR, "codec_cipher: hmac operation on decrypt failed for pgno=%d", pgno);
1094+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlcipher_page_cipher: hmac operation on decrypt failed for pgno=%d", pgno);
10961095
goto error;
10971096
}
10981097

1099-
sqlcipher_log(SQLCIPHER_LOG_DEBUG, "codec_cipher: comparing hmac on in=%p out=%p hmac_sz=%d", hmac_in, hmac_out, ctx->hmac_sz);
1098+
sqlcipher_log(SQLCIPHER_LOG_DEBUG, "sqlcipher_page_cipher: comparing hmac on in=%p out=%p hmac_sz=%d", hmac_in, hmac_out, ctx->hmac_sz);
11001099
if(sqlcipher_memcmp(hmac_in, hmac_out, ctx->hmac_sz) != 0) { /* the hmac check failed */
11011100
if(sqlcipher_ismemset(in, 0, page_sz) == 0) {
11021101
/* first check if the entire contents of the page is zeros. If so, this page
11031102
resulted from a short read (i.e. sqlite attempted to pull a page after the end of the file. these
11041103
short read failures must be ignored for autovaccum mode to work so wipe the output buffer
11051104
and return SQLITE_OK to skip the decryption step. */
1106-
sqlcipher_log(SQLCIPHER_LOG_INFO, "codec_cipher: zeroed page (short read) for pgno %d, encryption but returning SQLITE_OK", pgno);
1105+
sqlcipher_log(SQLCIPHER_LOG_INFO, "sqlcipher_page_cipher: zeroed page (short read) for pgno %d, encryption but returning SQLITE_OK", pgno);
11071106
sqlcipher_memset(out, 0, page_sz);
11081107
return SQLITE_OK;
11091108
} else {
11101109
/* if the page memory is not all zeros, it means the there was data and a hmac on the page.
11111110
since the check failed, the page was either tampered with or corrupted. wipe the output buffer,
11121111
and return SQLITE_ERROR to the caller */
1113-
sqlcipher_log(SQLCIPHER_LOG_ERROR, "codec_cipher: hmac check failed for pgno=%d returning SQLITE_ERROR", pgno);
1112+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlcipher_page_cipher: hmac check failed for pgno=%d returning SQLITE_ERROR", pgno);
11141113
goto error;
11151114
}
11161115
}
11171116
}
11181117

11191118
if(ctx->provider->cipher(ctx->provider_ctx, mode, c_ctx->key, ctx->key_sz, iv_out, in, size, out) != SQLITE_OK) {
1120-
sqlcipher_log(SQLCIPHER_LOG_ERROR, "codec_cipher: cipher operation mode=%d failed for pgno=%d returning SQLITE_ERROR", mode, pgno);
1119+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlcipher_page_cipher: cipher operation mode=%d failed for pgno=%d returning SQLITE_ERROR", mode, pgno);
11211120
goto error;
11221121
};
11231122

11241123
if((ctx->flags & CIPHER_FLAG_HMAC) && (mode == CIPHER_ENCRYPT)) {
11251124
if(sqlcipher_page_hmac(ctx, c_ctx, pgno, out_start, size + ctx->iv_sz, hmac_out) != SQLITE_OK) {
1126-
sqlcipher_log(SQLCIPHER_LOG_ERROR, "codec_cipher: hmac operation on encrypt failed for pgno=%d", pgno);
1125+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlcipher_page_cipher: hmac operation on encrypt failed for pgno=%d", pgno);
11271126
goto error;
11281127
};
11291128
}
11301129

1131-
CODEC_HEXDUMP("codec_cipher: output page data", out_start, page_sz);
1130+
CODEC_HEXDUMP("sqlcipher_page_cipher: output page data", out_start, page_sz);
11321131

11331132
return SQLITE_OK;
11341133
error:
@@ -1181,7 +1180,10 @@ static int sqlcipher_cipher_ctx_key_derive(codec_ctx *ctx, cipher_ctx *c_ctx) {
11811180
sqlcipher_log(SQLCIPHER_LOG_DEBUG, "cipher_ctx_key_derive: deriving key using full PBKDF2 with %d iterations", ctx->kdf_iter);
11821181
if(ctx->provider->kdf(ctx->provider_ctx, ctx->kdf_algorithm, c_ctx->pass, c_ctx->pass_sz,
11831182
ctx->kdf_salt, ctx->kdf_salt_sz, ctx->kdf_iter,
1184-
ctx->key_sz, c_ctx->key) != SQLITE_OK) return SQLITE_ERROR;
1183+
ctx->key_sz, c_ctx->key) != SQLITE_OK) {
1184+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "cipher_ctx_key_derive: error occurred from provider kdf generating encryption key");
1185+
return SQLITE_ERROR;
1186+
}
11851187
}
11861188

11871189
/* set the context "keyspec" containing the hex-formatted key and salt to be used when attaching databases */
@@ -1209,27 +1211,40 @@ static int sqlcipher_cipher_ctx_key_derive(codec_ctx *ctx, cipher_ctx *c_ctx) {
12091211

12101212
if(ctx->provider->kdf(ctx->provider_ctx, ctx->kdf_algorithm, c_ctx->key, ctx->key_sz,
12111213
ctx->hmac_kdf_salt, ctx->kdf_salt_sz, ctx->fast_kdf_iter,
1212-
ctx->key_sz, c_ctx->hmac_key) != SQLITE_OK) return SQLITE_ERROR;
1214+
ctx->key_sz, c_ctx->hmac_key) != SQLITE_OK) {
1215+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "cipher_ctx_key_derive: error occurred from provider kdf generating HMAC key");
1216+
return SQLITE_ERROR;
1217+
}
12131218
}
12141219

12151220
c_ctx->derive_key = 0;
12161221
return SQLITE_OK;
1217-
};
1222+
}
1223+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "cipher_ctx_key_derive: key material is not present on the context for key derivation");
12181224
return SQLITE_ERROR;
12191225
}
12201226

12211227
int sqlcipher_codec_key_derive(codec_ctx *ctx) {
12221228
/* derive key on first use if necessary */
12231229
if(ctx->read_ctx->derive_key) {
1224-
if(sqlcipher_cipher_ctx_key_derive(ctx, ctx->read_ctx) != SQLITE_OK) return SQLITE_ERROR;
1230+
if(sqlcipher_cipher_ctx_key_derive(ctx, ctx->read_ctx) != SQLITE_OK) {
1231+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlcipher_codec_key_derive: error occurred deriving read_ctx key");
1232+
return SQLITE_ERROR;
1233+
}
12251234
}
12261235

12271236
if(ctx->write_ctx->derive_key) {
12281237
if(sqlcipher_cipher_ctx_cmp(ctx->write_ctx, ctx->read_ctx) == 0) {
12291238
/* the relevant parameters are the same, just copy read key */
1230-
if(sqlcipher_cipher_ctx_copy(ctx, ctx->write_ctx, ctx->read_ctx) != SQLITE_OK) return SQLITE_ERROR;
1239+
if(sqlcipher_cipher_ctx_copy(ctx, ctx->write_ctx, ctx->read_ctx) != SQLITE_OK) {
1240+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlcipher_codec_key_derive: error occurred copying read_ctx to write_ctx");
1241+
return SQLITE_ERROR;
1242+
}
12311243
} else {
1232-
if(sqlcipher_cipher_ctx_key_derive(ctx, ctx->write_ctx) != SQLITE_OK) return SQLITE_ERROR;
1244+
if(sqlcipher_cipher_ctx_key_derive(ctx, ctx->write_ctx) != SQLITE_OK) {
1245+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlcipher_codec_key_derive: error occurred deriving write_ctx key");
1246+
return SQLITE_ERROR;
1247+
}
12331248
}
12341249
}
12351250

@@ -1601,6 +1616,7 @@ int sqlcipher_codec_add_random(codec_ctx *ctx, const char *zRight, int random_sz
16011616
sqlcipher_free(random, buffer_sz);
16021617
return rc;
16031618
}
1619+
sqlcipher_log(SQLCIPHER_LOG_ERROR, "sqlcipher_codec_add_random: attemt to add random with invalid format");
16041620
return SQLITE_ERROR;
16051621
}
16061622

0 commit comments

Comments
 (0)