/*-------------------------------------------------------------------------
 *
 * logfmt.c
 *	  logfmt logging
 *
 * Portions Copyright (c) 2023, Dalibo
 * Portions Copyright (c) 1996-2023, PostgreSQL Global Development Group
 * Portions Copyright (c) 1994, Regents of the University of California
 *
 *
 * IDENTIFICATION
 *	  logfmt.c
 *
 *-------------------------------------------------------------------------
 */

#include "postgres.h"

#include <stdio.h>
#include <string.h>

#include "access/xact.h"
#include "fmgr.h"
#include "lib/stringinfo.h"
#include "libpq/libpq-be.h"
#include "miscadmin.h"
#include "postmaster/syslogger.h"
#include "storage/fd.h"
#include "storage/proc.h"
#include "tcop/tcopprot.h"
#include "utils/backend_status.h"
#include "utils/elog.h"
#include "utils/memutils.h"

PG_MODULE_MAGIC;

void _PG_init(void);
void _PG_fini(void);

static void	 write_logfmt(ErrorData *edata);
static int	 appendLogFmtAttr(StringInfo buf, const char *key, const char *value);
static int	 appendLogFmtAttrf(StringInfo buf, const char *key, const char *fmt, ...) pg_attribute_printf(3, 4);
static void	 appendPadding(StringInfo buf, int padding, int pos);
static char *get_logfmt_formatted_log_time(void);
static void	 write_console(const char *line, int len);

static emit_log_hook_type prev_emit_log_hook = NULL;
static char				 *logfmt_application_context;

void
_PG_init(void)
{
	prev_emit_log_hook = emit_log_hook;
	emit_log_hook	   = write_logfmt;

	DefineCustomStringVariable("logfmt.application_context",
							   "A user defined field to attach log lines to a context.",
							   NULL,
							   &logfmt_application_context,
							   NULL,
							   PGC_USERSET,
							   0,
							   NULL,
							   NULL,
							   NULL);
	MarkGUCPrefixReserved("logfmt");
}

void
_PG_fini(void)
{
	if (emit_log_hook == write_logfmt)
		emit_log_hook = prev_emit_log_hook;
}

static void
write_logfmt(ErrorData *edata)
{
	static bool	   in_hook = false;
	StringInfoData buf;
	int			   attr_len;
	TransactionId  xid;
	uint64		   qid;

	/* Protect from recursive calls */
	if (in_hook)
		return;

	if (!edata->output_to_server)
		return;

	in_hook = true;

	initStringInfo(&buf);
	appendLogFmtAttr(&buf, "ts", get_logfmt_formatted_log_time());
	if (MyProcPid != 0) {
		attr_len = appendLogFmtAttrf(&buf, "pid", "%d", MyProcPid);
		appendPadding(&buf, 6, attr_len);
	}
	attr_len = appendLogFmtAttr(&buf, "level", error_severity(edata->elevel));
	appendPadding(&buf, 8, attr_len);

	if (Log_error_verbosity >= PGERROR_VERBOSE)
		appendLogFmtAttr(&buf, "errcode", unpack_sql_state(edata->sqlerrcode));
	appendLogFmtAttr(&buf, "message", edata->message);

	if (application_name && application_name[0] != '\0')
		appendLogFmtAttr(&buf, "application.name", application_name);
	if (logfmt_application_context && logfmt_application_context[0] != '\0')
		appendLogFmtAttr(&buf, "application.context", logfmt_application_context);

	if (MyProcPort) {
		appendLogFmtAttr(&buf, "user", MyProcPort->user_name);
		if (Log_error_verbosity >= PGERROR_DEFAULT && MyProcPort->remote_host) {
			appendLogFmtAttr(&buf, "remote.host", MyProcPort->remote_host);
			if (MyProcPort->remote_port && MyProcPort->remote_port[0] != '\0')
				appendLogFmtAttr(&buf, "remote.port", MyProcPort->remote_port);
		}
		appendLogFmtAttr(&buf, "dbname", MyProcPort->database_name);
	}

	if (Log_error_verbosity >= PGERROR_DEFAULT) {
		if (edata->detail_log)
			appendLogFmtAttr(&buf, "detail", edata->detail_log);
		else if (edata->detail)
			appendLogFmtAttr(&buf, "detail", edata->detail);
		appendLogFmtAttr(&buf, "hint", edata->hint);
		xid = GetTopTransactionIdIfAny();
		if (xid)
			appendLogFmtAttrf(&buf, "xid", "%u", xid);
		if (MyProc != NULL && MyProc->backendId != InvalidBackendId)
			appendLogFmtAttrf(&buf, "vxid", "%d/%u", MyProc->backendId, MyProc->lxid);

		if (edata->internalquery) {
			appendLogFmtAttr(&buf, "internal.query", edata->internalquery);
			/* if printed internal query, print internal pos too */
			if (edata->internalpos > 0)
				appendLogFmtAttrf(&buf, "internal.position", "%d", edata->internalpos);
		}

		if (edata->context && !edata->hide_ctx)
			appendLogFmtAttr(&buf, "context", edata->context);

		appendLogFmtAttr(&buf, "backend_type", get_backend_type_for_log());
		if (MyProc) {
			PGPROC *leader = MyProc->lockGroupLeader;
			if (leader && leader->pid != MyProcPid)
				appendLogFmtAttrf(&buf, "leader.pid", "%d", leader->pid);
		}
	}

	/* user query --- only reported if not disabled by the caller */
	if (check_log_of_query(edata)) {
		appendLogFmtAttr(&buf, "statement", debug_query_string);
		if (edata->cursorpos > 0)
			appendLogFmtAttrf(&buf, "statement.position", "%d", edata->cursorpos);
	}
	if (Log_error_verbosity >= PGERROR_DEFAULT) {
		qid = pgstat_get_my_query_id();
		if (qid)
			appendLogFmtAttrf(&buf, "statement.qid", "%lld", (long long)qid);
	}

	if (Log_error_verbosity >= PGERROR_VERBOSE) {
		if (edata->filename) {
			appendLogFmtAttr(&buf, "location.file", edata->filename);
			appendLogFmtAttrf(&buf, "location.line", "%d", edata->lineno);
		}
		if (edata->funcname)
			appendLogFmtAttr(&buf, "location.func", edata->funcname);
		if (edata->backtrace)
			appendLogFmtAttr(&buf, "backtrace", edata->backtrace);
	}

	appendStringInfoString(&buf, "\n");

	/* Always write to console, directly. The target usage is a container with postgres binary stderr piped to loki by
	 * container runtime. */
	write_console(buf.data, buf.len);

	pfree(buf.data);

	in_hook = false;

	/* Skip built-in writer by skipping error. */
	edata->output_to_server = false;
}

