HaikuDepot: Improved logging control

The application had previously no means to control the verbosity of
logging.  This excessive logging meant that it was bit hard to
understand what is going on.  Now it is possible to define the level
of logging that is output; especially as the application pulls-down
data from the remote server system.

src/apps/haikudepot/Jamfile

@@ -53,6 +53,7 @@ Application HaikuDepot :
 	JobStateListener.cpp
 	LinkView.cpp
 	LinkedBitmapView.cpp
+	Logger.cpp
 	main.cpp
 	MainWindow.cpp
 	MarkupTextView.cpp

src/apps/haikudepot/model/Logger.cpp

@@ -0,0 +1,62 @@
+/*
+ * Copyright 2017, Andrew Lindesay <[email protected]>.
+ * All rights reserved. Distributed under the terms of the MIT License.
+ */
+#include "Logger.h"
+
+
+log_level Logger::fLevel = LOG_LEVEL_INFO;
+
+
+log_level
+Logger::Level()
+{
+	return fLevel;
+}
+
+
+void
+Logger::SetLevel(log_level value)
+{
+	fLevel = value;
+}
+
+
+bool
+Logger::SetLevelByName(const char *name)
+{
+	if (strcmp(name, "off") == 0) {
+		fLevel = LOG_LEVEL_OFF;
+	} else if (strcmp(name, "info") == 0) {
+		fLevel = LOG_LEVEL_INFO;
+	} else if (strcmp(name, "debug") == 0) {
+		fLevel = LOG_LEVEL_DEBUG;
+	} else if (strcmp(name, "trace") == 0) {
+		fLevel = LOG_LEVEL_TRACE;
+	} else {
+		return false;
+	}
+
+	return true;
+}
+
+
+bool
+Logger::IsInfoEnabled()
+{
+	return fLevel >= LOG_LEVEL_INFO;
+}
+
+
+bool
+Logger::IsDebugEnabled()
+{
+	return fLevel >= LOG_LEVEL_DEBUG;
+}
+
+
+bool
+Logger::IsTraceEnabled()
+{
+	return fLevel >= LOG_LEVEL_TRACE;
+}

src/apps/haikudepot/model/Logger.h

@@ -0,0 +1,40 @@
+/*
+ * Copyright 2017, Andrew Lindesay <[email protected]>.
+ * All rights reserved. Distributed under the terms of the MIT License.
+ */
+
+
+#ifndef LOGGER_H
+#define LOGGER_H
+
+#include <String.h>
+#include <File.h>
+#include <Path.h>
+
+#include "PackageInfo.h"
+
+
+typedef enum log_level {
+	LOG_LEVEL_OFF		= 1,
+	LOG_LEVEL_INFO		= 2,
+	LOG_LEVEL_DEBUG		= 3,
+	LOG_LEVEL_TRACE		= 4
+} log_level;
+
+
+class Logger {
+public:
+	static	log_level			Level();
+	static	void				SetLevel(log_level value);
+	static	bool				SetLevelByName(const char *name);
+
+	static	bool				IsInfoEnabled();
+	static	bool				IsDebugEnabled();
+	static	bool				IsTraceEnabled();
+
+private:
+	static	log_level			fLevel;
+};
+
+
+#endif // LOGGER_H

src/apps/haikudepot/model/Model.cpp

@@ -6,8 +6,6 @@
  */
 
 #include "Model.h"
-#include "RepositoryDataUpdateProcess.h"
-#include "StorageUtils.h"
 
 #include <ctime>
 #include <stdarg.h>
@@ -24,6 +22,10 @@
 #include <Message.h>
 #include <Path.h>
 
+#include "Logger.h"
+#include "RepositoryDataUpdateProcess.h"
+#include "StorageUtils.h"
+
 
 #undef B_TRANSLATION_CONTEXT
 #define B_TRANSLATION_CONTEXT "Model"
