Project

General

Profile

Bug #2934

Time is always 00:00:00 in replicaVerified

Added by Dave Vieglais almost 12 years ago. Updated over 11 years ago.

Status:
Closed
Priority:
Normal
Assignee:
Category:
Metacat
Start date:
2012-06-14
Due date:
2012-10-27
% Done:

100%

Milestone:
CCI-1.1
Product Version:
*
Story Points:
Sprint:

Description

The replicaVerified entry in system metadata always has the time portion zeroed out. e.g.

https://cn.dataone.org/cn/v1/meta/doi%3A10.5063%2FAA%2Fdpennington.159.5

urn:node:KNB
completed
2012-06-14T00:00:00.000+00:00


urn:node:CN
completed
2012-06-14T00:00:00.000+00:00

History

#1 Updated by Robert Waltz almost 12 years ago

Synchronization code is thus:

@@cnReplica.setReplicaVerified(new Date());

which should add in the full date/time.

the code is the same for both Data and SciData records

you will notice that on https://cn-orc-1.dataone.org/cn/v1/meta/doi:10.5063/AA/doc.1190394793078.1
the timestamp is 0'ed out
note: this record is SCI METADATA inserted with 'CNCore.create' call

while on https://cn.dataone.org/cn/v1/meta/doi:10.5063/AA/nceasadmin.814.1
the timestamp is accurate
note: record is SCI DATA inserted with 'CNCore.registerSystemMetadata' call

So, I do not see this as a trivial fix in synchronization

#2 Updated by Robert Waltz almost 12 years ago

  • Milestone changed from CCI-1.0.1 to CCI-1.0.2

#3 Updated by Robert Waltz almost 12 years ago

  • Target version changed from Sprint-2012.23-Block.3.4 to Sprint-2012.25-Block.4.1

#4 Updated by Robert Waltz almost 12 years ago

  • Priority changed from High to Normal

#5 Updated by Robert Waltz almost 12 years ago

  • Milestone changed from CCI-1.0.2 to CCI-1.0.3

#6 Updated by Robert Waltz almost 12 years ago

  • Target version changed from Sprint-2012.25-Block.4.1 to Sprint-2012.27-Block.4.2

#7 Updated by Robert Waltz almost 12 years ago

  • Position set to 1
  • Position changed from 1 to 474
  • Target version changed from Sprint-2012.27-Block.4.2 to Sprint-2012.29-Block.4.3

#8 Updated by Dave Vieglais over 11 years ago

  • Milestone changed from CCI-1.0.3 to CCI-1.0.4

#9 Updated by Robert Waltz over 11 years ago

  • Target version changed from Sprint-2012.29-Block.4.3 to Sprint-2012.33-Block.5.1

#10 Updated by Robert Waltz over 11 years ago

  • Milestone changed from CCI-1.0.4 to CCI-1.0.5
  • Target version changed from Sprint-2012.33-Block.5.1 to Sprint-2012.37-Block.5.3

#11 Updated by Chris Jones over 11 years ago

In Metacat we use Calendar.getTime() in order to get a full timestamp as a Date object. Perhaps try that in d1_synchronization.

#12 Updated by Chris Jones over 11 years ago

  • Position set to 1
  • Position changed from 1 to 488
  • Target version changed from Sprint-2012.37-Block.5.3 to Sprint-2012.35-Block.5.2
  • Position deleted (480)

#13 Updated by Robert Waltz over 11 years ago

  • Target version changed from Sprint-2012.35-Block.5.2 to Sprint-2012.39-Block.5.4
  • Position deleted (487)
  • Position set to 2

#14 Updated by Robert Waltz over 11 years ago

  • Milestone changed from CCI-1.0.5 to CCI-1.1

#15 Updated by Robert Waltz over 11 years ago

  • Target version changed from Sprint-2012.39-Block.5.4 to Sprint-2012.41-Block.6.1
  • Due date set to 2012-10-27
  • translation missing: en.field_remaining_hours set to 0.0

#16 Updated by Chris Jones over 11 years ago

I've searched through the Metacat codebase and d1_replication, and both are calling Replica.setReplicaVerified(Calendar.getInstance.getTime()); It looks like d1_synchronization TransferObjectTask.processSystemMetadata() and TransferObjectTask.updateSystemMetadata() are calling Replica.setReplicaVerified(new Date()), which is likely where the problem lies.

#17 Updated by Robert Waltz over 11 years ago

  • Category changed from d1_synchronization to Metacat

I ran a test outside of d1_synchronization using d1_libclient_java create and then retrieving the systemMetadata afterwards. Below is the output of the tests. You will notice that the replica verified date when sent across the wire to cn-dev-orc-1 has a timestamp; however upon retrieval- it is missing.

