Kylin Real Time OLAP查询数据不准确问题定位解决全过程

最近团队正在调研Kylin Real Time OLAP (RT OLAP)模块，由于此模块社区还未发布稳定版，在调研过程中多多少少会踩坑，本文主要是对《通过Kylin查询的数据与ES查询的数据对不上》的问题，整个过程的排查、定位、解决思路的全过程进行记录，希望大家在遇见类似问题时可以有一些参考。

一、问题描述

通过 Kylin RT OLAP 创建了一个cube(rt_cube_test1),消费kafka中的数据，
kafka的数据同时也会写一份到ES中，但是用户随机抽取了一分钟的数据查询，发现Kylin 
中的与ES中的条数无法匹配上，时而Kylin多，时而ES多。

Kylin 中rt_cube_test1 cube 定义:

- **3个维度列:**
EVENTCODE（string）,
MINUTE_START(Kylin RT OLAP根据业务时间构建的字段),
HOUR_START(Kylin RT OLAP根据业务时间构建的字段),
- **1个度量列：**
 count

查询Kylin的SQL

select MINUTE_START, EVENTCODE as NAME, count(1) as CNT from TASK_SNAPSHOT  
where MINUTE_START >= '2019-09-27 21:48:00' and MINUTE_START<='2019-09-27 21:48:00'
and EVENTCODE = 'faceAntispam' 
group by MINUTE_START, EVENTCODE order by MINUTE_START desc

二、解决思路

Step 1、找到是ES还是Kylin的问题，最后确定为Kylin问题

由于目前的cube只有统计后的结果没有明细，所以咱们决定从新配置一个cube （==rt_cube_test2==），
加上两个明细字段（taskid 全局唯一，runtime 业务时间，kylin中的kafka 配置的timestamp字段也
为此字段）

Kylin 中rt_cube_test2 cube 定义:

- **5个维度列:**
TASKID（string）
RUNTIME(timestamp 也是kylin消费kafka的业务字段),
EVENTCODE（string）,
MINUTE_START(Kylin RT OLAP根据业务时间构建的字段),
HOUR_START(Kylin RT OLAP根据业务时间构建的字段),

- **1个度量列：**
 count

再次比对此Cube与ES中的数据，此时查询的SQL加上了刚刚添加的TASKID/RUNTIME两个维度列，发现Kylin 的查询结果，RUNTIME与MINUTE_START根本对不上，比如
runtime=2019-09-25 18:32:53确对应到了MINUTE_START=2019-09-25 18:33（实际应该是2019-09-25 18:32才是正确的）。

无法返回正确结果的SQL，叫做SQL_error1，后面会用到

select MINUTE_START, EVENTCODE as NAME, RUNTIME,  TASKID, count(1) as CNT from TASK_SNAPSHOT  
where MINUTE_START >= '2019-09-25 18:32:00' and MINUTE_START<='2019-09-25 18:33:00'
and EVENTCODE = 'faceAntispam' 
group by MINUTE_START, EVENTCODE, RUNTIME, TASKID order by RUNTIME desc

错误记录截图1：
PS:图中runtime还有个小问题，就是差了8小时时差，这个不在这里讨论，咱们只看分钟和秒。如

上面的截图中的错误还只能说明Kylin的结果肯定不对，但是ES是否正确，Kylin是否只有这个问题，
是否有多消费、少消费等问题还不确定，但是可以确定通过Kylin的minute_start圈定的某个
分钟的数据不仅包含自己分钟的，还可能包含上一分钟的，而自己这一分钟的数据也可能在后面
几个Minute_start出现。所以接下来我们把runtime限定到一分钟内，把minute_start扩大，
然后在与ES进行比对，此时发现可以与ES的结果100%匹配上，由此可以断定问题出在Kylin且
Kylin本身没有多和少消费，只是这个Minute_start有问题，导致最后结果错误。

查询SQL,通过原始时间RUNTIME定位10:32的数据，与ES能够100%匹配上。

