Hackish changes to debug Windows Transfers...

Committing these so others can run tests.
Most of these changes will be removed once the problem is fixed!
 * Fixed formatting of various serialiser item::print() fns.
 * Disabled printout of TlvBinaryData - data.
 * added AccurateTimeString() function to util/rsprint.cc
 * print serialise / deserialise of FileRequest & FileData + Timestamps.
 * added print + timestamp in ftFileProvider::getFileData()
 * #define TRANSFER_DEBUG to isolate these changes.
 * enabled debugging in fttransfermodule.cc



git-svn-id: http://svn.code.sf.net/p/retroshare/code/trunk@3779 b45a01b8-16f6-495d-af2f-9b41ad6348cc

libretroshare/src/ft/ftfileprovider.cc

@@ -13,6 +13,16 @@
 * #define DEBUG_FT_FILE_PROVIDER 1
 ********/
 
+/***** TO GET TIMESTAMPS of DATA READING ****/
+#define DEBUG_TRANSFERS	1
+
+#ifdef DEBUG_TRANSFERS
+	#include "util/rsprint.h"
+	#include <iomanip>
+#endif
+
+
+
 static const time_t UPLOAD_CHUNK_MAPS_TIME = 20 ;	// time to ask for a new chunkmap from uploaders in seconds.
 
 ftFileProvider::ftFileProvider(std::string path, uint64_t size, std::string hash) 
@@ -186,6 +196,17 @@ bool ftFileProvider::getFileData(const std::string& peer_id,uint64_t offset, uin
 		//
 		time_t now = time(NULL) ;
 		uploading_peers[peer_id].updateStatus(offset,data_size,now) ;
+
+#ifdef DEBUG_TRANSFERS
+		std::cerr << "ftFileProvider::getFileData() ";
+		std::cerr << " at " << RsUtil::AccurateTimeString();
+		std::cerr << " hash: " << hash;
+		std::cerr << " for peerId: " << peer_id;
+		std::cerr << " offset: " << offset;
+		std::cerr << " chunkSize: " << chunk_size;
+		std::cerr << std::endl;
+#endif
+
 	}
 	else 
 	{

libretroshare/src/ft/fttransfermodule.cc

@@ -27,6 +27,8 @@
  * #define FT_DEBUG 1
  *****/
 
+#define FT_DEBUG 1
+
 #include "retroshare/rsturtle.h"
 #include "fttransfermodule.h"
 

libretroshare/src/serialiser/rsbaseitems.cc

@@ -32,6 +32,12 @@
 #define RSSERIAL_DEBUG 1
 ***/
 
+#define TRANSFER_DEBUG 1
+
+#ifdef TRANSFER_DEBUG
+	#include "util/rsprint.h"
+#endif
+
 #include <iostream>
 
 /*************************************************************************/
@@ -168,8 +174,8 @@ std::ostream &RsFileRequest::print(std::ostream &out, uint16_t indent)
         printRsItemBase(out, "RsFileRequest", indent);
 	uint16_t int_Indent = indent + 2;
         printIndent(out, int_Indent);
-        out << "FileOffset: " << fileoffset << std::endl;
+        out << "FileOffset: " << fileoffset;
-        out << "ChunkSize:  " << chunksize  << std::endl;
+        out << " ChunkSize:  " << chunksize  << std::endl;
 	file.print(out, int_Indent);
         printRsItemEnd(out, "RsFileRequest", indent);
         return out;
@@ -222,6 +228,15 @@ bool     RsFileItemSerialiser::serialiseReq(RsFileRequest *item, void *data, uin
 #endif
 	}
 
+	/*** Debugging Transfer rates. 
+	 * print timestamp, and file details so we can workout packet lags.
+	 ***/
+
+#ifdef TRANSFER_DEBUG
+	std::cerr << "RsFileItemSerialiser::serialiseReq() at: " << RsUtil::AccurateTimeString() << std::endl;
+	item->print(std::cerr, 10);
+#endif
+
 	return ok;
 }
 
@@ -275,6 +290,16 @@ RsFileRequest *RsFileItemSerialiser::deserialiseReq(void *data, uint32_t *pktsiz
 		return NULL;
 	}
 
