Bug 1904429 - Introduce Logging interface and JS_LOG r=jandem

Differential Revision: https://phabricator.services.mozilla.com/D214747

js/public/experimental/LoggingInterface.h

@@ -0,0 +1,87 @@
+/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*-
+ * vim: set ts=8 sts=2 et sw=2 tw=80:
+ * This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
+
+// An experimental logging interface for connecting the JS Engine to some
+// (*cough*Gecko*cough*) consumer.
+
+#ifndef _js_experimental_LoggingInterface_h_
+#define _js_experimental_LoggingInterface_h_
+
+#include "mozilla/LoggingCore.h"
+
+#include "jstypes.h"
+#include "js/GCAPI.h"
+
+struct JSContext;
+
+namespace JS {
+
+// An Opaque pointer to a LoggerType. It must be possible for this logger type
+// to conform to the interface below, using the LogLevel type exported in
+// mozglue LoggingCore.h
+//
+// There are some requirements that we cannot express through the type-system:
+//
+// - A Logger must outlive any caller. This is an obvious statement, but in the
+//   context of the JS engine means that a logger must live until after the JS
+//   engine is shutdown.
+// - A logger cannot move. The logging interfaces assumes 1) That an
+//   OpaqueLogger will remain a valid handle to a logger for the entire duration
+//   of an initialize JS library, and 2) We are able to cache a reference to the
+//   log level of a particular logger (see getLevelRef below).
+using OpaqueLogger = void*;
+
+// [SMDOC] Logging Interface
+//
+// The logging interface contains a set of function pointers which explain how
+// to talk to an embedder provided logging system.
+//
+// The design of the JS Consumer of this relies heavily on these to be freely
+// copyable.
+struct LoggingInterface {
+  // Acquire a new logger for a given name.
+  //
+  // This interface has no way of indicating backwards that a logger is no
+  // longer needed, and as such this pointer needs to be kept alive by the
+  // embedding for the lifetime of the JS engine.
+  OpaqueLogger (*getLoggerByName)(const char* loggerName) = nullptr;
+
+  // Print a message to a particular logger with a particular level and
+  // format.
+  void (*logPrintVA)(const OpaqueLogger aModule, mozilla::LogLevel aLevel,
+                     const char* aFmt, va_list ap)
+      MOZ_FORMAT_PRINTF(3, 0) = nullptr;
+
+  // Return a reference to the provided OpaqueLogger's level ref; Implementation
+  // wise this can be a small violation of encapsulation but is intended to help
+  // ensure that we can build lightweight logging without egregious costs to
+  // simply check even if a mesage will the writen
+  mozilla::AtomicLogLevel& (*getLevelRef)(OpaqueLogger) = nullptr;
+
+  // Wrapper function for calling va-version
+  void logPrint(const OpaqueLogger aModule, mozilla::LogLevel aLevel,
+                const char* aFmt, ...) MOZ_FORMAT_PRINTF(4, 5) {
+    JS::AutoSuppressGCAnalysis suppress;
+    va_list ap;
+    va_start(ap, aFmt);
+    this->logPrintVA(aModule, aLevel, aFmt, ap);
+    va_end(ap);
+  }
+
+  // Used to ensure that before we use an interface, it's successfully been
+  // completely filled in.
+  bool isComplete() const {
+    return getLoggerByName && logPrintVA && getLevelRef;
+  }
+};
+
+// Install the logging interface. This will also install the interface into
+// any JS loggers
+extern JS_PUBLIC_API bool SetLoggingInterface(LoggingInterface& iface);
+
+}  // namespace JS
+
+#endif /* _js_experimental_LoggingInterface_h_ */

js/src/jsapi.cpp

@@ -91,6 +91,7 @@
 #include "vm/JSFunction.h"
 #include "vm/JSObject.h"
 #include "vm/JSScript.h"
