Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error on creating new SPVisioServiceApplication: Command not found #1392

Open
JenTonUg opened this issue Feb 28, 2022 · 10 comments
Open

Error on creating new SPVisioServiceApplication: Command not found #1392

JenTonUg opened this issue Feb 28, 2022 · 10 comments
Labels
needs investigation The issue needs to be investigated by the maintainers or/and the community.

Comments

@JenTonUg
Copy link

Problem description

When creating a new Visio Service application, I'm getting that the command new-SPVisioServiceApplication is not found.
This is a fresh rollout of SP2019 on Windows 2019 servers. I believe line 111 in the MSFT_SPVisioServiceApp resource generates the issue. Just to make sure, I checked if something was off with my Sharepoint snapin, but the New-SPVisioServiceApplication cmdlet is there.
Other webapplications are getting created succesfully.

DSC Operational log:

Job {658948CE-987B-11EC-8DB2-EE000000024D} : 
MIResult: 1
Error Message: PowerShell DSC resource MSFT_SPVisioServiceApp  failed to execute Set-TargetResource functionality with error message: The term 'New-SPVisioServiceApplication' is not recognized as the name of a cmdlet, function, script file, or operable program. Check the spelling of the name, or if a path was included, verify that the path is correct and try again. 
Message ID: ProviderOperationExecutionFailure
Error Category: 7
Error Code: 1
Error Type: MI
Job {658948CE-987B-11EC-8DB2-EE000000024D} : 
Message The term 'New-SPVisioServiceApplication' is not recognized as the name of a cmdlet, function, script file, or operable program. Check the spelling of the name, or if a path was included, verify that the path is correct and try again. 
HResult -2146233087 
StackTrack    at System.Management.Automation.Runspaces.AsyncResult.EndInvoke()
   at System.Management.Automation.PowerShell.CoreInvokeRemoteHelper[TInput,TOutput](PSDataCollection`1 input, PSDataCollection`1 output, PSInvocationSettings settings)
   at System.Management.Automation.PowerShell.CoreInvoke[TInput,TOutput](PSDataCollection`1 input, PSDataCollection`1 output, PSInvocationSettings settings)
   at System.Management.Automation.PowerShell.Invoke(IEnumerable input, PSInvocationSettings settings)
   at Microsoft.PowerShell.DesiredStateConfiguration.Internal.ResourceProviderAdapter.ExecuteCommand(PowerShell powerShell, ResourceModuleInfo resInfo, String operationCmd, List`1 acceptedProperties, CimInstance nonResourcePropeties, CimInstance resourceConfiguration, LCMDebugMode debugMode, PSInvocationSettings pSInvocationSettings, UInt32& resultStatusHandle, Collection`1& result, ErrorRecord& errorRecord, PSModuleInfo localRunSpaceModuleInfo)

Verbose logs

{"time": "2022-02-28T11:06:28.511+01:00", "type": "verbose", "message": "[APP01]: LCM:  [ Start  Resource ]  [[SPVisioServiceApp]VisioServiceApplication]  "},
  {"time": "2022-02-28T11:06:28.511+01:00", "type": "verbose", "message": "[APP01]: LCM:  [ Start  Test     ]  [[SPVisioServiceApp]VisioServiceApplication]  "},
  {"time": "2022-02-28T11:06:28.932+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Testing Visio Graphics service app 'Visio Graphics Service Application'"},
  {"time": "2022-02-28T11:06:28.932+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Getting Visio Graphics service app 'Visio Graphics Service Application'"},
  {"time": "2022-02-28T11:06:28.932+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Executing as the local run as user domain\\setupaccount"},
  {"time": "2022-02-28T11:06:28.932+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Leaving BeginProcessing Method of Get-SPServiceApplication."},
  {"time": "2022-02-28T11:06:28.932+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Leaving ProcessRecord Method of Get-SPServiceApplication."},
  {"time": "2022-02-28T11:06:28.932+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Leaving EndProcessing Method of Get-SPServiceApplication."},
  {"time": "2022-02-28T11:06:28.932+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Current Values: ApplicationPool=SharePoint Web Services Default; Ensure=Absent; Name=Visio Graphics Service Application"},
  {"time": "2022-02-28T11:06:28.932+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Target Values: ApplicationPool=SharePoint Web Services Default; Ensure=Present; Name=Visio Graphics Service Application; ProxyName=Visio Graphics Service Application Proxy; Verbose=True"},
  {"time": "2022-02-28T11:06:28.932+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Test-TargetResource returned False"},
  {"time": "2022-02-28T11:06:28.932+01:00", "type": "verbose", "message": "[APP01]: LCM:  [ End    Test     ]  [[SPVisioServiceApp]VisioServiceApplication]  in 0.4220 seconds."},
  {"time": "2022-02-28T11:06:28.932+01:00", "type": "verbose", "message": "[APP01]: LCM:  [ Start  Set      ]  [[SPVisioServiceApp]VisioServiceApplication]  "},
  {"time": "2022-02-28T11:06:29.261+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Setting Visio Graphics service app 'Visio Graphics Service Application'"},
  {"time": "2022-02-28T11:06:29.261+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Getting Visio Graphics service app 'Visio Graphics Service Application'"},
  {"time": "2022-02-28T11:06:29.261+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Executing as the local run as user domain\\setupaccount"},
  {"time": "2022-02-28T11:06:29.261+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Leaving BeginProcessing Method of Get-SPServiceApplication."},
  {"time": "2022-02-28T11:06:29.261+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Leaving ProcessRecord Method of Get-SPServiceApplication."},
  {"time": "2022-02-28T11:06:29.261+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Leaving EndProcessing Method of Get-SPServiceApplication."},
  {"time": "2022-02-28T11:06:29.261+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Creating Visio Graphics Service Application Visio Graphics Service Application"},
  {"time": "2022-02-28T11:06:29.261+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApplication] Executing as the local run as user domain\\setupaccount"},
  {"time": "2022-02-28T11:06:29.292+01:00", "type": "verbose", "message": "[APP01]: LCM:  [ End    Set      ]  [[SPVisioServiceApp]VisioServiceApplication]  in 0.3600 seconds."},
  {"time": "2022-02-28T11:06:29.292+01:00", "type": "error", "message": "PowerShell DSC resource MSFT_SPVisioServiceApp  failed to execute Set-TargetResource functionality with error message: The term 'New-SPVisioServiceApplication' is not recognized as the name of a cmdlet, function, script file, or operable program. Check the spelling of the name, or if a path was included, verify that the path is correct and try again. "},

