Merge "Fix sdcard logging." (47b077a4) · Commits · e / os / android_system_core

sdcard/Android.mk

+1 −1

Original line number	Diff line number	Diff line
		@@ -5,7 +5,7 @@ include $(CLEAR_VARS)
		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

sdcard/fuse.cpp

+51 −45

Original line number	Diff line number	Diff line
		@@ -39,18 +39,20 @@ static inline __u64 ptr_to_id(void *ptr)
		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 @@ static void release_node_locked(struct node* node)
		free(node);
		}
		} else {
		ERROR("Zero refcnt %p\n", node);
		LOG(ERROR) << std::hex << node << std::dec << " refcount=0";
		}
		}

		@@ -155,7 +157,7 @@ static char* find_file_within(const char* path, const char* name,
		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 @@ static int touch(char* path, mode_t mode) {
		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 @@ struct node create_node_locked(struct fuse fuse,
		// 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 @@ static void fuse_reply(struct fuse fuse, __u64 unique, void data, int len)

		res = writev(fuse->fd, vec, 2);
		if (res < 0) {
		ERROR("* REPLY FAILED * %d\n", errno);
		PLOG(ERROR) << "* REPLY FAILED *";
		}
		}

		@@ -560,7 +562,7 @@ static void fuse_notify_delete(struct fuse* fuse, const __u64 parent,
		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 @@ static int handle_getattr(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_setattr(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_setattr(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_mkdir(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_mkdir(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_unlink(struct fuse* fuse, struct fuse_handler* handler,
		/* 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 @@ static int handle_rmdir(struct fuse* fuse, struct fuse_handler* handler,
		/* 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 @@ static int handle_rename(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_open(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_open(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_read(struct fuse* fuse, struct fuse_handler* handler,
		* 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 @@ static int handle_write(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_statfs(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_release(struct fuse* fuse, struct fuse_handler* handler,
		{
		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 @@ static int handle_fsync(struct fuse* fuse, struct fuse_handler* handler,
		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_fsync(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_opendir(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_readdir(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_releasedir(struct fuse* fuse, struct fuse_handler* handler,
		{
		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 @@ static int handle_init(struct fuse* fuse, struct fuse_handler* handler,
		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 @@ static int handle_init(struct fuse* fuse, struct fuse_handler* handler,
		* 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 @@ static int handle_fuse_request(struct fuse fuse, struct fuse_handler handler,

		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 @@ void handle_fuse_requests(struct fuse_handler* handler)
		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 @@ void handle_fuse_requests(struct fuse_handler* handler)

		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);
		}

sdcard/fuse.h

+0 −5

Original line number	Diff line number	Diff line
		@@ -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 @@ static constexpr bool kEnableDLog = false;
		#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)

sdcard/sdcard.cpp

+2 −4

Original line number	Diff line number	Diff line
		@@ -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 @@ static bool read_package_list(struct fuse_global* global) {

		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 @@ static void watch_package_list(struct fuse_global* global) {
		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. */