Reduce log spam from debug.rhizome

This commit is contained in:
Jeremy Lakeman 2014-03-12 13:48:08 +10:30
parent 0bef066949
commit ee68856878
6 changed files with 39 additions and 46 deletions

View File

@ -266,6 +266,7 @@ ATOM(bool_t, packetconstruction, 0, boolean,, "")
ATOM(bool_t, rhizome, 0, boolean,, "")
ATOM(bool_t, rhizome_manifest, 0, boolean,, "")
ATOM(bool_t, rhizome_sql_bind, 0, boolean,, "")
ATOM(bool_t, rhizome_store, 0, boolean,, "")
ATOM(bool_t, rhizome_tx, 0, boolean,, "")
ATOM(bool_t, rhizome_rx, 0, boolean,, "")
ATOM(bool_t, rhizome_ads, 0, boolean,, "")
@ -277,7 +278,6 @@ ATOM(bool_t, manifests, 0, boolean,, "")
ATOM(bool_t, vomp, 0, boolean,, "")
ATOM(bool_t, trace, 0, boolean,, "")
ATOM(bool_t, profiling, 0, boolean,, "")
ATOM(bool_t, externalblobs, 0, boolean,, "")
ATOM(bool_t, linkstate, 0, boolean,, "")
END_STRUCT

View File

@ -1198,7 +1198,7 @@ static int rhizome_delete_external(const rhizome_filehash_t *hashp)
return WHYF_perror("unlink(%s)", alloca_str_toprint(blob_path));
return 1;
}
if (config.debug.externalblobs)
if (config.debug.rhizome_store)
DEBUGF("Deleted blob file %s", blob_path);
return 0;
}

View File

