Use VLOG instead of vfprintf in PLUGIN_PRINTF.

The trusted plugin refactor will move code from ppapi/native_client to
components/nacl/renderer.

For consistency with the rest of Chrome, the refactored code will use VLOG
intead of PLUGIN_PRINTF. However, moving log statements over piecemeal will
make debugging difficult as multiple logfiles would need to be consulted
when debugging.

Instead, this changes the internals of PLUGIN_PRINTF to call VLOG instead of
vfprintf for logging. Any users who wish to see these debug statements must
then pass one of the following additional flags to Chrome:
  "--v=1" or
  "--vmodule=components/nacl/renderer*=1"
in addition to setting NACL_PLUGIN_DEBUG.

This change removes any effects of the environment variable "NACL_PLUGIN_LOG".
Once this change is submitted, I'll update any NaCl debugging documentation as
appropriate.

Note that this change may introduce allocations on the logging path. I think it
should be unlikely that PLUGIN_PRINTF will receive inputs larger than 512
characters, but truncating the output is worse than heap allocations.

BUG=239656

Review URL: https://codereview.chromium.org/224933006

git-svn-id: svn://svn.chromium.org/chrome/trunk/src@262150 0039d316-1c4b-4281-b951-d872f2087c98

4 files changed, 45 insertions, 48 deletions

diff --git a/ppapi/native_client/src/trusted/plugin/plugin.cc b/ppapi/native_client/src/trusted/plugin/plugin.cc
index 5c5f347..fe01eba 100644
--- a/ppapi/native_client/src/trusted/plugin/plugin.cc
+++ b/ppapi/native_client/src/trusted/plugin/plugin.cc
@@ -84,13 +84,6 @@ const int64_t kSizeKBMin = 1;
 const int64_t kSizeKBMax = 512*1024;     // very large .nexe
 const uint32_t kSizeKBBuckets = 100;
 
