[Python] Python script jobs fail with permission denied error in Apache Dolphin Standalone...

I'm trying to create a cronjob with a python script in apache dolphin scheduler. These are the steps I followed. (Used the default admin user and default tenant)

1. Created a project
2. Created a workflow
3. Added a python node. (In the script section added a line print('Hello From Python!')). Saved the node and workflow.
4. Scheduled it to run in every minute and made the workflow and scheduler online.

When I checked the logs, I noticed there's a permission denied error and after the execution of the workflow it is deleting the script files created for the execution.

Then, for further investigation I enable develop mode. (made development.state=true in standalone-server/conf/common.properties).

OS version: fedora 40 Apache dolphin version: 3.2.1

Following is the logs of the workflow execution.

[LOG-PATH]: /home/ishad/Software/apache-dolphinscheduler-3.2.1-bin/standalone-server/logs/20240723/14374012970432/1/1/1.log, [HOST]: 192.168.49.1:1234

[INFO] 2024-07-23 15:07:00.763 +0530 - ***********************************************************************************************

[INFO] 2024-07-23 15:07:00.771 +0530 - ********************************* Initialize task context ***********************************

[INFO] 2024-07-23 15:07:00.771 +0530 - ***********************************************************************************************

[INFO] 2024-07-23 15:07:00.771 +0530 - Begin to initialize task

[INFO] 2024-07-23 15:07:00.772 +0530 - Set task startTime: 1721727420772

[INFO] 2024-07-23 15:07:00.772 +0530 - Set task appId: 1_1

[INFO] 2024-07-23 15:07:00.779 +0530 - End initialize task {

"taskInstanceId" : 1,

"taskName" : "n1",

"firstSubmitTime" : 1721727420494,

"startTime" : 1721727420772,

"taskType" : "PYTHON",

"workflowInstanceHost" : "192.168.49.1:5678",

"host" : "192.168.49.1:1234",

"logPath" : "/home/ishad/Software/apache-dolphinscheduler-3.2.1-bin/standalone-server/logs/20240723/14374012970432/1/1/1.log",

"processId" : 0,

"processDefineCode" : 14374012970432,

"processDefineVersion" : 1,

"processInstanceId" : 1,

"scheduleTime" : 1721727420000,

"executorId" : 1,

"cmdTypeIfComplement" : 6,

"tenantCode" : "default",

"processDefineId" : 0,

"projectId" : 0,

"projectCode" : 14374006444992,

"taskParams" : "{\"localParams\":[],\"rawScript\":\"print(\\\"Hello from python!\\\")\",\"resourceList\":[]}",

"prepareParamsMap" : {

"system.task.definition.name" : {

"prop" : "system.task.definition.name",

"direct" : "IN",

"type" : "VARCHAR",

"value" : "n1"

},

"system.project.name" : {

"prop" : "system.project.name",

"direct" : "IN",

"type" : "VARCHAR",

"value" : null

},

"system.project.code" : {

"prop" : "system.project.code",

"direct" : "IN",

"type" : "VARCHAR",

"value" : "14374006444992"

},

"system.workflow.instance.id" : {

"prop" : "system.workflow.instance.id",

"direct" : "IN",

"type" : "VARCHAR",

"value" : "1"

},

"system.biz.curdate" : {

"prop" : "system.biz.curdate",

"direct" : "IN",

"type" : "VARCHAR",

"value" : "20240723"

},

"system.biz.date" : {

"prop" : "system.biz.date",

"direct" : "IN",

"type" : "VARCHAR",

"value" : "20240722"

},

"system.task.instance.id" : {

"prop" : "system.task.instance.id",

"direct" : "IN",

"type" : "VARCHAR",

"value" : "1"

},

"system.workflow.definition.name" : {

"prop" : "system.workflow.definition.name",

"direct" : "IN",

"type" : "VARCHAR",

"value" : "w1"

},

"system.task.definition.code" : {

"prop" : "system.task.definition.code",

"direct" : "IN",

"type" : "VARCHAR",

"value" : "14374008341824"

},

"system.workflow.definition.code" : {

"prop" : "system.workflow.definition.code",

"direct" : "IN",

"type" : "VARCHAR",

"value" : "14374012970432"

},

"system.datetime" : {

"prop" : "system.datetime",

"direct" : null,

"type" : null,

"value" : "20240723150700"

}

},

"taskAppId" : "1_1",

"taskTimeout" : 2147483647,

"workerGroup" : "default",

"delayTime" : 0,

"currentExecutionStatus" : "SUBMITTED_SUCCESS",

"endTime" : 0,

"dryRun" : 0,

"paramsMap" : {

"system.datetime" : {

"prop" : "system.datetime",

"direct" : null,

"type" : null,

"value" : "20240723150700"

}

},

"cpuQuota" : -1,

"memoryMax" : -1,

"testFlag" : 0,

"logBufferEnable" : false,

"dispatchFailTimes" : 0

}

