Upload DIP to AtoM error: Response code: 500

413 views
Skip to first unread message

craig....@arkivum.com

unread,
Jun 13, 2016, 7:05:20 AM6/13/16
to archivematica
Hello,

I'm experiencing problems uploading DIPs to AtoM on my Archivematica 1.4 install.  The AtoM version is 2.2.1.  Once I create the DIP and choose to upload to AtoM, the job fails with the following error:

ERROR     archivematica.upload.qubit.log:  [uploadDIP] Target: test-archive-1
ERROR     archivematica.upload.qubit.log:  [uploadDIP] rsync --protect-args -rltz -P --chmod=ugo=rwX /var/archivematica/sharedDirectory/watchedDirectories/uploadDIP/testbag1-4713d2f1-f423-4908-9d2a-2207eb1df696 ubuntu-atom:/tmp
ERROR     archivematica.upload.qubit.log:  [uploadDIP] Rsync output is being saved in /tmp/tmpiOPzGO
ERROR     archivematica.upload.qubit.log:  [uploadDIP] Sending... 100 (ETA: 0:00:00)
ERROR     archivematica.upload.qubit.log:  [uploadDIP] About to deposit to: http://ubuntu-atom/index.php/sword/deposit/test-archive-1
ERROR     archivematica.upload.qubit.log:  [uploadDIP] > Response code: 500
ERROR     archivematica.upload.qubit.log:  [uploadDIP] > Location: None
[uploadDIP] Response code not expected


The issue seems similar to the one documented in this post here. Unfortunately my upload directory is already in place and has the correct permissions so the solution presented here is not available to me.

astoradmin@ubuntu-atom:/var/log$ ls -la /usr/share/nginx/atom/
total 308
drwxr-xr-x 14 www-data www-data   4096 May  9 14:25 .
drwxr-xr-x  4 root     root       4096 May  6 09:04 ..
drwxr-xr-x  3 www-data www-data   4096 May  6 09:04 apps
drwxrwxrwx  3 www-data www-data   4096 May  6 10:39 cache
drwxr-xr-x  3 www-data www-data   4096 May  6 09:13 config
-rw-rw-r--  1 www-data www-data    490 Feb  4 00:21 CONTRIBUTING
-rw-rw-r--  1 www-data www-data   5199 Feb  4 00:21 COPYRIGHT
drwxr-xr-x  2 www-data www-data   4096 May  6 09:04 css
drwxr-xr-x  9 www-data www-data   4096 May  6 10:39 data
-rw-rw-r--  1 www-data www-data 182068 Feb  4 00:21 ead.dtd
-rw-rw-r--  1 www-data www-data   1150 Feb  4 00:21 favicon.ico
drwxr-xr-x  5 www-data www-data   4096 May  6 09:04 images
-rw-rw-r--  1 www-data www-data    229 Feb  4 00:21 index.php
drwxr-xr-x  2 www-data www-data   4096 May  6 09:04 js
drwxr-xr-x 16 www-data www-data   4096 May  6 09:04 lib
-rw-rw-r--  1 www-data www-data  34519 Feb  4 00:21 LICENSE
drwxr-xr-x  2 www-data www-data   4096 May  6 17:20 log
drwxr-xr-x 30 www-data www-data   4096 May  6 09:04 plugins
-rw-rw-r--  1 www-data www-data    751 Feb  4 00:21 qubit_dev.php
-rw-rw-r--  1 www-data www-data    339 Feb  4 00:21 README
-rw-rw-r--  1 www-data www-data     26 Feb  4 00:21 robots.txt
lrwxrwxrwx  1 www-data www-data     48 May  6 09:12 sf -> /usr/share/nginx/atom/vendor/symfony/data/web/sf
-rwxrwxr-x  1 www-data www-data    445 Feb  4 00:21 symfony
drwxr-xr-x  3 www-data www-data   4096 May  6 17:30 uploads
drwxr-xr-x 14 www-data www-data   4096 May  6 09:04 vendor

