jbe adaptor times out after 360 sec
RTC 7.1.2
BF 7.1.2
I am using the JBE adaptor to load a workspace to a redhat build server. Normally that step takes around 2 minutes (BF overhead and all). Every so often I get a timeout from what looks to me jbe. It also ends the BF adaptor. The step timeout is actually 15 minutes and the timeout is after 8 minutes in this case.
I found a thread where a shortage in some tmp directory could cause RTC to wait (it was a defect and I didn't bookmark it and now I can't find it again). /tmp on the build server has plenty of space.
The jbe log that usually shows up in RTC isn't there either and I only have the info that is below.
Is there anything I can look at on the build server?
Could there be anything in the RTC server logs (I don't have server access, and have to open a ticket to get the logs looked at).
It looks to me like this happens more with the bigger components and we leave the build workspace loaded and it needs to actually not do much as often there are no source changes, it needs to rebuild because components it depends on had changes.
I don't see a timeout parameter for jbe, is there one somewhere?
BF 7.1.2
I am using the JBE adaptor to load a workspace to a redhat build server. Normally that step takes around 2 minutes (BF overhead and all). Every so often I get a timeout from what looks to me jbe. It also ends the BF adaptor. The step timeout is actually 15 minutes and the timeout is after 8 minutes in this case.
I found a thread where a shortage in some tmp directory could cause RTC to wait (it was a defect and I didn't bookmark it and now I can't find it again). /tmp on the build server has plenty of space.
The jbe log that usually shows up in RTC isn't there either and I only have the info that is below.
Is there anything I can look at on the build server?
Could there be anything in the RTC server logs (I don't have server access, and have to open a ticket to get the logs looked at).
It looks to me like this happens more with the bigger components and we leave the build workspace loaded and it needs to actually not do much as often there are no source changes, it needs to rebuild because components it depends on had changes.
I don't see a timeout parameter for jbe, is there one somewhere?
807 7/29/13 7:39 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Invoking pre-build participant "com.ibm.team.build.jazzscm" 808 7/29/13 7:44 AM TMO Timeout after 360 seconds. 809 7/29/13 7:44 AM RESULT 999
4 answers
The JBE can time out. You can control the socket timeout.
In case anyone is interested in the /tmp file problem that is here:
Hi Martina, the timeout shown looks to be coming from the build agent itself (indicated by TMO code from agent), not JBE, and it's happening after 6 minutes (360 secs) not 8. Is it possible there's a different timeout configured for the SCM step than the default, or some project-level timeout that's interfering?
Requests from JBE to the RTC server do have a default timeout of 8 minutes, and that can be overridden using system properties (see post referenced by Spencer), but that's not what I'm seeing here.
Is there any other output captured from the invocation of JBE?
Does anything earlier in the step log indicate what the step timeout is?
my comment was getting way too long, so here are more details, mostly a reply to Nick.
the BF step timeout is definitely 15 minutes. The step does several commands:
1. RTC ant task buildResultPublisher - set label
2. BF .retag
3. JazzJBE_lx - my tweaked JPE adaptor that uses a password file
So in the run I was using as an example above it starts at 7:36 and timed out 8 min later at 7:44. I don't know of any project level timeout settings in BF and the build step runs much longer, so I think that is definitely not the case.
Re post by Spencer, is that a -D for the jbe call below (ln 740) or something else? I also have access to the bf agent startup and conf, so I could enable logging there.
the log shows
the BF step timeout is definitely 15 minutes. The step does several commands:
1. RTC ant task buildResultPublisher - set label
2. BF .retag
3. JazzJBE_lx - my tweaked JPE adaptor that uses a password file
So in the run I was using as an example above it starts at 7:36 and timed out 8 min later at 7:44. I don't know of any project level timeout settings in BF and the build step runs much longer, so I think that is definitely not the case.
Re post by Spencer, is that a -D for the jbe call below (ln 740) or something else? I also have access to the bf agent startup and conf, so I could enable logging there.
the log shows
1 7/29/13 7:36 AM MANIFEST 450 lines of setting the env 454 7/29/13 7:37 AM SCRIPT /opt/IBM/apache-ant-1.6.5/bin/ant ... buildResultPublisher - set label
458 7/29/13 7:37 AM EXEC setBuildLabel: 461 7/29/13 7:37 AM EXEC BUILD SUCCESSFUL 462 7/29/13 7:37 AM EXEC Total time: 17 seconds
465 7/29/13 7:37 AM EXEC Changed tag string from ...
.... more set env vars
700 7/29/13 7:38 AM INT Adaptor using env name 'xxxx' for macro [ADAPTOR]. 701 7/29/13 7:38 AM EXEC Interface Processor Loaded. 702 7/29/13 7:38 AM INT Parsing Adaptor XML. 703 7/29/13 7:38 AM INT Loading source adaptor JazzJBE_lx
739 7/29/13 7:38 AM INT <command name="runJBE"> 740 7/29/13 7:38 AM INT <execute>$Build_Engine_Path/jbe -userId $Build_User -passwordFile $Build_PasswordFile -repository $Repository_Address -buildResultUUID $buildResultUuid -engineUUID $engineUUID -participants com.ibm.team.build.jazzscm -noComplete -verbose</execute> 741 7/29/13 7:38 AM INT <resultsblock> 742 7/29/13 7:38 AM INT <match pattern="RC\=[0]"> 743 7/29/13 7:38 AM INT <setenv name="Changes" value="TRUE" type="temp append\n" /> 744 7/29/13 7:38 AM INT </match> 745 7/29/13 7:38 AM INT <match pattern="RC\=[1]"> 746 7/29/13 7:38 AM INT <setenv name="Failure" value="TRUE" type="temp append\n" /> 747 7/29/13 7:38 AM INT </match> 748 7/29/13 7:38 AM INT <match pattern="RC\=[2]"> 749 7/29/13 7:38 AM INT <setenv name="Delete" value="TRUE" type="temp append\n" /> 750 7/29/13 7:38 AM INT </match> 751 7/29/13 7:38 AM INT </resultsblock> 752 7/29/13 7:38 AM INT </command> 785 7/29/13 7:38 AM EXEC Java Version: 786 7/29/13 7:38 AM EXEC J2RE 1.5.0 IBM J9 2.3 Linux x86-32 j9vmxi3223ifx-20100510 (JIT enabled) 787 7/29/13 7:38 AM EXEC J9VM - 20100509_57823_lHdSMr 788 7/29/13 7:38 AM EXEC JIT - 20091016_1845ifx7_r8 789 7/29/13 7:38 AM EXEC GC - 20091026_AA 790 7/29/13 7:38 AM EXEC 2013-07-29 07:38:35 [Jazz build engine] Searching for buildResultUUID=_pVrWofhCEeKyZYLCz_EuLQ 791 7/29/13 7:38 AM EXEC 2013-07-29 07:38:35 [Jazz build engine] The -noComplete parameter specified, build result will not be completed by JBE. 792 7/29/13 7:38 AM EXEC 2013-07-29 07:38:35 [Jazz build engine] Building only the specified participants: "[com.ibm.team.build.jazzscm]" 793 7/29/13 7:38 AM EXEC 2013-07-29 07:38:36 [Jazz build engine] Not using a proxy to reach https://xxxx:9443/jazz/ 794 7/29/13 7:38 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Searching for build request... 795 7/29/13 7:38 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Found a user request for build definition "dev_yyyyyyy.dddddd_zzzzzzz_bd". 796 7/29/13 7:38 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Build participant "com.ibm.team.build.cmdline" was not specified on -participants list. 797 7/29/13 7:38 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Build participant "com.ibm.team.build.ant" was not specified on -participants list. 798 7/29/13 7:38 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Build participant "com.ibm.team.build.maven" was not specified on -participants list. 799 7/29/13 7:38 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Build participant "com.ibm.team.build.junit.publishing" was not specified on -participants list. 800 7/29/13 7:38 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Build participant "com.ibm.team.build.jdt.publishing" was not specified on -participants list. 801 7/29/13 7:38 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Build participant "com.ibm.team.build.msbuild" was not specified on -participants list. 802 7/29/13 7:38 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Build participant "com.ibm.team.build.mstest.config" was not specified on -participants list. 803 7/29/13 7:38 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Build participant "com.ibm.team.build.nunit.config" was not specified on -participants list. 804 7/29/13 7:38 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Build participant "com.ibm.team.build.autoDeliver" was not specified on -participants list. 805 7/29/13 7:38 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Should build occur? 806 7/29/13 7:38 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Yes: Always build a user initiated request. 807 7/29/13 7:39 AM EXEC 2013-07-29 07:38:40 [Jazz build engine] Invoking pre-build participant "com.ibm.team.build.jazzscm" 808 7/29/13 7:44 AM TMO Timeout after 360 seconds. 809 7/29/13 7:44 AM RESULT 999
How long does the JBE command take from the command line on the agent machine? If its a large file download it may just be taking long to pull it down. JBE doesn't put anything into standard out so BF doesn't know that its still working, so if it take more than 360 seconds it will time out. Alternatively you can try bumping up the step timeout and see if the JBE eventually comes back.
~Spencer
Comments
hmm, the "interesting" piece is that it works just fine if I delete the load directory first. It hangs when we do incremental builds, i.e. the load directory is still there from the last build and there are no or very few changes. The load of the whole thing takes 2:30, so it is well below the 6 minutes that something is timing out in when I try to load only the changes.
I guess I will spend 30 sec on a compare and only call the JBE if I truly have changes and watch it. It should just load whatever changes there are - or does it do some sort of a check?
Good idea to just take BF out of the equation and run the JBE from the command line and see what it does there.
If I load the whole thing, I am looking at a 15 to 20 minute build from scratch. The incremental build should be much faster (I haven't made it to that in a while).
Lots of things to try.
The question fo ryou would be whether you have any insights on how the JBE loads changes.
hmm, running the jbe from the command line is easier said than done. I think it wants to have a build running in RTC. I will need to rig something and it will take time.
My guess right now is that the JBE is "thinking" and not sending any bits and the bf agent is timing out.
Re the tmp directory that the JBE uses, is that on the build server or the RTC server?