[INFO] 2024-07-23 15:07:00.781 +0530 - ***********************************************************************************************

[INFO] 2024-07-23 15:07:00.781 +0530 - ********************************* Load task instance plugin *********************************

[INFO] 2024-07-23 15:07:00.781 +0530 - ***********************************************************************************************

[INFO] 2024-07-23 15:07:00.839 +0530 - Send task status RUNNING_EXECUTION master: 192.168.49.1:1234

[INFO] 2024-07-23 15:07:00.842 +0530 - Current tenant is default tenant, will use bootstrap user: ishad to execute the task

[INFO] 2024-07-23 15:07:00.842 +0530 - TenantCode: ishad check successfully

[INFO] 2024-07-23 15:07:00.856 +0530 - WorkflowInstanceExecDir: /tmp/dolphinscheduler/exec/process/ishad/14374006444992/14374012970432_1/1/1 check successfully

[INFO] 2024-07-23 15:07:00.857 +0530 - Create TaskChannel: org.apache.dolphinscheduler.plugin.task.python.PythonTaskChannel successfully

[INFO] 2024-07-23 15:07:00.858 +0530 - Download resources successfully:

ResourceContext(resourceItemMap={})

[INFO] 2024-07-23 15:07:00.861 +0530 - Download upstream files: [] successfully

[INFO] 2024-07-23 15:07:00.864 +0530 - Task plugin instance: PYTHON create successfully

[INFO] 2024-07-23 15:07:00.867 +0530 - Initialize python task params {

"localParams" : [ ],

"varPool" : null,

"rawScript" : "print(\"Hello from python!\")",

"resourceList" : [ ]

}

[INFO] 2024-07-23 15:07:00.868 +0530 - Success initialized task plugin instance successfully

[INFO] 2024-07-23 15:07:00.868 +0530 - Set taskVarPool: null successfully

[INFO] 2024-07-23 15:07:00.870 +0530 - ***********************************************************************************************

[INFO] 2024-07-23 15:07:00.870 +0530 - ********************************* Execute task instance *************************************

[INFO] 2024-07-23 15:07:00.870 +0530 - ***********************************************************************************************

[INFO] 2024-07-23 15:07:00.870 +0530 - raw python script : print("Hello from python!")

[INFO] 2024-07-23 15:07:00.874 +0530 - tenantCode :ishad, task dir:/tmp/dolphinscheduler/exec/process/ishad/14374006444992/14374012970432_1/1/1

[INFO] 2024-07-23 15:07:00.874 +0530 - generate python script file:/tmp/dolphinscheduler/exec/process/ishad/14374006444992/14374012970432_1/1/1/py_1_1.py

[INFO] 2024-07-23 15:07:00.874 +0530 - #-*- encoding=utf8 -*-


print("Hello from python!")

[INFO] 2024-07-23 15:07:00.903 +0530 - Final Shell file is:

[INFO] 2024-07-23 15:07:00.904 +0530 - ****************************** Script Content *****************************************************************

[INFO] 2024-07-23 15:07:00.904 +0530 - #!/bin/bash

BASEDIR=$(cd `dirname $0`; pwd)

cd $BASEDIR

${PYTHON_LAUNCHER} /tmp/dolphinscheduler/exec/process/ishad/14374006444992/14374012970432_1/1/1/py_1_1.py

[INFO] 2024-07-23 15:07:00.904 +0530 - ****************************** Script Content *****************************************************************

