TypeError: pdf_job is undefined

Rdornier commented 4 months ago

Hello @will-moore,

I've noticed an error when exporting the PDF of the figure.

Uncaught TypeError: pdf_job is undefined
    i https://localhost/static/figure/figure.js?version=6.1.0:3929
    jQuery 8
    i https://localhost/static/figure/figure.js?version=6.1.0:3924
figure.js:3929:33

Sometimes, it is followed by a second error

Uncaught TypeError: pdf_job.results is undefined

and this second error stops the code before creating the download button. Thus, the figure cannot be downloaded, and it is not attached to any images.

This first error is reproducible by just exporting the Figure as PDF ; I couldn't find a way to reproduce the second one. It first happend when I tried to export a figure which already exist on the database.

Rémy ping @gaelrayot-epfl

will-moore commented 4 months ago

It looks like the export has failed in some way and that this isn't being handled by figure app very well. Do all Figures have the first error? Is your figure export completely failing? Can you check the OMERO.web logs $OMERODIR/var/log/ and the server logs?

In the first case, where pdf_job is undefined it seems to be missing from the activities JSON data: var pdf_job = act_data[jobId]; which suggests there was a problem when the script started running, since that's when the "in progress" job gets added to the activities list that's stored in the session.

The 2nd error comes after it is "finished" but there's no results.

I wonder if you could check the 'Activities' panel in webclient (where you normally see script results). The figure export should show up here as it's added to the same list of activities. This view might do a better job of handling the script results and hopefully allow you to see any stderr and stdout. Although in the first case it might not show up at all.

But it looks like OMERO.figure should do a better job here and not fail if there's no job or results.

gaelrayot-epfl commented 4 months ago

There is no relevant log on the server side, just some info like this:

2024-02-28 09:32:23,086  INFO [                           omero.gateway] (proc.831704) connect():2273 created connection (uuid=60b520f1-8a0a-4f4a-8b6c-358984a1e3ef)
2024-02-28 09:32:23,087  INFO [                omeroweb.webclient.views] (proc.831704) activities():3847 Check callback on script: ProcessCallback/87c5ad4f-c7e3-4398-9356-29b6e32f6529 -t -e 1.1:tcp -h XXX.XXX.XXX.XXX -p 35089 -t 60000
2024-02-28 09:32:23,365  INFO [                           omero.gateway] (proc.831704) close():1987 closed connection (uuid=60b520f1-8a0a-4f4a-8b6c-358984a1e3ef)

While checking the logs, I just realized that when you click on the 'Export PDF' button a second time after the first export, the JS still use the old JobID: the log on the server give me a new processcallback while on the client side, the JobID has not changed and is still the same as the first export even if I make some changes to the figure.

Hope this helps...

Rdornier commented 4 months ago

Hi,

Thanks for your answers.

Do all Figures have the first error?

Yes, this error always occur at the end of the export.

Is your figure export completely failing?

The figure export is failing ONYL if the second error appears. Otherwise, the PDF is readable and downloadable. By failing, I mean not downloadable.

I wonder if you could check the 'Activities' panel in webclient (where you normally see script results).

I've checked it ; there is no stderr neither stdout in the logs (only <__main__.FigureExport object at 0x7fb1cb04dd60>)

While checking the logs, I just realized that when you click on the 'Export PDF' button a second time after the first export, the JS still use the old JobID: the log on the server give me a new processcallback while on the client side, the JobID has not changed and is still the same as the first export even if I make some changes to the figure.

This may explain the second error.

Rémy.

will-moore commented 4 months ago

"The first error always occur at the end of the export" but "the figure export is failing ONLY if the second error appears".

So that means that when you see the first error pdf_job is undefined the figure export doesn't fail and the PDF is downloadable?

Can you try to inspect where in the code that error is coming from, because I can't understand how the PDF download button is enabled etc if the pdf_job is undefined. I would guess it's at https://github.com/ome/omero-figure/blob/3b7ccfa865a44b0309b69c6dca34af2d12343a5d/src/js/views/figure_view.js#L254C33-L254C40

While checking the logs, I just realized that when you click on the 'Export PDF' button a second time after the first export, the JS still use the old JobID:

You're checking the JobID in the JS with the browser debugger? Could you check in the dev-tools the response to the POST request that is sent when you export the Figure? In particular, the "jobId" in the JSON response to see if it changes each time?

It might also be useful to inspect the Activities JSON data that is loaded repeatedly while the script is running and a final time when it is finished.

gaelrayot-epfl commented 4 months ago

You're checking the JobID in the JS with the browser debugger?

Yes, line 3926 where the pdf_job is defined

Could you check in the dev-tools the response to the POST request that is sent when you export the Figure? In particular, the "jobId" in the JSON response to see if it changes each time?