@@ -930,10 +932,12 @@ Model::_PopulateAllPackagesIcons()
 			depotIndex++;
 		} else {
 			package = packages.ItemAt(packageIndex);
-#ifdef DEBUG
+
-			fprintf(stdout, "will populate package icon for [%s]\n",
+			if (Logger::IsDebugEnabled()) {
-				package->Name().String());
+				fprintf(stdout, "will populate package icon for [%s]\n",
-#endif
+					package->Name().String());
+			}
+
 			if (_PopulatePackageIcon(package) == B_OK)
 				countIconsSet++;
 
@@ -1162,10 +1166,19 @@ Model::_PopulatePackageInfos(PackageList& packages, bool fromCacheOnly)
 	}
 
 	if (packages.CountItems() > 0) {
+		uint32 count = 0;
+		bool debug_enabled = Logger::IsDebugEnabled();
+
 		for (int i = 0; i < packages.CountItems(); i++) {
 			const PackageInfoRef& package = packages.ItemAtFast(i);
-			printf("No package info for %s\n", package->Name().String());
+			count++;
+
+			if (debug_enabled) {
+				printf("No package info for %s\n", package->Name().String());
+			}
 		}
+
+		printf("No package info for %" B_PRIu32 " packages\n", count);
 	}
 }
 
@@ -1220,6 +1233,7 @@ append_word_list(BString& words, const char* word)
 void
 Model::_PopulatePackageInfo(const PackageInfoRef& package, const BMessage& data)
 {
+	bool debug_enabled = Logger::IsDebugEnabled();
 	BAutolock locker(&fLock);
 
 	BString foundInfo;
@@ -1238,22 +1252,30 @@ Model::_PopulatePackageInfo(const PackageInfoRef& package, const BMessage& data)
 			BString title;
 			if (version.FindString("title", &title) == B_OK) {
 				package->SetTitle(title);
-				append_word_list(foundInfo, "title");
+
+				if (debug_enabled)
+					append_word_list(foundInfo, "title");
 			}
 			BString summary;
 			if (version.FindString("summary", &summary) == B_OK) {
 				package->SetShortDescription(summary);
-				append_word_list(foundInfo, "summary");
+
+				if (debug_enabled)
+					append_word_list(foundInfo, "summary");
 			}
 			BString description;
 			if (version.FindString("description", &description) == B_OK) {
 				package->SetFullDescription(description);
-				append_word_list(foundInfo, "description");
+
+				if (debug_enabled)
+					append_word_list(foundInfo, "description");
 			}
 			double payloadLength;
 			if (version.FindDouble("payloadLength", &payloadLength) == B_OK) {
 				package->SetSize((int64)payloadLength);
-				append_word_list(foundInfo, "size");
+
+				if (debug_enabled)
+					append_word_list(foundInfo, "size");
 			}
 			break;
 		}
@@ -1280,7 +1302,7 @@ Model::_PopulatePackageInfo(const PackageInfoRef& package, const BMessage& data)
 				}
 			}
 		}
-		if (foundCategory)
+		if (debug_enabled && foundCategory)
 			append_word_list(foundInfo, "categories");
 	}
 
@@ -1290,21 +1312,24 @@ Model::_PopulatePackageInfo(const PackageInfoRef& package, const BMessage& data)
 		summary.averageRating = derivedRating;
 		package->SetRatingSummary(summary);
 
-		append_word_list(foundInfo, "rating");
+		if (debug_enabled)
+			append_word_list(foundInfo, "rating");
 	}
 
 	double prominenceOrdering;
 	if (data.FindDouble("prominenceOrdering", &prominenceOrdering) == B_OK) {
 		package->SetProminence(prominenceOrdering);
 
-		append_word_list(foundInfo, "prominence");
+		if (debug_enabled)
+			append_word_list(foundInfo, "prominence");
 	}
 
 	BString changelog;
 	if (data.FindString("pkgChangelogContent", &changelog) == B_OK) {
 		package->SetChangelog(changelog);
 
-		append_word_list(foundInfo, "changelog");
+		if (debug_enabled)
+			append_word_list(foundInfo, "changelog");
 	}
 
 	BMessage screenshots;
@@ -1333,11 +1358,11 @@ Model::_PopulatePackageInfo(const PackageInfoRef& package, const BMessage& data)
 				foundScreenshot = true;
 			}
 		}
-		if (foundScreenshot)
+		if (debug_enabled && foundScreenshot)
 			append_word_list(foundInfo, "screenshots");
 	}
 
