Merge "libbinder : Use logging from liblog" am: 58864fd37f am: 424b87710b am:... (e8dba843) · Commits · e / devices / smdk4412 / android_frameworks_native

libs/binder/IPCThreadState.cpp

+100 −80

Original line number	Original line	Diff line number	Diff line
	@@ -39,7 +39,6 @@
	#include <sys/resource.h>		#include <sys/resource.h>
	#include <unistd.h>		#include <unistd.h>

	#include "Static.h"
	#include "binder_module.h"		#include "binder_module.h"

	#if LOG_NDEBUG		#if LOG_NDEBUG
	@@ -124,46 +123,43 @@ static const char* getReturnString(uint32_t cmd)
	return "unknown";		return "unknown";
	}		}

	static const void* printBinderTransactionData(TextOutput& out, const void* data)		static const void* printBinderTransactionData(std::ostream& out, const void* data) {
	{
	const binder_transaction_data* btd =		const binder_transaction_data* btd =
	(const binder_transaction_data*)data;		(const binder_transaction_data*)data;
	if (btd->target.handle < 1024) {		if (btd->target.handle < 1024) {
	/* want to print descriptors in decimal; guess based on value */		/* want to print descriptors in decimal; guess based on value */
	out << "target.desc=" << btd->target.handle;		out << "\ttarget.desc=" << btd->target.handle;
	} else {		} else {
	out << "target.ptr=" << btd->target.ptr;		out << "\ttarget.ptr=" << btd->target.ptr;
	}		}
	out << " (cookie " << btd->cookie << ")" << endl		out << "\t (cookie " << btd->cookie << ")"
	<< "code=" << TypeCode(btd->code) << ", flags=" << (void*)(uint64_t)btd->flags << endl		<< "\n"
	<< "data=" << btd->data.ptr.buffer << " (" << (void*)btd->data_size		<< "\tcode=" << TypeCode(btd->code) << ", flags=" << (void*)(uint64_t)btd->flags << "\n"
	<< " bytes)" << endl		<< "\tdata=" << btd->data.ptr.buffer << " (" << (void*)btd->data_size << " bytes)"
	<< "offsets=" << btd->data.ptr.offsets << " (" << (void*)btd->offsets_size		<< "\n"
	<< " bytes)";		<< "\toffsets=" << btd->data.ptr.offsets << " (" << (void*)btd->offsets_size << " bytes)";
	return btd+1;		return btd+1;
	}		}

	static const void* printReturnCommand(TextOutput& out, const void* _cmd)		static const void* printReturnCommand(std::ostream& out, const void* _cmd) {
	{
	static const size_t N = sizeof(kReturnStrings)/sizeof(kReturnStrings[0]);		static const size_t N = sizeof(kReturnStrings)/sizeof(kReturnStrings[0]);
	const int32_t* cmd = (const int32_t*)_cmd;		const int32_t* cmd = (const int32_t*)_cmd;
	uint32_t code = (uint32_t)*cmd++;		uint32_t code = (uint32_t)*cmd++;
	size_t cmdIndex = code & 0xff;		size_t cmdIndex = code & 0xff;
	if (code == BR_ERROR) {		if (code == BR_ERROR) {
	out << "BR_ERROR: " << (void)(uint64_t)(cmd++) << endl;		out << "\tBR_ERROR: " << (void)(uint64_t)(cmd++) << "\n";
	return cmd;		return cmd;
	} else if (cmdIndex >= N) {		} else if (cmdIndex >= N) {
	out << "Unknown reply: " << code << endl;		out << "\tUnknown reply: " << code << "\n";
	return cmd;		return cmd;
	}		}
	out << kReturnStrings[cmdIndex];		out << "\t" << kReturnStrings[cmdIndex];

	switch (code) {		switch (code) {
	case BR_TRANSACTION:		case BR_TRANSACTION:
	case BR_REPLY: {		case BR_REPLY: {
	out << ": " << indent;		out << ": ";
	cmd = (const int32_t*)printBinderTransactionData(out, cmd);		cmd = (const int32_t*)printBinderTransactionData(out, cmd);
	out << dedent;
	} break;		} break;

	case BR_ACQUIRE_RESULT: {		case BR_ACQUIRE_RESULT: {
	@@ -200,19 +196,18 @@ static const void* printReturnCommand(TextOutput& out, const void* _cmd)
	break;		break;
	}		}

	out << endl;		out << "\n";
	return cmd;		return cmd;
	}		}

	static const void* printCommand(TextOutput& out, const void* _cmd)		static const void* printCommand(std::ostream& out, const void* _cmd) {
	{
	static const size_t N = sizeof(kCommandStrings)/sizeof(kCommandStrings[0]);		static const size_t N = sizeof(kCommandStrings)/sizeof(kCommandStrings[0]);
	const int32_t* cmd = (const int32_t*)_cmd;		const int32_t* cmd = (const int32_t*)_cmd;
	uint32_t code = (uint32_t)*cmd++;		uint32_t code = (uint32_t)*cmd++;
	size_t cmdIndex = code & 0xff;		size_t cmdIndex = code & 0xff;

	if (cmdIndex >= N) {		if (cmdIndex >= N) {
	out << "Unknown command: " << code << endl;		out << "Unknown command: " << code << "\n";
	return cmd;		return cmd;
	}		}
	out << kCommandStrings[cmdIndex];		out << kCommandStrings[cmdIndex];
	@@ -220,9 +215,8 @@ static const void* printCommand(TextOutput& out, const void* _cmd)
	switch (code) {		switch (code) {
	case BC_TRANSACTION:		case BC_TRANSACTION:
	case BC_REPLY: {		case BC_REPLY: {
	out << ": " << indent;		out << ": ";
	cmd = (const int32_t*)printBinderTransactionData(out, cmd);		cmd = (const int32_t*)printBinderTransactionData(out, cmd);
	out << dedent;
	} break;		} break;

	case BC_ACQUIRE_RESULT: {		case BC_ACQUIRE_RESULT: {
	@@ -274,7 +268,7 @@ static const void* printCommand(TextOutput& out, const void* _cmd)
	break;		break;
	}		}

	out << endl;		out << "\n";
	return cmd;		return cmd;
	}		}

	@@ -548,8 +542,10 @@ status_t IPCThreadState::getAndExecuteCommand()
	if (IN < sizeof(int32_t)) return result;		if (IN < sizeof(int32_t)) return result;
	cmd = mIn.readInt32();		cmd = mIn.readInt32();
	IF_LOG_COMMANDS() {		IF_LOG_COMMANDS() {
	alog << "Processing top-level Command: "		std::ostringstream logStream;
	<< getReturnString(cmd) << endl;		logStream << "Processing top-level Command: " << getReturnString(cmd) << "\n";
			std::string message = logStream.str();
			ALOGI("%s", message.c_str());
	}		}

	pthread_mutex_lock(&mProcess->mThreadCountLock);		pthread_mutex_lock(&mProcess->mThreadCountLock);
	@@ -726,10 +722,11 @@ status_t IPCThreadState::transact(int32_t handle,
	flags \|= TF_ACCEPT_FDS;		flags \|= TF_ACCEPT_FDS;

	IF_LOG_TRANSACTIONS() {		IF_LOG_TRANSACTIONS() {
	TextOutput::Bundle _b(alog);		std::ostringstream logStream;
	alog << "BC_TRANSACTION thr " << (void*)pthread_self() << " / hand "		logStream << "BC_TRANSACTION thr " << (void*)pthread_self() << " / hand " << handle
	<< handle << " / code " << TypeCode(code) << ": "		<< " / code " << TypeCode(code) << ": \t" << data << "\n";
	<< indent << data << dedent << endl;		std::string message = logStream.str();
			ALOGI("%s", message.c_str());
	}		}

	LOG_ONEWAY(">>>> SEND from pid %d uid %d %s", getpid(), getuid(),		LOG_ONEWAY(">>>> SEND from pid %d uid %d %s", getpid(), getuid(),
	@@ -774,11 +771,15 @@ status_t IPCThreadState::transact(int32_t handle,
	#endif		#endif

	IF_LOG_TRANSACTIONS() {		IF_LOG_TRANSACTIONS() {
	TextOutput::Bundle _b(alog);		std::ostringstream logStream;
	alog << "BR_REPLY thr " << (void*)pthread_self() << " / hand "		logStream << "BR_REPLY thr " << (void*)pthread_self() << " / hand " << handle << ": ";
	<< handle << ": ";		if (reply)
	if (reply) alog << indent << *reply << dedent << endl;		logStream << "\t" << *reply << "\n";
	else alog << "(none requested)" << endl;		else
			logStream << "(none requested)"
			<< "\n";
			std::string message = logStream.str();
			ALOGI("%s", message.c_str());
	}		}
	} else {		} else {
	err = waitForResponse(nullptr, nullptr);		err = waitForResponse(nullptr, nullptr);
	@@ -920,8 +921,10 @@ status_t IPCThreadState::waitForResponse(Parcel reply, status_t acquireResult)
	cmd = (uint32_t)mIn.readInt32();		cmd = (uint32_t)mIn.readInt32();

	IF_LOG_COMMANDS() {		IF_LOG_COMMANDS() {
	alog << "Processing waitForResponse Command: "		std::ostringstream logStream;
	<< getReturnString(cmd) << endl;		logStream << "Processing waitForResponse Command: " << getReturnString(cmd) << "\n";
			std::string message = logStream.str();
			ALOGI("%s", message.c_str());
	}		}

	switch (cmd) {		switch (cmd) {
	@@ -1033,17 +1036,19 @@ status_t IPCThreadState::talkWithDriver(bool doReceive)
	}		}

	IF_LOG_COMMANDS() {		IF_LOG_COMMANDS() {
	TextOutput::Bundle _b(alog);		std::ostringstream logStream;
	if (outAvail != 0) {		if (outAvail != 0) {
	alog << "Sending commands to driver: " << indent;		logStream << "Sending commands to driver: ";
	const void* cmds = (const void*)bwr.write_buffer;		const void* cmds = (const void*)bwr.write_buffer;
	const void* end = ((const uint8_t*)cmds) + bwr.write_size;		const void* end = ((const uint8_t*)cmds) + bwr.write_size;
	alog << HexDump(cmds, bwr.write_size) << endl;		logStream << "\t" << HexDump(cmds, bwr.write_size) << "\n";
	while (cmds < end) cmds = printCommand(alog, cmds);		while (cmds < end) cmds = printCommand(logStream, cmds);
	alog << dedent;
	}		}
	alog << "Size of receive buffer: " << bwr.read_size		logStream << "Size of receive buffer: " << bwr.read_size << ", needRead: " << needRead
	<< ", needRead: " << needRead << ", doReceive: " << doReceive << endl;		<< ", doReceive: " << doReceive << "\n";

			std::string message = logStream.str();
			ALOGI("%s", message.c_str());
	}		}

	// Return immediately if there is nothing to do.		// Return immediately if there is nothing to do.
	@@ -1054,7 +1059,10 @@ status_t IPCThreadState::talkWithDriver(bool doReceive)
	status_t err;		status_t err;
	do {		do {
	IF_LOG_COMMANDS() {		IF_LOG_COMMANDS() {
	alog << "About to read/write, write size = " << mOut.dataSize() << endl;		std::ostringstream logStream;
			logStream << "About to read/write, write size = " << mOut.dataSize() << "\n";
			std::string message = logStream.str();
			ALOGI("%s", message.c_str());
	}		}
	#if defined(__ANDROID__)		#if defined(__ANDROID__)
	if (ioctl(mProcess->mDriverFD, BINDER_WRITE_READ, &bwr) >= 0)		if (ioctl(mProcess->mDriverFD, BINDER_WRITE_READ, &bwr) >= 0)
	@@ -1068,14 +1076,20 @@ status_t IPCThreadState::talkWithDriver(bool doReceive)
	err = -EBADF;		err = -EBADF;
	}		}
	IF_LOG_COMMANDS() {		IF_LOG_COMMANDS() {
	alog << "Finished read/write, write size = " << mOut.dataSize() << endl;		std::ostringstream logStream;
			logStream << "Finished read/write, write size = " << mOut.dataSize() << "\n";
			std::string message = logStream.str();
			ALOGI("%s", message.c_str());
	}		}
	} while (err == -EINTR);		} while (err == -EINTR);

	IF_LOG_COMMANDS() {		IF_LOG_COMMANDS() {
	alog << "Our err: " << (void*)(intptr_t)err << ", write consumed: "		std::ostringstream logStream;
	<< bwr.write_consumed << " (of " << mOut.dataSize()		logStream << "Our err: " << (void*)(intptr_t)err
	<< "), read consumed: " << bwr.read_consumed << endl;		<< ", write consumed: " << bwr.write_consumed << " (of " << mOut.dataSize()
			<< "), read consumed: " << bwr.read_consumed << "\n";
			std::string message = logStream.str();
			ALOGI("%s", message.c_str());
	}		}

	if (err >= NO_ERROR) {		if (err >= NO_ERROR) {
	@@ -1096,14 +1110,15 @@ status_t IPCThreadState::talkWithDriver(bool doReceive)
	mIn.setDataPosition(0);		mIn.setDataPosition(0);
	}		}
	IF_LOG_COMMANDS() {		IF_LOG_COMMANDS() {
	TextOutput::Bundle _b(alog);		std::ostringstream logStream;
	alog << "Remaining data size: " << mOut.dataSize() << endl;		logStream << "Remaining data size: " << mOut.dataSize() << "\n";
	alog << "Received commands from driver: " << indent;		logStream << "Received commands from driver: ";
	const void* cmds = mIn.data();		const void* cmds = mIn.data();
	const void* end = mIn.data() + mIn.dataSize();		const void* end = mIn.data() + mIn.dataSize();
	alog << HexDump(cmds, mIn.dataSize()) << endl;		logStream << "\t" << HexDump(cmds, mIn.dataSize()) << "\n";
	while (cmds < end) cmds = printReturnCommand(alog, cmds);		while (cmds < end) cmds = printReturnCommand(logStream, cmds);
	alog << dedent;		std::string message = logStream.str();
			ALOGI("%s", message.c_str());
	}		}
	return NO_ERROR;		return NO_ERROR;
	}		}
	@@ -1285,15 +1300,15 @@ status_t IPCThreadState::executeCommand(int32_t cmd)
	Parcel reply;		Parcel reply;
	status_t error;		status_t error;
	IF_LOG_TRANSACTIONS() {		IF_LOG_TRANSACTIONS() {
	TextOutput::Bundle _b(alog);		std::ostringstream logStream;
	alog << "BR_TRANSACTION thr " << (void*)pthread_self()		logStream << "BR_TRANSACTION thr " << (void*)pthread_self() << " / obj "
	<< " / obj " << tr.target.ptr << " / code "		<< tr.target.ptr << " / code " << TypeCode(tr.code) << ": \t" << buffer
	<< TypeCode(tr.code) << ": " << indent << buffer		<< "\n"
	<< dedent << endl		<< "Data addr = " << reinterpret_cast<const uint8_t*>(tr.data.ptr.buffer)
	<< "Data addr = "
	<< reinterpret_cast<const uint8_t*>(tr.data.ptr.buffer)
	<< ", offsets addr="		<< ", offsets addr="
	<< reinterpret_cast<const size_t*>(tr.data.ptr.offsets) << endl;		<< reinterpret_cast<const size_t*>(tr.data.ptr.offsets) << "\n";
			std::string message = logStream.str();
			ALOGI("%s", message.c_str());
	}		}
	if (tr.target.ptr) {		if (tr.target.ptr) {
	// We only have a weak reference on the target object, so we must first try to		// We only have a weak reference on the target object, so we must first try to
	@@ -1329,8 +1344,8 @@ status_t IPCThreadState::executeCommand(int32_t cmd)
	sendReply(reply, (tr.flags & kForwardReplyFlags));		sendReply(reply, (tr.flags & kForwardReplyFlags));
	} else {		} else {
	if (error != OK) {		if (error != OK) {
	alog << "oneway function results for code " << tr.code		std::ostringstream logStream;
	<< " on binder at "		logStream << "oneway function results for code " << tr.code << " on binder at "
	<< reinterpret_cast<void*>(tr.target.ptr)		<< reinterpret_cast<void*>(tr.target.ptr)
	<< " will be dropped but finished with status "		<< " will be dropped but finished with status "
	<< statusToString(error);		<< statusToString(error);
	@@ -1340,10 +1355,10 @@ status_t IPCThreadState::executeCommand(int32_t cmd)
	// interfaces have clients that call methods which always		// interfaces have clients that call methods which always
	// write results, sometimes as oneway methods.		// write results, sometimes as oneway methods.
	if (reply.dataSize() != 0) {		if (reply.dataSize() != 0) {
	alog << " and reply parcel size " << reply.dataSize();		logStream << " and reply parcel size " << reply.dataSize();
	}		}
			std::string message = logStream.str();
	alog << endl;		ALOGI("%s", message.c_str());
	}		}
	LOG_ONEWAY("NOT sending reply to %d!", mCallingPid);		LOG_ONEWAY("NOT sending reply to %d!", mCallingPid);
	}		}
	@@ -1358,9 +1373,11 @@ status_t IPCThreadState::executeCommand(int32_t cmd)
	mPropagateWorkSource = origPropagateWorkSet;		mPropagateWorkSource = origPropagateWorkSet;

	IF_LOG_TRANSACTIONS() {		IF_LOG_TRANSACTIONS() {
	TextOutput::Bundle _b(alog);		std::ostringstream logStream;
	alog << "BC_REPLY thr " << (void*)pthread_self() << " / obj "		logStream << "BC_REPLY thr " << (void*)pthread_self() << " / obj " << tr.target.ptr
	<< tr.target.ptr << ": " << indent << reply << dedent << endl;		<< ": \t" << reply << "\n";
			std::string message = logStream.str();
			ALOGI("%s", message.c_str());
	}		}

	}		}
	@@ -1481,7 +1498,10 @@ void IPCThreadState::freeBuffer(const uint8_t* data, size_t /dataSize/,
	const binder_size_t* /objects/, size_t /objectsSize/) {		const binder_size_t* /objects/, size_t /objectsSize/) {
	//ALOGI("Freeing parcel %p", &parcel);		//ALOGI("Freeing parcel %p", &parcel);
	IF_LOG_COMMANDS() {		IF_LOG_COMMANDS() {
	alog << "Writing BC_FREE_BUFFER for " << data << endl;		std::ostringstream logStream;
			logStream << "Writing BC_FREE_BUFFER for " << data << "\n";
			std::string message = logStream.str();
			ALOGI("%s", message.c_str());
	}		}
	ALOG_ASSERT(data != NULL, "Called with NULL data");		ALOG_ASSERT(data != NULL, "Called with NULL data");
	IPCThreadState* state = self();		IPCThreadState* state = self();

libs/binder/Parcel.cpp

+3 −5

Original line number	Original line	Diff line number	Diff line
	@@ -2639,8 +2639,7 @@ status_t Parcel::rpcSetDataReference(
	return OK;		return OK;
	}		}

	void Parcel::print(TextOutput& to, uint32_t /flags/) const		void Parcel::print(std::ostream& to, uint32_t /flags/) const {
	{
	to << "Parcel(";		to << "Parcel(";

	if (errorCheck() != NO_ERROR) {		if (errorCheck() != NO_ERROR) {
	@@ -2648,7 +2647,7 @@ void Parcel::print(TextOutput& to, uint32_t /flags/) const
	to << "Error: " << (void*)(intptr_t)err << " \"" << strerror(-err) << "\"";		to << "Error: " << (void*)(intptr_t)err << " \"" << strerror(-err) << "\"";
	} else if (dataSize() > 0) {		} else if (dataSize() > 0) {
	const uint8_t* DATA = data();		const uint8_t* DATA = data();
	to << indent << HexDump(DATA, dataSize()) << dedent;		to << "\t" << HexDump(DATA, dataSize());
	#ifdef BINDER_WITH_KERNEL_IPC		#ifdef BINDER_WITH_KERNEL_IPC
	if (const auto* kernelFields = maybeKernelFields()) {		if (const auto* kernelFields = maybeKernelFields()) {
	const binder_size_t* OBJS = kernelFields->mObjects;		const binder_size_t* OBJS = kernelFields->mObjects;
	@@ -2656,8 +2655,7 @@ void Parcel::print(TextOutput& to, uint32_t /flags/) const
	for (size_t i = 0; i < N; i++) {		for (size_t i = 0; i < N; i++) {
	const flat_binder_object* flat =		const flat_binder_object* flat =
	reinterpret_cast<const flat_binder_object*>(DATA + OBJS[i]);		reinterpret_cast<const flat_binder_object*>(DATA + OBJS[i]);
	to << endl		to << "Object #" << i << " @ " << (void*)OBJS[i] << ": "
	<< "Object #" << i << " @ " << (void*)OBJS[i] << ": "
	<< TypeCode(flat->hdr.type & 0x7f7f7f00) << " = " << flat->binder;		<< TypeCode(flat->hdr.type & 0x7f7f7f00) << " = " << flat->binder;
	}		}
	}		}

libs/binder/TextOutput.cpp

+3 −5

Original line number	Original line	Diff line number	Diff line
	@@ -39,11 +39,10 @@ TextOutput::~TextOutput() {

	static void textOutputPrinter(void* cookie, const char* txt)		static void textOutputPrinter(void* cookie, const char* txt)
	{		{
	((TextOutput*)cookie)->print(txt, strlen(txt));		((std::ostream*)cookie)->write(txt, strlen(txt));
	}		}

	TextOutput& operator<<(TextOutput& to, const TypeCode& val)		std::ostream& operator<<(std::ostream& to, const TypeCode& val) {
	{
	printTypeCode(val.typeCode(), textOutputPrinter, (void*)&to);		printTypeCode(val.typeCode(), textOutputPrinter, (void*)&to);
	return to;		return to;
	}		}
	@@ -61,8 +60,7 @@ HexDump::HexDump(const void *buf, size_t size, size_t bytesPerLine)
	else mAlignment = 1;		else mAlignment = 1;
	}		}

	TextOutput& operator<<(TextOutput& to, const HexDump& val)		std::ostream& operator<<(std::ostream& to, const HexDump& val) {
	{
	printHexData(0, val.buffer(), val.size(), val.bytesPerLine(),		printHexData(0, val.buffer(), val.size(), val.bytesPerLine(),
	val.singleLineCutoff(), val.alignment(), val.carrayStyle(),		val.singleLineCutoff(), val.alignment(), val.carrayStyle(),
	textOutputPrinter, (void*)&to);		textOutputPrinter, (void*)&to);

libs/binder/include/binder/Parcel.h

+2 −3

Original line number	Original line	Diff line number	Diff line
	@@ -595,7 +595,7 @@ public:
	// uid.		// uid.
	uid_t readCallingWorkSourceUid() const;		uid_t readCallingWorkSourceUid() const;

	void print(TextOutput& to, uint32_t flags = 0) const;		void print(std::ostream& to, uint32_t flags = 0) const;

	private:		private:
	// `objects` and `objectsSize` always 0 for RPC Parcels.		// `objects` and `objectsSize` always 0 for RPC Parcels.
	@@ -1594,8 +1594,7 @@ status_t Parcel::readNullableStrongBinder(sp<T>* val) const {

	// ---------------------------------------------------------------------------		// ---------------------------------------------------------------------------

	inline TextOutput& operator<<(TextOutput& to, const Parcel& parcel)		inline std::ostream& operator<<(std::ostream& to, const Parcel& parcel) {
	{
	parcel.print(to);		parcel.print(to);
	return to;		return to;
	}		}

libs/binder/include/binder/TextOutput.h

+2 −2

Original line number	Original line	Diff line number	Diff line
	@@ -94,7 +94,7 @@ private:
	uint32_t mCode;		uint32_t mCode;
	};		};

	TextOutput& operator<<(TextOutput& to, const TypeCode& val);		std::ostream& operator<<(std::ostream& to, const TypeCode& val);

	class HexDump		class HexDump
	{		{
	@@ -123,7 +123,7 @@ private:
	bool mCArrayStyle;		bool mCArrayStyle;
	};		};

	TextOutput& operator<<(TextOutput& to, const HexDump& val);		std::ostream& operator<<(std::ostream& to, const HexDump& val);
	inline TextOutput& operator<<(TextOutput& to,		inline TextOutput& operator<<(TextOutput& to,
	decltype(std::endl<char,		decltype(std::endl<char,
	std::char_traits<char>>)		std::char_traits<char>>)