DSC configuration

SPVisioServiceApp VisioServiceApplication{
            Name                 = "Visio Graphics Service Application";
            ProxyName            = "Visio Graphics Service Application Proxy";
            ApplicationPool      = "SharePoint Web Services Default";
            PsDscRunAsCredential = $SPSetupAccount;
            DependsOn            = "[SPServiceAppPool]SharePointWebServicesDefault"
        }

Suggested solution

Checking for the command in memory, if not, adding sharepoint pssnapin?

SharePoint version and build

Sharepoint 2019 (16.0.10383.20001)

Operating system the target node is running

OsName               : Microsoft Windows Server 2019 Standard
OsOperatingSystemSKU : StandardServerEdition
OsArchitecture       : 64-bit
WindowsVersion       : 1809
WindowsBuildLabEx    : 17763.1.amd64fre.rs5_release.180914-1434
OsLanguage           : en-US
OsMuiLanguages       : {en-US}

PowerShell version and build the target node is running

Name                           Value
----                           -----
PSVersion                      5.1.17763.2268
PSEdition                      Desktop
PSCompatibleVersions           {1.0, 2.0, 3.0, 4.0...}
BuildVersion                   10.0.17763.2268
CLRVersion                     4.0.30319.42000
WSManStackVersion              3.0
PSRemotingProtocolVersion      2.3
SerializationVersion           1.1.0.1

SharePointDsc version

Name          Version Path
----          ------- ----
SharePointDSC 5.0.0   C:\Program Files\WindowsPowerShell\Modules\SharePointDSC\5.0.0\SharePointDSC.psd1
@JenTonUg
Copy link
Author

JenTonUg commented Mar 1, 2022

The next run, it ran fine. I've had this happen before when starting out fresh. Might this be an issue with the visio resource creation starting before the snapin is loaded?

@ykuijs
Copy link
Member

ykuijs commented Mar 3, 2022

This issue has been reported before, #372 and #790. Unfortunately we were unable to solve the issue in those cases because we were unable to reproduce and the issue creator didn't respond anymore.

This issue has something to do with timing: The code is loading the snap-in, but still can't find the cmdlet. Are you able to reproduce the issue when deploying a new farm?

@JenTonUg
Copy link
Author

JenTonUg commented Mar 3, 2022

I was just about to do a fresh deploy overnight, I'll let you know tomorrow.

@ykuijs
Copy link
Member

ykuijs commented Mar 3, 2022

Great! Just another quick question: Are you using SQLServerDsc in the same config by any chance?

@ykuijs
Copy link
Member

ykuijs commented Mar 3, 2022

Oh and another request if you are able to reproduce, could you please do another fresh deployment and test the following:
Adding a Start-Sleep -Seconds 3 in front of line 111 in MSFT_SPVisioServiceApp.psm1? Just to see if this is a timing issue.

@JenTonUg
Copy link
Author

JenTonUg commented Mar 3, 2022

No SQLServerDsc in use. I am using these, though:

  • xWebAdministration
  • CertificateDSC
  • StorageDSC
  • xCredSSP
  • OfficeOnlineServerDsc

@ykuijs ykuijs added the needs investigation The issue needs to be investigated by the maintainers or/and the community. label Mar 3, 2022
@JenTonUg
Copy link
Author

JenTonUg commented Mar 7, 2022

The reason why I was rolling out a fresh deploy, is that I refactored my config. Of course this results in a failed deploy because of dependencies, which I'm currently trying to fix first. I'll get back here once I have that fixed.
Bear with me...

@JenTonUg
Copy link
Author