select MINUTE_START, EVENTCODE as NAME, RUNTIME,  TASKID, count(1) as CNT from TASK_SNAPSHOT  
where MINUTE_START = '2019-09-25 18:32:00' and MINUTE_START<='2019-09-25 18:36:00'
and EVENTCODE = 'faceAntispam' 
and RUNTIME>='2019-09-27 10:32:00' and RUNTIME<'2019-09-27 10:33:00'
 group by MINUTE_START, EVENTCODE, RUNTIME, TASKID order by RUNTIME desc

Step 2、继续排查是Kylin哪部分问题（reciver查询/receiver存储/calcite等），最终确定为实时部分查询的问题

1、由于是minute_start的值不对，最开始我们怀疑是实时测的在通过runtime转换为
minute_start持久化到fsegment的时候有问题，详细看了下这块儿的代
码，觉
得唯一可能出现问题的地方就是dataformat.parse可能由于多线程并发导致的问题，
可是后来多次验证并非此处问题。

2、排除了存储侧，则再来看查询侧，定位到实时侧返回给calcite地方的代码是通过http调用的
receiver的一个DataController返回，此处已经经过了receiver端的过滤了，在这个地方设置上
断点，分别发送如下SQL1和SQL2进行查询，为了便于排查我们把runtime限定到某一秒。
发现SQL1和SQL2在此处返回的条数一样，此时咱们认为错误不在receiver端查询侧，则还
可能出现问题的地方只剩下calcite了，calcite将结果过滤掉了。

SQL1：可以返回正确的结果，与ES条数对上，且RUNTIME与MINUTE_START能够100%匹配上。

select MINUTE_START, EVENTCODE as NAME, RUNTIME,  TASKID, count(1) as CNT from TASK_SNAPSHOT  
where MINUTE_START >= '2019-09-25 18:32:00' and MINUTE_START<='2019-09-25 18:36:00'
and EVENTCODE = 'faceAntispam' 
and RUNTIME='2019-09-27 10:32:58'
group by MINUTE_START, EVENTCODE, RUNTIME, TASKID order by RUNTIME desc

SQL2：返回错误的结果，与ES条数对不上，且RUNTIME与MINUTE_START不能够100%匹配上。

select MINUTE_START, EVENTCODE as NAME, RUNTIME,  TASKID, count(1) as CNT from TASK_SNAPSHOT  
where MINUTE_START >= '2019-09-25 18:32:00' and MINUTE_START<='2019-09-25 18:36:00'
and EVENTCODE = 'faceAntispam' 
-- and RUNTIME='2019-09-27 10:32:58'
group by MINUTE_START, EVENTCODE, RUNTIME, TASKID order by RUNTIME desc

DataController.query方法源码

