flinckcdc-导入数据时合并数据刷新到磁盘报错

U_1630408960324_5459 · 2022年02月21日 10:36

【详述】3千万据量导入数据到SR里，报 Failed to flush data to StarRocks, Error response
【导入/导出方式】flink-cdc
【背景】
【业务影响】
【StarRocks版本】例如：1.19.2
【集群规模】例如：3fe（1 follower+2observer）+5be（fe与be混部）
【机器信息】CPU虚拟核/内存/网卡，例如：4C/8G/百兆
【附件】
Caused by: java.io.IOException: com.starrocks.connector.flink.manager.StarRocksStreamLoadFailedException: Failed to flush data to StarRocks, Error response:
{“Status”:“Fail”,“BeginTxnTimeMs”:0,“Message”:“cancelled”,“NumberUnselectedRows”:0,“CommitAndPublishTimeMs”:0,“Label”:“e24620e8-8199-48de-9bbc-97134d906205”,“LoadBytes”:9430704,“StreamLoadPutTimeMs”:5,“NumberTotalRows”:0,“WriteDataTimeMs”:159,“TxnId”:20513,“LoadTimeMs”:223,“ReadDataTimeMs”:7,“NumberLoadedRows”:0,“NumberFilteredRows”:0}

at com.starrocks.connector.flink.manager.StarRocksSinkManager.asyncFlush(StarRocksSinkManager.java:272)
at com.starrocks.connector.flink.manager.StarRocksSinkManager.access$000(StarRocksSinkManager.java:52)
at com.starrocks.connector.flink.manager.StarRocksSinkManager$1.run(StarRocksSinkManager.java:120)
... 1 more

Caused by: com.starrocks.connector.flink.manager.StarRocksStreamLoadFailedException: Failed to flush data to StarRocks, Error response:
{“Status”:“Fail”,“BeginTxnTimeMs”:0,“Message”:“cancelled”,“NumberUnselectedRows”:0,“CommitAndPublishTimeMs”:0,“Label”:“e24620e8-8199-48de-9bbc-97134d906205”,“LoadBytes”:9430704,“StreamLoadPutTimeMs”:5,“NumberTotalRows”:0,“WriteDataTimeMs”:159,“TxnId”:20513,“LoadTimeMs”:223,“ReadDataTimeMs”:7,“NumberLoadedRows”:0,“NumberFilteredRows”:0}

at com.starrocks.connector.flink.manager.StarRocksStreamLoadVisitor.doStreamLoad(StarRocksStreamLoadVisitor.java:89)
at com.starrocks.connector.flink.manager.StarRocksSinkManager.asyncFlush(StarRocksSinkManager.java:258)
... 3 more

JiangLai · 2022年02月21日 11:57

你好，fe的日志可以提供一下吗？

U_1630408960324_5459 · 2022年02月22日 07:14

