added even more debugging info

4 files changed, 93 insertions, 33 deletions

diff --git a/src/engine/e_engine.c b/src/engine/e_engine.c
index c3851380..b1cf345f 100644
--- a/src/engine/e_engine.c
+++ b/src/engine/e_engine.c
@@ -109,11 +109,11 @@ void perf_start(PERFORMACE_INFO *info)
 
 void perf_end()
 {
-	int64 delta = time_get()-current->start;
-	current->total += delta;
+	current->last_delta = time_get()-current->start;
+	current->total += current->last_delta;
 	
-	if(delta > current->biggest)
-		current->biggest = delta;
+	if(current->last_delta > current->biggest)
+		current->biggest = current->last_delta;
 	
 	current = current->parent;
 }
diff --git a/src/engine/e_interface.h b/src/engine/e_interface.h
index 9d251443..b8a0a6a7 100644
--- a/src/engine/e_interface.h
+++ b/src/engine/e_interface.h
@@ -99,6 +99,7 @@ typedef struct PERFORMACE_INFO_t
 	int64 start;
 	int64 total;
 	int64 biggest;
+	int64 last_delta;
 } PERFORMACE_INFO;
 
 void perf_init();
diff --git a/src/engine/e_snapshot.c b/src/engine/e_snapshot.c
index 91b7797b..112f8fed 100644
--- a/src/engine/e_snapshot.c
+++ b/src/engine/e_snapshot.c
@@ -1,6 +1,7 @@
 /* copyright (c) 2007 magnus auvinen, see licence.txt for more info */
 #include "e_snapshot.h"
 #include "e_compression.h"
+#include "e_interface.h"
 
 
 int *snapitem_data(SNAPSHOT_ITEM *item) { return (int *)(item+1); }
@@ -154,52 +155,80 @@ int snapshot_create_delta(SNAPSHOT *from, SNAPSHOT *to, void *dstdata)
 	delta->num_temp_items = 0;
 
 	/* pack deleted stuff */
-	for(i = 0; i < from->num_items; i++)
 	{
-		fromitem = snapshot_get_item(from, i);
-		if(snapshot_get_item_index(to, (snapitem_key(fromitem))) == -1)
+		static PERFORMACE_INFO scope = {"delete", 0};
+		perf_start(&scope);
+		
+		for(i = 0; i < from->num_items; i++)
 		{
-			/* deleted */
-			delta->num_deleted_items++;
-			*data = snapitem_key(fromitem);
-			data++;
+			fromitem = snapshot_get_item(from, i);
+			if(snapshot_get_item_index(to, (snapitem_key(fromitem))) == -1)
+			{
+				/* deleted */
+				delta->num_deleted_items++;
+				*data = snapitem_key(fromitem);
+				data++;
+			}
 		}
+		
+		perf_end();
 	}
 	
 	/* pack updated stuff */
-	for(i = 0; i < to->num_items; i++)
 	{
-		/* do delta */
-		itemsize = snapshot_get_item_datasize(to, i);
-		
-		curitem = snapshot_get_item(to, i);
-		pastindex = snapshot_get_item_index(from, snapitem_key(curitem));
-		if(pastindex != -1)
+		static PERFORMACE_INFO scope = {"update", 0};
+		perf_start(&scope);
+			
+		for(i = 0; i < to->num_items; i++)
 		{
-			pastitem = snapshot_get_item(from, pastindex);
-			if(diff_item((int*)snapitem_data(pastitem), (int*)snapitem_data(curitem), data+3, itemsize/4))
+			/* do delta */
 			{
+				static PERFORMACE_INFO scope = {"find", 0};
+				perf_start(&scope);
+				itemsize = snapshot_get_item_datasize(to, i);
+				curitem = snapshot_get_item(to, i);
+				pastindex = snapshot_get_item_index(from, snapitem_key(curitem));
+				perf_end();
+			}
+			
+			if(pastindex != -1)
+			{
+				static PERFORMACE_INFO scope = {"diff", 0};
+				perf_start(&scope);
+		
+				pastitem = snapshot_get_item(from, pastindex);
+				if(diff_item((int*)snapitem_data(pastitem), (int*)snapitem_data(curitem), data+3, itemsize/4))
+				{
+					*data++ = itemsize;
+					*data++ = snapitem_type(curitem);
+					*data++ = snapitem_id(curitem);
+					/*data++ = curitem->key();*/
+					data += itemsize/4;
+					delta->num_update_items++;
+				}
+				perf_end();
+			}
+			else
+			{
+				static PERFORMACE_INFO scope = {"copy", 0};
+				perf_start(&scope);
+				
 				*data++ = itemsize;
 				*data++ = snapitem_type(curitem);
 				*data++ = snapitem_id(curitem);
 				/*data++ = curitem->key();*/
+				
+				mem_copy(data, snapitem_data(curitem), itemsize);
+				size_count += itemsize;
 				data += itemsize/4;
 				delta->num_update_items++;
+				count++;
+				
+				perf_end();
 			}
 		}
-		else
-		{
-			*data++ = itemsize;
-			*data++ = snapitem_type(curitem);
-			*data++ = snapitem_id(curitem);
-			/*data++ = curitem->key();*/
-			
-			mem_copy(data, snapitem_data(curitem), itemsize);
-			size_count += itemsize;
-			data += itemsize/4;
-			delta->num_update_items++;
-			count++;
-		}
+		
+		perf_end();
 	}
 	
 	if(0)
diff --git a/src/engine/server/es_server.c b/src/engine/server/es_server.c
index c8bdebc0..161bd3dc 100644
--- a/src/engine/server/es_server.c
+++ b/src/engine/server/es_server.c
@@ -346,9 +346,39 @@ static void server_do_snap()
 			/* create delta */
 			{
 				static PERFORMACE_INFO scope = {"delta", 0};
+				static int temp = 0;
 				perf_start(&scope);
 				deltasize = snapshot_create_delta(deltashot, (SNAPSHOT*)data, deltadata);
 				perf_end();
+				
+				temp++;
+				
+				if(scope.last_delta > time_freq()/50 || (temp%1000) == 0)
+				{
+					static int id = 0;
+					char buf[64];
+					IOHANDLE f;
+					id++;
+					
+					dbg_msg("server", "took very long time to create delta, saving info");
+					
+					sprintf(buf, "%d_from.raw", id);
+					f = io_open(buf, IOFLAG_WRITE);
+					if(f)
+					{
+						io_write(f, deltashot, deltashot_size);
+						io_close(f);
+					}
+
+					sprintf(buf, "%d_to.raw", id);
+					f = io_open(buf, IOFLAG_WRITE);
+					if(f)
+					{
+						io_write(f, data, snapshot_size);
+						io_close(f);
+					}
+
+				}
 			}