public DataResponse query(@RequestBody DataRequest dataRequest) {
        IStreamingSearchResult searchResult = null;
        String queryId = dataRequest.getQueryId();
        StreamingQueryProfile queryProfile = new StreamingQueryProfile(queryId, dataRequest.getRequestSendTime());
        if (dataRequest.isEnableDetailProfile()) {
            queryProfile.enableDetailProfile();
        }
        if (dataRequest.getStorageBehavior() != null) {
            queryProfile.setStorageBehavior(StorageSideBehavior.valueOf(dataRequest.getStorageBehavior()));
        }
        StreamingQueryProfile.set(queryProfile);
        logger.info("receive query request queryId:{}", queryId);
        try {
            final Stopwatch sw = new Stopwatch();
            sw.start();
            String cubeName = dataRequest.getCubeName();
            long minSegmentTime = dataRequest.getMinSegmentTime();
            KylinConfig kylinConfig = KylinConfig.getInstanceFromEnv();
            CubeDesc cubeDesc = CubeDescManager.getInstance(kylinConfig).getCubeDesc(cubeName);

            Set<FunctionDesc> metrics = convertMetrics(cubeDesc, dataRequest.getMetrics());
            byte[] tupleFilterBytes = Base64.decodeBase64(dataRequest.getTupleFilter());
            TupleFilter tupleFilter = TupleFilterSerializer.deserialize(tupleFilterBytes, StringCodeSystem.INSTANCE);

            TupleFilter havingFilter = null;
            if (dataRequest.getHavingFilter() != null) {
                byte[] havingFilterBytes = Base64.decodeBase64(dataRequest.getHavingFilter());
                havingFilter = TupleFilterSerializer.deserialize(havingFilterBytes, StringCodeSystem.INSTANCE);
            }

            Set<TblColRef> dimensions = convertToTblColRef(dataRequest.getDimensions(), cubeDesc);
            Set<TblColRef> groups = convertToTblColRef(dataRequest.getGroups(), cubeDesc);

            StreamingSegmentManager segmentManager = streamingServer.getStreamingSegmentManager(cubeName);
            StreamingCubeDataSearcher dataSearcher = segmentManager.getSearcher();

            StreamingSearchContext gtSearchRequest = new StreamingSearchContext(cubeDesc, dimensions, groups,
                    metrics, tupleFilter, havingFilter);
                    //调用receiver查询
            searchResult = dataSearcher.doSearch(gtSearchRequest, minSegmentTime,
                    dataRequest.isAllowStorageAggregation());

            if (StorageSideBehavior.RAW_SCAN == queryProfile.getStorageBehavior()) {
                long counter = 0;
                for (Record record : searchResult) {
                    counter ++;
                }
                logger.info("query-{}: scan {} rows", queryId, counter);
            }
            RecordsSerializer serializer = new RecordsSerializer(gtSearchRequest.getRespResultSchema());
            //序列化，满足条件的结果和条数在此处获得
            Pair<byte[], Long> serializedRowsInfo = serializer.serialize(searchResult.iterator(),
                    dataRequest.getStoragePushDownLimit());
            DataResponse dataResponse = new DataResponse();
            dataResponse.setData(Base64.encodeBase64String(serializedRowsInfo.getFirst()));
            sw.stop();
            logger.info("query-{}: return response, took {} ms", queryId, sw.elapsedMillis());
            //此次查询此receiver满足条件的条数，发现两个SQL返回的条数一致
            long finalCnt = serializedRowsInfo.getSecond();
            queryProfile.setFinalRows(finalCnt);
            String profileInfo = queryProfile.toString();
            dataResponse.setProfile(profileInfo);
            logger.info("query-{}: profile: {}", queryId, profileInfo);
            return dataResponse;
        } catch (Exception e) {
            throw new StreamingException(e);
        } finally {
            if (searchResult != null) {
                try {
                    searchResult.close();
                } catch (Exception e) {
                    logger.error("Fail to close result scanner, query id:" + queryId);
                }
            }
        }
    }

3、排查calcite，由于之前对calcite了解不多，咨询了社区如何debug calcite ，后来得知calcite没法
真正的debug（或许有，只是我目前还不知道咋整），但是可以把运行的代码打印出来。于是开
启calcite.debug（打印calcite动态生成的代码）

Kylin如何打印calcite代码，开启calcite.debug,启动jvm的地方
加上== -Dcalcite.debug=true==,
对应Kylin则在kylin.sh文件中添加，运行的代码会打印在kylin.out文件中

