From 9cf950472cbbb5452f9eca63ad7e0f37725a9535 Mon Sep 17 00:00:00 2001 From: mr-alice Date: Sun, 18 Sep 2016 22:05:27 +0200 Subject: [PATCH] removed most of debug info in file list sharing code --- .../src/file_sharing/directory_storage.cc | 20 ++++-- .../src/file_sharing/directory_updater.cc | 21 ++++-- libretroshare/src/file_sharing/hash_cache.cc | 4 +- libretroshare/src/file_sharing/p3filelists.cc | 69 +++++++++++++++++-- libretroshare/src/file_sharing/p3filelists.h | 3 - 5 files changed, 99 insertions(+), 18 deletions(-) diff --git a/libretroshare/src/file_sharing/directory_storage.cc b/libretroshare/src/file_sharing/directory_storage.cc index efb88bd08..45cb3ccca 100644 --- a/libretroshare/src/file_sharing/directory_storage.cc +++ b/libretroshare/src/file_sharing/directory_storage.cc @@ -32,6 +32,8 @@ #include "dir_hierarchy.h" #include "filelist_io.h" +//#define DEBUG_REMOTE_DIRECTORY_STORAGE 1 + /******************************************************************************************************************/ /* Iterators */ /******************************************************************************************************************/ @@ -384,7 +386,9 @@ void LocalDirectoryStorage::updateShareFlags(const SharedDirInfo& info) { it->second = info; +#ifdef DEBUG_LOCAL_DIRECTORY_STORAGE std::cerr << "Updating dir mod time because flags at level 0 have changed." << std::endl; +#endif changed = true ; } } @@ -427,12 +431,16 @@ void LocalDirectoryStorage::updateTimeStamps() if(mTSChanged) { +#ifdef DEBUG_LOCAL_DIRECTORY_STORAGE std::cerr << "Updating recursive TS for local shared dirs..." << std::endl; +#endif time_t last_modf_time = mFileHierarchy->recursUpdateLastModfTime(EntryIndex(0)) ; mTSChanged = false ; +#ifdef DEBUG_LOCAL_DIRECTORY_STORAGE std::cerr << "LocalDirectoryStorage: global last modf time is " << last_modf_time << " (which is " << time(NULL) - last_modf_time << " secs ago)" << std::endl; +#endif } } @@ -444,7 +452,7 @@ std::string LocalDirectoryStorage::locked_findRealRootFromVirtualFilename(const if (cit == mLocalDirs.end()) { - std::cerr << "FileIndexMonitor::locked_findRealRoot() Invalid RootDir: " << virtual_rootdir << std::endl; + std::cerr << "(EE) locked_findRealRootFromVirtualFilename() Invalid RootDir: " << virtual_rootdir << std::endl; return std::string(); } return cit->second.filename; @@ -681,7 +689,9 @@ bool LocalDirectoryStorage::serialiseDirEntry(const EntryIndex& indx,RsTlvBinary free(file_section_data) ; } +#ifdef DEBUG_LOCAL_DIRECTORY_STORAGE std::cerr << "Serialised dir entry to send for entry index " << (void*)(intptr_t)indx << ". Data size is " << section_size << " bytes" << std::endl; +#endif bindata.bin_data = section_data ; bindata.bin_len = section_offset ; @@ -698,10 +708,10 @@ RemoteDirectoryStorage::RemoteDirectoryStorage(const RsPeerId& pid,const std::st { load(fname) ; - std::cerr << "***************************************" << std::endl; - std::cerr << "Loaded following directory for peer " << pid << std::endl; + std::cerr << "Loaded remote directory for peer " << pid << std::endl; +#ifdef DEBUG_REMOTE_DIRECTORY_STORAGE mFileHierarchy->print(); - std::cerr << "***************************************" << std::endl; +#endif } void RemoteDirectoryStorage::checkSave() @@ -721,7 +731,9 @@ bool RemoteDirectoryStorage::deserialiseUpdateDirEntry(const EntryIndex& indx,co uint32_t section_size = bindata.bin_len ; uint32_t section_offset=0 ; +#ifdef DEBUG_REMOTE_DIRECTORY_STORAGE std::cerr << "RemoteDirectoryStorage::deserialiseDirEntry(): deserialising directory content for friend " << peerId() << ", and directory " << indx << std::endl; +#endif std::string dir_name ; uint32_t most_recent_time ,dir_modtime ; diff --git a/libretroshare/src/file_sharing/directory_updater.cc b/libretroshare/src/file_sharing/directory_updater.cc index 16ca35be8..c2e20aeca 100644 --- a/libretroshare/src/file_sharing/directory_updater.cc +++ b/libretroshare/src/file_sharing/directory_updater.cc @@ -29,7 +29,7 @@ #include "directory_updater.h" #include "file_sharing_defaults.h" -#define DEBUG_LOCAL_DIR_UPDATER 1 +//#define DEBUG_LOCAL_DIR_UPDATER 1 //=============================================================================================================// // Local Directory Updater // @@ -89,8 +89,9 @@ void LocalDirectoryUpdater::forceUpdate() void LocalDirectoryUpdater::sweepSharedDirectories() { RsServer::notify()->notifyListPreChange(NOTIFY_LIST_DIRLIST_LOCAL, 0); - - std::cerr << "LocalDirectoryUpdater::sweep()" << std::endl; +#ifdef DEBUG_LOCAL_DIR_UPDATER + std::cerr << "[directory storage] LocalDirectoryUpdater::sweep()" << std::endl; +#endif // recursive update algorithm works that way: // - the external loop starts on the shared directory list and goes through sub-directories @@ -114,7 +115,9 @@ void LocalDirectoryUpdater::sweepSharedDirectories() for(DirectoryStorage::DirIterator stored_dir_it(mSharedDirectories,mSharedDirectories->root()) ; stored_dir_it;++stored_dir_it) { - std::cerr << " recursing into " << stored_dir_it.name() << std::endl; +#ifdef DEBUG_LOCAL_DIR_UPDATER + std::cerr << "[directory storage] recursing into " << stored_dir_it.name() << std::endl; +#endif recursUpdateSharedDir(stored_dir_it.name(), *stored_dir_it) ; // here we need to use the list that was stored, instead of the shared dir list, because the two // are not necessarily in the same order. @@ -124,7 +127,9 @@ void LocalDirectoryUpdater::sweepSharedDirectories() void LocalDirectoryUpdater::recursUpdateSharedDir(const std::string& cumulated_path, DirectoryStorage::EntryIndex indx) { - std::cerr << " parsing directory " << cumulated_path << ", index=" << indx << std::endl; +#ifdef DEBUG_LOCAL_DIR_UPDATER + std::cerr << "[directory storage] parsing directory " << cumulated_path << ", index=" << indx << std::endl; +#endif // make sure list of subdirs is the same // make sure list of subfiles is the same @@ -143,11 +148,15 @@ void LocalDirectoryUpdater::recursUpdateSharedDir(const std::string& cumulated_p { case librs::util::FolderIterator::TYPE_FILE: subfiles[dirIt.file_name()].modtime = dirIt.file_modtime() ; subfiles[dirIt.file_name()].size = dirIt.file_size(); +#ifdef DEBUG_LOCAL_DIR_UPDATER std::cerr << " adding sub-file \"" << dirIt.file_name() << "\"" << std::endl; +#endif break; case librs::util::FolderIterator::TYPE_DIR: subdirs[dirIt.file_name()] = dirIt.file_modtime(); +#ifdef DEBUG_LOCAL_DIR_UPDATER std::cerr << " adding sub-dir \"" << dirIt.file_name() << "\"" << std::endl; +#endif break; default: std::cerr << "(EE) Dir entry of unknown type with path \"" << cumulated_path << "/" << dirIt.file_name() << "\"" << std::endl; @@ -182,7 +191,9 @@ void LocalDirectoryUpdater::recursUpdateSharedDir(const std::string& cumulated_p for(std::map::const_iterator real_dir_it(subdirs.begin());real_dir_it!=subdirs.end();++real_dir_it, ++stored_dir_it) { +#ifdef DEBUG_LOCAL_DIR_UPDATER std::cerr << " recursing into " << stored_dir_it.name() << std::endl; +#endif recursUpdateSharedDir(cumulated_path + "/" + stored_dir_it.name(), *stored_dir_it) ; } } diff --git a/libretroshare/src/file_sharing/hash_cache.cc b/libretroshare/src/file_sharing/hash_cache.cc index becbf48f5..3f96abec1 100644 --- a/libretroshare/src/file_sharing/hash_cache.cc +++ b/libretroshare/src/file_sharing/hash_cache.cc @@ -30,7 +30,7 @@ #include "filelist_io.h" #include "file_sharing_defaults.h" -#define HASHSTORAGE_DEBUG 1 +//#define HASHSTORAGE_DEBUG 1 static const uint32_t DEFAULT_INACTIVITY_SLEEP_TIME = 50*1000; static const uint32_t MAX_INACTIVITY_SLEEP_TIME = 2*1000*1000; @@ -100,7 +100,9 @@ void HashStorage::data_tick() // sleep off mutex! if(empty) { +#ifdef HASHSTORAGE_DEBUG std::cerr << "nothing to hash. Sleeping for " << st << " us" << std::endl; +#endif usleep(st); // when no files to hash, just wait for 2 secs. This avoids a dramatic loop. diff --git a/libretroshare/src/file_sharing/p3filelists.cc b/libretroshare/src/file_sharing/p3filelists.cc index 9608ef8a6..0fd6bc5db 100644 --- a/libretroshare/src/file_sharing/p3filelists.cc +++ b/libretroshare/src/file_sharing/p3filelists.cc @@ -39,6 +39,8 @@ #define P3FILELISTS_DEBUG() std::cerr << time(NULL) << " : FILE_LISTS : " << __FUNCTION__ << " : " #define P3FILELISTS_ERROR() std::cerr << "***ERROR***" << " : FILE_LISTS : " << __FUNCTION__ << " : " +//#define DEBUG_P3FILELISTS 1 + static const uint32_t P3FILELISTS_UPDATE_FLAG_NOTHING_CHANGED = 0x0000 ; static const uint32_t P3FILELISTS_UPDATE_FLAG_REMOTE_MAP_CHANGED = 0x0001 ; static const uint32_t P3FILELISTS_UPDATE_FLAG_LOCAL_DIRS_CHANGED = 0x0002 ; @@ -179,9 +181,9 @@ int p3FileDatabase::tick() { RS_STACK_MUTEX(mFLSMtx) ; -//#ifdef DEBUG_FILE_HIERARCHY +#ifdef DEBUG_FILE_HIERARCHY mLocalSharedDirs->print(); -//#endif +#endif last_print_time = now ; //#warning this should be removed, but it's necessary atm for updating the GUI @@ -200,7 +202,7 @@ int p3FileDatabase::tick() mUpdateFlags = P3FILELISTS_UPDATE_FLAG_NOTHING_CHANGED ; } -#warning we need to make sure that one req per directory will not cause to keep re-asking the top level dirs. + if(mLastRemoteDirSweepTS + 5 < now) { RS_STACK_MUTEX(mFLSMtx) ; @@ -235,20 +237,29 @@ int p3FileDatabase::tick() void p3FileDatabase::startThreads() { RS_STACK_MUTEX(mFLSMtx) ; +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "Starting directory watcher thread..." ; +#endif mLocalDirWatcher->start(); +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "Done." << std::endl; +#endif } void p3FileDatabase::stopThreads() { RS_STACK_MUTEX(mFLSMtx) ; +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "Stopping hash cache thread..." ; std::cerr.flush() ; +#endif mHashCache->fullstop(); +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "Done." << std::endl; - P3FILELISTS_DEBUG() << "Stopping directory watcher thread..." ; std::cerr.flush() ; +#endif mLocalDirWatcher->fullstop(); +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "Done." << std::endl; +#endif } void p3FileDatabase::tickWatchers() @@ -404,8 +415,9 @@ void p3FileDatabase::cleanup() { { RS_STACK_MUTEX(mFLSMtx) ; - +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "p3FileDatabase::cleanup()" << std::endl; +#endif // look through the list of friend directories. Remove those who are not our friends anymore. // @@ -422,7 +434,10 @@ void p3FileDatabase::cleanup() for(uint32_t i=0;ipeerId()) == friend_set.end()) { + +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << " removing file list of non friend " << mRemoteDirectories[i]->peerId() << std::endl; +#endif delete mRemoteDirectories[i]; mRemoteDirectories[i] = NULL ; @@ -446,7 +461,9 @@ void p3FileDatabase::cleanup() if(mRemoteDirectories.size() > friend_index && mRemoteDirectories[friend_index] != NULL) continue ; +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << " adding missing remote dir entry for friend " << *it << ", with index " << friend_index << std::endl; +#endif if(mRemoteDirectories.size() <= friend_index) mRemoteDirectories.resize(friend_index+1,NULL) ; @@ -467,7 +484,9 @@ void p3FileDatabase::cleanup() for(std::map::iterator it = mPendingSyncRequests.begin();it!=mPendingSyncRequests.end();) if(online_peers.find(it->second.peer_id) == online_peers.end() || it->second.request_TS + DELAY_BEFORE_DROP_REQUEST < now) { +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << " removing pending request " << std::hex << it->first << std::dec << " for peer " << it->second.peer_id << ", because peer is offline or request is too old." << std::endl; +#endif std::map::iterator tmp(it); ++tmp; @@ -476,7 +495,9 @@ void p3FileDatabase::cleanup() } else { +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << " keeping request " << std::hex << it->first << std::dec << " for peer " << it->second.peer_id << std::endl; +#endif ++it ; } } @@ -597,10 +618,16 @@ void p3FileDatabase::requestDirUpdate(void *ref) if(fi == 0) return ; // not updating current directory (should we?) +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "Trying to force sync of entry ndex " << e << " to friend " << mRemoteDirectories[fi-1]->peerId() << std::endl; +#endif if(generateAndSendSyncRequest(mRemoteDirectories[fi-1],e)) + { +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << " Succeed." << std::endl; +#endif + } } bool p3FileDatabase::findChildPointer(void *ref, int row, void *& result, FileSearchFlags flags) const @@ -1010,7 +1037,9 @@ void p3FileDatabase::handleDirSyncRequest(RsFileListsSyncRequestItem *item) { RS_STACK_MUTEX(mFLSMtx) ; +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "Received directory sync request. hash=" << item->entry_hash << ", flags=" << (void*)(intptr_t)item->flags << ", request id: " << std::hex << item->request_id << std::dec << ", last known TS: " << item->last_known_recurs_modf_TS << std::endl; +#endif EntryIndex entry_index = DirectoryStorage::NO_INDEX; @@ -1030,7 +1059,9 @@ void p3FileDatabase::handleDirSyncRequest(RsFileListsSyncRequestItem *item) if(entry_type != DIR_TYPE_DIR) { +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << " Directory does not exist anymore, or is not a directory, or permission denied. Answering with proper flags." << std::endl; +#endif ritem->flags = RsFileListsItem::FLAGS_SYNC_RESPONSE | RsFileListsItem::FLAGS_ENTRY_WAS_REMOVED ; } else if(entry_index != 0 && (!mLocalSharedDirs->getFileSharingPermissions(entry_index,node_flags,node_groups) || !(rsPeers->computePeerPermissionFlags(item->PeerId(),node_flags,node_groups) & RS_FILE_HINTS_BROWSABLE))) @@ -1045,7 +1076,9 @@ void p3FileDatabase::handleDirSyncRequest(RsFileListsSyncRequestItem *item) if(item->last_known_recurs_modf_TS != local_recurs_max_time) // normally, should be "<", but since we provided the TS it should be equal, so != is more robust. { +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << " Directory is more recent than what the friend knows. Sending full dir content as response." << std::endl; +#endif ritem->flags = RsFileListsItem::FLAGS_SYNC_RESPONSE | RsFileListsItem::FLAGS_SYNC_DIR_CONTENT; ritem->last_known_recurs_modf_TS = local_recurs_max_time; @@ -1055,7 +1088,9 @@ void p3FileDatabase::handleDirSyncRequest(RsFileListsSyncRequestItem *item) } else { +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << " Directory is up to date w.r.t. what the friend knows. Sending ACK." << std::endl; +#endif ritem->flags = RsFileListsItem::FLAGS_SYNC_RESPONSE | RsFileListsItem::FLAGS_ENTRY_UP_TO_DATE ; ritem->last_known_recurs_modf_TS = local_recurs_max_time ; @@ -1074,7 +1109,9 @@ void p3FileDatabase::splitAndSendItem(RsFileListsSyncResponseItem *ritem) while(ritem->directory_content_data.bin_len > MAX_DIR_SYNC_RESPONSE_DATA_SIZE) { +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "Chopping off partial chunk of size " << MAX_DIR_SYNC_RESPONSE_DATA_SIZE << " from item data of size " << ritem->directory_content_data.bin_len << std::endl; +#endif ritem->flags |= RsFileListsItem::FLAGS_SYNC_PARTIAL ; @@ -1116,7 +1153,9 @@ RsFileListsSyncResponseItem *p3FileDatabase::recvAndRebuildItem(RsFileListsSyncR // item is a partial item. Look first for a starting entry +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "Item from peer " << ritem->PeerId() << " is partial. Size = " << ritem->directory_content_data.bin_len << std::endl; +#endif RS_STACK_MUTEX(mFLSMtx) ; @@ -1130,7 +1169,9 @@ RsFileListsSyncResponseItem *p3FileDatabase::recvAndRebuildItem(RsFileListsSyncR P3FILELISTS_ERROR() << "Impossible situation: partial item ended right away. Dropping..." << std::endl; return NULL; } +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "Creating new item buffer" << std::endl; +#endif mPartialResponseItems[ritem->request_id] = new RsFileListsSyncResponseItem(*ritem) ; return NULL ; @@ -1151,13 +1192,17 @@ RsFileListsSyncResponseItem *p3FileDatabase::recvAndRebuildItem(RsFileListsSyncR memcpy(&((unsigned char*)it->second->directory_content_data.bin_data)[old_len],ritem->directory_content_data.bin_data,added); it->second->directory_content_data.bin_len = old_len + added ; +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "Added new chunk of length " << added << ". New size is " << old_len + added << std::endl; +#endif // if finished, return the item if(is_ending) { +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "Item is complete. Returning it" << std::endl; +#endif RsFileListsSyncResponseItem *ret = it->second ; mPartialResponseItems.erase(it) ; @@ -1186,7 +1231,9 @@ void p3FileDatabase::handleDirSyncResponse(RsFileListsSyncResponseItem *sitem) return ; } +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "Handling sync response for directory with hash " << item->entry_hash << std::endl; +#endif EntryIndex entry_index = DirectoryStorage::NO_INDEX; @@ -1229,7 +1276,9 @@ void p3FileDatabase::handleDirSyncResponse(RsFileListsSyncResponseItem *sitem) P3FILELISTS_ERROR() << " (EE) cannot find index from hash " << item->entry_hash << ". Dropping the response." << std::endl; return ; } +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << " entry index is " << entry_index << " " ; +#endif } if(item->flags & RsFileListsItem::FLAGS_ENTRY_WAS_REMOVED) @@ -1272,7 +1321,9 @@ void p3FileDatabase::locked_recursSweepRemoteDirectory(RemoteDirectoryStorage *r // get the info for this entry +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << "currently at entry index " << e << std::endl; +#endif time_t local_update_TS; @@ -1286,7 +1337,11 @@ void p3FileDatabase::locked_recursSweepRemoteDirectory(RemoteDirectoryStorage *r if((e == 0 && now > local_update_TS + DELAY_BETWEEN_REMOTE_DIRECTORY_SYNC_REQ) || local_update_TS == 0) // we need to compare local times only. We cannot compare local (now) with remote time. if(generateAndSendSyncRequest(rds,e)) + { +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << " Asking for sync of directory " << e << " to peer " << rds->peerId() << " because it's " << (now - local_update_TS) << " secs old since last check." << std::endl; +#endif + } for(DirectoryStorage::DirIterator it(rds,e);it;++it) locked_recursSweepRemoteDirectory(rds,*it,depth+1); @@ -1342,7 +1397,9 @@ bool p3FileDatabase::generateAndSendSyncRequest(RemoteDirectoryStorage *rds,cons if(it != mPendingSyncRequests.end()) { +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << " Not asking for sync of directory " << e << " to friend " << rds->peerId() << " because a recent pending request still exists." << std::endl; +#endif return false ; } @@ -1360,7 +1417,9 @@ bool p3FileDatabase::generateAndSendSyncRequest(RemoteDirectoryStorage *rds,cons data.peer_id = item->PeerId(); data.flags = item->flags; +#ifdef DEBUG_P3FILELISTS P3FILELISTS_DEBUG() << " Pushing req in pending list with peer id " << data.peer_id << std::endl; +#endif mPendingSyncRequests[sync_req_id] = data ; diff --git a/libretroshare/src/file_sharing/p3filelists.h b/libretroshare/src/file_sharing/p3filelists.h index ec4e583ba..bd35a8015 100644 --- a/libretroshare/src/file_sharing/p3filelists.h +++ b/libretroshare/src/file_sharing/p3filelists.h @@ -139,9 +139,6 @@ class p3FileDatabase: public p3Service, public p3Config, public ftSearch //, pub void forceDirectoryCheck(); // Force re-sweep the directories and see what's changed bool inDirectoryCheck(); - // debug - void full_print(); - protected: int filterResults(const std::list& firesults,std::list& results,FileSearchFlags flags,const RsPeerId& peer_id) const;