Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

[BUG] CWLTool throw error the missing folder for Python dist #275

Open
pedringcoding opened this issue Jul 7, 2021 · 2 comments · May be fixed by #278
Open

[BUG] CWLTool throw error the missing folder for Python dist #275

pedringcoding opened this issue Jul 7, 2021 · 2 comments · May be fixed by #278
Assignees
@fmigneault
Labels
triage/bug Something isn't working

Comments

@pedringcoding
Copy link

Hello,

I having the weaver in ems configurated and running using docker compose.
When I triying execute some job, for this case "file2string_array", catch the next error:

'/opt/local/src/weaver/bin/python' not found: [Errno 2] No such file or directory: '/opt/local/src/weaver/bin/python': '/opt/local/src/weaver/bin/python'",".

When you have a weaver in runtime, with default configuration, execute the next request in post using Postman:

<wps:Execute version="1.0.0" service="WPS"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xmlns="http://www.opengis.net/wps/1.0.0"
xmlns:wfs="http://www.opengis.net/wfs"
xmlns:wps="http://www.opengis.net/wps/1.0.0"
xmlns:ows="http://www.opengis.net/ows/1.1"
xmlns:gml="http://www.opengis.net/gml"
xmlns:ogc="http://www.opengis.net/ogc"
xmlns:wcs="http://www.opengis.net/wcs/1.1.1"
xmlns:xlink="http://www.w3.org/1999/xlink" xsi:schemaLocation="http://www.opengis.net/wps/1.0.0 http://schemas.opengis.net/wps/1.0.0/wpsAll.xsd">
ows:Identifierfile2string_array</ows:Identifier>
wps:DataInputs
wps:Input
ows:Identifierinput</ows:Identifier>
wps:Data
<wps:ComplexData mimeType="text/plain"></wps:ComplexData>
</wps:Data>
</wps:Input>
</wps:DataInputs>
wps:ResponseForm
<wps:ResponseDocument lineage="true" status="true">
</wps:ResponseDocument>
</wps:ResponseForm>
</wps:Execute>

And I obtains the next response:

<wps:ExecuteResponse xmlns:wps="http://www.opengis.net/wps/1.0.0" xmlns:ows="http://www.opengis.net/ows/1.1" xmlns:xlink="http://www.w3.org/1999/xlink" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://www.opengis.net/wps/1.0.0 ../wpsExecute_response.xsd" service="WPS" version="1.0.0" xml:lang="en-US" serviceInstance="http://localhost/wps?request=GetCapabilities&amp;amp;service=WPS" statusLocation="http://localhost:4001/processes/file2string_array/jobs/e5df41b0-6c26-4db4-8543-a101b6f678ea">
<wps:Process wps:processVersion="None">
ows:Identifierfile2string_array</ows:Identifier>
ows:TitleNone</ows:Title>
ows:AbstractTransforms a file input into JSON file containing an array of file references as value.</ows:Abstract>
</wps:Process>
<wps:Status creationTime="2021-07-07T11:16:14Z">
<wps:ProcessAccepted percentCompleted="0">PyWPS Process file2string_array accepted</wps:ProcessAccepted>
</wps:Status>
</wps:ExecuteResponse>

And the next status to job:

