search

alibaba / DataX

DataX是阿里云DataWorks数据集成的开源版本。
Other
16.02k stars 5.46k forks source link

抽取Oracle数据经常会出现卡死情况，speed一直为0 records/s #1634

Open zhuli20 opened 1 year ago

zhuli20 commented 1 year ago

完整日志

`[INFO] 2022-12-08 05:58:10.177 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 13:58:09.650 [job-0] INFO StandAloneJobContainerCommunicator - Total 0 records, 0 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 0.000s | All Task WaitReaderTime 0.000s | Percentage 0.00% [INFO] 2022-12-08 05:58:20.179 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 13:58:19.656 [job-0] INFO StandAloneJobContainerCommunicator - Total 4608 records, 6277817 bytes | Speed 613.07KB/s, 460 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 3.237s | All Task WaitReaderTime 3.731s | Percentage 0.00% [INFO] 2022-12-08 05:58:30.181 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 13:58:29.659 [job-0] INFO StandAloneJobContainerCommunicator - Total 10752 records, 14699781 bytes | Speed 822.46KB/s, 614 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 10.901s | All Task WaitReaderTime 6.728s | Percentage 0.00% [INFO] 2022-12-08 05:58:40.183 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 13:58:39.663 [job-0] INFO StandAloneJobContainerCommunicator - Total 16896 records, 22460788 bytes | Speed 757.91KB/s, 614 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 18.509s | All Task WaitReaderTime 9.124s | Percentage 0.00% [INFO] 2022-12-08 05:58:50.186 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 13:58:49.666 [job-0] INFO StandAloneJobContainerCommunicator - Total 23040 records, 30126263 bytes | Speed 748.58KB/s, 614 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 25.827s | All Task WaitReaderTime 11.468s | Percentage 0.00% [INFO] 2022-12-08 05:59:00.188 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 13:58:59.670 [job-0] INFO StandAloneJobContainerCommunicator - Total 29184 records, 37774235 bytes | Speed 746.87KB/s, 614 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 33.089s | All Task WaitReaderTime 13.739s | Percentage 0.00% [INFO] 2022-12-08 05:59:10.190 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 13:59:09.674 [job-0] INFO StandAloneJobContainerCommunicator - Total 35328 records, 45415777 bytes | Speed 746.24KB/s, 614 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 40.777s | All Task WaitReaderTime 16.129s | Percentage 0.00% [INFO] 2022-12-08 05:59:20.193 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 13:59:19.677 [job-0] INFO StandAloneJobContainerCommunicator - Total 41472 records, 52928876 bytes | Speed 733.70KB/s, 614 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 48.784s | All Task WaitReaderTime 19.879s | Percentage 0.00% [INFO] 2022-12-08 05:59:30.194 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 13:59:29.681 [job-0] INFO StandAloneJobContainerCommunicator - Total 44736 records, 56843682 bytes | Speed 382.30KB/s, 326 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 56.453s | All Task WaitReaderTime 22.714s | Percentage 0.00% [INFO] 2022-12-08 05:59:40.196 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 13:59:39.687 [job-0] INFO StandAloneJobContainerCommunicator - Total 49664 records, 62876511 bytes | Speed 589.14KB/s, 492 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 61.742s | All Task WaitReaderTime 26.319s | Percentage 0.00% [INFO] 2022-12-08 05:59:50.198 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 13:59:49.691 [job-0] INFO StandAloneJobContainerCommunicator - Total 55264 records, 69533828 bytes | Speed 650.13KB/s, 560 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 69.047s | All Task WaitReaderTime 29.414s | Percentage 0.00% [INFO] 2022-12-08 06:00:00.200 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 13:59:59.698 [job-0] INFO StandAloneJobContainerCommunicator - Total 59360 records, 74503600 bytes | Speed 485.33KB/s, 409 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 74.629s | All Task WaitReaderTime 34.235s | Percentage 0.00% [INFO] 2022-12-08 06:00:10.207 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:00:09.701 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 117.84KB/s, 102 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:00:20.209 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:00:19.704 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:00:30.211 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:00:29.708 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:00:40.213 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:00:39.713 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:00:50.216 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:00:49.716 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:01:00.217 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:00:59.720 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:01:10.220 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:01:09.724 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:01:20.228 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:01:19.728 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:01:30.230 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:01:29.730 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:01:40.232 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:01:39.734 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:01:50.234 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:01:49.737 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:02:00.236 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:01:59.740 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:02:10.238 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:02:09.743 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:02:20.240 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:02:19.747 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:02:30.242 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:02:29.752 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:02:40.244 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:02:39.754 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:02:50.246 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:02:49.758 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:03:00.248 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:02:59.762 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% 2022-12-08 14:02:59.772 [job-0] INFO VMInfo - [delta cpu info] => curDeltaCpu | averageCpu | maxDeltaCpu | minDeltaCpu
-1.00% | -1.00% | -1.00% | -1.00%

     [delta memory info] => 
         NAME                           | used_size                      | used_percent                   | max_used_size                  | max_percent                    
         tenured-SOA                    | 71.97MB                        | 2.47%                          | 71.97MB                        | 2.47%                          
         class storage                  | 21.76MB                        | 29.12%                         | 21.76MB                        | 29.12%                         
         nursery-survivor               | 437.94MB                       | 100.00%                        | 437.94MB                       | 100.00%                        
         miscellaneous non-heap storage | 26.45MB                        | 32.04%                         | 26.45MB                        | 32.04%                         
         tenured-LOA                    | 0.00MB                         | 0.00%                          | 0.00MB                         | 0.00%                          
         JIT code cache                 | 1.92MB                         | 0.75%                          | 1.92MB                         | 0.75%                          
         nursery-allocate               | 441.24MB                       | 75.29%                         | 441.24MB                       | 75.29%                         
         JIT data cache                 | 2.00MB                         | 100.00%                        | 2.00MB                         | 100.00%                        

     [delta gc info] => 
         NAME                 | curDeltaGCCount    | totalGCCount       | maxDeltaGCCount    | minDeltaGCCount    | curDeltaGCTime     | totalGCTime        | maxDeltaGCTime     | minDeltaGCTime     
         scavenge             | 5                  | 5                  | 5                  | 5                  | 0.178s             | 0.178s             | 0.178s             | 0.178s             
         global               | 0                  | 0                  | 0                  | 0                  | 0.000s             | 0.000s             | 0.000s             | 0.000s

[INFO] 2022-12-08 06:03:10.250 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:03:09.774 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:03:20.252 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:03:19.777 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:03:30.254 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:03:29.780 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:03:40.256 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:03:39.783 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:03:50.258 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:03:49.785 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:04:00.260 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:03:59.787 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:04:10.262 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:04:09.790 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:04:20.264 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:04:19.793 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:04:30.266 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:04:29.796 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:04:40.268 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:04:39.798 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:04:50.270 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:04:49.801 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:05:00.272 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:04:59.804 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:05:10.274 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:05:09.806 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:05:20.276 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:05:19.808 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:05:30.278 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:05:29.810 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:05:40.280 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:05:39.813 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:05:50.282 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:05:49.816 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:06:00.284 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:05:59.819 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:06:10.286 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:06:09.821 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:06:20.289 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:06:19.824 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:06:30.290 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:06:29.828 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:06:40.292 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:06:39.830 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:06:50.294 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:06:49.832 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:07:00.297 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:06:59.835 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00% [INFO] 2022-12-08 06:07:10.298 +0000 [taskAppId=TASK-20221208-7803683914016_3-1739-11789] TaskLogLogger-class org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[63] - -> 2022-12-08 14:07:09.837 [job-0] INFO StandAloneJobContainerCommunicator - Total 60384 records, 75710329 bytes | Speed 0B/s, 0 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00%`

