[NaCl SDK] Add some more logging to nacl_io.

BUG=none
R=sbc@chromium.org

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

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

20 files changed, 394 insertions, 197 deletions

diff --git a/native_client_sdk/src/libraries/nacl_io/devfs/dev_fs.cc b/native_client_sdk/src/libraries/nacl_io/devfs/dev_fs.cc
index 9b50c90..efe8055 100644
--- a/native_client_sdk/src/libraries/nacl_io/devfs/dev_fs.cc
+++ b/native_client_sdk/src/libraries/nacl_io/devfs/dev_fs.cc
@@ -189,16 +189,21 @@ Error ConsoleNode::Write(const HandleAttr& attr,
                          int* out_bytes) {
   *out_bytes = 0;
 
-  ConsoleInterface* con_intr = filesystem_->ppapi()->GetConsoleInterface();
-  VarInterface* var_intr = filesystem_->ppapi()->GetVarInterface();
+  ConsoleInterface* con_iface = filesystem_->ppapi()->GetConsoleInterface();
+  VarInterface* var_iface = filesystem_->ppapi()->GetVarInterface();
 
-  if (!(var_intr && con_intr))
+  if (!(var_iface && con_iface)) {
+    LOG_ERROR("Got NULL interface(s): %s%s",
+              con_iface ? "" : "Console ",
+              var_iface ? "" : "Var");
     return ENOSYS;
+  }
 
   const char* var_data = static_cast<const char*>(buf);
   uint32_t len = static_cast<uint32_t>(count);
-  struct PP_Var val = var_intr->VarFromUtf8(var_data, len);
-  con_intr->Log(filesystem_->ppapi()->GetInstance(), level_, val);
+  struct PP_Var val = var_iface->VarFromUtf8(var_data, len);
+  con_iface->Log(filesystem_->ppapi()->GetInstance(), level_, val);
+  var_iface->Release(val);
 
   *out_bytes = count;
   return 0;
@@ -241,8 +246,10 @@ Error UrandomNode::Read(const HandleAttr& attr,
   *out_bytes = 0;
 
 #if defined(__native_client__)
-  if (!interface_ok_)
+  if (!interface_ok_) {
+    LOG_ERROR("NACL_IRT_RANDOM_v0_1 interface not avaiable.");
     return EBADF;
+  }
 
   size_t nread;
   int error = (*random_interface_.get_random_bytes)(buf, count, &nread);
@@ -295,8 +302,10 @@ Error DevFs::Access(const Path& path, int a_mode) {
     return error;
 
   // Don't allow execute access.
-  if (a_mode & X_OK)
+  if (a_mode & X_OK) {
+    LOG_TRACE("Executing devfs nodes is not allowed.");
     return EACCES;
+  }
 
   return 0;
 }
@@ -305,38 +314,47 @@ Error DevFs::Open(const Path& path, int open_flags, ScopedNode* out_node) {
   out_node->reset(NULL);
   int error;
   if (path.Part(1) == "fs") {
-    if (path.Size() == 3)
+    if (path.Size() == 3) {
       error = fs_dir_->FindChild(path.Part(2), out_node);
-    else
+    } else {
+      LOG_TRACE("Bad devfs path: %s", path.Join().c_str());
       error = ENOENT;
+    }
   } else {
     error = root_->FindChild(path.Join(), out_node);
   }
 
   // Only return EACCES when trying to create a node that does not exist.
-  if ((error == ENOENT) && (open_flags & O_CREAT))
+  if ((error == ENOENT) && (open_flags & O_CREAT)) {
+    LOG_TRACE("Cannot create devfs node: %s", path.Join().c_str());
     return EACCES;
+  }
 
   return error;
 }
 
 Error DevFs::Unlink(const Path& path) {
+  LOG_ERROR("unlink not supported.");
   return EPERM;
 }
 
 Error DevFs::Mkdir(const Path& path, int permissions) {
+  LOG_ERROR("mkdir not supported.");
   return EPERM;
 }
 
 Error DevFs::Rmdir(const Path& path) {
+  LOG_ERROR("rmdir not supported.");
   return EPERM;
 }
 
 Error DevFs::Remove(const Path& path) {
+  LOG_ERROR("remove not supported.");
   return EPERM;
 }
 
 Error DevFs::Rename(const Path& path, const Path& newpath) {
+  LOG_ERROR("rename not supported.");
   return EPERM;
 }
 
diff --git a/native_client_sdk/src/libraries/nacl_io/devfs/jspipe_event_emitter.cc b/native_client_sdk/src/libraries/nacl_io/devfs/jspipe_event_emitter.cc
index a00dbfd..8bf4d03 100644
--- a/native_client_sdk/src/libraries/nacl_io/devfs/jspipe_event_emitter.cc
+++ b/native_client_sdk/src/libraries/nacl_io/devfs/jspipe_event_emitter.cc
@@ -112,8 +112,12 @@ Error JSPipeEventEmitter::Read_Locked(char* data, size_t len, int* out_bytes) {
 
 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);
@@ -126,16 +130,23 @@ Error JSPipeEventEmitter::SendWriteMessage(const void* buf, size_t count) {
 }
 
 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;
@@ -144,8 +155,18 @@ Error JSPipeEventEmitter::SetName(const char* name) {
 }
 
 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();
@@ -180,7 +201,7 @@ size_t JSPipeEventEmitter::HandleJSWrite(const char* data, size_t 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;
   }
 
@@ -192,12 +213,14 @@ void JSPipeEventEmitter::HandleJSAck(size_t byte_count) {
 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);
 
@@ -205,7 +228,7 @@ Error JSPipeEventEmitter::HandleJSWrite(struct PP_Var message) {
   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);
@@ -214,7 +237,7 @@ Error JSPipeEventEmitter::HandleJSWrite(struct PP_Var message) {
 
 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);
@@ -234,20 +257,24 @@ int JSPipeEventEmitter::VarStrcmp(PP_Var a, PP_Var b) {
 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);
@@ -255,7 +282,7 @@ Error JSPipeEventEmitter::HandleJSMessage(struct PP_Var message) {
 
   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;
@@ -270,7 +297,7 @@ Error JSPipeEventEmitter::HandleJSMessage(struct PP_Var message) {
     } 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);
diff --git a/native_client_sdk/src/libraries/nacl_io/devfs/tty_node.cc b/native_client_sdk/src/libraries/nacl_io/devfs/tty_node.cc
index d237fdd..f1f7a26 100644
--- a/native_client_sdk/src/libraries/nacl_io/devfs/tty_node.cc
+++ b/native_client_sdk/src/libraries/nacl_io/devfs/tty_node.cc
@@ -89,8 +89,11 @@ Error TtyNode::Write(const HandleAttr& attr,
   *out_bytes = 0;
 
   // No handler registered.
-  if (output_handler_.handler == NULL)
+  if (output_handler_.handler == NULL) {
+    // No error here; many of the tests trigger this message.
+    LOG_TRACE("No output handler registered.");
     return EIO;
+  }
 
   int rtn = output_handler_.handler(
       static_cast<const char*>(buf), count, output_handler_.user_data);
@@ -170,19 +173,19 @@ Error TtyNode::Echo(const char* string, int count) {
 
 Error TtyNode::ProcessInput(PP_Var message) {
   if (message.type != PP_VARTYPE_STRING) {
-    LOG_ERROR("ProcessInput: expected VarString but got %d.", message.type);
+    LOG_ERROR("Expected VarString but got %d.", message.type);
     return EINVAL;
   }
 
   PepperInterface* ppapi = filesystem_->ppapi();
   if (!ppapi) {
-    LOG_ERROR("ProcessInput: ppapi is NULL.");
+    LOG_ERROR("ppapi is NULL.");
     return EINVAL;
   }
 
   VarInterface* var_iface = ppapi->GetVarInterface();
   if (!var_iface) {
-    LOG_ERROR("ProcessInput: Var interface pointer is NULL.");
+    LOG_ERROR("Got NULL interface: Var");
     return EINVAL;
   }
 
@@ -265,8 +268,10 @@ Error TtyNode::VIoctl(int request, va_list args) {
         output_handler_.handler = NULL;
         return 0;
       }
-      if (output_handler_.handler != NULL)
+      if (output_handler_.handler != NULL) {
+        LOG_ERROR("Output handler already set.");
         return EALREADY;
+      }
       output_handler_ = *arg;
       return 0;
     }
diff --git a/native_client_sdk/src/libraries/nacl_io/dir_node.cc b/native_client_sdk/src/libraries/nacl_io/dir_node.cc
index 0486198..e16c0c7 100644
--- a/native_client_sdk/src/libraries/nacl_io/dir_node.cc
+++ b/native_client_sdk/src/libraries/nacl_io/dir_node.cc
@@ -7,7 +7,9 @@
 #include <errno.h>
 #include <string.h>
 
+#include "nacl_io/log.h"
 #include "nacl_io/osdirent.h"
+#include "nacl_io/osinttypes.h"
 #include "nacl_io/osstat.h"
 #include "sdk_util/auto_lock.h"
 #include "sdk_util/macros.h"
@@ -40,10 +42,12 @@ Error DirNode::Read(const HandleAttr& attr,
                     size_t count,
                     int* out_bytes) {
   *out_bytes = 0;
+  LOG_TRACE("Can't read a directory.");
   return EISDIR;
 }
 
 Error DirNode::FTruncate(off_t size) {
+  LOG_TRACE("Can't truncate a directory.");
   return EISDIR;
 }
 
@@ -52,6 +56,7 @@ Error DirNode::Write(const HandleAttr& attr,
                      size_t count,
                      int* out_bytes) {
   *out_bytes = 0;
+  LOG_TRACE("Can't write to a directory.");
   return EISDIR;
 }
 
@@ -67,15 +72,23 @@ Error DirNode::GetDents(size_t offs,
 Error DirNode::AddChild(const std::string& name, const ScopedNode& node) {
   AUTO_LOCK(node_lock_);
 
-  if (name.empty())
+  if (name.empty()) {
+    LOG_ERROR("Can't add child with no name.");
     return ENOENT;
+  }
 
-  if (name.length() >= MEMBER_SIZE(dirent, d_name))
+  if (name.length() >= MEMBER_SIZE(dirent, d_name)) {
+    LOG_ERROR("Child name is too long: %" PRIuS " >= %" PRIuS,
+              name.length(),
+              MEMBER_SIZE(dirent, d_name));
     return ENAMETOOLONG;
+  }
 
   NodeMap_t::iterator it = map_.find(name);
-  if (it != map_.end())
+  if (it != map_.end()) {
+    LOG_TRACE("Can't add child \"%s\", it already exists.", name);
     return EEXIST;
+  }
 
   node->Link();
   map_[name] = node;
diff --git a/native_client_sdk/src/libraries/nacl_io/filesystem.cc b/native_client_sdk/src/libraries/nacl_io/filesystem.cc
index c627ce3..feda1e7 100644
--- a/native_client_sdk/src/libraries/nacl_io/filesystem.cc
+++ b/native_client_sdk/src/libraries/nacl_io/filesystem.cc
@@ -11,6 +11,7 @@
 #include <string>
 
 #include "nacl_io/dir_node.h"
+#include "nacl_io/log.h"
 #include "nacl_io/node.h"
 #include "nacl_io/osstat.h"
 #include "nacl_io/path.h"
@@ -40,6 +41,7 @@ void Filesystem::Destroy() {
 
 Error Filesystem::OpenResource(const Path& path, ScopedNode* out_node) {
   out_node->reset(NULL);
+  LOG_TRACE("Can't open resource: %s", path.Join().c_str());
   return EINVAL;
 }
 
@@ -54,6 +56,7 @@ void Filesystem::OnNodeDestroyed(Node* node) {
 }
 
 Error Filesystem::Filesystem_VIoctl(int request, va_list args) {
+  LOG_ERROR("Unsupported ioctl: %#x", request);
   return EINVAL;
 }
 
diff --git a/native_client_sdk/src/libraries/nacl_io/fusefs/fuse_fs.cc b/native_client_sdk/src/libraries/nacl_io/fusefs/fuse_fs.cc
index 34e7064..fdf74be 100644
--- a/native_client_sdk/src/libraries/nacl_io/fusefs/fuse_fs.cc
+++ b/native_client_sdk/src/libraries/nacl_io/fusefs/fuse_fs.cc
@@ -12,6 +12,7 @@
 
 #include "nacl_io/getdents_helper.h"
 #include "nacl_io/kernel_handle.h"
+#include "nacl_io/log.h"
 #include "sdk_util/macros.h"
 
 namespace nacl_io {
@@ -38,8 +39,10 @@ Error FuseFs::Init(const FsInitArgs& args) {
     return error;
 
   fuse_ops_ = args.fuse_ops;
-  if (fuse_ops_ == NULL)
+  if (fuse_ops_ == NULL) {
+    LOG_ERROR("fuse_ops_ is NULL.");
     return EINVAL;
+  }
 
   if (fuse_ops_->init) {
     struct fuse_conn_info info;
@@ -55,8 +58,10 @@ void FuseFs::Destroy() {
 }
 
 Error FuseFs::Access(const Path& path, int a_mode) {
-  if (!fuse_ops_->access)
+  if (!fuse_ops_->access) {
+    LOG_TRACE("fuse_ops_->access is NULL.");
     return ENOSYS;
+  }
 
   int result = fuse_ops_->access(path.Join().c_str(), a_mode);
   if (result < 0)
@@ -87,6 +92,7 @@ Error FuseFs::Open(const Path& path, int open_flags, ScopedNode* out_node) {
       if (result < 0)
         return -result;
     } else {
+      LOG_TRACE("fuse_ops_->create and fuse_ops_->mknod are NULL.");
       return ENOSYS;
     }
   } else {
@@ -114,15 +120,19 @@ Error FuseFs::Open(const Path& path, int open_flags, ScopedNode* out_node) {
     if (open_flags & O_TRUNC) {
       // According to the FUSE docs, O_TRUNC does two calls: first truncate()
       // then open().
-      if (!fuse_ops_->truncate)
+      if (!fuse_ops_->truncate) {
+        LOG_TRACE("fuse_ops_->truncate is NULL.");
         return ENOSYS;
+      }
       result = fuse_ops_->truncate(path_cstr, 0);
       if (result < 0)
         return -result;
     }
 
-    if (!fuse_ops_->open)
+    if (!fuse_ops_->open) {
+      LOG_TRACE("fuse_ops_->open is NULL.");
       return ENOSYS;
+    }
     result = fuse_ops_->open(path_cstr, &fi);
     if (result < 0)
       return -result;
@@ -138,8 +148,10 @@ Error FuseFs::Open(const Path& path, int open_flags, ScopedNode* out_node) {
 }
 
 Error FuseFs::Unlink(const Path& path) {
-  if (!fuse_ops_->unlink)
+  if (!fuse_ops_->unlink) {
+    LOG_TRACE("fuse_ops_->unlink is NULL.");
     return ENOSYS;
+  }
 
   int result = fuse_ops_->unlink(path.Join().c_str());
   if (result < 0)
@@ -149,8 +161,10 @@ Error FuseFs::Unlink(const Path& path) {
 }
 
 Error FuseFs::Mkdir(const Path& path, int perm) {
-  if (!fuse_ops_->mkdir)
+  if (!fuse_ops_->mkdir) {
+    LOG_TRACE("fuse_ops_->mkdir is NULL.");
     return ENOSYS;
+  }
 
   int result = fuse_ops_->mkdir(path.Join().c_str(), perm);
   if (result < 0)
@@ -160,8 +174,10 @@ Error FuseFs::Mkdir(const Path& path, int perm) {
 }
 
 Error FuseFs::Rmdir(const Path& path) {
-  if (!fuse_ops_->rmdir)
+  if (!fuse_ops_->rmdir) {
+    LOG_TRACE("fuse_ops_->rmdir is NULL.");
     return ENOSYS;
+  }
 
   int result = fuse_ops_->rmdir(path.Join().c_str());
   if (result < 0)
@@ -191,8 +207,10 @@ Error FuseFs::Remove(const Path& path) {
 }
 
 Error FuseFs::Rename(const Path& path, const Path& newpath) {
-  if (!fuse_ops_->rename)
+  if (!fuse_ops_->rename) {
+    LOG_TRACE("fuse_ops_->rename is NULL.");
     return ENOSYS;
+  }
 
   int result = fuse_ops_->rename(path.Join().c_str(), newpath.Join().c_str());
   if (result < 0)
@@ -230,6 +248,7 @@ Error FuseFsNode::GetStat(struct stat* stat) {
     if (result < 0)
       return -result;
   } else {
+    LOG_TRACE("fuse_ops_->fgetattr and fuse_ops_->getattr are NULL.");
     return ENOSYS;
   }
 
@@ -239,23 +258,23 @@ Error FuseFsNode::GetStat(struct stat* stat) {
 }
 
 Error FuseFsNode::VIoctl(int request, va_list args) {
-  // TODO(binji): implement
+  LOG_ERROR("Ioctl not implemented for fusefs.");
   return ENOSYS;
 }
 
 Error FuseFsNode::Tcflush(int queue_selector) {
-  // TODO(binji): use ioctl for this?
+  LOG_ERROR("Tcflush not implemented for fusefs.");
   return ENOSYS;
 }
 
 Error FuseFsNode::Tcgetattr(struct termios* termios_p) {
-  // TODO(binji): use ioctl for this?
+  LOG_ERROR("Tcgetattr not implemented for fusefs.");
   return ENOSYS;
 }
 
 Error FuseFsNode::Tcsetattr(int optional_actions,
                             const struct termios* termios_p) {
-  // TODO(binji): use ioctl for this?
+  LOG_ERROR("Tcsetattr not implemented for fusefs.");
   return ENOSYS;
 }
 
@@ -283,8 +302,10 @@ void FileFuseFsNode::Destroy() {
 }
 
 Error FileFuseFsNode::FSync() {
-  if (!fuse_ops_->fsync)
+  if (!fuse_ops_->fsync) {
+    LOG_ERROR("fuse_ops_->fsync is NULL.");
     return ENOSYS;
+  }
 
   int datasync = 0;
   int result = fuse_ops_->fsync(path_.c_str(), datasync, &info_);
@@ -294,8 +315,10 @@ Error FileFuseFsNode::FSync() {
 }
 
 Error FileFuseFsNode::FTruncate(off_t length) {
-  if (!fuse_ops_->ftruncate)
+  if (!fuse_ops_->ftruncate) {
+    LOG_ERROR("fuse_ops_->ftruncate is NULL.");
     return ENOSYS;
+  }
 
   int result = fuse_ops_->ftruncate(path_.c_str(), length, &info_);
   if (result < 0)
@@ -307,8 +330,10 @@ Error FileFuseFsNode::Read(const HandleAttr& attr,
                            void* buf,
                            size_t count,
                            int* out_bytes) {
-  if (!fuse_ops_->read)
+  if (!fuse_ops_->read) {
+    LOG_ERROR("fuse_ops_->read is NULL.");
     return ENOSYS;
+  }
 
   char* cbuf = static_cast<char*>(buf);
 
@@ -330,8 +355,10 @@ Error FileFuseFsNode::Write(const HandleAttr& attr,
                             const void* buf,
                             size_t count,
                             int* out_bytes) {
-  if (!fuse_ops_->write)
+  if (!fuse_ops_->write) {
+    LOG_ERROR("fuse_ops_->write is NULL.");
     return ENOSYS;
+  }
 
   int result = fuse_ops_->write(
       path_.c_str(), static_cast<const char*>(buf), count, attr.offs, &info_);
@@ -360,8 +387,10 @@ void DirFuseFsNode::Destroy() {
 }
 
 Error DirFuseFsNode::FSync() {
-  if (!fuse_ops_->fsyncdir)
+  if (!fuse_ops_->fsyncdir) {
+    LOG_ERROR("fuse_ops_->fsyncdir is NULL.");
     return ENOSYS;
+  }
 
   int datasync = 0;
   int result = fuse_ops_->fsyncdir(path_.c_str(), datasync, &info_);
@@ -374,8 +403,10 @@ Error DirFuseFsNode::GetDents(size_t offs,
                               struct dirent* pdir,
                               size_t count,
                               int* out_bytes) {
-  if (!fuse_ops_->readdir)
+  if (!fuse_ops_->readdir) {
+    LOG_ERROR("fuse_ops_->readdir is NULL.");
     return ENOSYS;
+  }
 
   bool opened_dir = false;
   int result;
diff --git a/native_client_sdk/src/libraries/nacl_io/getdents_helper.cc b/native_client_sdk/src/libraries/nacl_io/getdents_helper.cc
index 87dc32d..47cc694 100644
--- a/native_client_sdk/src/libraries/nacl_io/getdents_helper.cc
+++ b/native_client_sdk/src/libraries/nacl_io/getdents_helper.cc
@@ -10,6 +10,8 @@
 
 #include <algorithm>
 
+#include "nacl_io/log.h"
+
 #include "sdk_util/macros.h"
 
 namespace nacl_io {
@@ -63,12 +65,16 @@ Error GetDentsHelper::GetDents(size_t offs,
   *out_bytes = 0;
 
   // If the buffer pointer is invalid, fail
-  if (NULL == pdir)
+  if (NULL == pdir) {
+    LOG_TRACE("dirent pointer is NULL.");
     return EINVAL;
+  }
 
   // If the buffer is too small, fail
-  if (size < sizeof(dirent))
+  if (size < sizeof(dirent)) {
+    LOG_TRACE("dirent buffer size is too small: %d < %d", size, sizeof(dirent));
     return EINVAL;
+  }
 
   // Force size to a multiple of dirent
   size -= size % sizeof(dirent);
diff --git a/native_client_sdk/src/libraries/nacl_io/host_resolver.cc b/native_client_sdk/src/libraries/nacl_io/host_resolver.cc
index c16fbcb..11648f6 100644
--- a/native_client_sdk/src/libraries/nacl_io/host_resolver.cc
+++ b/native_client_sdk/src/libraries/nacl_io/host_resolver.cc
@@ -14,6 +14,7 @@
 #include <string.h>
 
 #include "nacl_io/kernel_proxy.h"
+#include "nacl_io/log.h"
 #include "nacl_io/ossocket.h"
 #include "nacl_io/pepper_interface.h"
 
@@ -227,8 +228,10 @@ int HostResolver::getaddrinfo(const char* node,
   *result = NULL;
   struct addrinfo* end = NULL;
 
-  if (node == NULL && service == NULL)
+  if (node == NULL && service == NULL) {
+    LOG_TRACE("node and service are NULL.");
     return EAI_NONAME;
+  }
 
   // Check the service name (port).  Currently we only handle numeric
   // services.
@@ -239,6 +242,7 @@ int HostResolver::getaddrinfo(const char* node,
     if (port >= 0 && port <= UINT16_MAX && *cp == '\0') {
       port = htons(port);
     } else {
+      LOG_TRACE("Service \"%s\" not supported.", service);
       return EAI_SERVICE;
     }
   }
@@ -254,6 +258,7 @@ int HostResolver::getaddrinfo(const char* node,
     case AF_UNSPEC:
       break;
     default:
+      LOG_TRACE("Unknown family: %d.", hints->ai_family);
       return EAI_FAMILY;
   }
 
@@ -303,16 +308,23 @@ int HostResolver::getaddrinfo(const char* node,
     return 0;
   }
 
-  if (NULL == ppapi_)
+  if (NULL == ppapi_) {
+    LOG_ERROR("ppapi_ is NULL.");
     return EAI_SYSTEM;
+  }
 
   // Use PPAPI interface to resolve nodename
   HostResolverInterface* resolver_iface = ppapi_->GetHostResolverInterface();
-  VarInterface* var_interface = ppapi_->GetVarInterface();
+  VarInterface* var_iface = ppapi_->GetVarInterface();
   NetAddressInterface* netaddr_iface = ppapi_->GetNetAddressInterface();
 
-  if (NULL == resolver_iface || NULL == var_interface || NULL == netaddr_iface)
+  if (!(resolver_iface && var_iface && netaddr_iface)) {
+    LOG_ERROR("Got NULL interface(s): %s%s%s",
+              resolver_iface ? "" : "HostResolver ",
+              var_iface ? "" : "Var ",
+              netaddr_iface ? "" : "NetAddress");
     return EAI_SYSTEM;
+  }
 
   ScopedResource scoped_resolver(ppapi_,
                                  resolver_iface->Create(ppapi_->GetInstance()));
@@ -342,7 +354,7 @@ int HostResolver::getaddrinfo(const char* node,
     PP_Var name_var = resolver_iface->GetCanonicalName(resolver);
     if (PP_VARTYPE_STRING == name_var.type) {
       uint32_t len = 0;
-      const char* tmp = var_interface->VarToUtf8(name_var, &len);
+      const char* tmp = var_iface->VarToUtf8(name_var, &len);
       // For some reason GetCanonicalName alway returns an empty
       // string so this condition is never true.
       // TODO(sbc): investigate this issue with PPAPI team.
@@ -355,7 +367,7 @@ int HostResolver::getaddrinfo(const char* node,
     }
     if (!canon_name)
       canon_name = strdup(node);
-    var_interface->Release(name_var);
+    var_iface->Release(name_var);
   }
 
   int num_addresses = resolver_iface->GetNetAddressCount(resolver);
diff --git a/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs.cc b/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs.cc
index 1ef65e9..430e49f 100644
--- a/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs.cc
+++ b/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs.cc
@@ -41,7 +41,7 @@ Error Html5Fs::Open(const Path& path, int open_flags, ScopedNode* out_node) {
   if (error)
     return error;
 
-  PP_Resource fileref = ppapi()->GetFileRefInterface()->Create(
+  PP_Resource fileref = file_ref_iface_->Create(
       filesystem_resource_, GetFullPath(path).Join().c_str());
   if (!fileref)
     return ENOENT;
@@ -77,12 +77,12 @@ Error Html5Fs::Mkdir(const Path& path, int permissions) {
 
   ScopedResource fileref_resource(
       ppapi(),
-      ppapi()->GetFileRefInterface()->Create(filesystem_resource_,
-                                             GetFullPath(path).Join().c_str()));
+      file_ref_iface_->Create(filesystem_resource_,
+                              GetFullPath(path).Join().c_str()));
   if (!fileref_resource.pp_resource())
     return ENOENT;
 
-  int32_t result = ppapi()->GetFileRefInterface()->MakeDirectory(
+  int32_t result = file_ref_iface_->MakeDirectory(
       fileref_resource.pp_resource(), PP_FALSE, PP_BlockUntilComplete());
   if (result != PP_OK)
     return PPErrorToErrno(result);
@@ -105,15 +105,15 @@ Error Html5Fs::RemoveInternal(const Path& path, int remove_type) {
 
   ScopedResource fileref_resource(
       ppapi(),
-      ppapi()->GetFileRefInterface()->Create(filesystem_resource_,
-                                             GetFullPath(path).Join().c_str()));
+      file_ref_iface_->Create(filesystem_resource_,
+                              GetFullPath(path).Join().c_str()));
   if (!fileref_resource.pp_resource())
     return ENOENT;
 
   // Check file type
   if (remove_type != REMOVE_ALL) {
     PP_FileInfo file_info;
-    int32_t query_result = ppapi()->GetFileRefInterface()->Query(
+    int32_t query_result = file_ref_iface_->Query(
         fileref_resource.pp_resource(), &file_info, PP_BlockUntilComplete());
     if (query_result != PP_OK) {
       LOG_ERROR("Error querying file type");
@@ -134,8 +134,8 @@ Error Html5Fs::RemoveInternal(const Path& path, int remove_type) {
     }
   }
 
-  int32_t result = ppapi()->GetFileRefInterface()->Delete(
-      fileref_resource.pp_resource(), PP_BlockUntilComplete());
+  int32_t result = file_ref_iface_->Delete(fileref_resource.pp_resource(),
+                                           PP_BlockUntilComplete());
   if (result != PP_OK)
     return PPErrorToErrno(result);
 
@@ -149,24 +149,19 @@ Error Html5Fs::Rename(const Path& path, const Path& newpath) {
 
   const char* oldpath_full = GetFullPath(path).Join().c_str();
   ScopedResource fileref_resource(
-      ppapi(),
-      ppapi()->GetFileRefInterface()->Create(filesystem_resource_,
-                                             oldpath_full));
+      ppapi(), file_ref_iface_->Create(filesystem_resource_, oldpath_full));
   if (!fileref_resource.pp_resource())
     return ENOENT;
 
   const char* newpath_full = GetFullPath(newpath).Join().c_str();
   ScopedResource new_fileref_resource(
-      ppapi(),
-      ppapi()->GetFileRefInterface()->Create(filesystem_resource_,
-                                             newpath_full));
+      ppapi(), file_ref_iface_->Create(filesystem_resource_, newpath_full));
   if (!new_fileref_resource.pp_resource())
     return ENOENT;
 
-  int32_t result =
-      ppapi()->GetFileRefInterface()->Rename(fileref_resource.pp_resource(),
-                                             new_fileref_resource.pp_resource(),
-                                             PP_BlockUntilComplete());
+  int32_t result = file_ref_iface_->Rename(fileref_resource.pp_resource(),
+                                           new_fileref_resource.pp_resource(),
+                                           PP_BlockUntilComplete());
   if (result != PP_OK)
     return PPErrorToErrno(result);
 
@@ -174,7 +169,10 @@ Error Html5Fs::Rename(const Path& path, const Path& newpath) {
 }
 
 Html5Fs::Html5Fs()
-    : filesystem_resource_(0),
+    : filesystem_iface_(NULL),
+      file_ref_iface_(NULL),
+      file_io_iface_(NULL),
+      filesystem_resource_(0),
       filesystem_open_has_result_(false),
       filesystem_open_error_(0) {
 }
@@ -184,8 +182,25 @@ Error Html5Fs::Init(const FsInitArgs& args) {
   if (error)
     return error;
 
-  if (!args.ppapi)
+  if (!args.ppapi) {
+    LOG_ERROR("ppapi is NULL.");
+    return ENOSYS;
+  }
+
+  core_iface_ = ppapi()->GetCoreInterface();
+  filesystem_iface_ = ppapi()->GetFileSystemInterface();
+  file_io_iface_ = ppapi()->GetFileIoInterface();
+  file_ref_iface_ = ppapi()->GetFileRefInterface();
+
+  if (!(core_iface_ && filesystem_iface_ && file_io_iface_ &&
+        file_ref_iface_)) {
+    LOG_ERROR("Got NULL interface(s): %s%s%s%s",
+              core_iface_ ? "" : "Core ",
+              filesystem_iface_ ? "" : "FileSystem ",
+              file_ref_iface_ ? "" : "FileRef",
+              file_io_iface_ ? "" : "FileIo ");
     return ENOSYS;
+  }
 
   pthread_cond_init(&filesystem_open_cond_, NULL);
 
@@ -203,14 +218,14 @@ Error Html5Fs::Init(const FsInitArgs& args) {
       } else if (iter->second == "") {
         filesystem_type = PP_FILESYSTEMTYPE_LOCALPERSISTENT;
       } else {
-        LOG_ERROR("html5fs: unknown type: '%s'", iter->second.c_str());
+        LOG_ERROR("Unknown filesystem type: '%s'", iter->second.c_str());
         return EINVAL;
       }
     } else if (iter->first == "expected_size") {
       expected_size = strtoull(iter->second.c_str(), NULL, 10);
     } else if (iter->first == "filesystem_resource") {
       PP_Resource resource = strtoull(iter->second.c_str(), NULL, 10);
-      if (!ppapi_->GetFileSystemInterface()->IsFileSystem(resource))
+      if (!filesystem_iface_->IsFileSystem(resource))
         return EINVAL;
 
       filesystem_resource_ = resource;
@@ -218,7 +233,7 @@ Error Html5Fs::Init(const FsInitArgs& args) {
     } else if (iter->first == "SOURCE") {
       prefix_ = iter->second;
     } else {
-      LOG_ERROR("html5fs: bad param: %s", iter->first.c_str());
+      LOG_ERROR("Invalid mount param: %s", iter->first.c_str());
       return EINVAL;
     }
   }
@@ -230,22 +245,22 @@ Error Html5Fs::Init(const FsInitArgs& args) {
   }
 
   // Initialize filesystem.
-  filesystem_resource_ = ppapi_->GetFileSystemInterface()->Create(
-      ppapi_->GetInstance(), filesystem_type);
+  filesystem_resource_ =
+      filesystem_iface_->Create(ppapi_->GetInstance(), filesystem_type);
   if (filesystem_resource_ == 0)
     return ENOSYS;
 
   // We can't block the main thread, so make an asynchronous call if on main
   // thread. If we are off-main-thread, then don't make an asynchronous call;
   // otherwise we require a message loop.
-  bool main_thread = ppapi_->GetCoreInterface()->IsMainThread();
+  bool main_thread = core_iface_->IsMainThread();
   PP_CompletionCallback cc =
       main_thread ? PP_MakeCompletionCallback(
                         &Html5Fs::FilesystemOpenCallbackThunk, this)
                   : PP_BlockUntilComplete();
 
-  int32_t result = ppapi_->GetFileSystemInterface()->Open(
-      filesystem_resource_, expected_size, cc);
+  int32_t result =
+      filesystem_iface_->Open(filesystem_resource_, expected_size, cc);
 
   if (!main_thread) {
     filesystem_open_has_result_ = true;
diff --git a/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs.h b/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs.h
index fde92cd..8233639 100644
--- a/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs.h
+++ b/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs.h
@@ -46,6 +46,11 @@ class Html5Fs : public Filesystem {
   void FilesystemOpenCallback(int32_t result);
   Path GetFullPath(const Path& path);
 
+  CoreInterface* core_iface_;
+  FileSystemInterface* filesystem_iface_;
+  FileRefInterface* file_ref_iface_;
+  FileIoInterface* file_io_iface_;
+
   PP_Resource filesystem_resource_;
   bool filesystem_open_has_result_;  // protected by lock_.
   Error filesystem_open_error_;      // protected by lock_.
diff --git a/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs_node.cc b/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs_node.cc
index 3fc2f0f..981f69e 100644
--- a/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs_node.cc
+++ b/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs_node.cc
@@ -76,8 +76,8 @@ Error Html5FsNode::FSync() {
   if (IsaDir())
     return 0;
 
-  int32_t result = filesystem_->ppapi()->GetFileIoInterface()->Flush(
-      fileio_resource_, PP_BlockUntilComplete());
+  int32_t result =
+      file_io_iface_->Flush(fileio_resource_, PP_BlockUntilComplete());
   if (result != PP_OK)
     return PPErrorToErrno(result);
   return 0;
@@ -100,17 +100,15 @@ Error Html5FsNode::GetDents(size_t offs,
 
   OutputBuffer output_buf = {NULL, 0};
   PP_ArrayOutput output = {&GetOutputBuffer, &output_buf};
-  int32_t result =
-      filesystem_->ppapi()->GetFileRefInterface()->ReadDirectoryEntries(
-          fileref_resource_, output, PP_BlockUntilComplete());
+  int32_t result = file_ref_iface_->ReadDirectoryEntries(
+      fileref_resource_, output, PP_BlockUntilComplete());
   if (result != PP_OK)
     return PPErrorToErrno(result);
 
   PP_DirectoryEntry* entries = static_cast<PP_DirectoryEntry*>(output_buf.data);
 
   for (int i = 0; i < output_buf.element_count; ++i) {
-    PP_Var file_name_var = filesystem_->ppapi()->GetFileRefInterface()->GetName(
-        entries[i].file_ref);
+    PP_Var file_name_var = file_ref_iface_->GetName(entries[i].file_ref);
 
     // Release the file reference.
     filesystem_->ppapi()->ReleaseResource(entries[i].file_ref);
@@ -119,8 +117,8 @@ Error Html5FsNode::GetDents(size_t offs,
       continue;
 
     uint32_t file_name_length;
-    const char* file_name = filesystem_->ppapi()->GetVarInterface()->VarToUtf8(
-        file_name_var, &file_name_length);
+    const char* file_name =
+        var_iface_->VarToUtf8(file_name_var, &file_name_length);
 
     if (file_name) {
       file_name_length =
@@ -131,7 +129,7 @@ Error Html5FsNode::GetDents(size_t offs,
       helper.AddDirent(1, file_name, file_name_length);
     }
 
-    filesystem_->ppapi()->GetVarInterface()->Release(file_name_var);
+    var_iface_->Release(file_name_var);
   }
 
   // Release the output buffer.
@@ -144,8 +142,8 @@ Error Html5FsNode::GetStat(struct stat* stat) {
   AUTO_LOCK(node_lock_);
 
   PP_FileInfo info;
-  int32_t result = filesystem_->ppapi()->GetFileRefInterface()->Query(
-      fileref_resource_, &info, PP_BlockUntilComplete());
+  int32_t result =
+      file_ref_iface_->Query(fileref_resource_, &info, PP_BlockUntilComplete());
   if (result != PP_OK)
     return PPErrorToErrno(result);
 
@@ -181,12 +179,11 @@ Error Html5FsNode::Read(const HandleAttr& attr,
   if (IsaDir())
     return EISDIR;
 
-  int32_t result = filesystem_->ppapi()->GetFileIoInterface()->Read(
-      fileio_resource_,
-      attr.offs,
-      static_cast<char*>(buf),
-      static_cast<int32_t>(count),
-      PP_BlockUntilComplete());
+  int32_t result = file_io_iface_->Read(fileio_resource_,
+                                        attr.offs,
+                                        static_cast<char*>(buf),
+                                        static_cast<int32_t>(count),
+                                        PP_BlockUntilComplete());
   if (result < 0)
     return PPErrorToErrno(result);
 
@@ -198,7 +195,7 @@ Error Html5FsNode::FTruncate(off_t size) {
   if (IsaDir())
     return EISDIR;
 
-  int32_t result = filesystem_->ppapi()->GetFileIoInterface()->SetLength(
+  int32_t result = file_io_iface_->SetLength(
       fileio_resource_, size, PP_BlockUntilComplete());
   if (result != PP_OK)
     return PPErrorToErrno(result);
@@ -214,12 +211,11 @@ Error Html5FsNode::Write(const HandleAttr& attr,
   if (IsaDir())
     return EISDIR;
 
-  int32_t result = filesystem_->ppapi()->GetFileIoInterface()->Write(
-      fileio_resource_,
-      attr.offs,
-      static_cast<const char*>(buf),
-      static_cast<int32_t>(count),
-      PP_BlockUntilComplete());
+  int32_t result = file_io_iface_->Write(fileio_resource_,
+                                         attr.offs,
+                                         static_cast<const char*>(buf),
+                                         static_cast<int32_t>(count),
+                                         PP_BlockUntilComplete());
   if (result < 0)
     return PPErrorToErrno(result);
 
@@ -240,8 +236,8 @@ Error Html5FsNode::GetSize(off_t* out_size) {
   AUTO_LOCK(node_lock_);
 
   PP_FileInfo info;
-  int32_t result = filesystem_->ppapi()->GetFileIoInterface()->Query(
-      fileio_resource_, &info, PP_BlockUntilComplete());
+  int32_t result =
+      file_io_iface_->Query(fileio_resource_, &info, PP_BlockUntilComplete());
   if (result != PP_OK)
     return PPErrorToErrno(result);
 
@@ -260,23 +256,38 @@ Error Html5FsNode::Init(int open_flags) {
   if (error)
     return error;
 
+  file_io_iface_ = filesystem_->ppapi()->GetFileIoInterface();
+  file_ref_iface_ = filesystem_->ppapi()->GetFileRefInterface();
+  var_iface_ = filesystem_->ppapi()->GetVarInterface();
+
+  if (!(file_io_iface_ && file_ref_iface_ && var_iface_)) {
+    LOG_ERROR("Got NULL interface(s): %s%s%s",
+              file_ref_iface_ ? "" : "FileRef",
+              file_io_iface_ ? "" : "FileIo ",
+              var_iface_ ? "" : "Var ");
+    return EIO;
+  }
+
   // First query the FileRef to see if it is a file or directory.
   PP_FileInfo file_info;
-  int32_t query_result = filesystem_->ppapi()->GetFileRefInterface()->Query(
+  int32_t query_result = file_ref_iface_->Query(
       fileref_resource_, &file_info, PP_BlockUntilComplete());
   // If this is a directory, do not get a FileIO.
   if (query_result == PP_OK && file_info.type == PP_FILETYPE_DIRECTORY)
     return 0;
 
-  FileIoInterface* file_io = filesystem_->ppapi()->GetFileIoInterface();
-  fileio_resource_ = file_io->Create(filesystem_->ppapi()->GetInstance());
-  if (!fileio_resource_)
-    return ENOSYS;
+  fileio_resource_ =
+      file_io_iface_->Create(filesystem_->ppapi()->GetInstance());
+  if (!fileio_resource_) {
+    LOG_ERROR("Couldn't create FileIo resource.");
+    return EIO;
+  }
 
-  int32_t open_result = file_io->Open(fileio_resource_,
-                                      fileref_resource_,
-                                      OpenFlagsToPPAPIOpenFlags(open_flags),
-                                      PP_BlockUntilComplete());
+  int32_t open_result =
+      file_io_iface_->Open(fileio_resource_,
+                           fileref_resource_,
+                           OpenFlagsToPPAPIOpenFlags(open_flags),
+                           PP_BlockUntilComplete());
   if (open_result != PP_OK)
     return PPErrorToErrno(open_result);
   return 0;
@@ -286,7 +297,7 @@ void Html5FsNode::Destroy() {
   FSync();
 
   if (fileio_resource_) {
-    filesystem_->ppapi()->GetFileIoInterface()->Close(fileio_resource_);
+    file_io_iface_->Close(fileio_resource_);
     filesystem_->ppapi()->ReleaseResource(fileio_resource_);
   }
 
diff --git a/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs_node.h b/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs_node.h
index e76542e..7081bf2 100644
--- a/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs_node.h
+++ b/native_client_sdk/src/libraries/nacl_io/html5fs/html5_fs_node.h
@@ -5,12 +5,16 @@
 #ifndef LIBRARIES_NACL_IO_HTML5FS_HTML5_FS_NODE_H_
 #define LIBRARIES_NACL_IO_HTML5FS_HTML5_FS_NODE_H_
 
+#include <ppapi/c/pp_instance.h>
 #include <ppapi/c/pp_resource.h>
 #include "nacl_io/node.h"
 
 namespace nacl_io {
 
 class Html5Fs;
+class FileIoInterface;
+class FileRefInterface;
+class VarInterface;
 
 class Html5FsNode : public Node {
  public:
@@ -44,6 +48,9 @@ class Html5FsNode : public Node {
   virtual void Destroy();
 
  private:
+  FileIoInterface* file_io_iface_;
+  FileRefInterface* file_ref_iface_;
+  VarInterface* var_iface_;
   PP_Resource fileref_resource_;
   PP_Resource fileio_resource_;  // 0 if the file is a directory.
 
diff --git a/native_client_sdk/src/libraries/nacl_io/jsfs/js_fs.cc b/native_client_sdk/src/libraries/nacl_io/jsfs/js_fs.cc
index 3069e17..9c0b215 100644
--- a/native_client_sdk/src/libraries/nacl_io/jsfs/js_fs.cc
+++ b/native_client_sdk/src/libraries/nacl_io/jsfs/js_fs.cc
@@ -18,11 +18,6 @@
 #include "nacl_io/pepper_interface.h"
 #include "sdk_util/macros.h"
 
-#define TRACE(format, ...) \
-  LOG_TRACE("%s:%d: " format, __FILE__, __LINE__, ##__VA_ARGS__)
-#define ERROR(format, ...) \
-  LOG_ERROR("%s:%d: " format, __FILE__, __LINE__, ##__VA_ARGS__)
-
 namespace nacl_io {
 
 JsFs::JsFs()
@@ -49,12 +44,12 @@ Error JsFs::Init(const FsInitArgs& args) {
 
   if (!messaging_iface_ || !array_iface_ || !buffer_iface_ || !dict_iface_ ||
       !var_iface_) {
-    ERROR("Got 1+ NULL interface(s): %s%s%s%s%s",
-          messaging_iface_ ? "" : "Messaging ",
-          array_iface_ ? "" : "VarArray ",
-          buffer_iface_ ? "" : "VarArrayBuffer ",
-          dict_iface_ ? "" : "VarDictionary ",
-          var_iface_ ? "" : "Var ");
+    LOG_ERROR("Got 1+ NULL interface(s): %s%s%s%s%s",
+              messaging_iface_ ? "" : "Messaging ",
+              array_iface_ ? "" : "VarArray ",
+              buffer_iface_ ? "" : "VarArrayBuffer ",
+              dict_iface_ ? "" : "VarDictionary ",
+              var_iface_ ? "" : "Var ");
     return ENOSYS;
   }
 
@@ -69,13 +64,13 @@ bool JsFs::SetDictVar(PP_Var dict, const char* key, PP_Var value) {
   PP_Var key_var = var_iface_->VarFromUtf8(key, strlen(key));
   ScopedVar scoped_key(ppapi_, key_var);
   if (key_var.type != PP_VARTYPE_STRING) {
-    ERROR("Unable to create string key \"%s\".", key);
+    LOG_ERROR("Unable to create string key \"%s\".", key);
     return false;
   }
 
   PP_Bool success = dict_iface_->Set(dict, key_var, value);
   if (!success) {
-    ERROR("Unable to set \"%s\" key of dictionary.", key);
+    LOG_ERROR("Unable to set \"%s\" key of dictionary.", key);
     return false;
   }
 
@@ -86,7 +81,7 @@ PP_Var JsFs::GetDictVar(PP_Var dict, const char* key) {
   PP_Var key_var = var_iface_->VarFromUtf8(key, strlen(key));
   ScopedVar scoped_key(ppapi_, key_var);
   if (key_var.type != PP_VARTYPE_STRING) {
-    ERROR("Unable to create string key \"%s\".", key);
+    LOG_ERROR("Unable to create string key \"%s\".", key);
     return PP_MakeUndefined();
   }
 
@@ -136,7 +131,7 @@ bool JsFs::GetVarInt64(PP_Var var, int64_t* out_value) {
     case PP_VARTYPE_ARRAY: {
       uint32_t len = array_iface_->GetLength(var);
       if (len != 2) {
-        ERROR("Expected int64 array type to have 2 elements, not %d", len);
+        LOG_ERROR("Expected int64 array type to have 2 elements, not %d", len);
         return false;
       }
 
@@ -190,7 +185,7 @@ PP_Var JsFs::VMakeRequest(RequestId request_id,
         const char* value = va_arg(args, const char*);
         value_var = var_iface_->VarFromUtf8(value, strlen(value));
         if (value_var.type != PP_VARTYPE_STRING) {
-          ERROR("Unable to create \"%s\" string var.", value);
+          LOG_ERROR("Unable to create \"%s\" string var.", value);
           return PP_MakeNull();
         }
         break;
@@ -214,18 +209,18 @@ PP_Var JsFs::VMakeRequest(RequestId request_id,
           // Send as an array of two ints: [high int32, low int32].
           value_var = array_iface_->Create();
           if (!array_iface_->SetLength(value_var, 2)) {
-            ERROR("Unable to set length of s64 array.");
+            LOG_ERROR("Unable to set length of s64 array.");
             return PP_MakeNull();
           }
 
           if (!array_iface_->Set(value_var, 0, PP_MakeInt32(value >> 32))) {
-            ERROR("Unable to set of high int32 of s64 array.");
+            LOG_ERROR("Unable to set of high int32 of s64 array.");
             return PP_MakeNull();
           }
 
           if (!array_iface_->Set(
                   value_var, 1, PP_MakeInt32(value & 0xffffffff))) {
-            ERROR("Unable to set of low int32 of s64 array.");
+            LOG_ERROR("Unable to set of low int32 of s64 array.");
             return PP_MakeNull();
           }
         }
@@ -233,7 +228,7 @@ PP_Var JsFs::VMakeRequest(RequestId request_id,
         break;
       }
       default:
-        ERROR("Unknown format specifier %%\"%s\"", p);
+        LOG_ERROR("Unknown format specifier %%\"%s\"", p);
         assert(0);
         return PP_MakeNull();
     }
@@ -292,7 +287,7 @@ bool JsFs::SendRequestAndWait(ScopedVar* out_response,
 Error JsFs::ErrorFromResponse(const ScopedVar& response) {
   int32_t error;
   if (ScanVar(response.pp_var(), "%d", "error", &error) != 1) {
-    ERROR("Expected \"error\" field in response.");
+    LOG_ERROR("Expected \"error\" field in response.");
     return EINVAL;
   }
 
@@ -309,7 +304,7 @@ int JsFs::ScanVar(PP_Var var, const char* format, ...) {
 
 int JsFs::VScanVar(PP_Var dict_var, const char* format, va_list args) {
   if (dict_var.type != PP_VARTYPE_DICTIONARY) {
-    ERROR("Expected var of type dictionary, not %d.", dict_var.type);
+    LOG_ERROR("Expected var of type dictionary, not %d.", dict_var.type);
     return 0;
   }
 
@@ -333,7 +328,7 @@ int JsFs::VScanVar(PP_Var dict_var, const char* format, va_list args) {
       case 'd': {
         int32_t* value = va_arg(args, int32_t*);
         if (!GetVarInt32(value_var, value)) {
-          ERROR("Expected int32_t value for key \"%s\"", key);
+          LOG_ERROR("Expected int32_t value for key \"%s\"", key);
           ok = false;
         }
         break;
@@ -341,7 +336,7 @@ int JsFs::VScanVar(PP_Var dict_var, const char* format, va_list args) {
       case 'u': {
         uint32_t* value = va_arg(args, uint32_t*);
         if (!GetVarUint32(value_var, value)) {
-          ERROR("Expected uint32_t value for key \"%s\"", key);
+          LOG_ERROR("Expected uint32_t value for key \"%s\"", key);
           ok = false;
         }
         break;
@@ -355,7 +350,7 @@ int JsFs::VScanVar(PP_Var dict_var, const char* format, va_list args) {
 
         int64_t* value = va_arg(args, int64_t*);
         if (!GetVarInt64(value_var, value)) {
-          ERROR("Expected int64_t value for key \"%s\"", key);
+          LOG_ERROR("Expected int64_t value for key \"%s\"", key);
           ok = false;
         }
         break;
@@ -366,7 +361,7 @@ int JsFs::VScanVar(PP_Var dict_var, const char* format, va_list args) {
         break;
       }
       default:
-        ERROR("Unknown format specifier %%\"%s\"", p);
+        LOG_ERROR("Unknown format specifier %%\"%s\"", p);
         assert(0);
         ok = false;
         break;
@@ -402,7 +397,7 @@ Error JsFs::Access(const Path& path, int a_mode) {
                           "cmd", "access",
                           "path", path.Join().c_str(),
                           "amode", a_mode)) {
-    ERROR("Failed to send request.");
+    LOG_ERROR("Failed to send request.");
     return EINVAL;
   }
 
@@ -416,7 +411,7 @@ Error JsFs::Open(const Path& path, int open_flags, ScopedNode* out_node) {
                           "cmd", "open",
                           "path", path.Join().c_str(),
                           "oflag", open_flags)) {
-    ERROR("Failed to send request.");
+    LOG_ERROR("Failed to send request.");
     return EINVAL;
   }
 
@@ -427,7 +422,7 @@ Error JsFs::Open(const Path& path, int open_flags, ScopedNode* out_node) {
     return error;
 
   if (result != 2) {
-    ERROR("Expected \"error\" and \"fd\" fields in response.");
+    LOG_ERROR("Expected \"error\" and \"fd\" fields in response.");
     return EINVAL;
   }
 
@@ -439,7 +434,7 @@ Error JsFs::Unlink(const Path& path) {
   ScopedVar response(ppapi_);
   if (!SendRequestAndWait(
           &response, "%s%s", "cmd", "unlink", "path", path.Join().c_str())) {
-    ERROR("Failed to send request.");
+    LOG_ERROR("Failed to send request.");
     return EINVAL;
   }
 
@@ -452,7 +447,7 @@ Error JsFs::Mkdir(const Path& path, int perm) {
                           "cmd", "mkdir",
                           "path", path.Join().c_str(),
                           "mode", perm)) {
-    ERROR("Failed to send request.");
+    LOG_ERROR("Failed to send request.");
     return EINVAL;
   }
 
@@ -463,7 +458,7 @@ Error JsFs::Rmdir(const Path& path) {
   ScopedVar response(ppapi_);
   if (!SendRequestAndWait(
           &response, "%s%s", "cmd", "rmdir", "path", path.Join().c_str())) {
-    ERROR("Failed to send request.");
+    LOG_ERROR("Failed to send request.");
     return EINVAL;
   }
 
@@ -474,7 +469,7 @@ Error JsFs::Remove(const Path& path) {
   ScopedVar response(ppapi_);
   if (!SendRequestAndWait(
           &response, "%s%s", "cmd", "remove", "path", path.Join().c_str())) {
-    ERROR("Failed to send request.");
+    LOG_ERROR("Failed to send request.");
     return EINVAL;
   }
 
@@ -487,7 +482,7 @@ Error JsFs::Rename(const Path& path, const Path& newpath) {
                           "cmd", "rename",
                           "old", path.Join().c_str(),
                           "new", newpath.Join().c_str())) {
-    ERROR("Failed to send request.");
+    LOG_ERROR("Failed to send request.");
     return EINVAL;
   }
 
@@ -496,7 +491,7 @@ Error JsFs::Rename(const Path& path, const Path& newpath) {
 
 Error JsFs::Filesystem_VIoctl(int request, va_list args) {
   if (request != NACL_IOC_HANDLEMESSAGE) {
-    ERROR("Unknown ioctl: %#x", request);
+    LOG_ERROR("Unknown ioctl: %#x", request);
     return EINVAL;
   }
 
@@ -506,7 +501,7 @@ Error JsFs::Filesystem_VIoctl(int request, va_list args) {
 
   RequestId response_id;
   if (ScanVar(response, "%d", "id", &response_id) != 1) {
-    TRACE("ioctl with no \"id\", ignoring.\n");
+    LOG_TRACE("ioctl with no \"id\", ignoring.\n");
     return EINVAL;
   }
 
diff --git a/native_client_sdk/src/libraries/nacl_io/jsfs/js_fs_node.cc b/native_client_sdk/src/libraries/nacl_io/jsfs/js_fs_node.cc
index 166bf79..8e6f16c 100644
--- a/native_client_sdk/src/libraries/nacl_io/jsfs/js_fs_node.cc
+++ b/native_client_sdk/src/libraries/nacl_io/jsfs/js_fs_node.cc
@@ -17,12 +17,6 @@
 #include "nacl_io/pepper_interface.h"
 #include "sdk_util/macros.h"
 
-#define TRACE(format, ...) \
-  LOG_TRACE("%s:%d: " format, __FILE__, __LINE__, ##__VA_ARGS__)
-#define ERROR(format, ...) \
-  LOG_ERROR("%s:%d: " format, __FILE__, __LINE__, ##__VA_ARGS__)
-
-
 namespace nacl_io {
 
 JsFsNode::JsFsNode(Filesystem* filesystem, int32_t fd)
@@ -72,7 +66,7 @@ Error JsFsNode::GetStat(struct stat* stat) {
 
   ScopedVar response(ppapi_);
   if (!SendRequestAndWait(&response, "%s%d", "cmd", "fstat", "fildes", fd_)) {
-    ERROR("Failed to send request.");
+    LOG_ERROR("Failed to send request.");
     return EINVAL;
   }
 
@@ -127,7 +121,7 @@ const char* format = "%d%lld%d%d%d%d%lld%lld%d%d%lld%lld%lld";
     return error;
 
   if (result != 13) {
-    ERROR(
+    LOG_ERROR(
         "Expected \"st_*\" and \"error\" fields in response (should be 13 "
         "total).");
     return EINVAL;
@@ -155,7 +149,7 @@ Error JsFsNode::FSync() {
 
   ScopedVar response(ppapi_);
   if (!SendRequestAndWait(&response, "%s%d", "cmd", "fsync", "fildes", fd_)) {
-    ERROR("Failed to send request.");
+    LOG_ERROR("Failed to send request.");
     return EINVAL;
   }
 
@@ -168,7 +162,7 @@ Error JsFsNode::FTruncate(off_t length) {
   ScopedVar response(ppapi_);
   if (!SendRequestAndWait(&response,
       "%s%d%lld", "cmd", "ftruncate", "fildes", fd_, "length", length)) {
-    ERROR("Failed to send request.");
+    LOG_ERROR("Failed to send request.");
     return EINVAL;
   }
 
@@ -189,7 +183,7 @@ Error JsFsNode::Read(const HandleAttr& attr,
                           "fildes", fd_,
                           "nbyte", count,
                           "offset", attr.offs)) {
-    ERROR("Failed to send request.");
+    LOG_ERROR("Failed to send request.");
     return EINVAL;
   }
 
@@ -204,18 +198,18 @@ Error JsFsNode::Read(const HandleAttr& attr,
     return error;
 
   if (result != 2) {
-    ERROR("Expected \"error\" and \"buf\" fields in response.");
+    LOG_ERROR("Expected \"error\" and \"buf\" fields in response.");
     return EINVAL;
   }
 
   if (buf_var.type != PP_VARTYPE_ARRAY_BUFFER) {
-    ERROR("Expected \"buf\" to be an ArrayBuffer.");
+    LOG_ERROR("Expected \"buf\" to be an ArrayBuffer.");
     return EINVAL;
   }
 
   uint32_t src_buf_len;
   if (!buffer_iface_->ByteLength(buf_var, &src_buf_len)) {
-    ERROR("Unable to get byteLength of \"buf\".");
+    LOG_ERROR("Unable to get byteLength of \"buf\".");
     return EINVAL;
   }
 
@@ -224,7 +218,7 @@ Error JsFsNode::Read(const HandleAttr& attr,
 
   void* src_buf = buffer_iface_->Map(buf_var);
   if (src_buf == NULL) {
-    ERROR("Unable to map \"buf\".");
+    LOG_ERROR("Unable to map \"buf\".");
     return EINVAL;
   }
 
@@ -248,13 +242,13 @@ Error JsFsNode::Write(const HandleAttr& attr,
   ScopedVar scoped_buf_var(ppapi_, buf_var);
 
   if (buf_var.type != PP_VARTYPE_ARRAY_BUFFER) {
-    ERROR("Unable to create \"buf\" var.");
+    LOG_ERROR("Unable to create \"buf\" var.");
     return EINVAL;
   }
 
   void* dst_buf = buffer_iface_->Map(buf_var);
   if (dst_buf == NULL) {
-    ERROR("Unable to map \"buf\".");
+    LOG_ERROR("Unable to map \"buf\".");
     return EINVAL;
   }
 
@@ -269,7 +263,7 @@ Error JsFsNode::Write(const HandleAttr& attr,
                           "buf", &buf_var,
                           "nbyte", count,
                           "offset", attr.offs)) {
-    ERROR("Failed to send request.");
+    LOG_ERROR("Failed to send request.");
     return EINVAL;
   }
 
@@ -282,7 +276,7 @@ Error JsFsNode::Write(const HandleAttr& attr,
     return error;
 
   if (result != 2) {
-    ERROR("Expected \"error\" and \"nwrote\" fields in response.");
+    LOG_ERROR("Expected \"error\" and \"nwrote\" fields in response.");
     return EINVAL;
   }
 
@@ -308,7 +302,7 @@ Error JsFsNode::GetDents(size_t offs,
                           "fildes", fd_,
                           "offs", first,
                           "count", last - first)) {
-    ERROR("Failed to send request.");
+    LOG_ERROR("Failed to send request.");
     return EINVAL;
   }
 
@@ -323,12 +317,12 @@ Error JsFsNode::GetDents(size_t offs,
     return error;
 
   if (result != 2) {
-    ERROR("Expected \"error\" and \"dirents\" fields in response.");
+    LOG_ERROR("Expected \"error\" and \"dirents\" fields in response.");
     return EINVAL;
   }
 
   if (dirents_var.type != PP_VARTYPE_ARRAY) {
-    ERROR("Expected \"dirents\" to be an Array.");
+    LOG_ERROR("Expected \"dirents\" to be an Array.");
     return EINVAL;
   }
 
@@ -350,7 +344,7 @@ Error JsFsNode::GetDents(size_t offs,
     ScopedVar scoped_d_name_var(ppapi_, d_name_var);
 
     if (result != 2) {
-      ERROR("Expected dirent[%d] to have \"d_ino\" and \"d_name\".", i);
+      LOG_ERROR("Expected dirent[%d] to have \"d_ino\" and \"d_name\".", i);
       free(dirents);
       return EINVAL;
     }
diff --git a/native_client_sdk/src/libraries/nacl_io/kernel_handle.cc b/native_client_sdk/src/libraries/nacl_io/kernel_handle.cc
index 29c4890..5c5bcc10 100644
--- a/native_client_sdk/src/libraries/nacl_io/kernel_handle.cc
+++ b/native_client_sdk/src/libraries/nacl_io/kernel_handle.cc
@@ -151,6 +151,9 @@ Error KernelHandle::VFcntl(int request, int* result, va_list args) {
       handle_attr_.flags |= flags;
       return 0;
     }
+    default:
+      LOG_ERROR("Unsupported fcntl: %#x", request);
+      break;
   }
   return ENOSYS;
 }
diff --git a/native_client_sdk/src/libraries/nacl_io/kernel_object.cc b/native_client_sdk/src/libraries/nacl_io/kernel_object.cc
index 81e5729..69cd7ab 100644
--- a/native_client_sdk/src/libraries/nacl_io/kernel_object.cc
+++ b/native_client_sdk/src/libraries/nacl_io/kernel_object.cc
@@ -16,6 +16,7 @@
 
 #include "nacl_io/filesystem.h"
 #include "nacl_io/kernel_handle.h"
+#include "nacl_io/log.h"
 #include "nacl_io/node.h"
 
 #include "sdk_util/auto_lock.h"
@@ -35,8 +36,10 @@ Error KernelObject::AttachFsAtPath(const ScopedFilesystem& fs,
   std::string abs_path = GetAbsParts(path).Join();
 
   AUTO_LOCK(fs_lock_);
-  if (filesystems_.find(abs_path) != filesystems_.end())
+  if (filesystems_.find(abs_path) != filesystems_.end()) {
+    LOG_ERROR("Can't mount at %s, it is already mounted.", path.c_str());
     return EBUSY;
+  }
 
   filesystems_[abs_path] = fs;
   return 0;
@@ -48,12 +51,16 @@ Error KernelObject::DetachFsAtPath(const std::string& path,
 
   AUTO_LOCK(fs_lock_);
   FsMap_t::iterator it = filesystems_.find(abs_path);
-  if (filesystems_.end() == it)
+  if (filesystems_.end() == it) {
+    LOG_TRACE("Can't unmount at %s, nothing is mounted.", path.c_str());
     return EINVAL;
+  }
 
   // It is only legal to unmount if there are no open references
-  if (it->second->RefCount() != 1)
+  if (it->second->RefCount() != 1) {
+    LOG_TRACE("Can't unmount at %s, refcount is != 1.", path.c_str());
     return EBUSY;
+  }
 
   *out_fs = it->second;
 
diff --git a/native_client_sdk/src/libraries/nacl_io/kernel_proxy.cc b/native_client_sdk/src/libraries/nacl_io/kernel_proxy.cc
index 147c386..b709e29 100644
--- a/native_client_sdk/src/libraries/nacl_io/kernel_proxy.cc
+++ b/native_client_sdk/src/libraries/nacl_io/kernel_proxy.cc
@@ -418,8 +418,10 @@ Error KernelProxy::MountInternal(const char* source,
 
   // Find a factory of that type
   FsFactoryMap_t::iterator factory = factories_.find(filesystemtype);
-  if (factory == factories_.end())
+  if (factory == factories_.end()) {
+    LOG_ERROR("Unknown filesystem type: %s", filesystemtype);
     return ENODEV;
+  }
 
   // Create a map of settings
   StringMap_t smap;
@@ -459,8 +461,10 @@ Error KernelProxy::MountInternal(const char* source,
 
   if (create_fs_node) {
     error = CreateFsNode(fs);
-    if (error)
+    if (error) {
+      DetachFsAtPath(abs_path, &fs);
       return error;
+    }
   }
 
   *out_filesystem = fs;
@@ -840,22 +844,26 @@ int KernelProxy::access(const char* path, int amode) {
 }
 
 int KernelProxy::readlink(const char* path, char* buf, size_t count) {
+  LOG_TRACE("readlink is not implemented.");
   errno = EINVAL;
   return -1;
 }
 
 int KernelProxy::utimes(const char* filename, const struct timeval times[2]) {
+  LOG_TRACE("utimes is not implemented.");
   errno = EINVAL;
   return -1;
 }
 
 // TODO(noelallen): Needs implementation.
 int KernelProxy::link(const char* oldpath, const char* newpath) {
+  LOG_TRACE("link is not implemented.");
   errno = EINVAL;
   return -1;
 }
 
 int KernelProxy::symlink(const char* oldpath, const char* newpath) {
+  LOG_TRACE("symlink is not implemented.");
   errno = EINVAL;
   return -1;
 }
@@ -1001,6 +1009,7 @@ int KernelProxy::kill(pid_t pid, int sig) {
       break;
 
     default:
+      LOG_TRACE("Unsupported signal: %d", sig);
       errno = EINVAL;
       return -1;
   }
@@ -1044,6 +1053,7 @@ int KernelProxy::sigaction(int signum,
       if (action && action->sa_handler != SIG_DFL) {
         // Trying to set this action to anything other than SIG_DFL
         // is not yet supported.
+        LOG_TRACE("sigaction on signal %d != SIG_DFL not supported.", sig);
         errno = EINVAL;
         return -1;
       }
@@ -1057,6 +1067,7 @@ int KernelProxy::sigaction(int signum,
     // KILL and STOP cannot be handled
     case SIGKILL:
     case SIGSTOP:
+      LOG_TRACE("sigaction on SIGKILL/SIGSTOP not supported.");
       errno = EINVAL;
       return -1;
   }
@@ -1109,6 +1120,9 @@ int KernelProxy::select(int nfds,
     if ((timeout->tv_sec < 0) || (timeout->tv_sec >= (INT_MAX / 1000)) ||
         (timeout->tv_usec < 0) || (timeout->tv_usec >= 1000000) || (ms < 0) ||
         (ms >= INT_MAX)) {
+      LOG_TRACE("Invalid timeout: tv_sec=%d tv_usec=%d.",
+                timeout->tv_sec,
+                timeout->tv_usec);
       errno = EINVAL;
       return -1;
     }
diff --git a/native_client_sdk/src/libraries/nacl_io/log.h b/native_client_sdk/src/libraries/nacl_io/log.h
index 8c9ce8d..beffe1b 100644
--- a/native_client_sdk/src/libraries/nacl_io/log.h
+++ b/native_client_sdk/src/libraries/nacl_io/log.h
@@ -9,18 +9,38 @@
 
 #define LOG_PREFIX "nacl_io: "
 
+#if defined(NDEBUG)
+
+#define LOG_TRACE(format, ...)
+#define LOG_ERROR(format, ...)
+#define LOG_WARN(format, ...)
+
+#else
+
 #if NACL_IO_LOGGING
+
 #define LOG_TRACE(format, ...) \
   nacl_io_log(LOG_PREFIX format "\n", ##__VA_ARGS__)
+
 #else
+
 #define LOG_TRACE(format, ...)
+
 #endif
 
-#define LOG_ERROR(format, ...) \
-  nacl_io_log(LOG_PREFIX "error: " format "\n", ##__VA_ARGS__)
+#define LOG_ERROR(format, ...)                         \
+  nacl_io_log(LOG_PREFIX "%s:%d: error: " format "\n", \
+              __FILE__,                                \
+              __LINE__,                                \
+              ##__VA_ARGS__)
 
-#define LOG_WARN(format, ...) \
-  nacl_io_log(LOG_PREFIX "warning: " format "\n", ##__VA_ARGS__)
+#define LOG_WARN(format, ...)                            \
+  nacl_io_log(LOG_PREFIX "%s:%d: warning: " format "\n", \
+              __FILE__,                                  \
+              __LINE__,                                  \
+              ##__VA_ARGS__)
+
+#endif
 
 EXTERN_C_BEGIN
 
diff --git a/native_client_sdk/src/libraries/nacl_io/socket/tcp_node.cc b/native_client_sdk/src/libraries/nacl_io/socket/tcp_node.cc
index 28915aa..df7c867 100644
--- a/native_client_sdk/src/libraries/nacl_io/socket/tcp_node.cc
+++ b/native_client_sdk/src/libraries/nacl_io/socket/tcp_node.cc
@@ -11,6 +11,7 @@
 #include <algorithm>
 
 #include "nacl_io/kernel_handle.h"
+#include "nacl_io/log.h"
 #include "nacl_io/pepper_interface.h"
 #include "nacl_io/socket/tcp_node.h"
 #include "nacl_io/stream/stream_fs.h"
@@ -287,8 +288,10 @@ Error TcpNode::Init(int open_flags) {
   if (err != 0)
     return err;
 
-  if (TCPInterface() == NULL)
+  if (TCPInterface() == NULL) {
+    LOG_ERROR("Got NULL interface: TCP");
     return EACCES;
+  }
 
   if (socket_resource_ != 0) {
     // TCP sockets that are contructed with an existing socket_resource_
@@ -299,8 +302,10 @@ Error TcpNode::Init(int open_flags) {
   } else {
     socket_resource_ =
         TCPInterface()->Create(filesystem_->ppapi()->GetInstance());
-    if (0 == socket_resource_)
+    if (0 == socket_resource_) {
+      LOG_ERROR("Unable to create TCP resource.");
       return EACCES;
+    }
     SetStreamFlags(SSF_CAN_CONNECT);
   }
 
@@ -483,6 +488,7 @@ Error TcpNode::Shutdown(int how) {
   AUTO_LOCK(node_lock_);
   if (!IsConnected())
     return ENOTCONN;
+
   {
     AUTO_LOCK(emitter_->GetLock());
     emitter_->SetError_Locked();
diff --git a/native_client_sdk/src/libraries/nacl_io/socket/udp_node.cc b/native_client_sdk/src/libraries/nacl_io/socket/udp_node.cc
index 582286d..816f8e9 100644
--- a/native_client_sdk/src/libraries/nacl_io/socket/udp_node.cc
+++ b/native_client_sdk/src/libraries/nacl_io/socket/udp_node.cc
@@ -9,6 +9,7 @@
 
 #include <algorithm>
 
+#include "nacl_io/log.h"
 #include "nacl_io/pepper_interface.h"
 #include "nacl_io/socket/packet.h"
 #include "nacl_io/socket/udp_event_emitter.h"
@@ -169,13 +170,17 @@ Error UdpNode::Init(int open_flags) {
   if (err != 0)
     return err;
 
-  if (UDPInterface() == NULL)
+  if (UDPInterface() == NULL) {
+    LOG_ERROR("Got NULL interface: UDP");
     return EACCES;
+  }
 
   socket_resource_ =
       UDPInterface()->Create(filesystem_->ppapi()->GetInstance());
-  if (0 == socket_resource_)
+  if (0 == socket_resource_) {
+    LOG_ERROR("Unable to create UDP resource.");
     return EACCES;
+  }
 
   return 0;
 }