PowerShell / DscResource.Template

MIT License
10 stars 15 forks source link

Common Verbose logging and standards #25

Open kungfoome opened 5 years ago

kungfoome commented 5 years ago

related to #17

I had a few ideas about logging.

  1. Possibly group verbose messages together when possible (i'll show example)
  2. Start each function with a verbose message saying what you are going to do
  3. Verbose messages when comparing all parameters (state if parameter is in state or not)
  4. On Test, verbose message if state is compliant or not (maybe redundant?)
  5. Verbose message for every try/catch?

Example for 1:

ConvertFrom-StringData -StringData @'
    # Multiple (SRS{n}000) - These messages can be used for all areas in the script.
    # The 1000's decimal will say where the error came from [get (1),set (2),test (3), compare (4)]
    IssueRetrievingCIMInstance = There was an issue when trying to retrieve the CIM instance. This shouldn't have happened. For further diganostics, please ensure that the following command can run `{0}`. (SRS{1}001)
    IssueRetrievingRSInstance = There was an issue when trying to retrieve the Reporting Services instance name. This is probably due to the fact that Reporting Services may not be installed. (SRS{1}002)

    # Get-TargetResource (SRS0100)
    RetrievingRSState                = Attempting to get the current Reporting Service state. (SRS0100)
    RetrievingInstanceUrls           = Attempting to get the Reporting Service Instance Url list. (SRS0101)
    RetrievingInstanceUrlsSuccess    = Successfully retrieved the Reporting Service Instance Url list. (SRS0102)
    RetrievingModifiableUrls         = Attempting to get the Reporting Service Modifiable Url list. (SRS0103)
    RetrievingModifiableUrlsSuccess  = Successfully retrieved the Reporting Service Modifiable Url list. (SRS0104)
    RetrievingScaleOutServers        = Attempting to get a list of the Reporting Service Scale-Out servers. (SRS0104)
    RetrievingScaleOutServersSuccess = Successfully retrieved the list of Reporting Service Scale-Out servers. (SRS0105)
    RetrivedServiceAccount           = Retrieved the service account of '{0}', which is a '{1}' logon type. (SRS0106)

    # Test-TargetResource (SRS0200)
    TestingDesiredState = Testing if the Reporting Services instance of '{0}' is in desired state (SRS0200)
    RSInDesiredState    = Reporting Services '{0}' is in the desired state. (SRS0201)
    RSNotInDesiredState = Reporting Services '{0}' is NOT in the desired state. (SRS0202)

    # Set-TargetResource (SRS0300)
    SettingNonDesiredStateParameters = Attempting to set all parameters that are not in desired state for the instance '{0}'. (SRS0300)

    # Compare-TargetResourceState (SRS0400)
    ComparingSpecifiedParameters = Comparing all the parameters specified for the instance '{0}'. (SRS0400)
    CheckingParameterState       = Checking if the parameter '{0}' is in desired state. (SRS0401)
    ParameterNotInDesiredState   = The parameter '{0}' was found to NOT be in the correct desired state. Expected: '{1}', Actual '{2}'. (SRS0402)
    ParameterInDesiredState      = The parameter '{0}' was found to be the correct desired state. Expected: '{1}',        Actual '{2}'. (SRS0403)

    # (SRS9000) will be used for anything else
    # Get-RsCimInstance
    RetrievingRSInstanceNameAuto           = Attempting to retrieve the Reporting Service instance name automatically. (SRS9000)
    SetRSInstanceName                      = Reporting Service instance name was set to '{0}'. (SRS9001)
    RetrievingRSInstanceVersion            = Attempting to retrieve the Reporting Service instance version. (SRS9002)
    SetRSInstanceVersion                   = Reporting Service instance version was set to '{0}'. (SRS9003)
    RetrievingRSInstanceObject             = Attempting to retrieve the Reporting Service instance object. (SRS9004)
    RetrievingRSInstanceObjectSuccess      = The Reporting Services instance object was successfully retrieved. (SRS9005)
    RetrievingRSConfigurationObject        = Attempting to retrieve the Reporting Service configuration object. (SRS9006)
    RetrievingRSConfigurationObjectSuccess = The Reporting Services configuration object was successfully retrieved. (SRS9007)

    # MSFT_ReportServiceSkuUtils (SRS0600)
    RSSkuTypeNotInitialized       = It appears that the Reporting Services sku type hasn't been defined yet or not found. This should be set to one of the following types: {0}. (SRS0600)
    RSSkuTypeIsHigherEdition      = The Reporting services sku type: '{0}' was found to be a HIGHER edition than that of the '{1} Edition'. (SRS0601)
    RSSkuTypeIsNotHigherEdition   = The Reporting services sku type: '{0}' was found to be a LOWER edition than that of the '{1} Edition'. (SRS0602)
    RSSkuTypeFullNameNotFound     = Could not identify the reporting services edition of '{0}'. This could be that the edition is new and needs to be added to the resource. (SRS0603)
    RSandSQLEditionsNotValid      = The database installation of reporting services with the sku type of '{0}' is restricted on the SQL sku type of '{1}' (SRS0604)
    RSandSQLEditionsNotValidLocal = The database installation of reporting services with the sku type of '{0}' requires that the SQL instance be installed on the same node. It appears that you are trying to install reporting services on a remote node. (SRS0605)

'@

I'll try and explain. So it's kind of a rudimentary way to trace the code. Messages that can be used throughout start with {n}000, this gives you about 3000 messages basically. I'll explain later.

All messages that come from Get start with 0100 All messages that come from Test start with 0200 All messages that come from Set start with 0300

If it's a message that is shared, it would be whatever number each function starts with. So Get is 1, Test is 2, Set is 3. So if a shared message is called within Get, it would be 100x where x is whatever the actual message code is.

In this example, I have 9000+ has any other messages per function. so if i were to add more messaging for a new function I may want to do 9100. Giving me a possible 100 messages per function. This can really be whatever you want it to after 0300 though. And 1000-3999 would be reserved.

Few examples of what it would look like: You can see here, It's called from Test -> Compare -> Get

VERBOSE: Testing if the Reporting Services instance of 'SSRS' is in desired state (SRS0200)
VERBOSE: Comparing all the parameters specified for the instance 'SSRS'. (SRS0400)
VERBOSE: Attempting to get the current Reporting Service state. (SRS0100)
VERBOSE: Reporting Service instance name was set to 'RS_SSRS'. (SRS9001)
VERBOSE: Attempting to retrieve the Reporting Service instance version. (SRS9002)
VERBOSE: Perform operation 'Enumerate CimInstances' with following parameters, ''namespaceName' = ROOT\Microsoft\SqlServer\ReportServer\RS_SSRS,'className' = __NameSpace'.
VERBOSE: Reporting Service instance version was set to ''. (SRS9003)
VERBOSE: Attempting to retrieve the Reporting Service instance object. (SRS9004)
VERBOSE: Perform operation 'Enumerate CimInstances' with following parameters, ''namespaceName' = ROOT\Microsoft\SqlServer\ReportServer\RS_SSRS\,'className' = MSReportServer_Instance'.
System.Exception: There was an issue when trying to retrieve the CIM instance. This shouldn't have happened. For further diganostics, please ensure that the following command can run
`Get-CimInstance -Error 'True' -Result 'Invalid namespace '`. (SRS9001) ---> Microsoft.Management.Infrastructure.CimException: Invalid namespace
   at Microsoft.Management.Infrastructure.Internal.Operations.CimAsyncObserverProxyBase`1.ProcessNativeCallback(OperationCallbackProcessingContext callbackProcessingContext, T
currentItem, Boolean moreResults, MiResult operationResult, String errorMessage, InstanceHandle errorDetailsHandle)

Another longer one with parameter comparison:

VERBOSE: Comparing all the parameters specified for the instance 'PBIRS'. (SRS0400)
VERBOSE: Attempting to get the current Reporting Service state. (SRS0100)
VERBOSE: Reporting Service instance name was set to 'RS_PBIRS'. (SRS9001)
VERBOSE: Attempting to retrieve the Reporting Service instance version. (SRS9002)
VERBOSE: Perform operation 'Enumerate CimInstances' with following parameters, ''namespaceName' = ROOT\Microsoft\SqlServer\ReportServer\RS_PBIRS,'className' = __NameSpace'.
VERBOSE: Operation 'Enumerate CimInstances' complete.
VERBOSE: Reporting Service instance version was set to 'V15'. (SRS9003)
VERBOSE: Attempting to retrieve the Reporting Service instance object. (SRS9004)
VERBOSE: Perform operation 'Enumerate CimInstances' with following parameters, ''namespaceName' = ROOT\Microsoft\SqlServer\ReportServer\RS_PBIRS\V15,'className' = MSReportServer_Instance'.
VERBOSE: Operation 'Enumerate CimInstances' complete.
VERBOSE: The Reporting Services instance object was successfully retrieved. (SRS9005)
VERBOSE: Attempting to retrieve the Reporting Service configuration object. (SRS9006)
VERBOSE: Perform operation 'Enumerate CimInstances' with following parameters, ''namespaceName' = ROOT\Microsoft\SqlServer\ReportServer\RS_PBIRS\V15\Admin,'className' =
MSReportServer_ConfigurationSetting'.
VERBOSE: Operation 'Enumerate CimInstances' complete.
VERBOSE: The Reporting Services configuration object was successfully retrieved. (SRS9007)
VERBOSE: Retrieved the service account of 'NT Service\PowerBIReportServer', which is a 'Virtual' logon type. (SRS0106)
VERBOSE: Attempting to get the Reporting Service Instance Url list. (SRS0101)
VERBOSE: Perform operation 'Invoke CimMethod' with following parameters, ''instance' = MSReportServer_Instance (InstanceName = "PBIRS"),'methodName' = GetReportServerUrls,'namespaceName' =
 ROOT/Microsoft/SqlServer/ReportServer/RS_PBIRS/V15'.
VERBOSE: Operation 'Invoke CimMethod' complete.
VERBOSE: Successfully retrieved the Reporting Service Instance Url list. (SRS0102)
VERBOSE: Attempting to get the Reporting Service Modifiable Url list. (SRS0103)
VERBOSE: Perform operation 'Invoke CimMethod' with following parameters, ''instance' = MSReportServer_ConfigurationSetting (InstanceName = "PBIRS"),'methodName' =
ListReservedURLs,'namespaceName' = ROOT/Microsoft/SqlServer/ReportServer/RS_PBIRS/V15/Admin'.
VERBOSE: Operation 'Invoke CimMethod' complete.
VERBOSE: Successfully retrieved the Reporting Service Modifiable Url list. (SRS0104)
VERBOSE: Attempting to get a list of the Reporting Service Scale-Out servers. (SRS0104)
VERBOSE: Perform operation 'Invoke CimMethod' with following parameters, ''instance' = MSReportServer_ConfigurationSetting (InstanceName = "PBIRS"),'methodName' =
ListReportServersInDatabase,'namespaceName' = ROOT/Microsoft/SqlServer/ReportServer/RS_PBIRS/V15/Admin'.
VERBOSE: Operation 'Invoke CimMethod' complete.
VERBOSE: Successfully retrieved the list of Reporting Service Scale-Out servers. (SRS0105)
VERBOSE: Checking if the parameter 'ServiceAccount' is in desired state. (SRS0401)
VERBOSE: The parameter 'ServiceAccount' was found to NOT be in the correct desired state. Expected: 'computer\user', Actual 'NT Service\PowerBIReportServer'. (SRS0402)
VERBOSE: Checking if the parameter 'ServiceAccountLogonType' is in desired state. (SRS0401)
VERBOSE: The parameter 'ServiceAccountLogonType' was found to NOT be in the correct desired state. Expected: 'Windows', Actual 'Virtual'. (SRS0402)
VERBOSE: Checking if the parameter 'ReportManagerVirtualDirectory' is in desired state. (SRS0401)
VERBOSE: The parameter 'ReportManagerVirtualDirectory' was found to NOT be in the correct desired state. Expected: 'ReportServer', Actual ''. (SRS0402)
VERBOSE: Checking if the parameter 'ReportManagerUrls' is in desired state. (SRS0401)
VERBOSE: The parameter 'ReportManagerUrls' was found to NOT be in the correct desired state. Expected: '[http://+:80]', Actual '[]'. (SRS0402)
VERBOSE: Checking if the parameter 'DatabaseServerInstance' is in desired state. (SRS0401)
VERBOSE: The parameter 'DatabaseServerInstance' was found to NOT be in the correct desired state. Expected: 'MyServer', Actual ''. (SRS0402)
VERBOSE: Checking if the parameter 'DatabaseName' is in desired state. (SRS0401)
VERBOSE: The parameter 'DatabaseName' was found to NOT be in the correct desired state. Expected: 'ReportDatabase', Actual ''. (SRS0402)
VERBOSE: Checking if the parameter 'ReportDatabaseCredential' is in desired state. (SRS0401)
VERBOSE: The parameter 'ReportDatabaseCredential' was found to NOT be in the correct desired state. Expected: 'reportuser', Actual ''. (SRS0402)
VERBOSE: Checking if the parameter 'ReportDatabaseLogonType' is in desired state. (SRS0401)
VERBOSE: The parameter 'ReportDatabaseLogonType' was found to NOT be in the correct desired state. Expected: 'Service', Actual 'Windows'. (SRS0402)
VERBOSE: Checking if the parameter 'EmailSender' is in desired state. (SRS0401)
VERBOSE: The parameter 'EmailSender' was found to NOT be in the correct desired state. Expected: 'sds@sds.com', Actual ''. (SRS0402)
VERBOSE: Checking if the parameter 'EmailSMTP' is in desired state. (SRS0401)
VERBOSE: The parameter 'EmailSMTP' was found to NOT be in the correct desired state. Expected: 'smtp.amail.com', Actual ''. (SRS0402)
VERBOSE: Checking if the parameter 'EmailAuthentication' is in desired state. (SRS0401)
VERBOSE: The parameter 'EmailAuthentication' was found to be the correct desired state. Expected: 'None',        Actual 'None'. (SRS0403)
VERBOSE: Checking if the parameter 'EmailSMTPCredential' is in desired state. (SRS0401)
VERBOSE: The parameter 'EmailSMTPCredential' was found to NOT be in the correct desired state. Expected: 'dsasd', Actual ''. (SRS0402)
VERBOSE: Checking if the parameter 'ExecutionAccount' is in desired state. (SRS0401)
VERBOSE: The parameter 'ExecutionAccount' was found to NOT be in the correct desired state. Expected: 'execute', Actual ''. (SRS0402)
VERBOSE: Checking if the parameter 'FileShareAccount' is in desired state. (SRS0401)
VERBOSE: The parameter 'FileShareAccount' was found to NOT be in the correct desired state. Expected: 'share', Actual ''. (SRS0402)
VERBOSE: Checking if the parameter 'ReportWebPortalVirtualDirectory' is in desired state. (SRS0401)
VERBOSE: The parameter 'ReportWebPortalVirtualDirectory' was found to NOT be in the correct desired state. Expected: 'Reports', Actual ''. (SRS0402)
VERBOSE: Checking if the parameter 'ReportWebPortalUrls' is in desired state. (SRS0401)
VERBOSE: The parameter 'ReportWebPortalUrls' was found to NOT be in the correct desired state. Expected: '[https://+:80, http://]', Actual '[]'. (SRS0402)
VERBOSE: Checking if the parameter 'Verbose' is in desired state. (SRS0401)
VERBOSE: Checking if the parameter 'ReportServiceInstanceName' is in desired state. (SRS0401)
VERBOSE: The parameter 'ReportServiceInstanceName' was found to be the correct desired state. Expected: 'PBIRS',        Actual 'PBIRS'. (SRS0403)

Anyway, just some thoughts which may be helpful.

johlju commented 5 years ago

Awesome that you put this together.

TL;DR: I like the idea, but I'm not sure this is something that would help us. It would be hard to enforce this. ant would just over complicate things for contributors and maintainers. 🤔 The reason for this number in the first place is to be able to correlate a localized string from a verbose/error where the log is in another language. You could then see the number, look for the number in the English string resource file, and there see the localized string key, and search for that key in the code.

Possibly group verbose messages together when possible (i'll show example)

I like the idea, but I think this will be hard to enforce, and complicate things for contributors where the style guideline is already a problem. It would also be hard to write a common unit test (in the test framework) to verify that the localized string has the correct number. It's easier to write a common test to verify that each string do have a number, and not a specific number.

I think you suggestion is gonne be overly complicated, and I think we should be able to reuse any localized string in a resource if it fits.

Start each function with a verbose message saying what you are going to do

I try to do that in the code I write. I think this is the normal (?) in most resource, but there are probably exceptions. Most older resource can be missing this because verbose message was not as important back then when the resource was created (focus on functionality, not the help that verbose message gives when users ask for help).

Verbose messages when comparing all parameters (state if parameter is in state or not) On Test, verbose message if state is compliant or not (maybe redundant?

These messages can also be from a helper function in another module, for example the new pattern i made when i refactored xADComputer.

If that pattern works, we should move it here as a common pattern and replaces or exist beside the common helper function Test-DscParameterState. https://github.com/PowerShell/xActiveDirectory/blob/f91d0f3073c7bd5086bff31d27d87162ab1f0609/DSCResources/MSFT_xADCommon/MSFT_xADCommon.psm1#L1098-L1118

Verbose message for every try/catch?

Up to the contributor if it is necessary. I think it's normal to have a verbose message before or after an action/event (maybe both for long running tasks). We should not use verbose messages as debug messages. Verbose message can be used to see which actions was made or not made before an error was thrown, if the user can provide the verbose log. Normally the error message should be descriptive enough. But there are scenarios where I had needed the verbose messages to realizes the code went into the wrong code path because of values in either the desired state or the current state. In these scenarios I saw that the actions (verbose messages) that was made didn't seem correct.

kungfoome commented 5 years ago

Yeah, i was thinking about complexity as well. I think having verbose messages with numbers that associate to each function would still be ok. 100, 200, 300. This should be able to be automated checking as well. If you look at all the messages in say get and then look at the localized string, it should have x1xx as the number, so on.

But this would make it so you really couldn't reuse the strings, like you had said. Not sure how often this would come up.

Another option could be to come up with a few standard messages and explicitly set these IDs. It probably wouldn't be many. Maybe 5 or 6. But it would at least provide some traceability.

It would be nice to define some sort of standard though so we have the write amount of verbose messaging. Not too much, not too little.