Y-evil commented 1 year ago

从Oracle表中读不出来数据,可能你Oracle表被锁了,也可能是其他原因,检查下sql语句和Oracle数据库.

All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s 这两个值一直没有变动,说明Reader线程一直没有数据进来,Reader线程读出来的数据会先缓存到内存中,等缓存满了,才会刷给Writer线程去写.在刷缓存的过程中会更新上面的两个值.

Percentage 0.00% 一直是0,说明没有task执行成功,你看下是那几个task处于start,日志里有打印,向上翻翻就能找到.

zhuli20 commented 1 year ago

从Oracle表中读不出来数据,可能你Oracle表被锁了,也可能是其他原因,检查下sql语句和Oracle数据库.

All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s 这两个值一直没有变动,说明Reader线程一直没有数据进来,Reader线程读出来的数据会先缓存到内存中,等缓存满了,才会刷给Writer线程去写.在刷缓存的过程中会更新上面的两个值.

Percentage 0.00% 一直是0,说明没有task执行成功,你看下是那几个task处于start,日志里有打印,向上翻翻就能找到.

我监控过数据库，数据库是正常的，这个日志里显示一开始还是能写数据的，后面就停止了，JVM有两个指标异常，监控了GC发现内存也没问题

Y-evil commented 1 year ago

