Project

General

Profile

Bug #7938

Malformed system metadata

Added by Dave Vieglais over 7 years ago. Updated over 7 years ago.

Status:
Closed
Priority:
Urgent
Assignee:
Category:
-
Target version:
Start date:
2016-11-23
Due date:
% Done:

100%

Milestone:
None
Product Version:
*
Story Points:
Sprint:

Description

System metadata for the PID @doi:10.5063/AA/wolkovich.29.1@ is malformed:

<?xml version="1.0" encoding="UTF-8" standalone="yes"?>

11
doi:10.5063/AA/wolkovich.29.1
text/csv
171623
1286d997ca68c198862a6f1d266cbc2b
uid=wolkovich,o=NCEAS,dc=ecoinformatics,dc=org
uid=wolkovich,o=NCEAS,dc=ecoinformatics,dc=org


cn=esa-moderators,dc=ecoinformatics,dc=org
read
write
changePermission


public
read


cn=knb-prod,o=NCEAS,dc=ecoinformatics,dc=org</<?xml version="1.0" encoding="UTF-8"?>

Copy of system metadata retrieved from the KNB MN:

<?xml version="1.0" encoding="UTF-8"?>

11
doi:10.5063/AA/wolkovich.29.1
text/csv
171623
1286d997ca68c198862a6f1d266cbc2b
uid=wolkovich,o=NCEAS,dc=ecoinformatics,dc=org
uid=wolkovich,o=NCEAS,dc=ecoinformatics,dc=org


public
read


uid=nceasadmin,o=NCEAS,dc=ecoinformatics,dc=org
read
write
changePermission


cn=knb-prod,o=NCEAS,dc=ecoinformatics,dc=org
read
write
changePermission


cn=esa-moderators,dc=ecoinformatics,dc=org
read
write
changePermission


uid=ewolkovich,o=unaffiliated,dc=ecoinformatics,dc=org
read
write






false
2012-02-23T00:00:00.000+00:00
2014-12-14T04:25:32.024+00:00
urn:node:KNB
urn:node:KNB

urn:node:mnUCSB1
completed
2014-12-14T04:25:16.028+00:00


urn:node:mnUNM1
completed
2014-12-14T04:25:23.515+00:00


urn:node:KNB
completed
2014-12-14T04:25:30.943+00:00

wolkovich.logs (76.1 KB) Dave Vieglais, 2016-11-23 12:29

History

#1 Updated by Dave Vieglais over 7 years ago

  • Description updated (diff)

#2 Updated by Dave Vieglais over 7 years ago

Log grepping (from cn-ucsb-1, before upgrade complete):