I have performed the following checks to see if I can fix it and none of them have resolved the issue:
 - Ensure all services are running on the AtoM server as expected (mysql, nginx, elasticsearch, gearman)
 - check passwordless SSH is working from the archivematica server to the atom server
 - manually execute the rsync (works without issue)
 - ensure sword is enabled
 - ensure atom-worker.conf contains the correct info as described here

astoradmin@ubuntu-atom:/var/log$ cat /etc/init/atom-worker.conf
description "AtoM worker (gearmand) upstart service"

start on (started mysql)
stop on runlevel [016]

respawn
respawn limit 5 10

env LOCATION=/usr/share/nginx/atom
env LOGFILE=/usr/share/nginx/atom/log/atom-worker.log

setuid www-data
setgid www-data

script

  php \
    -d memory_limit=-1 \
    -d error_reporting="E_ALL" \
${LOCATION}/symfony jobs:worker >> ${LOGFILE} 2>&1

end script


Manually navigating to the URL in the error messages presents the following XML:


<summary type="text">Bad request</summary>
<title type="text">ERROR</title>
<updated>2016-06-13T03:37:40-07:00</updated>
<generator uri="http://ubuntu-atom/index.php/" version="2.2.1">Qubit 2.2.1</generator>
<sword:userAgent>
Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/51.0.2704.84 Safari/537.36
</sword:userAgent>
<link rel="alternate" href="http://www.accesstomemory.org/wiki/index.php?title=SWORD" type="text/html"/>
</sword:error>


Thank you for your assistance.

Regards,
Craig






craig....@arkivum.com

unread,
Jun 16, 2016, 4:19:44 AM6/16/16
to archivematica
Is anyone able to provide some guidance on this issue?

Thanks,
Craig

Miguel Alfaro

unread,
Jun 16, 2016, 8:22:15 AM6/16/16
to archiv...@googlegroups.com
Hello:

I'm not an expert but, Do you start yor gearman-worker? 

Are you configure in Archivematica: atom DIP upload?

--email="xx...@xxxxxxx.com" \
--password="xxxxx" \
--uuid="%SIPUUID%" \
--rsync-target="/tmp" \
--version=2

Miguel

--
You received this message because you are subscribed to the Google Groups "archivematica" group.
To unsubscribe from this group and stop receiving emails from it, send an email to archivematic...@googlegroups.com.
To post to this group, send email to archiv...@googlegroups.com.
Visit this group at https://groups.google.com/group/archivematica.
For more options, visit https://groups.google.com/d/optout.

craig....@arkivum.com

unread,
Jun 16, 2016, 10:11:10 AM6/16/16
to archivematica
Hi Miguel,

My gearman-job-server is running OK.

craig@ubuntu-amtc:~$ sudo service gearman-job-server status
gearman-job-server start/running, process 697

And I do have my atom config in place, yes.

--password="arkivum" \
--uuid="%SIPUUID%" \
--rsync-target="ubuntu-atom:/tmp" \
--version="2"

Craig

Mathieu Deschaine

unread,
Jun 16, 2016, 1:00:40 PM6/16/16
to archivematica
can you check that Rsync output file? Maybe there's more information there? 

"ERROR archivematica.upload.qubit.log: [uploadDIP] Rsync output is being saved in /tmp/tmpiOPzGO"

-Matt

Miguel Alfaro

unread,
Jun 16, 2016, 2:29:02 PM6/16/16
to archiv...@googlegroups.com
Hello:


If "craig@ubuntu-amtc" is your archivematica server, you'll need to start gearman-worker in the atom (astoradmin@ubuntu-atom)side. 


If not Try to use: --rsync-target="astoradmin@ubuntu-atom:/tmp" \

or --rsync-target="xx...@xxx.xxx.xx.x.xxx:/tmp \ 

I hope this help.

Cheers Miguel

craig....@arkivum.com

unread,
Jun 21, 2016, 11:55:53 AM6/21/16
to archivematica
Hi guys,

