TFS commands run very slow in Jenkins

[Keith Marchen]

We use TFS commands to get our source files for builds. But when we run them from Jenkins, they take around 40 seconds to execute. What could be the issue with our TFS configuration on Jenkins that is affecting execution of TFS commands?

Thanks,

Keith

[Richard Bywater]

If you run the commands locally on the same box and with the same user that is running Jenkins, do you get the same behaviour?

Don't know TFS really enough to comment more but perhaps there's an environment setup issue between when running in Jenkins and when running elsewhere?

Richard.

--
You received this message because you are subscribed to the Google Groups "Jenkins Users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to jenkinsci-use...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-users/9cfc2ee0-6fe8-482f-acca-a8a54b4b3a10%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Keith Marchen]

We have tested running the TFS scripts locally on the build server using same user and it runs fine.  

[Christopher Orr]

Does it take 40 seconds every time, for every single TFS command?

Can you see where the hang is in the build log (i.e. in the middle of
doing a TFS operation, or at the start, before anything happens)?
You could also try checking the thread dump — at
$JENKINS_URL/computer/$NAME/threadDump — to see what Jenkins is doing in
this time.

Are you always building on the same slaves, or a new slave for ~each
build (e.g. cloud-provisioned builders, which are discarded often)?

-Chris

> --
> You received this message because you are subscribed to the Google
> Groups "Jenkins Users" group.
> To unsubscribe from this group and stop receiving emails from it, send
> an email to jenkinsci-use...@googlegroups.com

> <mailto:jenkinsci-use...@googlegroups.com>.

> To view this discussion on the web visit

> https://groups.google.com/d/msgid/jenkinsci-users/232a8c04-c8b4-4f48-ab03-9be7bb55d4eb%40googlegroups.com
> <https://groups.google.com/d/msgid/jenkinsci-users/232a8c04-c8b4-4f48-ab03-9be7bb55d4eb%40googlegroups.com?utm_medium=email&utm_source=footer>.

[Keith Marchen]

On Tuesday, March 31, 2015 at 10:36:55 PM UTC-5, Keith Marchen wrote:

Yes, each and every TFS command is running close to 40 seconds. I'll check the logs and Jenkins thread dump.   

[Keith Marchen]

On Tuesday, March 31, 2015 at 10:36:55 PM UTC-5, Keith Marchen wrote:

Here is tread dump when I run a TF command. Looks like it might be locking on the FilePath...? 

FilePath.localPool [#414]

"FilePath.localPool [#414]" Id=9933 Group=main RUNNABLE
	at sun.management.ThreadImpl.dumpThreads0(Native Method)
	at sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:446)
	at hudson.Functions.getThreadInfos(Functions.java:1155)
	at hudson.util.RemotingDiagnostics$GetThreadDump.call(RemotingDiagnostics.java:95)
	at hudson.util.RemotingDiagnostics$GetThreadDump.call(RemotingDiagnostics.java:92)
	at hudson.remoting.LocalChannel$1.call(LocalChannel.java:52)
	at jenkins.util.ContextResettingExecutorService$2.call(ContextResettingExecutorService.java:46)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)

	Number of locked synchronizers = 1 

- java.util.concurrent.ThreadPoolExecutor$Worker@3b6ee141 

