From 06273fa775a2517cd4defd0a5022b926e94dc1b9 Mon Sep 17 00:00:00 2001 From: drbob Date: Thu, 11 Nov 2010 20:51:17 +0000 Subject: [PATCH] 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 | 21 +++++++++++ libretroshare/src/ft/fttransfermodule.cc | 2 + libretroshare/src/serialiser/rsbaseitems.cc | 42 +++++++++++++++++++-- libretroshare/src/serialiser/rstlvtypes.cc | 4 ++ libretroshare/src/util/rsprint.cc | 41 ++++++++++++++++++++ libretroshare/src/util/rsprint.h | 2 + 6 files changed, 109 insertions(+), 3 deletions(-) diff --git a/libretroshare/src/ft/ftfileprovider.cc b/libretroshare/src/ft/ftfileprovider.cc index 62840f944..62b54f658 100644 --- a/libretroshare/src/ft/ftfileprovider.cc +++ b/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 +#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 { diff --git a/libretroshare/src/ft/fttransfermodule.cc b/libretroshare/src/ft/fttransfermodule.cc index f3cffa9da..a782a69cd 100644 --- a/libretroshare/src/ft/fttransfermodule.cc +++ b/libretroshare/src/ft/fttransfermodule.cc @@ -27,6 +27,8 @@ * #define FT_DEBUG 1 *****/ +#define FT_DEBUG 1 + #include "retroshare/rsturtle.h" #include "fttransfermodule.h" diff --git a/libretroshare/src/serialiser/rsbaseitems.cc b/libretroshare/src/serialiser/rsbaseitems.cc index f50c8dd52..f5f4bea9f 100644 --- a/libretroshare/src/serialiser/rsbaseitems.cc +++ b/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 /*************************************************************************/ @@ -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 << "ChunkSize: " << chunksize << std::endl; + out << "FileOffset: " << fileoffset; + 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; } diff --git a/libretroshare/src/serialiser/rstlvtypes.cc b/libretroshare/src/serialiser/rstlvtypes.cc index 720dc6d3d..76cc5c00f 100644 --- a/libretroshare/src/serialiser/rstlvtypes.cc +++ b/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); diff --git a/libretroshare/src/util/rsprint.cc b/libretroshare/src/util/rsprint.cc index 2bb6e81cd..4e7f6c1e5 100644 --- a/libretroshare/src/util/rsprint.cc +++ b/libretroshare/src/util/rsprint.cc @@ -80,3 +80,44 @@ std::string RsUtil::HashId(std::string id, bool reverse) return hash; } + + + + +#ifdef WINDOWS_SYS +#include +#include +#endif + +#include +#include +#include + +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; +} + + + + diff --git a/libretroshare/src/util/rsprint.h b/libretroshare/src/util/rsprint.h index 1fb0947c2..dd1cce9ca 100644 --- a/libretroshare/src/util/rsprint.h +++ b/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