#修改kylin.sh中此处代码，添加-Dcalcite.debug=true
109     start_command="hbase ${KYLIN_EXTRA_START_OPTS} \
110     -Djava.util.logging.config.file=${tomcat_root}/conf/logging.properties \
111     -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager \
112     -Dlog4j.configuration=file:${KYLIN_HOME}/conf/kylin-server-log4j.properties \
113     -Dorg.apache.tomcat.util.buf.UDecoder.ALLOW_ENCODED_SLASH=true \
114     -Dorg.apache.catalina.connector.CoyoteAdapter.ALLOW_BACKSLASH=true \
115     -Djava.endorsed.dirs=${tomcat_root}/endorsed  \
116     -Dcatalina.base=${tomcat_root} \
117     -Dcatalina.home=${tomcat_root} \
118     -Djava.io.tmpdir=${tomcat_root}/temp  \
119     -Dkylin.hive.dependency=${hive_dependency} \
120     -Dkylin.hbase.dependency=${hbase_dependency} \
121     -Dkylin.kafka.dependency=${kafka_dependency} \
122     -Dkylin.spark.dependency=${spark_dependency} \
123     -Dkylin.hadoop.conf.dir=${kylin_hadoop_conf_dir} \
124     -Dkylin.server.host-address=${kylin_rest_address} \
125     -Dspring.profiles.active=${spring_profile} \
126     -agentlib:jdwp=transport=dt_socket,server=y,suspend=n,address=8032 \
127     -Dcalcite.debug=true \ ##添加此处代码
128     org.apache.hadoop.util.RunJar ${tomcat_root}/bin/bootstrap.jar  org.apache.catalina.startup.Bootstrap start"

每次查询后calcite中在Kylin.out文件中生成的源码日志内容

//由于内容太多，主要将核心的方法moveNext贴出来
/*  48 */           public boolean moveNext() {
/*  49 */             while (inputEnumerator.moveNext()) {
/*  50 */               final Object[] current = (Object[]) inputEnumerator.current();
/*  51 */               final Long inp36_ = (Long) current[36];
/*  52 */               final String inp4_ = current[4] == null ? (String) null : current[4].toString();
/*  53 */               final Long inp15_ = (Long) current[15];
																									   																																		  												 1569494181000
/*  54 */               if (inp36_ != null && inp36_ >= 1569522960000L && (inp36_ != null && inp36_ <= 1569522960000L) && (inp4_ != null && org.apache.calcite.runtime.SqlFunctions.eq(inp4_, "faceAntispam")) && (inp15_ != null && inp15_ > 1569494178000L) && (inp15_ != null && inp15_ < 1569494210000L)) {
/*  55 */                 return true;
/*  56 */               }
/*  57 */             }
/*  58 */             return false;
/*  59 */           }

比对了两个SQL生成的calcite文件，发现并无什么区别，除了查询条件外几乎一模一样。排除了calcite代码问题，再次陷入难题，由于calcite movenext这块儿的代码是动态生成，没法直接debug（或者我不知道），只能从调用calcite的地方开始着手。

4、定位kyliny传递给calcite的数据是否有问题.之前没有看过Kylin与calcite交互地方的代码，
于是加紧撸此处代码。

//kylin 下推到Hbase或者receiver 与 calcite连接的入口代码OLAPEnumerator.moveNext()方法：
@Override
    public boolean moveNext() {
        try {
            if (cursor == null) {
                cursor = queryStorage();//下推查询
            }

            if (!cursor.hasNext()) {
                return false;
            }

            ITuple tuple = cursor.next();//获取一条下推返回的记录
            if (tuple == null) {
                return false;
            }
            convertCurrentRow(tuple);//将记录映射成calicite需要的即我们查询的列和度量值
            return true;
        } catch (Exception e) {
            try {
                if (cursor != null) {
                    cursor.close();
                }
            } catch (Exception ee) {
                logger.info("Error when closing cursor, ignore it", ee);
            }
            throw e;
        }
    }

//OLAPEnumerator.convertCurrentRow

    private void convertCurrentRow(ITuple tuple) {
        // give calcite a new array every time, see details in KYLIN-2134
        Object[] values = tuple.getAllValues();
        current = Arrays.copyOf(values, values.length);//此处加断点debug，获取一条值的内容
    }

通过在OLAPEnumerator.convertCurrentRow方法加断点，分析一条记录的值，发现这条记录在此时返回的minute_start已经是个错误的值了与runtime对不上了。由于之前只看了DataController的条数是对的，但是没有看内容是否正确，于是接着去看DataController的内容是否正确。

