hudi-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From GitBox <...@apache.org>
Subject [GitHub] [incubator-hudi] lamber-ken opened a new pull request #1352: [HUDI-625] Fixing performance issues around DiskBasedMap & kryo
Date Mon, 24 Feb 2020 19:45:28 GMT
lamber-ken opened a new pull request #1352: [HUDI-625] Fixing performance issues around DiskBasedMap
& kryo
URL: https://github.com/apache/incubator-hudi/pull/1352
 
 
   ## What is the purpose of the pull request
   
   **ISSUE:** https://github.com/apache/incubator-hudi/issues/1328
   **JIRA:** https://issues.apache.org/jira/browse/HUDI-625
   
   **User report upsert hangs**
   **Analysis**
   Upsert (4000000 entries)
   ```
   WARN HoodieMergeHandle: 
   Number of entries in MemoryBasedMap => 150875 
   Total size in bytes of MemoryBasedMap => 83886580 
   Number of entries in DiskBasedMap => 3849125 
   Size of file spilled to disk => 1443046132
   ```
   Hang stackstrace (DiskBasedMap#get)
   ```
   at org.apache.hudi.common.util.SerializationUtils$KryoInstantiator$KryoBase$$Lambda$265/1458915834.newInstance(Unknown
Source)
       at com.esotericsoftware.kryo.Kryo.newInstance(Kryo.java:1139)
       at com.esotericsoftware.kryo.serializers.FieldSerializer.create(FieldSerializer.java:562)
       at com.esotericsoftware.kryo.serializers.FieldSerializer.read(FieldSerializer.java:538)
       at com.esotericsoftware.kryo.Kryo.readObject(Kryo.java:731)
       at com.esotericsoftware.kryo.serializers.ObjectField.read(ObjectField.java:125)
       at com.esotericsoftware.kryo.serializers.FieldSerializer.read(FieldSerializer.java:543)
       at com.esotericsoftware.kryo.Kryo.readClassAndObject(Kryo.java:813)
       at org.apache.hudi.common.util.SerializationUtils$KryoSerializerInstance.deserialize(SerializationUtils.java:112)
       at org.apache.hudi.common.util.SerializationUtils.deserialize(SerializationUtils.java:86)
       at org.apache.hudi.common.util.collection.DiskBasedMap.get(DiskBasedMap.java:217)
       at org.apache.hudi.common.util.collection.DiskBasedMap.get(DiskBasedMap.java:211)
       at org.apache.hudi.common.util.collection.DiskBasedMap.get(DiskBasedMap.java:207)
       at org.apache.hudi.common.util.collection.ExternalSpillableMap.get(ExternalSpillableMap.java:173)
       at org.apache.hudi.common.util.collection.ExternalSpillableMap.get(ExternalSpillableMap.java:55)
       at org.apache.hudi.io.HoodieMergeHandle.write(HoodieMergeHandle.java:280)
       at org.apache.hudi.table.HoodieCopyOnWriteTable$UpdateHandler.consumeOneRecord(HoodieCopyOnWriteTable.java:434)
       at org.apache.hudi.table.HoodieCopyOnWriteTable$UpdateHandler.consumeOneRecord(HoodieCopyOnWriteTable.java:424)
       at org.apache.hudi.common.util.queue.BoundedInMemoryQueueConsumer.consume(BoundedInMemoryQueueConsumer.java:37)
       at org.apache.hudi.common.util.queue.BoundedInMemoryExecutor.lambda$null$2(BoundedInMemoryExecutor.java:121)
       at org.apache.hudi.common.util.queue.BoundedInMemoryExecutor$$Lambda$76/1412692041.call(Unknown
Source)
       at java.util.concurrent.FutureTask.run(FutureTask.java:266)
       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
       at java.lang.Thread.run(Thread.java:745)
   ```
   Average time of DiskBasedMap#get
   ```
   $ monitor *DiskBasedMap get -c 12
   
   Affect(class-cnt:1 , method-cnt:4) cost in 221 ms.
    timestamp            class         method  total  success  fail  avg-rt(ms)  fail-rate
   ----------------------------------------------------------------------------------------
    2020-02-20 18:13:36  DiskBasedMap  get     5814   5814     0     6.12        0.00%
   
   
    timestamp            class         method  total  success  fail  avg-rt(ms)  fail-rate
   ----------------------------------------------------------------------------------------
   2020-02-20 18:13:48  DiskBasedMap   get     9117   9117     0     3.89        0.00%
   
   
    timestamp            class         method  total  success  fail  avg-rt(ms)  fail-rate
   ----------------------------------------------------------------------------------------
    2020-02-20 18:14:16  DiskBasedMap  get     8490   8490     0     4.10        0.00%
   
   ```
   
   Call time strace:
   ```
       `---[4.361707ms] org.apache.hudi.common.util.collection.DiskBasedMap:get()
           +---[0.001704ms] java.util.Map:get()
           `---[4.344261ms] org.apache.hudi.common.util.collection.DiskBasedMap:get()
               `---[4.328981ms] org.apache.hudi.common.util.collection.DiskBasedMap:get()
                   +---[0.00122ms] org.apache.hudi.common.util.collection.DiskBasedMap:getRandomAccessFile()
                   `---[4.313586ms] org.apache.hudi.common.util.collection.DiskBasedMap:get()
                       `---[4.283509ms] org.apache.hudi.common.util.collection.DiskBasedMap:get()
                           +---[0.001169ms] org.apache.hudi.common.util.collection.DiskBasedMap$ValueMetadata:getOffsetOfValue()
                           +---[7.1E-4ms] java.lang.Long:longValue()
                           +---[6.97E-4ms] org.apache.hudi.common.util.collection.DiskBasedMap$ValueMetadata:getSizeOfValue()
                           +---[0.036483ms] org.apache.hudi.common.util.SpillableMapUtils:readBytesFromDisk()
                           `---[4.201996ms] org.apache.hudi.common.util.SerializationUtils:deserialize()
   
   ```
   
   ## Solution
   
   Use `kryo.setInstantiatorStrategy(new Kryo.DefaultInstantiatorStrategy(new StdInstantiatorStrategy()));`
   
   The overried method "SerializationUtils.KryoInstantiator.KryoBase#newInstantiator" will
called when each entry deserialized, but the only "Kryo#newInstantiator" be called when then
type doesn’t has a no-arg constructor.
   
   ![image](https://user-images.githubusercontent.com/20113411/75185416-0553d800-5781-11ea-9f8a-4f397037be4c.png)
   
   ![image](https://user-images.githubusercontent.com/20113411/75185484-274d5a80-5781-11ea-8161-0aab095a8f14.png)
   
   
   ## Verify this pull request
   
   Check the pr by steps in jira.
   
   ## Committer checklist
   
    - [X] Has a corresponding JIRA in PR title & commit
    
    - [X] Commit message is descriptive of the change
    
    - [ ] CI is green
   
    - [ ] Necessary doc changes done or have another open PR
          
    - [ ] For large changes, please consider breaking it into sub-tasks under an umbrella
JIRA.

----------------------------------------------------------------
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
 
For queries about this service, please contact Infrastructure at:
users@infra.apache.org


With regards,
Apache Git Services

Mime
View raw message