-	if (foundInfo.Length() > 0) {
+	if (debug_enabled && foundInfo.Length() > 0) {
 		printf("Populated package info for %s: %s\n",
 			package->Name().String(), foundInfo.String());
 	}
@@ -1363,18 +1388,18 @@ Model::_PopulatePackageIcon(const PackageInfoRef& package)
 		BAutolock locker(&fLock);
 		package->SetIcon(bitmapRef);
 
-#ifdef DEBUG
+		if (Logger::IsDebugEnabled()) {
-		fprintf(stdout, "have set the package icon for [%s] from [%s]\n",
+			fprintf(stdout, "have set the package icon for [%s] from [%s]\n",
-			package->Name().String(), bestIconPath.Path());
+				package->Name().String(), bestIconPath.Path());
-#endif
+		}
 
 		return B_OK;
 	}
 
-#ifdef DEBUG
+	if (Logger::IsDebugEnabled()) {
-	fprintf(stdout, "did not set the package icon for [%s]; no data\n",
+		fprintf(stdout, "did not set the package icon for [%s]; no data\n",
-		package->Name().String());
+			package->Name().String());
-#endif
+	}
 
 	return B_FILE_NOT_FOUND;
 }

src/apps/haikudepot/model/PackageInfo.cpp

@@ -1098,3 +1098,10 @@ DepotInfo::SetWebAppRepositoryCode(const BString& code)
 {
 	fWebAppRepositoryCode = code;
 }
+
+
+void
+DepotInfo::SetWebAppRepositorySourceCode(const BString& code)
+{
+	fWebAppRepositorySourceCode = code;
+}

src/apps/haikudepot/model/PackageInfo.h

@@ -421,10 +421,16 @@ public:
 			const BString&		WebAppRepositoryCode() const
 									{ return fWebAppRepositoryCode; }
 
+			void				SetWebAppRepositorySourceCode(
+									const BString& code);
+			const BString&		WebAppRepositorySourceCode() const
+									{ return fWebAppRepositorySourceCode; }
+
 private:
 			BString				fName;
 			PackageList			fPackages;
 			BString				fWebAppRepositoryCode;
+			BString				fWebAppRepositorySourceCode;
 			BString				fBaseURL;
 };
 

src/apps/haikudepot/server/AbstractServerProcess.cpp

@@ -15,6 +15,7 @@
 
 #include <support/ZlibCompressionAlgorithm.h>
 
+#include "Logger.h"
 #include "ServerSettings.h"
 #include "StandardMetaDataJsonEventListener.h"
 #include "ToFileUrlProtocolListener.h"
@@ -180,7 +181,7 @@ AbstractServerProcess::DownloadToLocalFile(const BPath& targetFilePath,
 		targetFilePath.Path());
 
 	ToFileUrlProtocolListener listener(targetFilePath, LoggingName(),
-		ServerSettings::UrlConnectionTraceLoggingEnabled());
+		Logger::IsTraceEnabled());
 
 	BHttpHeaders headers;
 	ServerSettings::AugmentHeaders(headers);

src/apps/haikudepot/server/RepositoryDataUpdateProcess.cpp

@@ -125,11 +125,13 @@ DepotMatchingRepositoryListener::Handle(DumpExportRepository* repository)
 			DepotInfo modifiedDepotInfo(fDepotList->ItemAt(depotIndex));
 			modifiedDepotInfo.SetWebAppRepositoryCode(
 				BString(*(repository->Code())));
+			modifiedDepotInfo.SetWebAppRepositorySourceCode(
+				BString(*(repositorySource->Code())));
 			fDepotList->Replace(depotIndex, modifiedDepotInfo);
 
-			fprintf(stderr, "associated depot [%s] with haiku depot server"
+			printf("associated depot [%s] with haiku depot server"
-				" repository [%s]\n", modifiedDepotInfo.Name().String(),
+				" repository source [%s]\n", modifiedDepotInfo.Name().String(),
-				repository->Code()->String());
+				repositorySource->Code()->String());
 		}
 	}
 }