5、继续回到receiver段，排查到底是什么地方导致了Minute_start的不正确，从DataController
开始看起，果然DataController的条数正确但是内容已经错了即Minute_start在此处就对
不上了，但是为啥条数能对上了？？？？与社区同学交流后，也觉得
不可思议，
彻底否定了咱们之前认为的calcite的问题。
后来再次查询错误的SQL发现能够得到正确的结果（原因是因为此时已经过了很久，数据
已经不再reciver端，已经存入到hbase了，再次说明数据落盘没
有问题）。
只能一层一层向上跟踪，开始怀疑是不是reciver的filter有问题，将错误的记录返回给了controller，
结果看了代码和debug发现没有问题；那
将每次从fsegment
中读取的每条满足条件的记录放入的时候是否有问题，发现就是个简单的put放入treemap,且
调用Put map的地方就一个，而且能向放里面放的数据都是满足条件的；那只能看是否是读取的
时候，进行序列化或反序列化是否有问题，后来分析代码发现也不是此处问题，只是取出数据的
操作。疯狂中......
没有招了，我在存入的treemap的地方加了断点，在取值的地方加了断点，
这个时候更邪门的事情发生了，放进去的值，在取出来的时候就变了。minute_start对
不上，其他的几列都能对上。

//FragmentSearchResult.java
        @Override
        public Iterator<Record> iterator() {
            if (hasAggregation()) {
                while (sourceRecords.hasNext()) {
                //从fsegment中获取的一条记录给到rwaRecord
                    RawRecord rawRecord = sourceRecords.next();
                    if (filter != null && !satisfyFilter(rawRecord)) {//判断是否满足条件
                        filterRowCnt ++;
                    } else {
                    	//满足条件的记录放入缓存，其实是放入了一个treemap
                        aggrCache.aggregate(rawRecord);
                    }
                }
                return aggrCache.iterator();//迭代的就是刚刚放入的treemap
            } else {
                return transformAndFilterRecords();
            }
        }

//aggrCache.iterator()实际调用的为此处的代码，即获取值进行处理，在向上返回给datacontroller
public Iterator<Record> iterator() {
                Iterator<Entry<byte[][], MeasureAggregator[]>> it = aggBufMap.entrySet().iterator();//aggBufMap就是那个treemap

                final Iterator<Entry<byte[][], MeasureAggregator[]>> input = it;

                return new Iterator<Record>() {

                    final Record oneRecord = new Record(schema.getDimensionCount(), schema.getMetricsCount());
                    Entry<byte[][], MeasureAggregator[]> returningEntry = null;
                    final HavingFilterChecker havingFilterChecker = (havingFilter == null) ? null
                            : new HavingFilterChecker(havingFilter, schema);

                    @Override
                    public boolean hasNext() {
                        while (returningEntry == null && input.hasNext()) {
                            returningEntry = input.next();
                            if (havingFilterChecker != null) {
                                if (!havingFilterChecker.check(returningEntry.getValue())) {
                                    returningEntry = null;
                                }
                            }
                        }
                        return returningEntry != null;
                    }

                    @Override
                    public Record next() {
                        byte[][] rawDimVals = returningEntry.getKey();//
                        for (int i = 0; i < rawDimVals.length; i++) {
                            oneRecord.setDimension(i, recordDecoder.decodeDimension(i, rawDimVals[i]));
                        }
                        MeasureAggregator[] measures = returningEntry.getValue();
                        for (int i = 0; i < measures.length; i++) {
                            oneRecord.setMetric(i, measures[i].getState());
                        }
                        finalRowCnt ++;
                        returningEntry = null;
                        return oneRecord;//此时发现oneRecord的内容就不对了
                    }

                    @Override
                    public void remove() {
                        throw new UnsupportedOperationException();
                    }
                };
            }

