From 2f270e768229072f80ad2e6a756672ad7b412cd9 Mon Sep 17 00:00:00 2001 From: midipix Date: Jun 08 2020 01:00:09 +0000 Subject: logging: added core internal interfaces. --- diff --git a/include/toksvc/toksvc.h b/include/toksvc/toksvc.h index 4d68081..d3b56ad 100644 --- a/include/toksvc/toksvc.h +++ b/include/toksvc/toksvc.h @@ -93,6 +93,7 @@ struct toks_common_ctx { uint64_t drvflags; uint64_t actflags; uint64_t fmtflags; + int32_t loglevel; const nt_guid * uuid; void * hroot; const char * sysroot; diff --git a/project/common.mk b/project/common.mk index daf40a3..0309811 100644 --- a/project/common.mk +++ b/project/common.mk @@ -9,6 +9,7 @@ INTERNAL_SRCS = \ src/driver/toks_driver_ctx.c \ src/internal/nolibc/toksvc_compiler.c \ src/internal/toksvc_dprintf_impl.c \ + src/internal/toksvc_log_impl.c \ src/internal/toksvc_memfn_impl.c \ src/internal/toksvc_nolibc_impl.c \ src/internal/toksvc_ntaio_impl.c \ diff --git a/project/headers.mk b/project/headers.mk index ea6bb0c..011226b 100644 --- a/project/headers.mk +++ b/project/headers.mk @@ -15,6 +15,7 @@ INTERNAL_HEADERS = \ $(SOURCE_DIR)/src/internal/toksvc_driver_impl.h \ $(SOURCE_DIR)/src/internal/toksvc_dprintf_impl.h \ $(SOURCE_DIR)/src/internal/toksvc_init_impl.h \ + $(SOURCE_DIR)/src/internal/toksvc_log_impl.h \ $(SOURCE_DIR)/src/internal/toksvc_memfn_impl.h \ $(SOURCE_DIR)/src/internal/toksvc_nolibc_impl.h \ diff --git a/src/driver/toks_driver_ctx.c b/src/driver/toks_driver_ctx.c index 3a0fbb7..a9aba7c 100644 --- a/src/driver/toks_driver_ctx.c +++ b/src/driver/toks_driver_ctx.c @@ -89,6 +89,12 @@ static int toks_driver_usage( return TOKS_USAGE; } +static int32_t toks_query_performance_counters_failover(nt_filetime * ticks) +{ + (void)ticks; + return 0; +} + static struct toks_driver_ctx_impl * toks_driver_ctx_alloc( struct argv_meta * meta, const struct toks_common_ctx * cctx) @@ -108,6 +114,9 @@ static struct toks_driver_ctx_impl * toks_driver_ctx_alloc( if (cctx) memcpy(&ictx->ctx.cctx,cctx,sizeof(*cctx)); + ictx->ctx.ticks.qpc = toks_query_performance_counters_failover; + ictx->ctx.ticks.pcfreq.quad = 0; + ictx->meta = meta; ictx->ctx.rtdata = rtdata; return &ictx->ctx; @@ -173,6 +182,7 @@ int toks_get_driver_ctx( struct argv_entry * uuid; nt_guid svcguid; const char * program; + void * hkernel32; char * targv[TOKS_SARGV_ELEMENTS]; (void)envp; @@ -268,6 +278,19 @@ int toks_get_driver_ctx( if (toks_daemon_init(&toks_daemon_ctx,&ctx->uuid)) return toks_get_driver_ctx_fail(meta); + if ((toks_ntapi->tt_create_private_event( + &ctx->hevent, + NT_NOTIFICATION_EVENT, + NT_EVENT_NOT_SIGNALED))) + return toks_get_driver_ctx_fail(meta); + + if ((hkernel32 = pe_get_kernel32_module_handle())) + if ((ctx->ticks.qpc = pe_get_procedure_address( + hkernel32,"QueryPerformanceCounter"))) + ntapi->zw_query_performance_counter( + &(nt_filetime){{0,0}}, + &ctx->ticks.pcfreq); + ctx->ctx.program = program; ctx->ctx.cctx = &ctx->cctx; ctx->cctx.uuid = &ctx->uuid; @@ -278,6 +301,9 @@ int toks_get_driver_ctx( static void toks_free_driver_ctx_impl(struct toks_driver_ctx_alloc * ictx) { + if (ictx->ctx.hevent) + ntapi->zw_close(ictx->ctx.hevent); + argv_free(ictx->meta); free(ictx); } diff --git a/src/internal/toksvc_driver_impl.h b/src/internal/toksvc_driver_impl.h index 4222638..2c41eb0 100644 --- a/src/internal/toksvc_driver_impl.h +++ b/src/internal/toksvc_driver_impl.h @@ -25,6 +25,11 @@ enum app_tags { TAG_UUID, }; +struct toks_ticks { + nt_filetime pcfreq; + int32_t (*qpc)(nt_filetime *); +}; + struct toks_client_ctx { void * hprocess; void * hthread; @@ -37,6 +42,8 @@ struct toks_driver_ctx_impl { struct toks_client_ctx clctx; struct toks_common_ctx cctx; struct toks_driver_ctx ctx; + struct toks_ticks ticks; + void * hevent; nt_guid uuid; }; @@ -59,6 +66,13 @@ static inline nt_rtdata * toks_get_driver_rtdata(const struct toks_driver_ctx * return ictx->rtdata; } +static inline void * toks_get_driver_hevent(const struct toks_driver_ctx * dctx) +{ + struct toks_driver_ctx_impl * ictx; + ictx = toks_get_driver_ictx(dctx); + return ictx->hevent; +} + static inline const nt_guid * toks_get_driver_uuid(const struct toks_driver_ctx * dctx) { struct toks_driver_ctx_impl * ictx; @@ -66,6 +80,15 @@ static inline const nt_guid * toks_get_driver_uuid(const struct toks_driver_ctx return &ictx->uuid; } +static inline void toks_query_performance_counters(const struct toks_driver_ctx * dctx, nt_filetime * ticks) +{ + struct toks_driver_ctx_impl * ictx; + ictx = toks_get_driver_ictx(dctx); + + if (!(ictx->ticks.qpc(ticks))) + ticks->quad = 0; +} + int32_t toks_open_file(void ** hfile, void * hat, const char * arg, bool fprivate); int32_t toks_open_dir(void ** hfile, void * hat, const char * arg, bool fprivate); diff --git a/src/internal/toksvc_log_impl.c b/src/internal/toksvc_log_impl.c new file mode 100644 index 0000000..b6a9cbb --- /dev/null +++ b/src/internal/toksvc_log_impl.c @@ -0,0 +1,232 @@ +/*********************************************************/ +/* toksvc: a framework-native token broker service */ +/* Copyright (C) 2020 Z. Gilboa */ +/* Released under GPLv2 and GPLv3; see COPYING.TOKSVC. */ +/*********************************************************/ + +#include + +#include "toksvc_driver_impl.h" +#include "toksvc_dprintf_impl.h" +#include "toksvc_log_impl.h" + +static const char * toks_log_entry_header[15] = { + [TOKS_LOG_ENTRY_SERVER_STATUS] = "SERVER (STATUS):", + [TOKS_LOG_ENTRY_SERVER_INFO] = "SERVER (INFO): ", + [TOKS_LOG_ENTRY_SERVER_ERROR] = "SERVER (ERROR): ", + [TOKS_LOG_ENTRY_CLIENT_STATUS] = "CLIENT (STATUS):", + [TOKS_LOG_ENTRY_CLIENT_INFO] = "CLIENT (INFO): ", + [TOKS_LOG_ENTRY_CLIENT_ERROR] = "CLIENT (ERROR): ", + [TOKS_LOG_ENTRY_SUB_LEVEL_1] = " ├─", + [TOKS_LOG_ENTRY_SUB_LEVEL_2] = " ├───", + [TOKS_LOG_ENTRY_SUB_LEVEL_3] = " ├─────", + [TOKS_LOG_ENTRY_SUB_LEVEL_4] = " ├───────", + [TOKS_LOG_ENTRY_SUB_LEVEL_5] = " ├─────────", + [TOKS_LOG_ENTRY_SUB_LEVEL_6] = " ├───────────", +}; + +static int32_t toks_log_strconv_utf16_to_utf8( + const wchar16_t * wch, + size_t len, + char * ch, + size_t bufsize) +{ + int32_t status; + nt_strconv_nativetomb params; + + params.src = wch; + params.src_size_in_bytes = len; + params.dst = (unsigned char *)ch; + params.dst_size_in_bytes = bufsize; + params.code_points = 0; + params.bytes_written = 0; + + status = ntapi->uc_convert_unicode_stream_utf16_to_utf8(¶ms); + + if (status == NT_STATUS_SUCCESS) + ch[params.bytes_written] = 0; + + return params.leftover_count + ? NT_STATUS_ILLEGAL_CHARACTER + : status; +} + +static int32_t toks_log_write_impl( + const struct toks_driver_ctx * dctx, + const void * buf, + size_t size) +{ + int32_t status; + nt_runtime_data * rtdata; + ntapi_zw_write_file * iofn; + void * hlog; + void * hio; + void * hevent; + int fdtype; + nt_iosb iosb; + + /* size */ + if (size >= 0x80000000) + return NT_STATUS_INVALID_PARAMETER; + + /* rtdata, hevent, hlog */ + hevent = toks_get_driver_hevent(dctx); + rtdata = toks_get_driver_rtdata(dctx); + hlog = rtdata->hlog; + + /* hio, io type */ + if (hlog) { + hio = hlog; + fdtype = NT_FILE_TYPE_UNKNOWN; + } else { + hio = rtdata->hstderr; + fdtype = rtdata->stderr_type; + } + + if (!hio) + return NT_STATUS_INVALID_HANDLE; + + /* iofn */ + iofn = (fdtype == NT_FILE_TYPE_PTY) + ? (ntapi_zw_write_file *)toks_ntapi->pty_write + : toks_ntapi->zw_write_file; + + /* iowrite */ + status = iofn( + hio,hevent, + 0,0,&iosb, + (void *)buf,size, + 0,0); + + /* todo: flush */ + switch (status) { + case NT_STATUS_PENDING: + status = toks_ntapi->zw_wait_for_single_object( + hevent,0,0); + break; + + default: + iosb.status = status; + break; + } + + /* ret */ + return iosb.status ? iosb.status : iosb.info; +} + +void toks_log_header( + const struct toks_driver_ctx * dctx, + enum toks_log_entry_type type, + const char * fmt, + ...) +{ + nt_filetime pcnt; + va_list ap; + char * ch; + char buf[2048]; + + toks_query_performance_counters(dctx,&pcnt); + + va_start(ap, fmt); + ch = buf; + ch += ntapi->sprintf(ch,"\n[%08x.%08x]: ",pcnt.ihigh,pcnt.ulow); + ch += ntapi->sprintf(ch,"%s ",toks_log_entry_header[type]); + ch += ntapi->vsnprintf(ch, &buf[sizeof(buf)] - ch, fmt, ap); + va_end(ap); + + toks_log_write_impl(dctx,buf,ch-buf); +} + +void toks_log_write( + const struct toks_driver_ctx * dctx, + enum toks_log_entry_type type, + const char * fmt, + ...) +{ + va_list ap; + char * ch; + char buf[2048]; + + va_start(ap, fmt); + ch = buf; + ch += ntapi->sprintf(buf,"%s ",toks_log_entry_header[type]); + ch += ntapi->vsnprintf(ch, &buf[sizeof(buf)] - ch, fmt, ap); + va_end(ap); + + toks_log_write_impl(dctx,buf,ch-buf); +} + +void toks_log_get_process_name(void * hprocess, char * utf8, size_t bytes) +{ + wchar16_t buf[0x1000]; + nt_unicode_string * path; + + path = (nt_unicode_string *)buf; + + if (!(ntapi->zw_query_information_process( + hprocess, + NT_PROCESS_IMAGE_FILE_NAME, + buf,sizeof(buf), + &(uint32_t){0}))) + if (!(toks_log_strconv_utf16_to_utf8( + path->buffer, + path->strlen, + utf8,bytes))) + return; + + ntapi->tt_generic_memcpy( + utf8, + (char[]){'#','E','R','R','O','R',0}, + 7); +} + +void toks_log_get_arbitrary_process_name(nt_cid * cid, char * utf8, size_t bytes) +{ + void * hprocess = NT_INVALID_HANDLE_VALUE; + nt_oa oa = {sizeof(oa),0,0,0,0,0}; + + if (cid->process_id == 0) { + *utf8++ = '('; + *utf8++ = 'N'; + *utf8++ = '/'; + *utf8++ = 'A'; + *utf8++ = ')'; + *utf8++ = 0; + return; + } + + ntapi->zw_open_process( + &hprocess, + NT_PROCESS_SYNCHRONIZE | NT_PROCESS_QUERY_INFORMATION, + &oa,cid); + + if (hprocess == NT_INVALID_HANDLE_VALUE) { + ntapi->tt_generic_memcpy( + utf8, + (char[]){'#','E','R','R','O','R',0}, + 7); + + return; + } + + toks_log_get_process_name( + hprocess, + utf8,bytes); + + ntapi->zw_close( + hprocess); +} + +const char * toks_log_basename(const char * path) +{ + const char * ch; + + for (ch=path; *ch; ch++) + (void)0; + + for (--ch; ch>=path; ch--) + if (*ch == '\\') + return ++ch; + + return path; +} diff --git a/src/internal/toksvc_log_impl.h b/src/internal/toksvc_log_impl.h new file mode 100644 index 0000000..74b15ab --- /dev/null +++ b/src/internal/toksvc_log_impl.h @@ -0,0 +1,48 @@ +#ifndef TOKSVC_LOG_IMPL_H +#define TOKSVC_LOG_IMPL_H + +#include + +#define TOKS_LOG_LEVEL(dctx,x) \ + if (dctx->cctx->loglevel < x) \ + return + +#define TOKS_LOG_CHILD_EXIT_STATUS(x) (((x) & 0xff00) >> 8) +#define TOKS_LOG_CHILD_KILL_STATUS(x) (((x) & 0x7f)) + +enum toks_log_entry_type { + TOKS_LOG_ENTRY_SERVER_STATUS, + TOKS_LOG_ENTRY_SERVER_INFO, + TOKS_LOG_ENTRY_SERVER_ERROR, + TOKS_LOG_ENTRY_CLIENT_STATUS, + TOKS_LOG_ENTRY_CLIENT_INFO, + TOKS_LOG_ENTRY_CLIENT_ERROR, + TOKS_LOG_ENTRY_SUB_LEVEL_1, + TOKS_LOG_ENTRY_SUB_LEVEL_2, + TOKS_LOG_ENTRY_SUB_LEVEL_3, + TOKS_LOG_ENTRY_SUB_LEVEL_4, + TOKS_LOG_ENTRY_SUB_LEVEL_5, + TOKS_LOG_ENTRY_SUB_LEVEL_6, +}; + +const char * toks_log_basename(const char * path); + +void toks_log_header( + const struct toks_driver_ctx *, + enum toks_log_entry_type, + const char *, + ...); + +void toks_log_write( + const struct toks_driver_ctx *, + enum toks_log_entry_type, + const char *, + ...); + +void toks_log_get_process_name( + void *, char *, size_t); + +void toks_log_get_arbitrary_process_name( + nt_cid *, char *, size_t); + +#endif