remerged; commands JSON. logging upgrade. doxygen

2 files changed, 115 insertions, 21 deletions

diff --git a/contrib/otshell_utils/utils.cpp b/contrib/otshell_utils/utils.cpp
index ff39d15e8..3ca84da8e 100644
--- a/contrib/otshell_utils/utils.cpp
+++ b/contrib/otshell_utils/utils.cpp
@@ -40,6 +40,7 @@
 	#error "Compiler/OS platform detection failed - not supported"
 #endif
 
+
 namespace nOT {
 namespace nUtils {
 
@@ -246,6 +247,13 @@ bool cFilesystemUtils::CreateDirTree(const std::string & dir, bool only_below) {
 
 namespace nDetail {
 
+struct channel_use_info { ///< feedback information about using (e.g. opening) given debug channel - used internally by logging system 
+/// TODO not yet used in code
+/// e.g. used to write into channel net/in/all that given message was a first logged message from never-before-logged thread or PID etc
+	bool m_was_interesting; ///< anything interesting happened when using the channel?
+	std::vector<std::string> m_extra_msg; ///< any additional messages about this channel use
+};	
+
 cDebugScopeGuard::cDebugScopeGuard() : mLevel(-1) {
 }
 	
@@ -269,13 +277,18 @@ cLogger::cLogger() :
 mStream(NULL),
 mStreamBrokenDebug(NULL),
 mIsBroken(true), // before constructor finishes
-mLevel(85),
-mThread2Number_Biggest(0) // the CURRENT biggest value (no thread yet in map)
+mLevel(70),
+mThread2Number_Biggest(0), // the CURRENT biggest value (no thread yet in map)
+mPid2Number_Biggest(0)
 {
 	mStream = & std::cout;
-	mStreamBrokenDebug = & std::cerr;
-	Thread2Number( std::this_thread::get_id() ); // convert current id to short number, useful to reserve a number so that main thread is usually called 1
+	mStreamBrokenDebug = & std::cerr; // the backup stream
+	*mStreamBrokenDebug << "Creating the logger system" << endl;
 	mIsBroken=false; // ok, constr. succeeded, so string is not broken now
+
+	// this is here, because it could be using logging itself to log creation of first thread/PID etc
+	Thread2Number( std::this_thread::get_id() ); // convert current id to short number, useful to reserve a number so that main thread is usually called 1
+	Pid2Number( getpid() ); // add this proces ID as first one
 }
 
 cLogger::~cLogger() {
@@ -291,7 +304,9 @@ void cLogger::SetStreamBroken() {
 }
 
 void cLogger::SetStreamBroken(const std::string &msg) {
+	_dbg_dbg("Stream is broken (msg: " << msg << ")");
 	if (!mIsBroken) { // if not already marked as broken
+		_dbg_dbg("(It was not broken before)");
 		std::cerr << OT_CODE_STAMP << "WARNING: due to debug stream problem ("<<msg<<") - switching back to fallback stream (e.g. cerr)" << std::endl;
 		if (mStreamBrokenDebug == nullptr) {
 			std::cerr << OT_CODE_STAMP << " ERROR: in addition, while reporting this problem, mStreamBrokenDebug stream is NULL." << std::endl;
@@ -307,13 +322,24 @@ std::ostream & cLogger::write_stream(int level) {
 }
 
 std::ostream & cLogger::write_stream(int level, const std::string & channel ) {
-	if ((level >= mLevel) && (mStream)) { // TODO now disabling mStream also disables writting to any channel
-		ostream & output = SelectOutput(level,channel);
-		output << icon(level) << ' ';
-		std::thread::id this_id = std::this_thread::get_id();
-		output << "{" << Thread2Number(this_id) << "} ";
-		return output;
-	}
+	_dbg_dbg("level="<<level<<" channel="<<channel);
+	if (level >= mLevel) {
+		if (mStream) { // TODO now disabling mStream also disables writting to any channel
+			_dbg_dbg("Selecting output...");
+			ostream & output = SelectOutput(level,channel);
+			_dbg_dbg("Selecting output... done, output=" << (void*)(&output));
+			#if defined(OS_TYPE_WINDOWS)
+			output << windows_stream(level);
+			#endif
+			output << icon(level) << ' ';
+			std::thread::id this_id = std::this_thread::get_id();
+			output << "{" << Thread2Number(this_id) << "}";
+			auto nicePid = Pid2Number(getpid());
+			if (nicePid>0) output << " {p" << nicePid << "}";
+			output << ' ';
+			return output; // <--- return
+		} else _dbg_dbg("Not writting: No mStream");
+	} else _dbg_dbg("Not writting: Too low level level="<<level<<" not >= mLevel="<<mLevel);
 	return g_nullstream;
 }
 
@@ -323,7 +349,7 @@ std::string cLogger::GetLogBaseDir() const {
 
 void cLogger::OpenNewChannel(const std::string & channel) noexcept {
 	try {
-		std::cerr<<"openning channel for channel="<<channel<<endl;
+		_dbg_dbg("Openning channel for channel="<<channel);
 		OpenNewChannel_(channel);
 	}
 	catch (const std::exception &except) {
@@ -335,6 +361,7 @@ void cLogger::OpenNewChannel(const std::string & channel) noexcept {
 }
 
 void cLogger::OpenNewChannel_(const std::string & channel) { // channel=="net/sleep"
+	_dbg_dbg("Openning channel for channel="<<channel);
 	size_t last_split = channel.find_last_of(cFilesystemUtils::GetDirSeparatorInter());
 
 	string fname_system; // the full file name in system format
@@ -356,19 +383,28 @@ void cLogger::OpenNewChannel_(const std::string & channel) { // channel=="net/sl
 		if (!dirok) { string err = "In logger failed to open directory (" + dir +") for channel (" + channel +")"; throw std::runtime_error(err); }
 	}
 
+	_dbg_dbg("Openning fname_system="<<fname_system);
 	std::ofstream * thefile = new std::ofstream( fname_system.c_str() ); // file system
 	*thefile << "====== Log opened: " << fname_system << " (in " << ((void*)thefile) << ") ======" << endl;
     	cerr << "====== Log opened: " << fname_system << " (in " << ((void*)thefile) << ") ======" << endl;
+  	_dbg_dbg( "====== Log opened: " << fname_system << " (in " << ((void*)thefile) << ") ======" );
 	mChannels.insert( std::pair<string,std::ofstream*>(channel , thefile ) ); // <- created the channel mapping
 }
 
 std::ostream & cLogger::SelectOutput(int level, const std::string & channel) noexcept {
 	try {
-		if (mIsBroken) return *mStreamBrokenDebug;
-		if (channel=="") return *mStream;
+		if (mIsBroken) { 
+			_dbg_dbg("The stream is broken mIsBroken="<<mIsBroken<<" so will return backup stream");
+			return *mStreamBrokenDebug;
+		}
+		if (channel=="") { 
+			_dbg_dbg("No channel given (channel="<<channel<<") so will return main stream");
+			return *mStream;
+		}
 
 		auto obj = mChannels.find(channel);
 		if (obj == mChannels.end()) { // not found - need to make new channel
+			_dbg_dbg("No stream openened for channel="<<channel<<" so will create it now");
 			OpenNewChannel(channel); // <- create channel
 			obj = mChannels.find(channel); // find again
 			if (obj == mChannels.end()) { // still not found! something is wrong
@@ -377,15 +413,18 @@ std::ostream & cLogger::SelectOutput(int level, const std::string & channel) noe
 			}
 		}
 		auto the_stream_ptr = obj->second;
+		_dbg_dbg("Found the stream file for channel="<<channel<<" as the_stream_ptr="<<the_stream_ptr);
 		ASRT(the_stream_ptr);
 		return *the_stream_ptr; // <--- RETURN
 	} 
 	catch (std::exception &except) { 
 		SetStreamBroken( OT_CODE_STAMP + " Got exception: " + ToStr(except.what()) );
+		_dbg_dbg("Exception! Returning broken stream");
 		return *mStreamBrokenDebug;
 	}
 	catch (...) {
 		SetStreamBroken( OT_CODE_STAMP + " Got not-standard exception.");
+		_dbg_dbg("Exception! Returning broken stream");
 		return *mStreamBrokenDebug;
 	}
 
@@ -428,22 +467,38 @@ std::string cLogger::icon(int level) const {
 	// TODO replan to avoid needles converting back and forth char*, string etc
 
 	using namespace zkr;
-
-	if (level >= 100) return cc::back::red     + ToStr(cc::fore::black) + ToStr("ERROR ") + ToStr(cc::fore::lightyellow) + " " ;
+    #if defined(OS_TYPE_POSIX)
+	if (level >= 100) return cc::back::lightred     + ToStr(cc::fore::lightyellow) + ToStr("ERROR ") + ToStr(cc::fore::lightyellow) + " " ;
 	if (level >=  90) return cc::back::lightyellow  + ToStr(cc::fore::black) + ToStr("Warn  ") + ToStr(cc::fore::red)+ " " ;
 	if (level >=  80) return cc::back::lightmagenta + ToStr(cc::fore::black) + ToStr("MARK  "); //+ zkr::cc::console + ToStr(cc::fore::lightmagenta)+ " ";
-	if (level >=  75) return cc::back::lightyellow + ToStr(cc::fore::black) + ToStr("FACT ") + zkr::cc::console + ToStr(cc::fore::lightyellow)+ " ";
+    if (level >=  75) return cc::back::lightyellow + ToStr(cc::fore::black) + ToStr("FACT  ") + zkr::cc::console + ToStr(cc::fore::lightyellow)+ " ";
 	if (level >=  70) return cc::fore::green    + ToStr("Note  ");
 	if (level >=  50) return cc::fore::cyan   + ToStr("info  ");
 	if (level >=  40) return cc::fore::lightwhite    + ToStr("dbg   ");
 	if (level >=  30) return cc::fore::lightblue   + ToStr("dbg   ");
 	if (level >=  20) return cc::fore::blue    + ToStr("dbg   ");
 
+    #elif defined(OS_TYPE_WINDOWS)
+    if (level >= 100) return ToStr("ERROR ");
+    if (level >=  90) return ToStr("Warn  ");
+    if (level >=  80) return ToStr("MARK  ");
+    if (level >=  75) return ToStr("FACT  ");
+    if (level >=  70) return ToStr("Note  ");
+    if (level >=  50) return ToStr("info  ");
+    if (level >=  40) return ToStr("dbg   ");
+    if (level >=  30) return ToStr("dbg   ");
+    if (level >=  20) return ToStr("dbg   ");
+    #endif
+
 	return "  ";
 }
 
 std::string cLogger::endline() const {
+	#if defined(OS_TYPE_POSIX)
 	return ToStr("") + zkr::cc::console + ToStr("\n"); // TODO replan to avoid needles converting back and forth char*, string etc
+    #elif defined(OS_TYPE_WINDOWS)
+    return ToStr("\n");
+    #endif
 }
 
 int cLogger::Thread2Number(const std::thread::id id) {
@@ -451,13 +506,24 @@ int cLogger::Thread2Number(const std::thread::id id) {
 	if (found == mThread2Number.end()) { // new one
 		mThread2Number_Biggest++;
 		mThread2Number[id] = mThread2Number_Biggest;
+		_mark_c("dbg/main", "This is a new thread (used in debug), thread id="<<id); // can cause some recursion
 		return mThread2Number_Biggest;
-	//	_info("(This is a new thread)"); // recursion!
 	} else {
 		return mThread2Number[id];
 	}
 }
 
+int cLogger::Pid2Number(const t_anypid id) {
+	auto found = mPid2Number.find( id );
+	if (found == mPid2Number.end()) { // new one
+		mPid2Number_Biggest++;
+		mPid2Number[id] = mPid2Number_Biggest;
+		_mark_c("dbg/main", "This is a new process (used in debug), process pid="<<id); // can cause some recursion
+		return mPid2Number_Biggest;
+	} else {
+		return mPid2Number[id];
+	}
+}
 
 // ====================================================================
 // object gCurrentLogger is defined later - in global namespace below
diff --git a/contrib/otshell_utils/utils.hpp b/contrib/otshell_utils/utils.hpp
index 35b464b42..6fb0fc5f5 100644
--- a/contrib/otshell_utils/utils.hpp
+++ b/contrib/otshell_utils/utils.hpp
@@ -13,6 +13,10 @@
 	#include <unistd.h>
 #endif
 
+#if defined(_WIN32)
+    #include"windows_stream.h"
+#endif
+
 #ifndef CFG_WITH_TERMCOLORS
 	//#error "You requested to turn off terminal colors (CFG_WITH_TERMCOLORS), however currently they are hardcoded (this option to turn them off is not yet implemented)."
 #endif
@@ -21,6 +25,16 @@
 #define MAKE_CLASS_NAME(NAME) private: static std::string GetObjectName() { return #NAME; }
 #define MAKE_STRUCT_NAME(NAME) private: static std::string GetObjectName() { return #NAME; } public:
 
+// define this to debug the debug system itself:
+// #define opt_debug_debug
+
+#ifdef opt_debug_debug
+	#define _dbg_dbg(X) do { std::cerr<<"_dbg_dbg: " << OT_CODE_STAMP << " {thread=" << std::this_thread::get_id()<<"} " \
+	<< " {pid="<<getpid()<<"} " <<  ": " << X << std::endl; } while(0)
+#else
+	#define _dbg_dbg(X) do { } while(0)
+#endif
+
 namespace nOT {
 
 namespace nUtils {
@@ -74,6 +88,7 @@ std::atomic<int> & gLoggerGuardDepth_Get(); // getter for the global singleton o
 // detect stream e.g. operator<< error
 
 #define _debug_level(LEVEL,VAR) do { if (_dbg_ignore< LEVEL) { \
+	_dbg_dbg("WRITE DEBUG: LEVEL="<<LEVEL<<" VAR: " << VAR ); \
 	auto level=LEVEL; short int part=0; \
 	try { \
 		std::lock_guard<std::recursive_mutex> mutex_guard( nOT::nUtils::gLoggerGuard ); \
@@ -93,6 +108,7 @@ std::atomic<int> & gLoggerGuardDepth_Get(); // getter for the global singleton o
 
 // info for code below: oss object is normal stack variable, using it does not need lock protection
 #define _debug_level_c(CHANNEL,LEVEL,VAR) do { if (_dbg_ignore< LEVEL) { \
+	_dbg_dbg("WRITE DEBUG: LEVEL="<<LEVEL<<" CHANNEL="<<CHANNEL<<" VAR: " << VAR ); \
 	auto level=LEVEL; short int part=0; \
 	try { \
 		std::lock_guard<std::recursive_mutex> mutex_guard( nOT::nUtils::gLoggerGuard ); \
@@ -102,9 +118,11 @@ std::atomic<int> & gLoggerGuardDepth_Get(); // getter for the global singleton o
 			std::ostringstream oss; \
 			oss << nOT::nUtils::get_current_time() << ' ' << OT_CODE_STAMP << ' ' << VAR << gCurrentLogger.endline() << std::flush; \
 			std::string as_string = oss.str(); \
+			_dbg_dbg("START will write to log LEVEL="<<LEVEL<<" to CHANNEL="<<CHANNEL<<" as_string="<<as_string); \
 /* int counter = nOT::nUtils::gLoggerGuardDepth_Get();  if (counter!=1) gCurrentLogger.write_stream(100,"")<<"DEBUG-ERROR: recursion, counter="<<counter<<gCurrentLogger.endline(); */ \
 			gCurrentLogger.write_stream(LEVEL,""     ) << as_string << gCurrentLogger.endline() << std::flush; \
 			gCurrentLogger.write_stream(LEVEL,CHANNEL) << as_string << gCurrentLogger.endline() << std::flush; \
+			_dbg_dbg("DONE will write to log LEVEL="<<LEVEL<<" to CHANNEL="<<CHANNEL<<" as_string="<<as_string); \
 			part=9; \
 		} catch(...) { \
 			gCurrentLogger.write_stream(std::max(level,90),CHANNEL) << nOT::nUtils::get_current_time() << ' ' << OT_CODE_STAMP << ' ' << "(ERROR IN DEBUG)" << gCurrentLogger.endline(); \
@@ -182,6 +200,10 @@ const char* DbgShortenCodeFileName(const char *s); ///< Returns a pointer to som
 
 // ========== logger ==========
 
+namespace nDetail {
+	struct channel_use_info;
+} // namespace nDetail
+
 /*** 
 @brief Class to write debug into. Used it by calling the debug macros _dbg1(...) _info(...) _erro(...) etc, NOT directly!
 @author rfree (maintainer) 
@@ -202,6 +224,8 @@ class cLogger {
 		std::string endline() const; ///< returns string to be written at end of message
 
 	protected:
+		typedef long int t_anypid; // a portable representation of PID. long int should cover all platforms
+
 		void SetStreamBroken(); ///< call in case of internal error in logger (e.g. can not open a file)
 		void SetStreamBroken(const std::string &msg); ///< same but with error message
 
@@ -219,9 +243,13 @@ class cLogger {
 		void OpenNewChannel_(const std::string & channel);  ///< internal function, will throw in case of problems
 		std::string GetLogBaseDir() const;
 
-		std::map< std::thread::id , int > mThread2Number; // change long thread IDs into a short nice number to show
-		int mThread2Number_Biggest; // current biggest value held there (biggest key) - works as growing-only counter basically
-		int Thread2Number(const std::thread::id id); // convert the system's thread id into a nice short our id; make one if new thread
+		std::map< std::thread::id , int > mThread2Number; ///<  change long thread IDs into a short nice number to show
+		int mThread2Number_Biggest; ///<  current biggest value held there (biggest key) - works as growing-only counter basically
+		int Thread2Number(const std::thread::id id); ///<  convert the system's thread id into a nice short our id; make one if new thread
+
+		std::map< t_anypid , int > mPid2Number; ///<  change long proces PID into a short nice number to show
+		int mPid2Number_Biggest; ///<  current biggest value held there (biggest key) - works as growing-only counter basically
+		int Pid2Number(const t_anypid id); ///<  convert the system's PID id into a nice short our id; make one if new thread
 };