Sorry for the delay in responding, I've been a bit swamped this week.  I shall retest this on Thursday with your suggestions and report back.  Thanks!

Craig

craig....@arkivum.com

unread,
Jun 23, 2016, 7:15:26 AM6/23/16
to archivematica
Hi guys,

I've solved my problem!  My atom-worker wasn't starting for some reason.  Manually starting the atom-worker ($ sudo start atom-worker) fixed this issue.

I can't get atom-worker to start with MySQL using this conf: https://github.com/artefactual/atom/blob/stable/2.2.x/init/atom-worker.conf
I tried to get it working on boot with 'start on runlevel [2345]' and that isn't working for me either.  I'm not sure why.  I'll continue to investigate.

Thanks for your help.

Craig
Message has been deleted

Roberto JR

unread,
Jun 27, 2018, 7:36:08 PM6/27/18
to archivematica
Hello
I'm experiencing the same error using Archivematica 1.7.1 and AtoM 2.4, I tried all the indications here as well as the posts
but to no solutions. Has anyone ever experienced this problem with the versions 1.7.1/2.4?

Thank you

--------

upload-qubit.py: ERROR     2018-06-23 22:36:22,913  archivematica.upload.qubit:log:64:  [uploadDIP] Target: example-title-3-series
upload-qubit.py: ERROR     2018-06-23 22:36:22,913  archivematica.upload.qubit:log:64:  [uploadDIP] rsync --protect-args -rltz -P --chmod=ugo=rwX /var/archivematica/sharedDirectory/watchedDirectories/uploadDIP/images-44c8b16b-8fb5-4dcd-99dc-bd24759684c0 /tmp
upload-qubit.py: ERROR     2018-06-23 22:36:22,914  archivematica.upload.qubit:log:64:  [uploadDIP] Rsync output is being saved in /tmp/tmpCCv3va
upload-qubit.py: ERROR     2018-06-23 22:36:23,965  archivematica.upload.qubit:log:64:  [uploadDIP] Sending... 100 (ETA: 0:00:00)
upload-qubit.py: ERROR     2018-06-23 22:36:23,968  archivematica.upload.qubit:log:64:  [uploadDIP] About to deposit to: http://localhost//sword/deposit/example-title-3-series
upload-qubit.py: DEBUG     2018-06-23 22:36:23,973  urllib3.connectionpool:_new_conn:208:  Starting new HTTP connection (1): localhost
upload-qubit.py: DEBUG     2018-06-23 22:36:24,113  urllib3.connectionpool:_make_request:396:  http://localhost:80 "POST //sword/deposit/example-title-3-series HTTP/1.1" 500 None
upload-qubit.py: ERROR     2018-06-23 22:36:24,113  archivematica.upload.qubit:log:64:  [uploadDIP] > Response code: 500
upload-qubit.py: ERROR     2018-06-23 22:36:24,113  archivematica.upload.qubit:log:64:  [uploadDIP] > Location: None

Justin Simpson

unread,
Jun 27, 2018, 10:26:47 PM6/27/18
to archiv...@googlegroups.com
Hi Roberto,

In the log output you provided, I noticed this line:

upload-qubit.py: ERROR     2018-06-23 22:36:24,113  archivematica.upload.qubit:log:64:  [uploadDIP] > Response code: 500


That line says the AtoM server returned an http response could definitely of 500, which indicates a server error on the AtoM side.

You should try looking at the AtoM logs and see if there is an indication of what caused the 500 response.

On Wed, Jun 27, 2018, 16:31 Roberto JR <rbr...@gmail.com> wrote:
https://groups.google.com/forum/#!topic/archivematica/qDhgG-wLqbUbut to no solution. Has anyone ever experienced this problem?

Thank you

