Slow workflow execution

[francoisbnc]

I wonder why workflow execution is so slow at the first line of a command 2 minutes in this exemple with WFA 2.2 (same behavior with 2.1 version) without LDAP auth.

11:45:36.381 INFO  [Create volume] ### Command 'Create volume' ###

11:47:12.276 INFO  [Create volume] Executing command: ./Create_volume8173598297431862987.ps1 -AggregateName 'sas_t2_002' -Array '10.139.32.11' -Size '1000' -VolumeGuarantee 'none' -VolumeName 'test'

11:47:12.744 INFO  [Create volume] Get-WfaCredentials -Host 10.139.32.11

11:47:12.900 INFO  [Create volume] Credentials successfully provided for '10.139.32.11'

11:47:13.103 INFO  [Create volume] Connect-NaController (with credentials) -Name 10.139.32.11 -Timeout 60000 -ErrorAction Stop

11:47:24.662 INFO  [Create volume] Connected to controller

11:47:24.927 INFO  [Create volume] Creating a new volume - name 'test' , aggregate name 'sas_t2_002' , size '1000m' , volume guarantee 'none'

11:47:34.147 INFO  [Create volume] Command completed, took 117735 milliseconds

My productive wotkflows take more than 30 minutes just for cloning 5 volumes and mapping luns inside to igroup.

Any suggestions appreciate.

François

[adaikkap]

Hi Francois,

     Happy to see you back. Does preview or planning as well take the same time or is it just the execution alone ?

How may workflows were executed in parallel ?

Is it possible to share the workflow so that we can try it to see what is causing the problem ?

Regards

adai

[sinhaa]

I've seen it before but it was never consistently reproducible that I could draw some conclusion. After seeing your post, I just did 2 rounds of Test Create Volume on cm_storage command and I got it in 2nd time, first one was lightening quick in comparison. Is it consistent for you Francois? What is your browser? Are you running your server on non-default ports?

06:52:54.860 INFO  [Create volume] ### Command 'Create volume' ###

06:54:51.004 INFO  [Create volume] Executing command: ./Create_volume2491088665744029825.ps1 -AggregateName 'Test_aggregate' -SpaceGuarantee 'none' -Cluster '10.226.252.28' -Size '20' -VserverName 'vs1' -VolumeName 'myVol3003'

06:54:52.160 INFO  [Create volume] Get-WfaCredentials -Host 10.226.252.28

06:54:57.348 INFO  [Create volume] Credentials successfully provided for '10.226.252.28'

06:54:57.676 INFO  [Create volume] Connect-Controller -Type CLUSTER -Name 10.226.252.28 -Credential System.Management.Automation.PSCredential -Vserver  -Timeout 60000

06:54:58.567 INFO  [Create volume] Connect-NcController (with credentials) -Name 10.226.252.28 -Timeout 60000 -ErrorAction Stop

06:55:01.785 INFO  [Create volume] Connected to cluster node

06:55:02.145 INFO  [Create volume] Creating a new volume: New-NcVol -ErrorAction Stop -name myVol3003 -Aggregate Test_aggregate  -SpaceReserve none -State online -Size 20m -VserverContext vs1 -Type rw -JunctionPath /myVol3003

06:55:04.020 INFO  [Create volume] Configuring volume autosize attributes: Set-NcVolAutosize -ErrorAction Stop -name myVol3003 -VserverContext vs1 -Mode off

06:55:04.614 INFO  [Create volume] Command completed, took 18172 milliseconds

I've seen it with at times with commands doesn't even do anything real.

Working to dig the cause. Will update you.

sinhaa

[francoisbnc]

Hi sinhaa,

I use chrome v.32 and server running on standard port. There are no difference using from ie.

Thanks

[francoisbnc]

Hello Adai,

Happy as well you take care of WFA.

The preview goes fast and I just ran an workflow alone in a fresh installed WFA 2.2RC1.

Workflow is pretty simple, I just create a volume with certified "create volume" command . Every command takes 2 minutes at the first line.

Regards,

François

[adaikkap]

Thanks Francois,

     In the mean time pls open a case with NetApp Support for the same. Use a controller serial number along with the WFA System ID and ASUP.

Regards

adai

[abhit]

Hi Francois:

Couple of questions.

Where is time consumed more, is it that the command is taking more time to execute in the filer/cluster?

To verify you can run command line from the machine where WFA is running.

Try to connect to the cluster using powershell command or run a command from WFA and check how much time it is taking?

It may be an issue with the network or with the cluster also.

You have said that commands in the 1st row is taking more time?

In the 2nd row is it faster than 1st row?

Regards

Abhi

[francoisbnc]

Hello Abbit,

I don't think  that is relayed to PS or Network issue

PS commands from WFA itself run pretty fast.

In this exemple New-NaVol -Name test2 -Aggregate aggr0 -Size 1000m -SpaceReserve none that tooks some seconds.

Row is just the first line of in a execution , nothing to do with loops.

06:52:54.860 INFO  [Create volume] ### Command 'Create volume' ###

Regards,

François

[abhit]

Thanks for your prompt reply. It will be good to open a case with the logs.

We need to investigate why it is happening.

Regards

Abhi

[francoisbnc]

2004844286

Logs are uploaded to the case.

Thanks

[aparker]

Any update to this?   I'm seeing the same thing at a customer with 2.2.

[aparker]

The odd thing is that even the no-op (cluster mode) command takes almost 400 seconds in execute mode.  But in preview mode it runs as you would expect.

[mgoddard]

Have you tried running Powershell itself and time it, then load the "profile.ps1" in the <WFA>/PoSH folder and time that. (cd <wfa>\PoSH ;; .\profile.ps1)