此处好几个iterator，代码比较绕，但是理清楚了大概就是receiver读fsegment的数据，然后一条一条的过滤，将满足条件的放入一个treemap中，全部遍历完了后，在从这个treemap中一一取出数据进行一些聚合操作和反序列化，但是奇怪的是这个treemap放入的内容和取出的内容尽然不一样（条数能对上，其他维度列大概也能对上，就是minute_start对不上，比如放入时是2019-09-25 10:32 ,取出来就变成了2019-09-25 10:33了），真实邪门了，只能感觉是多线程或者转换出了问题，可是多线程如果有问题那么条数肯定也对不上（实际条数能对上），难道转换问题（仔细撸了代码就只有序列化和反序列，没有其他转换啊，序列化、反序列化也没有反人类的操作啊）…

6、虽然不知道啥问题，但是至少范围已经锁定很小了，从fsegment读没有问题，将记录放
入treemap没有问题，获取没有问题，问题在放入和获取之间的故事。决定叫上我们一
个非常资深的java 大牛（建丹同学）一起排查，我和他来来回回看了好几遍从放入到
取出的代码，分析了整个流程，发现过程很简单没有问题啊......
于是我们开始了从放入到取出的debug之旅，过程很艰难，此处只写其中重要的步骤。

1、既然map中最终的值变化了，那么肯定是有地方放入了，我们在唯一可以put的地方加上了条件判断断点，很遗憾放入的值全部符合条件，没有出现放入非法值的情况；

2、map刚放完一条记录，看一下Map中的此条记录结果是否正确，因为有debug，所以此条记录正确（稍后解释）；

3、整个map放完记录，不在放入的地方设置debug，放完后即刻查看map中的内容，发现此时记录就不正确了。（见鬼了，放进去都符合预期，放完了肉眼看没有做任何操作就不对了，难道treemap有bug？实际treemap没有bug）；

4、后来我们实在没有办法了，只能对可能出现问题的地方一行一行的代码提出疑问（比如new treemap的地方采用的是谷歌的Maps.newTreeMap(bytesComparator);创建，看看此处代码是否有问题），后来我们看到从treemap中取出每条记录时调用将记录又赋值给了另一个对象，发现用的System.arraycopy，这个可不是deep copy，猜测可能这里有问题，但是看了下代码这个dimVals也是每次一个新的啊，另外要有问题其他3列也应该有问题为啥就minute_start有问题啊，无法解释。不过这个地方肯定有问题，只是我们不知道为啥会引起，但是整个过程肯定与System.arraycopy有关。（总算有了一点进展了）：

   byte[][] dimVals = r.getDimensions();//从map中取出一条记录，其实此时记录已经不对了
                byte[][] metricsVals = r.getMetrics();
                MeasureAggregator[] aggrs = aggBufMap.get(dimVals);
                if (aggrs == null) {
                    //for storage push down limit
                    if (aggBufMap.size() >= pushDownLimit) {
                        return false;
                    }
                    byte[][] copyDimVals = new byte[schema.getDimensionCount()][];
                    System.arraycopy(dimVals, 0, copyDimVals, 0, dimVals.length);//将dimVals的值复制给copyDimVals中，罪魁祸首
                    aggrs = newAggregators();
                    aggBufMap.put(copyDimVals, aggrs);
                }

5、虽然不知道咋回事，但是给了我们思路，肯定是System.arraycopy导致的，于是我们再次在put到map的时候设置断点，记录下某条数据的内存地址，在全部Put完后，在通过taskId在这个map中找到此条记录的地址，比对发现前后地址一模一样，但是内容已经改变且不是通过put正常调用改变的。问题已经很显然了，由于在赋值的时候采用的是System.arraycopy（浅拷贝，二维数组的第二维存放的是一个地址），这个地址在后续又被其他地方放入了新的值，导致里面的值在后面的记录中被替换了。于是重点排查放入map中的对象RawRecord。

