Fix sdcard logging.
Use C++ logging for everything.
Bug: 30222003
Change-Id: I5c5d85102b01df6965a515b59aa275ac85f50f00
diff --git a/sdcard/Android.mk b/sdcard/Android.mk
index 992b51c..0c58574 100644
--- a/sdcard/Android.mk
+++ b/sdcard/Android.mk
@@ -5,7 +5,7 @@
LOCAL_SRC_FILES := sdcard.cpp fuse.cpp
LOCAL_MODULE := sdcard
LOCAL_CFLAGS := -Wall -Wno-unused-parameter -Werror
-LOCAL_SHARED_LIBRARIES := libbase liblog libcutils libminijail libpackagelistparser
+LOCAL_SHARED_LIBRARIES := libbase libcutils libminijail libpackagelistparser
LOCAL_SANITIZE := integer
LOCAL_CLANG := true
diff --git a/sdcard/fuse.cpp b/sdcard/fuse.cpp
index 03ca4dc..47e4257 100644
--- a/sdcard/fuse.cpp
+++ b/sdcard/fuse.cpp
@@ -39,18 +39,20 @@
static void acquire_node_locked(struct node* node)
{
node->refcount++;
- TRACE("ACQUIRE %p (%s) rc=%d\n", node, node->name, node->refcount);
+ DLOG(INFO) << "ACQUIRE " << std::hex << node << std::dec
+ << " (" << node->name << ") rc=" << node->refcount;
}
static void remove_node_from_parent_locked(struct node* node);
static void release_node_locked(struct node* node)
{
- TRACE("RELEASE %p (%s) rc=%d\n", node, node->name, node->refcount);
+ DLOG(INFO) << "RELEASE " << std::hex << node << std::dec
+ << " (" << node->name << ") rc=" << node->refcount;
if (node->refcount > 0) {
node->refcount--;
if (!node->refcount) {
- TRACE("DESTROY %p (%s)\n", node, node->name);
+ DLOG(INFO) << "DESTROY " << std::hex << node << std::dec << " (" << node->name << ")";
remove_node_from_parent_locked(node);
/* TODO: remove debugging - poison memory */
@@ -61,7 +63,7 @@
free(node);
}
} else {
- ERROR("Zero refcnt %p\n", node);
+ LOG(ERROR) << std::hex << node << std::dec << " refcount=0";
}
}
@@ -155,7 +157,7 @@
struct dirent* entry;
DIR* dir = opendir(path);
if (!dir) {
- ERROR("opendir %s failed: %s\n", path, strerror(errno));
+ PLOG(ERROR) << "opendir(" << path << ") failed";
return actual;
}
while ((entry = readdir(dir))) {
@@ -223,7 +225,7 @@
if (errno == EEXIST) {
return 0;
} else {
- ERROR("Failed to open(%s): %s\n", path, strerror(errno));
+ PLOG(ERROR) << "open(" << path << ") failed";
return -1;
}
}
@@ -335,7 +337,7 @@
// Detect overflows in the inode counter. "4 billion nodes should be enough
// for everybody".
if (fuse->global->inode_ctr == 0) {
- ERROR("No more inode numbers available");
+ LOG(ERROR) << "No more inode numbers available";
return NULL;
}
@@ -484,7 +486,7 @@
res = writev(fuse->fd, vec, 2);
if (res < 0) {
- ERROR("*** REPLY FAILED *** %d\n", errno);
+ PLOG(ERROR) << "*** REPLY FAILED ***";
}
}
@@ -560,7 +562,7 @@
res = writev(fuse->fd, vec, 3);
/* Ignore ENOENT, since other views may not have seen the entry */
if (res < 0 && errno != ENOENT) {
- ERROR("*** NOTIFY FAILED *** %d\n", errno);
+ PLOG(ERROR) << "*** NOTIFY FAILED ***";
}
}
@@ -620,7 +622,7 @@
pthread_mutex_lock(&fuse->global->lock);
node = lookup_node_and_path_by_id_locked(fuse, hdr->nodeid, path, sizeof(path));
DLOG(INFO) << "[" << handler->token << "] GETATTR flags=" << req->getattr_flags
- << " fh=" << std::hex << req->fh << " @ " << std::hex << hdr->nodeid
+ << " fh=" << std::hex << req->fh << " @ " << hdr->nodeid << std::dec
<< " (" << (node ? node->name : "?") << ")";
pthread_mutex_unlock(&fuse->global->lock);
@@ -644,7 +646,7 @@
pthread_mutex_lock(&fuse->global->lock);
node = lookup_node_and_path_by_id_locked(fuse, hdr->nodeid, path, sizeof(path));
DLOG(INFO) << "[" << handler->token << "] SETATTR fh=" << std::hex << req->fh
- << " valid=" << std::hex << req->valid << " @ " << std::hex << hdr->nodeid
+ << " valid=" << std::hex << req->valid << " @ " << hdr->nodeid << std::dec
<< " (" << (node ? node->name : "?") << ")";
pthread_mutex_unlock(&fuse->global->lock);
@@ -689,8 +691,8 @@
times[1].tv_nsec = req->mtimensec;
}
}
- TRACE("[%d] Calling utimensat on %s with atime %ld, mtime=%ld\n",
- handler->token, path, times[0].tv_sec, times[1].tv_sec);
+ DLOG(INFO) << "[" << handler->token << "] Calling utimensat on " << path
+ << " with atime " << times[0].tv_sec << ", mtime=" << times[1].tv_sec;
if (utimensat(-1, path, times, 0) < 0) {
return -errno;
}
@@ -761,7 +763,7 @@
char nomedia[PATH_MAX];
snprintf(nomedia, PATH_MAX, "%s/.nomedia", child_path);
if (touch(nomedia, 0664) != 0) {
- ERROR("Failed to touch(%s): %s\n", nomedia, strerror(errno));
+ PLOG(ERROR) << "touch(" << nomedia << ") failed";
return -ENOENT;
}
}
@@ -769,7 +771,7 @@
char nomedia[PATH_MAX];
snprintf(nomedia, PATH_MAX, "%s/.nomedia", fuse->global->obb_path);
if (touch(nomedia, 0664) != 0) {
- ERROR("Failed to touch(%s): %s\n", nomedia, strerror(errno));
+ PLOG(ERROR) << "touch(" << nomedia << ") failed";
return -ENOENT;
}
}
@@ -812,7 +814,8 @@
/* Tell all other views that node is gone */
DLOG(INFO) << "[" << handler->token << "] fuse_notify_delete"
<< " parent=" << std::hex << parent_node->nid
- << ", child=" << std::hex << child_node->nid << ", name=" << name;
+ << ", child=" << std::hex << child_node->nid << std::dec
+ << ", name=" << name;
if (fuse != fuse->global->fuse_default) {
fuse_notify_delete(fuse->global->fuse_default, parent_node->nid, child_node->nid, name);
}
@@ -861,7 +864,8 @@
/* Tell all other views that node is gone */
DLOG(INFO) << "[" << handler->token << "] fuse_notify_delete"
<< " parent=" << std::hex << parent_node->nid
- << ", child=" << std::hex << child_node->nid << ", name=" << name;
+ << ", child=" << std::hex << child_node->nid << std::dec
+ << ", name=" << name;
if (fuse != fuse->global->fuse_default) {
fuse_notify_delete(fuse->global->fuse_default, parent_node->nid, child_node->nid, name);
}
@@ -933,7 +937,7 @@
goto io_error;
}
- TRACE("[%d] RENAME %s->%s\n", handler->token, old_child_path, new_child_path);
+ DLOG(INFO) << "[" << handler->token << "] RENAME " << old_child_path << "->" << new_child_path;
res = rename(old_child_path, new_child_path);
if (res < 0) {
res = -errno;
@@ -981,7 +985,8 @@
pthread_mutex_lock(&fuse->global->lock);
node = lookup_node_and_path_by_id_locked(fuse, hdr->nodeid, path, sizeof(path));
DLOG(INFO) << "[" << handler->token << "] OPEN 0" << std::oct << req->flags
- << " @ " << std::hex << hdr->nodeid << " (" << (node ? node->name : "?") << ")";
+ << " @ " << std::hex << hdr->nodeid << std::dec
+ << " (" << (node ? node->name : "?") << ")";
pthread_mutex_unlock(&fuse->global->lock);
if (!node) {
@@ -995,7 +1000,7 @@
if (!h) {
return -ENOMEM;
}
- TRACE("[%d] OPEN %s\n", handler->token, path);
+ DLOG(INFO) << "[" << handler->token << "] OPEN " << path;
h->fd = open(path, req->flags);
if (h->fd < 0) {
free(h);
@@ -1028,8 +1033,8 @@
* overlaps the request buffer and will clobber data in the request. This
* saves us 128KB per request handler thread at the cost of this scary comment. */
- DLOG(INFO) << "[" << handler->token << "] READ " << std::hex << h << "(" << h->fd << ") "
- << size << "@" << offset;
+ DLOG(INFO) << "[" << handler->token << "] READ " << std::hex << h << std::dec
+ << "(" << h->fd << ") " << size << "@" << offset;
if (size > MAX_READ) {
return -EINVAL;
}
@@ -1055,8 +1060,8 @@
buffer = (const __u8*) aligned_buffer;
}
- DLOG(INFO) << "[" << handler->token << "] WRITE " << std::hex << h << "(" << h->fd << ") "
- << req->size << "@" << req->offset;
+ DLOG(INFO) << "[" << handler->token << "] WRITE " << std::hex << h << std::dec
+ << "(" << h->fd << ") " << req->size << "@" << req->offset;
res = pwrite64(h->fd, buffer, req->size, req->offset);
if (res < 0) {
return -errno;
@@ -1076,7 +1081,7 @@
int res;
pthread_mutex_lock(&fuse->global->lock);
- TRACE("[%d] STATFS\n", handler->token);
+ DLOG(INFO) << "[" << handler->token << "] STATFS";
res = get_node_path_locked(&fuse->global->root, path, sizeof(path));
pthread_mutex_unlock(&fuse->global->lock);
if (res < 0) {
@@ -1103,7 +1108,8 @@
{
struct handle *h = static_cast<struct handle*>(id_to_ptr(req->fh));
- TRACE("[%d] RELEASE %p(%d)\n", handler->token, h, h->fd);
+ DLOG(INFO) << "[" << handler->token << "] RELEASE " << std::hex << h << std::dec
+ << "(" << h->fd << ")";
close(h->fd);
free(h);
return 0;
@@ -1124,9 +1130,8 @@
fd = h->fd;
}
- TRACE("[%d] %s %p(%d) is_data_sync=%d\n", handler->token,
- is_dir ? "FSYNCDIR" : "FSYNC",
- static_cast<struct node*>(id_to_ptr(req->fh)), fd, is_data_sync);
+ DLOG(INFO) << "[" << handler->token << "] " << (is_dir ? "FSYNCDIR" : "FSYNC") << " "
+ << std::hex << req->fh << std::dec << "(" << fd << ") is_data_sync=" << is_data_sync;
int res = is_data_sync ? fdatasync(fd) : fsync(fd);
if (res == -1) {
return -errno;
@@ -1137,7 +1142,7 @@
static int handle_flush(struct fuse* fuse, struct fuse_handler* handler,
const struct fuse_in_header* hdr)
{
- TRACE("[%d] FLUSH\n", handler->token);
+ DLOG(INFO) << "[" << handler->token << "] FLUSH";
return 0;
}
@@ -1165,7 +1170,7 @@
if (!h) {
return -ENOMEM;
}
- TRACE("[%d] OPENDIR %s\n", handler->token, path);
+ DLOG(INFO) << "[" << handler->token << "] OPENDIR " << path;
h->d = opendir(path);
if (!h->d) {
free(h);
@@ -1192,10 +1197,10 @@
struct dirent *de;
struct dirhandle *h = static_cast<struct dirhandle*>(id_to_ptr(req->fh));
- TRACE("[%d] READDIR %p\n", handler->token, h);
+ DLOG(INFO) << "[" << handler->token << "] READDIR " << h;
if (req->offset == 0) {
/* rewinddir() might have been called above us, so rewind here too */
- TRACE("[%d] calling rewinddir()\n", handler->token);
+ DLOG(INFO) << "[" << handler->token << "] calling rewinddir()";
rewinddir(h->d);
}
de = readdir(h->d);
@@ -1218,7 +1223,7 @@
{
struct dirhandle *h = static_cast<struct dirhandle*>(id_to_ptr(req->fh));
- TRACE("[%d] RELEASEDIR %p\n", handler->token, h);
+ DLOG(INFO) << "[" << handler->token << "] RELEASEDIR " << h;
closedir(h->d);
free(h);
return 0;
@@ -1230,8 +1235,8 @@
struct fuse_init_out out;
size_t fuse_struct_size;
- TRACE("[%d] INIT ver=%d.%d maxread=%d flags=%x\n",
- handler->token, req->major, req->minor, req->max_readahead, req->flags);
+ DLOG(INFO) << "[" << handler->token << "] INIT ver=" << req->major << "." << req->minor
+ << " maxread=" << req->max_readahead << " flags=" << std::hex << req->flags;
/* Kernel 2.6.16 is the first stable kernel with struct fuse_init_out
* defined (fuse version 7.6). The structure is the same from 7.6 through
@@ -1239,8 +1244,9 @@
* new parameters.
*/
if (req->major != FUSE_KERNEL_VERSION || req->minor < 6) {
- ERROR("Fuse kernel version mismatch: Kernel version %d.%d, Expected at least %d.6",
- req->major, req->minor, FUSE_KERNEL_VERSION);
+ LOG(ERROR) << "Fuse kernel version mismatch: Kernel version "
+ << req->major << "." << req->minor
+ << ", Expected at least " << FUSE_KERNEL_VERSION << ".6";
return -1;
}
@@ -1390,7 +1396,7 @@
default: {
DLOG(INFO) << "[" << handler->token << "] NOTIMPL op=" << hdr->opcode
- << "uniq=" << std::hex << hdr->unique << "nid=" << std::hex << hdr->nodeid;
+ << "uniq=" << std::hex << hdr->unique << "nid=" << hdr->nodeid << std::dec;
return -ENOSYS;
}
}
@@ -1404,23 +1410,23 @@
handler->request_buffer, sizeof(handler->request_buffer)));
if (len < 0) {
if (errno == ENODEV) {
- ERROR("[%d] someone stole our marbles!\n", handler->token);
+ LOG(ERROR) << "[" << handler->token << "] someone stole our marbles!";
exit(2);
}
- ERROR("[%d] handle_fuse_requests: errno=%d\n", handler->token, errno);
+ PLOG(ERROR) << "[" << handler->token << "] handle_fuse_requests";
continue;
}
if ((size_t)len < sizeof(struct fuse_in_header)) {
- ERROR("[%d] request too short: len=%zu\n", handler->token, (size_t)len);
+ LOG(ERROR) << "[" << handler->token << "] request too short: len=" << len;
continue;
}
const struct fuse_in_header* hdr =
reinterpret_cast<const struct fuse_in_header*>(handler->request_buffer);
if (hdr->len != (size_t)len) {
- ERROR("[%d] malformed header: len=%zu, hdr->len=%u\n",
- handler->token, (size_t)len, hdr->len);
+ LOG(ERROR) << "[" << handler->token << "] malformed header: len=" << len
+ << ", hdr->len=" << hdr->len;
continue;
}
@@ -1434,7 +1440,7 @@
if (res != NO_STATUS) {
if (res) {
- TRACE("[%d] ERROR %d\n", handler->token, res);
+ DLOG(INFO) << "[" << handler->token << "] ERROR " << res;
}
fuse_status(fuse, unique, res);
}
diff --git a/sdcard/fuse.h b/sdcard/fuse.h
index 9dafa79..9ccd21d 100644
--- a/sdcard/fuse.h
+++ b/sdcard/fuse.h
@@ -35,7 +35,6 @@
#include <android-base/logging.h>
#include <cutils/fs.h>
-#include <cutils/log.h>
#include <cutils/multiuser.h>
#include <packagelistparser/packagelistparser.h>
@@ -44,10 +43,8 @@
#define FUSE_TRACE 0
#if FUSE_TRACE
-#define TRACE(x...) ALOGD(x)
static constexpr bool kEnableDLog = true;
#else // FUSE_TRACE == 0
-#define TRACE(x...) do {} while (0)
static constexpr bool kEnableDLog = false;
#endif
@@ -55,8 +52,6 @@
#define DLOG(x) \
if (kEnableDLog) LOG(x)
-#define ERROR(x...) ALOGE(x)
-
/* Maximum number of bytes to write in one request. */
#define MAX_WRITE (256 * 1024)
diff --git a/sdcard/sdcard.cpp b/sdcard/sdcard.cpp
index 3d7bdc9..3481ec3 100644
--- a/sdcard/sdcard.cpp
+++ b/sdcard/sdcard.cpp
@@ -32,7 +32,6 @@
#include <android-base/macros.h>
#include <cutils/fs.h>
-#include <cutils/log.h>
#include <cutils/multiuser.h>
#include <packagelistparser/packagelistparser.h>
@@ -89,8 +88,7 @@
global->package_to_appid->clear();
bool rc = packagelist_parse(package_parse_callback, global);
- TRACE("read_package_list: found %zu packages\n",
- global->package_to_appid->size());
+ DLOG(INFO) << "read_package_list: found " << global->package_to_appid->size() << " packages";
// Regenerate ownership details using newly loaded mapping.
derive_permissions_recursive_locked(global->fuse_default, &global->root);
@@ -148,7 +146,7 @@
int event_size;
event = (struct inotify_event *) (event_buf + event_pos);
- TRACE("inotify event: %08x\n", event->mask);
+ DLOG(INFO) << "inotify event: " << std::hex << event->mask << std::dec;
if ((event->mask & IN_IGNORED) == IN_IGNORED) {
/* Previously watched file was deleted, probably due to move
* that swapped in new data; re-arm the watch and read. */