----
upload-qubit.py: ERROR     2018-06-23 22:36:22,913  archivematica.upload.qubit:log:64:  [uploadDIP] Target: example-title-3-series
upload-qubit.py: ERROR     2018-06-23 22:36:22,913  archivematica.upload.qubit:log:64:  [uploadDIP] rsync --protect-args -rltz -P --chmod=ugo=rwX /var/archivematica/sharedDirectory/watchedDirectories/uploadDIP/images-44c8b16b-8fb5-4dcd-99dc-bd24759684c0 /tmp
upload-qubit.py: ERROR     2018-06-23 22:36:22,914  archivematica.upload.qubit:log:64:  [uploadDIP] Rsync output is being saved in /tmp/tmpCCv3va
upload-qubit.py: ERROR     2018-06-23 22:36:23,965  archivematica.upload.qubit:log:64:  [uploadDIP] Sending... 100 (ETA: 0:00:00)
upload-qubit.py: ERROR     2018-06-23 22:36:23,968  archivematica.upload.qubit:log:64:  [uploadDIP] About to deposit to: http://localhost//sword/deposit/example-title-3-series
upload-qubit.py: DEBUG     2018-06-23 22:36:23,973  urllib3.connectionpool:_new_conn:208:  Starting new HTTP connection (1): localhost
upload-qubit.py: DEBUG     2018-06-23 22:36:24,113  urllib3.connectionpool:_make_request:396:  http://localhost:80 "POST //sword/deposit/example-title-3-series HTTP/1.1" 500 None
upload-qubit.py: ERROR     2018-06-23 22:36:24,113  archivematica.upload.qubit:log:64:  [uploadDIP] > Response code: 500
upload-qubit.py: ERROR     2018-06-23 22:36:24,113  archivematica.upload.qubit:log:64:  [uploadDIP] > Location: None
[uploadDIP] Response code not expected----

Roberto JR

unread,
Jun 27, 2018, 10:52:49 PM6/27/18
to archiv...@googlegroups.com
Hello
Well, thanks for the quick feedback!.

I checked the logs folder (/ var / log /) but only found (/ var / log / archivematica). Where do I find atom logs (in Atom version 2.4)?

Thanks!

[[]]
R.J.R.

To unsubscribe from this group and stop receiving emails from it, send an email to archivematica+unsubscribe@googlegroups.com.

To post to this group, send email to archiv...@googlegroups.com.
Visit this group at https://groups.google.com/group/archivematica.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to a topic in the Google Groups "archivematica" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/archivematica/qDhgG-wLqbU/unsubscribe.
To unsubscribe from this group and all its topics, send an email to archivematica+unsubscribe@googlegroups.com.

To post to this group, send email to archiv...@googlegroups.com.
Visit this group at https://groups.google.com/group/archivematica.
For more options, visit https://groups.google.com/d/optout.



--

Justin Simpson

unread,
Jun 27, 2018, 10:56:20 PM6/27/18
to archiv...@googlegroups.com
I believe there is a logs/ directory inside the AtoM source code folder, which may be where AtoM is putting the logs.



To unsubscribe from this group and stop receiving emails from it, send an email to archivematic...@googlegroups.com.

To post to this group, send email to archiv...@googlegroups.com.
Visit this group at https://groups.google.com/group/archivematica.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to a topic in the Google Groups "archivematica" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/archivematica/qDhgG-wLqbU/unsubscribe.
To unsubscribe from this group and all its topics, send an email to archivematic...@googlegroups.com.

To post to this group, send email to archiv...@googlegroups.com.
Visit this group at https://groups.google.com/group/archivematica.
For more options, visit https://groups.google.com/d/optout.



--

--
You received this message because you are subscribed to the Google Groups "archivematica" group.
To unsubscribe from this group and stop receiving emails from it, send an email to archivematic...@googlegroups.com.

Roberto JR

unread,
Jun 28, 2018, 3:35:58 AM6/28/18
to archivematica

Hello,

Found a log in [/var/log/nginx/error.log] with content

018/06/27 19:57:58 [error] 866#866: *7508 FastCGI sent in stderr: "PHP message: No Gearman worker available that can handle the job qtSwordPluginWorker" while reading response header from upstream, client: 127.0.0.1, server: _, request: "POST //sword/deposit/example-title-3-series HTTP/1.1", upstream: "fastcgi://unix:/run/php7.0-fpm.atom.sock:", host: "localhost"

