Skip to content
This repository has been archived by the owner on Apr 3, 2020. It is now read-only.

Commit

Permalink
NaCl cleanup: Remove not-very-useful debug logging in the plugin code
Browse files Browse the repository at this point in the history
This removes all the PLUGIN_PRINTF/MODULE_PRINTF calls from
components/nacl/renderer/plugin/.

There aren't very many of these logging calls left now.  They don't
look useful to have in release binaries, and it's against Chromium
style to keep this sort of logging in the code.  Anyone doing
debugging can manually add their own logging.

My main motivation here is to remove a non-standard logging mechanism
that depends on some native_client/ headers.

BUG= https://bugs.chromium.org/p/nativeclient/issues/detail?id=2832
TEST=e.g. NaClBrowserTestPnacl.PPAPICore (tests PNaCl translation)

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

Cr-Commit-Position: refs/heads/master@{#371865}
  • Loading branch information
mseaborn authored and Commit bot committed Jan 27, 2016
1 parent 7d33571 commit 58c568b
Show file tree
Hide file tree
Showing 9 changed files with 1 addition and 159 deletions.
15 changes: 1 addition & 14 deletions components/nacl/renderer/plugin/module_ppapi.cc
Original file line number Diff line number Diff line change
Expand Up @@ -16,16 +16,12 @@ namespace plugin {
ModulePpapi::ModulePpapi() : pp::Module(),
init_was_successful_(false),
private_interface_(NULL) {
MODULE_PRINTF(("ModulePpapi::ModulePpapi (this=%p)\n",
static_cast<void*>(this)));
}

ModulePpapi::~ModulePpapi() {
if (init_was_successful_) {
NaClNrdAllModulesFini();
}
MODULE_PRINTF(("ModulePpapi::~ModulePpapi (this=%p)\n",
static_cast<void*>(this)));
}

bool ModulePpapi::Init() {
Expand All @@ -34,8 +30,6 @@ bool ModulePpapi::Init() {
GetBrowserInterface(PPB_NACL_PRIVATE_INTERFACE));

if (NULL == private_interface_) {
MODULE_PRINTF(("ModulePpapi::Init failed: "
"GetBrowserInterface returned NULL\n"));
return false;
}
SetNaClInterface(private_interface_);
Expand All @@ -57,13 +51,7 @@ bool ModulePpapi::Init() {
}

pp::Instance* ModulePpapi::CreateInstance(PP_Instance pp_instance) {
MODULE_PRINTF(("ModulePpapi::CreateInstance (pp_instance=%" NACL_PRId32
")\n",
pp_instance));
Plugin* plugin = new Plugin(pp_instance);
MODULE_PRINTF(("ModulePpapi::CreateInstance (return %p)\n",
static_cast<void* >(plugin)));
return plugin;
return new Plugin(pp_instance);
}

} // namespace plugin
Expand All @@ -72,7 +60,6 @@ pp::Instance* ModulePpapi::CreateInstance(PP_Instance pp_instance) {
namespace pp {

Module* CreateModule() {
MODULE_PRINTF(("CreateModule ()\n"));
return new plugin::ModulePpapi();
}

Expand Down
10 changes: 0 additions & 10 deletions components/nacl/renderer/plugin/plugin.cc
Original file line number Diff line number Diff line change
Expand Up @@ -28,15 +28,9 @@ void NoOpCallback(void* user_data, int32_t result) {
namespace plugin {

void Plugin::ShutDownSubprocesses() {
PLUGIN_PRINTF(("Plugin::ShutDownSubprocesses (this=%p)\n",
static_cast<void*>(this)));

// Shut down service runtime. This must be done before all other calls so
// they don't block forever when waiting for the upcall thread to exit.
main_subprocess_.Shutdown();

PLUGIN_PRINTF(("Plugin::ShutDownSubprocess (this=%p, return)\n",
static_cast<void*>(this)));
}

void Plugin::StartSelLdr(ServiceRuntime* service_runtime,
Expand Down Expand Up @@ -164,8 +158,6 @@ void Plugin::NexeFileDidOpen(int32_t pp_error) {
}

void Plugin::BitcodeDidTranslate(int32_t pp_error) {
PLUGIN_PRINTF(("Plugin::BitcodeDidTranslate (pp_error=%" NACL_PRId32 ")\n",
pp_error));
if (pp_error != PP_OK) {
// Error should have been reported by pnacl. Just return.
return;
Expand All @@ -185,8 +177,6 @@ void Plugin::BitcodeDidTranslate(int32_t pp_error) {
}

void Plugin::NaClManifestFileDidOpen(int32_t pp_error) {
PLUGIN_PRINTF(("Plugin::NaClManifestFileDidOpen (pp_error=%"
NACL_PRId32 ")\n", pp_error));
if (pp_error != PP_OK)
return;

Expand Down
17 changes: 0 additions & 17 deletions components/nacl/renderer/plugin/pnacl_coordinator.cc
Original file line number Diff line number Diff line change
Expand Up @@ -62,8 +62,6 @@ PnaclCoordinator* PnaclCoordinator::BitcodeToNative(
const std::string& pexe_url,
const PP_PNaClOptions& pnacl_options,
const pp::CompletionCallback& translate_notify_callback) {
PLUGIN_PRINTF(("PnaclCoordinator::BitcodeToNative (plugin=%p, pexe=%s)\n",
static_cast<void*>(plugin), pexe_url.c_str()));
PnaclCoordinator* coordinator =
new PnaclCoordinator(plugin, pexe_url,
pnacl_options,
Expand Down Expand Up @@ -107,9 +105,6 @@ PnaclCoordinator::PnaclCoordinator(
}

PnaclCoordinator::~PnaclCoordinator() {
PLUGIN_PRINTF(("PnaclCoordinator::~PnaclCoordinator (this=%p, "
"translate_thread=%p\n",
static_cast<void*>(this), translate_thread_.get()));
// Stopping the translate thread will cause the translate thread to try to
// run translation_complete_callback_ on the main thread. This destructor is
// running from the main thread, and by the time it exits, callback_factory_
Expand Down Expand Up @@ -143,7 +138,6 @@ void PnaclCoordinator::ReportNonPpapiError(PP_NaClError err_code,
}

void PnaclCoordinator::ExitWithError() {
PLUGIN_PRINTF(("PnaclCoordinator::ExitWithError\n"));
// Free all the intermediate callbacks we ever created.
// Note: this doesn't *cancel* the callbacks from the factories attached
// to the various helper classes (e.g., pnacl_resources). Thus, those
Expand All @@ -163,8 +157,6 @@ void PnaclCoordinator::ExitWithError() {

// Signal that Pnacl translation completed normally.
void PnaclCoordinator::TranslateFinished(int32_t pp_error) {
PLUGIN_PRINTF(("PnaclCoordinator::TranslateFinished (pp_error=%"
NACL_PRId32 ")\n", pp_error));
// Bail out if there was an earlier error (e.g., pexe load failure),
// or if there is an error from the translation thread.
if (translate_finish_error_ != PP_OK || pp_error != PP_OK) {
Expand Down Expand Up @@ -305,8 +297,6 @@ void PnaclCoordinator::BitcodeStreamGotData(const void* data, int32_t length) {
}

void PnaclCoordinator::BitcodeStreamDidFinish(int32_t pp_error) {
PLUGIN_PRINTF(("PnaclCoordinator::BitcodeStreamDidFinish (pp_error=%"
NACL_PRId32 ")\n", pp_error));
if (pp_error != PP_OK) {
// Defer reporting the error and cleanup until after the translation
// thread returns, because it may be accessing the coordinator's
Expand Down Expand Up @@ -370,7 +360,6 @@ pp::CompletionCallback PnaclCoordinator::GetCompileProgressCallback(
}

void PnaclCoordinator::LoadCompiler() {
PLUGIN_PRINTF(("PnaclCoordinator::LoadCompiler"));
base::TimeTicks compiler_load_start_time = base::TimeTicks::Now();
pp::CompletionCallback load_finished = callback_factory_.NewCallback(
&PnaclCoordinator::RunCompile, compiler_load_start_time);
Expand All @@ -386,8 +375,6 @@ void PnaclCoordinator::LoadCompiler() {

void PnaclCoordinator::RunCompile(int32_t pp_error,
base::TimeTicks compiler_load_start_time) {
PLUGIN_PRINTF(
("PnaclCoordinator::RunCompile (pp_error=%" NACL_PRId32 ")\n", pp_error));
if (pp_error != PP_OK) {
ReportNonPpapiError(
PP_NACL_ERROR_PNACL_LLC_SETUP,
Expand Down Expand Up @@ -419,8 +406,6 @@ void PnaclCoordinator::RunCompile(int32_t pp_error,
}

void PnaclCoordinator::LoadLinker(int32_t pp_error) {
PLUGIN_PRINTF(
("PnaclCoordinator::LoadLinker (pp_error=%" NACL_PRId32 ")\n", pp_error));
// Errors in the previous step would have skipped to TranslateFinished
// so we only expect PP_OK here.
DCHECK(pp_error == PP_OK);
Expand All @@ -439,8 +424,6 @@ void PnaclCoordinator::LoadLinker(int32_t pp_error) {

void PnaclCoordinator::RunLink(int32_t pp_error,
base::TimeTicks ld_load_start_time) {
PLUGIN_PRINTF(
("PnaclCoordinator::RunLink (pp_error=%" NACL_PRId32 ")\n", pp_error));
if (pp_error != PP_OK) {
ReportNonPpapiError(
PP_NACL_ERROR_PNACL_LD_SETUP,
Expand Down
2 changes: 0 additions & 2 deletions components/nacl/renderer/plugin/pnacl_resources.cc
Original file line number Diff line number Diff line change
Expand Up @@ -77,8 +77,6 @@ bool PnaclResources::ReadResourceInfo() {


bool PnaclResources::StartLoad() {
PLUGIN_PRINTF(("PnaclResources::StartLoad\n"));

// Do a blocking load of each of the resources.
std::vector<ResourceType> to_load;
if (use_subzero_) {
Expand Down
19 changes: 0 additions & 19 deletions components/nacl/renderer/plugin/pnacl_translate_thread.cc
Original file line number Diff line number Diff line change
Expand Up @@ -87,7 +87,6 @@ void PnaclTranslateThread::SetupState(
PP_PNaClOptions* pnacl_options,
const std::string& architecture_attributes,
PnaclCoordinator* coordinator) {
PLUGIN_PRINTF(("PnaclTranslateThread::SetupState)\n"));
compiler_subprocess_ = compiler_subprocess;
ld_subprocess_ = ld_subprocess;
obj_files_ = obj_files;
Expand All @@ -103,7 +102,6 @@ void PnaclTranslateThread::SetupState(

void PnaclTranslateThread::RunCompile(
const pp::CompletionCallback& compile_finished_callback) {
PLUGIN_PRINTF(("PnaclTranslateThread::RunCompile)\n"));
DCHECK(started());
DCHECK(compiler_subprocess_->service_runtime());
compiler_subprocess_active_ = true;
Expand All @@ -127,7 +125,6 @@ void PnaclTranslateThread::RunCompile(
}

void PnaclTranslateThread::RunLink() {
PLUGIN_PRINTF(("PnaclTranslateThread::RunLink)\n"));
DCHECK(started());
DCHECK(ld_subprocess_->service_runtime());
ld_subprocess_active_ = true;
Expand Down Expand Up @@ -212,8 +209,6 @@ void PnaclTranslateThread::DoCompile() {
compiler_channel_peer_pid_));
}

PLUGIN_PRINTF(("DoCompile using subzero: %d\n", pnacl_options_->use_subzero));

pp::Core* core = pp::Module::Get()->core();
base::TimeTicks do_compile_start_time = base::TimeTicks::Now();

Expand Down Expand Up @@ -245,23 +240,18 @@ void PnaclTranslateThread::DoCompile() {
std::string("Stream init failed: ") + error_str);
return;
}
PLUGIN_PRINTF(("PnaclCoordinator: StreamInit successful\n"));

// llc process is started.
while(!done_ || data_buffers_.size() > 0) {
cond_mu_.Acquire();
while(!done_ && data_buffers_.size() == 0) {
buffer_cond_.Wait();
}
PLUGIN_PRINTF(("PnaclTranslateThread awake (done=%d, size=%" NACL_PRIuS
")\n",
done_, data_buffers_.size()));
if (data_buffers_.size() > 0) {
std::string data;
data.swap(data_buffers_.front());
data_buffers_.pop_front();
cond_mu_.Release();
PLUGIN_PRINTF(("StreamChunk\n"));

if (!compiler_channel_filter_->Send(
new PpapiMsg_PnaclTranslatorCompileChunk(data, &success))) {
Expand All @@ -278,7 +268,6 @@ void PnaclTranslateThread::DoCompile() {
// console.
break;
}
PLUGIN_PRINTF(("StreamChunk Successful\n"));
core->CallOnMainThread(
0,
coordinator_->GetCompileProgressCallback(data.size()),
Expand All @@ -287,7 +276,6 @@ void PnaclTranslateThread::DoCompile() {
cond_mu_.Release();
}
}
PLUGIN_PRINTF(("PnaclTranslateThread done with chunks\n"));
// Finish llc.
if (!compiler_channel_filter_->Send(
new PpapiMsg_PnaclTranslatorCompileEnd(&success, &error_str))) {
Expand Down Expand Up @@ -373,8 +361,6 @@ void PnaclTranslateThread::DoLink() {
GetNaClInterface()->LogTranslateTime(
"NaCl.Perf.PNaClLoadTime.LinkTime",
(base::TimeTicks::Now() - link_start_time).InMicroseconds());
PLUGIN_PRINTF(("PnaclCoordinator: link (translator=%p) succeeded\n",
this));

// Shut down the ld subprocess.
{
Expand All @@ -390,8 +376,6 @@ void PnaclTranslateThread::DoLink() {
void PnaclTranslateThread::TranslateFailed(
PP_NaClError err_code,
const std::string& error_string) {
PLUGIN_PRINTF(("PnaclTranslateThread::TranslateFailed (error_string='%s')\n",
error_string.c_str()));
pp::Core* core = pp::Module::Get()->core();
if (coordinator_error_info_->message().empty()) {
// Only use our message if one hasn't already been set by the coordinator
Expand All @@ -404,7 +388,6 @@ void PnaclTranslateThread::TranslateFailed(
}

void PnaclTranslateThread::AbortSubprocesses() {
PLUGIN_PRINTF(("PnaclTranslateThread::AbortSubprocesses\n"));
{
base::AutoLock lock(subprocess_mu_);
if (compiler_subprocess_ != NULL && compiler_subprocess_active_) {
Expand All @@ -427,11 +410,9 @@ void PnaclTranslateThread::AbortSubprocesses() {
}

PnaclTranslateThread::~PnaclTranslateThread() {
PLUGIN_PRINTF(("~PnaclTranslateThread (translate_thread=%p)\n", this));
AbortSubprocesses();
if (translate_thread_)
translate_thread_->Join();
PLUGIN_PRINTF(("~PnaclTranslateThread joined\n"));
}

} // namespace plugin
52 changes: 0 additions & 52 deletions components/nacl/renderer/plugin/utility.cc
Original file line number Diff line number Diff line change
Expand Up @@ -4,63 +4,11 @@
* found in the LICENSE file.
*/

#include <stdarg.h>
#include <stdlib.h>
#include <string.h>

#include "components/nacl/renderer/plugin/utility.h"
#include "ppapi/cpp/module.h"

namespace plugin {

int gNaClPluginDebugPrintEnabled = -1;

/*
* Prints formatted message to the log.
*/
int NaClPluginPrintLog(const char *format, ...) {
va_list arg;
int out_size;

static const int kStackBufferSize = 512;
char stack_buffer[kStackBufferSize];

// Just log locally to stderr if we can't use the nacl interface.
if (!GetNaClInterface()) {
va_start(arg, format);
int rc = vfprintf(stderr, format, arg);
va_end(arg);
return rc;
}

va_start(arg, format);
out_size = vsnprintf(stack_buffer, kStackBufferSize, format, arg);
va_end(arg);
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 out_size;
}

/*
* Currently looks for presence of NACL_PLUGIN_DEBUG and returns
* 0 if absent and 1 if present. In the future we may include notions
* of verbosity level.
*/
int NaClPluginDebugPrintCheckEnv() {
char* env = getenv("NACL_PLUGIN_DEBUG");
return (NULL != env);
}

// 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;
Expand Down
38 changes: 0 additions & 38 deletions components/nacl/renderer/plugin/utility.h
Original file line number Diff line number Diff line change
Expand Up @@ -12,8 +12,6 @@
#include <stdint.h>

#include "components/nacl/renderer/ppb_nacl_private.h"
#include "native_client/src/shared/platform/nacl_threads.h"
#include "native_client/src/shared/platform/nacl_time.h"

#define SRPC_PLUGIN_DEBUG 1

Expand All @@ -22,42 +20,6 @@ namespace plugin {
const PPB_NaCl_Private* GetNaClInterface();
void SetNaClInterface(const PPB_NaCl_Private* nacl_interface);

// Debugging print utility
extern int gNaClPluginDebugPrintEnabled;
extern int NaClPluginPrintLog(const char *format, ...);
extern int NaClPluginDebugPrintCheckEnv();
#if SRPC_PLUGIN_DEBUG
#define INIT_PLUGIN_LOGGING() do { \
if (-1 == ::plugin::gNaClPluginDebugPrintEnabled) { \
::plugin::gNaClPluginDebugPrintEnabled = \
::plugin::NaClPluginDebugPrintCheckEnv(); \
} \
} while (0)

#define PLUGIN_PRINTF(args) do { \
INIT_PLUGIN_LOGGING(); \
if (0 != ::plugin::gNaClPluginDebugPrintEnabled) { \
::plugin::NaClPluginPrintLog("PLUGIN %" NACL_PRIu64 ": ", \
NaClGetTimeOfDayMicroseconds()); \
::plugin::NaClPluginPrintLog args; \
} \
} while (0)

// MODULE_PRINTF is used in the module because PLUGIN_PRINTF uses a
// a timer that may not yet be initialized.
#define MODULE_PRINTF(args) do { \
INIT_PLUGIN_LOGGING(); \
if (0 != ::plugin::gNaClPluginDebugPrintEnabled) { \
::plugin::NaClPluginPrintLog("MODULE: "); \
::plugin::NaClPluginPrintLog args; \
} \
} while (0)
#else
# define PLUGIN_PRINTF(args) do { if (0) { printf args; } } while (0)
# define MODULE_PRINTF(args) do { if (0) { printf args; } } while (0)
/* allows DCE but compiler can still do format string checks */
#endif

} // namespace plugin

#endif // COMPONENTS_NACL_RENDERER_PLUGIN_UTILITY_H_
Loading

0 comments on commit 58c568b

Please sign in to comment.