You are viewing a plain text version of this content. The canonical link for it is here.
Posted to ivy-user@ant.apache.org by Misha Dmitriev <mi...@cloudera.com> on 2016/10/25 20:50:03 UTC

Problem when building the same project concurrently for several OSes

Hi everybody,

We have some projects, like Zookeeper, that use Ant/Ivy. In some situations
such a project needs to be built multiple times, for different OSes. To
save time, we do it on the same machine and in parallel (we use docker
containers to build for different OSes). The main problem in this scenario
is when we want all these builds to share the same Ivy cache, i.e. use it
for concurrent reads and writes.

Ivy 2.4 and artifact-lock-nio locking strategy are supposed to address
this. However, when I attempted to switch to this combination and enable a
single cache, my builds failed. I've verified that NIO-based file locking
works across docker containers. I then found and enabled debug logging in
Ivy's FileBasedLockStrategy (one has to invoke ant with
'-Divy.log.locking=true'). It looks like locking for artifacts that are
downloaded from the web works as expected. However, in the end there is a
failure that says "failed to parse report: /home/cauldron/.ivy2/cache/
org.apache.zookeeper-zookeeper-default.xml". See the end of the log file
pasted below. The file in question contains essentially the list of
Zookeeper's external dependencies, and looks like Ivy itself has just
generated it.

So I am confused - why is Ivy trying to read it immediately after writing?
And, generally, is there any chance for us to fix or work around this
problem and use the single, shared Ivy cache?

Regards,

Misha


 [ivy:retrieve] Thread[main,5,main] 1477355454558 entered synchronized area
(locking)
 [ivy:retrieve] Thread[main,5,main] 1477355454558 current status for
/home/cauldron/.ivy2/cache/io.netty/netty/metadatas/metadata-3.10.5.Final.ivy.lck
is 1 held locks: Thread[main,5,main]
 [ivy:retrieve] Thread[main,5,main] 1477355454558 reentrant lock acquired
on /home/cauldron/.ivy2/cache/io.netty/netty/metadatas/metadata-3.10.5.Final.ivy.lck
in 0ms - hold locks = 2
 [ivy:retrieve] Thread[main,5,main] 1477355454558 releasing lock on
/home/cauldron/.ivy2/cache/io.netty/netty/metadatas/
metadata-3.10.5.Final.ivy.lck
 [ivy:retrieve] Thread[main,5,main] 1477355454558 entered synchronized area
(unlocking)
 [ivy:retrieve] Thread[main,5,main] 1477355454558 reentrant lock released
on /home/cauldron/.ivy2/cache/io.netty/netty/metadatas/metadata-3.10.5.Final.ivy.lck
- hold locks = 1
 [ivy:retrieve] Thread[main,5,main] 1477355454559 releasing lock on
/home/cauldron/.ivy2/cache/io.netty/netty/metadatas/
metadata-3.10.5.Final.ivy.lck
 [ivy:retrieve] Thread[main,5,main] 1477355454559 entered synchronized area
(unlocking)
 [ivy:retrieve] Thread[main,5,main] 1477355454559 lock released on
/home/cauldron/.ivy2/cache/io.netty/netty/metadatas/
metadata-3.10.5.Final.ivy.lck
 [ivy:retrieve] :: resolution report :: resolve 468ms :: artifacts dl 131ms
     ---------------------------------------------------------------------
     |                  |            modules            ||   artifacts   |
     |       conf       | number| search|dwnlded|evicted|| number|dwnlded|
     ---------------------------------------------------------------------
     |      default     |   5   |   0   |   0   |   0   ||   5   |   0   |
     ---------------------------------------------------------------------
 [ivy:retrieve] :: retrieving :: org.apache.zookeeper#zookeeper
 [ivy:retrieve]     confs: [default]

 BUILD FAILED
 /container.debian7/output/cdh/zookeeper/zookeeper-3.4.5+cdh6.x+0/build.xml:362:
