Reference based motion correction error ====== Job process terminated abnormally

wtempel · January 18, 2024, 7:18pm

It was not; I apologize. The commands were intended to be run from within the interactive icli, which you can access with the command
cryosparcm icli

Dmitry · January 18, 2024, 9:50pm

hello @wtempel ,

here is the result.

In [2]: puid, juid = ‘P2’, ‘J139’
…: cli.get_job(puid, juid, ‘params_spec’, ‘heartbeat_at’, ‘killed_at’, ‘failed_at’)
…:
Out[2]:
{‘_id’: ‘65a852521e3a4e5ed243eb02’,
‘failed_at’: ‘Thu, 18 Jan 2024 05:42:24 GMT’,
‘heartbeat_at’: ‘Thu, 18 Jan 2024 05:42:23 GMT’,
‘killed_at’: None,
‘params_spec’: {‘compute_num_gpus’: {‘value’: 4},
‘hyparam_search_thoroughness’: {‘value’: ‘Extensive’}},
‘project_uid’: ‘P2’,
‘uid’: ‘J139’}

Kind regards,
Dmitry

rbs_sci · January 19, 2024, 12:25am

First thing I’d test is run on a single GPU and set the oversubscription threshold over the GPU VRAM (e.g. on 16GB, leave at 20, on 24GB, set to 30, etc) and the in-memory cache to 300.

RBMC system RAM usage oscillates a bit based on particles on each micrograph, so it’s possible one micrograph needs >80GB of system RAM… EER data can be particularly heavy if upsampling 2 (I’ve not tried 16K in CryoSPARC…)

Dmitry · January 19, 2024, 11:08am

hello @rbs_sci ,

Thank you for your answer.

Set accordingly:

I will update on the results.

Kind regards,
Dmitry

p.s.
usually this protocol dies on the 19th checkpoint becoming too slow. I believe we will have results today.

rbs_sci · January 19, 2024, 12:02pm

I hope so! Good luck!

Dmitry · January 22, 2024, 3:22pm

hello @wtempel and @rbs_sci,

I am still having the same error. Please see the summary below:

Issue summary –

Reference based motion correction stops all the time on Checkpoint 19
When applying 1 GPU 30 Ram // 300 RAM, I got an error at the Checkpointe 21 with duplicated particles (just as described here - Crash of Reference Based Motion Correction - Motion Correction - CryoSPARC Discuss)
When fixed the error running – Remove duplicate particles – again, the stop error from 1. Returns.

So currently the error remains the same.

I am testing the refinement - if that could caused and issue.

But apart from that I have no idea for now.

Any tips?

Thank you.

Kind regards,
Dmitry

rbs_sci · January 22, 2024, 10:38pm

Hi @Dmitry, that seems very odd…! Sorry, it really sounded like it was running out of memory…

Let me just check that step 3 was run with the same conditions as step 2 (1GPU 30 VRAM, 300 RAM)? It seems odd to me that increasing the hardware parameters changes the crash (and makes it later) but upon fixing the duplicate issue it crashes back where it used to once again…

Does dmesg have anything which might shed further light on the situation?

