Blob Blame History Raw
/*********************************************************/
/*  toksvc: a framework-native token broker service      */
/*  Copyright (C) 2020  Z. Gilboa                        */
/*  Released under GPLv2 and GPLv3; see COPYING.TOKSVC.  */
/*********************************************************/

#include <psxtypes/psxtypes.h>
#include <ntapi/nt_tty.h>

#include <toksvc/toksvc.h>
#include "toksvc_driver_impl.h"
#include "toksvc_daemon_impl.h"
#include "toksvc_log_impl.h"

#define  TOKS_OPCODE_STR(IDX) [TOKS_DAEMON_ ## IDX - TOKS_DAEMON_OPCODE_BASE]

static const char toks_error_str[]      = "#ERROR";
static const char toks_unknown_str[]    = "#UNKNOWN_OPCODE";

static const char toks_internal_msg[]   = "internal LPC message";
static const char toks_external_msg[]   = "external LPC message";

static const char * toks_opcode_str[]   = {
	TOKS_OPCODE_STR(CONNECT)        = "TOKS_DAEMON_CONNECT",
	TOKS_OPCODE_STR(DISCONNECT)     = "TOKS_DAEMON_DISCONNECT",
	TOKS_OPCODE_STR(TTYSIGNAL)      = "TOKS_DAEMON_TTYSIGNAL",
	TOKS_OPCODE_STR(IPCSIGNAL)      = "TOKS_DAEMON_IPCSIGNAL",
	TOKS_OPCODE_STR(SIGCHLD)        = "TOKS_DAEMON_SIGCHLD",
	TOKS_OPCODE_STR(THREADEXIT)     = "TOKS_DAEMON_THREADEXIT",
	TOKS_OPCODE_STR(CIDQUERY)       = "TOKS_DAEMON_CIDQUERY",
	TOKS_OPCODE_STR(ACQUIRE)        = "TOKS_DAEMON_ACQUIRE",
	TOKS_OPCODE_STR(RELEASE)        = "TOKS_DAEMON_RELEASE",
	TOKS_OPCODE_STR(CANCEL)         = "TOKS_DAEMON_CANCEL",
	TOKS_OPCODE_STR(ABORT)          = "TOKS_DAEMON_ABORT",
	TOKS_OPCODE_STR(IOCTL)          = "TOKS_DAEMON_IOCTL",
};

static const char * toks_lpc_msg_str[]  = {
	[NT_LPC_NEW_MESSAGE]            = "NT_LPC_NEW_MESSAGE",
	[NT_LPC_REQUEST]                = "NT_LPC_REQUEST",
	[NT_LPC_REPLY]                  = "NT_LPC_REPLY",
	[NT_LPC_DATAGRAM]               = "NT_LPC_DATAGRAM",
	[NT_LPC_LOST_REPLY]             = "NT_LPC_LOST_REPLY",
	[NT_LPC_PORT_CLOSED]            = "NT_LPC_PORT_CLOSED",
	[NT_LPC_CLIENT_DIED]            = "NT_LPC_CLIENT_DIED",
	[NT_LPC_EXCEPTION]              = "NT_LPC_EXCEPTION",
	[NT_LPC_DEBUG_EVENT]            = "NT_LPC_DEBUG_EVENT",
	[NT_LPC_ERROR_EVENT]            = "NT_LPC_ERROR_EVENT",
	[NT_LPC_CONNECTION_REQUEST]     = "NT_LPC_CONNECTION_REQUEST",
};

static const char * toks_alpc_msg_str[] = {
	[NT_ALPC_REQUEST ^ 0x2000]            = "NT_ALPC_REQUEST",
	[NT_ALPC_CONNECTION_REQUEST ^ 0x2000] = "NT_ALPC_CONNECTION_REQUEST",
};

static const char * toks_lpc_msg_type_desc(unsigned msgtype)
{
	if (msgtype <= NT_LPC_CONNECTION_REQUEST)
		return toks_lpc_msg_str[msgtype];

	else if (msgtype == NT_ALPC_REQUEST)
		return toks_alpc_msg_str[msgtype ^ 0x2000];

	else if (msgtype == NT_ALPC_CONNECTION_REQUEST)
		return toks_alpc_msg_str[msgtype ^ 0x2000];

	else
		return toks_error_str;
}

static const char * toks_lpc_msg_source_desc(uintptr_t syspid)
{
	return (syspid == pe_get_current_process_id())
		? toks_internal_msg
		: toks_external_msg;
}

static const char * toks_lpc_opcode_desc(struct toks_daemon_ctx * dctx)
{
	if ((dctx->opcode >= TOKS_DAEMON_OPCODE_BASE)
			&& (dctx->opcode < TOKS_DAEMON_OPCODE_CAP))
		return toks_opcode_str[dctx->opcode-TOKS_DAEMON_OPCODE_BASE];

	return toks_unknown_str;
}

static void toks_log_lpc_request_desc(
	struct toks_daemon_ctx * dctx,
	const nt_tty_port_msg *  msg,
	char *                   desc)
{
	char * ch = desc;

	ch += ntapi->sprintf(
		ch,
		" ::: REQUEST INFO ::: "
		"opcode=%s, "
		"opdata=%u (0x%08x)",
		toks_lpc_opcode_desc(dctx),
		msg->ttyinfo.opdata,
		msg->ttyinfo.opdata);

	if (dctx->opcode == TOKS_DAEMON_ACQUIRE)
		if (msg->syncinfo.ipcsvc.keys.reserved)
			ch += ntapi->sprintf(
				ch,
				" (tokpid=%d)",
				msg->syncinfo.ipcsvc.keys.reserved);

	if (msg->syncinfo.ipcsvc.keys.key[0])
		ch += ntapi->sprintf(
			ch,", refstr=``%s''",
			(const char *)msg->syncinfo.ipcsvc.keys.key);
}

