On Thu, Jan 14, 2010 at 9:19 PM, Martin Gerner < martin.ger...@postgrad.manchester.ac.uk> wrote:
> As far as I can tell from the source, it looks like the temporary directory > is specified by a parameter Constants.Configuration.ARTIFACTS_TEMP_DIR, > which according to a comment in > http://issues.apache.org/jira/browse/AXIS2-3552 is set to > javax.servlet.context.tempdir. > But currently I think this value is not being used. please check whether there is any temp folder created under temp folder. thanks, Amila. > > I haven't had much success with changing it myself though, or finding out > what the real value of the parameter is. > > > [WARN] Exception extracting jars into temporary directory : > java.io.IOException: No such file or directory : switching to alternate > class loading mechanism > [DEBUG] java.io.IOException: No such file or directory > java.lang.RuntimeException: java.io.IOException: No such file or directory > at > org.apache.axis2.deployment.util.Utils.getURLsForAllJars(Utils.java:194) > at > org.apache.axis2.deployment.util.Utils.createClassLoader(Utils.java:899) > at > org.apache.axis2.deployment.repository.util.DeploymentFileData.setClassLoader(DeploymentFileData.java:115) > at > org.apache.axis2.deployment.ServiceDeployer.deploy(ServiceDeployer.java:64) > at > org.apache.axis2.deployment.repository.util.DeploymentFileData.deploy(DeploymentFileData.java:136) > at > org.apache.axis2.deployment.DeploymentEngine.doDeploy(DeploymentEngine.java:659) > at > org.apache.axis2.deployment.repository.util.WSInfoList.update(WSInfoList.java:144) > at > org.apache.axis2.deployment.RepositoryListener.update(RepositoryListener.java:337) > at > org.apache.axis2.deployment.RepositoryListener.checkServices(RepositoryListener.java:241) > at > org.apache.axis2.deployment.DeploymentEngine.loadServices(DeploymentEngine.java:131) > at > org.apache.axis2.deployment.FileSystemConfigurator.loadServices(FileSystemConfigurator.java:147) > at > org.apache.axis2.context.ConfigurationContextFactory.createConfigurationContext(ConfigurationContextFactory.java:95) > at > org.apache.axis2.context.ConfigurationContextFactory.createConfigurationContextFromFileSystem(ConfigurationContextFactory.java:206) > at > org.apache.axis2.transport.SimpleAxis2Server.<init>(SimpleAxis2Server.java:47) > at > org.apache.axis2.transport.SimpleAxis2Server.main(SimpleAxis2Server.java:98) > Caused by: java.io.IOException: No such file or directory > at java.io.UnixFileSystem.createFileExclusively(Native Method) > at java.io.File.checkAndCreate(File.java:1704) > at java.io.File.createTempFile(File.java:1792) > at > org.apache.axis2.deployment.util.TempFileManager.createTempFile(TempFileManager.java:101) > at > org.apache.axis2.deployment.util.Utils.createTempFile(Utils.java:224) > at > org.apache.axis2.deployment.util.Utils.getURLsForAllJars(Utils.java:188) > ... 14 more > > > On 14/01/2010 14:36, Amila Suriarachchi wrote: > >> >> >> On Thu, Jan 14, 2010 at 4:38 PM, Martin Gerner < >> martin.ger...@postgrad.manchester.ac.uk <mailto: >> martin.ger...@postgrad.manchester.ac.uk>> wrote: >> >> Hi Andreas (and the rest of you), >> >> Thank you very much for your answer. >> >> Seeing as the problem seems to be in accessing the .jar file, I >> extracted the .jar file to the services directory and then removed >> the .jar file, so axis2 could access the service in an already >> extracted format. The access times are now down to what I would >> expect them to be, and everything seems to be running fine. >> >> I'm now guessing that the extremely slow accessing of the service >> .jar file is related to the following warning I get during axis2 >> startup: "[WARN] Exception extracting jars into temporary >> directory : java.io.IOException: No such file or directory : >> switching to alternate class loading mechanism". It would be nice >> to be able to solve this root cause of the problem (both so I can >> go back to using .jars but also for future readers of this >> conversation), but I have been unable to find where this >> "temporary directory" is set (so I could change the directory to >> something that would work). As far as I can tell, conf/axis2.xml >> does not contain any option for this. >> >> It is a bit irritating that the warning does not specify what path >> the temporary directory is - that would really be a helpful >> addition to the warning message. Axis2 does make use of the /tmp >> directory, which it can access (and indeed does store data in) >> which just makes it more strange. >> >> >> normally axis2 creates the temp files at the "java.io.tmpdir". >> >> String tmpDirName = System.getProperty("java.io.tmpdir"); >> >> For linux this is /tmp. Could you swith on the debug (which you should be >> able to do with log4j file) and see the real exception. >> >> On 13/01/2010 19:17, Andreas Veithen wrote: >> >> The issue seems to be as follows: >> >> * For POJO services, Axis2 uses the JRE's bean introspector to detect >> the properties of the POJOs. >> * Following the Java Beans standard, the introspector attempts to find >> BeanInfo classes corresponding to these POJOs. BeanInfo classes are >> optional and rarely used in this context. >> * Axis2 uses the service class loader to introspect the beans. This is >> not a standard class loader, but a component specific to Axis2 >> (DeploymentClassLoader) which uses a different strategy to load the >> classes. I had a quick look at the code, and it appears that in order >> to load a class, it needs to scan all the JARs used by the service >> archive. >> >> Conclusion: in this case, Axis2 repeatedly attempts to load non >> existing classes from a class loader that uses a suboptimal strategy >> to load resources from JARs. >> >> Unfortunately, I'm not very familiar with the POJO and class loading >> parts of Axis2. Maybe some of the other developers can shed some light >> on the following questions: >> >> * Shouldn't the POJO code cache the results returned by the bean >> introspector? >> * Why is the DeploymentClassLoader implemented in this way? My guess >> is that it is to avoid file locking issues. Thus, it is only used when >> hot deployment is enabled? >> >> Andreas >> >> On Wed, Jan 13, 2010 at 15:24, Martin Gerner >> <martin.ger...@postgrad.manchester.ac.uk >> <mailto:martin.ger...@postgrad.manchester.ac.uk>> wrote: >> >> I've attached a full thread dump. I'd greatly appreciate any >> help in >> determining the cause, as I'm quite a novice when it comes to >> Axis2 and its >> internal workings. CPU usage for the java process goes up to >> 100% when it's >> blocking. >> >> The top parts of a few dumps (taken at different times to get >> an idea about >> whether it's the same thing blocking): >> >> "HttpConnection-8080-1" prio=10 tid=0x08c06c00 nid=0x1c77 runnable >> [0x2e9fe000] >> java.lang.Thread.State: RUNNABLE >> at java.util.zip.Inflater.inflateBytes(Native Method) >> at java.util.zip.Inflater.inflate(Inflater.java:223) >> - locked <0xa65b86e0> (a java.util.zip.Inflater) >> at >> >> java.util.zip.InflaterInputStream.read(InflaterInputStream.java:135) >> at java.util.zip.ZipInputStream.read(ZipInputStream.java:146) >> at >> java.util.zip.ZipInputStream.closeEntry(ZipInputStream.java:92) >> at >> java.util.zip.ZipInputStream.getNextEntry(ZipInputStream.java:70) >> at >> >> >> org.apache.axis2.deployment.DeploymentClassLoader.getBytes(DeploymentClassLoader.java:198) >> at >> >> >> org.apache.axis2.deployment.DeploymentClassLoader.getBytes(DeploymentClassLoader.java:178) >> at >> >> >> org.apache.axis2.deployment.DeploymentClassLoader.findClass(DeploymentClassLoader.java:81) >> at java.lang.ClassLoader.loadClass(ClassLoader.java:307) >> - locked <0x34220a70> (a >> org.apache.axis2.deployment.DeploymentClassLoader) >> at java.lang.ClassLoader.loadClass(ClassLoader.java:252) >> at >> java.beans.Introspector.instantiate(Introspector.java:1453) >> [...] >> >> >> ---- >> >> "HttpConnection-8080-2" prio=10 tid=0x08a4fc00 nid=0x1cf6 runnable >> [0x2e9ad000] >> java.lang.Thread.State: RUNNABLE >> at >> java.util.zip.ZipInputStream.readFully(ZipInputStream.java:403) >> at >> java.util.zip.ZipInputStream.readEnd(ZipInputStream.java:361) >> at java.util.zip.ZipInputStream.read(ZipInputStream.java:148) >> at >> java.util.zip.ZipInputStream.closeEntry(ZipInputStream.java:92) >> at >> java.util.zip.ZipInputStream.getNextEntry(ZipInputStream.java:70) >> at >> >> >> org.apache.axis2.deployment.DeploymentClassLoader.getBytes(DeploymentClassLoader.java:198) >> at >> >> >> org.apache.axis2.deployment.DeploymentClassLoader.getBytes(DeploymentClassLoader.java:178) >> at >> >> >> org.apache.axis2.deployment.DeploymentClassLoader.findClass(DeploymentClassLoader.java:81) >> at java.lang.ClassLoader.loadClass(ClassLoader.java:307) >> - locked <0x342afa70> (a >> org.apache.axis2.deployment.DeploymentClassLoader) >> at java.lang.ClassLoader.loadClass(ClassLoader.java:252) >> at >> java.beans.Introspector.instantiate(Introspector.java:1453) >> >> ---- >> >> Best wishes, >> Martin Gerner >> >> On 13/01/2010 12:30, Andreas Veithen wrote: >> >> The type of databinding cannot account for this delay. I >> would suggest >> to take a thread dump and try to understand where Axis2 is >> blocking. >> >> Andreas >> >> On Wed, Jan 13, 2010 at 13:04, Bruno Simioni >> <brunosimi...@gmail.com <mailto:brunosimi...@gmail.com>> >> >> wrote: >> >> >> Maybe using JAXB annotations on Java return objects, >> you can speed up the >> process. >> >> Bruno. >> >> On Wed, Jan 13, 2010 at 9:51 AM, Martin Gerner >> <martin.ger...@postgrad.manchester.ac.uk >> <mailto:martin.ger...@postgrad.manchester.ac.uk>> wrote: >> >> >> Hi all, >> >> I'm running a simple web service which receives a >> string from the >> client, processes it and returns an array of >> custom objects (nothing >> complicated, they're just data holders containing >> a few ints, strings >> and booleans). While the actual serverside >> processing performed by my >> server code is performed very fast, the response >> times from the server >> are very large and seem to be linear in the number >> of returned objects. >> >> A short example: if I send a string to the server >> which results in 0 >> objects being returned, the response from the >> server is received just a >> few milliseconds after the request is made. If the >> string is modified >> such that it returns one object, that increases to >> 8 seconds, and if it >> returns two objects it increases to 16 seconds. In >> all cases, I can see >> that the actual processing takes less than a >> second, so the web service >> java code that I've deployed is handling the >> requests quickly. >> >> All responses are small in size - the largest is >> ~900 bytes (so I can't >> imagine that it's an XML transformation issue). >> Using packet sniffers, I >> can see that the delay definitely is occurring on >> the server side (for >> the last example, I could see the POST packet >> going to the server, and >> then the response packet coming back 16 seconds >> later). Going by client >> and server log timings, I can see that the delay >> occurs after processing >> rather than before. >> >> I'm running axis2 1.5.1 with default settings, >> have tested it running on >> both the bundled SimpleAxisServer and Tomcat (both >> on a Debian server) >> and am using a very simple client based on code >> auto-generated by axis >> from the WSDL (running in Windows). >> >> Does anybody here have any clue as to what's >> causing the delays? It >> seems clear enough that it's something in the >> internal axis2 system, but >> as I'm quite new to axis2 I'm having difficulties >> locating the issue. >> >> Best wishes, >> Martin Gerner >> >> >> >> -- >> Martin Gerner >> Faculty of Life Sciences >> Michael Smith Building >> University of Manchester >> Manchester, M13 9PT >> >> >> Full thread dump Java HotSpot(TM) Server VM (14.2-b01 mixed mode): >> >> "HttpConnection-8080-1" prio=10 tid=0x08c06c00 nid=0x1c77 runnable >> [0x2e9fe000] >> java.lang.Thread.State: RUNNABLE >> at java.util.zip.Inflater.inflateBytes(Native Method) >> at java.util.zip.Inflater.inflate(Inflater.java:223) >> - locked <0xa65b86e0> (a java.util.zip.Inflater) >> at >> >> java.util.zip.InflaterInputStream.read(InflaterInputStream.java:135) >> at >> java.util.zip.ZipInputStream.read(ZipInputStream.java:146) >> at >> java.util.zip.ZipInputStream.closeEntry(ZipInputStream.java:92) >> at >> java.util.zip.ZipInputStream.getNextEntry(ZipInputStream.java:70) >> at >> >> >> org.apache.axis2.deployment.DeploymentClassLoader.getBytes(DeploymentClassLoader.java:198) >> at >> >> >> org.apache.axis2.deployment.DeploymentClassLoader.getBytes(DeploymentClassLoader.java:178) >> at >> >> >> org.apache.axis2.deployment.DeploymentClassLoader.findClass(DeploymentClassLoader.java:81) >> at java.lang.ClassLoader.loadClass(ClassLoader.java:307) >> - locked <0x34220a70> (a >> org.apache.axis2.deployment.DeploymentClassLoader) >> at java.lang.ClassLoader.loadClass(ClassLoader.java:252) >> at >> java.beans.Introspector.instantiate(Introspector.java:1453) >> at >> java.beans.Introspector.findExplicitBeanInfo(Introspector.java:425) >> - locked <0x303c7a30> (a java.lang.Class for >> java.beans.Introspector) >> at java.beans.Introspector.<init>(Introspector.java:374) >> at >> java.beans.Introspector.getBeanInfo(Introspector.java:231) >> at >> java.beans.Introspector.getBeanInfo(Introspector.java:217) >> at >> >> >> org.apache.axis2.databinding.utils.BeanUtil.getPropertyQnameList(BeanUtil.java:132) >> at >> >> org.apache.axis2.databinding.utils.BeanUtil.getPullParser(BeanUtil.java:67) >> at >> >> >> org.apache.axis2.databinding.utils.reader.ADBXMLStreamReaderImpl.processProperties(ADBXMLStreamReaderImpl.java:998) >> at >> >> >> org.apache.axis2.databinding.utils.reader.ADBXMLStreamReaderImpl.next(ADBXMLStreamReaderImpl.java:854) >> at >> org.apache.axis2.util.StreamWrapper.next(StreamWrapper.java:71) >> at >> >> >> javax.xml.stream.util.StreamReaderDelegate.next(StreamReaderDelegate.java:60) >> at >> >> >> org.apache.axiom.om.impl.builder.SafeXMLStreamReader.next(SafeXMLStreamReader.java:183) >> at >> >> >> org.apache.axiom.om.impl.builder.StAXOMBuilder.parserNext(StAXOMBuilder.java:597) >> at >> >> org.apache.axiom.om.impl.builder.StAXOMBuilder.next(StAXOMBuilder.java:172) >> at >> org.apache.axiom.om.impl.llom.OMNodeImpl.build(OMNodeImpl.java:335) >> at >> >> org.apache.axiom.om.impl.llom.OMElementImpl.build(OMElementImpl.java:737) >> at >> >> org.apache.axiom.om.impl.llom.OMElementImpl.detach(OMElementImpl.java:706) >> at >> >> org.apache.axiom.om.impl.llom.OMNodeImpl.setParent(OMNodeImpl.java:124) >> at >> >> org.apache.axiom.om.impl.llom.OMElementImpl.addChild(OMElementImpl.java:297) >> at >> >> org.apache.axiom.om.impl.llom.OMElementImpl.addChild(OMElementImpl.java:213) >> at >> >> org.apache.axiom.soap.impl.llom.SOAPBodyImpl.addChild(SOAPBodyImpl.java:231) >> at >> >> >> org.apache.axis2.rpc.receivers.RPCUtil.processResponseAsDocLitWrapped(RPCUtil.java:381) >> at >> >> >> org.apache.axis2.rpc.receivers.RPCMessageReceiver.invokeBusinessLogic(RPCMessageReceiver.java:138) >> at >> >> >> org.apache.axis2.receivers.AbstractInOutMessageReceiver.invokeBusinessLogic(AbstractInOutMessageReceiver.java:40) >> at >> >> >> org.apache.axis2.receivers.AbstractMessageReceiver.receive(AbstractMessageReceiver.java:114) >> at >> org.apache.axis2.engine.AxisEngine.receive(AxisEngine.java:173) >> at >> >> >> org.apache.axis2.transport.http.HTTPTransportUtils.processHTTPPostRequest(HTTPTransportUtils.java:167) >> at >> >> org.apache.axis2.transport.http.HTTPWorker.service(HTTPWorker.java:266) >> at >> >> >> org.apache.axis2.transport.http.server.AxisHttpService.doService(AxisHttpService.java:281) >> at >> >> >> org.apache.axis2.transport.http.server.AxisHttpService.handleRequest(AxisHttpService.java:187) >> at >> >> >> org.apache.axis2.transport.http.server.HttpServiceProcessor.run(HttpServiceProcessor.java:82) >> at >> >> >> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) >> at >> >> >> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) >> at java.lang.Thread.run(Thread.java:619) >> >> "DestroyJavaVM" prio=10 tid=0x2ee3c000 nid=0x1c66 waiting on >> condition >> [0x00000000] >> java.lang.Thread.State: RUNNABLE >> >> "HttpListener-8080-1" prio=10 tid=0x2f013400 nid=0x1c75 runnable >> [0x2ebad000] >> java.lang.Thread.State: RUNNABLE >> at java.net.PlainSocketImpl.socketAccept(Native Method) >> at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390) >> - locked <0x34998010> (a java.net.SocksSocketImpl) >> at java.net.ServerSocket.implAccept(ServerSocket.java:453) >> at java.net.ServerSocket.accept(ServerSocket.java:421) >> at >> >> >> org.apache.axis2.transport.http.server.DefaultConnectionListener.run(DefaultConnectionListener.java:79) >> at >> >> >> java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) >> at >> >> >> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) >> at java.lang.Thread.run(Thread.java:619) >> >> "Timer-1" daemon prio=10 tid=0x0896ac00 nid=0x1c74 in >> Object.wait() >> [0x2ebfe000] >> java.lang.Thread.State: TIMED_WAITING (on object monitor) >> at java.lang.Object.wait(Native Method) >> - waiting on <0x3445d260> (a java.util.TaskQueue) >> at java.util.TimerThread.mainLoop(Timer.java:509) >> - locked <0x3445d260> (a java.util.TaskQueue) >> at java.util.TimerThread.run(Timer.java:462) >> >> "Timer-0" daemon prio=10 tid=0x08c17c00 nid=0x1c73 in >> Object.wait() >> [0x2eda7000] >> java.lang.Thread.State: TIMED_WAITING (on object monitor) >> at java.lang.Object.wait(Native Method) >> - waiting on <0x342b3a08> (a java.util.TaskQueue) >> at java.util.TimerThread.mainLoop(Timer.java:509) >> - locked <0x342b3a08> (a java.util.TaskQueue) >> at java.util.TimerThread.run(Timer.java:462) >> >> "Low Memory Detector" daemon prio=10 tid=0x2f78d800 nid=0x1c6f >> runnable >> [0x00000000] >> java.lang.Thread.State: RUNNABLE >> >> "CompilerThread1" daemon prio=10 tid=0x2f78b400 nid=0x1c6e >> waiting on >> condition [0x00000000] >> java.lang.Thread.State: RUNNABLE >> >> "CompilerThread0" daemon prio=10 tid=0x2f789800 nid=0x1c6d >> waiting on >> condition [0x00000000] >> java.lang.Thread.State: RUNNABLE >> >> "Signal Dispatcher" daemon prio=10 tid=0x2f788000 nid=0x1c6c >> waiting on >> condition [0x00000000] >> java.lang.Thread.State: RUNNABLE >> >> "Finalizer" daemon prio=10 tid=0x2f778800 nid=0x1c6b in >> Object.wait() >> [0x2f517000] >> java.lang.Thread.State: WAITING (on object monitor) >> at java.lang.Object.wait(Native Method) >> - waiting on <0x341b10f0> (a >> java.lang.ref.ReferenceQueue$Lock) >> at >> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118) >> - locked <0x341b10f0> (a java.lang.ref.ReferenceQueue$Lock) >> at >> java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134) >> at >> java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159) >> >> "Reference Handler" daemon prio=10 tid=0x2f777000 nid=0x1c6a in >> Object.wait() [0x2f568000] >> java.lang.Thread.State: WAITING (on object monitor) >> at java.lang.Object.wait(Native Method) >> - waiting on <0x341b1110> (a java.lang.ref.Reference$Lock) >> at java.lang.Object.wait(Object.java:485) >> at >> java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116) >> - locked <0x341b1110> (a java.lang.ref.Reference$Lock) >> >> "VM Thread" prio=10 tid=0x2f773000 nid=0x1c69 runnable >> >> "GC task thread#0 (ParallelGC)" prio=10 tid=0x08891800 >> nid=0x1c67 runnable >> >> "GC task thread#1 (ParallelGC)" prio=10 tid=0x08893000 >> nid=0x1c68 runnable >> >> "VM Periodic Task Thread" prio=10 tid=0x2f78f800 nid=0x1c70 >> waiting on >> condition >> >> JNI global references: 1196 >> >> Heap >> PSYoungGen total 105984K, used 11722K [0xa5e10000, >> 0xacb90000, >> 0xb4190000) >> eden space 103232K, 8% used [0xa5e10000,0xa66d9fc8,0xac2e0000) >> from space 2752K, 98% used [0xac8e0000,0xacb889e8,0xacb90000) >> to space 4096K, 0% used [0xac390000,0xac390000,0xac790000) >> PSOldGen total 23552K, used 18525K [0x34190000, >> 0x35890000, >> 0xa5e10000) >> object space 23552K, 78% used [0x34190000,0x353a7510,0x35890000) >> PSPermGen total 16384K, used 8087K [0x30190000, 0x31190000, >> 0x34190000) >> object space 16384K, 49% used [0x30190000,0x30975f70,0x31190000) >> >> >> >> >> -- Martin Gerner >> Faculty of Life Sciences >> Michael Smith Building >> University of Manchester >> Manchester, M13 9PT >> >> >> >> >> -- >> Amila Suriarachchi >> WSO2 Inc. >> blog: http://amilachinthaka.blogspot.com/ >> > > > -- > Martin Gerner > Faculty of Life Sciences > Michael Smith Building > University of Manchester > Manchester, M13 9PT > > -- Amila Suriarachchi WSO2 Inc. blog: http://amilachinthaka.blogspot.com/