JenTonUg commented Mar 8, 2022

And we're back. I've added the sleep to the code, and the issue persists. Once finished, the second time the dsc config is applied, the issue is fixed. I've just missed it this time. If you want me to test some more, just let me know, happy to help!
I'll add some extra time to the sleep and will initiate another run on clean servers, in the hope to catch the issue and provide debug logging.

@JenTonUg
Copy link
Author

JenTonUg commented Mar 9, 2022

Upped the sleep time to 120 seconds, which is clearly visible in the log, yet the commandlet is still unavailable:

  {"time": "2022-03-09T13:16:22.061+01:00", "type": "verbose", "message": "[APP01]: LCM:  [ Start  Resource ]  [[SPVisioServiceApp]VisioServiceApp]  "},
  {"time": "2022-03-09T13:16:22.061+01:00", "type": "verbose", "message": "[APP01]: LCM:  [ Start  Test     ]  [[SPVisioServiceApp]VisioServiceApp]  "},
  {"time": "2022-03-09T13:16:22.482+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Testing Visio Graphics service app 'Visio Graphics Service Application'"},
  {"time": "2022-03-09T13:16:22.482+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Getting Visio Graphics service app 'Visio Graphics Service Application'"},
  {"time": "2022-03-09T13:16:22.482+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Executing as the local run as user UGENT\\SA-Setup"},
  {"time": "2022-03-09T13:16:22.482+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Leaving BeginProcessing Method of Get-SPServiceApplication."},
  {"time": "2022-03-09T13:16:22.482+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Leaving ProcessRecord Method of Get-SPServiceApplication."},
  {"time": "2022-03-09T13:16:22.482+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Leaving EndProcessing Method of Get-SPServiceApplication."},
  {"time": "2022-03-09T13:16:22.482+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Current Values: ApplicationPool=SharePoint Web Services Default; Ensure=Absent; Name=Visio Graphics Service Application"},
  {"time": "2022-03-09T13:16:22.482+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Target Values: ApplicationPool=SharePoint Web Services Default; Ensure=Present; Name=Visio Graphics Service Application; ProxyName=Visio Graphics Service Application Proxy; Verbose=True"},
  {"time": "2022-03-09T13:16:22.482+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Test-TargetResource returned False"},
  {"time": "2022-03-09T13:16:22.498+01:00", "type": "verbose", "message": "[APP01]: LCM:  [ End    Test     ]  [[SPVisioServiceApp]VisioServiceApp]  in 0.4370 seconds."},
  {"time": "2022-03-09T13:16:22.498+01:00", "type": "verbose", "message": "[APP01]: LCM:  [ Start  Set      ]  [[SPVisioServiceApp]VisioServiceApp]  "},
  {"time": "2022-03-09T13:16:23.207+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Setting Visio Graphics service app 'Visio Graphics Service Application'"},
  {"time": "2022-03-09T13:16:23.207+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Getting Visio Graphics service app 'Visio Graphics Service Application'"},
  {"time": "2022-03-09T13:16:23.207+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Executing as the local run as user UGENT\\SA-Setup"},
  {"time": "2022-03-09T13:16:23.207+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Leaving BeginProcessing Method of Get-SPServiceApplication."},
  {"time": "2022-03-09T13:16:23.207+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Leaving ProcessRecord Method of Get-SPServiceApplication."},
  {"time": "2022-03-09T13:16:23.207+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Leaving EndProcessing Method of Get-SPServiceApplication."},
  {"time": "2022-03-09T13:16:23.207+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Creating Visio Graphics Service Application Visio Graphics Service Application"},
  {"time": "2022-03-09T13:16:23.207+01:00", "type": "verbose", "message": "[APP01]:                            [[SPVisioServiceApp]VisioServiceApp] Executing as the local run as user UGENT\\SA-Setup"},
  {"time": "2022-03-09T13:18:22.889+01:00", "type": "verbose", "message": "[APP01]: LCM:  [ End    Set      ]  [[SPVisioServiceApp]VisioServiceApp]  in 120.3910 seconds."},
  {"time": "2022-03-09T13:18:22.889+01:00", "type": "error", "message": "PowerShell DSC resource MSFT_SPVisioServiceApp  failed to execute Set-TargetResource functionality with error message: The term 'New-SPVisioServiceApplication' is not recognized as the name of a cmdlet, function, script file, or operable program. Check the spelling of the name, or if a path was included, verify that the path is correct and try again. "},

@Mr-Kappelmann
Copy link

Mr-Kappelmann commented Apr 18, 2024

same problem as
#990
The loaded Powershell can not load New-SPVisioServiceApplication.

A Remove- & Add-PsSnapin not solve this... The CmdLet New-SPVisioServiceApplication not available.
The Remove-PsSnapin Microsoft.SharePoint.PowerShell not working. PsSnapin still loaded and available.

In a new fresh startet powershell, the CmdLet New-SPVisioServiceApplication are available

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
needs investigation The issue needs to be investigated by the maintainers or/and the community.
Projects
None yet
Development

No branches or pull requests

3 participants