? src/lib-index/mail-cache-debug.diff
Index: src/lib-index/mail-cache-compress.c
===================================================================
RCS file: /var/lib/cvs/dovecot/src/lib-index/mail-cache-compress.c,v
retrieving revision 1.42
diff -u -r1.42 mail-cache-compress.c
--- src/lib-index/mail-cache-compress.c	3 May 2006 20:07:13 -0000	1.42
+++ src/lib-index/mail-cache-compress.c	28 May 2006 20:00:13 -0000
@@ -152,6 +152,7 @@
 	hdr.indexid = idx_hdr->indexid;
 	hdr.file_seq = get_next_file_seq(cache, view);
 	o_stream_send(output, &hdr, sizeof(hdr));
+	i_debug("mail_cache_copy: new file_seq = ", hdr.file_seq);
 
 	memset(&ctx, 0, sizeof(ctx));
 	ctx.buffer = buffer_create_dynamic(default_pool, 4096);
@@ -306,9 +307,10 @@
 	}
 
 #ifdef DEBUG
-	i_warning("Compressing cache file %s (%u)",
-		  cache->filepath, cache->need_compress_file_seq);
+	/*i_warning("Compressing cache file %s (%u)",
+		  cache->filepath, cache->need_compress_file_seq);*/
 #endif
+	i_debug("mail_cache_compress: begin");
 
 	if (cache->index->gid != (gid_t)-1 &&
 	    fchown(fd, (uid_t)-1, cache->index->gid) < 0) {
@@ -330,6 +332,8 @@
 		return -1;
 	}
 
+	i_debug("mail_cache_compress: done");
+
 	mail_cache_file_close(cache);
 	cache->fd = fd;
 
Index: src/lib-index/mail-cache-fields.c
===================================================================
RCS file: /var/lib/cvs/dovecot/src/lib-index/mail-cache-fields.c,v
retrieving revision 1.21
diff -u -r1.21 mail-cache-fields.c
--- src/lib-index/mail-cache-fields.c	31 Mar 2006 14:06:52 -0000	1.21
+++ src/lib-index/mail-cache-fields.c	28 May 2006 20:00:13 -0000
@@ -26,6 +26,9 @@
 				     &orig_key, &orig_value)) {
 			fields[i].idx =
 				POINTER_CAST_TO(orig_value, unsigned int);
+			i_debug("mail_cache_register_fields: "
+				"registered %s as existing %u",
+				fields[i].name, fields[i].idx);
 			continue;
 		}
 
@@ -38,8 +41,16 @@
 			}
 		}
 
-		if (j == i)
+		if (j == i) {
 			fields[i].idx = new_idx++;
+			i_debug("mail_cache_register_fields: "
+				"registered %s as new %u",
+				fields[i].name, fields[i].idx);
+		} else {
+			i_debug("mail_cache_register_fields: "
+				"registered %s as existing %u",
+				fields[i].name, fields[i].idx);
+		}
 	}
 
 	if (new_idx == cache->fields_count)
@@ -168,6 +179,7 @@
 
 	if (offset == 0) {
 		/* no fields - the file is empty */
+		i_debug("mail_cache_header_fields_read: file is empty");
 		return 0;
 	}
 
@@ -268,6 +280,8 @@
 
                 names = p + 1;
 	}
+	i_debug("mail_cache_header_fields_read: file has %d/%d fields now",
+		cache->file_fields_count, cache->fields_count);
 	return 0;
 }
 
@@ -318,6 +332,8 @@
 	uint32_t i, offset;
 	int ret = 0;
 
+	i_debug("mail_cache_header_fields_update: updating..");
+
 	if (mail_cache_header_fields_read(cache) < 0 ||
 	    mail_cache_header_fields_get_offset(cache, &offset) < 0)
 		return -1;
@@ -328,6 +344,8 @@
 	copy_to_buf(cache, buffer,
 		    offsetof(struct mail_cache_field_private, last_used),
 		    sizeof(uint32_t));
+	i_debug("mail_cache_header_fields_update: writing to offset %u",
+		offset + MAIL_CACHE_FIELD_LAST_USED());
 	ret = mail_cache_write(cache, buffer->data,
 			       sizeof(uint32_t) * cache->file_fields_count,
 			       offset + MAIL_CACHE_FIELD_LAST_USED());
@@ -336,6 +354,9 @@
 		copy_to_buf_byte(cache, buffer,
 				 offsetof(struct mail_cache_field, decision));
 
