How to stop "arFileImportJob" and solve "SQLSTATE[22001]: String data, right truncated: 1406 Data too long for column 'output' at row 1"

[arth...@gmail.com]

Hello everybody,
with AtoM 2.6.4 - 184, we have a problem with the import job "arFileImportJob" which keeps failing atom-worker and I don't understand how to fix.

The error is "SQLSTATE[22001]: String data, right truncated: 1406 Data too long for column 'output' at row 1", and it's also mentioned here.

We tried to change the settings of MySQL (8.0.30 CE) and to restart atom-worker, which however always fails with the same error.

It seems that every time we restart atom-worker, the "arFileImportJob" job tries to continue processing and fails at the same point.

On the "Manage jobs/Active jobs" menu, the " arFileImportJob" still has "N/A" end date and the Status is "Running".

Is there a way to stop / cancel the "arFileImportJob" job?

Thanks in advance.

[arth...@gmail.com]

I just restarted the "gearmand" service and now "atom-worker" is up.

In the "Manage jobs" I still have "arFileImportJob" running, despite the "real" status of this job.

Any way to reset the job log/list?

[Dan Gillean]

Hi Arthy, 

You have two options to end a stalled job. 

The first is to terminate all running jobs. You can do this with the following command: 

• php symfony jobs:clear

This clear ALL jobs from the queue, including any others queued behind the stalled job. You would need to re-launch those jobs again after clearing the queue. The command will also clear the history of completed jobs from AtoM's user interface, so if for some reason you want to preserve this, be sure to use the export option on the Manage Jobs page before running the command. 

The other option is to use the MySQL command prompt, and then use a SQL query to terminate the specific job. Details on this can be found here: 

• Access the MySQL command prompt: https://www.accesstomemory.org/docs/latest/admin-manual/maintenance/common-atom-queries/#accessing-the-mysql-command-prompt
• Kill a specific job: https://www.accesstomemory.org/docs/latest/admin-manual/maintenance/common-atom-queries/#kill-a-specific-atom-worker-job

Did following the linked post with the same SQL error and changing your SQL modes resolve the original problem for you?

Cheers, 

Dan Gillean, MAS, MLIS
AtoM Program Manager
Artefactual Systems, Inc.
604-527-2056

@accesstomemory

he / him

--
You received this message because you are subscribed to the Google Groups "AtoM Users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to ica-atom-user...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/ica-atom-users/1a549b19-f5d5-4304-9679-61a390ebbb06n%40googlegroups.com.

[arth...@gmail.com]

Hi Dan,

process killed by SQL, without clearing all jobs, this worked.

The problem still remains with atom-worker, but different.

Now, after changing the SQL Mode, the import process overtakes the "... data truncated..." point and imports again a lot of archival nodes.

But, at a certain point, the job status goes to "Error".

The job "Full report" shows nothing usefull, only:

[info] [2022-10-26 09:19:51] Job 2777151 "arFileImportJob": Job started.
[info] [2022-10-26 09:19:51] Job 2777151 "arFileImportJob": Importing XML file: <omissis>.xml.
[info] [2022-10-26 09:19:51] Job 2777151 "arFileImportJob": Indexing imported records.
[info] [2022-10-26 09:19:51] Job 2777151 "arFileImportJob": Update type: import-as-new
[info] [2022-10-26 09:26:26] Job 2777151 "arFileImportJob": Exception:

At this point atom-worker is still up but, after about 9 minuts it fails apparently loosing the DB connection:

# systemctl status atom-worker
● atom-worker.service - AtoM worker
   Loaded: loaded (/usr/lib/systemd/system/atom-worker.service; disabled; vendor preset: disabled)
   Active: failed (Result: exit-code) since Wed 2022-10-26 18:35:29 CEST; 28min ago
  Process: 95758 ExecStop=/bin/kill -s TERM $MAINPID (code=exited, status=1/FAILURE)
  Process: 97325 ExecStart=/opt/rh/rh-php72/root/bin/php -d memory_limit=-1 -d error_reporting="E_ALL" symfony jobs:worker (code=exited, status=1/FAILURE)
 Main PID: 97325 (code=exited, status=1/FAILURE)