@@ -144,12 +146,12 @@ DepotMatchingRepositoryListener::Complete()
 		const DepotInfo& depot = fDepotList->ItemAt(i);
 
 		if (depot.WebAppRepositoryCode().Length() == 0) {
-			fprintf(stderr, "depot [%s]", depot.Name().String());
+			printf("depot [%s]", depot.Name().String());
 
 			if (depot.BaseURL().Length() > 0)
-				fprintf(stderr, " (%s)", depot.BaseURL().String());
+				printf(" (%s)", depot.BaseURL().String());
 
-			fprintf(stderr, " correlates with no repository in the haiku"
+			printf(" correlates with no repository in the haiku"
 				"depot server system\n");
 		}
 	}
@@ -173,7 +175,7 @@ RepositoryDataUpdateProcess::~RepositoryDataUpdateProcess()
 status_t
 RepositoryDataUpdateProcess::Run()
 {
-	fprintf(stdout, "will fetch repositories data\n");
+	printf("will fetch repositories data\n");
 
 		// TODO: add language ISO code to the path; just 'en' for now.
 	status_t result = DownloadToLocalFile(fLocalFilePath,
@@ -181,13 +183,13 @@ RepositoryDataUpdateProcess::Run()
 		0, 0);
 
 	if (result == B_OK) {
-		fprintf(stdout, "did fetch repositories data\n");
+		printf("did fetch repositories data\n");
 
 			// now load the data in and process it.
 
-		fprintf(stderr, "will process repository data and match to depots\n");
+		printf("will process repository data and match to depots\n");
 		result = PopulateDataToDepots();
-		fprintf(stderr, "did process repository data and match to depots\n");
+		printf("did process repository data and match to depots\n");
 	}
 
 	return result;

src/apps/haikudepot/server/ServerIconExportUpdateProcess.cpp

@@ -37,7 +37,7 @@ ServerIconExportUpdateProcess::Run()
 	BPath tarGzFilePath(tmpnam(NULL));
 	status_t result = B_OK;
 
-	fprintf(stdout, "will start fetching icons\n");
+	printf("will start fetching icons\n");
 
 	result = Download(tarGzFilePath);
 
@@ -45,7 +45,7 @@ ServerIconExportUpdateProcess::Run()
 		if (result != B_OK)
 			return result;
 
-		fprintf(stdout, "delete any existing stored data\n");
+		printf("delete any existing stored data\n");
 		StorageUtils::RemoveDirectoryContents(fLocalStorageDirectoryPath);
 
 		BFile *tarGzFile = new BFile(tarGzFilePath.Path(), O_RDONLY);
@@ -73,7 +73,7 @@ ServerIconExportUpdateProcess::Run()
 		delete tarGzFile;
 	}
 
-	fprintf(stdout, "did complete fetching icons\n");
+	printf("did complete fetching icons\n");
 
 	return result;
 }

src/apps/haikudepot/server/ServerSettings.cpp

@@ -21,7 +21,6 @@
 BUrl ServerSettings::sBaseUrl = BUrl(BASEURL_DEFAULT);
 BString ServerSettings::sUserAgent = BString();
 pthread_once_t ServerSettings::sUserAgentInitOnce = PTHREAD_ONCE_INIT;
-bool ServerSettings::sUrlConnectionTraceLogging = false;
 
 
 status_t
@@ -68,17 +67,6 @@ ServerSettings::_InitUserAgent()
 }
 
 
-void
-ServerSettings::EnableUrlConnectionTraceLogging() {
-	sUrlConnectionTraceLogging = true;
-}
-
-bool
-ServerSettings::UrlConnectionTraceLoggingEnabled() {
-	return sUrlConnectionTraceLogging;
-}
-
-
 const BString
 ServerSettings::_GetUserAgentVersionString()
 {

src/apps/haikudepot/server/ServerSettings.h

@@ -19,8 +19,6 @@ public:
 		static void						AugmentHeaders(BHttpHeaders& headers);
 		static BUrl						CreateFullUrl(
 											const BString urlPathComponents);
-		static void						EnableUrlConnectionTraceLogging();
-		static bool						UrlConnectionTraceLoggingEnabled();
 
 private:
 		static void						_InitUserAgent();
@@ -29,7 +27,6 @@ private:
 		static BUrl						sBaseUrl;
 		static BString					sUserAgent;
 		static pthread_once_t			sUserAgentInitOnce;
-		static bool						sUrlConnectionTraceLogging;
 };
 
 #endif // SERVER_SETTINGS_H

