[NaCl SDK] Add some more logging to nacl_io.

native_client_sdk/src/libraries/nacl_io/devfs/jspipe_event_emitter.cc

 // Copyright 2014 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "nacl_io/devfs/jspipe_event_emitter.h"
 
 #include <assert.h>
 #include <errno.h>
 #include <string.h>
 
@@ skipping 94 matching lines @@
     if (err != 0)
       ERROR("Sending ACK failed: %d\n", err.error);
   }
 
   UpdateStatus_Locked();
   return 0;
 }
 
 Error JSPipeEventEmitter::SendWriteMessage(const void* buf, size_t count) {
   TRACE("SendWriteMessage [%" PRIuS "] total=%" PRIuS, count, bytes_sent_);
-  if (!var_iface_ || !buffer_iface_)
+  if (!var_iface_ || !buffer_iface_) {
+    ERROR("Got NULL interface(s): %s%s",
+          var_iface_ ? "" : "Var ",
+          buffer_iface_ ? "" : "ArrayBuffer");
     return EIO;
+  }
 
   // Copy payload data in a new ArrayBuffer
   PP_Var buffer = buffer_iface_->Create(count);
   memcpy(buffer_iface_->Map(buffer), buf, count);
   buffer_iface_->Unmap(buffer);
 
   Error rtn = SendMessageToJS(write_var_, buffer);
   var_iface_->Release(buffer);
   return rtn;
 }
 
 Error JSPipeEventEmitter::SetName(const char* name) {
-  if (var_iface_ == NULL)
+  if (var_iface_ == NULL) {
+    // No error here: many of the tests trigger this message.
+    LOG_TRACE("Got NULL interface: Var");
     return EIO;
+  }
 
   // name can only be set once
-  if (!name_.empty())
+  if (!name_.empty()) {
+    LOG_ERROR("Attempting to set name more than once.");
     return EIO;
+  }
 
   // new name must not be empty
-  if (!name || strlen(name) == 0)
+  if (!name || strlen(name) == 0) {
+    LOG_ERROR("Empty name is invalid.");
     return EIO;
+  }
 
   TRACE("set name: %s", name);
   name_ = name;
   pipe_name_var_ = VarFromCStr(name);
   return 0;
 }
 
 Error JSPipeEventEmitter::SendMessageToJS(PP_Var operation, PP_Var payload) {
-  if (!ppapi_ || !messaging_iface_ || !var_iface_ || !dict_iface_)
+  if (!ppapi_) {
+    LOG_ERROR("ppapi_ is NULL.");
     return EIO;
+  }
+
+  if (!messaging_iface_ || !var_iface_ || !dict_iface_) {
+    LOG_ERROR("Got NULL interface(s): %s%s%s",
+              messaging_iface_ ? "" : "Messaging ",
+              dict_iface_ ? "" : "Dictionary ",
+              var_iface_ ? "" : "Var");
+    return EIO;
+  }
 
   // Create dict object which will be sent to JavaScript.
   PP_Var dict = dict_iface_->Create();
 
   // Set three keys in the dictionary: 'pipe', 'operation', and 'payload'
   dict_iface_->Set(dict, pipe_key_, pipe_name_var_);
   dict_iface_->Set(dict, operation_key_, operation);
   dict_iface_->Set(dict, payload_key_, payload);
 
   // Send the dict via PostMessage
@@ skipping 14 matching lines @@
 }
 
 size_t JSPipeEventEmitter::HandleJSWrite(const char* data, size_t len) {
   size_t out_len = input_fifo_.Write(data, len);
   UpdateStatus_Locked();
   return out_len;
 }
 
 void JSPipeEventEmitter::HandleJSAck(size_t byte_count) {
   if (byte_count > bytes_sent_) {
-    ERROR("HandleAck unexpected byte count: %" PRIuS, byte_count);
+    ERROR("Unexpected byte count: %" PRIuS, byte_count);
     return;
   }
 
   bytes_acked_ = byte_count;
   TRACE("HandleAck: %" SCNuS "/%" PRIuS, bytes_acked_, bytes_sent_);
   UpdateStatus_Locked();
 }
 
 Error JSPipeEventEmitter::HandleJSWrite(struct PP_Var message) {
   TRACE("HandleJSWrite");
   if (message.type != PP_VARTYPE_ARRAY_BUFFER) {
-    TRACE("HandleJSWrite expected ArrayBuffer but got %d.", message.type);
+    ERROR("Expected ArrayBuffer but got %d.", message.type);
     return EINVAL;
   }
   uint32_t length;
-  if (buffer_iface_->ByteLength(message, &length) != PP_TRUE)
+  if (buffer_iface_->ByteLength(message, &length) != PP_TRUE) {
+    ERROR("ArrayBuffer.ByteLength returned PP_FALSE");
     return EINVAL;
+  }
 
   char* buffer = (char*)buffer_iface_->Map(message);
 
   // Write data to the input fifo
   size_t wrote = HandleJSWrite(buffer, length);
   buffer_iface_->Unmap(message);
   if (wrote != length) {
-    LOG_ERROR("Only wrote %d of %d bytes to pipe", (int)wrote, (int)length);
+    ERROR("Only wrote %d of %d bytes to pipe", (int)wrote, (int)length);
     return EIO;
   }
   TRACE("done HandleWrite: %d", length);
   return 0;
 }
 
 Error JSPipeEventEmitter::HandleJSAck(PP_Var message) {
   if (message.type != PP_VARTYPE_INT32) {
-    TRACE("HandleAck integer object expected but got %d.", message.type);
+    ERROR("Integer object expected but got %d.", message.type);
     return EINVAL;
   }
   HandleJSAck(message.value.as_int);
   return 0;
 }
 
 int JSPipeEventEmitter::VarStrcmp(PP_Var a, PP_Var b) {
   uint32_t length_a = 0;
   uint32_t length_b = 0;
   const char* cstring_a = var_iface_->VarToUtf8(a, &length_a);
   const char* cstring_b = var_iface_->VarToUtf8(a, &length_b);
   std::string string_a(cstring_a, length_a);
   std::string string_b(cstring_b, length_a);
   return strcmp(string_a.c_str(), string_b.c_str());
 }
 
 Error JSPipeEventEmitter::HandleJSMessage(struct PP_Var message) {
   Error err = 0;
   if (!messaging_iface_ || !var_iface_ || !dict_iface_ || !buffer_iface_) {
-    TRACE("HandleJSMessage: missing PPAPI interfaces");
+    ERROR("Got NULL interface(s): %s%s%s%s",
+          messaging_iface_ ? "" : "Messaging ",
+          var_iface_ ? "" : "Var ",
+          dict_iface_ ? "" : "Dictionary ",
+          buffer_iface_ ? "" : "ArrayBuffer");
     return ENOSYS;
   }
 
   // Verify that we have an array with size two.
   if (message.type != PP_VARTYPE_DICTIONARY) {
-    TRACE("HandleJSMessage passed non-dictionary var");
+    ERROR("Expected Dictionary but got %d.", message.type);
     return EINVAL;
   }
 
 #ifndef NDEBUG
   PP_Var pipe_name_var = dict_iface_->Get(message, pipe_key_);
   if (VarStrcmp(pipe_name_var, pipe_name_var_)) {
-    TRACE("HandleJSMessage wrong pipe name");
+    ERROR("Wrong pipe name.");
     return EINVAL;
   }
   var_iface_->Release(pipe_name_var);
 #endif
 
   PP_Var operation_var = dict_iface_->Get(message, operation_key_);
   if (operation_var.type != PP_VARTYPE_STRING) {
-    TRACE("HandleJSMessage invalid operation");
+    ERROR("Expected String but got %d.", operation_var.type);
     err = EINVAL;
   } else {
     uint32_t length;
     const char* operation_string;
     operation_string = var_iface_->VarToUtf8(operation_var, &length);
     std::string message_type(operation_string, length);
 
     TRACE("HandleJSMessage %s", message_type.c_str());
     PP_Var payload = dict_iface_->Get(message, payload_key_);
     if (message_type == kOperationNameWrite) {
       err = HandleJSWrite(payload);
     } else if (message_type == kOperationNameAck) {
       err = HandleJSAck(payload);
     } else {
-      TRACE("Unknown message type: %s", message_type.c_str());
+      ERROR("Unknown message type: %s", message_type.c_str());
       err = EINVAL;
     }
     var_iface_->Release(payload);
   }
 
   var_iface_->Release(operation_var);
   return err;
 }
 
 Error JSPipeEventEmitter::Write_Locked(const char* data,
@@ skipping 15 matching lines @@
   if (err != 0)
     return err;
   *out_bytes = len;
   bytes_sent_ += len;
 
   UpdateStatus_Locked();
   return 0;
 }
 
 }  // namespace nacl_io