Reading assembly descriptor taking longer on new install
We have TeamCity running in EC2. We recently moved it from an m1.small instance to an m1.large and now java builds take longer than they did before which is obviously not what we wanted. We noticed that the step:
Reading assembly descriptor
is what's taking the extra time - went from a few seconds to a minute. New insance is running a newer version of TeamCity (17985 vs 17795). Also, the m1.small runs a 32bit OS where the m1.large a 64 bit. Both are linux although not the same distribution. Both are Ubuntu, old is 10.04 and new is 11.04.
Any idea what could cause the increase in time?
Please sign in to leave a comment.
I turned on debug logging in maven and I can see it's whatever process (jar?) that's creating the zip? The other difference between the two machines is our old instance is running sun java:
bitnami@ip-10-162-30-192:/usr/lib/youtrack3.0/standalone$ java -version
java version "1.6.0_24"
Java(TM) SE Runtime Environment (build 1.6.0_24-b07)
Java HotSpot(TM) Client VM (build 19.1-b02, mixed mode, sharing)
vs open jdk on the new:
ubuntu@ip-10-171-54-43:/home/youtrack/standalone$ java -version
java version "1.6.0_22"
OpenJDK Runtime Environment (IcedTea6 1.10.2) (6b22-1.10.2-0ubuntu1~11.04.1)
OpenJDK 64-Bit Server VM (build 20.0-b11, mixed mode)
Debug log snippits:
old:
[21:41:34]: [com.oggifinogi:logpusher] [DEBUG] asm:asm:jar:3.3.1:runtime (selected for runtime)
[21:41:34]: [com.oggifinogi:logpusher] [DEBUG] Adding file: /usr/lib/teamcity6.5/buildAgent/work/303822e41e7d9710/com.oggifinogi.logpusher/../com.oggifinogi.build/win/install-service.cmd to archive location: install-service.cmd
[21:41:35]: [com.oggifinogi:logpusher] [DEBUG] Adding file: /usr/lib/teamcity6.5/buildAgent/work/303822e41e7d9710/com.oggifinogi.logpusher/../com.oggifinogi.build/win/prunmgr.exe to archive location: logpusherw.exe
[21:41:35]: [com.oggifinogi:logpusher] [DEBUG] Adding file: /usr/lib/teamcity6.5/buildAgent/work/303822e41e7d9710/com.oggifinogi.logpusher/../com.oggifinogi.build/win/prunsrv.exe to archive location: logpusher.exe
[21:41:35]: [com.oggifinogi:logpusher] [DEBUG] Adding file: /usr/lib/teamcity6.5/buildAgent/work/303822e41e7d9710/com.oggifinogi.logpusher/bin/maven/logpusher-5.0.1-SNAPSHOT.jar to archive location: oggifinogi-logpusher.jar
[21:41:35]: [com.oggifinogi:logpusher] [DEBUG] Adding file: /usr/lib/teamcity6.5/buildAgent/work/303822e41e7d9710/com.oggifinogi.logpusher/../com.oggifinogi.build/nix/log-pusher.sh to archive location: log-pusher.sh
[21:41:35]: [com.oggifinogi:logpusher] [DEBUG] Processing DependencySet (output=/lib)
[21:41:35]: [com.oggifinogi:logpusher] [DEBUG] Dependencies for project: com.oggifinogi:logpusher:jar:5.0.1-SNAPSHOT are:
[21:41:35]: [com.oggifinogi:logpusher] active project artifact:
[21:41:35]: [com.oggifinogi:logpusher] artifact = com.oggifinogi:basement:jar:5.0.1-SNAPSHOT:compile;
new:
[21:30:36]: [com.oggifinogi:logpusher] [DEBUG] asm:asm:jar:3.3.1:runtime (selected for runtime)
[21:30:36]: [com.oggifinogi:logpusher] [DEBUG] Adding file: /home/teamcity/teamcity6.5/buildAgent/work/303822e41e7d9710/com.oggifinogi.logpusher/../com.oggifinogi.build/win/install-service.cmd to archive location: install-service.cmd
[21:30:38]: [com.oggifinogi:logpusher] [DEBUG] Adding file: /home/teamcity/teamcity6.5/buildAgent/work/303822e41e7d9710/com.oggifinogi.logpusher/../com.oggifinogi.build/win/prunmgr.exe to archive location: logpusherw.exe
[21:30:39]: [com.oggifinogi:logpusher] [DEBUG] Adding file: /home/teamcity/teamcity6.5/buildAgent/work/303822e41e7d9710/com.oggifinogi.logpusher/../com.oggifinogi.build/win/prunsrv.exe to archive location: logpusher.exe
[21:30:41]: [com.oggifinogi:logpusher] [DEBUG] Adding file: /home/teamcity/teamcity6.5/buildAgent/work/303822e41e7d9710/com.oggifinogi.logpusher/bin/maven/logpusher-5.0.1-SNAPSHOT.jar to archive location: oggifinogi-logpusher.jar
[21:30:42]: [com.oggifinogi:logpusher] [DEBUG] Adding file: /home/teamcity/teamcity6.5/buildAgent/work/303822e41e7d9710/com.oggifinogi.logpusher/../com.oggifinogi.build/nix/log-pusher.sh to archive location: log-pusher.sh
[21:30:43]: [com.oggifinogi:logpusher] [DEBUG] Processing DependencySet (output=/lib)
[21:30:43]: [com.oggifinogi:logpusher] [DEBUG] Dependencies for project: com.oggifinogi:logpusher:jar:5.0.1-SNAPSHOT are:
[21:30:43]: [com.oggifinogi:logpusher] active project artifact:
[21:30:43]: [com.oggifinogi:logpusher] artifact = com.oggifinogi:basement:jar:5.0.1-SNAPSHOT:compile;
Hi Jerry,
Why do you think this effect is related to TeamCity?
Did you try to perfrom this command manually and check the time?
I don't know that it is and likely it's not. But I thought someone on this forum might have an idea to help me... And I haven't yet tried running the commands manually but will.
How do I execute maven commands locally using the plugin?
Hi Jerry,
just login to this machine under the agent's account, go to the checkout directory, and run the build from the command line.
If you still observe slowness then TeamCity hardly has something to do with it.
I think I'm seeing the same issue. I tried Sergey's suggestion of running it locally and found that it was much faster, however when run through teamcity it's much slower.
I turned on verbose garbage collection logging and found that reading from the assembly-descriptor.xml and building the artifact often kicks off a full GC. Any idea why a remote build would trigger longer more frequent full GC's?
details:
apache-maven-2.2.1
jdk1.6.0_21
build agent 5.1.3
In which JVM you were seeing GC working hard - the agent's or the Maven's one?