src/apps/haikudepot/server/WebAppInterface.cpp

@@ -24,6 +24,7 @@
 
 #include "AutoLocker.h"
 #include "List.h"
+#include "Logger.h"
 #include "PackageInfo.h"
 #include "ServerSettings.h"
 
@@ -522,8 +523,7 @@ WebAppInterface::RetrieveScreenshot(const BString& code,
 
 	bool isSecure = url.Protocol() == "https";
 
-	ProtocolListener listener(
+	ProtocolListener listener(Logger::IsTraceEnabled());
-		ServerSettings::UrlConnectionTraceLoggingEnabled());
 	listener.SetDownloadIO(stream);
 
 	BHttpHeaders headers;
@@ -626,14 +626,13 @@ status_t
 WebAppInterface::_SendJsonRequest(const char* domain, BString jsonString,
 	uint32 flags, BMessage& reply) const
 {
-	if (ServerSettings::UrlConnectionTraceLoggingEnabled())
+	if (Logger::IsTraceEnabled())
 		printf("_SendJsonRequest(%s)\n", jsonString.String());
 
 	BUrl url = ServerSettings::CreateFullUrl(BString("/__api/v1/") << domain);
 	bool isSecure = url.Protocol() == "https";
 
-	ProtocolListener listener(
+	ProtocolListener listener(Logger::IsTraceEnabled());
-		ServerSettings::UrlConnectionTraceLoggingEnabled());
 	BUrlContext context;
 
 	BHttpHeaders headers;
@@ -680,8 +679,7 @@ WebAppInterface::_SendJsonRequest(const char* domain, BString jsonString,
 		return B_ERROR;
 
 	status_t status = BJson::Parse(jsonString, reply);
-	if (ServerSettings::UrlConnectionTraceLoggingEnabled() &&
+	if (Logger::IsTraceEnabled() && status == B_BAD_DATA) {
-		status == B_BAD_DATA) {
 		printf("Parser choked on JSON:\n%s\n", jsonString.String());
 	}
 	return status;

src/apps/haikudepot/server/dumpexportrepository/DumpExportRepositoryJsonListener.cpp

@@ -767,7 +767,7 @@ AbstractMainDumpExportRepositoryJsonListener::~AbstractMainDumpExportRepositoryJ
 void
 AbstractMainDumpExportRepositoryJsonListener::HandleError(status_t status, int32 line, const char* message)
 {
-    fprintf(stderr, "an error has arisen processing json for 'DumpExportRepository'; %s", message);
+    printf("an error has arisen processing json for 'DumpExportRepository'; %s", message);
     fErrorStatus = status;
 }
 

src/apps/haikudepot/tar/TarArchiveService.cpp

@@ -4,7 +4,6 @@
  */
 
 #include "TarArchiveService.h"
-#include "StorageUtils.h"
 
 #include <stdio.h>
 
@@ -12,6 +11,9 @@
 #include <File.h>
 #include <StringList.h>
 
+#include "Logger.h"
+#include "StorageUtils.h"
+
 
 #define LENGTH_BLOCK 512
 
@@ -106,8 +108,10 @@ TarArchiveService::_UnpackItem(BDataIO& tarDataIo,
 	BString entryFileName = header.GetFileName();
 	uint32 entryLength = header.GetLength();
 
-	fprintf(stdout, "will unpack item [%s] length [%" B_PRIu32 "]b\n",
+	if (Logger::IsDebugEnabled()) {
-		entryFileName.String(), entryLength);
+		fprintf(stdout, "will unpack item [%s] length [%" B_PRIu32 "]b\n",
+			entryFileName.String(), entryLength);
+	}
 
 	// if the path ends in "/" then it is a directory and there's no need to
 	// unpack it although if there is a length, it will need to be skipped.

src/apps/haikudepot/ui/App.cpp

@@ -5,7 +5,6 @@
 
 
 #include "App.h"
-#include "ServerSettings.h"
 
 #include <stdio.h>
 
@@ -22,7 +21,9 @@
 #include "support.h"
 
 #include "FeaturedPackagesView.h"
+#include "Logger.h"
 #include "MainWindow.h"
+#include "ServerSettings.h"
 
 
 #undef B_TRANSLATION_CONTEXT
@@ -123,7 +124,7 @@ enum arg_switch {
 	NOT_SWITCH,
 	HELP_SWITCH,
 	WEB_APP_BASE_URL_SWITCH,
-	URL_CONNECTION_TRACE_LOGGING_SWITCH,
+	VERBOSITY_SWITCH,
 };
 
 
@@ -132,8 +133,12 @@ app_print_help()
 {
 	fprintf(stdout, "HaikuDepot ");
 	fprintf(stdout, "[-u|--webappbaseurl <web-app-base-url>] ");
-	fprintf(stdout, "[-h] ");
+	fprintf(stdout, "[-v|--verbosity [off|info|debug|trace] ");
-	fprintf(stdout, "[-t|--urlconnectiontracelogging]\n");
+	fprintf(stdout, "[-h|--help]\n\n");
+	fprintf(stdout, "'-h' : causes this help text to be printed out.\n");
+	fprintf(stdout, "'-v' : allows for the verbosity level to be set.\n");
+	fprintf(stdout, "'-u' : allows for the haiku depot server to be\n");
+	fprintf(stdout, "   configured.");
 }
 
 
@@ -151,8 +156,8 @@ app_resolve_switch(char *arg)
 			if (0 == strcmp(&arg[2], "help"))
 				return HELP_SWITCH;
 
-			if (0 == strcmp(&arg[2], "urlconnectiontracelogging"))
+			if (0 == strcmp(&arg[2], "verbosity"))
-				return URL_CONNECTION_TRACE_LOGGING_SWITCH;
+				return VERBOSITY_SWITCH;
 		} else {
 			if (arglen == 2) { // short form
 				switch (arg[1]) {
@@ -162,8 +167,8 @@ app_resolve_switch(char *arg)
 					case 'h':
 						return HELP_SWITCH;
 
-					case 't':
+					case 'v':
-						return URL_CONNECTION_TRACE_LOGGING_SWITCH;
+						return VERBOSITY_SWITCH;
 				}
 			}
 		}
@@ -179,10 +184,35 @@ void
 App::ArgvReceived(int32 argc, char* argv[])
 {
 	for (int i = 1; i < argc;) {
+
+			// check to make sure that if there is a value for the switch,
+			// that the value is in fact supplied.
+
+		switch (app_resolve_switch(argv[i])) {
+			case VERBOSITY_SWITCH:
+			case WEB_APP_BASE_URL_SWITCH:
+				if (i == argc-1) {
+					fprintf(stdout, "unexpected end of arguments; missing "
+						"value for switch [%s]\n", argv[i]);
+					Quit();
+					return;
+				}
+				break;
+
+			default:
+				break;
+		}
+
+			// now process each switch.
+
 		switch (app_resolve_switch(argv[i])) {
 
-			case URL_CONNECTION_TRACE_LOGGING_SWITCH:
+			case VERBOSITY_SWITCH:
-				ServerSettings::EnableUrlConnectionTraceLogging();
+				if (!Logger::SetLevelByName(argv[i+1])) {
+					fprintf(stdout, "unknown log level [%s]\n", argv[i + 1]);
+					Quit();
+				}
+				i++; // also move past the log level value
 				break;
 
 			case HELP_SWITCH:
@@ -191,12 +221,6 @@ App::ArgvReceived(int32 argc, char* argv[])
 				break;
 
 			case WEB_APP_BASE_URL_SWITCH:
-				if (i == argc-1) {
-					fprintf(stdout, "unexpected end of arguments; missing "
-						"web-app base url\n");
-					Quit();
-				}
-
 				if (ServerSettings::SetBaseUrl(BUrl(argv[i + 1])) != B_OK) {
 					fprintf(stdout, "malformed web app base url; %s\n",
 						argv[i + 1]);