Hi. I'll set that and run the process again.
As an aside I just pulled Master and TDB won't compile because it's can't find MultiSet? Are there notes on getting the Jena GIT into Eclipse? I want to put a count on the BufferAllocatorMem to see what it's doing. I've put a break point on but gave up on F8 after counting to 500.... Dick. On 26 July 2016 at 11:05, Andy Seaborne <a...@apache.org> wrote: > On 26/07/16 10:51, Dick Murray wrote: > >> Hi. >> >> Where do you set "transactionJournalWriteBlockMode" please? >> > > We don't - its off by default. > > It's a symbol you can set in the global context. > TDB.transactionJournalWriteBlockMode > > It is the only place that triggers DirectByteBuffers in TDB which I see in > your jmap output. > > >> Would you expect to see a large number of [B heap entries in a 3.1 TDB? >> > > Probably not, particularly not retained ones. > > Looking at the average sizes: > > >>> 1: 132187 636210296 [B > Average size: 4812.9 > >>> 1: 1148534 1420727464 [B > Average size: 1237.0 > >>> 1: 1377821 2328657400 [B > Average size: 1690.101544395099218258394958 > >>> 1: 333123 2285460248 [B > Average size: 6860.7 > >>> 1: 333123 2285460248 [B > Average size: 6860.7 > >>> 1: 333123 2285460248 [B > Average size: 6860.7 > >>> 1: 934984 3083070024 [B > Average size: 3297.5 > >>> 1: 1067937 3321067472 [B > Average size: 3109.8 > >>> 1: 581039 3615795256 [B > Average size: 6223.0 > > Does "6860.7" suggest anything? > > It's not a unit in TDB that I recognize. Maybe the data has that in some > way? > > Andy > > >> Dick. >> >> On 26 July 2016 at 10:39, Andy Seaborne <a...@apache.org> wrote: >> >> Dick, >>> >>> The report is embedded in your application setup with a lot of >>> "org.iungo.dataset.bulkload" >>> >>> Just because the OOME occurs in TDB does not mean that the space is >>> consumed in TDB - there may be a bigger memory hog elsewhere. >>> >>> Could you produce an RDF example? >>> >>> Maybe that file, already converted to RDF, and loaded with tdbloader? >>> >>> If TDB is using DiretcByteBuffersm have you set >>> "transactionJournalWriteBlockMode" to "direct"? >>> >>> You need to increase the direct memory space, not the heap. >>> >>> Andy >>> >>> >>> On 26/07/16 10:14, Dick Murray wrote: >>> >>> Hi. >>>> >>>> I've got a repeatable problem with Jena 3.1 when performing a bulk load. >>>> >>>> The bulk load converts a file into ~200k quads and adds them to a TDB >>>> instance within a normal begin write, add quads and commit. Initially >>>> this >>>> completes in 30-40 seconds, However if I repeat the process (with the >>>> same >>>> file) on the 5th iteration I get a OOME exception. As I'm importing the >>>> same file into different graphs I would expect the DAT file to stay the >>>> same size after the first process and just the index files to grow. >>>> >>>> There are no other process running against the TDB whilst this process >>>> is >>>> run. >>>> >>>> Using jmap the [B grows with each process until finally I get the >>>> exception. >>>> >>>> If I increase the Xmx the OOME occurs later. >>>> >>>> Any ideas? >>>> >>>> I've included details below, including jmap output which shows the heap >>>> being used and the JVM output which shows the GC (Allocation Failure) >>>> entries transiting to Full GC (Economics) entries... >>>> >>>> Regards Dick. >>>> >>>> JVM args -Xms2g -Xmx4g -XX:+PrintGCDetails >>>> >>>> -javaagent:/home/dick/eclipse-jee-neon/opt/classmexer-0_03/classmexer.jar >>>> >>>> dick@Dick-M3800:~$ uname -a >>>> Linux Dick-M3800 4.4.0-31-generic #50-Ubuntu SMP Wed Jul 13 00:07:12 UTC >>>> 2016 x86_64 x86_64 x86_64 GNU/Linux >>>> dick@Dick-M3800:~$ java -version >>>> openjdk version "1.8.0_91" >>>> OpenJDK Runtime Environment (build >>>> 1.8.0_91-8u91-b14-0ubuntu4~16.04.1-b14) >>>> OpenJDK 64-Bit Server VM (build 25.91-b14, mixed mode) >>>> dick@Dick-M3800:~$ >>>> >>>> >>>> Output from jmap >>>> >>>> dick@Dick-M3800:~$ jmap -histo 15031 | head -25 >>>> >>>> num #instances #bytes class name >>>> ---------------------------------------------- >>>> 1: 132187 636210296 [B >>>> 2: 500242 31189608 [C >>>> 3: 533380 25602240 >>>> org.apache.jena.ext.com >>>> .google.common.cache.LocalCache$StrongAccessEntry >>>> 4: 468220 18728800 org.kabeja.math.Point3D >>>> 5: 349351 16768848 org.kabeja.entities.Vertex >>>> 6: 1654 16374552 [I >>>> 7: 445589 16219672 [Ljava.lang.Object; >>>> dick@Dick-M3800:~$ jmap -histo 15031 | head -25 >>>> >>>> num #instances #bytes class name >>>> ---------------------------------------------- >>>> 1: 1148534 1420727464 [B >>>> 2: 5961841 344220520 [C >>>> 3: 1335412 85466368 java.nio.DirectByteBuffer >>>> 4: 3453219 82877256 java.lang.String >>>> 5: 573585 65399360 [I >>>> 6: 1261244 60539712 >>>> org.apache.jena.ext.com >>>> .google.common.cache.LocalCache$StrongAccessEntry >>>> 7: 945955 36365560 [Ljava.lang.Object; >>>> dick@Dick-M3800:~$ jmap -histo 15031 | head -25 >>>> >>>> num #instances #bytes class name >>>> ---------------------------------------------- >>>> 1: 1377821 2328657400 [B >>>> 2: 7566951 434495472 [C >>>> 3: 1717606 109926784 java.nio.DirectByteBuffer >>>> 4: 4339997 104159928 java.lang.String >>>> 5: 749581 75578568 [I >>>> 6: 1485127 71286096 >>>> org.apache.jena.ext.com >>>> .google.common.cache.LocalCache$StrongAccessEntry >>>> 7: 1089303 42230696 [Ljava.lang.Object; >>>> dick@Dick-M3800:~$ jmap -histo 15031 | head -25 >>>> >>>> num #instances #bytes class name >>>> ---------------------------------------------- >>>> 1: 333123 2285460248 [B >>>> 2: 604102 38062832 [C >>>> 3: 660301 31694448 >>>> org.apache.jena.ext.com >>>> .google.common.cache.LocalCache$StrongAccessEntry >>>> 4: 468220 18728800 org.kabeja.math.Point3D >>>> 5: 349351 16768848 org.kabeja.entities.Vertex >>>> 6: 445689 16486104 [Ljava.lang.Object; >>>> 7: 590752 14178048 java.lang.String >>>> 8: 278273 13357104 java.nio.HeapByteBuffer >>>> 9: 530557 12733368 org.apache.jena.tdb.store.NodeId >>>> 10: 420 11221544 [Ljava.util.HashMap$Node; >>>> 11: 334514 10704448 java.util.HashMap$Node >>>> 12: 660301 10564816 >>>> org.apache.jena.ext.com >>>> .google.common.cache.LocalCache$StrongValueReference >>>> 13: 420443 10090632 org.kabeja.tools.LazyContainer >>>> 14: 278249 8903968 org.apache.jena.tdb.base.block.Block >>>> 15: 201719 8068760 >>>> org.apache.jena.graph.impl.LiteralLabelImpl >>>> 16: 227185 5452440 java.lang.Long >>>> 17: 257247 4115952 org.apache.jena.graph.BlankNodeId >>>> 18: 257247 4115952 org.apache.jena.graph.Node_Blank >>>> 19: 1694 3770384 [I >>>> 20: 201719 3227504 org.apache.jena.graph.Node_Literal >>>> 21: 17199 2476656 org.kabeja.entities.Attrib >>>> 22: 91570 2197680 java.lang.Double >>>> dick@Dick-M3800:~$ jmap -histo 15031 | head -10 >>>> >>>> num #instances #bytes class name >>>> ---------------------------------------------- >>>> 1: 333123 2285460248 [B >>>> 2: 604102 38062832 [C >>>> 3: 660301 31694448 >>>> org.apache.jena.ext.com >>>> .google.common.cache.LocalCache$StrongAccessEntry >>>> 4: 468220 18728800 org.kabeja.math.Point3D >>>> 5: 349351 16768848 org.kabeja.entities.Vertex >>>> 6: 445689 16486104 [Ljava.lang.Object; >>>> 7: 590752 14178048 java.lang.String >>>> dick@Dick-M3800:~$ jmap -histo 15031 | head -13 >>>> >>>> num #instances #bytes class name >>>> ---------------------------------------------- >>>> 1: 333123 2285460248 [B >>>> 2: 604102 38062832 [C >>>> 3: 660301 31694448 >>>> org.apache.jena.ext.com >>>> .google.common.cache.LocalCache$StrongAccessEntry >>>> 4: 468220 18728800 org.kabeja.math.Point3D >>>> 5: 349351 16768848 org.kabeja.entities.Vertex >>>> 6: 445689 16486104 [Ljava.lang.Object; >>>> 7: 590752 14178048 java.lang.String >>>> 8: 278273 13357104 java.nio.HeapByteBuffer >>>> 9: 530557 12733368 org.apache.jena.tdb.store.NodeId >>>> 10: 420 11221544 [Ljava.util.HashMap$Node; >>>> dick@Dick-M3800:~$ jmap -histo 15031 | head -13 >>>> >>>> num #instances #bytes class name >>>> ---------------------------------------------- >>>> 1: 934984 3083070024 [B >>>> 2: 798242 51297104 [C >>>> 3: 842007 40416336 java.nio.HeapByteBuffer >>>> 4: 697063 33459024 >>>> org.apache.jena.ext.com >>>> .google.common.cache.LocalCache$StrongAccessEntry >>>> 5: 581662 23266480 org.kabeja.math.Point3D >>>> 6: 630910 20189120 java.util.HashMap$Node >>>> 7: 349351 16768848 org.kabeja.entities.Vertex >>>> 8: 445723 16618536 [Ljava.lang.Object; >>>> 9: 664750 15954000 org.apache.jena.tdb.store.NodeId >>>> 10: 639327 15343848 java.lang.String >>>> dick@Dick-M3800:~$ jmap -histo 15031 | head -13 >>>> >>>> num #instances #bytes class name >>>> ---------------------------------------------- >>>> 1: 1067937 3321067472 [B >>>> 2: 1935834 114366720 [C >>>> 3: 734818 35271264 >>>> org.apache.jena.ext.com >>>> .google.common.cache.LocalCache$StrongAccessEntry >>>> 4: 1262875 30309000 java.lang.String >>>> 5: 759345 24299040 java.util.HashMap$Node >>>> 6: 570771 21620680 [Ljava.lang.Object; >>>> 7: 333915 21370560 java.nio.DirectByteBuffer >>>> 8: 443744 21299712 java.nio.HeapByteBuffer >>>> 9: 468220 18728800 org.kabeja.math.Point3D >>>> 10: 548013 17536416 org.apache.jena.tdb.base.block.Block >>>> dick@Dick-M3800:~$ jmap -histo 15031 | head -13 >>>> >>>> num #instances #bytes class name >>>> ---------------------------------------------- >>>> 1: 581039 3615795256 [B >>>> 2: 624485 39191288 [C >>>> 3: 700593 33628464 >>>> org.apache.jena.ext.com >>>> .google.common.cache.LocalCache$StrongAccessEntry >>>> 4: 440069 21123312 java.nio.HeapByteBuffer >>>> 5: 607056 19425792 java.util.HashMap$Node >>>> 6: 445421 17816840 org.kabeja.math.Point3D >>>> 7: 422565 16272432 [Ljava.lang.Object; >>>> 8: 326910 15691680 org.kabeja.entities.Vertex >>>> 9: 433 15577272 [Ljava.util.HashMap$Node; >>>> 10: 611550 14677200 java.lang.String >>>> dick@Dick-M3800:~$ >>>> >>>> >>>> Output from JVM. >>>> >>>> >>>> dataset node "TDB" bulkload source type "image/vnd.dxf" url >>>> >>>> >>>> "file:///home/dick/eclipse-jee-neon/git/iungo-ssl/iungo-ssl/test/resources/0005_XXXX-SSL-XXX-XX-DR-U-0200.dxf" >>>> METHOD 2016-07-26T08:26:36.824Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#2 >>>> org.iungo.result.Result bulkload(org.iungo.context.Context) >>>> DEBUG 2016-07-26T08:26:36.833Z RootLogger Thread-5 process ([ID >>>> [bdb348e4-0f33-481c-8af9-dee18583d917] Result [null]]) >>>> true >>>> Added bulkload >>>> org.iungo.queue.EntryDEBUG 2016-07-26T08:26:36.833Z RootLogger Thread-5 >>>> >>>> >>>> org.iungo.lang.ClassUtils.create(org.iungo.dataset.bulkload.DXFDatasetBulkload, >>>> [Ljava.lang.Class;@17790d45, [Ljava.lang.Object;@19bef1da) >>>> INFO 2016-07-26T08:26:36.838Z RootLogger >>>> org.iungo.logger.AbstractLogger#4 >>>> Started [Logger [org.iungo.logger.SystemLogger] Name >>>> [org.iungo.dataset.bulkload.DXFDatasetBulkload#1] Level [ALL] Counts >>>> [3/0/0]] >>>> INFO 2016-07-26T08:26:36.838Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 Set level to [ALL] >>>> METHOD 2016-07-26T08:26:36.838Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 >>>> org.iungo.result.Result bulkload(org.iungo.context.Context) >>>> TRY_BLOCK 2016-07-26T08:26:36.838Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Try [null] >>>> TRY_BLOCK 2016-07-26T08:26:36.838Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Try [URL >>>> input >>>> stream] >>>> RETURN 2016-07-26T08:26:36.833Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#2 Return Timer >>>> [Started [2016:07:26 09:26:36] Stopped [2016:07:26 09:26:36] Elapsed >>>> [9ms]] >>>> Value [org.iungo.result.Result] >>>> VARIABLE 2016-07-26T08:26:36.846Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#2 Return Value >>>> [true >>>> [Added bulkload] [org.iungo.queue.Entry]] >>>> CALL_TRY 2016-07-26T08:26:36.878Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 >>>> [2016-07-26T08:26:36.878Z] [DXF Parser parse] >>>> [GC (Allocation Failure) [PSYoungGen: 524800K->31301K(611840K)] >>>> 524800K->31381K(2010112K), 0.0424604 secs] [Times: user=0.20 sys=0.06, >>>> real=0.04 secs] >>>> WARN 2016-07-26T08:26:37.652Z RootLogger Finalizer Return value not >>>> called >>>> [Logger [Logger [org.iungo.logger.SystemLogger] Name >>>> [org.iungo.dataset.tdb.node.TDBDatasetNode#TDB] Level [INFO] Counts >>>> [3/3/0]] Name [bulkload#2] Timer [Started [2016:07:26 09:26:36] Stopped >>>> [2016:07:26 09:26:36] Elapsed [9ms]]] >>>> CALL_FINALLY 2016-07-26T08:26:37.814Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Call >>>> [2016-07-26T08:26:37.814Z] [DXF Parser parse] >>>> CALL_TRY 2016-07-26T08:26:37.815Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 >>>> [2016-07-26T08:26:37.815Z] [sizeOf(Object)#Object] >>>> CALL_FINALLY 2016-07-26T08:26:37.816Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Call >>>> [2016-07-26T08:26:37.816Z] [sizeOf(Object)#Object] >>>> CALL_TRY 2016-07-26T08:26:37.816Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 >>>> [2016-07-26T08:26:37.816Z] [sizeOf(Object)#References] >>>> CALL_FINALLY 2016-07-26T08:26:38.333Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Call >>>> [2016-07-26T08:26:38.333Z] [sizeOf(Object)#References] >>>> SIZE_OF 2016-07-26T08:26:38.334Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Variable >>>> [draftDocument] = [72/27301560] >>>> VARIABLE 2016-07-26T08:26:38.334Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Variable [g] >>>> = >>>> [urn:iungo:dxf/graph/af64364c-7424-4eba-ad7a-798c21821650] >>>> CALL_TRY 2016-07-26T08:26:38.335Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 >>>> [2016-07-26T08:26:38.335Z] [Dataset write] >>>> CALL_FINALLY 2016-07-26T08:26:38.347Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Call >>>> [2016-07-26T08:26:38.346Z] [Dataset write] >>>> TRY_BLOCK 2016-07-26T08:26:38.347Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Try [Visitor] >>>> DEBUG 2016-07-26T08:26:38.347Z RootLogger Thread-5 DXF [Layers [0] >>>> Blocks >>>> [0] Entities [0] LWPolyline [0] LW2DVertex [0] Bounds [0] Quads [0]] >>>> Process [Interval [10000] Timer [Started [2016:07:26 09:26:38] Running >>>> Elapsed [0ms]]] >>>> CALL_TRY 2016-07-26T08:26:38.352Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 >>>> [2016-07-26T08:26:38.352Z] [Visitor] >>>> [GC (Allocation Failure) [PSYoungGen: 556101K->33176K(611840K)] >>>> 556181K->33272K(2010112K), 0.0378728 secs] [Times: user=0.14 sys=0.08, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 557976K->87034K(611840K)] >>>> 558072K->107618K(2010112K), 0.1034050 secs] [Times: user=0.61 sys=0.09, >>>> real=0.11 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 611834K->87022K(1136640K)] >>>> 632418K->149718K(2534912K), 0.1022982 secs] [Times: user=0.30 sys=0.37, >>>> real=0.10 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1136622K->87008K(1136640K)] >>>> 1199318K->217256K(2534912K), 0.1187315 secs] [Times: user=0.33 sys=0.45, >>>> real=0.12 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1136608K->172800K(1145856K)] >>>> 1266856K->303057K(2544128K), 0.1087404 secs] [Times: user=0.35 sys=0.39, >>>> real=0.10 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1126144K->222176K(1175552K)] >>>> 1256401K->376515K(2573824K), 0.0622131 secs] [Times: user=0.30 sys=0.09, >>>> real=0.06 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1175520K->222176K(966656K)] >>>> 1329859K->433901K(2364928K), 0.0803317 secs] [Times: user=0.39 sys=0.09, >>>> real=0.08 secs] >>>> DEBUG 2016-07-26T08:26:48.351Z RootLogger Thread-7 DXF [Layers [220] >>>> Blocks >>>> [264] Entities [48439] LWPolyline [1638] LW2DVertex [11886] Bounds >>>> [49608] >>>> Quads [810533]] Process [Interval [10000] Timer [Started [2016:07:26 >>>> 09:26:38] Running Elapsed [10005ms]]] >>>> [GC (Allocation Failure) [PSYoungGen: 966624K->186400K(1071104K)] >>>> 1178349K->472365K(2469376K), 0.0867127 secs] [Times: user=0.38 sys=0.16, >>>> real=0.09 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 930848K->120192K(1042944K)] >>>> 1216813K->501872K(2441216K), 0.0767022 secs] [Times: user=0.29 sys=0.18, >>>> real=0.07 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 867200K->59072K(1058304K)] >>>> 1248880K->533021K(2456576K), 0.0869604 secs] [Times: user=0.28 sys=0.28, >>>> real=0.08 secs] >>>> CALL_FINALLY 2016-07-26T08:26:51.670Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Call >>>> [2016-07-26T08:26:51.670Z] [Visitor] >>>> CALL_TRY 2016-07-26T08:26:51.670Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 >>>> [2016-07-26T08:26:51.670Z] [Visitor] >>>> [GC (Allocation Failure) [PSYoungGen: 806080K->44608K(1080320K)] >>>> 1280029K->562512K(2478592K), 0.0509676 secs] [Times: user=0.18 sys=0.13, >>>> real=0.05 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 821824K->48352K(1084416K)] >>>> 1339728K->598834K(2482688K), 0.0407001 secs] [Times: user=0.15 sys=0.08, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 825568K->52384K(1077760K)] >>>> 1376050K->638066K(2476032K), 0.0370391 secs] [Times: user=0.16 sys=0.01, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 840352K->55584K(1083904K)] >>>> 1426034K->679568K(2482176K), 0.0393499 secs] [Times: user=0.17 sys=0.10, >>>> real=0.03 secs] >>>> DEBUG 2016-07-26T08:26:58.351Z RootLogger Thread-7 DXF [Layers [440] >>>> Blocks >>>> [703] Entities [117777] LWPolyline [3637] LW2DVertex [25661] Bounds >>>> [121118] Quads [1919732]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:26:38] Running Elapsed [20004ms]]] >>>> [GC (Allocation Failure) [PSYoungGen: 843552K->49568K(1088000K)] >>>> 1467536K->714395K(2486272K), 0.0399583 secs] [Times: user=0.15 sys=0.11, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 864160K->58560K(1093632K)] >>>> 1528987K->759621K(2491904K), 0.0383629 secs] [Times: user=0.19 sys=0.07, >>>> real=0.04 secs] >>>> CALL_FINALLY 2016-07-26T08:27:00.849Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Call >>>> [2016-07-26T08:27:00.849Z] [Visitor] >>>> CALL_TRY 2016-07-26T08:27:00.850Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 >>>> [2016-07-26T08:27:00.850Z] [Dataset commit] >>>> [GC (Allocation Failure) [PSYoungGen: 873152K->39066K(1109504K)] >>>> 1574213K->784272K(2507776K), 0.0351013 secs] [Times: user=0.17 sys=0.05, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 889498K->25856K(1111552K)] >>>> 1634704K->802171K(2509824K), 0.0375312 secs] [Times: user=0.22 sys=0.07, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 876288K->23232K(1127424K)] >>>> 1652603K->820595K(2525696K), 0.0366533 secs] [Times: user=0.24 sys=0.02, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 904896K->26464K(1129984K)] >>>> 1702259K->842555K(2528256K), 0.0367213 secs] [Times: user=0.25 sys=0.00, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 908128K->24992K(1138688K)] >>>> 1724219K->862659K(2536960K), 0.0391041 secs] [Times: user=0.26 sys=0.00, >>>> real=0.04 secs] >>>> DEBUG 2016-07-26T08:27:08.351Z RootLogger Thread-7 DXF [Layers [440] >>>> Blocks >>>> [878] Entities [137566] LWPolyline [3998] LW2DVertex [27550] Bounds >>>> [141908] Quads [2203968]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:26:38] Running Elapsed [30004ms]]] >>>> CALL_FINALLY 2016-07-26T08:27:09.393Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Call >>>> [2016-07-26T08:27:09.393Z] [Dataset commit] >>>> DEBUG 2016-07-26T08:27:09.394Z RootLogger Thread-5 DXF [Layers [440] >>>> Blocks >>>> [878] Entities [137566] LWPolyline [3998] LW2DVertex [27550] Bounds >>>> [141908] Quads [2203968]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:26:38] Stopped [2016:07:26 09:27:09] Elapsed [31047ms]]] >>>> CALL_TRY 2016-07-26T08:27:09.395Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 >>>> [2016-07-26T08:27:09.395Z] [Dataset end] >>>> DEBUG 2016-07-26T08:27:09.395Z RootLogger Thread-5 take() >>>> CALL_FINALLY 2016-07-26T08:27:09.395Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Call >>>> [2016-07-26T08:27:09.395Z] [Dataset end] >>>> FINALLY_BLOCK 2016-07-26T08:27:09.395Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Finally >>>> RETURN 2016-07-26T08:27:09.395Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Return Timer >>>> [Started [2016:07:26 09:26:36] Stopped [2016:07:26 09:27:09] Elapsed >>>> [32558ms]] Value [org.iungo.result.Result] >>>> VARIABLE 2016-07-26T08:27:09.396Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#1 bulkload#3 Return Value >>>> [true [DXF [Layers [440] Blocks [878] Entities [137566] LWPolyline >>>> [3998] >>>> LW2DVertex [27550] Bounds [141908] Quads [2203968]] Timer [Interval >>>> [10000] >>>> Timer [Started [2016:07:26 09:26:38] Stopped [2016:07:26 09:27:09] >>>> Elapsed >>>> [31047ms]]]] [java.lang.String]] >>>> iungo runtime >>>> true >>>> Processors [8] Memory MB [Total [2477(68%)] Free [1177(48%)] Max [3641]] >>>> (No value returned)iungo gc >>>> [GC (System.gc()) [PSYoungGen: 493704K->20032K(929792K)] >>>> 1331371K->879995K(2328064K), 0.0567158 secs] [Times: user=0.30 sys=0.06, >>>> real=0.05 secs] >>>> [Full GC (System.gc()) [PSYoungGen: 20032K->0K(929792K)] [ParOldGen: >>>> 859963K->814267K(1398272K)] 879995K->814267K(2328064K), [Metaspace: >>>> 18575K->18575K(1067008K)], 0.7482168 secs] [Times: user=4.75 sys=0.07, >>>> real=0.75 secs] >>>> true >>>> Before [Processors [8] Memory MB [Total [2477(68%)] Free [1177(48%)] Max >>>> [3641]]] >>>> After [Processors [8] Memory MB [Total [2273(62%)] Free [1471(65%)] Max >>>> [3641]]] >>>> (No value returned)WARN 2016-07-26T08:28:25.234Z RootLogger Finalizer >>>> Return value not called [Logger [Logger [org.iungo.logger.SystemLogger] >>>> Name [org.iungo.dataset.bulkload.DXFDatasetBulkload#1] Level [ALL] >>>> Counts >>>> [26/26/0]] Name [bulkload#3] Timer [Started [2016:07:26 09:26:36] >>>> Stopped >>>> [2016:07:26 09:27:09] Elapsed [32558ms]]] >>>> dataset node "TDB" bulkload source type "image/vnd.dxf" url >>>> >>>> >>>> "file:///home/dick/eclipse-jee-neon/git/iungo-ssl/iungo-ssl/test/resources/0005_XXXX-SSL-XXX-XX-DR-U-0200.dxf" >>>> METHOD 2016-07-26T08:29:57.849Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#4 >>>> org.iungo.result.Result bulkload(org.iungo.context.Context) >>>> DEBUG 2016-07-26T08:29:57.849Z RootLogger Thread-5 process ([ID >>>> [a48c964d-d365-42f7-9435-e61b21869de2] Result [null]]) >>>> true >>>> Added bulkload >>>> org.iungo.queue.EntryDEBUG 2016-07-26T08:29:57.849Z RootLogger Thread-5 >>>> >>>> >>>> org.iungo.lang.ClassUtils.create(org.iungo.dataset.bulkload.DXFDatasetBulkload, >>>> [Ljava.lang.Class;@122fe874, [Ljava.lang.Object;@299ed608) >>>> RETURN 2016-07-26T08:29:57.849Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#4 Return Timer >>>> [Started [2016:07:26 09:29:57] Stopped [2016:07:26 09:29:57] Elapsed >>>> [1ms]] >>>> Value [org.iungo.result.Result] >>>> VARIABLE 2016-07-26T08:29:57.849Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#4 Return Value >>>> [true >>>> [Added bulkload] [org.iungo.queue.Entry]] >>>> INFO 2016-07-26T08:29:57.850Z RootLogger >>>> org.iungo.logger.AbstractLogger#5 >>>> Started [Logger [org.iungo.logger.SystemLogger] Name >>>> [org.iungo.dataset.bulkload.DXFDatasetBulkload#2] Level [ALL] Counts >>>> [1/0/0]] >>>> INFO 2016-07-26T08:29:57.850Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 Set level to [ALL] >>>> METHOD 2016-07-26T08:29:57.850Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 >>>> org.iungo.result.Result bulkload(org.iungo.context.Context) >>>> TRY_BLOCK 2016-07-26T08:29:57.850Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Try [null] >>>> TRY_BLOCK 2016-07-26T08:29:57.850Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Try [URL >>>> input >>>> stream] >>>> CALL_TRY 2016-07-26T08:29:57.850Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 >>>> [2016-07-26T08:29:57.850Z] [DXF Parser parse] >>>> CALL_FINALLY 2016-07-26T08:29:58.434Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Call >>>> [2016-07-26T08:29:58.433Z] [DXF Parser parse] >>>> CALL_TRY 2016-07-26T08:29:58.434Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 >>>> [2016-07-26T08:29:58.433Z] [sizeOf(Object)#Object] >>>> CALL_FINALLY 2016-07-26T08:29:58.434Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Call >>>> [2016-07-26T08:29:58.433Z] [sizeOf(Object)#Object] >>>> CALL_TRY 2016-07-26T08:29:58.434Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 >>>> [2016-07-26T08:29:58.433Z] [sizeOf(Object)#References] >>>> CALL_FINALLY 2016-07-26T08:29:58.868Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Call >>>> [2016-07-26T08:29:58.868Z] [sizeOf(Object)#References] >>>> SIZE_OF 2016-07-26T08:29:58.868Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Variable >>>> [draftDocument] = [72/27336336] >>>> VARIABLE 2016-07-26T08:29:58.868Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Variable [g] >>>> = >>>> [urn:iungo:dxf/graph/f57eadb0-680f-4bd9-9e53-9e0c89b3a392] >>>> CALL_TRY 2016-07-26T08:29:58.868Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 >>>> [2016-07-26T08:29:58.868Z] [Dataset write] >>>> CALL_FINALLY 2016-07-26T08:29:58.870Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Call >>>> [2016-07-26T08:29:58.870Z] [Dataset write] >>>> TRY_BLOCK 2016-07-26T08:29:58.870Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Try [Visitor] >>>> DEBUG 2016-07-26T08:29:58.870Z RootLogger Thread-5 DXF [Layers [0] >>>> Blocks >>>> [0] Entities [0] LWPolyline [0] LW2DVertex [0] Bounds [0] Quads [0]] >>>> Process [Interval [10000] Timer [Started [2016:07:26 09:29:58] Running >>>> Elapsed [0ms]]] >>>> CALL_TRY 2016-07-26T08:29:58.870Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 >>>> [2016-07-26T08:29:58.870Z] [Visitor] >>>> [GC (Allocation Failure) [PSYoungGen: 909312K->30273K(1143296K)] >>>> 1723579K->844540K(2541568K), 0.0180773 secs] [Times: user=0.10 sys=0.00, >>>> real=0.01 secs] >>>> WARN 2016-07-26T08:29:58.966Z RootLogger Finalizer Return value not >>>> called >>>> [Logger [Logger [org.iungo.logger.SystemLogger] Name >>>> [org.iungo.dataset.tdb.node.TDBDatasetNode#TDB] Level [INFO] Counts >>>> [6/6/0]] Name [bulkload#4] Timer [Started [2016:07:26 09:29:57] Stopped >>>> [2016:07:26 09:29:57] Elapsed [1ms]]] >>>> [GC (Allocation Failure) [PSYoungGen: 949825K->114208K(1133056K)] >>>> 1764092K->957885K(2531328K), 0.0413847 secs] [Times: user=0.27 sys=0.00, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1033760K->75344K(1166336K)] >>>> 1877437K->1015335K(2564608K), 0.0730055 secs] [Times: user=0.31 >>>> sys=0.17, >>>> real=0.07 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1041488K->77392K(1172480K)] >>>> 1981479K->1073770K(2570752K), 0.0377806 secs] [Times: user=0.16 >>>> sys=0.06, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1043536K->85568K(1182720K)] >>>> 2039914K->1140048K(2580992K), 0.0504137 secs] [Times: user=0.22 >>>> sys=0.13, >>>> real=0.05 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1080384K->88928K(1185280K)] >>>> 2134864K->1208335K(2583552K), 0.0468659 secs] [Times: user=0.23 >>>> sys=0.11, >>>> real=0.05 secs] >>>> DEBUG 2016-07-26T08:30:08.871Z RootLogger Thread-9 DXF [Layers [220] >>>> Blocks >>>> [255] Entities [38309] LWPolyline [1630] LW2DVertex [11854] Bounds >>>> [39447] >>>> Quads [668039]] Process [Interval [10000] Timer [Started [2016:07:26 >>>> 09:29:58] Running Elapsed [10001ms]]] >>>> [GC (Allocation Failure) [PSYoungGen: 1083744K->84224K(1196544K)] >>>> 2203151K->1270900K(2594816K), 0.0492592 secs] [Times: user=0.21 >>>> sys=0.13, >>>> real=0.05 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1106176K->88992K(1200640K)] >>>> 2292852K->1339473K(2598912K), 0.0542794 secs] [Times: user=0.21 >>>> sys=0.20, >>>> real=0.05 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1110944K->83808K(1207296K)] >>>> 2361425K->1402124K(2605568K), 0.0499539 secs] [Times: user=0.22 >>>> sys=0.11, >>>> real=0.05 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 83808K->0K(1207296K)] [ParOldGen: >>>> 1318316K->1282727K(1988096K)] 1402124K->1282727K(3195392K), [Metaspace: >>>> 18575K->18575K(1067008K)], 0.5090303 secs] [Times: user=3.44 sys=0.01, >>>> real=0.51 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1044992K->90336K(1212928K)] >>>> 2327719K->1373063K(3201024K), 0.0245114 secs] [Times: user=0.17 >>>> sys=0.00, >>>> real=0.03 secs] >>>> CALL_FINALLY 2016-07-26T08:30:15.726Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Call >>>> [2016-07-26T08:30:15.726Z] [Visitor] >>>> CALL_TRY 2016-07-26T08:30:15.727Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 >>>> [2016-07-26T08:30:15.726Z] [Visitor] >>>> [GC (Allocation Failure) [PSYoungGen: 1135328K->53984K(1217536K)] >>>> 2418055K->1405913K(3205632K), 0.0471537 secs] [Times: user=0.24 >>>> sys=0.07, >>>> real=0.05 secs] >>>> DEBUG 2016-07-26T08:30:18.870Z RootLogger Thread-9 DXF [Layers [424] >>>> Blocks >>>> [439] Entities [86599] LWPolyline [2112] LW2DVertex [14845] Bounds >>>> [88974] >>>> Quads [1421451]] Process [Interval [10000] Timer [Started [2016:07:26 >>>> 09:29:58] Running Elapsed [20001ms]]] >>>> [GC (Allocation Failure) [PSYoungGen: 1119456K->50912K(1224704K)] >>>> 2471385K->1443866K(3212800K), 0.0396251 secs] [Times: user=0.20 >>>> sys=0.08, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1116384K->59328K(1224704K)] >>>> 2509338K->1490447K(3212800K), 0.0453817 secs] [Times: user=0.26 >>>> sys=0.07, >>>> real=0.05 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1143232K->65248K(1232896K)] >>>> 2574351K->1541287K(3220992K), 0.0435746 secs] [Times: user=0.24 >>>> sys=0.05, >>>> real=0.05 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1149152K->57792K(1237504K)] >>>> 2625191K->1583621K(3225600K), 0.0448676 secs] [Times: user=0.22 >>>> sys=0.13, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1164736K->62912K(1243648K)] >>>> 2690565K->1632705K(3231744K), 0.0442824 secs] [Times: user=0.27 >>>> sys=0.03, >>>> real=0.05 secs] >>>> CALL_FINALLY 2016-07-26T08:30:27.809Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Call >>>> [2016-07-26T08:30:27.809Z] [Visitor] >>>> CALL_TRY 2016-07-26T08:30:27.809Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 >>>> [2016-07-26T08:30:27.809Z] [Dataset commit] >>>> DEBUG 2016-07-26T08:30:28.870Z RootLogger Thread-9 DXF [Layers [440] >>>> Blocks >>>> [878] Entities [137566] LWPolyline [3998] LW2DVertex [27550] Bounds >>>> [141908] Quads [2203968]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:29:58] Running Elapsed [30001ms]]] >>>> [GC (Allocation Failure) [PSYoungGen: 1169856K->46720K(1255424K)] >>>> 2739649K->1663932K(3243520K), 0.0501241 secs] [Times: user=0.30 >>>> sys=0.06, >>>> real=0.05 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1176704K->32064K(1258496K)] >>>> 2793916K->1685111K(3246592K), 0.0601839 secs] [Times: user=0.38 >>>> sys=0.08, >>>> real=0.06 secs] >>>> CALL_FINALLY 2016-07-26T08:30:33.971Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Call >>>> [2016-07-26T08:30:33.971Z] [Dataset commit] >>>> DEBUG 2016-07-26T08:30:33.972Z RootLogger Thread-5 DXF [Layers [440] >>>> Blocks >>>> [878] Entities [137566] LWPolyline [3998] LW2DVertex [27550] Bounds >>>> [141908] Quads [2203968]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:29:58] Stopped [2016:07:26 09:30:33] Elapsed [35102ms]]] >>>> CALL_TRY 2016-07-26T08:30:33.972Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 >>>> [2016-07-26T08:30:33.972Z] [Dataset end] >>>> DEBUG 2016-07-26T08:30:33.972Z RootLogger Thread-5 take() >>>> CALL_FINALLY 2016-07-26T08:30:33.972Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Call >>>> [2016-07-26T08:30:33.972Z] [Dataset end] >>>> FINALLY_BLOCK 2016-07-26T08:30:33.972Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Finally >>>> RETURN 2016-07-26T08:30:33.972Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Return Timer >>>> [Started [2016:07:26 09:29:57] Stopped [2016:07:26 09:30:33] Elapsed >>>> [36122ms]] Value [org.iungo.result.Result] >>>> VARIABLE 2016-07-26T08:30:33.973Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#2 bulkload#5 Return Value >>>> [true [DXF [Layers [440] Blocks [878] Entities [137566] LWPolyline >>>> [3998] >>>> LW2DVertex [27550] Bounds [141908] Quads [2203968]] Timer [Interval >>>> [10000] >>>> Timer [Started [2016:07:26 09:29:58] Stopped [2016:07:26 09:30:33] >>>> Elapsed >>>> [35102ms]]]] [java.lang.String]] >>>> iungo runtime >>>> true >>>> Processors [8] Memory MB [Total [3170(87%)] Free [743(23%)] Max [3641]] >>>> (No value returned)iungo gc >>>> [GC (System.gc()) [PSYoungGen: 831864K->24096K(1269248K)] >>>> 2484911K->1703087K(3257344K), 0.0730718 secs] [Times: user=0.49 >>>> sys=0.01, >>>> real=0.07 secs] >>>> [Full GC (System.gc()) [PSYoungGen: 24096K->0K(1269248K)] [ParOldGen: >>>> 1678991K->1580464K(1988096K)] 1703087K->1580464K(3257344K), [Metaspace: >>>> 18575K->18575K(1067008K)], 0.5331020 secs] [Times: user=3.27 sys=0.01, >>>> real=0.54 secs] >>>> true >>>> Before [Processors [8] Memory MB [Total [3170(87%)] Free [743(23%)] Max >>>> [3641]]] >>>> After [Processors [8] Memory MB [Total [3181(87%)] Free [1634(51%)] Max >>>> [3641]]] >>>> (No value returned)WARN 2016-07-26T08:31:06.089Z RootLogger Finalizer >>>> Return value not called [Logger [Logger [org.iungo.logger.SystemLogger] >>>> Name [org.iungo.dataset.bulkload.DXFDatasetBulkload#2] Level [ALL] >>>> Counts >>>> [26/26/0]] Name [bulkload#5] Timer [Started [2016:07:26 09:29:57] >>>> Stopped >>>> [2016:07:26 09:30:33] Elapsed [36122ms]]] >>>> dataset node "TDB" bulkload source type "image/vnd.dxf" url >>>> >>>> >>>> "file:///home/dick/eclipse-jee-neon/git/iungo-ssl/iungo-ssl/test/resources/0005_XXXX-SSL-XXX-XX-DR-U-0200.dxf" >>>> METHOD 2016-07-26T08:31:12.475Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#6 >>>> org.iungo.result.Result bulkload(org.iungo.context.Context) >>>> true >>>> Added bulkload >>>> org.iungo.queue.EntryDEBUG 2016-07-26T08:31:12.475Z RootLogger Thread-5 >>>> process ([ID [87d72201-6f16-45f8-b076-7448b50d35ba] Result [null]]) >>>> RETURN 2016-07-26T08:31:12.475Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#6 Return Timer >>>> [Started [2016:07:26 09:31:12] Stopped [2016:07:26 09:31:12] Elapsed >>>> [0ms]] >>>> Value [org.iungo.result.Result] >>>> VARIABLE 2016-07-26T08:31:12.476Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#6 Return Value >>>> [true >>>> [Added bulkload] [org.iungo.queue.Entry]] >>>> DEBUG 2016-07-26T08:31:12.476Z RootLogger Thread-5 >>>> >>>> >>>> org.iungo.lang.ClassUtils.create(org.iungo.dataset.bulkload.DXFDatasetBulkload, >>>> [Ljava.lang.Class;@71472638, [Ljava.lang.Object;@6dbb2118) >>>> INFO 2016-07-26T08:31:12.476Z RootLogger >>>> org.iungo.logger.AbstractLogger#6 >>>> Started [Logger [org.iungo.logger.SystemLogger] Name >>>> [org.iungo.dataset.bulkload.DXFDatasetBulkload#3] Level [ALL] Counts >>>> [1/0/0]] >>>> INFO 2016-07-26T08:31:12.477Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 Set level to [ALL] >>>> METHOD 2016-07-26T08:31:12.477Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 >>>> org.iungo.result.Result bulkload(org.iungo.context.Context) >>>> TRY_BLOCK 2016-07-26T08:31:12.477Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Try [null] >>>> TRY_BLOCK 2016-07-26T08:31:12.477Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Try [URL >>>> input >>>> stream] >>>> CALL_TRY 2016-07-26T08:31:12.477Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 >>>> [2016-07-26T08:31:12.477Z] [DXF Parser parse] >>>> CALL_FINALLY 2016-07-26T08:31:13.019Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Call >>>> [2016-07-26T08:31:13.019Z] [DXF Parser parse] >>>> CALL_TRY 2016-07-26T08:31:13.020Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 >>>> [2016-07-26T08:31:13.019Z] [sizeOf(Object)#Object] >>>> CALL_FINALLY 2016-07-26T08:31:13.020Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Call >>>> [2016-07-26T08:31:13.019Z] [sizeOf(Object)#Object] >>>> CALL_TRY 2016-07-26T08:31:13.020Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 >>>> [2016-07-26T08:31:13.019Z] [sizeOf(Object)#References] >>>> CALL_FINALLY 2016-07-26T08:31:13.459Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Call >>>> [2016-07-26T08:31:13.459Z] [sizeOf(Object)#References] >>>> SIZE_OF 2016-07-26T08:31:13.459Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Variable >>>> [draftDocument] = [72/27324264] >>>> VARIABLE 2016-07-26T08:31:13.459Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Variable [g] >>>> = >>>> [urn:iungo:dxf/graph/b5a430eb-65f0-458b-91f7-aae611d358e9] >>>> CALL_TRY 2016-07-26T08:31:13.459Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 >>>> [2016-07-26T08:31:13.459Z] [Dataset write] >>>> CALL_FINALLY 2016-07-26T08:31:13.461Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Call >>>> [2016-07-26T08:31:13.461Z] [Dataset write] >>>> DEBUG 2016-07-26T08:31:13.461Z RootLogger Thread-5 DXF [Layers [0] >>>> Blocks >>>> [0] Entities [0] LWPolyline [0] LW2DVertex [0] Bounds [0] Quads [0]] >>>> Process [Interval [10000] Timer [Started [2016:07:26 09:31:13] Running >>>> Elapsed [0ms]]] >>>> TRY_BLOCK 2016-07-26T08:31:13.461Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Try [Visitor] >>>> CALL_TRY 2016-07-26T08:31:13.463Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 >>>> [2016-07-26T08:31:13.463Z] [Visitor] >>>> [GC (Allocation Failure) [PSYoungGen: 1140736K->58401K(1199616K)] >>>> 2721200K->1638873K(3187712K), 0.0203087 secs] [Times: user=0.13 >>>> sys=0.00, >>>> real=0.02 secs] >>>> WARN 2016-07-26T08:31:13.926Z RootLogger Finalizer Return value not >>>> called >>>> [Logger [Logger [org.iungo.logger.SystemLogger] Name >>>> [org.iungo.dataset.tdb.node.TDBDatasetNode#TDB] Level [INFO] Counts >>>> [9/9/0]] Name [bulkload#6] Timer [Started [2016:07:26 09:31:12] Stopped >>>> [2016:07:26 09:31:12] Elapsed [0ms]]] >>>> [GC (Allocation Failure) [PSYoungGen: 1199137K->121328K(1185280K)] >>>> 2779609K->1779577K(3173376K), 0.0556827 secs] [Times: user=0.36 >>>> sys=0.05, >>>> real=0.06 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1185264K->105408K(1169408K)] >>>> 2843513K->1859014K(3157504K), 0.0643966 secs] [Times: user=0.27 >>>> sys=0.20, >>>> real=0.07 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1169344K->102592K(1227776K)] >>>> 2922950K->1935821K(3215872K), 0.0544275 secs] [Times: user=0.25 >>>> sys=0.13, >>>> real=0.06 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1160384K->113184K(1171456K)] >>>> 2993613K->2023999K(3159552K), 0.0517638 secs] [Times: user=0.19 >>>> sys=0.13, >>>> real=0.06 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 113184K->0K(1171456K)] [ParOldGen: >>>> 1910815K->1912144K(2796544K)] 2023999K->1912144K(3968000K), [Metaspace: >>>> 18577K->18577K(1067008K)], 0.4101127 secs] [Times: user=3.02 sys=0.00, >>>> real=0.40 secs] >>>> DEBUG 2016-07-26T08:31:23.461Z RootLogger Thread-11 DXF [Layers [220] >>>> Blocks [211] Entities [36397] LWPolyline [1435] LW2DVertex [10876] >>>> Bounds >>>> [37380] Quads [636022]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:31:13] Running Elapsed [10001ms]]] >>>> [GC (Allocation Failure) [PSYoungGen: 1057792K->97376K(1227264K)] >>>> 2969936K->2009520K(4023808K), 0.0267507 secs] [Times: user=0.16 >>>> sys=0.00, >>>> real=0.03 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1151072K->101312K(1155072K)] >>>> 3063216K->2087266K(3951616K), 0.0558575 secs] [Times: user=0.26 >>>> sys=0.13, >>>> real=0.05 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1155008K->96512K(1225728K)] >>>> 3140962K->2159487K(4022272K), 0.0580832 secs] [Times: user=0.30 >>>> sys=0.13, >>>> real=0.05 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1154304K->82336K(1221632K)] >>>> 3217279K->2219090K(4018176K), 0.0567664 secs] [Times: user=0.24 >>>> sys=0.12, >>>> real=0.06 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1140128K->95968K(1226752K)] >>>> 3276882K->2294688K(4023296K), 0.0685312 secs] [Times: user=0.31 >>>> sys=0.20, >>>> real=0.07 secs] >>>> CALL_FINALLY 2016-07-26T08:31:30.719Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Call >>>> [2016-07-26T08:31:30.719Z] [Visitor] >>>> CALL_TRY 2016-07-26T08:31:30.719Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 >>>> [2016-07-26T08:31:30.719Z] [Visitor] >>>> [GC (Allocation Failure) [PSYoungGen: 1165536K->54368K(1223168K)] >>>> 3364256K->2326061K(4019712K), 0.0587577 secs] [Times: user=0.25 >>>> sys=0.13, >>>> real=0.06 secs] >>>> DEBUG 2016-07-26T08:31:33.461Z RootLogger Thread-11 DXF [Layers [423] >>>> Blocks [439] Entities [83173] LWPolyline [2112] LW2DVertex [14845] >>>> Bounds >>>> [85547] Quads [1360158]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:31:13] Running Elapsed [20000ms]]] >>>> [GC (Allocation Failure) [PSYoungGen: 1123936K->42656K(1239552K)] >>>> 3395629K->2355614K(4036096K), 0.0509542 secs] [Times: user=0.21 >>>> sys=0.13, >>>> real=0.05 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1129632K->48320K(1239552K)] >>>> 3442590K->2392905K(4036096K), 0.0319827 secs] [Times: user=0.16 >>>> sys=0.06, >>>> real=0.03 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1135296K->58720K(1239040K)] >>>> 3479881K->2439459K(4035584K), 0.0351797 secs] [Times: user=0.19 >>>> sys=0.06, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1153376K->55392K(1241088K)] >>>> 3534115K->2480817K(4037632K), 0.0389223 secs] [Times: user=0.21 >>>> sys=0.06, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1150048K->52352K(1245696K)] >>>> 3575473K->2519604K(4042240K), 0.0403291 secs] [Times: user=0.18 >>>> sys=0.08, >>>> real=0.04 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1160832K->54112K(1247744K)] >>>> 3628084K->2560955K(4044288K), 0.0351433 secs] [Times: user=0.21 >>>> sys=0.04, >>>> real=0.04 secs] >>>> DEBUG 2016-07-26T08:31:43.461Z RootLogger Thread-11 DXF [Layers [440] >>>> Blocks [877] Entities [137515] LWPolyline [3996] LW2DVertex [27538] >>>> Bounds >>>> [141851] Quads [2201819]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:31:13] Running Elapsed [30000ms]]] >>>> CALL_FINALLY 2016-07-26T08:31:43.556Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Call >>>> [2016-07-26T08:31:43.556Z] [Visitor] >>>> CALL_TRY 2016-07-26T08:31:43.556Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 >>>> [2016-07-26T08:31:43.556Z] [Dataset commit] >>>> [GC (Allocation Failure) [PSYoungGen: 1162592K->46656K(1255424K)] >>>> 3669435K->2594228K(4051968K), 0.0512520 secs] [Times: user=0.34 >>>> sys=0.04, >>>> real=0.06 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1169984K->31680K(1255936K)] >>>> 3717556K->2614996K(4052480K), 0.0546956 secs] [Times: user=0.33 >>>> sys=0.10, >>>> real=0.05 secs] >>>> CALL_FINALLY 2016-07-26T08:31:49.964Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Call >>>> [2016-07-26T08:31:49.964Z] [Dataset commit] >>>> DEBUG 2016-07-26T08:31:49.964Z RootLogger Thread-5 DXF [Layers [440] >>>> Blocks >>>> [878] Entities [137566] LWPolyline [3998] LW2DVertex [27550] Bounds >>>> [141908] Quads [2203968]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:31:13] Stopped [2016:07:26 09:31:49] Elapsed [36503ms]]] >>>> CALL_TRY 2016-07-26T08:31:49.965Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 >>>> [2016-07-26T08:31:49.965Z] [Dataset end] >>>> DEBUG 2016-07-26T08:31:49.965Z RootLogger Thread-5 take() >>>> CALL_FINALLY 2016-07-26T08:31:49.965Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Call >>>> [2016-07-26T08:31:49.965Z] [Dataset end] >>>> FINALLY_BLOCK 2016-07-26T08:31:49.965Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Finally >>>> RETURN 2016-07-26T08:31:49.965Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Return Timer >>>> [Started [2016:07:26 09:31:12] Stopped [2016:07:26 09:31:49] Elapsed >>>> [37489ms]] Value [org.iungo.result.Result] >>>> VARIABLE 2016-07-26T08:31:49.965Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7 Return Value >>>> [true [DXF [Layers [440] Blocks [878] Entities [137566] LWPolyline >>>> [3998] >>>> LW2DVertex [27550] Bounds [141908] Quads [2203968]] Timer [Interval >>>> [10000] >>>> Timer [Started [2016:07:26 09:31:13] Stopped [2016:07:26 09:31:49] >>>> Elapsed >>>> [36503ms]]]] [java.lang.String]] >>>> iungo gc >>>> [GC (System.gc()) [PSYoungGen: 1048053K->29888K(1262080K)] >>>> 3631370K->2637612K(4058624K), 0.0699907 secs] [Times: user=0.49 >>>> sys=0.02, >>>> real=0.07 secs] >>>> [Full GC (System.gc()) [PSYoungGen: 29888K->0K(1262080K)] [ParOldGen: >>>> 2607724K->2481924K(2796544K)] 2637612K->2481924K(4058624K), [Metaspace: >>>> 18577K->18577K(1067008K)], 0.8021440 secs] [Times: user=5.16 sys=0.03, >>>> real=0.80 secs] >>>> true >>>> Before [Processors [8] Memory MB [Total [3957(100%)] Free [411(10%)] Max >>>> [3957]]] >>>> After [Processors [8] Memory MB [Total [3963(100%)] Free [1538(39%)] Max >>>> [3963]]] >>>> (No value returned)WARN 2016-07-26T08:32:06.132Z RootLogger Finalizer >>>> Return value not called [Logger [Logger [org.iungo.logger.SystemLogger] >>>> Name [org.iungo.dataset.bulkload.DXFDatasetBulkload#3] Level [ALL] >>>> Counts >>>> [26/26/0]] Name [bulkload#7] Timer [Started [2016:07:26 09:31:12] >>>> Stopped >>>> [2016:07:26 09:31:49] Elapsed [37489ms]]] >>>> dataset node "TDB" bulkload source type "image/vnd.dxf" url >>>> >>>> >>>> "file:///home/dick/eclipse-jee-neon/git/iungo-ssl/iungo-ssl/test/resources/0005_XXXX-SSL-XXX-XX-DR-U-0200.dxf" >>>> METHOD 2016-07-26T08:35:07.737Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#8 >>>> org.iungo.result.Result bulkload(org.iungo.context.Context) >>>> true >>>> Added bulkload >>>> org.iungo.queue.EntryDEBUG 2016-07-26T08:35:07.738Z RootLogger Thread-5 >>>> process ([ID [464ebfd9-3a8b-4f46-af17-07079ca933de] Result [null]]) >>>> DEBUG 2016-07-26T08:35:07.738Z RootLogger Thread-5 >>>> >>>> >>>> org.iungo.lang.ClassUtils.create(org.iungo.dataset.bulkload.DXFDatasetBulkload, >>>> [Ljava.lang.Class;@44346c67, [Ljava.lang.Object;@5052bc39) >>>> INFO 2016-07-26T08:35:07.738Z RootLogger >>>> org.iungo.logger.AbstractLogger#7 >>>> Started [Logger [org.iungo.logger.SystemLogger] Name >>>> [org.iungo.dataset.bulkload.DXFDatasetBulkload#4] Level [ALL] Counts >>>> [1/0/0]] >>>> RETURN 2016-07-26T08:35:07.738Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#8 Return Timer >>>> [Started [2016:07:26 09:35:07] Stopped [2016:07:26 09:35:07] Elapsed >>>> [1ms]] >>>> Value [org.iungo.result.Result] >>>> INFO 2016-07-26T08:35:07.738Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 Set level to [ALL] >>>> VARIABLE 2016-07-26T08:35:07.738Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#8 Return Value >>>> [true >>>> [Added bulkload] [org.iungo.queue.Entry]] >>>> METHOD 2016-07-26T08:35:07.738Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 >>>> org.iungo.result.Result bulkload(org.iungo.context.Context) >>>> TRY_BLOCK 2016-07-26T08:35:07.738Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Try [null] >>>> TRY_BLOCK 2016-07-26T08:35:07.739Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Try [URL >>>> input >>>> stream] >>>> CALL_TRY 2016-07-26T08:35:07.739Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 >>>> [2016-07-26T08:35:07.739Z] [DXF Parser parse] >>>> CALL_FINALLY 2016-07-26T08:35:08.241Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Call >>>> [2016-07-26T08:35:08.241Z] [DXF Parser parse] >>>> CALL_TRY 2016-07-26T08:35:08.241Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 >>>> [2016-07-26T08:35:08.241Z] [sizeOf(Object)#Object] >>>> CALL_FINALLY 2016-07-26T08:35:08.241Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Call >>>> [2016-07-26T08:35:08.241Z] [sizeOf(Object)#Object] >>>> CALL_TRY 2016-07-26T08:35:08.241Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 >>>> [2016-07-26T08:35:08.241Z] [sizeOf(Object)#References] >>>> CALL_FINALLY 2016-07-26T08:35:08.634Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Call >>>> [2016-07-26T08:35:08.634Z] [sizeOf(Object)#References] >>>> SIZE_OF 2016-07-26T08:35:08.635Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Variable >>>> [draftDocument] = [72/27314624] >>>> VARIABLE 2016-07-26T08:35:08.635Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Variable [g] >>>> = >>>> [urn:iungo:dxf/graph/cf994529-31b5-4c71-a312-99a6fecd276b] >>>> CALL_TRY 2016-07-26T08:35:08.635Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 >>>> [2016-07-26T08:35:08.635Z] [Dataset write] >>>> CALL_FINALLY 2016-07-26T08:35:08.636Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Call >>>> [2016-07-26T08:35:08.636Z] [Dataset write] >>>> TRY_BLOCK 2016-07-26T08:35:08.636Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Try [Visitor] >>>> DEBUG 2016-07-26T08:35:08.636Z RootLogger Thread-5 DXF [Layers [0] >>>> Blocks >>>> [0] Entities [0] LWPolyline [0] LW2DVertex [0] Bounds [0] Quads [0]] >>>> Process [Interval [10000] Timer [Started [2016:07:26 09:35:08] Running >>>> Elapsed [0ms]]] >>>> CALL_TRY 2016-07-26T08:35:08.636Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 >>>> [2016-07-26T08:35:08.636Z] [Visitor] >>>> [GC (Allocation Failure) [PSYoungGen: 1133056K->57105K(1190400K)] >>>> 3614980K->2539030K(3986944K), 0.0212950 secs] [Times: user=0.14 >>>> sys=0.00, >>>> real=0.02 secs] >>>> WARN 2016-07-26T08:35:09.037Z RootLogger Finalizer Return value not >>>> called >>>> [Logger [Logger [org.iungo.logger.SystemLogger] Name >>>> [org.iungo.dataset.tdb.node.TDBDatasetNode#TDB] Level [INFO] Counts >>>> [12/12/0]] Name [bulkload#8] Timer [Started [2016:07:26 09:35:07] >>>> Stopped >>>> [2016:07:26 09:35:07] Elapsed [1ms]]] >>>> [GC (Allocation Failure) [PSYoungGen: 1190161K->124384K(1185280K)] >>>> 3672086K->2677930K(3981824K), 0.0491260 secs] [Times: user=0.37 >>>> sys=0.00, >>>> real=0.05 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1185248K->102160K(1163264K)] >>>> 3738794K->2754409K(3959808K), 0.0536836 secs] [Times: user=0.24 >>>> sys=0.14, >>>> real=0.05 secs] >>>> [GC (Allocation Failure) [PSYoungGen: 1163024K->97920K(1229824K)] >>>> 3815273K->2827108K(4026368K), 0.0502531 secs] [Times: user=0.21 >>>> sys=0.14, >>>> real=0.05 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 97920K->0K(1229824K)] [ParOldGen: >>>> 2729188K->2724606K(2796544K)] 2827108K->2724606K(4026368K), [Metaspace: >>>> 18595K->18595K(1067008K)], 0.4307318 secs] [Times: user=3.20 sys=0.00, >>>> real=0.43 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->4136K(1229824K)] >>>> [ParOldGen: >>>> 2724606K->2796543K(2796544K)] 3784958K->2800679K(4026368K), [Metaspace: >>>> 18595K->18595K(1067008K)], 0.6340951 secs] [Times: user=4.81 sys=0.05, >>>> real=0.64 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->89403K(1229824K)] >>>> [ParOldGen: >>>> 2796543K->2796516K(2796544K)] 3856895K->2885919K(4026368K), [Metaspace: >>>> 18595K->18595K(1067008K)], 0.5056083 secs] [Times: user=3.74 sys=0.00, >>>> real=0.51 secs] >>>> DEBUG 2016-07-26T08:35:18.920Z RootLogger Thread-13 DXF [Layers [220] >>>> Blocks [208] Entities [31216] LWPolyline [880] LW2DVertex [6758] Bounds >>>> [32187] Quads [547324]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:35:08] Running Elapsed [10284ms]]] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->154367K(1229824K)] >>>> [ParOldGen: >>>> 2796516K->2796501K(2796544K)] 3856868K->2950869K(4026368K), [Metaspace: >>>> 18595K->18595K(1067008K)], 0.5614438 secs] [Times: user=4.15 sys=0.01, >>>> real=0.56 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->220038K(1229824K)] >>>> [ParOldGen: >>>> 2796501K->2796325K(2796544K)] 3856853K->3016363K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.5745505 secs] [Times: user=4.30 sys=0.01, >>>> real=0.57 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->284390K(1229824K)] >>>> [ParOldGen: >>>> 2796325K->2796126K(2796544K)] 3856677K->3080516K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.5558938 secs] [Times: user=4.08 sys=0.01, >>>> real=0.55 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->335022K(1229824K)] >>>> [ParOldGen: >>>> 2796126K->2796468K(2796544K)] 3856478K->3131491K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.6343564 secs] [Times: user=4.72 sys=0.01, >>>> real=0.63 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->382045K(1229824K)] >>>> [ParOldGen: >>>> 2796468K->2796084K(2796544K)] 3856820K->3178130K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.6525819 secs] [Times: user=4.90 sys=0.02, >>>> real=0.66 secs] >>>> DEBUG 2016-07-26T08:35:28.636Z RootLogger Thread-13 DXF [Layers [220] >>>> Blocks [405] Entities [59671] LWPolyline [1950] LW2DVertex [13564] >>>> Bounds >>>> [61728] Quads [979381]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:35:08] Running Elapsed [20001ms]]] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->432432K(1229824K)] >>>> [ParOldGen: >>>> 2796084K->2796509K(2796544K)] 3856436K->3228941K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.5903141 secs] [Times: user=4.29 sys=0.02, >>>> real=0.60 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->476206K(1229824K)] >>>> [ParOldGen: >>>> 2796509K->2796291K(2796544K)] 3856861K->3272497K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.6317856 secs] [Times: user=4.66 sys=0.00, >>>> real=0.63 secs] >>>> CALL_FINALLY 2016-07-26T08:35:32.206Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Call >>>> [2016-07-26T08:35:32.206Z] [Visitor] >>>> CALL_TRY 2016-07-26T08:35:32.206Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 >>>> [2016-07-26T08:35:32.206Z] [Visitor] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->495124K(1229824K)] >>>> [ParOldGen: >>>> 2796291K->2796342K(2796544K)] 3856643K->3291466K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.7499834 secs] [Times: user=5.43 sys=0.01, >>>> real=0.75 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->510081K(1229824K)] >>>> [ParOldGen: >>>> 2796342K->2796517K(2796544K)] 3856694K->3306599K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.4042336 secs] [Times: user=2.93 sys=0.02, >>>> real=0.40 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->525065K(1229824K)] >>>> [ParOldGen: >>>> 2796517K->2796423K(2796544K)] 3856869K->3321489K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.4187337 secs] [Times: user=3.05 sys=0.00, >>>> real=0.42 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->539657K(1229824K)] >>>> [ParOldGen: >>>> 2796423K->2796250K(2796544K)] 3856775K->3335907K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.4128904 secs] [Times: user=3.02 sys=0.00, >>>> real=0.41 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->555275K(1229824K)] >>>> [ParOldGen: >>>> 2796250K->2796047K(2796544K)] 3856602K->3351322K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.4273892 secs] [Times: user=3.08 sys=0.01, >>>> real=0.43 secs] >>>> DEBUG 2016-07-26T08:35:38.786Z RootLogger Thread-13 DXF [Layers [440] >>>> Blocks [484] Entities [90453] LWPolyline [2224] LW2DVertex [16067] >>>> Bounds >>>> [92977] Quads [1494896]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:35:08] Running Elapsed [30150ms]]] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->570067K(1229824K)] >>>> [ParOldGen: >>>> 2796047K->2796530K(2796544K)] 3856399K->3366597K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.3771630 secs] [Times: user=2.67 sys=0.00, >>>> real=0.38 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->586713K(1229824K)] >>>> [ParOldGen: >>>> 2796530K->2796473K(2796544K)] 3856882K->3383186K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.4079098 secs] [Times: user=2.94 sys=0.02, >>>> real=0.41 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->604230K(1229824K)] >>>> [ParOldGen: >>>> 2796473K->2796473K(2796544K)] 3856825K->3400703K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.4887390 secs] [Times: user=3.29 sys=0.00, >>>> real=0.49 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->619437K(1229824K)] >>>> [ParOldGen: >>>> 2796473K->2796473K(2796544K)] 3856825K->3415910K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.3851926 secs] [Times: user=2.72 sys=0.01, >>>> real=0.38 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->633907K(1229824K)] >>>> [ParOldGen: >>>> 2796473K->2796473K(2796544K)] 3856825K->3430380K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.4670582 secs] [Times: user=3.03 sys=0.01, >>>> real=0.47 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->646536K(1229824K)] >>>> [ParOldGen: >>>> 2796473K->2796473K(2796544K)] 3856825K->3443010K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.3946525 secs] [Times: user=2.76 sys=0.01, >>>> real=0.40 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->658701K(1229824K)] >>>> [ParOldGen: >>>> 2796473K->2796473K(2796544K)] 3856825K->3455175K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.4139186 secs] [Times: user=2.96 sys=0.00, >>>> real=0.42 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->671599K(1229824K)] >>>> [ParOldGen: >>>> 2796473K->2796473K(2796544K)] 3856825K->3468072K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.4255710 secs] [Times: user=3.10 sys=0.00, >>>> real=0.43 secs] >>>> DEBUG 2016-07-26T08:35:48.636Z RootLogger Thread-13 DXF [Layers [440] >>>> Blocks [780] Entities [124611] LWPolyline [3739] LW2DVertex [26322] >>>> Bounds >>>> [128308] Quads [2016664]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:35:08] Running Elapsed [40000ms]]] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->685273K(1229824K)] >>>> [ParOldGen: >>>> 2796473K->2796473K(2796544K)] 3856825K->3481746K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.5331408 secs] [Times: user=3.79 sys=0.02, >>>> real=0.53 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->697738K(1229824K)] >>>> [ParOldGen: >>>> 2796473K->2796473K(2796544K)] 3856825K->3494212K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.4704802 secs] [Times: user=2.99 sys=0.01, >>>> real=0.48 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->709033K(1229824K)] >>>> [ParOldGen: >>>> 2796473K->2796473K(2796544K)] 3856825K->3505506K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.5106929 secs] [Times: user=2.91 sys=0.01, >>>> real=0.51 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->720016K(1229824K)] >>>> [ParOldGen: >>>> 2796473K->2796473K(2796544K)] 3856825K->3516490K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.4739230 secs] [Times: user=3.05 sys=0.00, >>>> real=0.47 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->731050K(1229824K)] >>>> [ParOldGen: >>>> 2796473K->2796473K(2796544K)] 3856825K->3527524K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.3991563 secs] [Times: user=2.85 sys=0.00, >>>> real=0.40 secs] >>>> CALL_FINALLY 2016-07-26T08:35:53.658Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Call >>>> [2016-07-26T08:35:53.658Z] [Visitor] >>>> CALL_TRY 2016-07-26T08:35:53.658Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 >>>> [2016-07-26T08:35:53.658Z] [Dataset commit] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->732725K(1229824K)] >>>> [ParOldGen: >>>> 2796473K->2796323K(2796544K)] 3856825K->3529049K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.7759076 secs] [Times: user=5.61 sys=0.00, >>>> real=0.78 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->731644K(1229824K)] >>>> [ParOldGen: >>>> 2796323K->2796502K(2796544K)] 3856675K->3528146K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.8256613 secs] [Times: user=5.72 sys=0.02, >>>> real=0.82 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->731144K(1229824K)] >>>> [ParOldGen: >>>> 2796502K->2796200K(2796544K)] 3856854K->3527344K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.7834860 secs] [Times: user=5.63 sys=0.06, >>>> real=0.79 secs] >>>> DEBUG 2016-07-26T08:35:58.807Z RootLogger Thread-13 DXF [Layers [440] >>>> Blocks [878] Entities [137566] LWPolyline [3998] LW2DVertex [27550] >>>> Bounds >>>> [141908] Quads [2203968]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:35:08] Running Elapsed [50171ms]]] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->730955K(1229824K)] >>>> [ParOldGen: >>>> 2796200K->2796193K(2796544K)] 3856552K->3527149K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.5440818 secs] [Times: user=4.09 sys=0.02, >>>> real=0.54 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->730926K(1229824K)] >>>> [ParOldGen: >>>> 2796193K->2796210K(2796544K)] 3856545K->3527136K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.5644173 secs] [Times: user=4.14 sys=0.00, >>>> real=0.57 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->730898K(1229824K)] >>>> [ParOldGen: >>>> 2796210K->2796357K(2796544K)] 3856562K->3527255K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.5922727 secs] [Times: user=4.20 sys=0.00, >>>> real=0.59 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->731269K(1229824K)] >>>> [ParOldGen: >>>> 2796357K->2796103K(2796544K)] 3856709K->3527372K(4026368K), [Metaspace: >>>> 18600K->18600K(1067008K)], 0.5994868 secs] [Times: user=4.21 sys=0.00, >>>> real=0.60 secs] >>>> CALL_FINALLY 2016-07-26T08:36:03.446Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Call >>>> [2016-07-26T08:36:03.446Z] [Dataset commit] >>>> DEBUG 2016-07-26T08:36:03.446Z RootLogger Thread-5 DXF [Layers [440] >>>> Blocks >>>> [878] Entities [137566] LWPolyline [3998] LW2DVertex [27550] Bounds >>>> [141908] Quads [2203968]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:35:08] Stopped [2016:07:26 09:36:03] Elapsed [54810ms]]] >>>> CALL_TRY 2016-07-26T08:36:03.447Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 >>>> [2016-07-26T08:36:03.447Z] [Dataset end] >>>> CALL_FINALLY 2016-07-26T08:36:03.447Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Call >>>> [2016-07-26T08:36:03.447Z] [Dataset end] >>>> DEBUG 2016-07-26T08:36:03.447Z RootLogger Thread-5 take() >>>> FINALLY_BLOCK 2016-07-26T08:36:03.447Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Finally >>>> RETURN 2016-07-26T08:36:03.447Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Return Timer >>>> [Started [2016:07:26 09:35:07] Stopped [2016:07:26 09:36:03] Elapsed >>>> [55709ms]] Value [org.iungo.result.Result] >>>> VARIABLE 2016-07-26T08:36:03.447Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#4 bulkload#9 Return Value >>>> [true [DXF [Layers [440] Blocks [878] Entities [137566] LWPolyline >>>> [3998] >>>> LW2DVertex [27550] Bounds [141908] Quads [2203968]] Timer [Interval >>>> [10000] >>>> Timer [Started [2016:07:26 09:35:08] Stopped [2016:07:26 09:36:03] >>>> Elapsed >>>> [54810ms]]]] [java.lang.String]] >>>> dataset node "TDB" bulkload source type "image/vnd.dxf" url >>>> >>>> >>>> "file:///home/dick/eclipse-jee-neon/git/iungo-ssl/iungo-ssl/test/resources/0005_XXXX-SSL-XXX-XX-DR-U-0200.dxf" >>>> METHOD 2016-07-26T08:37:28.081Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#10 >>>> org.iungo.result.Result bulkload(org.iungo.context.Context) >>>> true >>>> Added bulkload >>>> org.iungo.queue.EntryDEBUG 2016-07-26T08:37:28.081Z RootLogger Thread-5 >>>> process ([ID [d9d16c72-da01-4690-b5bc-6c2ea3cb9e86] Result [null]]) >>>> DEBUG 2016-07-26T08:37:28.081Z RootLogger Thread-5 >>>> >>>> >>>> org.iungo.lang.ClassUtils.create(org.iungo.dataset.bulkload.DXFDatasetBulkload, >>>> [Ljava.lang.Class;@15f6e228, [Ljava.lang.Object;@47282d40) >>>> RETURN 2016-07-26T08:37:28.081Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#10 Return Timer >>>> [Started [2016:07:26 09:37:28] Stopped [2016:07:26 09:37:28] Elapsed >>>> [0ms]] >>>> Value [org.iungo.result.Result] >>>> VARIABLE 2016-07-26T08:37:28.082Z >>>> org.iungo.dataset.tdb.node.TDBDatasetNode#TDB bulkload#10 Return Value >>>> [true [Added bulkload] [org.iungo.queue.Entry]] >>>> INFO 2016-07-26T08:37:28.083Z RootLogger >>>> org.iungo.logger.AbstractLogger#8 >>>> Started [Logger [org.iungo.logger.SystemLogger] Name >>>> [org.iungo.dataset.bulkload.DXFDatasetBulkload#5] Level [ALL] Counts >>>> [1/0/0]] >>>> INFO 2016-07-26T08:37:28.083Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 Set level to [ALL] >>>> METHOD 2016-07-26T08:37:28.083Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 >>>> org.iungo.result.Result bulkload(org.iungo.context.Context) >>>> TRY_BLOCK 2016-07-26T08:37:28.083Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 Try [null] >>>> TRY_BLOCK 2016-07-26T08:37:28.083Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 Try [URL >>>> input >>>> stream] >>>> CALL_TRY 2016-07-26T08:37:28.083Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 >>>> [2016-07-26T08:37:28.083Z] [DXF Parser parse] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->634453K(1229824K)] >>>> [ParOldGen: >>>> 2796103K->2796208K(2796544K)] 3856455K->3430661K(4026368K), [Metaspace: >>>> 18624K->18624K(1067008K)], 0.4857900 secs] [Times: user=3.43 sys=0.01, >>>> real=0.49 secs] >>>> WARN 2016-07-26T08:37:28.688Z RootLogger Finalizer Return value not >>>> called >>>> [Logger [Logger [org.iungo.logger.SystemLogger] Name >>>> [org.iungo.dataset.tdb.node.TDBDatasetNode#TDB] Level [INFO] Counts >>>> [15/15/0]] Name [bulkload#10] Timer [Started [2016:07:26 09:37:28] >>>> Stopped >>>> [2016:07:26 09:37:28] Elapsed [0ms]]] >>>> WARN 2016-07-26T08:37:28.688Z RootLogger Finalizer Return value not >>>> called >>>> [Logger [Logger [org.iungo.logger.SystemLogger] Name >>>> [org.iungo.dataset.bulkload.DXFDatasetBulkload#4] Level [ALL] Counts >>>> [26/26/0]] Name [bulkload#9] Timer [Started [2016:07:26 09:35:07] >>>> Stopped >>>> [2016:07:26 09:36:03] Elapsed [55709ms]]] >>>> CALL_FINALLY 2016-07-26T08:37:29.068Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 Call >>>> [2016-07-26T08:37:29.068Z] [DXF Parser parse] >>>> CALL_TRY 2016-07-26T08:37:29.068Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 >>>> [2016-07-26T08:37:29.068Z] [sizeOf(Object)#Object] >>>> CALL_FINALLY 2016-07-26T08:37:29.069Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 Call >>>> [2016-07-26T08:37:29.068Z] [sizeOf(Object)#Object] >>>> CALL_TRY 2016-07-26T08:37:29.069Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 >>>> [2016-07-26T08:37:29.068Z] [sizeOf(Object)#References] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->660104K(1229824K)] >>>> [ParOldGen: >>>> 2796208K->2796206K(2796544K)] 3856560K->3456311K(4026368K), [Metaspace: >>>> 18625K->18625K(1067008K)], 0.4694237 secs] [Times: user=3.42 sys=0.00, >>>> real=0.47 secs] >>>> CALL_FINALLY 2016-07-26T08:37:29.920Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 Call >>>> [2016-07-26T08:37:29.920Z] [sizeOf(Object)#References] >>>> SIZE_OF 2016-07-26T08:37:29.920Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 Variable >>>> [draftDocument] = [72/27333824] >>>> VARIABLE 2016-07-26T08:37:29.920Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 Variable >>>> [g] = >>>> [urn:iungo:dxf/graph/837fd0e8-f97e-43c3-8b92-dd8827db9226] >>>> CALL_TRY 2016-07-26T08:37:29.920Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 >>>> [2016-07-26T08:37:29.920Z] [Dataset write] >>>> CALL_FINALLY 2016-07-26T08:37:29.921Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 Call >>>> [2016-07-26T08:37:29.921Z] [Dataset write] >>>> TRY_BLOCK 2016-07-26T08:37:29.921Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 Try >>>> [Visitor] >>>> DEBUG 2016-07-26T08:37:29.921Z RootLogger Thread-5 DXF [Layers [0] >>>> Blocks >>>> [0] Entities [0] LWPolyline [0] LW2DVertex [0] Bounds [0] Quads [0]] >>>> Process [Interval [10000] Timer [Started [2016:07:26 09:37:29] Running >>>> Elapsed [0ms]]] >>>> CALL_TRY 2016-07-26T08:37:29.921Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 >>>> [2016-07-26T08:37:29.921Z] [Visitor] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->662029K(1229824K)] >>>> [ParOldGen: >>>> 2796206K->2796165K(2796544K)] 3856558K->3458194K(4026368K), [Metaspace: >>>> 18636K->18636K(1067008K)], 0.7270263 secs] [Times: user=5.42 sys=0.02, >>>> real=0.73 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->731387K(1229824K)] >>>> [ParOldGen: >>>> 2796165K->2796126K(2796544K)] 3856517K->3527514K(4026368K), [Metaspace: >>>> 18636K->18636K(1067008K)], 0.5115597 secs] [Times: user=3.83 sys=0.00, >>>> real=0.52 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->761272K(1229824K)] >>>> [ParOldGen: >>>> 2796126K->2796440K(2796544K)] 3856478K->3557713K(4026368K), [Metaspace: >>>> 18636K->18626K(1067008K)], 1.1277286 secs] [Times: user=8.34 sys=0.04, >>>> real=1.13 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->789655K(1229824K)] >>>> [ParOldGen: >>>> 2796440K->2796409K(2796544K)] 3856792K->3586065K(4026368K), [Metaspace: >>>> 18626K->18626K(1067008K)], 0.7945983 secs] [Times: user=5.81 sys=0.04, >>>> real=0.79 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->812589K(1229824K)] >>>> [ParOldGen: >>>> 2796409K->2796401K(2796544K)] 3856761K->3608990K(4026368K), [Metaspace: >>>> 18626K->18626K(1067008K)], 0.8251349 secs] [Times: user=6.26 sys=0.02, >>>> real=0.82 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->833406K(1229824K)] >>>> [ParOldGen: >>>> 2796401K->2796395K(2796544K)] 3856753K->3629801K(4026368K), [Metaspace: >>>> 18626K->18626K(1067008K)], 0.8759976 secs] [Times: user=6.60 sys=0.01, >>>> real=0.87 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->851906K(1229824K)] >>>> [ParOldGen: >>>> 2796395K->2796390K(2796544K)] 3856747K->3648297K(4026368K), [Metaspace: >>>> 18626K->18626K(1067008K)], 0.9034920 secs] [Times: user=6.75 sys=0.04, >>>> real=0.90 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->869713K(1229824K)] >>>> [ParOldGen: >>>> 2796390K->2796385K(2796544K)] 3856742K->3666098K(4026368K), [Metaspace: >>>> 18626K->18626K(1067008K)], 0.8542784 secs] [Times: user=6.41 sys=0.03, >>>> real=0.85 secs] >>>> DEBUG 2016-07-26T08:37:39.921Z RootLogger Thread-15 DXF [Layers [190] >>>> Blocks [0] Entities [11352] LWPolyline [113] LW2DVertex [1070] Bounds >>>> [11542] Quads [203643]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:37:29] Running Elapsed [10001ms]]] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->884338K(1229824K)] >>>> [ParOldGen: >>>> 2796385K->2796380K(2796544K)] 3856737K->3680719K(4026368K), [Metaspace: >>>> 18629K->18629K(1067008K)], 0.9539835 secs] [Times: user=7.09 sys=0.02, >>>> real=0.95 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->899372K(1229824K)] >>>> [ParOldGen: >>>> 2796380K->2796373K(2796544K)] 3856732K->3695745K(4026368K), [Metaspace: >>>> 18629K->18629K(1067008K)], 0.9115765 secs] [Times: user=6.81 sys=0.03, >>>> real=0.91 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->912688K(1229824K)] >>>> [ParOldGen: >>>> 2796373K->2796366K(2796544K)] 3856725K->3709054K(4026368K), [Metaspace: >>>> 18629K->18629K(1067008K)], 0.8182557 secs] [Times: user=6.12 sys=0.02, >>>> real=0.82 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->924573K(1229824K)] >>>> [ParOldGen: >>>> 2796366K->2796361K(2796544K)] 3856718K->3720934K(4026368K), [Metaspace: >>>> 18629K->18629K(1067008K)], 0.8474470 secs] [Times: user=6.37 sys=0.03, >>>> real=0.85 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->935645K(1229824K)] >>>> [ParOldGen: >>>> 2796361K->2796357K(2796544K)] 3856713K->3732002K(4026368K), [Metaspace: >>>> 18629K->18629K(1067008K)], 0.9291745 secs] [Times: user=6.95 sys=0.04, >>>> real=0.93 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->945499K(1229824K)] >>>> [ParOldGen: >>>> 2796357K->2796354K(2796544K)] 3856709K->3741854K(4026368K), [Metaspace: >>>> 18629K->18629K(1067008K)], 0.8776748 secs] [Times: user=6.52 sys=0.03, >>>> real=0.88 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->954858K(1229824K)] >>>> [ParOldGen: >>>> 2796354K->2796350K(2796544K)] 3856706K->3751209K(4026368K), [Metaspace: >>>> 18629K->18629K(1067008K)], 0.9409550 secs] [Times: user=7.08 sys=0.03, >>>> real=0.95 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->963198K(1229824K)] >>>> [ParOldGen: >>>> 2796350K->2796348K(2796544K)] 3856702K->3759546K(4026368K), [Metaspace: >>>> 18629K->18629K(1067008K)], 0.8486727 secs] [Times: user=6.39 sys=0.01, >>>> real=0.84 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->970783K(1229824K)] >>>> [ParOldGen: >>>> 2796348K->2796346K(2796544K)] 3856700K->3767129K(4026368K), [Metaspace: >>>> 18629K->18629K(1067008K)], 0.8557959 secs] [Times: user=6.46 sys=0.01, >>>> real=0.86 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->977965K(1229824K)] >>>> [ParOldGen: >>>> 2796346K->2796343K(2796544K)] 3856698K->3774308K(4026368K), [Metaspace: >>>> 18629K->18629K(1067008K)], 0.9415255 secs] [Times: user=7.12 sys=0.00, >>>> real=0.94 secs] >>>> DEBUG 2016-07-26T08:37:50.791Z RootLogger Thread-15 DXF [Layers [206] >>>> Blocks [0] Entities [18020] LWPolyline [113] LW2DVertex [1070] Bounds >>>> [18225] Quads [323131]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:37:29] Running Elapsed [20870ms]]] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->984279K(1229824K)] >>>> [ParOldGen: >>>> 2796343K->2796341K(2796544K)] 3856695K->3780620K(4026368K), [Metaspace: >>>> 18629K->18629K(1067008K)], 0.9347525 secs] [Times: user=6.96 sys=0.02, >>>> real=0.93 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->990255K(1229824K)] >>>> [ParOldGen: >>>> 2796341K->2796339K(2796544K)] 3856693K->3786595K(4026368K), [Metaspace: >>>> 18629K->18629K(1067008K)], 0.9520571 secs] [Times: user=7.11 sys=0.02, >>>> real=0.95 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->995623K(1229824K)] >>>> [ParOldGen: >>>> 2796339K->2796337K(2796544K)] 3856691K->3791960K(4026368K), [Metaspace: >>>> 18629K->18629K(1067008K)], 0.9310927 secs] [Times: user=6.64 sys=0.03, >>>> real=0.94 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1000588K(1229824K)] >>>> [ParOldGen: 2796337K->2796335K(2796544K)] 3856689K->3796924K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.8826194 secs] [Times: user=6.51 >>>> sys=0.01, real=0.88 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1005364K(1229824K)] >>>> [ParOldGen: 2796335K->2796334K(2796544K)] 3856687K->3801699K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.9608125 secs] [Times: user=7.05 >>>> sys=0.01, real=0.97 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1009414K(1229824K)] >>>> [ParOldGen: 2796334K->2796333K(2796544K)] 3856686K->3805747K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.9711567 secs] [Times: user=6.94 >>>> sys=0.03, real=0.97 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1013627K(1229824K)] >>>> [ParOldGen: 2796333K->2796332K(2796544K)] 3856685K->3809959K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.9274380 secs] [Times: user=6.95 >>>> sys=0.01, real=0.93 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1017445K(1229824K)] >>>> [ParOldGen: 2796332K->2796331K(2796544K)] 3856684K->3813776K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.8895476 secs] [Times: user=6.36 >>>> sys=0.03, real=0.89 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1020287K(1229824K)] >>>> [ParOldGen: 2796331K->2796330K(2796544K)] 3856683K->3816617K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.8152140 secs] [Times: user=6.12 >>>> sys=0.01, real=0.82 secs] >>>> DEBUG 2016-07-26T08:38:00.209Z RootLogger Thread-15 DXF [Layers [212] >>>> Blocks [0] Entities [20918] LWPolyline [181] LW2DVertex [1750] Bounds >>>> [21129] Quads [378143]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:37:29] Running Elapsed [30288ms]]] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1023334K(1229824K)] >>>> [ParOldGen: 2796330K->2796322K(2796544K)] 3856682K->3819657K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.9673286 secs] [Times: user=7.00 >>>> sys=0.05, real=0.96 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1026701K(1229824K)] >>>> [ParOldGen: 2796322K->2796319K(2796544K)] 3856674K->3823020K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.8716560 secs] [Times: user=6.17 >>>> sys=0.01, real=0.87 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1029198K(1229824K)] >>>> [ParOldGen: 2796319K->2796317K(2796544K)] 3856671K->3825515K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.9958862 secs] [Times: user=7.05 >>>> sys=0.03, real=0.99 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1031541K(1229824K)] >>>> [ParOldGen: 2796317K->2796315K(2796544K)] 3856669K->3827856K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.9095475 secs] [Times: user=6.17 >>>> sys=0.03, real=0.91 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1033860K(1229824K)] >>>> [ParOldGen: 2796315K->2796313K(2796544K)] 3856667K->3830174K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 1.0211152 secs] [Times: user=7.49 >>>> sys=0.02, real=1.02 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1035868K(1229824K)] >>>> [ParOldGen: 2796313K->2796311K(2796544K)] 3856665K->3832179K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.9288378 secs] [Times: user=6.84 >>>> sys=0.01, real=0.93 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1037782K(1229824K)] >>>> [ParOldGen: 2796311K->2796310K(2796544K)] 3856663K->3834092K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.9366751 secs] [Times: user=7.03 >>>> sys=0.01, real=0.93 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1039590K(1229824K)] >>>> [ParOldGen: 2796310K->2796308K(2796544K)] 3856662K->3835899K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.8240543 secs] [Times: user=6.13 >>>> sys=0.02, real=0.83 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1041128K(1229824K)] >>>> [ParOldGen: 2796308K->2796307K(2796544K)] 3856660K->3837436K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.9203202 secs] [Times: user=6.90 >>>> sys=0.02, real=0.92 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1042578K(1229824K)] >>>> [ParOldGen: 2796307K->2796306K(2796544K)] 3856659K->3838885K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.8958402 secs] [Times: user=6.70 >>>> sys=0.04, real=0.90 secs] >>>> DEBUG 2016-07-26T08:38:09.968Z RootLogger Thread-15 DXF [Layers [220] >>>> Blocks [125] Entities [22399] LWPolyline [225] LW2DVertex [2292] Bounds >>>> [22993] Quads [405217]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:37:29] Running Elapsed [40047ms]]] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1043759K(1229824K)] >>>> [ParOldGen: 2796306K->2796305K(2796544K)] 3856658K->3840064K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.7587285 secs] [Times: user=5.68 >>>> sys=0.02, real=0.76 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1044959K(1229824K)] >>>> [ParOldGen: 2796305K->2796304K(2796544K)] 3856657K->3841264K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.8307296 secs] [Times: user=6.15 >>>> sys=0.01, real=0.83 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1046075K(1229824K)] >>>> [ParOldGen: 2796304K->2796303K(2796544K)] 3856656K->3842379K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.7428160 secs] [Times: user=5.47 >>>> sys=0.02, real=0.75 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1047051K(1229824K)] >>>> [ParOldGen: 2796303K->2796303K(2796544K)] 3856655K->3843354K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.8363360 secs] [Times: user=6.22 >>>> sys=0.06, real=0.84 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1047949K(1229824K)] >>>> [ParOldGen: 2796303K->2796302K(2796544K)] 3856655K->3844252K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.9068747 secs] [Times: user=6.76 >>>> sys=0.01, real=0.91 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1048827K(1229824K)] >>>> [ParOldGen: 2796302K->2796301K(2796544K)] 3856654K->3845128K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.8800083 secs] [Times: user=6.62 >>>> sys=0.01, real=0.88 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1049840K(1229824K)] >>>> [ParOldGen: 2796301K->2796300K(2796544K)] 3856653K->3846141K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.9044757 secs] [Times: user=6.73 >>>> sys=0.03, real=0.90 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1050652K(1229824K)] >>>> [ParOldGen: 2796300K->2796300K(2796544K)] 3856652K->3846952K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.6777164 secs] [Times: user=5.03 >>>> sys=0.01, real=0.68 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1051357K(1229824K)] >>>> [ParOldGen: 2796300K->2796300K(2796544K)] 3856652K->3847658K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.6891479 secs] [Times: user=5.07 >>>> sys=0.01, real=0.68 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1051977K(1229824K)] >>>> [ParOldGen: 2796300K->2796300K(2796544K)] 3856652K->3848278K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.6847955 secs] [Times: user=5.11 >>>> sys=0.01, real=0.68 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1052515K(1229824K)] >>>> [ParOldGen: 2796300K->2796300K(2796544K)] 3856652K->3848816K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.6887732 secs] [Times: user=5.13 >>>> sys=0.01, real=0.69 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1052954K(1229824K)] >>>> [ParOldGen: 2796300K->2796299K(2796544K)] 3856652K->3849254K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.7548947 secs] [Times: user=5.58 >>>> sys=0.01, real=0.76 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1053471K(1229824K)] >>>> [ParOldGen: 2796299K->2796299K(2796544K)] 3856651K->3849771K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.6764151 secs] [Times: user=5.04 >>>> sys=0.03, real=0.68 secs] >>>> DEBUG 2016-07-26T08:38:20.259Z RootLogger Thread-15 DXF [Layers [220] >>>> Blocks [193] Entities [23283] LWPolyline [256] LW2DVertex [2417] Bounds >>>> [24087] Quads [420321]] Process [Interval [10000] Timer [Started >>>> [2016:07:26 09:37:29] Running Elapsed [50338ms]]] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1053938K(1229824K)] >>>> [ParOldGen: 2796299K->2796298K(2796544K)] 3856651K->3850236K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.7496102 secs] [Times: user=5.55 >>>> sys=0.02, real=0.74 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1054710K(1229824K)] >>>> [ParOldGen: 2796298K->2796292K(2796544K)] 3856650K->3851002K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.7361073 secs] [Times: user=5.50 >>>> sys=0.01, real=0.73 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1055336K(1229824K)] >>>> [ParOldGen: 2796292K->2796290K(2796544K)] 3856644K->3851626K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.7170885 secs] [Times: user=5.34 >>>> sys=0.02, real=0.72 secs] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1055845K(1229824K)] >>>> [ParOldGen: 2796290K->2796176K(2796544K)] 3856642K->3852021K(4026368K), >>>> [Metaspace: 18629K->18629K(1067008K)], 0.8833491 secs] [Times: user=6.48 >>>> sys=0.03, real=0.88 secs] >>>> CALL_CATCH 2016-07-26T08:38:23.383Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 >>>> java.lang.OutOfMemoryError: GC overhead limit exceeded >>>> java.nio.HeapByteBuffer.asIntBuffer(HeapByteBuffer.java:391) >>>> org.apache.jena.tdb.base.buffer.PtrBuffer.<init>(PtrBuffer.java:47) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr.formatBPTreeNode(BPTreeNodeMgr.java:259) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr.overlay(BPTreeNodeMgr.java:204) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr.access$000(BPTreeNodeMgr.java:36) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr$Block2BPTreeNode.fromBlock(BPTreeNodeMgr.java:144) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr$Block2BPTreeNode.fromBlock(BPTreeNodeMgr.java:119) >>>> org.apache.jena.tdb.base.page.PageBlockMgr.getRead(PageBlockMgr.java:68) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr.getRead(BPTreeNodeMgr.java:105) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr.getRoot(BPTreeNodeMgr.java:90) >>>> >>>> org.apache.jena.tdb.index.bplustree.BPlusTree.getRoot(BPlusTree.java:237) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPlusTree.addAndReturnOld(BPlusTree.java:325) >>>> org.apache.jena.tdb.index.bplustree.BPlusTree.add(BPlusTree.java:318) >>>> >>>> >>>> org.apache.jena.tdb.store.tupletable.TupleIndexRecord.performAdd(TupleIndexRecord.java:60) >>>> >>>> >>>> org.apache.jena.tdb.store.tupletable.TupleIndexBase.add(TupleIndexBase.java:62) >>>> org.apache.jena.tdb.store.tupletable.TupleTable.add(TupleTable.java:95) >>>> >>>> >>>> org.apache.jena.tdb.store.nodetupletable.NodeTupleTableConcrete.addRow(NodeTupleTableConcrete.java:88) >>>> org.apache.jena.tdb.store.QuadTable.add(QuadTable.java:60) >>>> >>>> >>>> org.apache.jena.tdb.store.DatasetGraphTDB.addToNamedGraph(DatasetGraphTDB.java:98) >>>> >>>> >>>> org.apache.jena.sparql.core.DatasetGraphTriplesQuads.add(DatasetGraphTriplesQuads.java:49) >>>> >>>> >>>> org.apache.jena.sparql.core.DatasetGraphWrapper.add(DatasetGraphWrapper.java:106) >>>> >>>> >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:340) >>>> >>>> >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:355) >>>> org.kabeja.entities.Entity.accept(Entity.java:67) >>>> >>>> >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:312) >>>> org.kabeja.common.Block.accept(Block.java:59) >>>> >>>> >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:197) >>>> org.kabeja.DraftDocument.accept(DraftDocument.java:100) >>>> >>>> >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload$6.get(DXFDatasetBulkload.java:503) >>>> >>>> >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload$6.get(DXFDatasetBulkload.java:1) >>>> org.iungo.logger.MethodLogger.call(MethodLogger.java:104) >>>> >>>> >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload.bulkload(DXFDatasetBulkload.java:500) >>>> CALL_FINALLY 2016-07-26T08:38:23.384Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 Call >>>> [2016-07-26T08:38:23.383Z] [Visitor] >>>> CALL_TRY 2016-07-26T08:38:23.386Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 >>>> [2016-07-26T08:38:23.386Z] [Dataset abort] >>>> CALL_FINALLY 2016-07-26T08:38:23.392Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 Call >>>> [2016-07-26T08:38:23.392Z] [Dataset abort] >>>> [Full GC (Ergonomics) [PSYoungGen: 1060352K->1046588K(1229824K)] >>>> [ParOldGen: 2796176K->2796174K(2796544K)] 3856528K->3842763K(4026368K), >>>> [Metaspace: 18632K->18632K(1067008K)], 0.7879990 secs] [Times: user=5.76 >>>> sys=0.03, real=0.79 secs] >>>> CATCH_BLOCK 2016-07-26T08:38:24.180Z >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload#5 bulkload#11 Catch >>>> [java.lang.UnsupportedOperationException: java.lang.OutOfMemoryError: GC >>>> overhead limit exceeded >>>> org.iungo.logger.MethodLogger.call(MethodLogger.java:107) >>>> >>>> >>>> org.iungo.dataset.bulkload.DXFDatasetBulkload.bulkload(DXFDatasetBulkload.java:500) >>>> org.iungo.dataset.node.DatasetNode$1$1.accept(DatasetNode.java:222) >>>> org.iungo.dataset.node.DatasetNode$1$1.accept(DatasetNode.java:1) >>>> org.iungo.queue.Q.process(Q.java:64) >>>> org.iungo.queue.Q$1.run(Q.java:45) >>>> java.lang.Thread.run(Thread.java:745)Cause: >>>> java.lang.OutOfMemoryError: GC overhead limit exceeded >>>> java.nio.HeapByteBuffer.asIntBuffer(HeapByteBuffer.java:391) >>>> org.apache.jena.tdb.base.buffer.PtrBuffer.<init>(PtrBuffer.java:47) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr.formatBPTreeNode(BPTreeNodeMgr.java:259) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr.overlay(BPTreeNodeMgr.java:204) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr.access$000(BPTreeNodeMgr.java:36) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr$Block2BPTreeNode.fromBlock(BPTreeNodeMgr.java:144) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr$Block2BPTreeNode.fromBlock(BPTreeNodeMgr.java:119) >>>> org.apache.jena.tdb.base.page.PageBlockMgr.getRead(PageBlockMgr.java:68) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr.getRead(BPTreeNodeMgr.java:105) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPTreeNodeMgr.getRoot(BPTreeNodeMgr.java:90) >>>> >>>> org.apache.jena.tdb.index.bplustree.BPlusTree.getRoot(BPlusTree.java:237) >>>> >>>> >>>> org.apache.jena.tdb.index.bplustree.BPlusTree.addAndReturnOld(BPlusTree.java:325) >>>> org.apache.jena.tdb.index.bplustree.BPlusTree.add(BPlusTree.java:318) >>>> >>>> >>>> org.apache.jena.tdb.store.tupletable.TupleIndexRecord.performAdd(TupleIndexRecord.java:60) >>>> >>>> >>>> org.apache.jena.tdb.store.tupletable.TupleIndexBase.add(TupleIndexBase.java:62) >>>> org.apache.jena.tdb.store.tupletable.TupleTable.add(TupleTable.java:95) >>>> >>>> >>>> org.apache.jena.tdb.store.nodetupletable.NodeTupleTableConcrete.addRow(NodeTupleTableConcrete.java:88) >>>> org.apache.jena.tdb.store.QuadTable.add(QuadTable.java:60) >>> >>>
