hyliu777 commented on issue #12368:
URL:
https://github.com/apache/dolphinscheduler/issues/12368#issuecomment-1280146883
@DarkAssassinator the following is worker log while running datax
> [INFO] 2022-10-17 09:27:15.486 +0800
org.apache.dolphinscheduler.server.log.LoggerRequestProcessor:[79] -
[WorkflowInstance-0][TaskInstance-0] - received command : Command
[type=ROLL_VIEW_LOG_REQUEST, opaque=169, bodyLen=117]
[INFO] 2022-10-17 09:27:15.533 +0800
org.apache.dolphinscheduler.server.log.LoggerRequestProcessor:[79] -
[WorkflowInstance-0][TaskInstance-0] - received command : Command
[type=ROLL_VIEW_LOG_REQUEST, opaque=171, bodyLen=118]
[INFO] 2022-10-17 09:27:19.613 +0800
org.apache.dolphinscheduler.server.worker.task.WorkerHeartBeatTask:[88] -
[WorkflowInstance-0][TaskInstance-0] - Success write worker group heartBeatInfo
into registry, workGroupPath: [/nodes/worker/default/172.16.10.15:1234]
workerHeartBeatInfo:
{"startupTime":1665969146369,"reportTime":1665970039602,"cpuUsage":0.36,"memoryUsage":0.68,"loadAverage":2.78,"availablePhysicalMemorySize":20.04,"maxCpuloadAvg":16.0,"reservedMemory":0.3,"diskAvailable":34.09,"serverStatus":0,"processId":11664,"workerHostWeight":100,"workerWaitingTaskCount":0,"workerExecThreadCount":100}
[INFO] 2022-10-17 09:27:22.011 +0800
org.apache.dolphinscheduler.server.worker.processor.TaskDispatchProcessor:[98]
- [WorkflowInstance-0][TaskInstance-0] - task execute request message:
TaskDispatchCommand(super=BaseCommand(messageSenderAddress=172.16.10.15:5678,
messageReceiverAddress=null, messageSendTime=1665970042008),
taskExecutionContext=TaskExecutionContext(taskInstanceId=484,
taskName=datax_test, firstSubmitTime=Mon Oct 17 09:27:21 CST 2022,
startTime=null, taskType=DATAX, host=null, executePath=null, logPath=null,
taskJson=null, processId=0, processDefineCode=7195111179040,
processDefineVersion=2, appIds=null, processInstanceId=468, scheduleTime=null,
globalParams=null, executorId=1, cmdTypeIfComplement=7, tenantCode=root,
queue=default, processDefineId=0, projectId=0, projectCode=7193666667040,
taskParams={"localParams":[],"resourceList":[],"customConfig":0,"dsType":"MYSQL","dataSource":1,"dtType":"MYSQL","dataTarget":1,"sql":"select
id,name from ods.ods_jdx_site","targ
etTable":"ods_jdx_site_copy1","jobSpeedByte":0,"jobSpeedRecord":1000,"preStatements":[],"postStatements":[],"xms":1,"xmx":1},
envFile=null, environmentConfig=export HADOOP_HOME=/opt/soft/hadoop
export HADOOP_CONF_DIR=/opt/soft/hadoop/etc/hadoop
export SPARK_HOME1=/opt/soft/spark1
export SPARK_HOME2=/opt/soft/spark2
export PYTHON_HOME=/opt/anaconda3/envs/py37
export JAVA_HOME=/usr/lib/java/jdk
export HIVE_HOME=/opt/soft/hive
export FLINK_HOME=/opt/flink
export DATAX_HOME=/opt/soft/datax/bin/datax.py
export
PATH=$HADOOP_HOME/bin:$SPARK_HOME1/bin:$SPARK_HOME2/bin:$PYTHON_HOME/bin:$JAVA_HOME/bin:$HIVE_HOME/bin:$FLINK_HOME/bin:$DATAX_HOME:$PATH,
definedParams=null, prepareParamsMap=null, taskAppId=null,
taskTimeoutStrategy=null, taskTimeout=2147483647, workerGroup=default,
delayTime=0, currentExecutionStatus=TaskExecutionStatus{code=0, desc='submit
success'}, taskLogName=null,
resourceParametersHelper=org.apache.dolphinscheduler.plugin.task.api.parameters.resource.ResourceParametersHelper@48f0b0ea,
endTime=null, sqlTaskExecutionContext=null,
k8sTaskExecutionContext=K8sTaskExecutionContext{configYaml='null'},
resources={}, varPool=null, dryRun=0, paramsMap={},
dataQualityTaskExecutionContext=org.apache.dolphinscheduler.plugin.task.api.DataQualityTaskExecutionContext@292b7f5,
cpuQuota=-1, memoryMax=-1))
[INFO] 2022-10-17 09:27:22.012 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[90]
- [WorkflowInstance-468][TaskInstance-484] - Set task logger name:
taskAppId=TASK-20221017-7195111179040_2-468-484
[INFO] 2022-10-17 09:27:22.013 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[136]
- [WorkflowInstance-468][TaskInstance-484] - Begin to pulling task
[INFO] 2022-10-17 09:27:22.015 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[164]
- [WorkflowInstance-468][TaskInstance-484] - Begin to initialize task
[INFO] 2022-10-17 09:27:22.015 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[168]
- [WorkflowInstance-468][TaskInstance-484] - Set task startTime: Mon Oct 17
09:27:22 CST 2022
[INFO] 2022-10-17 09:27:22.015 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[172]
- [WorkflowInstance-468][TaskInstance-484] - Set task envFile:
/opt/dolphinscheduler/worker-server/conf/dolphinscheduler_env.sh
[INFO] 2022-10-17 09:27:22.015 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[176]
- [WorkflowInstance-468][TaskInstance-484] - Set task appId: 468_484
[INFO] 2022-10-17 09:27:22.015 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[178]
- [WorkflowInstance-468][TaskInstance-484] - End initialize task
[INFO] 2022-10-17 09:27:22.016 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[184]
- [WorkflowInstance-468][TaskInstance-484] - Set task status to
TaskExecutionStatus{code=1, desc='running'}
[INFO] 2022-10-17 09:27:22.017 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[187]
- [WorkflowInstance-468][TaskInstance-484] - TenantCode:root check success
[INFO] 2022-10-17 09:27:22.017 +0800
org.apache.dolphinscheduler.common.utils.FileUtils:[140] -
[WorkflowInstance-468][TaskInstance-484] - create dir success
/tmp/dolphinscheduler/exec/process/7193666667040/7195111179040_2/468/484
[INFO] 2022-10-17 09:27:22.017 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[190]
- [WorkflowInstance-468][TaskInstance-484] -
ProcessExecDir:/tmp/dolphinscheduler/exec/process/7193666667040/7195111179040_2/468/484
check success
[INFO] 2022-10-17 09:27:22.017 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[193]
- [WorkflowInstance-468][TaskInstance-484] - Resources:{} check success
[INFO] 2022-10-17 09:27:22.017 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[203]
- [WorkflowInstance-468][TaskInstance-484] - Task plugin: DATAX create success
[INFO] 2022-10-17 09:27:22.017 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[134] -
[WorkflowInstance-468][TaskInstance-484] - datax task params
{"localParams":[],"resourceList":[],"customConfig":0,"dsType":"MYSQL","dataSource":1,"dtType":"MYSQL","dataTarget":1,"sql":"select
id,name from
ods_jdx_site","targetTable":"ods_jdx_site_copy","jobSpeedByte":0,"jobSpeedRecord":1000,"preStatements":[],"postStatements":[],"xms":1,"xmx":1}
[INFO] 2022-10-17 09:27:22.018 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[206]
- [WorkflowInstance-468][TaskInstance-484] - Success initialized task plugin
instance success
[INFO] 2022-10-17 09:27:22.018 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[209]
- [WorkflowInstance-468][TaskInstance-484] - Success set taskVarPool: null
[ERROR] 2022-10-17 09:27:22.019 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.plugin.task.datax.DataxTask:[169] -
[WorkflowInstance-468][TaskInstance-484] - datax task error
java.lang.NullPointerException: null
at
org.apache.dolphinscheduler.plugin.task.datax.DataxTask.addCustomParameters(DataxTask.java:426)
at
org.apache.dolphinscheduler.plugin.task.datax.DataxTask.buildShellCommandFile(DataxTask.java:400)
at
org.apache.dolphinscheduler.plugin.task.datax.DataxTask.handle(DataxTask.java:157)
at
org.apache.dolphinscheduler.server.worker.runner.DefaultWorkerDelayTaskExecuteRunnable.executeTask(DefaultWorkerDelayTaskExecuteRunnable.java:48)
at
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable.run(WorkerTaskExecuteRunnable.java:151)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at
com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:131)
at
com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:74)
at
com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:82)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
[ERROR] 2022-10-17 09:27:22.020 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[156]
- [WorkflowInstance-468][TaskInstance-484] - Task execute failed, due to meet
an exception
org.apache.dolphinscheduler.plugin.task.api.TaskException: Execute DataX
task failed
at
org.apache.dolphinscheduler.plugin.task.datax.DataxTask.handle(DataxTask.java:171)
at
org.apache.dolphinscheduler.server.worker.runner.DefaultWorkerDelayTaskExecuteRunnable.executeTask(DefaultWorkerDelayTaskExecuteRunnable.java:48)
at
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable.run(WorkerTaskExecuteRunnable.java:151)
at
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at
com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:131)
at
com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:74)
at
com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:82)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException: null
at
org.apache.dolphinscheduler.plugin.task.datax.DataxTask.addCustomParameters(DataxTask.java:426)
at
org.apache.dolphinscheduler.plugin.task.datax.DataxTask.buildShellCommandFile(DataxTask.java:400)
at
org.apache.dolphinscheduler.plugin.task.datax.DataxTask.handle(DataxTask.java:157)
... 9 common frames omitted
[INFO] 2022-10-17 09:27:22.173 +0800
org.apache.dolphinscheduler.server.worker.processor.TaskExecuteRunningAckProcessor:[61]
- [WorkflowInstance-0][TaskInstance-484] - task execute running ack command :
TaskExecuteRunningAckMessage(success=true, taskInstanceId=484)
[INFO] 2022-10-17 09:27:23.021 +0800
org.apache.dolphinscheduler.service.log.LogClientService:[206] -
[WorkflowInstance-468][TaskInstance-484] - Begin to get appIds from worker:
172.16.10.15:1234 taskLogPath:
/opt/dolphinscheduler/worker-server/logs/20221017/7195111179040_2-468-484.log
[INFO] 2022-10-17 09:27:23.022 +0800
org.apache.dolphinscheduler.service.log.LogClientService:[223] -
[WorkflowInstance-468][TaskInstance-484] - Get appIds: [] from worker:
172.16.10.15:1234 taskLogPath:
/opt/dolphinscheduler/worker-server/logs/20221017/7195111179040_2-468-484.log
[INFO] 2022-10-17 09:27:23.024 +0800
org.apache.dolphinscheduler.service.log.LogClientService:[81] -
[WorkflowInstance-468][TaskInstance-484] - logger client closed
[INFO] 2022-10-17 09:27:23.024 +0800
org.apache.dolphinscheduler.server.utils.ProcessUtils:[213] -
[WorkflowInstance-468][TaskInstance-484] - The current appId is empty, don't
need to kill the yarn job, taskInstanceId: 484
[INFO] 2022-10-17 09:27:23.025 +0800 TaskLogLogger-class
org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecuteRunnable:[114]
- [WorkflowInstance-468][TaskInstance-484] - Get a exception when execute the
task, will send the task execute result to master, the current task execute
result is TaskExecutionStatus{code=6, desc='failure'}
[INFO] 2022-10-17 09:27:23.168 +0800
org.apache.dolphinscheduler.server.worker.processor.TaskExecuteResultAckProcessor:[57]
- [WorkflowInstance-0][TaskInstance-0] - task execute response ack command :
TaskExecuteAckCommand(super=BaseCommand(messageSenderAddress=172.16.10.15:5678,
messageReceiverAddress=172.16.10.15:1234, messageSendTime=1665970043167),
taskInstanceId=484, success=true)
[INFO] 2022-10-17 09:27:29.623 +0800
org.apache.dolphinscheduler.server.worker.task.WorkerHeartBeatTask:[88] -
[WorkflowInstance-0][TaskInstance-0] - Success write worker group heartBeatInfo
into registry, workGroupPath: [/nodes/worker/default/172.16.10.15:1234]
workerHeartBeatInfo:
{"startupTime":1665969146369,"reportTime":1665970049614,"cpuUsage":0.36,"memoryUsage":0.68,"loadAverage":3.63,"availablePhysicalMemorySize":20.03,"maxCpuloadAvg":16.0,"reservedMemory":0.3,"diskAvailable":34.09,"serverStatus":0,"processId":11664,"workerHostWeight":100,"workerWaitingTaskCount":0,"workerExecThreadCount":100}
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
