· 9 years ago · Jan 20, 2017, 11:02 AM
1CREATE KEYSPACE IF NOT EXISTS import_test WITH REPLICATION =
2{ 'class' : 'SimpleStrategy', 'replication_factor' : 1 };
3
4CREATE TABLE transactional_data (
5 job varchar,
6 client varchar,
7 run int,
8 chunk int,
9 mdh_id uuid,
10 gtin varchar,
11 sender varchar,
12 receiver varchar,
13 quantity int,
14 ta_id varchar,
15 type varchar,
16 ts timestamp,
17 add_info map<text, text>,
18 PRIMARY KEY ((job, client, run, chunk), mdh_id));
19
20java -ea -javaagent:./../lib/jamm-0.3.0.jar -XX:+CMSClassUnloadingEnabled -XX:+UseThreadPriorities -XX:ThreadPriorityPolicy=42 -Xms4G -Xmx4G -Xmn800M -XX:+HeapDumpOnOutOfMemoryError -Xss256k -XX:StringTableSize=1000003 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:+CMSParallelRemarkEnabled -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=1 -XX:CMSInitiatingOccupancyFraction=75 -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseTLAB -XX:+PerfDisableSharedMem -XX:CompileCommandFile=./../conf/hotspot_compiler -XX:CMSWaitDuration=10000 -XX:+CMSParallelInitialMarkEnabled -XX:+CMSEdenChunksRecordAlways -XX:CMSWaitDuration=10000 -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -XX:+PrintTenuringDistribution -XX:+PrintGCApplicationStoppedTime -XX:+PrintPromotionFailure -Xloggc:./../logs/gc.log -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=10M -Djava.net.preferIPv4Stack=true -Dcassandra.jmx.local.port=7199 -XX:+DisableExplicitGC
21
22int chunks = 1053; // chunk size is known
23List<List<TransactionalData>> resultLists = new ArrayList<>(chunks);
24
25for (int chunk = 1; chunk <= chunks; chunk++) {
26 Select select = QueryBuilder.select().from(TABLE_TRANSACTIONAL_DATA);
27 select.where(QueryBuilder.eq(CASSANDRA_COLUMN_JOB, jobId))
28 .and(QueryBuilder.eq(CASSANDRA_COLUMN_CLIENT, clientId))
29 .and(QueryBuilder.eq(CASSANDRA_COLUMN_RUN, run))
30 .and(QueryBuilder.eq(CASSANDRA_COLUMN_CHUNK, chunk));
31
32 StopWatch s = new StopWatch();
33 s.start();
34 List<TransactionalData> result = cassandraOperations.select(select, TransactionalData.class);
35 s.stop();
36 log.info("query [" + jobId + ", " + clientId + ", " + run + ", " + chunk + "] returned " + result.size() + " results in " + s.getTotalTimeMillis() + " ms");
37 resultLists.add(result);
38}
39
4020:09:26.380 INFO ExportServiceImpl: query [initial, RM, 1, 1] returned 7700 results in 293 ms
41[multiple reads between 300 - 400ms]
4220:09:40.922 INFO ExportServiceImpl: query [initial, RM, 1, 36] returned 7700 results in 1160 ms
43[multiple reads between 300 - 400ms]
4420:09:51.785 INFO ExportServiceImpl: query [initial, RM, 1, 64] returned 7700 results in 1701 ms
45[multiple reads between 300 - 400ms]
4620:10:05.583 INFO ExportServiceImpl: query [initial, RM, 1, 97] returned 7700 results in 2476 ms
47[multiple reads between 300 - 600ms]
4820:11:00.956 INFO ExportServiceImpl: query [initial, RM, 1, 230] returned 7700 results in 3615 ms
49[multiple reads between 300 - 3000ms and suddenly behaviour collapses]
5020:11:17.707 INFO ExportServiceImpl: query [initial, RM, 1, 276] returned 7700 results in 370 ms
5120:11:23.398 INFO ExportServiceImpl: query [initial, RM, 1, 277] returned 7700 results in 5691 ms
5220:11:23.717 INFO ExportServiceImpl: query [initial, RM, 1, 278] returned 7700 results in 319 ms
5320:11:24.033 INFO ExportServiceImpl: query [initial, RM, 1, 279] returned 7700 results in 316 ms
5420:11:27.289 INFO ExportServiceImpl: query [initial, RM, 1, 280] returned 7700 results in 3256 ms
5520:11:27.607 INFO ExportServiceImpl: query [initial, RM, 1, 281] returned 7700 results in 318 ms
5620:11:30.380 INFO ExportServiceImpl: query [initial, RM, 1, 282] returned 7700 results in 2773 ms
5720:11:30.669 INFO ExportServiceImpl: query [initial, RM, 1, 283] returned 7700 results in 288 ms
58[multiple reads time increases up to 10000ms each read]
5920:13:55.341 INFO ExportServiceImpl: query [initial, RM, 1, 323] returned 7700 results in 13813 ms
6020:14:09.200 INFO ExportServiceImpl: query [initial, RM, 1, 324] returned 7700 results in 13859 ms
6120:14:32.799 INFO ExportServiceImpl: query [initial, RM, 1, 325] returned 7700 results in 23599 ms
6220:15:05.796 INFO ExportServiceImpl: query [initial, RM, 1, 326] returned 7700 results in 32997 ms
63
64java.lang.OutOfMemoryError: GC overhead limit exceeded
65
66 at java.lang.reflect.Proxy.newProxyInstance(Proxy.java:710)
67 at org.springframework.core.annotation.AnnotationUtils.synthesizeAnnotation(AnnotationUtils.java:1503)
68 at org.springframework.core.annotation.AnnotatedElementUtils.findMergedAnnotation(AnnotatedElementUtils.java:731)
69 at org.springframework.data.cassandra.mapping.BasicCassandraPersistentProperty.isCompositePrimaryKey(BasicCassandraPersistentProperty.java:109)
70 at org.springframework.data.cassandra.mapping.BasicCassandraPersistentProperty.getCompositePrimaryKeyType(BasicCassandraPersistentProperty.java:113)
71 at org.springframework.data.cassandra.mapping.BasicCassandraPersistentProperty.getCompositePrimaryKeyTypeInformation(BasicCassandraPersistentProperty.java:118)
72 at org.springframework.data.cassandra.mapping.BasicCassandraPersistentProperty.getCompositePrimaryKeyEntity(BasicCassandraPersistentProperty.java:394)
73 at org.springframework.data.cassandra.convert.MappingCassandraConverter.readPropertyFromRow(MappingCassandraConverter.java:164)
74 at org.springframework.data.cassandra.convert.MappingCassandraConverter$1.doWithPersistentProperty(MappingCassandraConverter.java:148)
75 at org.springframework.data.cassandra.convert.MappingCassandraConverter$1.doWithPersistentProperty(MappingCassandraConverter.java:143)
76 at org.springframework.data.mapping.model.BasicPersistentEntity.doWithProperties(BasicPersistentEntity.java:322)
77 at org.springframework.data.cassandra.convert.MappingCassandraConverter.readPropertiesFromRow(MappingCassandraConverter.java:143)
78 at org.springframework.data.cassandra.convert.MappingCassandraConverter.readEntityFromRow(MappingCassandraConverter.java:135)
79 at org.springframework.data.cassandra.convert.MappingCassandraConverter.readRow(MappingCassandraConverter.java:115)
80 at org.springframework.data.cassandra.convert.MappingCassandraConverter.read(MappingCassandraConverter.java:200)
81 at org.springframework.data.cassandra.core.CassandraConverterRowCallback.doWith(CassandraConverterRowCallback.java:47)
82 at org.springframework.data.cassandra.core.CassandraTemplate.select(CassandraTemplate.java:587)
83 at org.springframework.data.cassandra.core.CassandraTemplate.select(CassandraTemplate.java:354)
84 at AbstractExportService.exportData(AbstractExportService.java:79)
85 at ExportServiceImpl.exportData(ExportServiceImpl.java:33)
86 at ExportServiceImplTest.exportData(ExportServiceImplTest.java:37)
87 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
88 at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
89 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
90 at java.lang.reflect.Method.invoke(Method.java:498)
91 at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
92 at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
93 at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
94 at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
95 at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75)
96 at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86)
97 at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84)
98
9919:55:36,960 GCInspector.java:284 - ParNew GC in 715ms. CMS Old Gen: 2008935960 -> 2008954320; Par Eden Space: 671088640 -> 0; Par Survivor Space: 13605416 -> 16345128
10019:55:36,967 StatusLogger.java:52 - Pool Name Active Pending Completed Blocked All Time Blocked
10119:55:37,069 StatusLogger.java:56 - MutationStage 0 0 8321004 0 0
10219:55:37,070 StatusLogger.java:56 - ReadStage 0 0 256399 0 0
10319:55:37,071 StatusLogger.java:56 - RequestResponseStage 0 0 17 0 0
10419:55:37,080 StatusLogger.java:56 - ReadRepairStage 0 0 0 0 0
10519:55:37,081 StatusLogger.java:56 - CounterMutationStage 0 0 0 0 0
10619:55:37,083 StatusLogger.java:56 - HintedHandoff 0 0 0 0 0
10719:55:37,084 StatusLogger.java:56 - MiscStage 0 0 0 0 0
10819:55:37,085 StatusLogger.java:56 - CompactionExecutor 0 0 61989 0 0
10919:55:37,086 StatusLogger.java:56 - MemtableReclaimMemory 0 0 331 0 0
11019:55:37,087 StatusLogger.java:56 - PendingRangeCalculator 0 0 1 0 0
11119:55:37,088 StatusLogger.java:56 - GossipStage 0 0 0 0 0
11219:55:37,089 StatusLogger.java:56 - MigrationStage 0 0 17 0 0
11319:55:37,092 StatusLogger.java:56 - MemtablePostFlush 0 0 2387 0 0
11419:55:37,095 StatusLogger.java:56 - ValidationExecutor 0 0 0 0 0
11519:55:37,097 StatusLogger.java:56 - Sampler 0 0 0 0 0
11619:55:37,099 StatusLogger.java:56 - MemtableFlushWriter 0 0 331 0 0
11719:55:37,099 StatusLogger.java:56 - InternalResponseStage 0 0 0 0 0
11819:55:37,100 StatusLogger.java:56 - AntiEntropyStage 0 0 0 0 0
11919:55:37,102 StatusLogger.java:56 - CacheCleanupExecutor 0 0 0 0 0
12019:55:37,102 StatusLogger.java:56 - Native-Transport-Requests 1 0 8356278 0 306061
12119:55:37,116 StatusLogger.java:66 - CompactionManager 0 0
12219:55:37,122 StatusLogger.java:78 - MessagingService n/a 0/0
12319:55:37,122 StatusLogger.java:88 - Cache Type Size Capacity KeysToSave
12419:55:37,126 StatusLogger.java:90 - KeyCache 50823767 104857600 all
12519:55:37,126 StatusLogger.java:96 - RowCache 0 0 all
12619:55:37,126 StatusLogger.java:103 - Table Memtable ops,data
12719:55:37,144 StatusLogger.java:106 - system_distributed.parent_repair_history 0,0
12819:55:37,144 StatusLogger.java:106 - system_distributed.repair_history 0,0
12919:55:37,144 StatusLogger.java:106 - import_test.transactional_data 1199451,37053335
13019:55:37,144 StatusLogger.java:106 - system.compaction_history 9,246
13119:55:37,144 StatusLogger.java:106 - system.hints 0,0
13219:55:37,144 StatusLogger.java:106 - system.schema_aggregates 0,0
13319:55:37,144 StatusLogger.java:106 - system.IndexInfo 0,0
13419:55:37,145 StatusLogger.java:106 - system.schema_columnfamilies 0,0
13519:55:37,145 StatusLogger.java:106 - system.schema_triggers 0,0
13619:55:37,145 StatusLogger.java:106 - system.schema_functions 0,0
13719:55:37,145 StatusLogger.java:106 - system.size_estimates 520,3162
13819:55:37,146 StatusLogger.java:106 - system.paxos 0,0
13919:55:37,146 StatusLogger.java:106 - system.peer_events 0,0
14019:55:37,146 StatusLogger.java:106 - system.range_xfers 0,0
14119:55:37,146 StatusLogger.java:106 - system.compactions_in_progress 0,0
14219:55:37,146 StatusLogger.java:106 - system.peers 0,0
14319:55:37,146 StatusLogger.java:106 - system.schema_keyspaces 0,0
14419:55:37,146 StatusLogger.java:106 - system.schema_usertypes 0,0
14519:55:37,146 StatusLogger.java:106 - system.local 0,0
14619:55:37,146 StatusLogger.java:106 - system.sstable_activity 418,1545
14719:55:37,146 StatusLogger.java:106 - system.schema_columns 0,0
14819:55:37,146 StatusLogger.java:106 - system.batchlog 0,0
14919:55:37,147 StatusLogger.java:106 - system.available_ranges 0,0
15019:55:37,147 StatusLogger.java:106 - system_auth.roles 0,0
15119:55:37,147 StatusLogger.java:106 - system_auth.role_members 0,0
15219:55:37,147 StatusLogger.java:106 - system_auth.resource_role_permissons_index 0,0
15319:55:37,147 StatusLogger.java:106 - system_auth.role_permissions 0,0
15419:55:37,147 StatusLogger.java:106 - system_traces.sessions 0,0
15519:55:37,148 StatusLogger.java:106 - system_traces.events 0,0
15620:14:32,062 Memtable.java:352 - Writing Memtable-sstable_activity@1527249591(1.509KiB serialized bytes, 616 ops, 0%/0% of on/off-heap limit)
15720:14:32,062 Memtable.java:352 - Writing Memtable-size_estimates@907520469(3.088KiB serialized bytes, 780 ops, 0%/0% of on/off-heap limit)
15820:14:32,128 Memtable.java:352 - Writing Memtable-compaction_history@173198051(0.240KiB serialized bytes, 9 ops, 0%/0% of on/off-heap limit)
159
1602017-01-19T20:11:10.127+0100: 117198.441: Total time for which application threads were stopped: 0.0020544 seconds, Stopping threads took: 0.0009831 seconds
161{Heap before GC invocations=7026 (full 16):
162 par new generation total 737280K, used 664609K [0x00000006c0000000, 0x00000006f2000000, 0x00000006f2000000)
163 eden space 655360K, 100% used [0x00000006c0000000, 0x00000006e8000000, 0x00000006e8000000)
164 from space 81920K, 11% used [0x00000006ed000000, 0x00000006ed908710, 0x00000006f2000000)
165 to space 81920K, 0% used [0x00000006e8000000, 0x00000006e8000000, 0x00000006ed000000)
166 concurrent mark-sweep generation total 3375104K, used 1965475K [0x00000006f2000000, 0x00000007c0000000, 0x00000007c0000000)
167 Metaspace used 34481K, capacity 34783K, committed 35184K, reserved 1081344K
168 class space used 3678K, capacity 3772K, committed 3808K, reserved 1048576K
1692017-01-19T20:11:12.390+0100: 117200.704: [GC (Allocation Failure) 2017-01-19T20:11:12.390+0100: 117200.704: [ParNew
170Desired survivor size 41943040 bytes, new threshold 1 (max 1)
171- age 1: 4114136 bytes, 4114136 total
172: 664609K->7031K(737280K), 0.0122370 secs] 2630084K->1972513K(4112384K), 0.0123827 secs] [Times: user=0.03 sys=0.01, real=0.01 secs]
173Heap after GC invocations=7027 (full 16):
174 par new generation total 737280K, used 7031K [0x00000006c0000000, 0x00000006f2000000, 0x00000006f2000000)
175 eden space 655360K, 0% used [0x00000006c0000000, 0x00000006c0000000, 0x00000006e8000000)
176 from space 81920K, 8% used [0x00000006e8000000, 0x00000006e86ddfe8, 0x00000006ed000000)
177 to space 81920K, 0% used [0x00000006ed000000, 0x00000006ed000000, 0x00000006f2000000)
178 concurrent mark-sweep generation total 3375104K, used 1965481K [0x00000006f2000000, 0x00000007c0000000, 0x00000007c0000000)
179 Metaspace used 34481K, capacity 34783K, committed 35184K, reserved 1081344K
180 class space used 3678K, capacity 3772K, committed 3808K, reserved 1048576K
181}
1822017-01-19T20:11:17.399+0100: 117205.714: Total time for which application threads were stopped: 0.0274807 seconds, Stopping threads took: 0.0002973 seconds
183{Heap before GC invocations=7028 (full 16):
184 par new generation total 737280K, used 670595K [0x00000006c0000000, 0x00000006f2000000, 0x00000006f2000000)
185 eden space 655360K, 100% used [0x00000006c0000000, 0x00000006e8000000, 0x00000006e8000000)
186 from space 81920K, 18% used [0x00000006ed000000, 0x00000006edee0c40, 0x00000006f2000000)
187 to space 81920K, 0% used [0x00000006e8000000, 0x00000006e8000000, 0x00000006ed000000)
188 concurrent mark-sweep generation total 3375104K, used 1965487K [0x00000006f2000000, 0x00000007c0000000, 0x00000007c0000000)
189 Metaspace used 34481K, capacity 34783K, committed 35184K, reserved 1081344K
190 class space used 3678K, capacity 3772K, committed 3808K, reserved 1048576K
1912017-01-19T20:11:39.887+0100: 117228.201: [GC (Allocation Failure) 2017-01-19T20:11:39.887+0100: 117228.201: [ParNew
192Desired survivor size 41943040 bytes, new threshold 1 (max 1)
193- age 1: 4632832 bytes, 4632832 total
194: 670595K->11530K(737280K), 0.0211463 secs] 2636082K->1977022K(4112384K), 0.0212837 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
195Heap after GC invocations=7029 (full 16):
196 par new generation total 737280K, used 11530K [0x00000006c0000000, 0x00000006f2000000, 0x00000006f2000000)
197 eden space 655360K, 0% used [0x00000006c0000000, 0x00000006c0000000, 0x00000006e8000000)
198 from space 81920K, 14% used [0x00000006e8000000, 0x00000006e8b428b0, 0x00000006ed000000)
199 to space 81920K, 0% used [0x00000006ed000000, 0x00000006ed000000, 0x00000006f2000000)
200 concurrent mark-sweep generation total 3375104K, used 1965491K [0x00000006f2000000, 0x00000007c0000000, 0x00000007c0000000)
201 Metaspace used 34481K, capacity 34783K, committed 35184K, reserved 1081344K
202 class space used 3678K, capacity 3772K, committed 3808K, reserved 1048576K
203}
2042017-01-19T20:12:10.131+0100: 117258.445: Total time for which application threads were stopped: 0.0005586 seconds, Stopping threads took: 0.0002172 seconds
205{Heap before GC invocations=7030 (full 16):
206 par new generation total 737280K, used 664725K [0x00000006c0000000, 0x00000006f2000000, 0x00000006f2000000)
207 eden space 655360K, 100% used [0x00000006c0000000, 0x00000006e8000000, 0x00000006e8000000)
208 from space 81920K, 11% used [0x00000006ed000000, 0x00000006ed925448, 0x00000006f2000000)
209 to space 81920K, 0% used [0x00000006e8000000, 0x00000006e8000000, 0x00000006ed000000)
210 concurrent mark-sweep generation total 3375104K, used 1965495K [0x00000006f2000000, 0x00000007c0000000, 0x00000007c0000000)
211 Metaspace used 34481K, capacity 34783K, committed 35184K, reserved 1081344K
212 class space used 3678K, capacity 3772K, committed 3808K, reserved 1048576K
2132017-01-19T20:12:42.762+0100: 117291.077: [GC (Allocation Failure) 2017-01-19T20:12:42.762+0100: 117291.077: [ParNew
214Desired survivor size 41943040 bytes, new threshold 1 (max 1)
215- age 1: 15961696 bytes, 15961696 total
216: 664725K->19181K(737280K), 0.0197058 secs] 2630220K->1984679K(4112384K), 0.0198265 secs] [Times: user=0.05 sys=0.01, real=0.02 secs]
217Heap after GC invocations=7031 (full 16):
218 par new generation total 737280K, used 19181K [0x00000006c0000000, 0x00000006f2000000, 0x00000006f2000000)
219 eden space 655360K, 0% used [0x00000006c0000000, 0x00000006c0000000, 0x00000006e8000000)
220 from space 81920K, 23% used [0x00000006e8000000, 0x00000006e92bb500, 0x00000006ed000000)
221 to space 81920K, 0% used [0x00000006ed000000, 0x00000006ed000000, 0x00000006f2000000)
222 concurrent mark-sweep generation total 3375104K, used 1965498K [0x00000006f2000000, 0x00000007c0000000, 0x00000007c0000000)
223 Metaspace used 34481K, capacity 34783K, committed 35184K, reserved 1081344K
224 class space used 3678K, capacity 3772K, committed 3808K, reserved 1048576K
225}
2262017-01-19T20:13:13.099+0100: 117321.413: Total time for which application threads were stopped: 0.0003673 seconds, Stopping threads took: 0.0000710 seconds
227
22820:14:03,669 SliceQueryPager.java:92 - Querying next page of slice query; new filter: SliceQueryFilter [reversed=false, slices=[[0010a7676a007a2949e490e58703550c222b0000047479706500, ]], count=5001, toGroup = 1]
22920:14:03,670 FileCacheService.java:102 - Evicting cold readers for /home/cassandra/data/data/import_test/transactional_data-79c13380dd9111e6b9e0d333906ebbeb/lb-49-big-Data.db
23020:14:03,709 AbstractQueryPager.java:95 - Fetched 2701 live rows
23120:14:03,709 AbstractQueryPager.java:112 - Got result (2701) smaller than page size (5001), considering pager exhausted
23220:14:03,712 AbstractQueryPager.java:133 - Remaining rows to page: 2147475947
23320:14:09,201 SliceQueryPager.java:92 - Querying next page of slice query; new filter: SliceQueryFilter [reversed=false, slices=[[, ]], count=5000, toGroup = 1]
23420:14:09,202 FileCacheService.java:102 - Evicting cold readers for /home/cassandra/data/data/import_test/transactional_data-79c13380dd9111e6b9e0d333906ebbeb/lb-49-big-Data.db
23520:14:09,282 AbstractQueryPager.java:95 - Fetched 5000 live rows
23620:14:09,282 AbstractQueryPager.java:133 - Remaining rows to page: 2147478647
23720:14:10,153 ColumnFamilyStore.java:980 - forceFlush requested but everything is clean in batchlog
23820:14:24,442 SliceQueryPager.java:92 - Querying next page of slice query; new filter: SliceQueryFilter [reversed=false, slices=[[0010a8ceba29bcec45b7b66323cbb506f09a0000047479706500, ]], count=5001, toGroup = 1]
23920:14:24,443 FileCacheService.java:102 - Evicting cold readers for /home/cassandra/data/data/import_test/transactional_data-79c13380dd9111e6b9e0d333906ebbeb/lb-49-big-Data.db
24020:14:24,489 AbstractQueryPager.java:95 - Fetched 2701 live rows
24120:14:24,489 AbstractQueryPager.java:112 - Got result (2701) smaller than page size (5001), considering pager exhausted
24220:14:24,492 AbstractQueryPager.java:133 - Remaining rows to page: 2147475947
24320:14:32,039 ColumnFamilyStore.java:927 - Enqueuing flush of sstable_activity: 13998 (0%) on-heap, 0 (0%) off-heap
24420:14:32,050 ColumnFamilyStore.java:927 - Enqueuing flush of size_estimates: 42686 (0%) on-heap, 0 (0%) off-heap
24520:14:32,064 ColumnFamilyStore.java:927 - Enqueuing flush of compaction_history: 1197 (0%) on-heap, 0 (0%) off-heap
24620:14:32,062 Memtable.java:352 - Writing Memtable-size_estimates@907520469(3.088KiB serialized bytes, 780 ops, 0%/0% of on/off-heap limit)
24720:14:32,086 Memtable.java:386 - Completed flushing /home/cassandra/data/data/system/size_estimates-618f817b005f3678b8a453f3930b8e86/tmp-lb-198-big-Data.db (0.000KiB) for commitlog position ReplayPosition(segmentId=1484733263564, position=31840472)
24820:14:32,128 Memtable.java:352 - Writing Memtable-compaction_history@173198051(0.240KiB serialized bytes, 9 ops, 0%/0% of on/off-heap limit)
24920:14:32,130 Memtable.java:386 - Completed flushing /home/cassandra/data/data/system/compaction_history-b4dbb7b4dc493fb5b3bfce6e434832ca/tmp-lb-151-big-Data.db (0.000KiB) for commitlog position ReplayPosition(segmentId=1484733263564, position=31840472)
25020:14:32,150 CompactionTask.java:142 - Compacting (81ce1850-de7b-11e6-b9e0-d333906ebbeb) [/home/cassandra/data/data/system/sstable_activity-5a1ff267ace03f128563cfae6103c65e/lb-198-big-Data.db:level=0, /home/cassandra/data/data/system/sstable_activity-5a1ff267ace03f128563cfae6103c65e/lb-199-big-Data.db:level=0, /home/cassandra/data/data/system/sstable_activity-5a1ff267ace03f128563cfae6103c65e/lb-200-big-Data.db:level=0, /home/cassandra/data/data/system/sstable_activity-5a1ff267ace03f128563cfae6103c65e/lb-197-big-Data.db:level=0, ]
25120:14:32,190 FileCacheService.java:177 - Invalidating cache for /home/cassandra/data/data/system/sstable_activity-5a1ff267ace03f128563cfae6103c65e/tmplink-lb-201-big-Data.db
25220:14:32,198 FileCacheService.java:177 - Invalidating cache for /home/cassandra/data/data/system/sstable_activity-5a1ff267ace03f128563cfae6103c65e/lb-200-big-Data.db
25320:14:32,198 CompactionTask.java:224 - Compacted (81ce1850-de7b-11e6-b9e0-d333906ebbeb) 4 sstables to [/home/cassandra/data/data/system/sstable_activity-5a1ff267ace03f128563cfae6103c65e/lb-201-big,] to level=0. 4,012 bytes to 939 (~23% of original) in 40ms = 0.022388MB/s. 0 total partitions merged to 17. Partition merge counts were {1:12, 4:17, }
25420:14:32,198 FileCacheService.java:102 - Evicting cold readers for /home/cassandra/data/data/import_test/transactional_data-79c13380dd9111e6b9e0d333906ebbeb/lb-85-big-Data.db
25520:14:32,201 FileCacheService.java:177 - Invalidating cache for /home/cassandra/data/data/system/sstable_activity-5a1ff267ace03f128563cfae6103c65e/lb-197-big-Data.db
25620:14:32,800 SliceQueryPager.java:92 - Querying next page of slice query; new filter: SliceQueryFilter [reversed=false, slices=[[, ]], count=5000, toGroup = 1]
25720:14:32,800 FileCacheService.java:102 - Evicting cold readers for /home/cassandra/data/data/import_test/transactional_data-79c13380dd9111e6b9e0d333906ebbeb/lb-49-big-Data.db
25820:14:54,860 AbstractQueryPager.java:112 - Got result (2701) smaller than page size (5001), considering pager exhausted
25920:14:54,862 AbstractQueryPager.java:133 - Remaining rows to page: 2147475947
26020:15:05,797 SliceQueryPager.java:92 - Querying next page of slice query; new filter: SliceQueryFilter [reversed=false, slices=[[, ]], count=5000, toGroup = 1]
26120:15:05,797 FileCacheService.java:102 - Evicting cold readers for /home/cassandra/data/data/import_test/transactional_data-79c13380dd9111e6b9e0d333906ebbeb/lb-49-big-Data.db
26220:15:05,876 AbstractQueryPager.java:95 - Fetched 5000 live rows
26320:15:05,876 AbstractQueryPager.java:133 - Remaining rows to page: 2147478647
26420:15:10,153 ColumnFamilyStore.java:980 - forceFlush requested but everything is clean in batchlog
26520:15:51,040 SliceQueryPager.java:92 - Querying next page of slice query; new filter: SliceQueryFilter [reversed=false, slices=[[0010a5a53060d5d043f2832958356689c4ee0000047479706500, ]], count=5001, toGroup = 1]
26620:15:51,040 FileCacheService.java:102 - Evicting cold readers for /home/cassandra/data/data/import_test/transactional_data-79c13380dd9111e6b9e0d333906ebbeb/lb-49-big-Data.db
26720:15:51,083 AbstractQueryPager.java:95 - Fetched 2701 live rows
26820:15:51,083 AbstractQueryPager.java:112 - Got result (2701) smaller than page size (5001), considering pager exhausted
26920:15:51,086 AbstractQueryPager.java:133 - Remaining rows to page: 2147475947
27020:18:10,161 ColumnFamilyStore.java:980 - forceFlush requested but everything is clean in batchlog
27120:18:42,277 FileCacheService.java:102 - Evicting cold readers for /home/cassandra/data/data/system/local-7ad54392bcdd35a684174e047860b377/lb-134-big-Data.db