Restarted atom-worker and german-job-server too and dip uploaded. but...

But clicking in the uploaded dip in access area I get this error:

This XML file does not appear to have any style information associated with it. The document tree is shown below.

<summary type="text">Bad request</summary>
<title type="text">ERROR</title>
<updated>2018-06-28T00:23:51-07:00</updated>
<generator uri="http://localhost/index.php/" version="2.4.0">Qubit 2.4.0</generator>
<sword:userAgent>
Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36
</sword:userAgent>
<link rel="alternate" href="http://www.accesstomemory.org/wiki/index.php?title=SWORD" type="text/html"/>
</sword:error>

And other installation

<summary type="text">Bad request</summary>
<title type="text">ERROR</title>
<updated>2018-06-28T00:30:03-07:00</updated>
<generator uri="http://192.168.15.8/index.php/" version="2.4.0">Qubit 2.4.0</generator>
<sword:userAgent>
Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_5) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/67.0.3396.99 Safari/537.36
</sword:userAgent>
<link rel="alternate" href="http://www.accesstomemory.org/wiki/index.php?title=SWORD" type="text/html"/>
</sword:error>

What can be ?

Thanks

Justin Simpson

unread,
Jun 28, 2018, 12:09:46 PM6/28/18
to archiv...@googlegroups.com
Hi Roberto,

Sounds like the problem was solved?  The atom-worker was not running on the AtoM machine, for some reason and restarting it allowed the DIP to be uploaded, correct?

Your next question is about the Access tab in Archivematica, I think?  That tab shows a history of dip upload attempts - I believe what you are seeing is a record of the 500 server error you got the first time you tried to upload the DIP.  


Justin Simpson
Director of Archivematica Technical Services
www.artefactual.com
604-527-2056

--
You received this message because you are subscribed to the Google Groups "archivematica" group.
To unsubscribe from this group and stop receiving emails from it, send an email to archivematica+unsubscribe@googlegroups.com.

Roberto JR

unread,
Jun 28, 2018, 12:19:37 PM6/28/18
to archivematica
Hello.

The item displayed int Access area is:

images http://192.168.15.8/sword/deposit/example-title-3-series June 23, 2018, 2:12 p.m. Deposited asynchronously, AtoM is processing the DIP in the job queue

Note:
While, in the Ingest area ,the Dip Upload micro-service shows "Completed successfully", clicking int the "gear" next to it, I get:


upload-qubit.py: ERROR     2018-06-28 07:29:09,466  archivematica.upload.qubit:log:64:  [uploadDIP] Target: example-title-3-series
upload-qubit.py: ERROR     2018-06-28 07:29:09,466  archivematica.upload.qubit:log:64:  [uploadDIP] About to deposit to: http://192.168.15.8/sword/deposit/example-title-3-series
upload-qubit.py: DEBUG     2018-06-28 07:29:09,482  urllib3.connectionpool:_new_conn:208:  Starting new HTTP connection (1): 192.168.15.8
upload-qubit.py: DEBUG     2018-06-28 07:29:09,593  urllib3.connectionpool:_make_request:396:  http://192.168.15.8:80 "POST /sword/deposit/example-title-3-series HTTP/1.1" 302 None
upload-qubit.py: ERROR     2018-06-28 07:29:09,597  archivematica.upload.qubit:log:64:  [uploadDIP] > Response code: 302
upload-qubit.py: ERROR     2018-06-28 07:29:09,597  archivematica.upload.qubit:log:64:  [uploadDIP] > Location: /index.php/example-title-3-series
upload-qubit.py: ERROR     2018-06-28 07:29:09,597  archivematica.upload.qubit:log:64:  [uploadDIP] Deposited asynchronously, AtoM is processing the DIP in the job queue

Thanks.
To unsubscribe from this group and stop receiving emails from it, send an email to archivematic...@googlegroups.com.
Reply all
Reply to author
Forward
0 new messages