+		i_debug("mail_cache_header_fields_update: writing to offset %u",
+			offset +
+			MAIL_CACHE_FIELD_DECISION(cache->file_fields_count));
 		ret = mail_cache_write(cache, buffer->data,
 			sizeof(uint8_t) * cache->file_fields_count, offset +
 			MAIL_CACHE_FIELD_DECISION(cache->file_fields_count));
Index: src/lib-index/mail-cache-lookup.c
===================================================================
RCS file: /var/lib/cvs/dovecot/src/lib-index/mail-cache-lookup.c,v
retrieving revision 1.33
diff -u -r1.33 mail-cache-lookup.c
--- src/lib-index/mail-cache-lookup.c	13 Jan 2006 20:26:13 -0000	1.33
+++ src/lib-index/mail-cache-lookup.c	28 May 2006 20:00:13 -0000
@@ -107,6 +107,8 @@
 		return 1;
 	}
 
+	i_debug("mail_cache_foreach_rec: offset=%u", *offset);
+
 	max_size = cache_rec->size;
 	if (max_size < sizeof(*cache_rec) + sizeof(uint32_t)*2) {
 		mail_cache_set_corrupted(cache, "record has invalid size");
@@ -119,6 +121,7 @@
 			*((const uint32_t *)CONST_PTR_OFFSET(cache_rec, pos));
 		pos += sizeof(uint32_t);
 
+		i_debug("mail_cache_foreach_rec:  - file_field=%u", file_field);
 		if (file_field >= cache->file_fields_count) {
 			/* new field, have to re-read fields header to figure
 			   out its size */
Index: src/lib-index/mail-cache-transaction.c
===================================================================
RCS file: /var/lib/cvs/dovecot/src/lib-index/mail-cache-transaction.c,v
retrieving revision 1.49
diff -u -r1.49 mail-cache-transaction.c
--- src/lib-index/mail-cache-transaction.c	28 Jan 2006 21:10:41 -0000	1.49
+++ src/lib-index/mail-cache-transaction.c	28 May 2006 20:00:13 -0000
@@ -108,8 +108,10 @@
 	if ((ret = mail_cache_lock(ctx->cache)) <= 0)
 		return ret;
 
-	if (ctx->cache_file_seq != ctx->cache->hdr->file_seq)
+	if (ctx->cache_file_seq != ctx->cache->hdr->file_seq) {
+		i_debug("mail_cache_transaction_lock: reopened - reset");
 		mail_cache_transaction_reset(ctx);
+	}
 	return 1;
 }
 
@@ -120,6 +122,8 @@
 
 	i_assert(cache->locked);
 
+	i_debug("mail_cache_grow_file: size=%"PRIuSIZE_T, size);
+
 	/* grow the file */
 	new_fsize = cache->hdr_copy.used_file_size + size;
 	grow_size = new_fsize / 100 * MAIL_CACHE_GROW_PERCENTAGE;
@@ -151,6 +155,8 @@
 
 	i_assert(cache->locked);
 
+	i_debug("mail_cache_unlink_hole: offset=%u", hdr->hole_offset);
+
 	offset = hdr->hole_offset; prev_offset = 0;
 	while (offset != 0) {
 		if (pread_full(cache->fd, &hole, sizeof(hole), offset) <= 0) {
@@ -176,6 +182,7 @@
 	if (prev_offset == 0)
 		hdr->hole_offset = hole.next_offset;
 	else {
+		i_debug("mail_cache_unlink_hole: writing at %u", prev_offset);
 		if (mail_cache_write(cache, &hole.next_offset,
 				     sizeof(hole.next_offset), prev_offset) < 0)
 			return FALSE;
@@ -295,6 +302,7 @@
 		hole.size = size;
 		hole.magic = MAIL_CACHE_HOLE_HEADER_MAGIC;
 
+		i_debug("mail_cache_free_space: writing at %u", offset);
 		if (mail_cache_write(cache, &hole, sizeof(hole), offset) < 0)
 			return;
 
@@ -366,6 +374,7 @@
 
 		if (cache_file_seq != ctx->cache_file_seq) {
 			/* cache file reopened - need to abort */
+			i_debug("mail_cache_transaction_flush: aborted");
 			return 0;
 		}
 
@@ -455,6 +464,8 @@
 	int ret;
 	bool commit;
 
+	i_debug("mail_cache_transaction_flush");
+
 	if (MAIL_CACHE_IS_UNUSABLE(cache))
 		return -1;
 
@@ -502,6 +513,9 @@
 		}
 
 		/* write it to file */
+		i_debug("mail_cache_transaction_flush: "
+			"writing at %u, size=%"PRIuSIZE_T,
+			write_offset, max_size);
 		i_assert(ctx->cache_file_seq == cache->hdr->file_seq);
 		if (mail_cache_write(cache, rec, max_size, write_offset) < 0)
 			return -1;
@@ -563,6 +577,8 @@
 	struct mail_cache *cache = ctx->cache;
 	int ret = 0;
 
+	i_debug("mail_cache_transaction_commit");
+
 	if (!ctx->changes || MAIL_CACHE_IS_UNUSABLE(cache)) {
 		mail_cache_transaction_free(ctx);
 		return 0;
@@ -596,6 +612,8 @@
 	const struct mail_cache_reservation *reservations;
 	unsigned int count;
 
+	i_debug("mail_cache_transaction_rollback");
+
 	if ((ctx->reserved_space > 0 || array_count(&ctx->reservations) > 0) &&
 	    !MAIL_CACHE_IS_UNUSABLE(cache)) {
 		if (mail_cache_transaction_lock(ctx) > 0) {
@@ -628,6 +646,8 @@
 	uint32_t offset, hdr_offset;
 	int ret = 0;
 
+	i_debug("mail_cache_header_add_field: field=%u", field);
+
 	if (mail_cache_transaction_lock(ctx) <= 0)
 		return -1;
 
@@ -662,6 +682,10 @@
 		ret = -1;
 	else {
 		/* after it's guaranteed to be in disk, update header offset */
+		i_debug("mail_cache_header_add_field: writing at %u, "
+			"size=%"PRIuSIZE_T, offset, size);
+		i_debug("mail_cache_header_add_field: writing hdr_offset at %u",
+			hdr_offset);
 		offset = mail_index_uint32_to_offset(offset);
 		if (mail_cache_write(cache, &offset, sizeof(offset),
 				     hdr_offset) < 0)
@@ -751,6 +775,7 @@
 				    uint32_t old_offset, uint32_t new_offset)
 {
 	new_offset += offsetof(struct mail_cache_record, prev_offset);
+	i_debug("mail_cache_link_unlocked: writing at %u", new_offset);
 	return mail_cache_write(cache, &old_offset, sizeof(old_offset),
 				new_offset);
 }
Index: src/lib-index/mail-cache.c
===================================================================
RCS file: /var/lib/cvs/dovecot/src/lib-index/mail-cache.c,v
retrieving revision 1.80
diff -u -r1.80 mail-cache.c
--- src/lib-index/mail-cache.c	3 May 2006 20:07:13 -0000	1.80
+++ src/lib-index/mail-cache.c	28 May 2006 20:00:13 -0000
@@ -31,10 +31,10 @@
 {
 	va_list va;
 
-	(void)unlink(cache->filepath);
+	//(void)unlink(cache->filepath);
 
 	/* mark the cache as unusable */
-	cache->hdr = NULL;
+	//cache->hdr = NULL;
 
 	va_start(va, fmt);
 	t_push();
@@ -42,6 +42,7 @@
 			     cache->filepath, t_strdup_vprintf(fmt, va));
 	t_pop();
 	va_end(va);
+	abort();
 }
 
 void mail_cache_file_close(struct mail_cache *cache)
@@ -77,6 +78,7 @@
 		/* reopening does no good */
 		return 0;
 	}
+	i_debug("mail_cache_reopen: re-opened");
 
 	mail_cache_file_close(cache);
 
@@ -247,6 +249,7 @@
 		return -1;
 	}
 
+	i_debug("mail_cache_map: re-mmaped");
 	return 0;
 }
 
@@ -398,9 +401,12 @@
 		return 0;
 	}
 
+	i_debug("mail_cache_lock: locking");
+
 	if (cache->hdr->file_seq != ext->reset_id) {
 		/* we want the latest cache file */
 		if ((ret = mail_cache_reopen(cache)) <= 0) {
+			i_debug("mail_cache_lock: failed");
 			mail_index_view_close(&view);
 			return ret;
 		}
@@ -423,6 +429,7 @@
 			break;
 		ret = 0;
 	}
+	i_debug("mail_cache_lock: finished, ret = %d", ret);
 
 	if (ret > 0) {
 		/* make sure our header is up to date */
@@ -495,6 +502,7 @@
 	}
 
 	(void)mail_cache_lock_file(cache, F_UNLCK);
+	i_debug("mail_cache_unlock: unlocked");
 	return ret;
 }