[Archivesspace_Users_Group] Indexer erroring in 1.5.2

Majewski, Steven Dennis (sdm7g) sdm7g at eservices.virginia.edu
Wed Mar 22 20:00:46 EDT 2017


I’m going by memory, as I didn’t keep a copy of the filesystem from one of the failed install attempts:

When you performed the upgrade, some container conversion background jobs were run automatically for each repository. If you find them by browsing background jobs and looking for container_conversion jobs. The files are also in archivesspace/data/shared/job_files/container_conversion_job_*/ on the server.

2 files:
  output.log is the progress log that also displays in the batch_jobs console window.
  The other is an opaque hex digit identifier named file on the server, but probably downloads from that background joh page as something like container_conversion_jobnnn.csv .

That second file, should only have 1 line containing comma separated column names if there were no errors on the container conversion job:

error,message,url,uri,parent,resource,instances,instance_ids,preconversion_locations,postconversion_locations,conversion_context


If there are more lines following, that will have the error message and the uri of the record causing the error.

You may, however, also get an error if you try to access that object via either frontend or the backend API. So you may need to inspect and fix the object in 1.4.2, and then repeat the migration.

( If you didn’t test this first on a backup copy, as advised, I don’t know if you can perform a down migration again: not something I’ve ever tried.  You may have to fix it in MySQL. )

As we noted in that thread, the two common problems are either barcodes that are expected to be the same because the refer to the same container, are different ( and leading or trailing whitespace counts as different ), or else two different top_containers appear to have the same barcode ( in our case, it was a typo: same barcode was mistakenly assigned to the following container. ) In the case of a duplicate, I don’t think it tells you the id of the first instance of the duplicate. It’s the 2nd time that causes the error. You you will have to get the barcode from the 2nd and search for the other(s).

I hope the above fills in enough of the missing context from the thread below to figure out the source of your problem!

— Steve.




On Mar 22, 2017, at 6:00 PM, Brent Ellingson <brent_ellingson at byu.edu<mailto:brent_ellingson at byu.edu>> wrote:

We are in the process of upgrading our site from 1.4.2 to 1.5.3 and we are seeing a similar error as has been described in this thread. We are seeing the error below and continued looping of the indexer trying to index the archival objects.