+
+	/*** Debugging Transfer rates. 
+	 * print timestamp, and file details so we can workout packet lags.
+	 ***/
+
+#ifdef TRANSFER_DEBUG
+	std::cerr << "RsFileItemSerialiser::deserialiseReq() at: " << RsUtil::AccurateTimeString() << std::endl;
+	item->print(std::cerr, 10);
+#endif
+
 	return item;
 }
 
@@ -332,7 +357,6 @@ std::ostream &RsFileData::print(std::ostream &out, uint16_t indent)
 {
         printRsItemBase(out, "RsFileData", indent);
 	uint16_t int_Indent = indent + 2;
-        printIndent(out, int_Indent);
 	fd.print(out, int_Indent);
         printRsItemEnd(out, "RsFileData", indent);
         return out;
@@ -380,6 +404,12 @@ bool     RsFileItemSerialiser::serialiseData(RsFileData *item, void *data, uint3
 #endif
 	}
 
+#ifdef TRANSFER_DEBUG
+	std::cerr << "RsFileItemSerialiser::serialiseData() at: " << RsUtil::AccurateTimeString() << std::endl;
+	item->print(std::cerr, 10);
+#endif
+
+
 	return ok;
 }
 
@@ -430,6 +460,12 @@ RsFileData *RsFileItemSerialiser::deserialiseData(void *data, uint32_t *pktsize)
 		return NULL;
 	}
 
+#ifdef TRANSFER_DEBUG
+	std::cerr << "RsFileItemSerialiser::deserialiseData() at: " << RsUtil::AccurateTimeString() << std::endl;
+	item->print(std::cerr, 10);
+#endif
+
+
 	return item;
 }
 

libretroshare/src/serialiser/rstlvtypes.cc

@@ -212,6 +212,8 @@ std::ostream &RsTlvBinaryData::print(std::ostream &out, uint16_t indent)
         printIndent(sout, indent);
         sout << "RsTlvBinaryData: Type: " << tlvtype << " Size: " << bin_len;
         sout << std::hex;
+
+#if 0
         for(i = 0; i < bin_len; i++)
         {
                 if (i % 16 == 0)
@@ -222,7 +224,9 @@ std::ostream &RsTlvBinaryData::print(std::ostream &out, uint16_t indent)
                 sout << std::setw(2) << std::setfill('0')
                         << (int) (((unsigned char *) bin_data)[i]) << ":";
         }
+#endif
         sout << std::endl;
+
         out << sout.str();
 
         printEnd(out, "RsTlvBinaryData", indent);

libretroshare/src/util/rsprint.cc

@@ -80,3 +80,44 @@ std::string RsUtil::HashId(std::string id, bool reverse)
 
 	return hash;
 }
+
+
+
+
+#ifdef WINDOWS_SYS
+#include <time.h>
+#include <sys/timeb.h>
+#endif
+
+#include <sys/time.h>
+#include <sstream>
+#include <iomanip>
+
+static double getCurrentTS();
+
+// Little fn to get current timestamp in an independent manner.
+std::string RsUtil::AccurateTimeString()
+{
+	std::ostringstream out;
+	out << std::setprecision(15) << getCurrentTS();
+	return out.str();
+}
+
+static double getCurrentTS()
+{
+
+#ifndef WINDOWS_SYS
+        struct timeval cts_tmp;
+        gettimeofday(&cts_tmp, NULL);
+        double cts =  (cts_tmp.tv_sec) + ((double) cts_tmp.tv_usec) / 1000000.0;
+#else
+        struct _timeb timebuf;
+        _ftime( &timebuf);
+        double cts =  (timebuf.time) + ((double) timebuf.millitm) / 1000.0;
+#endif
+        return cts;
+}
+
+
+
+

libretroshare/src/util/rsprint.h

@@ -37,6 +37,8 @@ std::string BinToHex(std::string bin);
 std::string BinToHex(const char *arr, const uint32_t len);
 std::string HashId(std::string id, bool reverse = false);
 
+std::string AccurateTimeString();
+
 }
 	
 #endif