+#include "vm/Logging.h"
 #include "vm/PlainObject.h"    // js::PlainObject
 #include "vm/PromiseObject.h"  // js::PromiseObject
 #include "vm/Runtime.h"
@@ -4922,6 +4923,10 @@ JS_PUBLIC_API void JS::SetShadowRealmGlobalCreationCallback(
   cx->runtime()->shadowRealmGlobalCreationCallback = callback;
 }
 
+JS_PUBLIC_API bool JS::SetLoggingInterface(LoggingInterface& iface) {
+  return js::LogModule::initializeAll(iface);
+}
+
 JS::FirstSubsumedFrame::FirstSubsumedFrame(
     JSContext* cx, bool ignoreSelfHostedFrames /* = true */)
     : JS::FirstSubsumedFrame(cx, cx->realm()->principals(),

js/src/moz.build

@@ -250,6 +250,7 @@ EXPORTS.js.experimental += [
     "../public/experimental/Intl.h",
     "../public/experimental/JitInfo.h",
     "../public/experimental/JSStencil.h",
+    "../public/experimental/LoggingInterface.h",
     "../public/experimental/PCCountProfiling.h",
     "../public/experimental/SourceHook.h",
     "../public/experimental/TypedData.h",
@@ -394,6 +395,7 @@ UNIFIED_SOURCES += [
     "vm/JSONPrinter.cpp",
     "vm/JSScript.cpp",
     "vm/List.cpp",
+    "vm/Logging.cpp",
     "vm/MemoryMetrics.cpp",
     "vm/Modules.cpp",
     "vm/NativeObject.cpp",

js/src/shell/js.cpp

@@ -27,6 +27,7 @@
 #include "mozilla/Variant.h"
 
 #include <algorithm>
+#include <cctype>
 #include <chrono>
 #ifdef XP_WIN
 #  include <direct.h>
@@ -193,6 +194,7 @@
 #include "vm/JSFunction.h"
 #include "vm/JSObject.h"
 #include "vm/JSScript.h"
+#include "vm/Logging.h"
 #include "vm/ModuleBuilder.h"  // js::ModuleBuilder
 #include "vm/Modules.h"
 #include "vm/Monitor.h"
@@ -334,6 +336,114 @@ enum JSShellExitCode {
   EXITCODE_TIMEOUT = 6
 };
 
+struct ShellLogModule {
+  // Since ShellLogModules have references to their levels created
+  // we can't move them.
+  ShellLogModule(ShellLogModule&&) = delete;
+
+  const char* name;
+  explicit ShellLogModule(const char* name) : name(name) {}
+  mozilla::AtomicLogLevel level;
+};
+
+// If asserts related to this ever fail, simply bump this number.
+//
+// This is used to construct a mozilla::Array, which is used because a
+// ShellLogModule cannot move once constructed to avoid invalidating
+// a levelRef.
+static const int MAX_LOG_MODULES = 64;
+static int initialized_modules = 0;
+mozilla::Array<mozilla::Maybe<ShellLogModule>, MAX_LOG_MODULES> logModules;
+
+JS::OpaqueLogger GetLoggerByName(const char* name) {
+  // Check for pre-existing module
+  for (auto& logger : logModules) {
+    if (logger) {
+      if (logger->name == name) {
+        return logger.ptr();
+      }
+    }
+    // We've seen all initialized, not there, break out.
+    if (!logger) break;
+  }
+
+  // Not found, allocate a new module.
+  MOZ_RELEASE_ASSERT(initialized_modules < MAX_LOG_MODULES - 1);
+  auto index = initialized_modules++;
+  logModules[index].emplace(name);
+  return logModules[index].ptr();
+}
+
+mozilla::AtomicLogLevel& GetLevelRef(JS::OpaqueLogger logger) {
+  ShellLogModule* slm = static_cast<ShellLogModule*>(logger);
+  return slm->level;
+}
+
+void LogPrintVA(const JS::OpaqueLogger logger, mozilla::LogLevel level,
+                const char* fmt, va_list ap) {
+  ShellLogModule* mod = static_cast<ShellLogModule*>(logger);
+  fprintf(stderr, "[%s] ", mod->name);
+  vfprintf(stderr, fmt, ap);
+  fprintf(stderr, "\n");
+}
+
+JS::LoggingInterface shellLoggingInterface = {GetLoggerByName, LogPrintVA,
+                                              GetLevelRef};
+
+static void ToLower(const char* src, char* dest, size_t len) {
+  for (size_t c = 0; c < len; c++) {
+    dest[c] = (char)(tolower(src[c]));
+  }
+}
+
+// Run this after initialiation!
+void ParseLoggerOptions() {
+  char* mixedCaseOpts = getenv("MOZ_LOG");
+  if (!mixedCaseOpts) {
+    return;
+  }
+
+  // Copy into a new buffer and lower case to do case insensitive matching.
+  //
+  // Done this way rather than just using strcasestr because Windows doesn't
+  // have strcasestr as part of its base C library.
+  size_t len = strlen(mixedCaseOpts);
+  mozilla::UniqueFreePtr<char[]> logOpts(static_cast<char*>(calloc(len, 1)));
+  if (!logOpts) {
+    return;
+  }
+
+  ToLower(mixedCaseOpts, logOpts.get(), len);
+
+  // This is a really permissive parser, but will suffice!
+  for (auto& logger : logModules) {
+    if (logger) {
+      // Lowercase the logger name for strstr
+      size_t len = strlen(logger->name);
+      mozilla::UniqueFreePtr<char[]> lowerName(
+          static_cast<char*>(calloc(len, 1)));
+      ToLower(logger->name, lowerName.get(), len);
+
+      if (char* needle = strstr(logOpts.get(), lowerName.get())) {
+        // If the string to enable a logger is present, but no level is provided
+        // then default to Debug level.
+        int logLevel = static_cast<int>(mozilla::LogLevel::Debug);
+
+        if (char* colon = strchr(needle, ':')) {
+          // Parse character after colon as log level.
+          if (*(colon + 1)) {
+            logLevel = atoi(colon + 1);
+          }
+        }
+
+        fprintf(stderr, "[JS_LOG] Enabling Logger %s at level %d\n",
+                logger->name, logLevel);
+        logger->level = mozilla::ToLogLevel(logLevel);
+      }
+    }
+  }
+}
+
 /*
  * Limit the timeout to 30 minutes to prevent an overflow on platfoms
  * that represent the time internally in microseconds using 32-bit int.
@@ -11978,6 +12088,11 @@ int main(int argc, char** argv) {
     return 1;
   }
 
+  if (!JS::SetLoggingInterface(shellLoggingInterface)) {
+    return 1;
+  }
+  ParseLoggerOptions();
+
   // Register telemetry callbacks, if needed.
   if (telemetryLock) {
     JS_SetAccumulateTelemetryCallback(cx, AccumulateTelemetryDataCallback);

js/src/vm/Logging.cpp

@@ -0,0 +1,19 @@
+/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*-
+ * vim: set ts=8 sts=2 et sw=2 tw=80:
+ * This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
+
+#include "vm/Logging.h"
+
+// Initialize all LogModules to speak with the provided interface.
+/* static */ bool js::LogModule::initializeAll(
+    const JS::LoggingInterface iface) {
+#define INITIALIZE_MODULE(X) X##Module.initialize(iface);
+
+  FOR_EACH_JS_LOG_MODULE(INITIALIZE_MODULE)
+
+#undef INITIALIZE_MODULE
+
+  return true;
+}

js/src/vm/Logging.h

@@ -0,0 +1,109 @@
+/* -*- Mode: C++; tab-width: 8; indent-tabs-mode: nil; c-basic-offset: 2 -*-
+ * vim: set ts=8 sts=2 et sw=2 tw=80:
+ * This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
+
+// An experimental logging interface for connecting the JS Engine to some
+// (*cough*Gecko*cough*) consumer.
+
+#ifndef _js_vm_Logging_h_
+#define _js_vm_Logging_h_
+
+#include "mozilla/Assertions.h"
+
+#include "js/experimental/LoggingInterface.h"
+
+struct JSContext;
+
+namespace js {
+
+// [SMDOC] js::LogModule
+//
+// js::LogModule is the underlying type used for JS_LOG.
+//
+// To support declaring these statically, while simultaneously supporting the
+// initialization of the interfaces via a callback, each instance of LogModule
+// is registered in a module register (logModuleRegistry), which updates
+// the module interface for each log module.
+//
+// Log modules are declared below using a Macro to support the metaprogramming
+// required around their storage an initialization.
+class LogModule {
+ public:
+  explicit constexpr LogModule(const char* name) : name(name) {
+    MOZ_ASSERT(name);
+  }
+
+  // Return true iff we should log a message at this level.
+  inline bool shouldLog(mozilla::LogLevel level) const {
+    if (!isSetup()) {
+      return false;
+    }
+
+    return *levelPtr >= level;
+  }
+
+  // Initialize all LogModules to speak with the provided interface.
+  [[nodiscard]] static bool initializeAll(const JS::LoggingInterface iface);
+
+ public:
+  // Public as it's used by the macro below, and we don't need a
+  // forwarding interface.
+  mutable JS::LoggingInterface interface{};
+
+  // Opaque logger obtained via the interface; also public for macro useage.
+  mutable JS::OpaqueLogger logger{};
+
+  // Name of this logger
+  const char* name{};
+
+ private:
+  // Is this logger ready to be used.
+  inline bool isSetup() const { return interface.isComplete() && logger; }
+
+  // Initialize this Log module
+  bool initialize(const JS::LoggingInterface iface) const {
+    // Grab a local copy of the iface.
+    interface = iface;
+    MOZ_ASSERT(iface.isComplete());
+    logger = iface.getLoggerByName(name);
+    if (!logger) {
+      return false;
+    }
+
+    levelPtr = &iface.getLevelRef(logger);
+    return true;
+  }
+
+  // Used to fast-path check if we should log.
+  mutable mozilla::AtomicLogLevel* levelPtr{};
+};
+
+#define FOR_EACH_JS_LOG_MODULE(_) _(Test)
+
+// Declare Log modules
+#define DECLARE_MODULE(X) inline constexpr LogModule X##Module(#X);
+
+FOR_EACH_JS_LOG_MODULE(DECLARE_MODULE);
+
+#undef DECLARE_MODULE
+
+// The core logging macro for the JS Engine.
+// For now put this under JS_JITSPEW, but longer term this should be enabled
+// on release and so have its own flag.
+#ifdef JS_JITSPEW
+#  define JS_LOG(name, log_level, ...)                                  \
+    do {                                                                \
+      if (name##Module.shouldLog(log_level)) {                          \
+        name##Module.interface.logPrint(name##Module.logger, log_level, \
+                                        __VA_ARGS__);                   \
+      }                                                                 \
+    } while (0);
+#else
+#  define JS_LOG(module, log_level, ...)
+#endif
+
+}  // namespace js
+
+#endif /* _js_vm_Logging_h_ */

js/src/vm/Runtime.h

@@ -52,6 +52,7 @@
 #include "vm/GeckoProfiler.h"
 #include "vm/InvalidatingFuse.h"
 #include "vm/JSScript.h"
+#include "vm/Logging.h"
 #include "vm/OffThreadPromiseRuntimeState.h"  // js::OffThreadPromiseRuntimeState
 #include "vm/SharedScriptDataTableHolder.h"   // js::SharedScriptDataTableHolder
 #include "vm/Stack.h"