static int
appendLogFmtAttr(StringInfo buf, const char *key, const char *value)
{
	bool in_quote = false;
	int	 start;
	int	 i;
	int	 attr_start;

	if (NULL == value)
		return 0;

	if (0 < buf->len)
		appendStringInfoChar(buf, ' ');

	appendStringInfoString(buf, key);
	appendStringInfoChar(buf, '=');
	attr_start = buf->len;

	/* value = my log message
	 * start = ^
	 * i     = ^
	 * buf   = key=
	 */
	start = 0;
	for (i = start; value[i] != '\0'; i++) {
		if (' ' == value[i] || '"' == value[i] || '\n' == value[i]) {
			if (!in_quote) {
				appendStringInfoChar(buf, '"');
				in_quote = true;
			}

			if (i - start) {
				/* value = my log message
				 * start = ^
				 * i     =   ^
				 * buf   = key=
				 */
				appendBinaryStringInfo(buf, value + start, i - start);
			}
			/* value = my log message
			 * start =   ^
			 * i     =    ^
			 * buf   = key=my
			 */
			start = i + 1;

			if ('"' == value[i]) {
				/* value = my"log message
				 * start =   ^
				 * i     =   ^
				 * buf   = key=my\"
				 */
				appendStringInfoChar(buf, '\\');
				appendStringInfoChar(buf, '"');
			} else if ('\n' == value[i]) {
				/* value = my\nlog message
				 * start =   ^
				 * i     =   ^
				 * buf   = key="my\n
				 */
				appendStringInfoChar(buf, '\\');
				appendStringInfoChar(buf, 'n');
			} else {
				appendStringInfoChar(buf, ' ');
			}
		}
	}

	/* value = my log message
	 * start = ^
	 * i     =               ^
	 * buf   = "
	 */
	if (i - start)
		appendBinaryStringInfo(buf, value + start, i - start);

	/* value = my log message
	 * start = ^
	 * i     =               ^
	 * buf   = "my log message
	 */
	if (in_quote)
		appendStringInfoChar(buf, '"');

	return buf->len - attr_start;
}

static int
appendLogFmtAttrf(StringInfo buf, const char *key, const char *fmt, ...)
{
	int	   save_errno = errno;
	size_t len		  = 128; /* initial assumption about buffer size */
	char  *value;
	int	   attr_len;

	for (;;) {
		va_list args;
		size_t	newlen;

		/* Allocate result buffer */
		value = (char *)palloc(len);

		/* Try to format the data. */
		errno = save_errno;
		va_start(args, fmt);
		newlen = pvsnprintf(value, len, fmt, args);
		va_end(args);

		if (newlen < len)
			break; /* success */

		/* Release buffer and loop around to try again with larger len. */
		pfree(value);
		len = newlen;
	}

	attr_len = appendLogFmtAttr(buf, key, value);

	/* Clean up */
	pfree(value);

	return attr_len;
}