//FragmentSearchResult.java

        @Override
        public Iterator<Record> iterator() {
            if (hasAggregation()) {
                while (sourceRecords.hasNext()) {
                    RawRecord rawRecord = sourceRecords.next();//看了RawRecord的源码，发现里面有clone和copy方法里面都用到了System.arraycopy，，问题就出在此处，于是把RawRecord的clone和copy方法改为deep clone
                    if (filter != null && !satisfyFilter(rawRecord)) {
                        filterRowCnt ++;
                    } else {
                        aggrCache.aggregate(rawRecord);//放进去的全部合法
                    }
                }
                return aggrCache.iterator();//此时看值就变了
            } else {
                return transformAndFilterRecords();
            }
        }

发现RawRecord中的copy和clone方法均为System.arraycopy，但是每次这个对象为new的，还是没有找到到底哪个地方会再次改变这个地址的值，只能先修改代码验证咱们的推论是否正确。将RawRecord中的copy和clone方法中的System.arraycopy改为深度拷贝、将aggregrate方法中放入treemap地方的System.arraycopy改为深度拷贝，具体修改代码如下：

//修改后的RawRecord clone和copy方法

public void copy(RawRecord another) {
        if (another.getDimensions().length != dimensions.length || another.getMetrics().length != metrics.length) {
            throw new IllegalStateException("cannot copy record with different schema");
        }
        //修改后的deep clone
        for(int i=0;i<another.dimensions.length;i++){
            this.dimensions[i] = new byte[another.dimensions[i].length];
            System.arraycopy(another.dimensions[i], 0, this.dimensions[i], 0, another.dimensions[i].length);
        }

        for(int i=0;i<another.metrics.length;i++){
            this.metrics[i]=new byte[another.metrics[i].length];
            System.arraycopy(another.metrics[i], 0, this.metrics[i], 0, another.metrics[i].length);
        }
        //System.arraycopy(another.dimensions, 0, this.dimensions, 0, another.dimensions.length);//有问题的代码，多维数组此种方式并发deep clone
        //System.arraycopy(another.metrics, 0, this.metrics, 0, another.metrics.length);//有问题的代码，多维数组此种方式并发deep clone
    }

    public RawRecord clone() {
        RawRecord rawRecord = new RawRecord(dimensions.length, metrics.length);
        for(int i=0;i<dimensions.length;i++){
            rawRecord.dimensions[i]=new byte[dimensions[i].length];
            System.arraycopy(dimensions[i], 0, rawRecord.dimensions[i], 0, dimensions[i].length);
        }

        for(int i=0;i<metrics.length;i++){
            rawRecord.metrics[i]=new byte[metrics[i].length];
            System.arraycopy(metrics[i], 0, rawRecord.metrics[i], 0, metrics[i].length);
        }
        //System.arraycopy(dimensions, 0, rawRecord.dimensions, 0, dimensions.length);//有问题的代码，多维数组此种方式并发deep clone
        //System.arraycopy(metrics, 0, rawRecord.metrics, 0, metrics.length);//有问题的代码，多维数组此种方式并发deep clone
        return rawRecord;
    }

//修改获取map中的赋值操作，也改成deep clone

            public boolean aggregate(RawRecord r) {
                byte[][] dimVals = r.getDimensions();
                byte[][] metricsVals = r.getMetrics();
                MeasureAggregator[] aggrs = aggBufMap.get(dimVals);
                if (aggrs == null) {
                    //for storage push down limit
                    if (aggBufMap.size() >= pushDownLimit) {
                        return false;
                    }
                    byte[][] copyDimVals = new byte[schema.getDimensionCount()][];
                    //改为deep clone
                    for(int i=0;i<dimVals.length;i++){
                        copyDimVals[i] = new byte[dimVals[i].length];
                        System.arraycopy(dimVals[i], 0, copyDimVals[i], 0, dimVals[i].length);
                    }
                    //System.arraycopy(dimVals, 0, copyDimVals, 0, dimVals.length);//有问题的代码，多维数组此种方式并发deep clone
                    aggrs = newAggregators();
                    aggBufMap.put(copyDimVals, aggrs);
                }
                for (int i = 0; i < aggrs.length; i++) {
                    Object metrics = recordDecoder.decodeMetrics(i, metricsVals[i]);
                    aggrs[i].aggregate(metrics);
                }
                return true;
            }