This is crashing on hyperparameter search…? Can you try fewer particles (say, 5,000)? Even try 1,000 just to see if it can complete successully (although don’t use that parameter set if it does work…

Part of the issue is the TIFFRead spam in the log, which makes it really hard to track anything else (RELION has the same issue by default when motion correcting/polishing EER because libtiff doesn’t understand the EER headers)… if you cat [/path/to/logfile] | grep -v TIFFReadDirectory > ~/tempLog.txt it will filter out all the pointless TIFFRead warnings and make it a little easier to see what’s going on (if it has any information)…

Dmitry · January 23, 2024, 1:33pm

hello @rbs_sci,

I will give a try and report back.

Many thanks.

Regards,
Dmitry

Dmitry · January 27, 2024, 5:20pm

Hello @rbs_sci and @wtempel

I tried to re-run the Reference based motion correction using just a few images as a training and running input.

The results are always the same – the protocol stops at checkpoint #19 regardless of the settings.

The first attempt

The second attempt

The third attempt

– @wtempel , and @hsnyder do you have the test dataset I can run the Reference based motion correction to see what is wrong?
– Can it be some issue with CS installation?
– Can the initial wrong input parameters cause such an issue? What about the total dose?

Additionally, when I try to load the report from each failed protocol (reference-based motion cor)
I get the following error

But finally, the report is being downloaded anyhow.
Let me know if I can send you the reports to you.

Kind regards,
Dmitry

wtempel · January 29, 2024, 12:09am

For testing, you may run Reference Based Motion Correction with outputs from Extensive Validation with the T20s subset:

“Movies” from the validation’s Patch Motion Correction
particles and volume from the validation’s Homogeneous Refinement

Is your CryoSPARC master computer also acting as a GPU worker for the aforementioned motion correction jobs? Was a job running when you attempted to download the report?

Dmitry · January 30, 2024, 6:55am

hello @wtempel ,

you said: “Is your CryoSPARC master computer also acting as a GPU worker for the aforementioned motion correction jobs? Was a job running when you attempted to download the report?”

I am not sure - how to check that?
I tried to reproduce the downloading error - starting the Reference based motion correction and downloading the report, also when CS and system is not running any protocol. But currently the report downloads work without an issue.

About test - I will run it and report back.

Thank you.

Kind regards,
Dmitry

Dmitry · January 30, 2024, 7:02pm

Hello @wtempel ,

Following up on our discussion about the Reference-based motion correction error I am having for one of my projects - I have run the test using Extensive validation with the T20s subset, as you suggested.
Interestingly, it finished ok with 4GPU // default settings for the memory. Shall I send you the current report of it?
I am still not sure why my actual project keeps falling. Can we somehow derive the reason comparing the accomplished (T20 test) and failed (actural) reference-based motion correction reports?

Thank you.

Kind regards,
Dmitry

wtempel · January 30, 2024, 11:49pm

Please can you inspect the command core log for errors related to this event

cryosparcm log command_core
cryosparcm filterlog command_core -l ERROR

and let us know what you find.
The timestamps may help you narrow down the search (see guide).

Dmitry · January 31, 2024, 3:54pm

the command cryosparcm filterlog command_core -l ERROR shows nothing.

The cryosparcm log command_core

cryosparc_user@cryoem1:~$ cryosparcm filterlog command_core -l ERROR

cryosparc_user@cryoem1:~$ cryosparcm 2024-01-30 16:31:29,032 dump_job_database INFO 2024-01-30 16:31:29,033 dump_job_database INFO 2024-01-30 16:31:29,033 dump_job_database INFO 2024-01-30 16:31:29,033 run 2024-01-30 16:31:29,033 run 2024-01-30 16:31:29,054 run 2024-01-30 16:31:29,054 run 2024-01-30 16:31:29,074 run 2024-01-30 17:12:09,751 background_worker INFO 2024-01-30 18:12:10,511 background_worker INFO 2024-01-30 18:35:20,282 dump_job_database INFO 2024-01-30 18:35:20,282 dump_job_database INFO 2024-01-30 18:35:20,283 dump_job_database INFO 2024-01-30 18:35:20,434 dump_job_database INFO 2024-01-30 18:35:20,434 dump_job_database INFO 2024-01-30 18:35:20,434 dump_job_database INFO 2024-01-30 18:35:20,438 dump_job_database INFO 2024-01-30 18:35:20,438 dump_job_database INFO 2024-01-30 18:35:20,439 dump_job_database INFO 2024-01-30 18:35:20,441 dump_job_database INFO 2024-01-30 18:35:20,443 dump_job_database INFO 2024-01-30 18:35:20,443 dump_job_database INFO 2024-01-30 18:35:20,444 dump_job_database INFO 2024-01-30 18:35:20,444 dump_job_database INFO 2024-01-30 18:35:20,455 set_job_status 2024-01-30 18:35:20,457 app_stats_refresh INFO 2024-01-30 18:35:20,460 app_stats_refresh INFO 2024-01-30 19:12:11,440 background_worker INFO 2024-01-30 20:12:12,426 background_worker INFO 2024-01-30 21:12:12,732 background_worker INFO 2024-01-30 22:12:13,439 background_worker INFO 2024-01-30 23:12:13,662 background_worker INFO 2024-01-31 00:12:14,310 background_worker INFO 2024-01-31 01:12:15,110 background_worker INFO 2024-01-31 02:12:15,706 background_worker INFO 2024-01-31 03:12:16,547 background_worker INFO 2024-01-31 04:12:17,365 background_worker INFO 2024-01-31 05:12:18,146 background_worker INFO 2024-01-31 06:12:18,997 background_worker INFO 2024-01-31 07:12:19,296 background_worker INFO 2024-01-31 08:12:20,134 background_worker INFO 2024-01-31 09:12:20,834 background_worker INFO 2024-01-31 10:12:21,510 background_worker INFO 2024-01-31 11:12:22,098 background_worker INFO 2024-01-31 12:12:22,755 background_worker INFO 2024-01-31 13:12:23,455 background_worker INFO 2024-01-31 14:12:24,245 background_worker INFO 2024-01-31 15:12:25,246 background_worker INFO Waiting for data… (interrupt to abort) log command_core
| Updating job manifest…
| Done. Updated in 0.00s
| Exported P6 J43 in 0.02s
INFO | Completed task in 0.022545814514160156 seconds
INFO | Received task layout_tree with 4 args and 0 kwargs
INFO | Completed task in 0.020574331283569336 seconds
INFO | Received task layout_tree with 4 args and 0 kwargs
INFO | Completed task in 0.019555091857910156 seconds
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| Request to export P6 J44
| Exporting job to /data/dmitry/cryosparc/CS-test-motion-cor/J44
| Exporting all of job’s images in the database to /data/dmitry/cryosparc/CS-test-motion-cor/J44/gridfs_data…
| Writing 212 database images to /data/dmitry/cryosparc/CS-test-motion-cor/J44/gridfs_data/gridfsdata_0
| Done. Exported 212 images in 0.15s
| Exporting all job’s streamlog events…
| Done. Exported 1 files in 0.00s
| Exporting job metafile…
| Creating .csg file for particles_0
| Creating .csg file for hyperparameters
| Done. Exported in 0.01s
| Updating job manifest…
| Done. Updated in 0.00s
| Exported P6 J44 in 0.16s
INFO | Status changed for P6.J44 from running to completed
| Calling app stats refresh url http://cryoem1.itqb.unl.pt:39000/api/actions/stats/refresh_job for project_uid P6, workspace_uid None, job_uid J44 with body {‘projectUid’: ‘P6’, ‘jobUid’: ‘J44’}
| code 200, text {“success”:true}
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.
| License does not have telemetry enabled; will re-check license in 1 hour.

Shall I resturt the faluing Reference based morion correction protocol while having this script running - cryosparcm log command_core
?

thank you

wtempel · February 1, 2024, 8:20pm

Even though the “Unable to get log” issue may be (loosely) related to the problems you experienced with reference based motion correction, the issues should probably be investigated separately. The command

cryosparcm log command_core

initially only shows the tail of the log. If you press an interrupt key sequence, like Ctrl+C, you can navigate the log (how?).
Log rotation may have occurred after you observed Unable to get log. You may be able to identify the relevant log file by running the command

grep -i "unable to get log" /path/to/cryosparc_master/run/command_core.log*

Dmitry · February 1, 2024, 9:29pm

initially only shows the tail of the log. If you press an interrupt key sequence, like Ctrl+C, you can navigate the log (how?).

It seems to be very long - so I pressed the Ctrl+C and then can roll with the mouth wheel up without reaching the beginning of the document.

And about the Unable to get log -
this file seems to be not there any longer

wtempel · February 1, 2024, 11:20pm

Given that cryosparc_master/ is your working director, omitting the leading / from the command may help:

grep -i "unable to get log" run/command_core.log*

(explanation)

Dmitry · February 2, 2024, 8:30am

hello @wtempel ,

I tried the command

grep -i "unable to get log" run/command_core.log*

but it shows nothing.

Just to be sure - I have copied this file and sent you the link for it directly.

Please let me know what do you think.

Kind regards,
Dmitry

Dmitry · February 2, 2024, 7:01pm

Dear @wtempel and colleagues,

After the inspection of command_core.log file the “unable to get log” error was not observed.
Maybe it was some temporal issue since later it was possible to download the file.

Still my issue with Reference based motion correction error from my dataset remains but got modified a bit due to a bit different input parameters.

So, I used the and with the default settings and 3 GPU. It shows me the regular error - ====== Job process terminated abnormally.

Now it died on the Checkpoint 15 rather than 19. But this time in the input settings for Hyperparameter search thoroughness I used Fast option instead of extensive one.

Does anyone have any clue?
Shall I try to run this protocol just with 1 movie?

Kind regards,
Dmitry

wtempel · February 2, 2024, 9:30pm

[Edited: corrected command typo rail [sic] → tail]
@Dmitry (With apologies in case you already mentioned those items in this long thread)
Please can you describe

movie raw pixel size
movie frame dimensions
in case of EER data
- number of fractions (during import)
- upsampling factor (during import)
box size
average number of particles per exposure

output of the command (with correct project and job UIDs)

cryosparcm joblog PX JY | grep -v "Unknown field with tag 65002" | tail -n 50