static void
appendPadding(StringInfo buf, int padding, int pos)
{
	if (pos > padding) {
		return;
	}

	appendStringInfoSpaces(buf, padding - pos);
}

/* Stolen from elog.c */

#define FORMATTED_TS_LEN 128
/* static char formatted_start_time[FORMATTED_TS_LEN]; */
static char formatted_log_time[FORMATTED_TS_LEN];

static char *
get_logfmt_formatted_log_time(void)
{
	char		   msbuf[13];
	struct timeval log_timeval;
	pg_time_t	   stamp_time;

	gettimeofday(&log_timeval, NULL);
	stamp_time = (pg_time_t)log_timeval.tv_sec;

	/*
	 * Note: we expect that guc.c will ensure that log_timezone is set up (at
	 * least with a minimal GMT value) before Log_line_prefix can become
	 * nonempty or CSV mode can be selected.
	 */
	pg_strftime(formatted_log_time,
				FORMATTED_TS_LEN,
				/* leave room for milliseconds... */
				"%Y-%m-%dT%H:%M:%S    %z",
				pg_localtime(&stamp_time, log_timezone));

	/* 'paste' milliseconds into place... */
	sprintf(msbuf, ".%03d", (int)(log_timeval.tv_usec / 1000));
	memcpy(formatted_log_time + 19, msbuf, 4);

	return formatted_log_time;
}

/* Stolen from elog.c */
static void
write_console(const char *line, int len)
{
	int rc;

#ifdef WIN32

	/*
	 * Try to convert the message to UTF16 and write it with WriteConsoleW().
	 * Fall back on write() if anything fails.
	 *
	 * In contrast to write_eventlog(), don't skip straight to write() based
	 * on the applicable encodings.  Unlike WriteConsoleW(), write() depends
	 * on the suitability of the console output code page.  Since we put
	 * stderr into binary mode in SubPostmasterMain(), write() skips the
	 * necessary translation anyway.
	 *
	 * WriteConsoleW() will fail if stderr is redirected, so just fall through
	 * to writing unconverted to the logfile in this case.
	 *
	 * Since we palloc the structure required for conversion, also fall
	 * through to writing unconverted if we have not yet set up
	 * CurrentMemoryContext.
	 */
	if (!in_error_recursion_trouble() && !redirection_done && CurrentMemoryContext != NULL) {
		WCHAR *utf16;
		int	   utf16len;

		utf16 = pgwin32_message_to_UTF16(line, len, &utf16len);
		if (utf16 != NULL) {
			HANDLE stdHandle;
			DWORD  written;

			stdHandle = GetStdHandle(STD_ERROR_HANDLE);
			if (WriteConsoleW(stdHandle, utf16, utf16len, &written, NULL)) {
				pfree(utf16);
				return;
			}

			/*
			 * In case WriteConsoleW() failed, fall back to writing the
			 * message unconverted.
			 */
			pfree(utf16);
		}
	}
#else

	/*
	 * Conversion on non-win32 platforms is not implemented yet. It requires
	 * non-throw version of pg_do_encoding_conversion(), that converts
	 * unconvertible characters to '?' without errors.
	 *
	 * XXX: We have a no-throw version now. It doesn't convert to '?' though.
	 */
#endif

	/*
	 * We ignore any error from write() here.  We have no useful way to report
	 * it ... certainly whining on stderr isn't likely to be productive.
	 */
	rc = write(fileno(stderr), line, len);
	(void)rc;
}

PG_FUNCTION_INFO_V1(emit_test_logs);

Datum
emit_test_logs(PG_FUNCTION_ARGS)
{
	ereport(LOG, errcode(ERRCODE_UNDEFINED_CURSOR), errmsg("Lorem ipsum dolor sit amet."));
	ereport(DEBUG5, errmsg("Nam ut magna felis."));
	ereport(LOG,
			errmsg("Praesent nec ligula a erat tempus egestas vel a ligula."),
			errhint("Class aptent taciti sociosqu ad litora torquent."));
	ereport(LOG,
			errmsg("Fusce molestie augue non finibus tristique."),
			errcontext_msg("Context proin eget quam ultrices"));
	ereport(WARNING,
			errmsg("Integer quis consequat tellus.\n"
				   "Pellentesque habitant morbi tristique senectus et netus et malesuada fames ac turpis egestas.\n"));
	PG_RETURN_NULL();
}