[DEBUG] 2012-10-10 16:35:25,489 (DefaultClientConnection:sendRequestHeader:268) >> POST /cn/v1/object HTTP/1.1
[DEBUG] 2012-10-10 16:35:25,489 (DefaultClientConnection:sendRequestHeader:271) >> Accept: text/xml
[DEBUG] 2012-10-10 16:35:25,489 (DefaultClientConnection:sendRequestHeader:271) >> Content-Length: 36307
[DEBUG] 2012-10-10 16:35:25,489 (DefaultClientConnection:sendRequestHeader:271) >> Content-Type: multipart/form-data; boundary=tmarOmLoDz_fB0-VBGZXQP24VDA829n4jjfcEjMC
[DEBUG] 2012-10-10 16:35:25,489 (DefaultClientConnection:sendRequestHeader:271) >> Host: cn-dev-orc-1.test.dataone.org
[DEBUG] 2012-10-10 16:35:25,651 (Wire:wire:77) >> "<?xml version="1.0" encoding="UTF-8"?>1d1Test:152efbfb-55bc-4bb5-9f7e-967befcfe719
...
urn:node:sq1dcompleted2006-05-04T18:13:51.000+00:00/d1:systemMetadata"

[DEBUG] 2012-10-10 16:50:29,505 (DefaultClientConnection:sendRequestHeader:264) Sending request: GET /cn/v1/meta/d1Test:152efbfb-55bc-4bb5-9f7e-967befcfe719 HTTP/1.1
[DEBUG] 2012-10-10 16:50:29,506 (Wire:wire:63) >> "GET /cn/v1/meta/d1Test:152efbfb-55bc-4bb5-9f7e-967befcfe719 HTTP/1.1[\r][\n]"
[DEBUG] 2012-10-10 16:50:29,508 (Wire:wire:63) >> "Accept: text/xml[\r][\n]"
[DEBUG] 2012-10-10 16:50:29,508 (Wire:wire:63) >> "Host: cn-dev-orc-1.test.dataone.org[\r][\n]"
[DEBUG] 2012-10-10 16:50:29,508 (Wire:wire:63) >> "Connection: Keep-Alive[\r][\n]"
[ INFO] 2012-10-10 16:50:29,870 (RestClient:doRequestNoBody:270) rest call info: GET https://cn-dev-orc-1.test.dataone.org/cn/v1/meta/d1Test:152efbfb-55bc-4bb5-9f7e-967befcfe719
[ INFO] 2012-10-10 16:50:29,873 (ExceptionHandler:filterErrors:94) response httpCode: 200
[DEBUG] 2012-10-10 16:50:29,916 (Wire:wire:77) << "<?xml version="1.0" encoding="UTF-8"?>1d1Test:152efbfb-55bc-4bb5-9f7e-967befcfe719
...
urn:node:sq1dcompleted2006-05-04T00:00:00.000+00:00/d1:systemMetadata"

#18 Updated by Chris Jones over 11 years ago

Whenever system metadata is changed in Metacat, the call goes through Hazelcast as a put() to the hzSystemMetadata map. This event is picked up by HazelcastService, which saves the system metadata locally by calling IdentifierManager.insertOrUpdateSystemMetadata(). Within this call, we convert from a java.util.Date to a java.sql.Date by calling Replica.getReplicaVerified() to pull the date from the replica in the list. We can verify the precision of the timestamp during the subsequent SQL call with debugging turned on.

Line 1155 of IdentifierManager has:

logMetacat.debug("smReplicationStatus sql: " + insertStatement.toString());

I've turned on debugging for IdentifierManager on cn-dev-orc-1, so Robert, you should be able to run your create test again, and grep the knb.log for "smreplicationStatus sql". Perhaps that will tell us if it changed before the insert statement, or after.

#19 Updated by Robert Waltz over 11 years ago

  • Assignee changed from Robert Waltz to Chris Jones

In the method call insertReplicationStatus of the IdentifierManager change the following lines to be:

1157:
from -- java.sql.Date sqlDate = new java.sql.Date(replica.getReplicaVerified().getTime());
to -- java.sql.Timestamp sqlTimestamp = new java.sql.Timestamp(replica.getReplicaVerified().getTime());

1161:
from -- insertStatement.setTimestamp(4, sqlDate);
to -- insertStatement.setTimestamp(4, sqlTimestamp);

In the method call getReplicationStatus of the IdentifierManager change the following lines to be:

441:
from -- java.sql.Date verified = rs.getDate(4);
to -- java.sql.Timestamp verified = rs.getTimestamp(4);

#20 Updated by Chris Jones over 11 years ago

  • Status changed from New to Closed

Updated the IdentifierManager class in Metacat, and tested in sandbox. The date verified field is now being stored to the millisecond.

Also available in: Atom PDF

Add picture from clipboard (Maximum size: 14.8 MB)