Handling GET /threadDump : RequestHandlerThread[#232] Jenkins/threadDump.jelly

"Handling GET /threadDump : RequestHandlerThread[#232] Jenkins/threadDump.jelly" Id=9923 Group=main TIMED_WAITING on java.util.concurrent.FutureTask@43a7032c

Handling POST /script : RequestHandlerThread[#229]
"Handling POST /script : RequestHandlerThread[#229]" Id=9903 Group=main RUNNABLE (in native)
	at java.lang.ProcessImpl.waitForInterruptibly(Native Method)
	at java.lang.ProcessImpl.waitFor(ProcessImpl.java:449)
	at sun.reflect.GeneratedMethodAccessor342.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:483)

jenkins.util.Timer [#10]  (there are 10 timers in the dump -all the same )
"jenkins.util.Timer [#10]" Id=43 Group=main WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@1a6b2970
	at sun.misc.Unsafe.park(Native Method)
	-  waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@1a6b2970
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
	at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)

[Christopher Orr]

There appears to be nothing in that thread dump relating to the job that
executes TFS commands.

Did you get the dump from the right build machine? Sorry for not
clarifying that earlier.

On 01/04/15 14:38, Keith Marchen wrote:
>
>
> On Tuesday, March 31, 2015 at 10:36:55 PM UTC-5, Keith Marchen wrote:
>
> We use TFS commands to get our source files for builds. But when we
> run them from Jenkins, they take around 40 seconds to execute. What
> could be the issue with our TFS configuration on Jenkins that is
> affecting execution of TFS commands?
>
> Thanks,
> Keith
>
>
> Here is tread dump when I run a TF command. Looks like it might be
> locking on the FilePath...?
>
>

> *FilePath.localPool [#414]*

>
> "FilePath.localPool [#414]" Id=9933 Group=main RUNNABLE
> at sun.management.ThreadImpl.dumpThreads0(Native Method)
> at sun.management.ThreadImpl.dumpAllThreads(ThreadImpl.java:446)
> at hudson.Functions.getThreadInfos(Functions.java:1155)
> at hudson.util.RemotingDiagnostics$GetThreadDump.call(RemotingDiagnostics.java:95)
> at hudson.util.RemotingDiagnostics$GetThreadDump.call(RemotingDiagnostics.java:92)
> at hudson.remoting.LocalChannel$1.call(LocalChannel.java:52)
> at jenkins.util.ContextResettingExecutorService$2.call(ContextResettingExecutorService.java:46)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
>
> Number of locked synchronizers = 1
>
> - java.util.concurrent.ThreadPoolExecutor$Worker@3b6ee141
>
>

> *Handling GET /threadDump : RequestHandlerThread[#232]
> Jenkins/threadDump.jelly*

>
> "Handling GET /threadDump : RequestHandlerThread[#232] Jenkins/threadDump.jelly" Id=9923 Group=main TIMED_WAITING on java.util.concurrent.FutureTask@43a7032c
>
>

> *Handling POST /script : RequestHandlerThread[#229]*

>
> "Handling POST /script : RequestHandlerThread[#229]" Id=9903 Group=main RUNNABLE (in native)
> at java.lang.ProcessImpl.waitForInterruptibly(Native Method)
> at java.lang.ProcessImpl.waitFor(ProcessImpl.java:449)
> at sun.reflect.GeneratedMethodAccessor342.invoke(Unknown Source)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:483)
>
>

> *jenkins.util.Timer [#10] */(there are 10 timers in the dump -all
> the same )/

>
> "jenkins.util.Timer [#10]" Id=43 Group=main WAITING on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@1a6b2970
> at sun.misc.Unsafe.park(Native Method)
> - waiting on java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject@1a6b2970
> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
> at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
> at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
> at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
>
>

> --
> You received this message because you are subscribed to the Google
> Groups "Jenkins Users" group.
> To unsubscribe from this group and stop receiving emails from it, send
> an email to jenkinsci-use...@googlegroups.com
> <mailto:jenkinsci-use...@googlegroups.com>.
> To view this discussion on the web visit

> https://groups.google.com/d/msgid/jenkinsci-users/da0ab01e-0b32-4543-b932-3b381eb3f064%40googlegroups.com
> <https://groups.google.com/d/msgid/jenkinsci-users/da0ab01e-0b32-4543-b932-3b381eb3f064%40googlegroups.com?utm_medium=email&utm_source=footer>.

[Keith Marchen]

On Tuesday, March 31, 2015 at 10:36:55 PM UTC-5, Keith Marchen wrote:

 Hi Chris, 

This was from a groovy script executing of a TF 'DIR' command run from the Jenkins Script console. While it was running for 40 seconds, I was pulling this info from the thread dump.   

[Keith Marchen]

Would it be best to attach the complete dump?  

[Slide]

Can you try enabling tracing in TFS?

http://blogs.msdn.com/b/edhintz/archive/2007/03/30/tfs-client-tracing.aspx

--

You received this message because you are subscribed to the Google Groups "Jenkins Users" group.

To unsubscribe from this group and stop receiving emails from it, send an email to jenkinsci-use...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-users/c32c90fb-4861-4a5b-9ee1-ba677c4626a0%40googlegroups.com.

[Slide]

Also, see here for some possible reasons.

https://freecodery.wordpress.com/2011/03/30/slow-tfs-performance/

On Thu, Apr 2, 2015 at 10:58 AM Slide <slide...@gmail.com> wrote:

Can you try enabling tracing in TFS?

http://blogs.msdn.com/b/edhintz/archive/2007/03/30/tfs-client-tracing.aspx

On Thu, Apr 2, 2015 at 10:57 AM Keith Marchen <kmar...@gmail.com> wrote:

On Thursday, April 2, 2015 at 12:53:54 PM UTC-5, Keith Marchen wrote:

On Tuesday, March 31, 2015 at 10:36:55 PM UTC-5, Keith Marchen wrote:

We use TFS commands to get our source files for builds. But when we run them from Jenkins, they take around 40 seconds to execute. What could be the issue with our TFS configuration on Jenkins that is affecting execution of TFS commands?

Thanks,

Keith

 

 Hi Chris, 

This was from a groovy script executing of a TF 'DIR' command run from the Jenkins Script console. While it was running for 40 seconds, I was pulling this info from the thread dump.   

Would it be best to attach the complete dump?  

--
You received this message because you are subscribed to the Google Groups "Jenkins Users" group.

To unsubscribe from this group and stop receiving emails from it, send an email to jenkinsci-users+unsubscribe@googlegroups.com.

[Keith Marchen]

On Tuesday, March 31, 2015 at 10:36:55 PM UTC-5, Keith Marchen wrote:

I added the tfs trace log. Commands were taking about 1 second to run so the issue is not with TFS. Adding the system.net config to tf.exe.config only made matters worse. It took longer to run (60 seconds or more) and returned an empty result set. I'm at a loss but starting to think it's a server or browser config issue...? I'm running jenklns in Chrome 41.0.2

 

[Slide]

Did you try the changes to the IE network configuration?

--

You received this message because you are subscribed to the Google Groups "Jenkins Users" group.

To unsubscribe from this group and stop receiving emails from it, send an email to jenkinsci-use...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/jenkinsci-users/5cce17b5-8d73-4f09-ac2b-952a5d80e732%40googlegroups.com.