Error preventing submitter to deposit a new item in DSpace 7

[pilasou]

Describe the bug
When a user is making a new submission, sometimes when saving or depositing the item, an error occurs that prevent the item to be deposited.

It sure is an annoying bug as it is sporadic and we were not able to reproduce it. 2 users have reported it so far (and we were able to reproduce the error live with one of them following the steps described below). In the interface, only a generic message is displayed:

In the log, when the problem occurs, the following error appears:

2024-05-08 13:16:00,847 ERROR 2de1740b-f187-4a27-9a0a-afcefa9f9566 19e79358-cd4b-4795-8ccb-8788621e6802 org.dspace.app.rest.submit.SubmissionService @ [Assertion failed] - this collection must not be empty: it must contain at least 1 element
java.lang.IllegalArgumentException: [Assertion failed] - this collection must not be empty: it must contain at least 1 element)
[...]

Full error is attached to this issue : fullerrorlog.txt

To Reproduce
We are using DSpace 7.6.1 with the entities (Publication and Persons).

As mentioned, we were able to reproduce only once with a user. When the error occurs, we were following the steps as describe below:

1. Once connected with an account with submission rights only, add an item using left menu ("+", Item).
2. Choose one collection
3. Add a file using drag/drop feature.
4. Add an author : enter his name then click on the Search button on the right, then select the author in the new window and close the window.
5. Add a complete date Year, Month, day.
6. Add DOI and abstracts and declare a language for the abstracts
7. Save (Save button at the bottom of the page)
8. Add remaining fields : journal name and ISSN.
9. Save, (Save button at the bottom of the page).
10. The error happens, the last metadata entered are lost ( journal name and ISSN) and the item cannot deposited.

[tdonohue]