打包重启，发现问题解决了。。。。，虽然问题解决了，验证了咱们猜想正确（由于system.arrycopy导致），但是咱们还是没有找到到底哪个地方重新赋值操作了。由于整个验证完已经很晚了，决定明天继续追踪找到重新赋值的地方。

找到重新赋值的地方：
小结：
1、到目前为止已经明确出问题的地方在，获取到数据在放入到结果treemap之间的代码有问题，即如下代码；
//FragmentSearchResult.java

        @Override
        public Iterator<Record> iterator() {
            if (hasAggregation()) {
                while (sourceRecords.hasNext()) {
                    RawRecord rawRecord = sourceRecords.next();
                    if (filter != null && !satisfyFilter(rawRecord)) {
                        filterRowCnt ++;
                    } else {
                        aggrCache.aggregate(rawRecord);
                    }
                }
                return aggrCache.iterator();
            } else {
                return transformAndFilterRecords();
            }
        }

2、与system.arrycopy浅拷贝有关；

排查：
一步一步追踪变化的值(treemap的key即维度值)的来源，采用倒推的方式，treemap.key——>RawRecord.dimissions——>FragmentCuboidReader.iterator()|FragmentCuboidReader.read()——>(ColumnDataReader)dimensionDataReaders.iterator(),ColumnDataReader有多个实现类（由于之前跟踪的时候以为真正用到只有LZ4CompressedColumnDataItr，实际还有RunLengthCompressedColumnReader，有问题的正是RunLengthCompressedColumnReader中每次给readerbuffer都是给到同一个对象的）：

• LZ4CompressedColumnDataItr.iterator()——>LZ4CompressedColumnDataItr.next()——>readBuffer(此处的readBuffer每次都是new byte[valLen]，应该不会有问题)；
• RunLengthCompressedColumnReader——>RunLengthCompressedColumnReader.read()——>readBuffer(此处的readBuffer并没有重新构建而是作为了RunLengthCompressedColumnReader的成员变量，这就是出问题的地方：第一条记录获取到值存入这个内存地址，然后放入treemap(浅拷贝)，然后第二条记录来的时候放入新的值即改变这个地址中存放的值，所以treemap中的值也改变了)；

这同时也解决了之前的一个疑问，4个维度列，为什么system.arrycopy只影响了minute_start那一列，既然都是浅拷贝，应该所有维度列包括度量都有问题，实际是因为只有minute_start这一列采用的是RunLengthCompressedColumnReader，其他3列为LZ4CompressedColumnDataItr,LZ4的实现就算是浅拷贝也没有问题；

三、总结

至此此问题告一段落，查询不准确的根本原因为minute_start列从磁盘或者内存中读取时使用的是RunLengthCompressedColumnReader类，此类中的read方法实现，每次读取一条数据的内容直接赋值给了同一个成员变量readbuffer，kylin在将这些值放到treemap中的时候又是使用的浅拷贝（system.arrycopy），导致放进去的数据的内容实际会被后面新读取到记录覆盖更新，导致最终minute_start的值已经不再是最初放进去的值，而是被后面的值覆盖了,错误的值传给query server再经过calcite过滤（由于minute_start的部分值已经是非法值了，则这部分记录将被被过滤掉），这就是导致最终条数不一致的原因，同时如果满足calcite条件并返回了部分记录，这些记录的内容也可能会是错误的（minute_start与业务时间runtime对不上）。

修改代码已经提交给社区: https://github.com/apache/kylin/pull/867。

同时感谢社区和建丹同学给与的帮助；过程很痛苦，但也很享受这个过程，彻底看了一篇Kylin整个实时查询的代码逻辑，查询地方的实现还是比较复杂的，借此整理一下整个receiver端的查询逻辑（kylin rt olap receiver查询源码分析）。