impossible to ivy retrieve: java.lang.RuntimeException: problem during
retrieve of org.apache.zookeeper#zookeeper: java.text.ParseException:
failed to parse report:
/home/cauldron/.ivy2/cache/org.apache.zookeeper-zookeeper-default.xml:
Premature end of file.
     at org.apache.ivy.core.retrieve.RetrieveEngine.retrieve(
RetrieveEngine.java:249)
     at org.apache.ivy.Ivy.retrieve(Ivy.java:561)
     at org.apache.ivy.ant.IvyRetrieve.doExecute(IvyRetrieve.java:98)
     at org.apache.ivy.ant.IvyTask.execute(IvyTask.java:271)
     at org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:291)
     at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
     at sun.reflect.DelegatingMethodAccessorImpl.invoke(
DelegatingMethodAccessorImpl.java:43)
     at java.lang.reflect.Method.invoke(Method.java:498)
     at org.apache.tools.ant.dispatch.DispatchUtils.execute(
DispatchUtils.java:106)
     at org.apache.tools.ant.Task.perform(Task.java:348)
     at org.apache.tools.ant.Target.execute(Target.java:390)
     at org.apache.tools.ant.Target.performTasks(Target.java:411)
     at org.apache.tools.ant.Project.executeSortedTargets(Project.java:1399)
     at org.apache.tools.ant.Project.executeTarget(Project.java:1368)
     at org.apache.tools.ant.helper.DefaultExecutor.executeTargets(
DefaultExecutor.java:41)
     at org.apache.tools.ant.Project.executeTargets(Project.java:1251)
     at org.apache.tools.ant.Main.runBuild(Main.java:809)
     at org.apache.tools.ant.Main.startAnt(Main.java:217)
     at org.apache.tools.ant.launch.Launcher.run(Launcher.java:280)
     at org.apache.tools.ant.launch.Launcher.main(Launcher.java:109)
 Caused by: java.text.ParseException: failed to parse report:
/home/cauldron/.ivy2/cache/org.apache.zookeeper-zookeeper-default.xml:
Premature end of file.
     at org.apache.ivy.plugins.report.XmlReportParser.parse(
XmlReportParser.java:293)
     at org.apache.ivy.core.retrieve.RetrieveEngine.
determineArtifactsToCopy(RetrieveEngine.java:329)
     at org.apache.ivy.core.retrieve.RetrieveEngine.retrieve(
RetrieveEngine.java:118)
     ... 19 more
 Caused by: org.xml.sax.SAXParseException; systemId:
file:/home/cauldron/.ivy2/cache/org.apache.zookeeper-zookeeper-default.xml;
lineNumber: 1; columnNumber: 1; Premature end of file.
     at com.sun.org.apache.xerces.internal.util.ErrorHandlerWrapper.
createSAXParseException(ErrorHandlerWrapper.java:203)
     at com.sun.org.apache.xerces.internal.util.ErrorHandlerWrapper.
fatalError(ErrorHandlerWrapper.java:177)
     at com.sun.org.apache.xerces.internal.impl.
XMLErrorReporter.reportError(XMLErrorReporter.java:400)
     at com.sun.org.apache.xerces.internal.impl.
XMLErrorReporter.reportError(XMLErrorReporter.java:327)
     at com.sun.org.apache.xerces.internal.impl.XMLScanner.
reportFatalError(XMLScanner.java:1472)
     at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$
PrologDriver.next(XMLDocumentScannerImpl.java:1014)
     at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(
XMLDocumentScannerImpl.java:602)
     at com.sun.org.apache.xerces.internal.impl.
XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl
.java:505)
     at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(
XML11Configuration.java:841)
     at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(
XML11Configuration.java:770)
     at com.sun.org.apache.xerces.internal.parsers.XMLParser.
parse(XMLParser.java:141)
     at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(
AbstractSAXParser.java:1213)
     at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$
JAXPSAXParser.parse(SAXParserImpl.java:643)
     at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl.
parse(SAXParserImpl.java:327)
     at javax.xml.parsers.SAXParser.parse(SAXParser.java:328)
     at org.apache.ivy.plugins.report.XmlReportParser$
SaxXmlReportParser.parse(XmlReportParser.java:249)
     at org.apache.ivy.plugins.report.XmlReportParser.parse(
XmlReportParser.java:291)
     ... 21 more

AW: Problem when building the same project concurrently for several OSes

Posted by Geißler, Daniel <da...@salt-solutions.de>.
Hi Misha,

as far as i remember the problem might not be the artifact cache, but the resolution cache.
The behavior I observed was, that ivy keeps some kind of dependency-resolution-cache of recently resolved artifacts. This cache seems to have no locking and multiple builds may rewrite files that are currently read by another build.

http://ant.apache.org/ivy/history/2.0.0/settings/caches.html
see the properties for repositoryCacheDir vs. resolutionCacheDir