Oct 26 18:26:25 <omissis> php[97325]: Dictionary stack:
Oct 26 18:26:25 <omissis> php[97325]: --dict:958/1684(ro)(G)--   --dict:0/20(G)--   --dict:77/200(L)--
Oct 26 18:26:25 <omissis> php[97325]: Current allocation mode is local
Oct 26 18:26:25 <omissis> php[97325]: GPL Ghostscript 9.25: Unrecoverable error, exit code 1
Oct 26 18:26:25 <omissis> php[97325]: @ error/ghostscript-private.h/InvokeGhostscriptDelegate/171.
Oct 26 18:26:26 <omissis> php[97325]: 2022-10-26 09:26:26 > Exception:
Oct 26 18:35:28 <omissis> php[97325]: SQLSTATE[HY000]: General error: 2006 MySQL server has gone away
Oct 26 18:35:29 <omissis> systemd[1]: atom-worker.service: main process exited, code=exited, status=1/FAILURE
Oct 26 18:35:29 <omissis> systemd[1]: Unit atom-worker.service entered failed state.
Oct 26 18:35:29 <omissis> systemd[1]: atom-worker.service failed.

I noted lot of errors regarding "GPL Ghostscript" and this can be (I suppose) because the imported EAD mentions PDF files that are not really available to AtoM. Despite this, all archival nodes processed until this point are regularly visible in the AtoM interface (without PDFs, obvious).

Then you can see the declaration of "Exception", the EAD imports stops, the atom-worker service still resists for nine-ten minutes and in the end it definitely fails with the DB "gone away".

The DB is still up and running, available for all queries, and AtoM seems to be running without other problems (just to say that the DB is online).

What can I investigate?
Perhaps an excess of those Ghostscript-related errors can cause a similar problem (consider we are talking about an EAD file of more than 2MB)?

Thx, cheers

[Dan Gillean]

Hi Arthy, 

I asked one of our developers if they had any thoughts. Apparently it is very rare for AtoM to just spit out "Exception" with no further details, and it makes it difficult for us to suggest next steps to resolve the issue. He suggested that you might try repeating the import from the command-line interface, to see if the console provides further details?

If there are a lot of external file references in your XML file to PDFs that AtoM can't access, then I do wonder if the ghostscript errors and the DB connection being lost might be a result of repeated attempts to fetch these causing the problem - exhausting resources, endless retries breaking the connection, etc.... but I'm not sure. 

Let us know if the CLI returns more information! 

 

Dan Gillean, MAS, MLIS
AtoM Program Manager
Artefactual Systems, Inc.
604-527-2056

@accesstomemory

he / him

To view this discussion on the web visit https://groups.google.com/d/msgid/ica-atom-users/87319882-923c-4ffd-8f28-4e3a1cd76301n%40googlegroups.com.

[arth...@gmail.com]

Dan,
thank you and I must say that you and your colleagues are really quick and kind.

I did some tests and came up with the following hypothesis.

This new problem is generated by the use in the EAD file of the <dao> tag with inside it an <href> pointing to a pdf file that AtoM cannot reach (the pdf is in another DAM).
Whenever the AtoM parser finds the <dao>, it tries to retrieve the pdf file to apply a ghostscript command in order to create the thumbnail for the interface.
The repetition of these errors generates an anomalous consumption of memory dedicated to php and when a sort of limit of about 1405 errors (and about 270MB of dedicated memory) is exceeded, only the log line appears with "Exception:", the atom-worker service becomes unusable and for a new load attempt you have to restart atom-worker anyway.
I tried to increase the "memory_limit" parameter of /etc/opt/rh/rh-php72/php.ini (we are in RHEL7), up to set "-1", but it seems that this has no effect on this scenario: after 1405 errors "atom-worker" still returns "Exception".

We therefore decided to force <dao> not to be used in this mode in EAD files.
From the tests done today, without <dao> the loading of the EADs happens without problems, so the problem with MySQL from which everything started seems solved.

Also, again from the latest tests, it seems that there are no problems related to the use of memory by PHP. The last load brought the memory used by PHP (RES in htop) to 350MB, a value that does not seem linked to hidden limits and in any case it worked and more than 25k nodes were created in AtoM.

Fingers crossed and tomorrow we will probably start production again.

Thanks again and cheers!

AT

[Dan Gillean]

Thanks for the detailed update - I'm glad to hear that you found a way forward!

Cheers, 

Dan Gillean, MAS, MLIS
AtoM Program Manager
Artefactual Systems, Inc.
604-527-2056

@accesstomemory

he / him

To view this discussion on the web visit https://groups.google.com/d/msgid/ica-atom-users/d3100c9e-6036-4603-9df3-6b473738ade6n%40googlegroups.com.