The JobId returned by server is not the same between 2 exports. Here is an example First request: {"jobId": "ProcessCallback/edf77f1a-ed7f-4bf6-ad5b-270116f1e3e1 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000", "status": "in progress"} Second request for a new export: {"jobId": "ProcessCallback/2f29efda-610e-4e62-9f70-e849b3941611 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000", "status": "in progress"}

It might also be useful to inspect the Activities JSON data that is loaded repeatedly while the script is running and a final time when it is finished.

Activities during the process: {"ProcessCallback/48f3e776-0259-4b13-8c4b-c77b366390d3 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-28 06:44:28.162288", "status": "finished", "returncode": 0, "Message": "Figure created", "stdout": 49903, "results": {"New_Figure": {"id": 2558, "type": "FileAnnotation", "browse_url": "/webclient/userdata/?show=image-2251", "name": "Figure_2024-2-28_7-44-28.pdf"}}}, "ProcessCallback/b3568d03-f8a6-4c3d-9f6e-acce91de623e -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-28 06:46:48.315874", "status": "finished", "returncode": 0, "Message": "Figure created", "stdout": 49905, "results": {"New_Figure": {"id": 2559, "type": "FileAnnotation", "browse_url": "/webclient/userdata/?show=image-2251", "name": "Figure_2024-2-28_7-46-49.pdf"}}}, "ProcessCallback/a3f49269-2a75-4da4-ac50-12b82950b19b -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-28 06:55:59.077822", "status": "finished", "returncode": 0, "Message": "Figure created", "stdout": 49907, "results": {"New_Figure": {"id": 2560, "type": "FileAnnotation", "browse_url": "/webclient/userdata/?show=image-2251", "name": "Figure_2024-2-28_7-55-59.pdf"}}}, "ProcessCallback/87c5ad4f-c7e3-4398-9356-29b6e32f6529 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-28 09:32:12.920653", "status": "finished", "returncode": 0, "Message": "Figure created", "stdout": 49909, "results": {"New_Figure": {"id": 2561, "type": "FileAnnotation", "browse_url": "/webclient/userdata/?show=image-2252", "name": "Figure_2024-2-28_10-32-13.pdf"}}}, "ProcessCallback/6e62b00d-0787-4ec0-8030-697eeae7bf18 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-28 09:35:40.070100", "status": "finished", "returncode": 0, "Message": "Figure created", "stdout": 49911, "results": {"New_Figure": {"id": 2562, "type": "FileAnnotation", "browse_url": "/webclient/userdata/?show=image-2252", "name": "Figure_2024-2-28_10-35-40.pdf"}}}, "ProcessCallback/9ff782ee-c566-4740-baa0-b48bb0ba32a3 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-28 09:40:04.768406", "status": "finished", "returncode": 0, "Message": "Figure created", "stdout": 49913, "results": {"New_Figure": {"id": 2563, "type": "FileAnnotation", "browse_url": "/webclient/userdata/?show=image-2252", "name": "Figure_2024-2-28_10-40-5.pdf"}}}, "ProcessCallback/edf77f1a-ed7f-4bf6-ad5b-270116f1e3e1 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-29 06:59:18.405518", "status": "in progress"}, "inprogress": 1, "failure": 0, "jobs": 7}

Last call: {"ProcessCallback/48f3e776-0259-4b13-8c4b-c77b366390d3 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-28 06:44:28.162288", "status": "finished", "returncode": 0, "Message": "Figure created", "stdout": 49903, "results": {"New_Figure": {"id": 2558, "type": "FileAnnotation", "browse_url": "/webclient/userdata/?show=image-2251", "name": "Figure_2024-2-28_7-44-28.pdf"}}}, "ProcessCallback/b3568d03-f8a6-4c3d-9f6e-acce91de623e -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-28 06:46:48.315874", "status": "finished", "returncode": 0, "Message": "Figure created", "stdout": 49905, "results": {"New_Figure": {"id": 2559, "type": "FileAnnotation", "browse_url": "/webclient/userdata/?show=image-2251", "name": "Figure_2024-2-28_7-46-49.pdf"}}}, "ProcessCallback/a3f49269-2a75-4da4-ac50-12b82950b19b -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-28 06:55:59.077822", "status": "finished", "returncode": 0, "Message": "Figure created", "stdout": 49907, "results": {"New_Figure": {"id": 2560, "type": "FileAnnotation", "browse_url": "/webclient/userdata/?show=image-2251", "name": "Figure_2024-2-28_7-55-59.pdf"}}}, "ProcessCallback/87c5ad4f-c7e3-4398-9356-29b6e32f6529 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-28 09:32:12.920653", "status": "finished", "returncode": 0, "Message": "Figure created", "stdout": 49909, "results": {"New_Figure": {"id": 2561, "type": "FileAnnotation", "browse_url": "/webclient/userdata/?show=image-2252", "name": "Figure_2024-2-28_10-32-13.pdf"}}}, "ProcessCallback/6e62b00d-0787-4ec0-8030-697eeae7bf18 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-28 09:35:40.070100", "status": "finished", "returncode": 0, "Message": "Figure created", "stdout": 49911, "results": {"New_Figure": {"id": 2562, "type": "FileAnnotation", "browse_url": "/webclient/userdata/?show=image-2252", "name": "Figure_2024-2-28_10-35-40.pdf"}}}, "ProcessCallback/9ff782ee-c566-4740-baa0-b48bb0ba32a3 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-28 09:40:04.768406", "status": "finished", "returncode": 0, "Message": "Figure created", "stdout": 49913, "results": {"New_Figure": {"id": 2563, "type": "FileAnnotation", "browse_url": "/webclient/userdata/?show=image-2252", "name": "Figure_2024-2-28_10-40-5.pdf"}}}, "ProcessCallback/edf77f1a-ed7f-4bf6-ad5b-270116f1e3e1 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000": {"job_type": "script", "job_name": "Figure.pdf", "start_time": "2024-02-29 06:59:18.405518", "status": "finished", "returncode": 0, "Message": "Figure created", "stdout": 49950, "results": {"New_Figure": {"id": 2567, "type": "FileAnnotation", "browse_url": "/webclient/userdata/?show=image-2252", "name": "Figure_2024-2-29_7-59-19.pdf"}}}, "inprogress": 0, "failure": 0, "jobs": 7}