This may be difficult to debug if we cannot find a way to reliably reproduce it either locally or on our Demo (https://demo.dspace.org) or Sandbox (https://sandbox.dspace.org) site.

From the error stacktrace, it sounds like the Submission Form is attempting to replace a value in some metadata field with a new value. But, an error occurs because the old value (value to be replaced) no longer exists. The area of the code which throws the error appears to be here: https://github.com/DSpace/DSpace/blob/dspace-7_x/dspace-server-webapp/src/main/java/org/dspace/app/rest/submit/factory/impl/ItemMetadataValueReplacePatchOperation.java#L59
(Essentially, the check that the old value is "notEmpty" is failing.)

One possible solution might be to simply ignore that empty/missing value, since it's being replaced anyway. Instead, the code might be updated to add the new value even if the old one is missing.

As that might solve this issue, I'll add this to our bug board in search of a volunteer. However, the priority is uncertain until we can figure out how frequently this occurs. It's unclear to me how to get the Submission Form into this state where you are replacing a value that no longer exists. It's also possible that the core problem is that the Submission Form & underlying WorkspaceItem have gotten out-of-sync, which may mean this bug is potentially fixed by #2962 or #3016

[tdonohue]

This might be solved by #3053 (a new backport of #2962 to 7.x), but would need further testing. My suspicion is this error may be a side effect of the Submission Form & WorkspaceItem going "out of sync". If that suspicion is correct, then #3053 should fix the bug.

[pilasou]

Thanks @tdonohue We will try to apply the fix!

[nibou230]

Hi @tdonohue, how adding the method "getRequestInstance" will fix the error? Was this method being used somewhere and was missing in the code?

[tdonohue]

@nibou230 : the change in #3053 was to override the default getRequestInstance() method of JsonPatchOperations only for the SubmissionJsonPatchOperations service. This override ensures the embed=item is always included in every PATCH request sent by the submission form. See #2962 for more details on why this change is made.

(#2962 is the original PR that was created for 8.0 and #3053 is just a backport of that PR to 7.6.x)

[tdonohue]

I've found this is still reproducible on main (not fixed by #3053). It's difficult to reproduce regularly...but, I've been able to get it to occur randomly when I set the "Issue Date" field using the up/down arrows.

1. Start a new Submisssion
2. Fill out an Author and Title
3. In "Date of Issue" field, use the up/down arrows to set year, then month, then day.
4. Fill out other required fields in first section (namely "Type")
5. Click to next section. This triggers a Save. Sometimes it works, and sometimes you'll get a 500 error.
   • That said it is still very difficult to reproduce successfully. It seems almost like a race condition is occurring. I've tried this same process ~10 times today and only had it happen once. That said, I've captured the details below.

When the 500 error occurs, it's because the date field PATCH operation sends a "replace" action before the "add" action. For instance, this is an example PATCH request data that I had recently. Notice the third action is a "replace" on dc.date.issued even though nothing was added to that field yet.

[
  {"op":"add","path":"/sections/traditionalpageone/dc.title","value":[{"value":"Any Title","language":null,"authority":null,"display":"Any Title","confidence":-1,"place":0,"otherInformation":null}]}, 
  {"op":"add","path":"/sections/traditionalpageone/dc.contributor.author","value":[{"value":"Donohue, Tim","language":null,"authority":null,"display":"Donohue, Tim","confidence":-1,"place":0,"otherInformation":null}]}, 
  {"op":"replace","path":"/sections/traditionalpageone/dc.date.issued/0","value":{"value":"2023-06","language":null,"authority":null,"display":"2023-06","confidence":-1,"place":0,"otherInformation":null}}, 
  {"op":"add","path":"/sections/traditionalpageone/dc.date.issued","value":[{"value":"2023-06-12","language":null,"authority":null,"display":"2023-06-12","confidence":-1,"place":0,"otherInformation":null}]}, 
  {"op":"add","path":"/sections/traditionalpageone/dc.type","value":[{"value":"Article","language":null,"authority":null,"display":"Article","confidence":-1,"place":0,"otherInformation":null}]}, 
  {"op":"add","path":"/sections/traditionalpageone/dc.language.iso","value":[{"value":"en_US","language":null,"authority":null,"display":"en_US","confidence":-1,"place":0,"otherInformation":null}]}]

It's that "replace" action which causes the 500 error, as a "replace" REQUIRES that an "add" happened previously. On main, the error stacktrace is different and provides more details:

2024-06-12 11:40:51 2024-06-12 16:40:51,947 ERROR ec49885b-3617-4441-a022-20dcf8505f51 8f1ba5c2-21dc-4369-a1ff-57047af05d89 org.dspace.app.rest.submit.SubmissionService @ No metadata fields match dc.date.issued
2024-06-12 11:40:51 java.lang.IllegalArgumentException: No metadata fields match dc.date.issued
2024-06-12 11:40:51     at org.springframework.util.Assert.notEmpty(Assert.java:381) ~[spring-core-6.1.6.jar!/:6.1.6]
2024-06-12 11:40:51     at org.dspace.app.rest.submit.factory.impl.ItemMetadataValueReplacePatchOperation.replace(ItemMetadataValueReplacePatchOperation.java:59) ~[dspace-server-webapp-8.0-SNAPSHOT.jar!/:8.0-SNAPSHOT]
2024-06-12 11:40:51     at org.dspace.app.rest.submit.factory.impl.ReplacePatchOperation.perform(ReplacePatchOperation.java:26) ~[dspace-server-webapp-8.0-SNAPSHOT.jar!/:8.0-SNAPSHOT]
2024-06-12 11:40:51     at org.dspace.app.rest.submit.step.DescribeStep.doPatchProcessing(DescribeStep.java:172) ~[dspace-server-webapp-8.0-SNAPSHOT.jar!/:8.0-SNAPSHOT]
2024-06-12 11:40:51     at org.dspace.app.rest.submit.SubmissionService.evaluatePatchToInprogressSubmission(SubmissionService.java:504) ~[dspace-server-webapp-8.0-SNAPSHOT.jar!/:8.0-SNAPSHOT]
2024-06-12 11:40:51     at org.dspace.app.rest.repository.WorkspaceItemRestRepository.patch(WorkspaceItemRestRepository.java:213) ~[dspace-server-webapp-8.0-SNAPSHOT.jar!/:8.0-SNAPSHOT]

I'm going to bring this to this week's Dev Meeting, as this error blocks the ability to submit. It seems to be more reproducible than I originally thought.

[tdonohue]

@artlowel and @atarix83 : Pinging you on this ticket as there seems to be a PATCH "order of operations" bug in the Submission form which can cause instability in the submission form. See my prior comment for details.

Also bringing this to tomorrow's DevMtg as this seems to be a serious bug, when it occurs.

Possible Solutions?

• Obviously, the ideal solution is to figure out what is causing these out-of-order operations
• Another option may be to switch all "replace" operations to "add" operations on the Submission Form, as "add" can also be used for replacement.
• A third option is to change the behavior of "replace" on the backend and no longer throw a strict error (which fails all operations when a 500 error occurs). Instead, if no value exists to replace, log an error but ignore the "replace" operation.

[tdonohue]

@atarix83 : I wanted to note that I had this same issue happen again today. It happened on the first new item that I tried to submit after booting up my local copy of DSpace today (running on main).

The cause is the same. Again, I used the arrow keys (clicked all the up arrow keys) on the date field to set the year, month, and day (one by one). The resulting PATCH data again had the invalid replace on the date field.

{"op":"add","path":"/sections/traditionalpageone/dc.contributor.author","value":[{"value":"Donohue, Timothy","language":null,"authority":null,"display":"Donohue, Timothy","confidence":-1,"place":0,"otherInformation":null}]},
{"op":"add","path":"/sections/traditionalpageone/dc.title","value":[{"value":"Test Dataset","language":null,"authority":null,"display":"Test Dataset","confidence":-1,"place":0,"otherInformation":null}]},
{"op":"replace","path":"/sections/traditionalpageone/dc.date.issued/0","value":{"value":"2024-06","language":null,"authority":null,"display":"2024-06","confidence":-1,"place":0,"otherInformation":null}},
{"op":"add","path":"/sections/traditionalpageone/dc.date.issued","value":[{"value":"2024-06-13","language":null,"authority":null,"display":"2024-06-13","confidence":-1,"place":0,"otherInformation":null}]}
...

After discarding that first submission & trying the same process again... I cannot reproduce the error again. I don't know if it's more likely to occur on the first submission after a reboot, or if this was by coincidence.

[atarix83]

@tdonohue

I found a way to reproduce the error systematically:

• create a new submission
• start to edit the date field following those steps:
  • add the year by clicking on the up arrow button
  • edit the year manually by entering a different year
  • add the month by clicking on the up arrow button
• if you click on save you'll see the error

Video.del.19-06-2024.12.44.16.webm

I've found the cause and i'll open a PR asap

[tdonohue]

Fixed in 7.6.2 and 8.0 via #3139 and #3138 respectively.