-const PPB_NaCl_Private* GetNaClInterface() {
-  pp::Module *module = pp::Module::Get();
-  CHECK(module);
-  return static_cast<const PPB_NaCl_Private*>(
-      module->GetBrowserInterface(PPB_NACL_PRIVATE_INTERFACE));
-}
-
 }  // namespace
 
 bool Plugin::EarlyInit(int argc, const char* argn[], const char* argv[]) {
diff --git a/ppapi/native_client/src/trusted/plugin/utility.cc b/ppapi/native_client/src/trusted/plugin/utility.cc
index d800424..b1984ea 100644
--- a/ppapi/native_client/src/trusted/plugin/utility.cc
+++ b/ppapi/native_client/src/trusted/plugin/utility.cc
@@ -10,57 +10,39 @@
 
 #include "native_client/src/include/portability_io.h"
 #include "native_client/src/include/portability_process.h"
+#include "native_client/src/shared/platform/nacl_check.h"
+#include "ppapi/cpp/module.h"
 #include "ppapi/native_client/src/trusted/plugin/utility.h"
 
 namespace plugin {
 
 int gNaClPluginDebugPrintEnabled = -1;
-FILE* gNaClPluginLogFile = NULL;
 
 /*
  * Prints formatted message to the log.
  */
 int NaClPluginPrintLog(const char *format, ...) {
-  if (NULL == gNaClPluginLogFile) {
-    return 0;
-  }
   va_list arg;
-  int done;
+  int out_size;
+
+  static const int kStackBufferSize = 512;
+  char stack_buffer[kStackBufferSize];
   va_start(arg, format);
-  done = vfprintf(gNaClPluginLogFile, format, arg);
+  out_size = vsnprintf(stack_buffer, kStackBufferSize, format, arg);
   va_end(arg);
-  fflush(gNaClPluginLogFile);
-  return done;
-}
-
-/*
- * Opens file where plugin log should be written. The file name is
- * taken from NACL_PLUGIN_LOG environment variable and process pid.
- * If environment variable doesn't exist or file can't be opened,
- * the function returns stdout.
- */
-FILE* NaClPluginLogFileEnv() {
-  char* file = getenv("NACL_PLUGIN_LOG");
-  if (NULL != file) {
-    int pid = GETPID();
-    /*
-     * 11 characters for pid, 5 for a glue string and 1 for null terminator.
-     */
-    size_t filename_length = strlen(file) + 32;
-    char* filename = new char[filename_length];
-    int ret = SNPRINTF(filename, filename_length, "%s.%d.log", file, pid);
-    if (ret <= 0 || static_cast<size_t>(ret) >= filename_length) {
-      delete[] filename;
-      return stdout;
-    }
-    FILE* log_file = fopen(filename, "w+");
-    delete[] filename;
-    if (NULL == log_file) {
-        return stdout;
-    }
-    return log_file;
+  if (out_size < kStackBufferSize) {
+    GetNaClInterface()->Vlog(stack_buffer);
+  } else {
+    // Message too large for our stack buffer; we have to allocate memory
+    // instead.
+    char *buffer = static_cast<char*>(malloc(out_size + 1));
+    va_start(arg, format);
+    vsnprintf(buffer, out_size + 1, format, arg);
+    va_end(arg);
+    GetNaClInterface()->Vlog(buffer);
+    free(buffer);
   }
-  return stdout;
+  return out_size;
 }
 
 /*
@@ -114,4 +96,20 @@ bool IsValidIdentifierString(const char* strval, uint32_t* length) {
   return true;
 }
 
+// We cache the NaCl interface pointer and ensure that its set early on, on the
+// main thread. This allows GetNaClInterface() to be used from non-main threads.
+static const PPB_NaCl_Private* g_nacl_interface = NULL;
+
+const PPB_NaCl_Private* GetNaClInterface() {
+  if (g_nacl_interface)
+    return g_nacl_interface;
+
+  pp::Module *module = pp::Module::Get();
+  CHECK(module);
+  CHECK(module->core()->IsMainThread());
+  g_nacl_interface = static_cast<const PPB_NaCl_Private*>(
+      module->GetBrowserInterface(PPB_NACL_PRIVATE_INTERFACE));
+  return g_nacl_interface;
+}
+
 }  // namespace plugin
diff --git a/ppapi/native_client/src/trusted/plugin/utility.h b/ppapi/native_client/src/trusted/plugin/utility.h
index 6b9b27e..758759c 100644
--- a/ppapi/native_client/src/trusted/plugin/utility.h
+++ b/ppapi/native_client/src/trusted/plugin/utility.h
@@ -13,6 +13,7 @@
 #include "native_client/src/include/portability.h"
 #include "native_client/src/shared/platform/nacl_threads.h"
 #include "native_client/src/shared/platform/nacl_time.h"
+#include "ppapi/c/private/ppb_nacl_private.h"
 
 #define SRPC_PLUGIN_DEBUG 1
 
@@ -26,18 +27,17 @@ namespace plugin {
 // TODO(sehr): add Unicode identifier support.
 bool IsValidIdentifierString(const char* strval, uint32_t* length);
 
+const PPB_NaCl_Private* GetNaClInterface();
+
 // Debugging print utility
 extern int gNaClPluginDebugPrintEnabled;
-extern FILE* gNaClPluginLogFile;
 extern int NaClPluginPrintLog(const char *format, ...);
 extern int NaClPluginDebugPrintCheckEnv();
-extern FILE* NaClPluginLogFileEnv();
 #if SRPC_PLUGIN_DEBUG
 #define INIT_PLUGIN_LOGGING() do {                                    \
     if (-1 == ::plugin::gNaClPluginDebugPrintEnabled) {               \
       ::plugin::gNaClPluginDebugPrintEnabled =                        \
           ::plugin::NaClPluginDebugPrintCheckEnv();                   \
-      ::plugin::gNaClPluginLogFile = ::plugin::NaClPluginLogFileEnv();\
     }                                                                 \
 } while (0)
 
diff --git a/ppapi/native_client/src/untrusted/pnacl_irt_shim/pnacl_shim.c b/ppapi/native_client/src/untrusted/pnacl_irt_shim/pnacl_shim.c
index 7f40daa..092cf53 100644
--- a/ppapi/native_client/src/untrusted/pnacl_irt_shim/pnacl_shim.c
+++ b/ppapi/native_client/src/untrusted/pnacl_irt_shim/pnacl_shim.c
@@ -3237,6 +3237,11 @@ static void Pnacl_M25_PPB_NaCl_Private_SetExitStatus(PP_Instance instance, int32
   iface->SetExitStatus(instance, exit_status);
 }
 
+static void Pnacl_M25_PPB_NaCl_Private_Vlog(const char* message) {
+  const struct PPB_NaCl_Private_1_0 *iface = Pnacl_WrapperInfo_PPB_NaCl_Private_1_0.real_iface;
+  iface->Vlog(message);
+}
+
 /* End wrapper methods for PPB_NaCl_Private_1_0 */
 
 /* Begin wrapper methods for PPB_NetAddress_Private_0_1 */
@@ -5140,7 +5145,8 @@ static const struct PPB_NaCl_Private_1_0 Pnacl_Wrappers_PPB_NaCl_Private_1_0 = {
     .SetIsInstalled = (void (*)(PP_Instance instance, PP_Bool is_installed))&Pnacl_M25_PPB_NaCl_Private_SetIsInstalled,
     .SetReadyTime = (void (*)(PP_Instance instance))&Pnacl_M25_PPB_NaCl_Private_SetReadyTime,
     .GetExitStatus = (int32_t (*)(PP_Instance instance))&Pnacl_M25_PPB_NaCl_Private_GetExitStatus,
-    .SetExitStatus = (void (*)(PP_Instance instance, int32_t exit_status))&Pnacl_M25_PPB_NaCl_Private_SetExitStatus
+    .SetExitStatus = (void (*)(PP_Instance instance, int32_t exit_status))&Pnacl_M25_PPB_NaCl_Private_SetExitStatus,
+    .Vlog = (void (*)(const char* message))&Pnacl_M25_PPB_NaCl_Private_Vlog
 };
 
 static const struct PPB_NetAddress_Private_0_1 Pnacl_Wrappers_PPB_NetAddress_Private_0_1 = {