2022-02-22T14:45:18.729+0800: 1672.068: [GC (Allocation Failure) 2022-02-22T14:45:18.729+0800: 1672.068: [ParNew: 71058K->7321K(76800K), 0.0040634 secs] 206325K->150780K(266680K), 0.0042010 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
2022-02-22T14:45:31.217+0800: 1684.556: [GC (Allocation Failure) 2022-02-22T14:45:31.217+0800: 1684.557: [ParNew: 75609K->7406K(76800K), 0.0048011 secs] 219068K->165832K(266680K), 0.0049115 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
2022-02-22T14:45:31.222+0800: 1684.562: [GC (CMS Initial Mark) [1 CMS-initial-mark: 158426K(189880K)] 165937K(266680K), 0.0021358 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2022-02-22T14:45:31.224+0800: 1684.564: [CMS-concurrent-mark-start]
2022-02-22T14:45:31.272+0800: 1684.612: [CMS-concurrent-mark: 0.048/0.048 secs] [Times: user=0.10 sys=0.00, real=0.05 secs]
2022-02-22T14:45:31.272+0800: 1684.612: [CMS-concurrent-preclean-start]
2022-02-22T14:45:31.274+0800: 1684.614: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2022-02-22T14:45:31.275+0800: 1684.615: [GC (CMS Final Remark) [YG occupancy: 7894 K (76800 K)]2022-02-22T14:45:31.275+0800: 1684.615: [Rescan (non-parallel) 2022-02-22T14:45:31.275+0800: 1684.615: [grey object rescan, 0.0002803 secs]2022-02-22T14:45:31.275+0800: 1684.615: [root rescan, 0.0018125 secs]2022-02-22T14:45:31.277+0800: 1684.617: [visit unhandled CLDs, 0.0000092 secs]2022-02-22T14:45:31.277+0800: 1684.617: [dirty klass scan, 0.0007791 secs], 0.0029134 secs]2022-02-22T14:45:31.278+0800: 1684.617: [weak refs processing, 0.0000579 secs]2022-02-22T14:45:31.278+0800: 1684.618: [class unloading, 0.0293160 secs]2022-02-22T14:45:31.307+0800: 1684.647: [scrub symbol table, 0.0110622 secs]2022-02-22T14:45:31.318+0800: 1684.658: [scrub string table, 0.0012048 secs][1 CMS-remark: 158426K(189880K)] 166321K(266680K), 0.0581525 secs] [Times: user=0.06 sys=0.00, real=0.06 secs]
2022-02-22T14:45:31.333+0800: 1684.673: [CMS-concurrent-sweep-start]
2022-02-22T14:45:31.358+0800: 1684.698: [CMS-concurrent-sweep: 0.024/0.025 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
2022-02-22T14:45:31.358+0800: 1684.698: [CMS-concurrent-reset-start]
2022-02-22T14:45:31.372+0800: 1684.711: [CMS-concurrent-reset: 0.014/0.014 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]
2022-02-22T14:45:44.792+0800: 1698.132: [GC (Allocation Failure) 2022-02-22T14:45:44.792+0800: 1698.132: [ParNew: 75694K->8512K(76800K), 0.0048274 secs] 191899K->135419K(270476K), 0.0049514 secs] [Times: user=0.03 sys=0.00, real=0.00 secs]
2022-02-22T14:45:54.108+0800: 1707.447: [GC (Allocation Failure) 2022-02-22T14:45:54.108+0800: 1707.448: [ParNew: 75280K->7913K(76800K), 0.0065213 secs] 202187K->147330K(270476K), 0.0066319 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
2022-02-22T14:46:10.119+0800: 1723.459: [GC (Allocation Failure) 2022-02-22T14:46:10.119+0800: 1723.459: [ParNew: 76201K->6695K(76800K), 0.0037208 secs] 215618K->156397K(270476K), 0.0038632 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2022-02-22T14:46:25.702+0800: 1739.041: [GC (Allocation Failure) 2022-02-22T14:46:25.702+0800: 1739.041: [ParNew: 74983K->8512K(76800K), 0.0035512 secs] 224685K->168666K(270476K), 0.0036863 secs] [Times: user=0.02 sys=0.01, real=0.01 secs]
2022-02-22T14:46:25.707+0800: 1739.047: [GC (CMS Initial Mark) [1 CMS-initial-mark: 160154K(193676K)] 169065K(270476K), 0.0013459 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2022-02-22T14:46:25.709+0800: 1739.048: [CMS-concurrent-mark-start]
2022-02-22T14:46:25.758+0800: 1739.097: [CMS-concurrent-mark: 0.049/0.049 secs] [Times: user=0.10 sys=0.00, real=0.05 secs]
2022-02-22T14:46:25.758+0800: 1739.097: [CMS-concurrent-preclean-start]
2022-02-22T14:46:25.760+0800: 1739.099: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2022-02-22T14:46:25.760+0800: 1739.100: [GC (CMS Final Remark) [YG occupancy: 8912 K (76800 K)]2022-02-22T14:46:25.760+0800: 1739.100: [Rescan (non-parallel) 2022-02-22T14:46:25.760+0800: 1739.100: [grey object rescan, 0.0002764 secs]2022-02-22T14:46:25.760+0800: 1739.100: [root rescan, 0.0013774 secs]2022-02-22T14:46:25.762+0800: 1739.101: [visit unhandled CLDs, 0.0000167 secs]2022-02-22T14:46:25.762+0800: 1739.101: [dirty klass scan, 0.0007516 secs], 0.0024555 secs]2022-02-22T14:46:25.762+0800: 1739.102: [weak refs processing, 0.0000580 secs]2022-02-22T14:46:25.763+0800: 1739.102: [class unloading, 0.0288641 secs]2022-02-22T14:46:25.791+0800: 1739.131: [scrub symbol table, 0.0126830 secs]2022-02-22T14:46:25.804+0800: 1739.144: [scrub string table, 0.0011090 secs][1 CMS-remark: 160154K(193676K)] 169067K(270476K), 0.0453480 secs] [Times: user=0.04 sys=0.00, real=0.05 secs]
2022-02-22T14:46:25.806+0800: 1739.145: [CMS-concurrent-sweep-start]
2022-02-22T14:46:25.829+0800: 1739.169: [CMS-concurrent-sweep: 0.023/0.023 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
2022-02-22T14:46:25.829+0800: 1739.169: [CMS-concurrent-reset-start]
2022-02-22T14:46:25.842+0800: 1739.181: [CMS-concurrent-reset: 0.013/0.013 secs] [Times: user=0.01 sys=0.00, real=0.02 secs]
2022-02-22T14:46:39.551+0800: 1752.891: [GC (Allocation Failure) 2022-02-22T14:46:39.552+0800: 1752.891: [ParNew: 76800K->6828K(76800K), 0.0045930 secs] 190841K->133229K(270476K), 0.0047235 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
2022-02-22T14:46:47.129+0800: 1760.468: [GC (Allocation Failure) 2022-02-22T14:46:47.129+0800: 1760.468: [ParNew: 73731K->6616K(76800K), 0.0037621 secs] 200132K->139448K(270476K), 0.0038947 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2022-02-22T14:47:00.141+0800: 1773.481: [GC (Allocation Failure) 2022-02-22T14:47:00.141+0800: 1773.481: [ParNew: 74904K->8512K(76800K), 0.0140633 secs] 207736K->150007K(270476K), 0.0142047 secs] [Times: user=0.05 sys=0.01, real=0.02 secs]
2022-02-22T14:47:15.529+0800: 1788.869: [GC (Allocation Failure) 2022-02-22T14:47:15.529+0800: 1788.869: [ParNew: 76800K->8512K(76800K), 0.0053825 secs] 218295K->160751K(270476K), 0.0055244 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2022-02-22T14:47:31.469+0800: 1804.809: [GC (Allocation Failure) 2022-02-22T14:47:31.470+0800: 1804.809: [ParNew: 76528K->8512K(76800K), 0.0074810 secs] 228767K->171156K(270476K), 0.0075907 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2022-02-22T14:47:31.478+0800: 1804.817: [GC (CMS Initial Mark) [1 CMS-initial-mark: 162644K(193676K)] 173204K(270476K), 0.0012797 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2022-02-22T14:47:31.479+0800: 1804.819: [CMS-concurrent-mark-start]
2022-02-22T14:47:31.528+0800: 1804.867: [CMS-concurrent-mark: 0.048/0.048 secs] [Times: user=0.10 sys=0.00, real=0.05 secs]
2022-02-22T14:47:31.528+0800: 1804.867: [CMS-concurrent-preclean-start]
2022-02-22T14:47:31.530+0800: 1804.869: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2022-02-22T14:47:31.530+0800: 1804.870: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 2022-02-22T14:47:36.544+0800: 1809.883: [CMS-concurrent-abortable-preclean: 0.139/5.014 secs] [Times: user=0.21 sys=0.00, real=5.02 secs]
2022-02-22T14:47:36.544+0800: 1809.884: [GC (CMS Final Remark) [YG occupancy: 31013 K (76800 K)]2022-02-22T14:47:36.544+0800: 1809.884: [Rescan (non-parallel) 2022-02-22T14:47:36.544+0800: 1809.884: [grey object rescan, 0.0002808 secs]2022-02-22T14:47:36.545+0800: 1809.884: [root rescan, 0.0150133 secs]2022-02-22T14:47:36.560+0800: 1809.899: [visit unhandled CLDs, 0.0000168 secs]2022-02-22T14:47:36.560+0800: 1809.899: [dirty klass scan, 0.0009212 secs], 0.0163001 secs]2022-02-22T14:47:36.561+0800: 1809.900: [weak refs processing, 0.0001063 secs]2022-02-22T14:47:36.561+0800: 1809.900: [class unloading, 0.0271433 secs]2022-02-22T14:47:36.588+0800: 1809.928: [scrub symbol table, 0.0104707 secs]2022-02-22T14:47:36.598+0800: 1809.938: [scrub string table, 0.0011233 secs][1 CMS-remark: 162644K(193676K)] 193658K(270476K), 0.0553464 secs] [Times: user=0.06 sys=0.00, real=0.05 secs]
2022-02-22T14:47:36.600+0800: 1809.940: [CMS-concurrent-sweep-start]
2022-02-22T14:47:36.623+0800: 1809.963: [CMS-concurrent-sweep: 0.024/0.024 secs] [Times: user=0.02 sys=0.00, real=0.03 secs]
2022-02-22T14:47:36.624+0800: 1809.963: [CMS-concurrent-reset-start]
2022-02-22T14:47:36.637+0800: 1809.977: [CMS-concurrent-reset: 0.013/0.013 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2022-02-22T14:47:45.074+0800: 1818.413: [GC (Allocation Failure) 2022-02-22T14:47:45.074+0800: 1818.413: [ParNew: 76800K->8512K(76800K), 0.0083559 secs] 191031K->132777K(270476K), 0.0084747 secs] [Times: user=0.03 sys=0.01, real=0.01 secs]
2022-02-22T14:47:58.240+0800: 1831.580: [GC (Allocation Failure) 2022-02-22T14:47:58.240+0800: 1831.580: [ParNew: 76800K->8512K(76800K), 0.0110047 secs] 201065K->145048K(270476K), 0.0111396 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
2022-02-22T14:48:08.627+0800: 1841.967: [GC (Allocation Failure) 2022-02-22T14:48:08.627+0800: 1841.967: [ParNew: 76800K->8512K(76800K), 0.0099695 secs] 213336K->155747K(270476K), 0.0100990 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2022-02-22T14:48:19.695+0800: 1853.035: [GC (Allocation Failure) 2022-02-22T14:48:19.695+0800: 1853.035: [ParNew: 76800K->8512K(76800K), 0.0072884 secs] 224035K->164418K(270476K), 0.0074169 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2022-02-22T14:48:19.703+0800: 1853.043: [GC (CMS Initial Mark) [1 CMS-initial-mark: 155906K(193676K)] 164540K(270476K), 0.0018967 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2022-02-22T14:48:19.705+0800: 1853.045: [CMS-concurrent-mark-start]
2022-02-22T14:48:19.766+0800: 1853.105: [CMS-concurrent-mark: 0.061/0.061 secs] [Times: user=0.13 sys=0.00, real=0.06 secs]
2022-02-22T14:48:19.766+0800: 1853.106: [CMS-concurrent-preclean-start]
2022-02-22T14:48:19.768+0800: 1853.108: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2022-02-22T14:48:19.768+0800: 1853.108: [CMS-concurrent-abortable-preclean-start]
2022-02-22T14:48:22.661+0800: 1856.000: [CMS-concurrent-abortable-preclean: 0.090/2.892 secs] [Times: user=0.16 sys=0.00, real=2.89 secs]
2022-02-22T14:48:22.661+0800: 1856.001: [GC (CMS Final Remark) [YG occupancy: 46379 K (76800 K)]2022-02-22T14:48:22.661+0800: 1856.001: [Rescan (non-parallel) 2022-02-22T14:48:22.661+0800: 1856.001: [grey object rescan, 0.0002974 secs]2022-02-22T14:48:22.661+0800: 1856.001: [root rescan, 0.0255463 secs]2022-02-22T14:48:22.687+0800: 1856.027: [visit unhandled CLDs, 0.0000164 secs]2022-02-22T14:48:22.687+0800: 1856.027: [dirty klass scan, 0.0010822 secs], 0.0270053 secs]2022-02-22T14:48:22.688+0800: 1856.028: [weak refs processing, 0.0001177 secs]2022-02-22T14:48:22.688+0800: 1856.028: [class unloading, 0.0269058 secs]2022-02-22T14:48:22.715+0800: 1856.055: [scrub symbol table, 0.0106125 secs]2022-02-22T14:48:22.726+0800: 1856.065: [scrub string table, 0.0011348 secs][1 CMS-remark: 155906K(193676K)] 202286K(270476K), 0.0659629 secs] [Times: user=0.06 sys=0.00, real=0.07 secs]
2022-02-22T14:48:22.727+0800: 1856.067: [CMS-concurrent-sweep-start]
2022-02-22T14:48:22.754+0800: 1856.093: [CMS-concurrent-sweep: 0.026/0.027 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
2022-02-22T14:48:22.754+0800: 1856.094: [CMS-concurrent-reset-start]
2022-02-22T14:48:22.768+0800: 1856.108: [CMS-concurrent-reset: 0.014/0.014 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2022-02-22T14:48:26.732+0800: 1860.071: [GC (Allocation Failure) 2022-02-22T14:48:26.732+0800: 1860.071: [ParNew: 76800K->8512K(76800K), 0.0094521 secs] 191526K->133898K(270476K), 0.0095851 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
2022-02-22T14:49:43.933+0800: 1937.272: [GC (Allocation Failure) 2022-02-22T14:49:43.933+0800: 1937.272: [ParNew: 76800K->759K(76800K), 0.0044769 secs] 202186K->134456K(270476K), 0.0046183 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
2022-02-22T14:50:45.193+0800: 1998.533: [GC (Allocation Failure) 2022-02-22T14:50:45.193+0800: 1998.533: [ParNew: 69047K->4383K(76800K), 0.0050673 secs] 202744K->138081K(270476K), 0.0051665 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
2022-02-22T14:52:25.851+0800: 2099.191: [GC (Allocation Failure) 2022-02-22T14:52:25.851+0800: 2099.191: [ParNew: 72671K->3228K(76800K), 0.0026364 secs] 206369K->137332K(270476K), 0.0027649 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2022-02-22T14:53:44.978+0800: 2178.318: [GC (Allocation Failure) 2022-02-22T14:53:44.979+0800: 2178.318: [ParNew: 71516K->2215K(76800K), 0.0030062 secs] 205620K->136320K(270476K), 0.0031394 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2022-02-22T14:54:54.170+0800: 2247.510: [GC (Allocation Failure) 2022-02-22T14:54:54.170+0800: 2247.510: [ParNew: 70503K->1409K(76800K), 0.0017103 secs] 204608K->135514K(270476K), 0.0018318 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2022-02-22T14:56:44.512+0800: 2357.851: [GC (Allocation Failure) 2022-02-22T14:56:44.512+0800: 2357.851: [ParNew: 69697K->506K(76800K), 0.0027181 secs] 203802K->134610K(270476K), 0.0028615 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2022-02-22T14:57:45.401+0800: 2418.741: [GC (Allocation Failure) 2022-02-22T14:57:45.401+0800: 2418.741: [ParNew: 68794K->1880K(76800K), 0.0036602 secs] 202898K->135984K(270476K), 0.0038286 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2022-02-22T14:58:45.986+0800: 2479.326: [GC (Allocation Failure) 2022-02-22T14:58:45.986+0800: 2479.326: [ParNew: 70168K->1119K(76800K), 0.0022511 secs] 204272K->135224K(270476K), 0.0023801 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2022-02-22T15:00:05.038+0800: 2558.378: [GC (Allocation Failure) 2022-02-22T15:00:05.038+0800: 2558.378: [ParNew: 69407K->1205K(76800K), 0.0038655 secs] 203512K->135324K(270476K), 0.0040246 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2022-02-22T15:00:26.078+0800: 2579.417: [GC (Allocation Failure) 2022-02-22T15:00:26.078+0800: 2579.418: [ParNew: 69150K->7421K(76800K), 0.0110135 secs] 203269K->147704K(270476K), 0.0111406 secs] [Times: user=0.08 sys=0.00, real=0.01 secs]
2022-02-22T15:00:41.271+0800: 2594.610: [GC (Allocation Failure) 2022-02-22T15:00:41.271+0800: 2594.610: [ParNew: 75709K->7411K(76800K), 0.0195130 secs] 215992K->160641K(270476K), 0.0196738 secs] [Times: user=0.14 sys=0.00, real=0.02 secs]
2022-02-22T15:00:47.643+0800: 2600.983: [GC (Allocation Failure) 2022-02-22T15:00:47.643+0800: 2600.983: [ParNew: 75699K->6952K(76800K), 0.0316670 secs] 228929K->168521K(270476K), 0.0318486 secs] [Times: user=0.15 sys=0.00, real=0.03 secs]
2022-02-22T15:00:47.679+0800: 2601.018: [GC (CMS Initial Mark) [1 CMS-initial-mark: 161568K(193676K)] 170359K(270476K), 0.0067180 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2022-02-22T15:00:47.686+0800: 2601.025: [CMS-concurrent-mark-start]
2022-02-22T15:00:47.757+0800: 2601.096: [CMS-concurrent-mark: 0.071/0.071 secs] [Times: user=0.14 sys=0.00, real=0.07 secs]
2022-02-22T15:00:47.757+0800: 2601.096: [CMS-concurrent-preclean-start]
2022-02-22T15:00:47.760+0800: 2601.100: [CMS-concurrent-preclean: 0.003/0.003 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2022-02-22T15:00:47.760+0800: 2601.100: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 2022-02-22T15:00:52.865+0800: 2606.205: [CMS-concurrent-abortable-preclean: 0.254/5.105 secs] [Times: user=0.33 sys=0.01, real=5.11 secs]
2022-02-22T15:00:52.865+0800: 2606.205: [GC (CMS Final Remark) [YG occupancy: 31378 K (76800 K)]2022-02-22T15:00:52.866+0800: 2606.205: [Rescan (non-parallel) 2022-02-22T15:00:52.866+0800: 2606.205: [grey object rescan, 0.0003282 secs]2022-02-22T15:00:52.866+0800: 2606.206: [root rescan, 0.0179271 secs]2022-02-22T15:00:52.884+0800: 2606.224: [visit unhandled CLDs, 0.0000191 secs]2022-02-22T15:00:52.884+0800: 2606.224: [dirty klass scan, 0.0012098 secs], 0.0195699 secs]2022-02-22T15:00:52.885+0800: 2606.225: [weak refs processing, 0.0001295 secs]2022-02-22T15:00:52.885+0800: 2606.225: [class unloading, 0.0358902 secs]2022-02-22T15:00:52.921+0800: 2606.261: [scrub symbol table, 0.0129485 secs]2022-02-22T15:00:52.934+0800: 2606.274: [scrub string table, 0.0011529 secs][1 CMS-remark: 161568K(193676K)] 192946K(270476K), 0.0699976 secs] [Times: user=0.07 sys=0.00, real=0.07 secs]
2022-02-22T15:00:52.936+0800: 2606.275: [CMS-concurrent-sweep-start]
2022-02-22T15:00:52.964+0800: 2606.304: [CMS-concurrent-sweep: 0.029/0.029 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
2022-02-22T15:00:52.965+0800: 2606.304: [CMS-concurrent-reset-start]
2022-02-22T15:00:53.176+0800: 2606.516: [CMS-concurrent-reset: 0.211/0.211 secs] [Times: user=0.21 sys=0.00, real=0.21 secs]
2022-02-22T15:01:03.614+0800: 2616.954: [GC (Allocation Failure) 2022-02-22T15:01:03.614+0800: 2616.954: [ParNew: 75240K->8512K(76800K), 0.0221819 secs] 192271K->138137K(271852K), 0.0223692 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
2022-02-22T15:01:20.402+0800: 2633.741: [GC (Allocation Failure) 2022-02-22T15:01:20.402+0800: 2633.741: [ParNew: 75304K->8512K(76800K), 0.0124636 secs] 204930K->146829K(271852K), 0.0126068 secs] [Times: user=0.05 sys=0.00, real=0.02 secs]
2022-02-22T15:01:36.576+0800: 2649.916: [GC (Allocation Failure) 2022-02-22T15:01:36.576+0800: 2649.916: [ParNew: 76757K->8512K(76800K), 0.0109394 secs] 215075K->157277K(271852K), 0.0111112 secs] [Times: user=0.05 sys=0.00, real=0.01 secs]
2022-02-22T15:01:45.668+0800: 2659.008: [GC (Allocation Failure) 2022-02-22T15:01:45.668+0800: 2659.008: [ParNew: 76608K->8512K(76800K), 0.0241189 secs] 225373K->167788K(271852K), 0.0242788 secs] [Times: user=0.13 sys=0.00, real=0.03 secs]
2022-02-22T15:01:45.693+0800: 2659.033: [GC (CMS Initial Mark) [1 CMS-initial-mark: 159276K(195052K)] 169875K(271852K), 0.0014946 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2022-02-22T15:01:45.695+0800: 2659.034: [CMS-concurrent-mark-start]
2022-02-22T15:01:45.744+0800: 2659.083: [CMS-concurrent-mark: 0.049/0.049 secs] [Times: user=0.10 sys=0.00, real=0.05 secs]
2022-02-22T15:01:45.744+0800: 2659.084: [CMS-concurrent-preclean-start]
2022-02-22T15:01:45.746+0800: 2659.086: [CMS-concurrent-preclean: 0.002/0.002 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2022-02-22T15:01:45.746+0800: 2659.086: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 2022-02-22T15:01:50.836+0800: 2664.176: [CMS-concurrent-abortable-preclean: 0.142/5.090 secs] [Times: user=0.21 sys=0.01, real=5.09 secs]
2022-02-22T15:01:50.837+0800: 2664.176: [GC (CMS Final Remark) [YG occupancy: 31518 K (76800 K)]2022-02-22T15:01:50.837+0800: 2664.177: [Rescan (non-parallel) 2022-02-22T15:01:50.837+0800: 2664.177: [grey object rescan, 0.0002838 secs]2022-02-22T15:01:50.837+0800: 2664.177: [root rescan, 0.0159654 secs]2022-02-22T15:01:50.853+0800: 2664.193: [visit unhandled CLDs, 0.0000207 secs]2022-02-22T15:01:50.853+0800: 2664.193: [dirty klass scan, 0.0012133 secs], 0.0175714 secs]2022-02-22T15:01:50.854+0800: 2664.194: [weak refs processing, 0.0001091 secs]2022-02-22T15:01:50.855+0800: 2664.194: [class unloading, 0.0296887 secs]2022-02-22T15:01:50.884+0800: 2664.224: [scrub symbol table, 0.0115882 secs]2022-02-22T15:01:50.896+0800: 2664.236: [scrub string table, 0.0011330 secs][1 CMS-remark: 159276K(195052K)] 190795K(271852K), 0.0603195 secs] [Times: user=0.06 sys=0.00, real=0.06 secs]
2022-02-22T15:01:50.897+0800: 2664.237: [CMS-concurrent-sweep-start]
2022-02-22T15:01:50.923+0800: 2664.263: [CMS-concurrent-sweep: 0.025/0.026 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
2022-02-22T15:01:50.924+0800: 2664.263: [CMS-concurrent-reset-start]
2022-02-22T15:01:50.936+0800: 2664.275: [CMS-concurrent-reset: 0.012/0.012 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2022-02-22T15:02:00.501+0800: 2673.841: [GC (Allocation Failure) 2022-02-22T15:02:00.501+0800: 2673.841: [ParNew: 76800K->8512K(76800K), 0.0108528 secs] 189958K->136285K(271852K), 0.0110173 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
2022-02-22T15:02:16.415+0800: 2689.755: [GC (Allocation Failure) 2022-02-22T15:02:16.415+0800: 2689.755: [ParNew: 76800K->8512K(76800K), 0.0101702 secs] 204573K->144792K(271852K), 0.0103528 secs] [Times: user=0.04 sys=0.00, real=0.01 secs]
2022-02-22T15:02:29.743+0800: 2703.083: [GC (Allocation Failure) 2022-02-22T15:02:29.744+0800: 2703.083: [ParNew: 76800K->8512K(76800K), 0.0288266 secs] 213080K->157570K(271852K), 0.0290219 secs] [Times: user=0.19 sys=0.00, real=0.03 secs]
2022-02-22T15:02:44.515+0800: 2717.855: [GC (Allocation Failure) 2022-02-22T15:02:44.516+0800: 2717.855: [ParNew: 76800K->6958K(76800K), 0.0130990 secs] 225858K->168463K(271852K), 0.0132879 secs] [Times: user=0.09 sys=0.00, real=0.01 secs]
2022-02-22T15:02:44.530+0800: 2717.870: [GC (CMS Initial Mark) [1 CMS-initial-mark: 161504K(195052K)] 168778K(271852K), 0.0026007 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2022-02-22T15:02:44.533+0800: 2717.873: [CMS-concurrent-mark-start]
2022-02-22T15:02:44.609+0800: 2717.949: [CMS-concurrent-mark: 0.076/0.076 secs] [Times: user=0.16 sys=0.00, real=0.07 secs]
2022-02-22T15:02:44.609+0800: 2717.949: [CMS-concurrent-preclean-start]
2022-02-22T15:02:44.612+0800: 2717.952: [CMS-concurrent-preclean: 0.003/0.003 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
2022-02-22T15:02:44.612+0800: 2717.952: [CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time 2022-02-22T15:02:49.625+0800: 2722.965: [CMS-concurrent-abortable-preclean: 0.302/5.012 secs] [Times: user=0.44 sys=0.02, real=5.01 secs]
2022-02-22T15:02:49.625+0800: 2722.965: [GC (CMS Final Remark) [YG occupancy: 54304 K (76800 K)]2022-02-22T15:02:49.626+0800: 2722.965: [Rescan (non-parallel) 2022-02-22T15:02:49.626+0800: 2722.965: [grey object rescan, 0.0002909 secs]2022-02-22T15:02:49.626+0800: 2722.966: [root rescan, 0.0401689 secs]2022-02-22T15:02:49.666+0800: 2723.006: [visit unhandled CLDs, 0.0000191 secs]2022-02-22T15:02:49.666+0800: 2723.006: [dirty klass scan, 0.0012250 secs], 0.0418308 secs]2022-02-22T15:02:49.667+0800: 2723.007: [weak refs processing, 0.0001464 secs]2022-02-22T15:02:49.668+0800: 2723.007: [class unloading, 0.0726302 secs]2022-02-22T15:02:49.740+0800: 2723.080: [scrub symbol table, 0.0215799 secs]2022-02-22T15:02:49.762+0800: 2723.102: [scrub string table, 0.0011028 secs][1 CMS-remark: 161504K(195052K)] 215808K(271852K), 0.1375261 secs] [Times: user=0.14 sys=0.00, real=0.14 secs]
2022-02-22T15:02:49.763+0800: 2723.103: [CMS-concurrent-sweep-start]
2022-02-22T15:02:49.795+0800: 2723.134: [CMS-concurrent-sweep: 0.032/0.032 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
2022-02-22T15:02:49.795+0800: 2723.135: [CMS-concurrent-reset-start]
2022-02-22T15:02:49.859+0800: 2723.199: [CMS-concurrent-reset: 0.064/0.064 secs] [Times: user=0.07 sys=0.00, real=0.06 secs]
2022-02-22T15:02:53.815+0800: 2727.154: [GC (Allocation Failure) 2022-02-22T15:02:53.815+0800: 2727.154: [ParNew: 75246K->6755K(76800K), 0.0048605 secs] 192524K->130284K(272264K), 0.0050352 secs] [Times: user=0.03 sys=0.00, real=0.00 secs]
2022-02-22T15:03:09.269+0800: 2742.609: [GC (Allocation Failure) 2022-02-22T15:03:09.269+0800: 2742.609: [ParNew: 74819K->8512K(76800K), 0.0073470 secs] 198348K->142359K(272264K), 0.0074709 secs] [Times: user=0.03 sys=0.01, real=0.01 secs]
2022-02-22T15:03:24.071+0800: 2757.411: [GC (Allocation Failure) 2022-02-22T15:03:24.071+0800: 2757.411: [ParNew: 76800K->8512K(76800K), 0.0078362 secs] 210647K->153010K(272264K), 0.0079921 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
2022-02-22T15:03:38.500+0800: 2771.840: [GC (Allocation Failure) 2022-02-22T15:03:38.500+0800: 2771.840: [ParNew: 75400K->8512K(76800K), 0.0107571 secs] 219898K->161685K(272264K), 0.0109206 secs] [Times: user=0.06 sys=0.00, real=0.01 secs]
2022-02-22T15:03:45.602+0800: 2778.942: [GC (Allocation Failure) 2022-02-22T15:03:45.602+0800: 2778.942: [ParNew: 76800K->8512K(76800K), 0.0139390 secs] 229973K->173349K(272264K), 0.0141133 secs] [Times: user=0.07 sys=0.00, real=0.01 secs]
2022-02-22T15:03:45.619+0800: 2778.959: [GC (CMS Initial Mark) [1 CMS-initial-mark: 164837K(195464K)] 174137K(272264K), 0.0019997 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
2022-02-22T15:03:45.621+0800: 2778.961: [CMS-concurrent-mark-start]
2022-02-22T15:03:45.684+0800: 2779.024: [CMS-concurrent-mark: 0.063/0.063 secs] [Times: user=0.14 sys=0.00, real=0.07 secs]
2022-02-22T15:03:45.684+0800: 2779.024: [CMS-concurrent-preclean-start]
2022-02-22T15:03:45.687+0800: 2779.027: [CMS-concurrent-preclean: 0.003/0.003 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2022-02-22T15:03:45.687+0800: 2779.027: [CMS-concurrent-abortable-preclean-start]
2022-02-22T15:03:46.776+0800: 2780.116: [CMS-concurrent-abortable-preclean: 0.188/1.089 secs] [Times: user=0.30 sys=0.02, real=1.09 secs]
2022-02-22T15:03:46.777+0800: 2780.116: [GC (CMS Final Remark) [YG occupancy: 43275 K (76800 K)]2022-02-22T15:03:46.777+0800: 2780.116: [Rescan (non-parallel) 2022-02-22T15:03:46.777+0800: 2780.116: [grey object rescan, 0.0003645 secs]2022-02-22T15:03:46.777+0800: 2780.117: [root rescan, 0.0263881 secs]2022-02-22T15:03:46.804+0800: 2780.143: [visit unhandled CLDs, 0.0000145 secs]2022-02-22T15:03:46.804+0800: 2780.143: [dirty klass scan, 0.0015122 secs], 0.0283626 secs]2022-02-22T15:03:46.805+0800: 2780.145: [weak refs processing, 0.0001494 secs]2022-02-22T15:03:46.805+0800: 2780.145: [class unloading, 0.0268438 secs]2022-02-22T15:03:46.832+0800: 2780.172: [scrub symbol table, 0.0141069 secs]2022-02-22T15:03:46.846+0800: 2780.186: [scrub string table, 0.0012831 secs][1 CMS-remark: 164837K(195464K)] 208112K(272264K), 0.0709364 secs] [Times: user=0.07 sys=0.00, real=0.07 secs]
2022-02-22T15:03:46.848+0800: 2780.188: [CMS-concurrent-sweep-start]
2022-02-22T15:03:46.879+0800: 2780.219: [CMS-concurrent-sweep: 0.031/0.031 secs] [Times: user=0.03 sys=0.00, real=0.03 secs]
2022-02-22T15:03:46.879+0800: 2780.219: [CMS-concurrent-reset-start]
2022-02-22T15:03:46.922+0800: 2780.262: [CMS-concurrent-reset: 0.042/0.042 secs] [Times: user=0.04 sys=0.00, real=0.05 secs]
2022-02-22T15:03:51.541+0800: 2784.881: [GC (Allocation Failure) 2022-02-22T15:03:51.541+0800: 2784.881: [ParNew: 76800K->7622K(76800K), 0.0130790 secs] 195441K->138615K(274536K), 0.0132443 secs] [Times: user=0.04 sys=0.00, real=0.02 secs]
2022-02-22T15:04:45.617+0800: 2838.956: [GC (Allocation Failure) 2022-02-22T15:04:45.617+0800: 2838.957: [ParNew: 75910K->7623K(76800K), 0.0083166 secs] 206903K->144839K(274536K), 0.0085157 secs] [Times: user=0.04 sys=0.00, real=0.01 secs]
2022-02-22T15:05:56.125+0800: 2909.465: [GC (Allocation Failure) 2022-02-22T15:05:56.125+0800: 2909.465: [ParNew: 75911K->3036K(76800K), 0.0161844 secs] 213127K->146950K(274536K), 0.0163493 secs] [Times: user=0.09 sys=0.00, real=0.01 secs]
2022-02-22T15:07:44.572+0800: 3017.912: [GC (Allocation Failure) 2022-02-22T15:07:44.572+0800: 3017.912: [ParNew: 71324K->2738K(76800K), 0.0027814 secs] 215238K->146653K(274536K), 0.0029023 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2022-02-22T15:08:45.377+0800: 3078.716: [GC (Allocation Failure) 2022-02-22T15:08:45.377+0800: 3078.717: [ParNew: 71026K->4994K(76800K), 0.0037614 secs] 214941K->148909K(274536K), 0.0038999 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2022-02-22T15:10:04.782+0800: 3158.122: [GC (Allocation Failure) 2022-02-22T15:10:04.782+0800: 3158.122: [ParNew: 73282K->1895K(76800K), 0.0026735 secs] 217197K->148005K(274536K), 0.0027907 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2022-02-22T15:11:45.433+0800: 3258.773: [GC (Allocation Failure) 2022-02-22T15:11:45.433+0800: 3258.773: [ParNew: 70183K->1642K(76800K), 0.0023149 secs] 216293K->147751K(274536K), 0.0024225 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
2022-02-22T15:12:45.879+0800: 3319.219: [GC (Allocation Failure) 2022-02-22T15:12:45.879+0800: 3319.219: [ParNew: 69930K->3628K(76800K), 0.0034902 secs] 216039K->149738K(274536K), 0.0036586 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]

U_1630408960324_5459 · 2022年02月22日 07:15

今天我把服务器3fe 3be 系统都提升到8c16G，导入大批数据时还是出现了这个错误，大概是可以一批次导入800万数据就不行了