从Oracle表中读不出来数据,可能你Oracle表被锁了,也可能是其他原因,检查下sql语句和Oracle数据库. All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s 这两个值一直没有变动,说明Reader线程一直没有数据进来,Reader线程读出来的数据会先缓存到内存中,等缓存满了,才会刷给Writer线程去写.在刷缓存的过程中会更新上面的两个值. Percentage 0.00% 一直是0,说明没有task执行成功,你看下是那几个task处于start,日志里有打印,向上翻翻就能找到.

我监控过数据库，数据库是正常的，这个日志里显示一开始还是能写数据的，后面就停止了，JVM有两个指标异常，监控了GC发现内存也没问题

现在的问题就是读不到数据了,既然数据库没问题,先排查下网络问题,你再看下JVM中Reader和Writer线程的状态."JVM有两个指标异常"是哪两个? 你开始的读取速率就不快,还有你的Writer线程也很慢,再看下你写的数据库是不是有问题,如果缓存的数据一直无法消费,也是读不进来的.读写线程是一对一的生产者和消费者模式.

Y-evil commented 1 year ago

Total 59360 records, 74503600 bytes | Speed 485.33KB/s, 409 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 74.629s | All Task WaitReaderTime 34.235s | Percentage 0.00% Total 60384 records, 75710329 bytes | Speed 117.84KB/s, 102 records/s | Error 0 records, 0 bytes | All Task WaitWriterTime 77.184s | All Task WaitReaderTime 34.888s | Percentage 0.00%

从最后的这两条汇总看,WaitReaderTime的时间变动不大为0.6s,WaitWriterTime的变动为3s.WaitWriterTime指标意思是缓存中有数据一直未消费或消费的很慢,导致生产者线程(即Reader线程)一直阻塞等待.

简单说就是有数据在内存中,但写不进去,看下你写的数据库.

chenwj93 commented 1 year ago

我也碰到了这个问题，抽取sqlserver库的数据会出现这种情况，我改了core模块的AbstractScheduler类，在speed持续为0若干次后自动dealKillingStat；但之后就偶尔会出现oom异常

zlj0123 commented 1 year ago

我也经常碰到这个问题，目前只在oracle读或者oracle写参与的情况下才发生，分析肯定是oracle有问题，但定位不到具体的问题。 主要是链接也不断，就是取不到数，或者写不进去。如果是取不到数，那么为啥oracle不给数呢，写不进去为啥不报错了，这几年，每年都会碰到几次这样的问题，客户要就解释

stupidxian commented 1 year ago

我遇到的问题是，显示“连接超时”，读取失败。 1、看了下源代码，每个task新建连接，而不是线程池方式，所以不存在闲置超时的问题。 2、又找到了个java环境噪音机制的问题，也改了。 3、找了下源代码，新建连接的时候，设置的超时时间是48h，所以问题也不这里。 现在也确实定位不到问题。