I haven’t had time to evaluate the behavior, but any feedback is appreciated.

Regards,
Daniel

_____________________________________

SALT Solutions GmbH

Geschäftsführer: Dr. Bernhard Blüthner, Norbert H. Fiedler, Dieter Heyde, Markus Honold
Sitz: München, AG München, HRB 146081 

Hi everybody,

We have some projects, like Zookeeper, that use Ant/Ivy. In some situations such a project needs to be built multiple times, for different OSes. To save time, we do it on the same machine and in parallel (we use docker containers to build for different OSes). The main problem in this scenario is when we want all these builds to share the same Ivy cache, i.e. use it for concurrent reads and writes.

Ivy 2.4 and artifact-lock-nio locking strategy are supposed to address this. However, when I attempted to switch to this combination and enable a single cache, my builds failed. I've verified that NIO-based file locking works across docker containers. I then found and enabled debug logging in Ivy's FileBasedLockStrategy (one has to invoke ant with '-Divy.log.locking=true'). It looks like locking for artifacts that are downloaded from the web works as expected. However, in the end there is a failure that says "failed to parse report: /home/cauldron/.ivy2/cache/ org.apache.zookeeper-zookeeper-default.xml". See the end of the log file pasted below. The file in question contains essentially the list of Zookeeper's external dependencies, and looks like Ivy itself has just generated it.

So I am confused - why is Ivy trying to read it immediately after writing?
And, generally, is there any chance for us to fix or work around this problem and use the single, shared Ivy cache?

Regards,

Misha


 [ivy:retrieve] Thread[main,5,main] 1477355454558 entered synchronized area
(locking)
 [ivy:retrieve] Thread[main,5,main] 1477355454558 current status for /home/cauldron/.ivy2/cache/io.netty/netty/metadatas/metadata-3.10.5.Final.ivy.lck
is 1 held locks: Thread[main,5,main]
 [ivy:retrieve] Thread[main,5,main] 1477355454558 reentrant lock acquired on /home/cauldron/.ivy2/cache/io.netty/netty/metadatas/metadata-3.10.5.Final.ivy.lck
in 0ms - hold locks = 2
 [ivy:retrieve] Thread[main,5,main] 1477355454558 releasing lock on /home/cauldron/.ivy2/cache/io.netty/netty/metadatas/
metadata-3.10.5.Final.ivy.lck
 [ivy:retrieve] Thread[main,5,main] 1477355454558 entered synchronized area
(unlocking)
 [ivy:retrieve] Thread[main,5,main] 1477355454558 reentrant lock released on /home/cauldron/.ivy2/cache/io.netty/netty/metadatas/metadata-3.10.5.Final.ivy.lck
- hold locks = 1
 [ivy:retrieve] Thread[main,5,main] 1477355454559 releasing lock on /home/cauldron/.ivy2/cache/io.netty/netty/metadatas/
metadata-3.10.5.Final.ivy.lck
 [ivy:retrieve] Thread[main,5,main] 1477355454559 entered synchronized area
(unlocking)
 [ivy:retrieve] Thread[main,5,main] 1477355454559 lock released on /home/cauldron/.ivy2/cache/io.netty/netty/metadatas/
metadata-3.10.5.Final.ivy.lck
 [ivy:retrieve] :: resolution report :: resolve 468ms :: artifacts dl 131ms
     ---------------------------------------------------------------------
     |                  |            modules            ||   artifacts   |
     |       conf       | number| search|dwnlded|evicted|| number|dwnlded|
     ---------------------------------------------------------------------
     |      default     |   5   |   0   |   0   |   0   ||   5   |   0   |
     ---------------------------------------------------------------------
 [ivy:retrieve] :: retrieving :: org.apache.zookeeper#zookeeper
 [ivy:retrieve]     confs: [default]

 BUILD FAILED
 /container.debian7/output/cdh/zookeeper/zookeeper-3.4.5+cdh6.x+0/build.xml:362:
impossible to ivy retrieve: java.lang.RuntimeException: problem during retrieve of org.apache.zookeeper#zookeeper: java.text.ParseException:
failed to parse report:
/home/cauldron/.ivy2/cache/org.apache.zookeeper-zookeeper-default.xml:
Premature end of file.
     at org.apache.ivy.core.retrieve.RetrieveEngine.retrieve(
RetrieveEngine.java:249)
     at org.apache.ivy.Ivy.retrieve(Ivy.java:561)
     at org.apache.ivy.ant.IvyRetrieve.doExecute(IvyRetrieve.java:98)
     at org.apache.ivy.ant.IvyTask.execute(IvyTask.java:271)
     at org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:291)
     at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source)
     at sun.reflect.DelegatingMethodAccessorImpl.invoke(
DelegatingMethodAccessorImpl.java:43)
     at java.lang.reflect.Method.invoke(Method.java:498)
     at org.apache.tools.ant.dispatch.DispatchUtils.execute(
DispatchUtils.java:106)
     at org.apache.tools.ant.Task.perform(Task.java:348)
     at org.apache.tools.ant.Target.execute(Target.java:390)
     at org.apache.tools.ant.Target.performTasks(Target.java:411)
     at org.apache.tools.ant.Project.executeSortedTargets(Project.java:1399)
     at org.apache.tools.ant.Project.executeTarget(Project.java:1368)
     at org.apache.tools.ant.helper.DefaultExecutor.executeTargets(
DefaultExecutor.java:41)
     at org.apache.tools.ant.Project.executeTargets(Project.java:1251)
     at org.apache.tools.ant.Main.runBuild(Main.java:809)
     at org.apache.tools.ant.Main.startAnt(Main.java:217)
     at org.apache.tools.ant.launch.Launcher.run(Launcher.java:280)
     at org.apache.tools.ant.launch.Launcher.main(Launcher.java:109)
 Caused by: java.text.ParseException: failed to parse report:
/home/cauldron/.ivy2/cache/org.apache.zookeeper-zookeeper-default.xml:
Premature end of file.
     at org.apache.ivy.plugins.report.XmlReportParser.parse(
XmlReportParser.java:293)
     at org.apache.ivy.core.retrieve.RetrieveEngine.
determineArtifactsToCopy(RetrieveEngine.java:329)
     at org.apache.ivy.core.retrieve.RetrieveEngine.retrieve(
RetrieveEngine.java:118)
     ... 19 more
 Caused by: org.xml.sax.SAXParseException; systemId:
file:/home/cauldron/.ivy2/cache/org.apache.zookeeper-zookeeper-default.xml;
lineNumber: 1; columnNumber: 1; Premature end of file.
     at com.sun.org.apache.xerces.internal.util.ErrorHandlerWrapper.
createSAXParseException(ErrorHandlerWrapper.java:203)
     at com.sun.org.apache.xerces.internal.util.ErrorHandlerWrapper.
fatalError(ErrorHandlerWrapper.java:177)
     at com.sun.org.apache.xerces.internal.impl.
XMLErrorReporter.reportError(XMLErrorReporter.java:400)
     at com.sun.org.apache.xerces.internal.impl.
XMLErrorReporter.reportError(XMLErrorReporter.java:327)
     at com.sun.org.apache.xerces.internal.impl.XMLScanner.
reportFatalError(XMLScanner.java:1472)
     at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl$
PrologDriver.next(XMLDocumentScannerImpl.java:1014)
     at com.sun.org.apache.xerces.internal.impl.XMLDocumentScannerImpl.next(
XMLDocumentScannerImpl.java:602)
     at com.sun.org.apache.xerces.internal.impl.
XMLDocumentFragmentScannerImpl.scanDocument(XMLDocumentFragmentScannerImpl
.java:505)
     at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(
XML11Configuration.java:841)
     at com.sun.org.apache.xerces.internal.parsers.XML11Configuration.parse(
XML11Configuration.java:770)
     at com.sun.org.apache.xerces.internal.parsers.XMLParser.
parse(XMLParser.java:141)
     at com.sun.org.apache.xerces.internal.parsers.AbstractSAXParser.parse(
AbstractSAXParser.java:1213)
     at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl$
JAXPSAXParser.parse(SAXParserImpl.java:643)
     at com.sun.org.apache.xerces.internal.jaxp.SAXParserImpl.
parse(SAXParserImpl.java:327)
     at javax.xml.parsers.SAXParser.parse(SAXParser.java:328)
     at org.apache.ivy.plugins.report.XmlReportParser$
SaxXmlReportParser.parse(XmlReportParser.java:249)
     at org.apache.ivy.plugins.report.XmlReportParser.parse(
XmlReportParser.java:291)
     ... 21 more