~~~ Indexed 1225 of 67886 archival_object records in repository 2 ( added 25 records in  6399.0ms ) ~~~
~~~ Indexed 1250 of 67886 archival_object records in repository 2 ( added 25 records in  5488.0ms ) ~~~
E, [2017-03-16T16:53:51.425000 #779] ERROR -- : Thread-2392462: Unhandled exception!
E, [2017-03-16T16:53:51.425000 #779] ERROR -- :
undefined method `related_records' for nil:NilClass
/opt/archivesspace-1.5.3/archivesspace/data/tmp/jetty-0.0.0.0-9089-backend.war-_-any-/webapp/WEB-INF/app/lib/subcontainer_to_aspace_json_mapper.rb:64:in `top_container'
/opt/archivesspace-1.5.3/archivesspace/data/tmp/jetty-0.0.0.0-9089-backend.war-_-any-/webapp/WEB-INF/app/lib/subcontainer_to_aspace_json_mapper.rb:24:in `type_1'
/opt/archivesspace-1.5.3/archivesspace/data/tmp/jetty-0.0.0.0-9089-backend.war-_-any-/webapp/WEB-INF/app/lib/subcontainer_to_aspace_json_mapper.rb:14:in `to_hash'
org/jruby/RubyHash.java:1341:in `each'
org/jruby/RubyEnumerable.java:757:in `map'

Does a resolution to this issue exist?
How do I find what the offending set of data is causing the problem?
How do I proceed?

Thank you for your help.

Regards,
__________________________
Brent Ellingson
Sr. Software Engineer
BYU Library
801-422-6148


Date: Mon, 23 Jan 2017 19:54:53 +0000
From: "Majewski, Steven Dennis (sdm7g)" <sdm7g at eservices.virginia.edu<mailto:sdm7g at eservices.virginia.edu>>
To: Archivesspace Users Group
                <archivesspace_users_group at lyralists.lyrasis.org<mailto:archivesspace_users_group at lyralists.lyrasis.org>>
Subject: Re: [Archivesspace_Users_Group] Indexer erroring in 1.5.2
Message-ID:
                <1B0EA75C-EE19-492A-B057-FBAEFBBFB880 at eservices.virginia.edu<mailto:1B0EA75C-EE19-492A-B057-FBAEFBBFB880 at eservices.virginia.edu>>
Content-Type: text/plain; charset="utf-8"


The first two issues appear to be due to trailing spaces in some of the container barcodes.
Top containers have already been created for barcodes without trailing space, and so it appears that the barcodes don?t match.



On Jan 20, 2017, at 3:49 PM, Majewski, Steven Dennis (sdm7g) <sdm7g at eservices.virginia.edu<mailto:sdm7g at eservices.virginia.edu<mailto:sdm7g at eservices.virginia.edu%3cmailto:sdm7g at eservices.virginia.edu>>> wrote:


On Jan 13, 2017, at 6:15 PM, James Bullen <james at hudmol.com<mailto:james at hudmol.com<mailto:james at hudmol.com%3cmailto:james at hudmol.com>>> wrote:


Hi Steve,

That fits the pattern I?m seeing in John?s data. Have you checked the container conversion log for any errors relating to that record?


Cheers,
James



Just re-did migration from 1.4.2 to 1.5.1 again, and I?m inspecting the logs.

Yes, archival_objects/255 is on that list.

error,message,url
JSONModel::ValidationException,barcode_1 -- Mismatch when mapping between barcode and barcode_1,http://UL-sdm7g-mbp.local/resolve/readonly?uri=/repositories/3/archival_objects/331<http://ul-sdm7g-mbp.local/resolve/readonly?uri=/repositories/3/archival_objects/331><http://ul-sdm7g-mbp.local/resolve/readonly?uri=/repositories/3/archival_objects/331>
JSONModel::ValidationException,barcode_1 -- Mismatch when mapping between barcode and barcode_1,http://UL-sdm7g-mbp.local/resolve/readonly?uri=/repositories/3/archival_objects/2059<http://ul-sdm7g-mbp.local/resolve/readonly?uri=/repositories/3/archival_objects/2059><http://ul-sdm7g-mbp.local/resolve/readonly?uri=/repositories/3/archival_objects/2059>
JSONModel::ValidationException,indicator_1 -- Mismatch when mapping between indicator and indicator_1,http://UL-sdm7g-mbp.local/resolve/readonly?uri=/repositories/3/archival_objects/255<http://ul-sdm7g-mbp.local/resolve/readonly?uri=/repositories/3/archival_objects/255><http://ul-sdm7g-mbp.local/resolve/readonly?uri=/repositories/3/archival_objects/255>



I need to inspect the other repo logs and see if all of the ones that break are getting caught, but it looks likely.

I?m trying to interpret what exactly those messages are complaining about.
Do those error messages and object dumps mean anything to you off the bat?

? Steve.


On Jan 14, 2017, at 8:37 AM, Majewski, Steven Dennis (sdm7g) <sdm7g at eservices.virginia.edu<mailto:sdm7g at eservices.virginia.edu<mailto:sdm7g at eservices.virginia.edu%3cmailto:sdm7g at eservices.virginia.edu>>> wrote:


It looks like the indexer gives and error because the backend is getting an error turning the SQL model into a JSON model.

For some of the archival objects that are failing to index, the significant difference is that they do not have a sub_container in their instance. Trying to access the json from the backend in 1.5.2 just yields an error message, but going back to test 1.5.1 migration:

[ This is json from the same screen capture in my previous message. ]

archival_object 255 ( which causes error on index )

{
  "lock_version": 0,
  "position": 17,
  "publish": true,
  "ref_id": "aspace_22a35d6a6ee59ac454ca8f35232b0b40",
  "title": "Buttons and uniform parts, souvenirs, and medals",
  "display_string": "Buttons and uniform parts, souvenirs, and medals, undated",
  "restrictions_apply": false,
  "created_by": "admin",
  "last_modified_by": "admin",
  "create_time": "2015-08-11T21:43:55Z",
  "system_mtime": "2017-01-06T22:25:38Z",
  "user_mtime": "2015-08-11T21:43:55Z",
  "suppressed": false,
  "level": "file",
  "jsonmodel_type": "archival_object",
  "external_ids": [],
  "subjects": [],
  "linked_events": [],
  "extents": [],
  "dates": [
    {
      "lock_version": 0,
      "expression": "undated",
      "created_by": "admin",
      "last_modified_by": "admin",
      "create_time": "2015-08-11T21:43:55Z",
      "system_mtime": "2015-08-11T21:43:55Z",
      "user_mtime": "2015-08-11T21:43:55Z",
      "date_type": "inclusive",
      "label": "creation",
      "jsonmodel_type": "date"
    }
  ],
  "external_documents": [],
  "rights_statements": [],
  "linked_agents": [],
  "instances": [
    {
      "lock_version": 0,
      "created_by": "admin",
      "last_modified_by": "admin",
      "create_time": "2015-08-11T21:43:55Z",
      "system_mtime": "2015-08-11T21:43:55Z",
      "user_mtime": "2015-08-11T21:43:55Z",
      "instance_type": "Realia",
      "jsonmodel_type": "instance",
      "is_representative": false,
      "container": {
        "lock_version": 0,
        "indicator_1": "Artifacts 1",
        "barcode_1": "X030898965",
        "created_by": "admin",
        "last_modified_by": "admin",
        "create_time": "2015-08-11T21:43:55Z",
        "system_mtime": "2016-11-22T16:58:54Z",
        "user_mtime": "2015-08-11T21:43:55Z",
        "type_1": "box",
        "jsonmodel_type": "container",
        "container_locations": []
      }
    }
  ],
  "notes": [],
  "uri": "/repositories/3/archival_objects/255",
  "repository": {
    "ref": "/repositories/3"
  },
  "resource": {
    "ref": "/repositories/3/resources/11"
  },
  "has_unpublished_ancestor": false
}

archival_object 256: ( indexes successfully, once 255 is deleted. )

{
  "lock_version": 0,
  "position": 18,
  "publish": false,
  "ref_id": "aspace_15da7f2a9b0184a65b1280ae05a7598a",
  "title": "Buttons and uniform parts, souvenirs, and medals",
  "display_string": "Buttons and uniform parts, souvenirs, and medals, undated",
  "restrictions_apply": false,
  "created_by": "admin",
  "last_modified_by": "admin",
  "create_time": "2015-08-11T21:43:55Z",
  "system_mtime": "2017-01-06T22:25:38Z",
  "user_mtime": "2015-08-11T21:43:55Z",
  "suppressed": false,
  "level": "file",
  "jsonmodel_type": "archival_object",
  "external_ids": [],
  "subjects": [],
  "linked_events": [],
  "extents": [],
  "dates": [
    {
      "lock_version": 0,
      "expression": "undated",
      "created_by": "admin",
      "last_modified_by": "admin",
      "create_time": "2015-08-11T21:43:55Z",
      "system_mtime": "2015-08-11T21:43:55Z",
      "user_mtime": "2015-08-11T21:43:55Z",
      "date_type": "inclusive",
      "label": "creation",
      "jsonmodel_type": "date"
    }
  ],
  "external_documents": [],
  "rights_statements": [],
  "linked_agents": [],
  "instances": [
    {
      "lock_version": 0,
      "created_by": "admin",
      "last_modified_by": "admin",
      "create_time": "2015-08-11T21:43:55Z",
      "system_mtime": "2015-08-11T21:43:55Z",
      "user_mtime": "2015-08-11T21:43:55Z",
      "instance_type": "Realia",
      "jsonmodel_type": "instance",
      "is_representative": false,
      "sub_container": {
        "lock_version": 0,
        "created_by": "admin",
        "last_modified_by": "admin",
        "create_time": "2017-01-06T22:28:29Z",
        "system_mtime": "2017-01-06T22:28:29Z",
        "user_mtime": "2017-01-06T22:28:29Z",
        "jsonmodel_type": "sub_container",
        "top_container": {
          "ref": "/repositories/3/top_containers/1573"
        }
      },
      "container": {
        "type_1": "box",
        "indicator_1": "Artifacts 2",
        "barcode_1": "X030866782",
        "container_locations": [],
        "lock_version": 1
      }
    }
  ],
  "notes": [],
  "uri": "/repositories/3/archival_objects/256",
  "repository": {
    "ref": "/repositories/3"
  },
  "resource": {
    "ref": "/repositories/3/resources/11"
  },
  "has_unpublished_ancestor": false
}



But as I noted previously, I don?t see the significant difference in the data in 1.4.2 that was migrated that would account for one failing and the other succeeding.


( It appears that there are other records causing errors that don?t necessarily fit this same pattern. )

But the fact that this info is missing in the 1.5.1 migration does suggest it?s not a 1.5.2 only bug, but a problem with the container migration in earlier versions that is just made more visible by some 1.5.2 changes.


? Steve.



On Jan 12, 2017, at 11:39 PM, James Bullen <james at hudmol.com<mailto:james at hudmol.com<mailto:james at hudmol.com%3cmailto:james at hudmol.com>>> wrote:


Hi,

It looks like the problem John is seeing with the indexer failing after upgrading to 1.5.2 is caused by an issue with a record following the container conversion. I?m following up with John off-list on the specifics of his problem. Hopefully we?ll be able to confirm this when we get to a resolution.

The container management upgrade has been the source of quite a few bugs and it is on our radar for review.


Cheers,
James



On Jan 13, 2017, at 1:30 AM, Hambleton, John S <jhamblet at nmu.edu<mailto:jhamblet at nmu.edu<mailto:jhamblet at nmu.edu%3cmailto:jhamblet at nmu.edu>>> wrote:

Yes, thank you,
I sent my data to you off-list.

John H
NMU

From: archivesspace_users_group-bounces at lyralists.lyrasis.org<mailto:archivesspace_users_group-bounces at lyralists.lyrasis.org<mailto:archivesspace_users_group-bounces at lyralists.lyrasis.org%3cmailto:archivesspace_users_group-bounces at lyralists.lyrasis.org>> [mailto:archivesspace_users_group-bounces at lyralists.lyrasis.org] On Behalf Of James Bullen
Sent: Wednesday, January 11, 2017 6:56 PM
To: Archivesspace Users Group <archivesspace_users_group at lyralists.lyrasis.org<mailto:archivesspace_users_group at lyralists.lyrasis.org<mailto:archivesspace_users_group at lyralists.lyrasis.org%3cmailto:archivesspace_users_group at lyralists.lyrasis.org>>>
Subject: Re: [Archivesspace_Users_Group] Indexer erroring in 1.5.2


Hi John and Steve,

Can either of you send some sample data that surfaces this bug?


Cheers,
James


On Jan 12, 2017, at 8:17 AM, Majewski, Steven Dennis (sdm7g) <sdm7g at eservices.virginia.edu<mailto:sdm7g at eservices.virginia.edu<mailto:sdm7g at eservices.virginia.edu%3cmailto:sdm7g at eservices.virginia.edu>>> wrote:


After seeing this message, I tried 1.5.2 on my Mac (10.11.6) laptop and I?m also seeing the same undefined method `related_records' for nil:NilClass error, whether or not I do an intervening ( and successful, BTW ) update to 1.5.1.
Reindexing never seems to progress and so browse resources never shows any records.


? Steve Majewski



On Jan 11, 2017, at 1:58 PM, Hambleton, John S <jhamblet at nmu.edu<mailto:jhamblet at nmu.edu<mailto:jhamblet at nmu.edu%3cmailto:jhamblet at nmu.edu>>> wrote:

Folks,

I am testing archivesspace 1.5.2 on CentOS 6, using a copy of our 1.4.2 production database.
Wondering why it seems like the indexer is taking so long to finish, I am seeing this in the archivesspace.out log, which makes me think the indexer is caught in an endless loop:

Keep seeing the SAME indexer messages over and over again:
~~~ Indexed 1475 of 1941 accession records in repository 3 ( added 25 records in  8229.0ms ) ~~~ ~~~ Indexed 1500 of 1941 accession records in repository 3 ( added 25 records in  5251.0ms ) ~~~

And then,

E, [2017-01-11T13:41:10.740000 #32733] ERROR -- : Thread-6445852: Unhandled exception!
E, [2017-01-11T13:41:10.741000 #32733] ERROR -- :
undefined method `related_records' for nil:NilClass /usr/local/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/subcontainer_to_aspace_json_mapper.rb:64:in `top_container'
/usr/local/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/subcontainer_to_aspace_json_mapper.rb:24:in `type_1'
/usr/local/archivesspace/data/tmp/jetty-0.0.0.0-8089-backend.war-_-any-/webapp/WEB-INF/app/lib/subcontainer_to_aspace_json_mapper.rb:14:in `to_hash'
org/jruby/RubyHash.java:1341:in `each'

And then seems to start indexing the same data over again:
~~~ Indexed 50 of 1941 accession records in repository 3 ( added 25 records in  11153.0ms ) ~~~ ~~~ Indexed 75 of 1941 accession records in repository 3 ( added 25 records in  10051.0ms ) ~~~ ~~~ Indexed 100 of 1941 accession records in repository 3 ( added 25 records in  9558.0ms ) ~~~

Kind of looks like the indexer errors on ?something? then, tries to reindex the same accession records over and over again. I had followed the advice here:https://github.com/archivesspace/archivesspace/blob/master/UPGRADING_1.5.0.md#conversion<http://github.com/archivesspace/archivesspace/blob/master/UPGRADING_1.5.0.md#conversion>
before starting archivesspace, that is, ?delete your Solr index files to start with a fresh index?.

Any help is appreciated.
Thanks,
John H
NMU

_______________________________________________
Archivesspace_Users_Group mailing list
Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org%3cmailto:Archivesspace_Users_Group at lyralists.lyrasis.org>>
http://lyralists.lyrasis.org/mailman/listinfo/archivesspace_users_group

_______________________________________________
Archivesspace_Users_Group mailing list
Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org%3cmailto:Archivesspace_Users_Group at lyralists.lyrasis.org>>
http://lyralists.lyrasis.org/mailman/listinfo/archivesspace_users_group



!DSPAM:587793334611909212977! _______________________________________________
Archivesspace_Users_Group mailing list
Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org%3cmailto:Archivesspace_Users_Group at lyralists.lyrasis.org>>
http://lyralists.lyrasis.org/mailman/listinfo/archivesspace_users_group


!DSPAM:587793334611909212977!

_______________________________________________
Archivesspace_Users_Group mailing list
Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org%3cmailto:Archivesspace_Users_Group at lyralists.lyrasis.org>>
http://lyralists.lyrasis.org/mailman/listinfo/archivesspace_users_group

!DSPAM:587948af109451970717657!
_______________________________________________
Archivesspace_Users_Group mailing list
Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org%3cmailto:Archivesspace_Users_Group at lyralists.lyrasis.org>>
http://lyralists.lyrasis.org/mailman/listinfo/archivesspace_users_group


!DSPAM:587948af109451970717657!

_______________________________________________
Archivesspace_Users_Group mailing list
Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org%3cmailto:Archivesspace_Users_Group at lyralists.lyrasis.org>>
http://lyralists.lyrasis.org/mailman/listinfo/archivesspace_users_group

<7ebc58861f8c38997d24d1316e9276ec>_______________________________________________
Archivesspace_Users_Group mailing list
Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org%3cmailto:Archivesspace_Users_Group at lyralists.lyrasis.org>>
http://lyralists.lyrasis.org/mailman/listinfo/archivesspace_users_group

_______________________________________________
Archivesspace_Users_Group mailing list
Archivesspace_Users_Group at lyralists.lyrasis.org<mailto:Archivesspace_Users_Group at lyralists.lyrasis.org>
http://lyralists.lyrasis.org/mailman/listinfo/archivesspace_users_group

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lyralists.lyrasis.org/pipermail/archivesspace_users_group/attachments/20170323/1bde7825/attachment.html>


More information about the Archivesspace_Users_Group mailing list