$ cd /var/log/dataone
$ sudo grep -r "doi:10.5063/AA/wolkovich.29.1" * | tee /tmp/wolkovich.logs
[sudo] password for vieglais:
cn/d1SolrExtensions.log.19:[DEBUG] 2016-11-12 21:52:43,982 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.30.1" OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1") inPartialRobotList:false isRepeatVisit:false
cn/d1SolrExtensions.log.19:[DEBUG] 2016-11-12 21:52:43,984 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.30.1" OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1") inPartialRobotList:false isRepeatVisit:false
cn/d1SolrExtensions.log.37:[DEBUG] 2016-11-01 07:33:54,712 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1" OR "doi:10.5063/AA/wolkovich.30.1") inPartialRobotList:false isRepeatVisit:false
cn/d1SolrExtensions.log.37:[DEBUG] 2016-11-01 07:33:54,714 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1" OR "doi:10.5063/AA/wolkovich.30.1") inPartialRobotList:false isRepeatVisit:false
cn/d1SolrExtensions.log.38:[DEBUG] 2016-10-31 19:05:27,735 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1" OR "doi:10.5063/AA/wolkovich.30.1") inPartialRobotList:false isRepeatVisit:false
cn/d1SolrExtensions.log.38:[DEBUG] 2016-10-31 19:05:27,740 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1" OR "doi:10.5063/AA/wolkovich.30.1") inPartialRobotList:false isRepeatVisit:false
cn/d1SolrExtensions.log.38:[DEBUG] 2016-10-31 19:41:34,395 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1" OR "doi:10.5063/AA/wolkovich.30.1") inPartialRobotList:false isRepeatVisit:false
cn/d1SolrExtensions.log.38:[DEBUG] 2016-10-31 19:41:34,396 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1" OR "doi:10.5063/AA/wolkovich.30.1") inPartialRobotList:false isRepeatVisit:false
cn/d1SolrExtensions.log.26:[DEBUG] 2016-11-08 02:28:37,220 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1" OR "doi:10.5063/AA/wolkovich.30.1") inPartialRobotList:false isRepeatVisit:false
cn/d1SolrExtensions.log.26:[DEBUG] 2016-11-08 02:28:37,222 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1" OR "doi:10.5063/AA/wolkovich.30.1") inPartialRobotList:false isRepeatVisit:false
cn/d1SolrExtensions.log.4:[DEBUG] 2016-11-20 18:36:12,863 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1" OR "doi:10.5063/AA/wolkovich.30.1") inPartialRobotList:false isRepeatVisit:false
cn/d1SolrExtensions.log.4:[DEBUG] 2016-11-20 18:36:12,865 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1" OR "doi:10.5063/AA/wolkovich.30.1") inPartialRobotList:false isRepeatVisit:false
cn/d1SolrExtensions.log.47:[DEBUG] 2016-10-27 06:17:59,076 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1" OR "doi:10.5063/AA/wolkovich.30.1") inPartialRobotList:false isRepeatVisit:false
cn/d1SolrExtensions.log.47:[DEBUG] 2016-10-27 06:17:59,077 (SolrSearchHandlerUtil:logSolrParameters:205) value: nodeId:"urn:node:KNB" event:read pid:("doi:10.5063/F10V89RP" OR wolkovich.50.1 OR "doi:10.5063/AA/wolkovich.28.1" OR "doi:10.5063/AA/wolkovich.29.1" OR "doi:10.5063/AA/wolkovich.30.1") inPartialRobotList:false isRepeatVisit:false
daemon/cn-process-daemon.log.34:[DEBUG] 2016-11-18 07:11:18,490 (ReplicationManager:isAllowed:807) ReplicationManager.isAllowed() called for doi:10.5063/AA/wolkovich.29.1
daemon/cn-process-daemon.log.34:[DEBUG] 2016-11-18 07:11:18,490 (ReplicationManager:isAllowed:824) ReplicationManager.isAllowed() = true for doi:10.5063/AA/wolkovich.29.1
daemon/cn-process-daemon.log.34:[DEBUG] 2016-11-18 07:11:18,490 (ReplicationManager:processPid:418) Replication is allowed for identifier doi:10.5063/AA/wolkovich.29.1
daemon/cn-process-daemon.log.34:[DEBUG] 2016-11-18 07:11:18,490 (ReplicationManager:processPid:423) Getting the replica list for identifier doi:10.5063/AA/wolkovich.29.1
daemon/cn-process-daemon.log.34:[ INFO] 2016-11-18 07:11:18,550 (ReplicationManager:removeReplicationTasksForPid:772) removing replication tasks for pid: doi:10.5063/AA/wolkovich.29.1
daemon/cn-process-daemon.log.34:[ INFO] 2016-11-18 07:11:18,722 (ReplicationManager:createAndQueueTasks:390) Added 0 MNReplicationTasks to the queue for doi:10.5063/AA/wolkovich.29.1
daemon/cn-process-daemon.log.34:[ WARN] 2016-11-18 07:11:18,723 (ReplicationManager:requeueReplicationTask:787) In Replication Manager, task that should exist 'in process' does not exist. Creating new task for pid: doi:10.5063/AA/wolkovich.29.1
index/cn-index-generator-daemon.log.7:[ INFO] 2015-12-12 12:10:25,676 (IndexTaskGeneratorEntryListener:entryUpdated:87) UPDATE EVENT - index task generator - system metadata callback invoked on pid: doi:10.5063/AA/wolkovich.29.1
replicate/cn-replication.log.35:[DEBUG] 2016-11-18 07:11:18,490 (ReplicationManager:isAllowed:807) ReplicationManager.isAllowed() called for doi:10.5063/AA/wolkovich.29.1
replicate/cn-replication.log.35:[DEBUG] 2016-11-18 07:11:18,490 (ReplicationManager:isAllowed:824) ReplicationManager.isAllowed() = true for doi:10.5063/AA/wolkovich.29.1
replicate/cn-replication.log.35:[DEBUG] 2016-11-18 07:11:18,490 (ReplicationManager:processPid:418) Replication is allowed for identifier doi:10.5063/AA/wolkovich.29.1
replicate/cn-replication.log.35:[DEBUG] 2016-11-18 07:11:18,490 (ReplicationManager:processPid:423) Getting the replica list for identifier doi:10.5063/AA/wolkovich.29.1
replicate/cn-replication.log.35:[ INFO] 2016-11-18 07:11:18,550 (ReplicationManager:removeReplicationTasksForPid:772) removing replication tasks for pid: doi:10.5063/AA/wolkovich.29.1
replicate/cn-replication.log.35:[ INFO] 2016-11-18 07:11:18,722 (ReplicationManager:createAndQueueTasks:390) Added 0 MNReplicationTasks to the queue for doi:10.5063/AA/wolkovich.29.1
replicate/cn-replication.log.35:[ WARN] 2016-11-18 07:11:18,723 (ReplicationManager:requeueReplicationTask:787) In Replication Manager, task that should exist 'in process' does not exist. Creating new task for pid: doi:10.5063/AA/wolkovich.29.1

#3 Updated by Dave Vieglais over 7 years ago

Attaching output from grep on /var/log/dataone and /var/log/tomcat7 on cn-ucsb-1.

#4 Updated by Dave Vieglais over 7 years ago

  • Description updated (diff)

#5 Updated by Dave Vieglais over 7 years ago

  • Status changed from New to Closed
  • % Done changed from 0 to 100

This issue was resolved by manually editing the postgres database.

The problem appears to be that invalid system metadata was written to the postgres database in the past (metacat, or more specifically java libclient nodes would produce empty elements which caused invalid entries).

With the 2.3 upgrade, the infrastructure moved to a different serialization mechanism which would fail when the system metadata was being serialized to xml. By manually editing the database and doing the equivalent of removing empty elements, the serializer was able to correctly generate the system metadata entries.

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 14.8 MB)