#if UNIX using System; using System.Diagnostics; using System.Globalization; using System.Reflection; using System.Resources; using System.Runtime.InteropServices; using System.Text; using System.Threading; using System.Management.Automation.Internal; namespace System.Management.Automation.Tracing { /// /// Encapsulates the message resource and SysLog logging for an ETW event. /// The other half of the partial class is generated by EtwGen and contains a /// static dictionary containing the event id mapped to the associated event meta data /// and resource string reference. /// /// /// This component logs ETW trace events to syslog. /// The log entries use the following common format /// (commitId:threadId:channelid) [context] payload /// Where: /// commitId: A hash code of the full git commit id string. /// threadid: The thread identifier of calling code. /// channelid: The identifier for the output channel. See PSChannel for values. /// context: Dependent on the type of log entry. /// payload: Dependent on the type of log entry. /// Note: /// commitId, threadId, and eventId are logged as HEX without a leading /// '0x'. /// /// 4 types of log entries are produced. /// NOTE: Where constant string are logged, the template places the string in /// double quotes. For example, the GitCommitId log entry uses "GitCommitId" /// for the context value. /// /// Note that the examples illustrate the output from SysLogProvider.Log, /// Data automatically prepended by syslog, such as timestamp, hostname, ident, /// and processid are not shown. /// /// GitCommitId /// This is the first log entry for a session. It provides a correlation /// between the full git commit id string and a hash code used for subsequent /// log entries. /// Context: "GitCommitId" /// Payload: string "Hash:" hashcode as HEX string. /// For official builds, the GitCommitID is the release tag. For other builds the commit id may include an SHA-1 hash at the /// end of the release tag. /// Example 1: Official release /// (19E1025:3:10) [GitCommitId] v6.0.0-beta.9 Hash:64D0C08D /// Example 2: Commit id with SHA-1 hash /// (19E1025:3:10) [GitCommitId] v6.0.0-beta.8-67-gca2630a3dea6420a3cd3914c84a74c1c45311f54 Hash:8EE3A3B3 /// /// Transfer /// A log entry to record a transfer event. /// Context: "Transfer" /// The playload is two, space separated string guids, the first being the /// parent activityid followed by the new activityid. /// Example: (19E1025:3:10) [Transfer] {de168a71-6bb9-47e4-8712-bc02506d98be} {ab0077f6-c042-4728-be76-f688cfb1b054} /// /// Activity /// A log entry for when activity is set. /// Context: "Activity" /// Payload: The string guid of the activity id. /// Example: (19E1025:3:10) [Activity] {ab0077f6-c042-4728-be76-f688cfb1b054} /// /// Event /// Application logging (Events) /// Context: EventId:taskname.opcodename.levelname /// Payload: The event's message text formatted with arguments from the caller. /// Example: (19E1025:3:10) [Perftrack_ConsoleStartupStart:PowershellConsoleStartup.WinStart.Informational] PowerShell console is starting up /// internal class SysLogProvider { // Ensure the string pointer is not garbage collected. static IntPtr _nativeSyslogIdent = IntPtr.Zero; static NativeMethods.SysLogPriority _facility = NativeMethods.SysLogPriority.Local0; byte _channelFilter; ulong _keywordFilter; byte _levelFilter; /// /// Initializes a new instance of this class. /// /// The log identity name used to identify the application in syslog. /// The trace level to enable. /// The keywords to enable. /// The output channels to enable. public SysLogProvider(string applicationId, PSLevel level, PSKeyword keywords, PSChannel channels) { // NOTE: This string needs to remain valid for the life of the process since the underlying API keeps // a reference to it. // FUTURE: If logging is redesigned, make these details static or a singleton since there should only be one // instance active. _nativeSyslogIdent = Marshal.StringToHGlobalAnsi(applicationId); NativeMethods.OpenLog(_nativeSyslogIdent, _facility); _keywordFilter = (ulong)keywords; _levelFilter = (byte) level; _channelFilter = (byte) channels; } /// /// Defines a thread local StringBuilder for building log messages. /// /// /// NOTE: do not access this field directly, use the MessageBuilder /// property to ensure correct thread initialization; otherwise, a null reference can occur. /// [ThreadStatic] private static StringBuilder _messageBuilder; private static StringBuilder MessageBuilder { get { if (_messageBuilder == null) { // NOTE: Thread static fields must be explicitly initialized for each thread. _messageBuilder = new StringBuilder(200); } return _messageBuilder; } } /// /// Defines a activity id for the current thread. /// /// /// NOTE: do not access this field directly, use the Activity property /// to ensure correct thread initialization. /// [ThreadStatic] static Guid? _activity; private static Guid Activity { get { if (_activity.HasValue == false) { // NOTE: Thread static fields must be explicitly initialized for each thread. _activity = Guid.NewGuid(); } return _activity.Value; } set { _activity = value; } } /// /// Gets the value indicating if the specified level and keywords are enabled for logging. /// /// The PSLevel to check. /// The PSKeyword to check. /// true if the specified level and keywords are enabled for logging. internal bool IsEnabled(PSLevel level, PSKeyword keywords) { return ( ((ulong) keywords & _keywordFilter) != 0 && ((int) level <= _levelFilter) ); } // NOTE: There are a number of places where PowerShell code sends analytic events // to the operational channel. This is a side-effect of the custom wrappers that // use flags that are not consistent with the event definition. // To ensure filtering of analytic events is consistent, both keyword and channel // filtering is performed to suppress analytic events. private bool ShouldLog(PSLevel level, PSKeyword keywords, PSChannel channel) { return ((_channelFilter & (ulong)channel) != 0 && IsEnabled(level, keywords)); } #region resource manager private static global::System.Resources.ResourceManager _resourceManager; private static global::System.Globalization.CultureInfo _resourceCulture; private static global::System.Resources.ResourceManager ResourceManager { get { if (object.ReferenceEquals(_resourceManager, null)) { _resourceManager = new global::System.Resources.ResourceManager("System.Management.Automation.resources.EventResource", typeof(EventResource).GetTypeInfo().Assembly); } return _resourceManager; } } /// /// Overrides the current threads CurrentUICulture property for all /// resource lookups using this strongly typed resource class. /// [global::System.ComponentModel.EditorBrowsableAttribute(global::System.ComponentModel.EditorBrowsableState.Advanced)] internal static global::System.Globalization.CultureInfo Culture { get { return _resourceCulture; } set { _resourceCulture = value; } } private static string GetResourceString(string resourceName) { string value = ResourceManager.GetString(resourceName, Culture); if (string.IsNullOrEmpty(value)) { value = string.Format(CultureInfo.InvariantCulture, "Unknown resource: {0}", resourceName); Diagnostics.Assert(false, value); } return value; } #endregion resource manager /// /// Gets the EventMessage for a given event. /// /// The StringBuilder to append. /// The id of the event to retrieve. /// An array of zero or more payload objects. private static void GetEventMessage(StringBuilder sb, PSEventId eventId, params object[] args ) { int parameterCount; string resourceName = EventResource.GetMessage((int) eventId, out parameterCount); if (resourceName == null) { // If an event id was specified that is not found in the event resource lookup table, // use a placeholder message that includes the event id. resourceName = EventResource.GetMissingEventMessage(out parameterCount); Diagnostics.Assert(false, sb.ToString()); args = new object[] {eventId}; } string resourceValue = GetResourceString(resourceName); if (parameterCount > 0) { sb.AppendFormat(resourceValue, args); } else { sb.Append(resourceValue); } } #region logging // maps a LogLevel to an associated SysLogPriority. static NativeMethods.SysLogPriority[] _levels = { NativeMethods.SysLogPriority.Info, NativeMethods.SysLogPriority.Critical, NativeMethods.SysLogPriority.Error, NativeMethods.SysLogPriority.Warning, NativeMethods.SysLogPriority.Info, NativeMethods.SysLogPriority.Info }; /// /// Logs a activity transfer. /// /// The parent activity id. public void LogTransfer(Guid parentActivityId) { // NOTE: always log int threadId = Thread.CurrentThread.ManagedThreadId; string message = string.Format(CultureInfo.InvariantCulture, "({0}:{1:X}:{2:X}) [Transfer]:{3} {4}", PSVersionInfo.GitCommitId, threadId, PSChannel.Operational, parentActivityId.ToString("B"), Activity.ToString("B")); NativeMethods.SysLog(NativeMethods.SysLogPriority.Info, message); } /// /// Logs the activity identifier for the current thread. /// /// The Guid activity identifier. public void SetActivity(Guid activity) { int threadId = Thread.CurrentThread.ManagedThreadId; Activity = activity; // NOTE: always log string message = string.Format(CultureInfo.InvariantCulture, "({0:X}:{1:X}:{2:X}) [Activity] {3}", PSVersionInfo.GitCommitId, threadId, PSChannel.Operational, activity.ToString("B")); NativeMethods.SysLog(NativeMethods.SysLogPriority.Info, message); } /// /// Writes a log entry. /// /// The event id of the log entry. /// The channel to log. /// The task for the log entry. /// The operation for the log entry. /// The logging level. /// The keyword(s) for the event. /// The payload for the log message. public void Log(PSEventId eventId, PSChannel channel, PSTask task, PSOpcode opcode, PSLevel level, PSKeyword keyword, params object[] args) { if (keyword == PSKeyword.UseAlwaysAnalytic) { // Use the 'DefaultKeywords' to work around the default keyword filter. // Note that the PSKeyword argument is not really used in writing SysLog. keyword = PSSysLogProvider.DefaultKeywords; } if (ShouldLog(level, keyword, channel)) { int threadId = Thread.CurrentThread.ManagedThreadId; StringBuilder sb = MessageBuilder; sb.Clear(); // add the message preamble sb.AppendFormat(CultureInfo.InvariantCulture, "({0}:{1:X}:{2:X}) [{3:G}:{4:G}.{5:G}.{6:G}] ", PSVersionInfo.GitCommitId, threadId, channel, eventId, task, opcode, level); // add the message GetEventMessage(sb, eventId, args); NativeMethods.SysLogPriority priority; if ((int) level <= _levels.Length) { priority = _levels[(int)level]; } else { priority = NativeMethods.SysLogPriority.Info; } // log it. NativeMethods.SysLog(priority, sb.ToString()); } } #endregion logging } internal enum LogLevel : uint { Always = 0, Critical = 1, Error = 2, Warning = 3, Information = 4, Verbose = 5 } internal static class NativeMethods { const string libpslnative = "libpsl-native"; /// /// Write a message to the system logger, which in turn writes the message to the system console, log files, etc. /// See man 3 syslog for more info. /// /// /// The OR of a priority and facility in the SysLogPriority enum indicating the the priority and facility of the log entry. /// /// The message to put in the log entry. [DllImport(libpslnative, CharSet = CharSet.Ansi, EntryPoint = "Native_SysLog")] internal static extern void SysLog(SysLogPriority priority, string message); [DllImport(libpslnative, CharSet = CharSet.Ansi, EntryPoint = "Native_OpenLog")] internal static extern void OpenLog(IntPtr ident, SysLogPriority facility); [DllImport(libpslnative, EntryPoint = "Native_CloseLog")] internal static extern void CloseLog(); [Flags] internal enum SysLogPriority : uint { // Priorities enum values. /// /// System is unusable /// Emergency = 0, /// /// Action must be taken immediately /// Alert = 1, /// /// Critical conditions /// Critical = 2, /// /// Error conditions /// Error = 3, /// /// Warning conditions /// Warning = 4, /// /// Normal but significant condition /// Notice = 5, /// /// Informational /// Info = 6, /// /// Debug-level messages /// Debug = 7, // Facility enum values. /// /// Kernel messages /// Kernel = (0<<3), /// /// Random user-level messages /// User = (1<<3), /// /// Mail system /// Mail = (2<<3), /// /// System daemons /// Daemon = (3<<3), /// /// Authorization messages /// Authorization = (4<<3), /// /// Messages generated internally by syslogd /// Syslog = (5<<3), /// /// Line printer subsystem /// Lpr = (6<<3), /// /// Network news subsystem /// News = (7<<3), /// /// UUCP subsystem /// Uucp = (8<<3), /// /// Clock daemon /// Cron = (9<<3), /// /// Security/authorization messages (private) /// Authpriv = (10<<3), /// /// FTP daemon /// Ftp = (11<<3), // Reserved for system use /// /// Reserved for local use /// Local0 = (16<<3), /// /// Reserved for local use /// Local1 = (17<<3), /// /// Reserved for local use /// Local2 = (18<<3), /// /// Reserved for local use /// Local3 = (19<<3), /// /// Reserved for local use /// Local4 = (20<<3), /// /// Reserved for local use /// Local5 = (21<<3), /// /// Reserved for local use /// Local6 = (22<<3), /// /// Reserved for local use /// Local7 = (23<<3), } } } #endif // UNIX