{"jobID":"e5df41b0-6c26-4db4-8543-a101b6f678ea","status":"failed","message":"Job failed.","created":"2021-07-07T11:16:14.723000+00:00","started":"2021-07-07T11:16:15.811000+00:00","finished":"2021-07-07T11:16:18.383000+00:00","duration":"00:00:02","runningSeconds":2,"percentCompleted":100,"links":[{"type":"application/json","title":"Job status.","hreflang":"en-US","href":"http://localhost:4001/processes/file2string_array/jobs/e5df41b0-6c26-4db4-8543-a101b6f678ea","rel":"status"},{"type":"application/json","title":"Job logs.","hreflang":"en-US","href":"http://localhost:4001/processes/file2string_array/jobs/e5df41b0-6c26-4db4-8543-a101b6f678ea/logs","rel":"logs"},{"type":"application/json","title":"Job inputs.","hreflang":"en-US","href":"http://localhost:4001/processes/file2string_array/jobs/e5df41b0-6c26-4db4-8543-a101b6f678ea/inputs","rel":"inputs"},{"type":"application/json","title":"Job exceptions.","hreflang":"en-US","href":"http://localhost:4001/processes/file2string_array/jobs/e5df41b0-6c26-4db4-8543-a101b6f678ea/exceptions","rel":"exceptions"},{"type":"application/json","title":"Job status.","hreflang":"en-US","href":"http://localhost:4001/processes/file2string_array/jobs/e5df41b0-6c26-4db4-8543-a101b6f678ea","rel":"self"}]}

And I try the check logs for this job executing request: http://localhost:4001/processes/file2string_array/jobs/e5df41b0-6c26-4db4-8543-a101b6f678ea/logs