[INFO] 2024-07-23 15:07:00.906 +0530 - Executing shell command : sudo -u ishad -i /tmp/dolphinscheduler/exec/process/ishad/14374006444992/14374012970432_1/1/1/1_1.sh

[ERROR] 2024-07-23 15:07:00.920 +0530 - Get task pid failed

java.lang.reflect.InaccessibleObjectException: Unable to make field private final int java.lang.ProcessImpl.pid accessible: module java.base does not "opens java.lang" to unnamed module @679d4c1c

at java.base/java.lang.reflect.AccessibleObject.throwInaccessibleObjectException(AccessibleObject.java:391)

at java.base/java.lang.reflect.AccessibleObject.checkCanSetAccessible(AccessibleObject.java:367)

at java.base/java.lang.reflect.AccessibleObject.checkCanSetAccessible(AccessibleObject.java:315)

at java.base/java.lang.reflect.Field.checkCanSetAccessible(Field.java:183)

at java.base/java.lang.reflect.Field.setAccessible(Field.java:177)

at org.apache.dolphinscheduler.plugin.task.api.AbstractCommandExecutor.getProcessId(AbstractCommandExecutor.java:339)

at org.apache.dolphinscheduler.plugin.task.api.AbstractCommandExecutor.run(AbstractCommandExecutor.java:146)

at org.apache.dolphinscheduler.plugin.task.python.PythonTask.handle(PythonTask.java:96)

at org.apache.dolphinscheduler.server.worker.runner.DefaultWorkerTaskExecutor.executeTask(DefaultWorkerTaskExecutor.java:54)

at org.apache.dolphinscheduler.server.worker.runner.WorkerTaskExecutor.run(WorkerTaskExecutor.java:175)

at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)

at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)

at java.base/java.lang.Thread.run(Thread.java:1583)

[INFO] 2024-07-23 15:07:00.922 +0530 - process start, process id is: 0

[INFO] 2024-07-23 15:07:01.916 +0530 - ->

/tmp/dolphinscheduler/exec/process/ishad/14374006444992/14374012970432_1/1/1/1_1.sh: line 4: /tmp/dolphinscheduler/exec/process/ishad/14374006444992/14374012970432_1/1/1/py_1_1.py: Permission denied

[INFO] 2024-07-23 15:07:01.918 +0530 - process has exited. execute path:/tmp/dolphinscheduler/exec/process/ishad/14374006444992/14374012970432_1/1/1, processId:0 ,exitStatusCode:126 ,processWaitForStatus:true ,processExitValue:126

[INFO] 2024-07-23 15:07:01.919 +0530 - ***********************************************************************************************

[INFO] 2024-07-23 15:07:01.920 +0530 - ********************************* Finalize task instance ************************************

[INFO] 2024-07-23 15:07:01.920 +0530 - ***********************************************************************************************

[INFO] 2024-07-23 15:07:01.923 +0530 - Upload output files: [] successfully

[INFO] 2024-07-23 15:07:01.936 +0530 - Send task execute status: FAILURE to master : 192.168.49.1:1234

[INFO] 2024-07-23 15:07:01.937 +0530 - Remove the current task execute context from worker cache

[INFO] 2024-07-23 15:07:01.937 +0530 - The current execute mode is develop mode, will not clear the task execute file: /tmp/dolphinscheduler/exec/process/ishad/14374006444992/14374012970432_1/1/1

[INFO] 2024-07-23 15:07:01.939 +0530 - FINALIZE_SESSION


The files created for execution in /tmp/dolphinscheduler/exec/process/ishad/14374006444992/14374012970432_1/1/1 is as below.

drwxr-xr-x 2 ishad ishad 80 Jul 23 15:07 .
drwxr-xr-x 3 ishad ishad 60 Jul 23 15:07 ..
-rwxr-xr-x 1 ishad ishad 161 Jul 23 15:07 1_1.sh
-rw-r--r-- 1 ishad ishad 51 Jul 23 15:07 py_1_1.py


It's obvious that the permission denied error is due to the missing execution permission for the py_1_1.py file created. Even though I manually set the execution permissions for the file the next workflow execution instance is creating another set of scripts. How can I get this fixed?.

Continue reading...