static void toks_log_lpc_reply_desc(
	struct toks_daemon_ctx * dctx,
	const nt_tty_port_msg *  msg,
	char *                   desc)
{
	char *                ch;
	unsigned char *       uch;
	const unsigned int  * keys;

	ch = desc;

	ch += ntapi->sprintf(
		ch,
		" ::: REPLY INFO ::: "
		"status=0x%08x",
		msg->ttyinfo.status);

	switch (dctx->opcode) {
		case TOKS_DAEMON_ACQUIRE:
			keys = (msg->ttyinfo.status == NT_STATUS_SUCCESS)
				? msg->syncinfo.ipckeys : 0;
			break;

		case TOKS_DAEMON_RELEASE:
			keys = msg->syncinfo.ipckeys;
			break;

		default:
			keys = 0;
	}

	if (keys) {
		ch += ntapi->sprintf(ch,", token=[");

		uch = (unsigned char *)ch;

		uch[8]  = '-';
		uch[17] = '-';
		uch[26] = '-';
		uch[35] = '-';
		uch[44] = '-';

		ntapi->tt_uint32_to_hex_utf8(keys[0],&uch[0]);
		ntapi->tt_uint32_to_hex_utf8(keys[1],&uch[9]);
		ntapi->tt_uint32_to_hex_utf8(keys[2],&uch[18]);
		ntapi->tt_uint32_to_hex_utf8(keys[3],&uch[27]);
		ntapi->tt_uint32_to_hex_utf8(keys[4],&uch[36]);
		ntapi->tt_uint32_to_hex_utf8(keys[5],&uch[45]);

		ch += 6*8 + 5;

		*ch++ = ']';
		*ch   = 0;
	}

	if (dctx->opcode == TOKS_DAEMON_ACQUIRE) {
		if (msg->ttyinfo.status == NT_STATUS_SUCCESS) {
			(void)0;

		} else if (msg->ttyinfo.status == NT_STATUS_PENDING) {
			ch += ntapi->sprintf(ch," (pending, queued)");

		} else if (msg->ttyinfo.status == NT_STATUS_TIMEOUT) {
			if (!dctx->request.syncinfo.hevent)
				ch += ntapi->sprintf(ch," (timeout=0, not queued)");
			else
				ch += ntapi->sprintf(ch," (timeout, internal error)");
		} else {
			ch += ntapi->sprintf(ch," (error, not queued)");
		}
	}
}

void toks_log_lpc_request(
	struct toks_daemon_ctx * dctx,
	const nt_tty_port_msg *  msg)
{
	struct toks_driver_ctx * drvctx = dctx->driver_ctx;

	TOKS_LOG_LEVEL(drvctx,1);

	nt_cid cid;
	char   path[2048];
	char   desc[1024];

	cid.process_id = msg->header.client_id.process_id;
	cid.thread_id  = msg->header.client_id.thread_id;

	toks_log_get_arbitrary_process_name(
		&cid,path,sizeof(path));

	switch (msg->header.msg_type) {
		case NT_LPC_REQUEST:
			toks_log_lpc_request_desc(
				dctx,msg,desc);
			break;

		default:
			desc[0] = 0;
	}

	toks_log_header(
		drvctx,
		TOKS_LOG_ENTRY_SERVER_INFO,
		"%s from %s (syspid %d, systid %d), "
		"data_size=%u, msg_size=%u, "
		"msg_type=%u (%s), msg_id=%u%s\n",
		toks_lpc_msg_source_desc(msg->header.client_id.process_id),
		toks_log_basename(path),
		cid.process_id,
		cid.thread_id,
		msg->header.data_size,
		msg->header.msg_size,
		msg->header.msg_type,
		toks_lpc_msg_type_desc(msg->header.msg_type),
		msg->header.msg_id,
		desc);


	if (cid.process_id)
		toks_log_write(
			drvctx,
			TOKS_LOG_ENTRY_SUB_LEVEL_2,
			"%s.\n",path);
}

void toks_log_lpc_reply(
	struct toks_daemon_ctx * dctx,
	const nt_tty_port_msg *  msg)
{
	struct toks_driver_ctx * drvctx = dctx->driver_ctx;
	int                      opdata = msg->ttyinfo.opdata;

	TOKS_LOG_LEVEL(drvctx,1);

	nt_cid cid;
	char   desc[1024];

	cid.process_id = msg->header.client_id.process_id;
	cid.thread_id  = msg->header.client_id.thread_id;

	switch (dctx->request.header.msg_type) {
		case NT_LPC_REQUEST:
			toks_log_lpc_reply_desc(
				dctx,msg,desc);
			break;

		default:
			desc[0] = 0;
	}

	toks_log_header(
		drvctx,
		TOKS_LOG_ENTRY_SERVER_INFO,
		"%s (syspid %d, systid %d), "
		"data_size=%u, msg_size=%u, "
		"msg_type=%u (%s), msg_id=%u%s\n",
		toks_lpc_msg_source_desc(msg->header.client_id.process_id),
		cid.process_id,
		cid.thread_id,
		msg->header.data_size,
		msg->header.msg_size,
		msg->header.msg_type,
		toks_lpc_msg_type_desc(msg->header.msg_type),
		msg->header.msg_id,
		desc);

	if (dctx->opcode == TOKS_DAEMON_IOCTL) {
		if (opdata == TOKS_IOCTL_SET_TOKEN_COUNT)
			toks_log_service_info(dctx);
	}
}