@ -107,25 +107,25 @@ enum rhizome_payload_status rhizome_open_write(struct rhizome_write *write, cons
if (file_length == RHIZOME_SIZE_UNSET || file_length > config.rhizome.max_blob_size) {
if (!FORM_RHIZOME_DATASTORE_PATH(blob_path, "%s/%"PRIu64, RHIZOME_BLOB_SUBDIR, write->temp_id))
return RHIZOME_PAYLOAD_STATUS_ERROR;
if (config.debug.externalblobs)
if (config.debug.rhizome_store)
DEBUGF("Attempting to put blob for id='%"PRIu64"' in %s", write->temp_id, blob_path);
if ((write->blob_fd = open(blob_path, O_CREAT | O_TRUNC | O_RDWR, 0664)) == -1) {
WHYF("Failed to create payload file, id='%"PRIu64"'", write->temp_id);
return RHIZOME_PAYLOAD_STATUS_ERROR;
}
if (config.debug.externalblobs)
if (config.debug.rhizome_store)
DEBUGF("Writing to new blob file %s (fd=%d)", blob_path, write->blob_fd);
} else {
if ((write->blob_rowid = rhizome_create_fileblob(&retry, write->temp_id, (size_t)file_length)) == 0) {
sqlite_exec_void_retry(&retry, "ROLLBACK;", END);
return RHIZOME_PAYLOAD_STATUS_ERROR;
}
if (config.debug.rhizome_rx)
if (config.debug.rhizome_store)
DEBUGF("Got rowid=%"PRId64" for id='%"PRIu64"'", write->blob_rowid, write->temp_id);
}
if (sqlite_exec_void_retry(&retry, "COMMIT;", END) == -1){
if (write->blob_fd != -1) {
if (config.debug.externalblobs)
if (config.debug.rhizome_store)
DEBUGF("Cancel write to fd %d", write->blob_fd);
close(write->blob_fd);
write->blob_fd=-1;
@ -163,15 +163,12 @@ static int prepare_data(struct rhizome_write *write_state, unsigned char *buffer
write_state->file_offset + write_state->tail,
write_state->key, write_state->nonce))
return -1;
if (config.debug.rhizome) {
//dump("after encrypt", buffer, data_size);
}
}
SHA512_Update(&write_state->sha512_context, buffer, data_size);
write_state->file_offset+=data_size;
if (config.debug.rhizome)
if (config.debug.rhizome_store)
DEBUGF("Processed %"PRIu64" of %"PRIu64, write_state->file_offset, write_state->file_length);
return 0;
}
@ -193,10 +190,8 @@ static int write_get_lock(struct rhizome_write *write_state)
// write data to disk
static int write_data(struct rhizome_write *write_state, uint64_t file_offset, const unsigned char *buffer, size_t data_size)
{
if (config.debug.rhizome) {
if (config.debug.rhizome_store)
DEBUGF("write_state->file_length=%"PRIu64" file_offset=%"PRIu64, write_state->file_length, file_offset);
//dump("buffer", buffer, data_size);
}
if (data_size<=0)
return 0;
@ -213,7 +208,7 @@ static int write_data(struct rhizome_write *write_state, uint64_t file_offset, c
ssize_t r = write(write_state->blob_fd, buffer + ofs, (size_t)(data_size - ofs));
if (r == -1)
return WHY_perror("write");
if (config.debug.externalblobs)
if (config.debug.rhizome_store)
DEBUGF("Wrote %zd bytes to fd %d", (size_t)r, write_state->blob_fd);
ofs += (size_t)r;
}
@ -227,7 +222,7 @@ static int write_data(struct rhizome_write *write_state, uint64_t file_offset, c
write_state->written_offset = file_offset + data_size;
if (config.debug.rhizome)
if (config.debug.rhizome_store)
DEBUGF("Wrote %"PRIu64" of %"PRIu64, file_offset + data_size, write_state->file_length);
return 0;
}
@ -253,10 +248,8 @@ static int write_release_lock(struct rhizome_write *write_state)
// Though there is an upper bound on the amount of cached data
int rhizome_random_write(struct rhizome_write *write_state, uint64_t offset, unsigned char *buffer, size_t data_size)
{
if (config.debug.rhizome) {
if (config.debug.rhizome_store)
DEBUGF("write_state->file_length=%"PRIu64" offset=%"PRIu64, write_state->file_length, offset);
dump("buffer", buffer, data_size);
}
if ( write_state->file_length != RHIZOME_SIZE_UNSET
&& offset + data_size > write_state->file_length
)
@ -356,7 +349,7 @@ int rhizome_random_write(struct rhizome_write *write_state, uint64_t offset, uns
if (size<=0)
break;
if (config.debug.rhizome)
if (config.debug.rhizome_store)
DEBUGF("Caching block @%"PRId64", %zu", offset, size);
struct rhizome_write_buffer *i = emalloc(size + sizeof(struct rhizome_write_buffer));
if (!i){
@ -432,7 +425,7 @@ int rhizome_write_file(struct rhizome_write *write, const char *filename)
void rhizome_fail_write(struct rhizome_write *write)
{
if (write->blob_fd != -1){
if (config.debug.externalblobs)
if (config.debug.rhizome_store)
DEBUGF("Closing and removing fd %d", write->blob_fd);
close(write->blob_fd);
write->blob_fd=-1;
@ -464,7 +457,7 @@ enum rhizome_payload_status rhizome_finish_write(struct rhizome_write *write)
// Once the whole file has been written, we finally know its size and hash.
if (write->file_length == RHIZOME_SIZE_UNSET) {
if (config.debug.rhizome)
if (config.debug.rhizome_store)
DEBUGF("Wrote %"PRIu64" bytes, set file_length", write->file_offset);
write->file_length = write->file_offset;
} else {
@ -492,7 +485,7 @@ enum rhizome_payload_status rhizome_finish_write(struct rhizome_write *write)
if (write->blob_fd != -1) {
external = 1;
if (write->file_length <= config.rhizome.max_blob_size) {
if (config.debug.rhizome)
if (config.debug.rhizome_store)
DEBUGF("Copying %zu bytes from external file %s into blob, id=%"PRIu64, (size_t)write->file_offset, blob_path, write->temp_id);
int ret = 0;
if (lseek(write->blob_fd, 0, SEEK_SET) == (off_t) -1)
@ -507,7 +500,7 @@ enum rhizome_payload_status rhizome_finish_write(struct rhizome_write *write)
WARNF_perror("unlink(%s)", alloca_str_toprint(blob_path));
}
}
if (config.debug.externalblobs)
if (config.debug.rhizome_store)
DEBUGF("Closing fd=%d", write->blob_fd);
close(write->blob_fd);
write->blob_fd = -1;
@ -532,7 +525,7 @@ enum rhizome_payload_status rhizome_finish_write(struct rhizome_write *write)
// we've already got that payload, delete the new copy
sqlite_exec_void_retry_loglevel(LOG_LEVEL_WARN, &retry, "DELETE FROM FILEBLOBS WHERE id = ?;", UINT64_TOSTR, write->temp_id, END);
sqlite_exec_void_retry_loglevel(LOG_LEVEL_WARN, &retry, "DELETE FROM FILES WHERE id = ?;", UINT64_TOSTR, write->temp_id, END);
if (config.debug.rhizome)
if (config.debug.rhizome_store)
DEBUGF("Payload id=%s already present, removed id='%"PRIu64"'", alloca_tohex_rhizome_filehash_t(write->id), write->temp_id);
} else {
if (sqlite_exec_void_retry(&retry, "BEGIN TRANSACTION;", END) == -1)
@ -562,7 +555,7 @@ enum rhizome_payload_status rhizome_finish_write(struct rhizome_write *write)
WHYF_perror("rename(%s, %s)", blob_path, dest_path);
goto dbfailure;
}
if (config.debug.externalblobs)
if (config.debug.rhizome_store)
DEBUGF("Renamed %s to %s", blob_path, dest_path);
}else{
if (sqlite_exec_void_retry(
@ -577,7 +570,7 @@ enum rhizome_payload_status rhizome_finish_write(struct rhizome_write *write)
}
if (sqlite_exec_void_retry(&retry, "COMMIT;", END) == -1)
goto dbfailure;
if (config.debug.rhizome)
if (config.debug.rhizome_store)
DEBUGF("Stored file %s", alloca_tohex_rhizome_filehash_t(write->id));
}
write->blob_rowid = 0;
@ -670,7 +663,7 @@ enum rhizome_payload_status rhizome_stat_payload_file(rhizome_manifest *m, const
if (m->filesize == RHIZOME_SIZE_UNSET)
rhizome_manifest_set_filesize(m, size);
else if (size != m->filesize) {
if (config.debug.rhizome)
if (config.debug.rhizome_store)
DEBUGF("payload file %s (size=%"PRIu64") does not match manifest[%d].filesize=%"PRIu64,
alloca_str_toprint(filepath), size, m->manifest_record_number, m->filesize);
return RHIZOME_PAYLOAD_STATUS_WRONG_SIZE;
@ -688,7 +681,7 @@ static enum rhizome_bundle_status rhizome_write_derive_key(rhizome_manifest *m,
if (!rhizome_derive_payload_key(m))
return RHIZOME_PAYLOAD_STATUS_CRYPTO_FAIL;
if (config.debug.rhizome)
if (config.debug.rhizome_store)
DEBUGF("Encrypting payload contents for bid=%s, version=%"PRIu64,
alloca_tohex_rhizome_bid_t(m->cryptoSignPublic), m->version);
@ -788,7 +781,7 @@ enum rhizome_payload_status rhizome_open_read(struct rhizome_read *read, const r
read->blob_fd = open(blob_path, O_RDONLY);
if (read->blob_fd == -1) {
if (errno == ENOENT) {
if (config.debug.externalblobs)
if (config.debug.rhizome_store)
DEBUGF("Stored file does not exist: %s", blob_path);
// make sure we remove an orphan file row
rhizome_delete_file(&read->id);
@ -803,7 +796,7 @@ enum rhizome_payload_status rhizome_open_read(struct rhizome_read *read, const r
return RHIZOME_PAYLOAD_STATUS_ERROR;
}
read->length = pos;
if (config.debug.externalblobs)
if (config.debug.rhizome_store)
DEBUGF("Opened stored file %s as fd %d, len %"PRIx64, blob_path, read->blob_fd, read->length);
}
read->offset = 0;
@ -823,7 +816,7 @@ static ssize_t rhizome_read_retry(sqlite_retry_state *retry, struct rhizome_read
ssize_t rd = read(read_state->blob_fd, buffer, bufsz);
if (rd == -1)
RETURN(WHYF_perror("read(%d,%p,%zu)", read_state->blob_fd, buffer, bufsz));
if (config.debug.externalblobs)
if (config.debug.rhizome_store)
DEBUGF("Read %zu bytes from fd=%d @%"PRIx64, (size_t) rd, read_state->blob_fd, read_state->offset);
RETURN(rd);
}
@ -892,8 +885,6 @@ ssize_t rhizome_read(struct rhizome_read *read_state, unsigned char *buffer, siz
}
if (read_state->crypt && buffer && bytes_read>0){
if (config.debug.rhizome)
dump("before decrypt", buffer, bytes_read);
if(rhizome_crypt_xor_block(
buffer, bytes_read,
read_state->offset + read_state->tail,
@ -902,10 +893,8 @@ ssize_t rhizome_read(struct rhizome_read *read_state, unsigned char *buffer, siz
}
}
read_state->offset += bytes_read;
if (config.debug.rhizome) {
if (config.debug.rhizome_store)
DEBUGF("read %zu bytes, read_state->offset=%"PRIu64, bytes_read, read_state->offset);
//dump("buffer", buffer, bytes_read);
}
RETURN(bytes_read);
OUT();
}
@ -975,7 +964,7 @@ ssize_t rhizome_read_buffered(struct rhizome_read *read, struct rhizome_read_buf
void rhizome_read_close(struct rhizome_read *read)
{
if (read->blob_fd != -1) {
if (config.debug.externalblobs)
if (config.debug.rhizome_store)
DEBUGF("Closing store fd %d", read->blob_fd);
close(read->blob_fd);
read->blob_fd = -1;
@ -1183,7 +1172,7 @@ static enum rhizome_payload_status read_derive_key(rhizome_manifest *m, struct r
WHY("Unable to decrypt bundle, valid key not found");
return RHIZOME_PAYLOAD_STATUS_CRYPTO_FAIL;
}
if (config.debug.rhizome)
if (config.debug.rhizome_store)
DEBUGF("Decrypting payload contents for bid=%s version=%"PRIu64, alloca_tohex_rhizome_bid_t(m->cryptoSignPublic), m->version);
if (m->is_journal && m->tail > 0)
read_state->tail = m->tail;

View File

@ -33,7 +33,7 @@ setup_logging() {
set debug.meshms on \
set debug.rhizome on \
set debug.rhizome_manifest on \
set debug.externalblobs on \
set debug.rhizome_store on \
set debug.rejecteddata on \
set log.console.level debug \
set log.console.show_time on

View File

@ -106,7 +106,7 @@ set_rhizome_config() {
set debug.http_server on \
set debug.httpd on \
set debug.rhizome_manifest on \
set debug.externalblobs on \
set debug.rhizome_store on \
set debug.rhizome on \
set debug.verbose on \
set log.console.level debug

View File

@ -328,7 +328,7 @@ setup_FileTransferBigMDPExtBlob() {
executeOk_servald config \
set rhizome.http.enable 0 \
set rhizome.max_blob_size 0 \
set debug.externalblobs 1
set debug.rhizome_store 1
setup_bigfile_common
}
test_FileTransferBigMDPExtBlob() {
@ -342,7 +342,7 @@ setup_FileTransferBigHTTPExtBlob() {
executeOk_servald config \
set rhizome.mdp.enable 0 \
set rhizome.max_blob_size 0 \
set debug.externalblobs 1
set debug.rhizome_store 1
setup_bigfile_common
}
test_FileTransferBigHTTPExtBlob() {
@ -404,7 +404,7 @@ setup_FileTransferMultiMDPExtBlob() {
executeOk_servald config \
set rhizome.http.enable 0 \
set rhizome.max_blob_size 0 \
set debug.externalblobs 1
set debug.rhizome_store 1
setup_multitransfer_common
}
test_FileTransferMultiMDPExtBlob() {
@ -418,7 +418,7 @@ setup_FileTransferMultiHTTPExtBlob() {
executeOk_servald config \
set rhizome.mdp.enable 0 \
set rhizome.max_blob_size 0 \
set debug.externalblobs 1
set debug.rhizome_store 1
setup_multitransfer_common
}
test_FileTransferMultiHTTPExtBlob() {
@ -450,7 +450,9 @@ doc_CorruptPayload="A corrupted payload should be re-fetched"
setup_CorruptPayload() {
setup_common
set_instance +A
executeOk_servald config set rhizome.max_blob_size 0
executeOk_servald config \
set rhizome.max_blob_size 0 \
set debug.rhizome_store 1
rhizome_add_file file1 1024
start_servald_instances +A +B
wait_until bundle_received_by $BID:$VERSION +B
@ -473,7 +475,9 @@ doc_MissingPayload="A missing payload should be re-fetched"
setup_MissingPayload() {
setup_common
set_instance +A
executeOk_servald config set rhizome.max_blob_size 0
executeOk_servald config \
set rhizome.max_blob_size 0 \
set debug.rhizome_store 1
rhizome_add_file file1 1024
assert cmp file1 "$SERVALINSTANCE_PATH/blob/$FILEHASH"
start_servald_instances +A +B