Ok, I set that option and I get different OOME from the direct buffer
memory.
I then changed the GC using -XX:+UseG1GC (which still throws the OOME) and
I don't get why it's throwing the OOME.!?
[Eden: 2372.0M(2372.0M)->0.0B(1036.0M) Survivors: 84.0M->196.0M Heap:
2979.4M(4096.0M)->720.4M(4096.0M)]
Unless I'm mistaken I don't have a G1 Heap problem?
...
[GC pause (G1 Evacuation Pause) (young), 0.1580047 secs]
[Parallel Time: 149.8 ms, GC Workers: 8]
[GC Worker Start (ms): Min: 463499.3, Avg: 463499.4, Max: 463499.5,
Diff: 0.1]
[Ext Root Scanning (ms): Min: 0.2, Avg: 0.2, Max: 0.3, Diff: 0.2,
Sum: 1.8]
[Update RS (ms): Min: 12.5, Avg: 12.6, Max: 12.7, Diff: 0.2, Sum:
100.9]
[Processed Buffers: Min: 13, Avg: 15.6, Max: 18, Diff: 5, Sum: 125]
[Scan RS (ms): Min: 18.7, Avg: 18.8, Max: 18.8, Diff: 0.2, Sum: 150.2]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0,
Sum: 0.1]
[Object Copy (ms): Min: 116.7, Avg: 116.7, Max: 116.8, Diff: 0.1,
Sum: 933.8]
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 8]
[GC Worker Other (ms): Min: 0.0, Avg: 1.2, Max: 1.4, Diff: 1.3, Sum:
9.3]
[GC Worker Total (ms): Min: 148.3, Avg: 149.5, Max: 149.8, Diff: 1.4,
Sum: 1196.1]
[GC Worker End (ms): Min: 463647.8, Avg: 463648.9, Max: 463649.1,
Diff: 1.3]
[Code Root Fixup: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.8 ms]
[Other: 7.3 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 4.7 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.4 ms]
[Humongous Register: 0.1 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 1.8 ms]
[Eden: 2372.0M(2372.0M)->0.0B(1036.0M) Survivors: 84.0M->196.0M Heap:
2979.4M(4096.0M)->720.4M(4096.0M)]
[Times: user=1.13 sys=0.01, real=0.16 secs]
WARN 2016-07-26T15:26:10.196Z 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 16:26:05] Stopped
[2016:07:26 16:26:05] Elapsed [0ms]]]
[Full GC (System.gc()) 849M->327M(4096M), 1.4194434 secs]
[Eden: 130.0M(1036.0M)->0.0B(2456.0M) Survivors: 196.0M->0.0B Heap:
849.4M(4096.0M)->327.7M(4096.0M)], [Metaspace: 18671K->18671K(1067008K)]
[Times: user=1.80 sys=0.13, real=1.42 secs]
WARN 2016-07-26T15:26:12.001Z 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 16:24:03] Stopped
[2016:07:26 16:25:08] Elapsed [64979ms]]]
WARN 2016-07-26T15:26:12.002Z 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 16:21:45] Stopped
[2016:07:26 16:22:47] Elapsed [62554ms]]]
CALL_CATCH 2016-07-26T15:26:12.516Z
org.iungo.dataset.bulkload.DXFDatasetBulkload#3 bulkload#7
java.lang.OutOfMemoryError:
Direct buffer memory
java.nio.Bits.reserveMemory(Bits.java:693)
java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:123)
java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:311)
org.apache.jena.tdb.base.file.BufferAllocatorDirect.allocate(BufferAllocatorDirect.java:31)
org.apache.jena.tdb.transaction.BlockMgrJournal.replicate(BlockMgrJournal.java:381)
org.apache.jena.tdb.transaction.BlockMgrJournal.allocate(BlockMgrJournal.java:149)
org.apache.jena.tdb.base.page.PageBlockMgr.create(PageBlockMgr.java:51)
org.apache.jena.tdb.index.bplustree.BPTreeRecordsMgr.create(BPTreeRecordsMgr.java:79)
org.apache.jena.tdb.index.bplustree.BPTreeRecords.create(BPTreeRecords.java:207)
org.apache.jena.tdb.index.bplustree.BPTreeRecords.split(BPTreeRecords.java:181)
org.apache.jena.tdb.index.bplustree.BPTreeNode.split(BPTreeNode.java:518)
org.apache.jena.tdb.index.bplustree.BPTreeNode.internalInsert(BPTreeNode.java:454)
org.apache.jena.tdb.index.bplustree.BPTreeNode.internalInsert(BPTreeNode.java:467)
org.apache.jena.tdb.index.bplustree.BPTreeNode.internalInsert(BPTreeNode.java:467)
org.apache.jena.tdb.index.bplustree.BPTreeNode.insert(BPTreeNode.java:211)
org.apache.jena.tdb.index.bplustree.BPlusTree.addAndReturnOld(BPlusTree.java:326)
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:336)
org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:356)
org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:436)
org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:363)
org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:1)
org.kabeja.entities.Attrib.accept(Attrib.java:36)
org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:379)
org.kabeja.entities.Insert.accept(Insert.java:56)
org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:282)
org.kabeja.common.Layer.accept(Layer.java:61)
org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:193)
org.kabeja.DraftDocument.accept(DraftDocument.java:100)
org.iungo.dataset.bulkload.DXFDatasetBulkload$6.get(DXFDatasetBulkload.java:504)
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:501)
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)
Original GC
[GC (System.gc()) [PSYoungGen: 912254K->27048K(1323520K)]
1244937K->359739K(4120064K), 0.0178493 secs] [Times: user=0.12 sys=0.00,
real=0.01 secs]
[Full GC (System.gc()) [PSYoungGen: 27048K->0K(1323520K)] [ParOldGen:
332690K->275014K(2796544K)] 359739K->275014K(4120064K), [Metaspace:
18702K->18702K(1067008K)], 0.6541853 secs] [Times: user=4.11 sys=0.02,
real=0.66 secs]
[GC (Allocation Failure) [PSYoungGen: 1249792K->52800K(1315328K)]
1524806K->327814K(4111872K), 0.0372440 secs] [Times: user=0.22 sys=0.00,
real=0.04 secs]
[GC (Allocation Failure) [PSYoungGen: 1297984K->10992K(1321472K)]
1572998K->335623K(4118016K), 0.0398731 secs] [Times: user=0.24 sys=0.00,
real=0.04 secs]
[GC (System.gc()) [PSYoungGen: 230771K->2048K(1325056K)]
555403K->336871K(4121600K), 0.0101041 secs] [Times: user=0.06 sys=0.00,
real=0.02 secs]
[Full GC (System.gc()) [PSYoungGen: 2048K->0K(1325056K)] [ParOldGen:
334823K->332700K(2796544K)] 336871K->332700K(4121600K), [Metaspace:
18706K->18706K(1067008K)], 0.6672732 secs] [Times: user=4.40 sys=0.01,
real=0.66 secs]
CALL_CATCH 2016-07-26T15:07:18.146Z
org.iungo.dataset.bulkload.DXFDatasetBulkload#6 bulkload#13
java.lang.OutOfMemoryError: Direct buffer memory
java.nio.Bits.reserveMemory(Bits.java:693)
java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:123)
java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:311)
org.apache.jena.tdb.base.file.BufferAllocatorDirect.allocate(BufferAllocatorDirect.java:31)
org.apache.jena.tdb.transaction.BlockMgrJournal.replicate(BlockMgrJournal.java:381)
org.apache.jena.tdb.transaction.BlockMgrJournal._promote(BlockMgrJournal.java:220)
org.apache.jena.tdb.transaction.BlockMgrJournal.promote(BlockMgrJournal.java:214)
org.apache.jena.tdb.base.page.PageBlockMgr.promote(PageBlockMgr.java:109)
org.apache.jena.tdb.index.bplustree.BPTreeRecords.promote(BPTreeRecords.java:118)
org.apache.jena.tdb.index.bplustree.BPTreeRecords.internalInsert(BPTreeRecords.java:130)
org.apache.jena.tdb.index.bplustree.BPTreeNode.internalInsert(BPTreeNode.java:467)
org.apache.jena.tdb.index.bplustree.BPTreeNode.internalInsert(BPTreeNode.java:467)
org.apache.jena.tdb.index.bplustree.BPTreeNode.internalInsert(BPTreeNode.java:467)
org.apache.jena.tdb.index.bplustree.BPTreeNode.insert(BPTreeNode.java:211)
org.apache.jena.tdb.index.bplustree.BPlusTree.addAndReturnOld(BPlusTree.java:326)
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:437)
org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:363)
org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:1)
org.kabeja.entities.Attrib.accept(Attrib.java:36)
org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:379)
org.kabeja.entities.Insert.accept(Insert.java:56)
org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:282)
org.kabeja.common.Layer.accept(Layer.java:61)
org.iungo.dataset.bulkload.DXFDatasetBulkload$2.visit(DXFDatasetBulkload.java:193)
org.kabeja.DraftDocument.accept(DraftDocument.java:100)
org.iungo.dataset.bulkload.DXFDatasetBulkload$6.get(DXFDatasetBulkload.java:504)
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:501)
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)
Heap
PSYoungGen total 1325056K, used 139293K [0x000000076ab00000,
0x00000007c0000000, 0x00000007c0000000)
eden space 1251328K, 11% used
[0x000000076ab00000,0x0000000773307780,0x00000007b7100000)
from space 73728K, 0% used
[0x00000007bb800000,0x00000007bb800000,0x00000007c0000000)
to space 72704K, 0% used
[0x00000007b7100000,0x00000007b7100000,0x00000007bb800000)
ParOldGen total 2796544K, used 332700K [0x00000006c0000000,
0x000000076ab00000, 0x000000076ab00000)
object space 2796544K, 11% used
[0x00000006c0000000,0x00000006d44e71a8,0x000000076ab00000)
Metaspace used 18734K, capacity 19032K, committed 19328K, reserved
1067008K
class space used 2265K, capacity 2366K, committed 2432K, reserved
1048576K
On 26 July 2016 at 14:40, Andy Seaborne <[email protected]> wrote:
> To build clean locally do the following:
>
> at the top level: not jena-tdb
>
> mvn clean install -Pbootstrap
> mvn install -Pdev
>
> (or "mvn clean install" but that builds and tests a lot more)
>
> Andy
>
>
>
> On 26/07/16 14:25, Andy Seaborne wrote:
>
>> On 26/07/16 14:11, Dick Murray wrote:
>>
>>> 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.
>>>
>>
>> Make sure you have all the dependencies successfully resolved with
>> mvn -o dependency:tree.
>>
>> The Apache snapshot repo was having a bad day earlier and Multiset is
>> from org.apache.jena:jena-shaded-guava:jar
>>
>> Andy
>>
>>
>>> On 26 July 2016 at 11:05, Andy Seaborne <[email protected]> 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 <[email protected]> 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->105
>>>>>>
>>>>>> ...
>
> [Message clipped]