Rdornier commented 4 months ago

So that means that when you see the first error pdf_job is undefined the figure export doesn't fail and the PDF is downloadable?

Yes, and I don't really know how this is possible.

I would guess it's at https://github.com/ome/omero-figure/blob/3b7ccfa865a44b0309b69c6dca34af2d12343a5d/src/js/views/figure_view.js#L254C33-L254C40

Exact

I also noticed that it may also be due to the python environment. Those errors are not happening with python 3.6 whereas they first occur when we update the server with python 3.8, to be able to install the omero.web 5.24.0.

will-moore commented 4 months ago

I wonder if this is related to https://github.com/ome/omero-figure/pull/523 - You could have a different Pillow version with python 3.8 and this would cause the script to fail if it doesn't include that fix and the figure has labels (since it fails on handling fonts).

That still wouldn't explain why the script error isn't being shown in figure.

In the screenshot of the Activities above there is a (i) icon indicating stdout (but no (!) icon for stderr).

Do either of the errors depend on the contents of the figure being exported. E.g. if you create a new figure with just a single image panel (no labels), do you see the first error? And then you export the same figure a second time, do you see the 2nd error?

Rdornier commented 4 months ago

I wonder if this is related to https://github.com/ome/omero-figure/pull/523 - You could have a different Pillow version with python 3.8 and this would cause the script to fail if it doesn't include that fix and the figure has labels (since it fails on handling fonts).

We have Pillow 10.2.0 installed.

Do either of the errors depend on the contents of the figure being exported. E.g. if you create a new figure with just a single image panel (no labels), do you see the first error?

Unfortunately yes, the error still happens

And then you export the same figure a second time, do you see the 2nd error?

No, only the first one. What I found very weird is that I'm not able to reproduce this second error. We've configure our test server with the same configs for which it happened. I'm wondering if this second error could be due to the cache of the previous version that was not clean correctly right after the update (client side) and, somehow, introduces a mess.

will-moore commented 3 months ago

OK, let's focus on the first error...

When an export script is launched we POST the details and we get back a response that contains the jobId: E.g. As above:

{"jobId": "ProcessCallback/edf77f1a-ed7f-4bf6-ad5b-270116f1e3e1 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000", "status": "in progress"}

Then we keep fetching the Activities JSON, and this should include a response where the jobId is a key. In the responses above, the first jobId ProcessCallback/edf77f1a-ed7f-4bf6-ad5b-270116f1e3e1 -t -e 1.1:tcp -h 10.95.48.33 -p 35089 -t 60000 is a key in both the first and last Activities JSON.

In this case var pdf_job = act_data[jobId]; shouldn't give pdf_job as undefined.

@gaelrayot-epfl did you see that error in the first case above?

Starting from a new figure:

with python 3.8 deployment, start with a clean browser (e.g. "incognito") to make sure nothing is cached from before
Export a new figure - check the POST response for jobId
When the script is exporting, do you see pdf_job is undefined error?
When the export completes, do you see pdf_job is undefined error?
Check the content of the last Activities response: does it contain the jobId from when the export was started?
Are you able to download this figure?

will-moore commented 3 months ago

In recent figure testing, I saw a similar error and have opened a bug-fix PR at https://github.com/ome/omero-web/pull/541

will-moore commented 3 months ago

The fix for this is included in omero-web 5.25.0.

Rdornier commented 3 months ago

Nice, thank you very much !

ome / omero-figure

TypeError: pdf_job is undefined #545