I've found installing additional powershell extensions on the WFA machine, when there were configuration issues, or even the built-in ones, can cause long delays to launching and some logging commands.

Each time a command is run, even a No-Op, a new powershell.exe instance is launched and loads the profile that loads additional modules. If you run a lot of commands and there's a delay there, that time can add up.

Michael.

[sinhaa]

Adding to Michael's reply, can you run the following and send the output?

1. Open cmd prompt

2. Run command systeminfo and send me the output here or at sinhaa at netapp dot com

The thing is this issue is perhaps a JBOSS7 issue and JBOSS7 is what WFA2.1 onwards is using. We can give you a way to reduce the long delays.

warm regards,

Abhishek

[francoisbnc]

I opened a case, no answers for the moment.

Regards,

francois

[sinhaa]

Hi Francois and aparker,

DISCLAIMER: This solution is still under test and not guaranteed to work or not to cause any other issues. But its looks harmless to me.

      Please try the following JBoss config modification. Thanks to Sandeep for working on it.

1. Open file standalone-full.xml located at WFA\jboss\standalone\configuration for editing using some text editor like notepad++

2. Find the line : <connector name="http" protocol="HTTP/1.1" scheme="http" socket-binding="http" executor="http-executor"/>

and for HTTPS

     <connector name="https" protocol="HTTP/1.1" scheme="https" socket-binding="https" secure="true" executor="http-executor">

3. Remove the executor="http-executor" from them

4. Save the file.

5. Restart NetApp WFA Server service and wait for the service to be up.

6. Retest your command or workflow execution.

Let me know how this worked for you.

warm regards

sinhaa

[francoisbnc]

Hi sinhaa,

The modification doesn't help very much, seems better, but still more than minute.

15:29:52.405 INFO  [Remove volume] ### Command 'Remove volume' ###

15:31:08.394 INFO  [Remove volume] Executing command: ./Remove_volume3469935687972074943.ps1 -Array '10.139.32.11' -VolumeName 'test'

Regards,

francois

[sinhaa]

Francois,

         Does loading of powershell itself takes long time in your server?

Do the following:

1. Try to open Powershell CLI by typing command "powershell" in you command prompt. Does it take a long time?

2. Once Powershell is open, try this command "Import-Module <WFA>/PoSH/profile.ps1 . Does it take long to complete?

3. Type cmd : systeminfo and send the output.

sinhaa

[francoisbnc]

Hi sinhaa,

1. powershel prompt was loaded quickly < 5 seconds

2. Multiple loads of  profile.ps1 arround ~1:30 minutes

systeminfo:

  Host Name:                 GDC01249

OS Name:                   Microsoft Windows Server 2008 R2 Datacenter

OS Version:                6.1.7601 Service Pack 1 Build 7601

OS Manufacturer:           Microsoft Corporation

OS Configuration:          Member Server

OS Build Type:             Multiprocessor Free

Registered Owner:          SDS

Registered Organization:   The Swatch Group Ltd

Product ID:                00496-001-0001283-84686

Original Install Date:     9/11/2013, 5:27:54 PM

System Boot Time:          1/21/2014, 5:12:31 PM

System Manufacturer:       VMware, Inc.

System Model:              VMware Virtual Platform

System Type:               x64-based PC

Processor(s):              1 Processor(s) Installed.

                           [01]: Intel64 Family 6 Model 44 Stepping 2 GenuineIntel ~2666 Mhz

BIOS Version:              Phoenix Technologies LTD 6.00, 7/30/2013

Windows Directory:         C:\Windows

System Directory:          C:\Windows\system32

Boot Device:               \Device\HarddiskVolume1

System Locale:             en-us;English (United States)

Input Locale:              en-us;English (United States)

Time Zone:                 (UTC+01:00) Amsterdam, Berlin, Bern, Rome, Stockholm, Vienna

Total Physical Memory:     2,047 MB

Available Physical Memory: 74 MB

Virtual Memory: Max Size:  6,143 MB

Virtual Memory: Available: 2,850 MB

Virtual Memory: In Use:    3,293 MB

Page File Location(s):     P:\pagefile.sys

Domain:                    swatchgroup.net

Logon Server:              \\GDC00945

Hotfix(s):                 175 Hotfix(s) Installed.

                           [01]: KB2592687

                           [02]: KB2425227

.

.

Network Card(s):           1 NIC(s) Installed.

                           [01]: vmxnet3 Ethernet Adapter

                                 Connection Name: Local Area Connection

                                 DHCP Enabled:    No

                                 IP address(es)

                                 [01]: 10.140.16.45

francois

[sinhaa]

Looks like this loading of profile.ps1 is taking all the time and hence the delays. Its mainly your environment issue, but I don't exactly know what it is and why. Can you try the following

1. Lauch powershell and  Import-Module <WFA>\PoSH\Modules\WFA

   Import-Module <WFA>\PoSH\Modules\DataONTAP

How long do they take? I'm just thinking is the profile.ps1 loading slow due to relative path that it has in its code. Normally its not a problem, but could be.

Abhishek Sinha

[francoisbnc]

Here the test from wfa server, :

PS C:\Users\itsfe> Measure-Command {import-module 'C:\Program Files\NetApp\WFA\PoSH\Modules\WFA'}

TotalSeconds      : 0.0463199

PS C:\Users\itsfe> Measure-Command {import-module 'C:\Program Files\NetApp\WFA\PoSH\Modules\DataONTAP'}

TotalSeconds      : 74.4140401

Note in my personnal computer I use for developement  DataONTAP module is loaded very quickly

PS C:\Users\eggerf> Measure-Command {import-module 'C:\Windows\System32\WindowsPowerShell\v1.0\Modules\DataONTAP'}

TotalSeconds      : 0.580509