Get-WFALogger slow

[ktim]

Logging seems to slow down WFA commands significantly. For example, the simple command

for ($i=0; $i -lt 120; $i++) {

   Get-WFALogger -Info -message "Message #$i"

}

takes over 110 seconds to run, with significant pauses. See example (edited) output below.

Is there any way to avoid this (other than not logging!). This is a significant issue with some of the complex commands I am working on that need to be reasonably verbose. Is this addressed in WFA 2.2 perhaps?

Regards,

Tim

08:05:40.653 INFO  [Test-WFALogger] ### Command 'Test-WFALogger' ###

08:05:44.640 INFO  [Test-WFALogger] Message #0

08:05:44.654 INFO  [Test-WFALogger] Executing command: ./Test-WFALogger1452081226577934398.ps1

08:05:44.711 INFO  [Test-WFALogger] Message #1

...

08:05:47.069 INFO  [Test-WFALogger] Message #46

08:05:47.125 INFO  [Test-WFALogger] Message #47

08:06:38.736 INFO  [Test-WFALogger] Message #48   <--- 51 second pause here

08:06:38.765 INFO  [Test-WFALogger] Message #49

...

08:06:41.109 INFO  [Test-WFALogger] Message #95

08:06:41.165 INFO  [Test-WFALogger] Message #96

08:07:32.790 INFO  [Test-WFALogger] Message #97  <--- another pause

08:07:32.819 INFO  [Test-WFALogger] Message #98

...

08:07:33.801 INFO  [Test-WFALogger] Message #111

08:07:33.872 INFO  [Test-WFALogger] Message #112

08:07:34.265 INFO  [Test-WFALogger] Message #113

08:07:34.293 INFO  [Test-WFALogger] Message #114

08:07:34.756 INFO  [Test-WFALogger] Command completed, took 114047 milliseconds

08:14:01.809 INFO  [Test-WFALogger] ### Command 'Test-WFALogger' ###

08:14:03.747 INFO  [Test-WFALogger] Executing command: ./Test-WFALogger8603262905416236348.ps1

08:14:03.775 INFO  [Test-WFALogger] Message #0

08:14:03.817 INFO  [Test-WFALogger] Message #1

...

08:14:05.109 INFO  [Test-WFALogger] Message #45

08:14:05.151 INFO  [Test-WFALogger] Message #46

08:14:07.875 INFO  [Test-WFALogger] Message #47

08:14:57.843 INFO  [Test-WFALogger] Message #48  <--- another pause

08:14:57.885 INFO  [Test-WFALogger] Message #49

...

08:14:59.387 INFO  [Test-WFALogger] Message #94

08:14:59.416 INFO  [Test-WFALogger] Message #95

08:15:01.915 INFO  [Test-WFALogger] Message #96

08:15:53.833 INFO  [Test-WFALogger] Message #97  <--- another pause

08:15:53.904 INFO  [Test-WFALogger] Message #98

...

08:15:54.535 INFO  [Test-WFALogger] Message #118

08:15:54.563 INFO  [Test-WFALogger] Message #119

08:15:54.816 INFO  [Test-WFALogger] Command completed, took 112993 milliseconds

[sinhaa]

ktim,

      Slow response may be due to a number of reasons.

I tried the above logging example code on multiple WFA server versions, but I couldn't find anything to reach a conclusion.

1. WFA2.0.1 it was on average taking 4000milisec with no pause.
2. On 2 of my WFA2.1 servers it was taking time just about as yours. in fact more, in range of 120,000 miliseconds with 2-3 significant pause as your case.
3. On 2 WFA2.2 ( under development but Beta is out), it was on an avg taking 4500 milisec with no pause.

Can you please provide the below details?

1. WFA version

2. Windows OS version.

3. Powershell version

4. If possible your .NET version

If you help in determining the above, feel free to ask.

[ktim]

sinhaa,

Details:

WFA 2.1.0.70.32

Have seen this on 2 different systems:

1. Windows 2003 SP2 Datacenter x64 Edition, Powershell 2.0, .NET versions 2.0SP2, 3.0SP2, 3.5SP1, 4 (Client Profile & Extended) installed

2. Windows 2008R2, not sure of PoSH & .NET versions - lab is offline at the moment.

It's good to see that this might be fixed in 2.2. It may also help to explain the relative slowness observed moving from 2.0 to 2.1

Regards,

Tim

[sinhaa]

Thanks for providing the details Tim. We are looking into this issue. I'll keep you updated.

warm regards,

sinhaa

[ktim]

Thanks sinhaa.

For completeness, the other system I was testing on was Windows 2008 R2 SP1, Powershell 2.0, .NET 4.0.30319, WFA 2.1.0.70.32.

Is it possible for me to do some testing with the WFA 2.2 beta myself?

Regards,

Tim

[adaikkap]

Hi Tim,

Send me an email in couple days, I shall help you with 2.2 beta.

Regards,

adai

Sent from my Droid, excuse typos.

[sinhaa]

Tim,

    Its not a problem which may get resolved with upgrading to WFA2.2 beta. It perhaps is a Jboss issue, WFA2.0.1 used Jboss5.5 and WFA2.1 and above upgraded to Jboss7. We are working on a solution to reduce the long pauses without effecting any other performance parameters.

I'll update you very soon.

sinhaa

[adaikkap]

Hi Tim,

    For more details on the issue take a look at bug762050.

Regards

Adai