["[2021-07-07 11:16:15] INFO [weaver.datatype.Job] 00:00:00 1% accepted Job task setup completed.","[2021-07-07 11:16:15] DEBUG [weaver.datatype.Job] 00:00:00 2% accepted Employed WPS URL: [http://weaver-api:4001/ows/wps]","[2021-07-07 11:16:15] INFO [weaver.datatype.Job] 00:00:00 2% accepted Execute WPS request for process [file2string_array]","[2021-07-07 11:16:16] INFO [weaver.datatype.Job] 00:00:00 3% accepted Fetching job input definitions.","[2021-07-07 11:16:16] INFO [weaver.datatype.Job] 00:00:00 4% accepted Fetching job output definitions.","[2021-07-07 11:16:16] INFO [weaver.datatype.Job] 00:00:00 5% accepted Starting job process execution.","[2021-07-07 11:16:16] INFO [weaver.datatype.Job] 00:00:00 5% accepted Following updates could take a while until the Application Package answers...","[2021-07-07 11:16:18] DEBUG [weaver.datatype.Job] 00:00:02 6% accepted Updated job status location: [/tmp/weaver/wps-outputs/e5df41b0-6c26-4db4-8543-a101b6f678ea.xml].","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 7% running Starting monitoring of job execution.","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 8% running [2021-07-07 11:16:16] INFO [weaver.processes.wps_package.file2string_array] 1% running Preparing package logs done.","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 10% running [2021-07-07 11:16:16] INFO [weaver.processes.wps_package.file2string_array] 2% running Launching package...","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 13% running [2021-07-07 11:16:16] WARNING [weaver.processes.wps_package.file2string_array] Visible application CWL euid:egid [0:0]","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 15% running [2021-07-07 11:16:16] INFO [cwltool] Resolved '/tmp/tmp2vyf62ld/file2string_array' to 'file:///tmp/tmp2vyf62ld/file2string_array'","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 18% running [2021-07-07 11:16:16] INFO [cwltool] ../../../../tmp/tmp2vyf62ld/file2string_array:1:1: Unknown hint","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 20% running file:///tmp/tmp2vyf62ld/BuiltinRequirement","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 23% running [2021-07-07 11:16:16] INFO [weaver.processes.wps_package.file2string_array] 5% running Loading package content done.","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 26% running [2021-07-07 11:16:16] INFO [weaver.processes.wps_package.file2string_array] 6% running Retrieve package inputs done.","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 28% running [2021-07-07 11:16:16] INFO [weaver.processes.wps_package.file2string_array] File input (input) SKIPPED fetch: [config/files.txt]","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 31% running [2021-07-07 11:16:18] INFO [weaver.processes.wps_package.file2string_array] 8% running Convert package inputs done.","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 33% running [2021-07-07 11:16:18] INFO [weaver.processes.wps_package.file2string_array] 10% running Running package...","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 36% running [2021-07-07 11:16:18] INFO [cwltool] [job file2string_array] /tmp/weaver/wps-workdir/cwltool_out_gx5s9106$ /opt/local/src/weaver/bin/python \","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 39% running /opt/local/src/weaver/weaver/processes/builtin/file2string_array.py \","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 41% running -o \","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 44% running /tmp/weaver/wps-workdir/cwltool_out_gx5s9106 \","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 46% running -i \","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 49% running config/files.txt > /tmp/weaver/wps-workdir/cwltool_out_gx5s9106/stdout.log 2> /tmp/weaver/wps-workdir/cwltool_out_gx5s9106/stderr.log","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 52% running [2021-07-07 11:16:18] ERROR [cwltool] '/opt/local/src/weaver/bin/python' not found: [Errno 2] No such file or directory: '/opt/local/src/weaver/bin/python': '/opt/local/src/weaver/bin/python'","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 54% running [2021-07-07 11:16:18] WARNING [cwltool] [job file2string_array] completed permanentFail","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 57% running [2021-07-07 11:16:18] WARNING [weaver.processes.wps_package.file2string_array] 10% failed Could not retrieve any internal application log.","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 59% running Traceback (most recent call last):","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 62% running File "/opt/local/src/weaver/weaver/processes/wps_package.py", line 1063, in _handler","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 64% running result = package_inst(**cwl_inputs) # type: CWLResults","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 67% running File "/usr/local/lib/python3.7/site-packages/cwltool/factory.py", line 33, in call","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 70% running raise WorkflowStatus(out, status)","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 72% running cwltool.factory.WorkflowStatus: Completed permanentFail","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 75% running [2021-07-07 11:16:18] ERROR [weaver.processes.wps_package.file2string_array] 10% failed PackageExecutionError: Failed package execution. [WorkflowStatus('Completed permanentFail')]","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 77% running Traceback (most recent call last):","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 80% running File "/opt/local/src/weaver/weaver/processes/wps_package.py", line 1063, in _handler","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 83% running result = package_inst(**cwl_inputs) # type: CWLResults","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 85% running File "/usr/local/lib/python3.7/site-packages/cwltool/factory.py", line 33, in call","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 88% running raise WorkflowStatus(out, status)","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 90% running cwltool.factory.WorkflowStatus: Completed permanentFail","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 93% running [2021-07-07 11:16:18] INFO [weaver.processes.wps_package.file2string_array] 10% failed Package completed with errors. Server logs: /tmp/weaver/wps-outputs/e5df41b0-6c26-4db4-8543-a101b6f678ea.log","[2021-07-07 11:16:18] ERROR [weaver.datatype.Job] 00:00:02 96% failed Process failed, please check server error log - code=NoApplicableCode - locator=None","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 98% failed Job failed.","[2021-07-07 11:16:18] INFO [weaver.datatype.Job] 00:00:02 100% failed Job task complete."]

The next log is for docker compose execution:

mongodb | 2021-07-07T11:16:14.662+0000 I NETWORK [thread1] connection accepted from 172.20.0.5:40574 #167 (33 connections now open)
mongodb | 2021-07-07T11:16:14.663+0000 I NETWORK [conn167] received client metadata from 172.20.0.5:40574 conn167: { driver: { name: "PyMongo", version: "3.11.4" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "5.4.72-microsoft-standard-WSL2" }, platform: "CPython 3.7.10.final.0" }
mongodb | 2021-07-07T11:16:14.666+0000 I NETWORK [thread1] connection accepted from 172.20.0.5:40576 #168 (34 connections now open)
mongodb | 2021-07-07T11:16:14.666+0000 I NETWORK [conn168] received client metadata from 172.20.0.5:40576 conn168: { driver: { name: "PyMongo", version: "3.11.4" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "5.4.72-microsoft-standard-WSL2" }, platform: "CPython 3.7.10.final.0" }
mongodb | 2021-07-07T11:16:14.678+0000 I - [conn168] end connection 172.20.0.5:40576 (34 connections now open)
mongodb | 2021-07-07T11:16:14.678+0000 I - [conn167] end connection 172.20.0.5:40574 (34 connections now open)
weaver-api | [2021-07-07 11:16:14,680] INFO [MainThread][PYWPS] Request: execute
mongodb | 2021-07-07T11:16:14.688+0000 I NETWORK [thread1] connection accepted from 172.20.0.5:40578 #169 (33 connections now open)
mongodb | 2021-07-07T11:16:14.688+0000 I NETWORK [conn169] received client metadata from 172.20.0.5:40578 conn169: { driver: { name: "PyMongo", version: "3.11.4" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "5.4.72-microsoft-standard-WSL2" }, platform: "CPython 3.7.10.final.0" }
mongodb | 2021-07-07T11:16:14.691+0000 I NETWORK [thread1] connection accepted from 172.20.0.5:40580 #170 (34 connections now open)
mongodb | 2021-07-07T11:16:14.692+0000 I NETWORK [conn170] received client metadata from 172.20.0.5:40580 conn170: { driver: { name: "PyMongo", version: "3.11.4" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "5.4.72-microsoft-standard-WSL2" }, platform: "CPython 3.7.10.final.0" }
mongodb | 2021-07-07T11:16:14.704+0000 I - [conn170] end connection 172.20.0.5:40580 (34 connections now open)
mongodb | 2021-07-07T11:16:14.704+0000 I - [conn169] end connection 172.20.0.5:40578 (34 connections now open)
mongodb | 2021-07-07T11:16:14.711+0000 I NETWORK [thread1] connection accepted from 172.20.0.5:40582 #171 (33 connections now open)
mongodb | 2021-07-07T11:16:14.711+0000 I NETWORK [conn171] received client metadata from 172.20.0.5:40582 conn171: { driver: { name: "PyMongo", version: "3.11.4" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "5.4.72-microsoft-standard-WSL2" }, platform: "CPython 3.7.10.final.0" }
mongodb | 2021-07-07T11:16:14.714+0000 I NETWORK [thread1] connection accepted from 172.20.0.5:40584 #172 (34 connections now open)
mongodb | 2021-07-07T11:16:14.715+0000 I NETWORK [conn172] received client metadata from 172.20.0.5:40584 conn172: { driver: { name: "PyMongo", version: "3.11.4" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "5.4.72-microsoft-standard-WSL2" }, platform: "CPython 3.7.10.final.0" }
mongodb | 2021-07-07T11:16:14.731+0000 I - [conn172] end connection 172.20.0.5:40584 (34 connections now open)
mongodb | 2021-07-07T11:16:14.731+0000 I - [conn171] end connection 172.20.0.5:40582 (34 connections now open)
weaver-worker | [2021-07-07 11:16:15,733] INFO [MainThread][celery.worker.strategy] Received task: weaver.processes.execution.execute_process[6e7ff531-145c-4d32-9c65-a75753eb2a27]
weaver-worker | [2021-07-07 11:16:15,742] INFO [MainThread][weaver.wps.utils] Initial load of internal Weaver WPS configuration.
weaver-worker | [2021-07-07 11:16:15,745] INFO [MainThread][PYWPS] loading configuration
weaver-worker | [2021-07-07 11:16:15,753] INFO [MainThread][PYWPS] No configuration files loaded. Using default values
mongodb | 2021-07-07T11:16:15.786+0000 I NETWORK [thread1] connection accepted from 172.20.0.3:34098 #173 (33 connections now open)
mongodb | 2021-07-07T11:16:15.788+0000 I NETWORK [conn173] received client metadata from 172.20.0.3:34098 conn173: { driver: { name: "PyMongo", version: "3.11.4" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "5.4.72-microsoft-standard-WSL2" }, platform: "CPython 3.7.10.final.0" }
mongodb | 2021-07-07T11:16:15.792+0000 I NETWORK [thread1] connection accepted from 172.20.0.3:34100 #174 (34 connections now open)
mongodb | 2021-07-07T11:16:15.793+0000 I NETWORK [conn174] received client metadata from 172.20.0.3:34100 conn174: { driver: { name: "PyMongo", version: "3.11.4" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "5.4.72-microsoft-standard-WSL2" }, platform: "CPython 3.7.10.final.0" }
weaver-worker | [2021-07-07 11:16:15,814] WARNING [MainThread][py.warnings] /opt/local/src/weaver/weaver/utils.py:307: TimeZoneInfoAlreadySetWarning: tzinfo already set
weaver-worker | warnings.warn("tzinfo already set", TimeZoneInfoAlreadySetWarning)
weaver-worker |
weaver-worker | [2021-07-07 11:16:15,816] INFO [MainThread][weaver.processes.execution] 00:00:00 1% accepted Job task setup completed.
weaver-worker | [2021-07-07 11:16:15,830] INFO [MainThread][weaver.processes.execution] 00:00:00 2% accepted Execute WPS request for process [file2string_array]
mongodb | 2021-07-07T11:16:15.871+0000 I NETWORK [thread1] connection accepted from 172.20.0.5:40592 #175 (35 connections now open)
mongodb | 2021-07-07T11:16:15.872+0000 I NETWORK [conn175] received client metadata from 172.20.0.5:40592 conn175: { driver: { name: "PyMongo", version: "3.11.4" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "5.4.72-microsoft-standard-WSL2" }, platform: "CPython 3.7.10.final.0" }
mongodb | 2021-07-07T11:16:15.875+0000 I NETWORK [thread1] connection accepted from 172.20.0.5:40594 #176 (36 connections now open)
mongodb | 2021-07-07T11:16:15.876+0000 I NETWORK [conn176] received client metadata from 172.20.0.5:40594 conn176: { driver: { name: "PyMongo", version: "3.11.4" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "5.4.72-microsoft-standard-WSL2" }, platform: "CPython 3.7.10.final.0" }
mongodb | 2021-07-07T11:16:15.901+0000 I - [conn176] end connection 172.20.0.5:40594 (36 connections now open)
mongodb | 2021-07-07T11:16:15.902+0000 I - [conn175] end connection 172.20.0.5:40592 (35 connections now open)
weaver-api | [2021-07-07 11:16:15,904] INFO [MainThread][PYWPS] Request: getcapabilities
mongodb | 2021-07-07T11:16:16.029+0000 I NETWORK [thread1] connection accepted from 172.20.0.5:40598 #177 (35 connections now open)
mongodb | 2021-07-07T11:16:16.030+0000 I NETWORK [conn177] received client metadata from 172.20.0.5:40598 conn177: { driver: { name: "PyMongo", version: "3.11.4" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "5.4.72-microsoft-standard-WSL2" }, platform: "CPython 3.7.10.final.0" }
mongodb | 2021-07-07T11:16:16.033+0000 I NETWORK [thread1] connection accepted from 172.20.0.5:40600 #178 (36 connections now open)
mongodb | 2021-07-07T11:16:16.034+0000 I NETWORK [conn178] received client metadata from 172.20.0.5:40600 conn178: { driver: { name: "PyMongo", version: "3.11.4" }, os: { type: "Linux", name: "Linux", architecture: "x86_64", version: "5.4.72-microsoft-standard-WSL2" }, platform: "CPython 3.7.10.final.0" }
mongodb | 2021-07-07T11:16:16.054+0000 I - [conn178] end connection 172.20.0.5:40600 (36 connections now open)
mongodb | 2021-07-07T11:16:16.054+0000 I - [conn177] end connection 172.20.0.5:40598 (35 connections now open)
weaver-api | [2021-07-07 11:16:16,055] INFO [MainThread][PYWPS] Request: describeprocess
weaver-worker | [2021-07-07 11:16:16,201] INFO [MainThread][owslib] b'<wps:ProcessDescriptions xmlns:wps="http://www.opengis.net/wps/1.0.0" xmlns:ows="http://www.opengis.net/ows/1.1" xmlns:xlink="http://www.w3.org/1999/xlink" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:schemaLocation="http://www.opengis.net/wps/1.0.0 ../wpsDescribeProcess_response.xsd" service="WPS" version="1.0.0" xml:lang="en-US">\n \n ows:Identifierfile2string_array</ows:Identifier>\n ows:TitleNone</ows:Title>\n ows:AbstractTransforms a file input into JSON file containing an array of file references as value.</ows:Abstract>\n \n \n ows:Identifierinput</ows:Identifier>\n ows:Titleinput</ows:Title>\n ows:Abstract/\n \n \n \n text/plain\n \n \n \n \n text/plain\n \n \n \n \n \n \n \n ows:Identifieroutput</ows:Identifier>\n ows:Titleoutput</ows:Title>\n ows:Abstract/\n \n \n \n application/json\n \n \n \n \n application/json\n \n \n \n \n \n \n</wps:ProcessDescriptions>'
weaver-worker | [2021-07-07 11:16:16,204] INFO [MainThread][weaver.processes.execution] 00:00:00 3% accepted Fetching job input definitions.
weaver-worker | [2021-07-07 11:16:16,206] INFO [MainThread][weaver.processes.execution] 00:00:00 4% accepted Fetching job output definitions.
weaver-worker | [2021-07-07 11:16:16,208] INFO [MainThread][weaver.processes.execution] 00:00:00 5% accepted Starting job process execution.
weaver-worker | [2021-07-07 11:16:16,210] INFO [MainThread][weaver.processes.execution] 00:00:00 5% accepted Following updates could take a while until the Application Package answers...
weaver-worker | [2021-07-07 11:16:16,513] INFO [MainThread][PYWPS] Setting HOME to current working directory: /tmp/weaver/wps-workdir/pywps_process_tq49wqbt
weaver-worker | [2021-07-07 11:16:16,521] INFO [MainThread][weaver.processes.wps_package.file2string_array] 1% running Preparing package logs done.
weaver-worker | [2021-07-07 11:16:16,524] INFO [MainThread][weaver.processes.wps_package.file2string_array] 2% running Launching package...
weaver-worker | [2021-07-07 11:16:16,525] WARNING [MainThread][weaver.processes.wps_package.file2string_array] Visible application CWL euid:egid [0:0]
weaver-worker | [2021-07-07 11:16:16,527] INFO [MainThread][cwltool] Resolved '/tmp/tmp2vyf62ld/file2string_array' to 'file:///tmp/tmp2vyf62ld/file2string_array'
weaver-worker | ../../../../tmp/tmp2vyf62ld/file2string_array:1:697: checking item
weaver-worker | Field class contains undefined reference
weaver-worker | to file:///tmp/tmp2vyf62ld/BuiltinRequirement
weaver-worker | [2021-07-07 11:16:16,550] WARNING [MainThread][salad] ../../../../tmp/tmp2vyf62ld/file2string_array:1:697: checking item
weaver-worker | Field class contains undefined reference
weaver-worker | to file:///tmp/tmp2vyf62ld/BuiltinRequirement
weaver-worker | [2021-07-07 11:16:16,564] INFO [MainThread][cwltool] ../../../../tmp/tmp2vyf62ld/file2string_array:1:1: Unknown hint
weaver-worker | file:///tmp/tmp2vyf62ld/BuiltinRequirement
weaver-worker | [2021-07-07 11:16:16,569] INFO [MainThread][weaver.processes.wps_package.file2string_array] 5% running Loading package content done.
weaver-worker | [2021-07-07 11:16:16,572] INFO [MainThread][weaver.processes.wps_package.file2string_array] 6% running Retrieve package inputs done.
weaver-worker | [2021-07-07 11:16:16,573] INFO [MainThread][weaver.processes.wps_package.file2string_array] File input (input) SKIPPED fetch: [config/files.txt]
weaver-worker | [2021-07-07 11:16:17,169] WARNING [MainThread][py.warnings] /usr/local/lib/python3.7/site-packages/urllib3/connectionpool.py:1020: InsecureRequestWarning: Unverified HTTPS request is being made to host 'www.iana.org'. Adding certificate verification is strongly advised. See: https://urllib3.readthedocs.io/en/latest/advanced-usage.html#ssl-warnings
weaver-worker | InsecureRequestWarning,
weaver-worker |
weaver-worker | [2021-07-07 11:16:18,162] INFO [MainThread][weaver.processes.wps_package.file2string_array] 8% running Convert package inputs done.
weaver-worker | [2021-07-07 11:16:18,198] INFO [MainThread][weaver.processes.wps_package.file2string_array] 10% running Running package...
weaver-worker | [2021-07-07 11:16:18,290] INFO [MainThread][cwltool] [job file2string_array] /tmp/weaver/wps-workdir/cwltool_out_gx5s9106$ /opt/local/src/weaver/bin/python
weaver-worker | /opt/local/src/weaver/weaver/processes/builtin/file2string_array.py
weaver-worker | -o
weaver-worker | /tmp/weaver/wps-workdir/cwltool_out_gx5s9106
weaver-worker | -i
weaver-worker | config/files.txt > /tmp/weaver/wps-workdir/cwltool_out_gx5s9106/stdout.log 2> /tmp/weaver/wps-workdir/cwltool_out_gx5s9106/stderr.log
weaver-worker | [2021-07-07 11:16:18,308] ERROR [MainThread][cwltool] '/opt/local/src/weaver/bin/python' not found: [Errno 2] No such file or directory: '/opt/local/src/weaver/bin/python': '/opt/local/src/weaver/bin/python'
weaver-worker | [2021-07-07 11:16:18,309] WARNING [MainThread][cwltool] [job file2string_array] completed permanentFail
weaver-worker | [2021-07-07 11:16:18,314] WARNING [MainThread][weaver.processes.wps_package.file2string_array] 10% failed Could not retrieve any internal application log.
weaver-worker | Traceback (most recent call last):
weaver-worker | File "/opt/local/src/weaver/weaver/processes/wps_package.py", line 1063, in _handler
weaver-worker | result = package_inst(**cwl_inputs) # type: CWLResults
weaver-worker | File "/usr/local/lib/python3.7/site-packages/cwltool/factory.py", line 33, in call
weaver-worker | raise WorkflowStatus(out, status)
weaver-worker | cwltool.factory.WorkflowStatus: Completed permanentFail
weaver-worker | [2021-07-07 11:16:18,317] ERROR [MainThread][weaver.processes.wps_package.file2string_array] 10% failed PackageExecutionError: Failed package execution. [WorkflowStatus('Completed permanentFail')]
weaver-worker | Traceback (most recent call last):
weaver-worker | File "/opt/local/src/weaver/weaver/processes/wps_package.py", line 1063, in _handler
weaver-worker | result = package_inst(**cwl_inputs) # type: CWLResults
weaver-worker | File "/usr/local/lib/python3.7/site-packages/cwltool/factory.py", line 33, in call
weaver-worker | raise WorkflowStatus(out, status)
weaver-worker | cwltool.factory.WorkflowStatus: Completed permanentFail
weaver-worker | [2021-07-07 11:16:18,327] INFO [MainThread][PYWPS] Removing temporary working directory: /tmp/weaver/wps-workdir/pywps_process_tq49wqbt
weaver-worker | [2021-07-07 11:16:18,327] INFO [MainThread][weaver.processes.wps_package.file2string_array] 10% failed Package completed with errors. Server logs: /tmp/weaver/wps-outputs/e5df41b0-6c26-4db4-8543-a101b6f678ea.log
weaver-worker | Traceback (most recent call last):
weaver-worker | File "/opt/local/src/weaver/weaver/processes/wps_package.py", line 1063, in _handler
weaver-worker | result = package_inst(**cwl_inputs) # type: CWLResults
weaver-worker | File "/usr/local/lib/python3.7/site-packages/cwltool/factory.py", line 33, in call
weaver-worker | raise WorkflowStatus(out, status)
weaver-worker | cwltool.factory.WorkflowStatus: Completed permanentFail
weaver-worker |
weaver-worker | During handling of the above exception, another exception occurred:
weaver-worker |
weaver-worker | Traceback (most recent call last):
weaver-worker | File "/usr/local/lib/python3.7/site-packages/pywps/app/Process.py", line 250, in _run_process
weaver-worker | self.handler(wps_request, wps_response) # the user must update the wps_response.
weaver-worker | File "/opt/local/src/weaver/weaver/processes/wps_package.py", line 1069, in _handler
weaver-worker | raise self.exception_message(PackageExecutionError, exc, "Failed package execution.")
weaver-worker | weaver.exceptions.PackageExecutionError: Failed package execution. [WorkflowStatus('Completed permanentFail')]
weaver-worker | [2021-07-07 11:16:18,328] ERROR [MainThread][PYWPS] Process error: method=wps_package.py._handler, line=1069, msg=Failed package execution. [WorkflowStatus('Completed permanentFail')]
weaver-worker | [2021-07-07 11:16:18,361] INFO [MainThread][PYWPS] Removing temporary working directory: /tmp/weaver/wps-workdir/pywps_process_tq49wqbt
weaver-worker | [2021-07-07 11:16:18,368] INFO [MainThread][owslib] Execution status=Exception
weaver-worker | [2021-07-07 11:16:18,368] INFO [MainThread][owslib] Percent completed=0
weaver-worker | [2021-07-07 11:16:18,368] INFO [MainThread][owslib] Status message=
weaver-worker |
weaver-worker | [2021-07-07 11:16:18,370] INFO [MainThread][weaver.processes.execution] 00:00:02 7% running Starting monitoring of job execution.
weaver-worker | [2021-07-07 11:16:18,375] INFO [MainThread][owslib] Execution status=Exception
weaver-worker | [2021-07-07 11:16:18,376] INFO [MainThread][owslib] Percent completed=0
weaver-worker | [2021-07-07 11:16:18,376] INFO [MainThread][owslib] Status message=
weaver-worker |
weaver-worker | [2021-07-07 11:16:18,380] ERROR [MainThread][weaver.processes.execution] 00:00:02 96% failed Process failed, please check server error log - code=NoApplicableCode - locator=None
weaver-worker | [2021-07-07 11:16:18,383] INFO [MainThread][weaver.processes.execution] 00:00:02 98% failed Job failed.
weaver-worker | [2021-07-07 11:16:18,384] INFO [MainThread][weaver.processes.execution] 00:00:02 100% failed Job task complete.
weaver-worker | [2021-07-07 11:16:18,388] INFO [MainThread][celery.app.trace] Task weaver.processes.execution.execute_process[6e7ff531-145c-4d32-9c65-a75753eb2a27] succeeded in 2.6483950999972876s: 'failed'

  • OS: Linux (Docker context)
  • Browser: chrome
  • Instance: EMS
  • Version: 3.2.1

Thanks for all,
Best regards
@pedringcoding pedringcoding added the triage/bug Something isn't working label Jul 7, 2021
@fmigneault
Copy link
Collaborator

Thanks for the issue. It's a valid bug for that process,
Fix will be in a upcoming version.

@pedringcoding
Copy link
Author

That's excellent news!
That’s really nice of you @fmigneault

fmigneault added a commit that referenced this issue Jul 16, 2021
@fmigneault
update changelog notes about file2string_array (fixes #275)
a7f2842
@fmigneault fmigneault linked a pull request Jul 16, 2021 that will close this issue
Open
@pedringcoding pedringcoding mentioned this issue Sep 2, 2021
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@fmigneault fmigneault

Labels
triage/bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Fix python file2stringarray crim-ca/weaver
2 participants
@fmigneault @pedringcoding