unable to convert (2017) into YYYY format and couldn't index it (dsDescriptionDate) #4558

andrewSC · 2018-03-29T19:45:14Z

After clearing the Solr index and kicking off a full-reindex I noticed multiple log messages similar to:

[2018-03-29T14:41:40.296-0400] [glassfish 4.1] [INFO] [] [edu.harvard.iq.dataverse.search.IndexAllServiceBean] [tid: _ThreadID=160 _ThreadName=__ejb-thread-pool10] [timeMillis: 1522348900296] [levelValue: 800] [[
indexing dataset 618 of 975 (id=4684, persistentId=<omitted>)]]

[2018-03-29T14:41:40.346-0400] [glassfish 4.1] [INFO] [] [edu.harvard.iq.dataverse.search.IndexServiceBean] [tid: _ThreadID=160 _ThreadName=__ejb-thread-pool10] [timeMillis: 1522348900346] [levelValue: 800] [[
unable to convert (2017-02-22) into YYYY format and couldn't index it (dsDescriptionDate)]]

[2018-03-29T14:41:40.777-0400] [glassfish 4.1] [INFO] [] [edu.harvard.iq.dataverse.search.IndexAllServiceBean] [tid: _ThreadID=160 _ThreadName=__ejb-thread-pool10] [timeMillis: 1522348900777] [levelValue: 800] [[
indexing dataset 619 of 975 (id=4686, persistentId=<omitted>)]]

After running asadmin set-log-levels edu.harvard.iq.dataverse.search.IndexServiceBean=FINE I was able to capture some more descriptive output (of a different dataset failing) from the logging in IndexServiceBean.java#L713 which provided:

15906-[2018-03-29T15:14:02.360-0400] [glassfish 4.1] [FINE] [] [edu.harvard.iq.dataverse.search.IndexServiceBean] [tid: _ThreadID=158 _ThreadName=__ejb-thread-pool8] [timeMillis: 1522350842360] [levelValue: 500] [CLASSNAME: edu.harvard.iq.dataverse.search.IndexServiceBean] [METHODNAME: addOrUpdateDataset] [[
15907-  indexing dsDescriptionDate:[(2017)] into dsDescriptionDate and maybe dsDescriptionDate_ss]]
15908-
15909-[2018-03-29T15:14:02.360-0400] [glassfish 4.1] [FINE] [] [edu.harvard.iq.dataverse.search.IndexServiceBean] [tid: _ThreadID=158 _ThreadName=__ejb-thread-pool8] [timeMillis: 1522350842360] [levelValue: 500] [CLASSNAME: edu.harvard.iq.dataverse.search.IndexServiceBean] [METHODNAME: addOrUpdateDataset] [[
15910-  date as string: (2017)]]
15911-
15912-[2018-03-29T15:14:02.360-0400] [glassfish 4.1] [FINE] [] [edu.harvard.iq.dataverse.search.IndexServiceBean] [tid: _ThreadID=158 _ThreadName=__ejb-thread-pool8] [timeMillis: 1522350842360] [levelValue: 500] [CLASSNAME: edu.harvard.iq.dataverse.search.IndexServiceBean] [METHODNAME: addOrUpdateDataset] [[
15913:  Trying to convert (2017) to a YYYY date from dataset 5135]]
15914-
15915-[2018-03-29T15:14:02.360-0400] [glassfish 4.1] [INFO] [] [edu.harvard.iq.dataverse.search.IndexServiceBean] [tid: _ThreadID=158 _ThreadName=__ejb-thread-pool8] [timeMillis: 1522350842360] [levelValue: 800] [[
15916-  unable to convert (2017) into YYYY format and couldn't index it (dsDescriptionDate)]]

Which seems to imply that the conversion is failing due to parenthesis existing around the date at the time of conversion. I did some quick spelunking and it doesn't seem immediately obvious what's adding them? Here's what I found in the codebase:

$ ag '\"\(\"\ \+'
main/java/edu/harvard/iq/dataverse/mydata/MyDataFilterParams.java
273:            valStr = "(" + valStr + ")";
294:            valStr = "(" + valStr + ")";
297:        return  "(" + SearchFields.PUBLICATION_STATUS + ":" + valStr + ")";

main/java/edu/harvard/iq/dataverse/mydata/MyDataFinder.java
354:            return "(" + entityIdClause + " OR " + parentIdClause + ")";

main/java/edu/harvard/iq/dataverse/mydata/RoleTagRetriever.java
395:            //msg("dv id: " + dvId + "(" + this.idToDvObjectType.get(dvId) + ") | roleId: "
396:            //        + roleId + "(" +  this.rolePermissionHelper.getRoleName(roleId)+")");
496:           //msgt("dvIdForCard: " + dvIdForCard + "(" + this.idToDvObjectType.get(dvIdForCard) + ")");

main/java/edu/harvard/iq/dataverse/mydata/SolrQueryFormatter.java
53:                            String qPart = "(" + paramName  + ":(" + orClause + "))";
55:             qPart = "(" + paramName  + ":(" + orClause + ") AND " + SearchFields.TYPE + ":(" +  dvObjectType + "))";

main/java/edu/harvard/iq/dataverse/authorization/AuthenticationServiceBean.java
849:                            String error = "at " + stacktrace.getClassName() + "." + stacktrace.getMethodName() + "(" + stacktrace.getFileName() + ":" + lineNumber + ") ";

main/java/edu/harvard/iq/dataverse/harvest/server/OAISetServiceBean.java
222:        query = "(" + query + ")";

main/java/edu/harvard/iq/dataverse/api/Index.java
191:                            String error = "at " + stacktrace.getClassName() + "." + stacktrace.getMethodName() + "(" + stacktrace.getFileName() + ":" + lineNumber + ") ";
279:                            String error = "at " + stacktrace.getClassName() + "." + stacktrace.getMethodName() + "(" + stacktrace.getFileName() + ":" + lineNumber + ") ";

main/java/edu/harvard/iq/dataverse/PermissionServiceBean.java
503:                    indirectParentIds = "(" + Integer.toString(dvIdAsInt);
525:                        indirectDatasetParentIds = "(" + Integer.toString(dvIdAsInt);

main/java/edu/harvard/iq/dataverse/dataaccess/ImageThumbConverter.java
347:        logger.fine("image dimensions: " + width + "x" + height + "(" + storageIO.getDataFile().getStorageIdentifier() + ")");

main/java/edu/harvard/iq/dataverse/search/IndexServiceBean.java
133:        logger.fine("indexDataverse called on dataverse id " + dataverse.getId() + "(" + dataverse.getAlias() + ")");

The text was updated successfully, but these errors were encountered:

scolapasta · 2018-03-29T19:58:25Z

The () are likely being added by the display formatting, but I would've though the indexing code would not be using that. Not sure if this is a new regression or not, but thanks for bringing to our attention.

pdurbin · 2018-03-29T21:14:12Z

Over at http://irclog.iq.harvard.edu/dataverse/2018-03-29#i_65142 @andrewSC mentioned he's running 4.8.5 but I wanted to mention that I see this problem in the develop branch as well. The phoenix server is running 3845816 and this is what I see:

[root@dvnweb-vm6 ~]# grep dsDescriptionDate /usr/local/glassfish4/glassfish/domains/domain1/logs/server.log -B1
[2018-03-29T09:54:44.537-0400] [glassfish 4.1] [INFO] [] [edu.harvard.iq.dataverse.search.IndexServiceBean] [tid: _ThreadID=51 _ThreadName=jk-connector(2)] [timeMillis: 1522331684537] [levelValue: 800] [[
  unable to convert (2015-01-14) into YYYY format and couldn't index it (dsDescriptionDate)]]
--
[2018-03-29T09:54:45.379-0400] [glassfish 4.1] [INFO] [] [edu.harvard.iq.dataverse.search.IndexServiceBean] [tid: _ThreadID=51 _ThreadName=jk-connector(2)] [timeMillis: 1522331685379] [levelValue: 800] [[
  unable to convert (2015-01-14) into YYYY format and couldn't index it (dsDescriptionDate)]]
--
[2018-03-29T09:54:48.233-0400] [glassfish 4.1] [INFO] [] [edu.harvard.iq.dataverse.search.IndexServiceBean] [tid: _ThreadID=50 _ThreadName=jk-connector(1)] [timeMillis: 1522331688233] [levelValue: 800] [[
  unable to convert (2015-01-14) into YYYY format and couldn't index it (dsDescriptionDate)]]
--
[2018-03-29T09:54:49.031-0400] [glassfish 4.1] [INFO] [] [edu.harvard.iq.dataverse.search.IndexServiceBean] [tid: _ThreadID=54 _ThreadName=jk-connector(5)] [timeMillis: 1522331689031] [levelValue: 800] [[
  unable to convert (2015-01-14) into YYYY format and couldn't index it (dsDescriptionDate)]]
[root@dvnweb-vm6 ~]#

Here's where the exception is being caught: https://github.com/IQSS/dataverse/blob/v4.8.5/src/main/java/edu/harvard/iq/dataverse/search/IndexServiceBean.java#L730

pameyer · 2018-03-29T21:31:16Z

Checked my notes; similar behavior seen for dateOfCollectionStart and timePeriodCoveredEnd earlier this month (no commit tag in my notes, unfortunately). But not restricted to dsDescriptionDate

scolapasta · 2018-03-30T15:32:46Z

Right, I'd expect you'd see it with any date subfield of a compound field that has a display format. @pameyer at some point you had made a change to how these things were indexed, no? Could that have introduced this regression? (not trying to call you out, sorry)

pameyer · 2018-03-30T15:59:06Z

@scolapasta I did make some changes there; but I'm pretty sure I didn't add parenthesis anywhere.

scolapasta · 2018-03-30T16:00:42Z

@pameyer not that you added the parenthesis, but that if you use the displayformat version of the field the parenthesis would be added due to being defined that way for display in the db.

pameyer · 2018-03-30T19:20:56Z

@scolapasta if I'm remembering correctly, the changes I made sent value instead of display value to solr. I'd expect that to mean that things that were sent to solr with parenthesis in displayvalue wouldn't have the parenthesis anymore - but that doesn't seem to be what's happening here.

Not at all discounting the possibility that this was something that change broke without noticing (especially since that's happened previously)...

scolapasta · 2018-03-30T19:26:56Z

@pameyer OK, went and found that old pull request: #4038

You are correct re: the change here - I wonder if something got reverted.

bikramj · 2018-04-26T16:04:20Z

I have tried upgrades from 4.7.1 -> 4.8 -> 4.8.1 -> 4.8.2 -> 4.8.3 -> 4.8.4 -> 4.8.5 in our test instance and I saw these indexing errors in each released build!

unable to convert Start: 2014-05  into YYYY format and couldn't index it (dateOfCollectionStart)]]
unable to convert End: 2014-09  into YYYY format and couldn't index it (dateOfCollectionEnd)]]
unable to convert (2015-02) into YYYY format and couldn't index it (dsDescriptionDate)]]
unable to convert Start: 2009  into YYYY format and couldn't index it (dateOfCollectionStart)]]
unable to convert End: 2010  into YYYY format and couldn't index it (dateOfCollectionEnd)]]
unable to convert Start: 1871  into YYYY format and couldn't index it (timePeriodCoveredStart)]]
unable to convert End: 1994  into YYYY format and couldn't index it (timePeriodCoveredEnd)]]

Does it mean we will have to fix dates in DB!

pdurbin · 2018-04-26T18:01:28Z

@bikramj I don't think you need to worry about your dates in general but "(2015-02)" doesn't pass our validator. Check this out:

We haven't investigated this issue yet. It's still in the "inbox" according to our kanban board: https://waffle.io/IQSS/dataverse

If anyone wants to poke around and try figure out what's happening, please go ahead!

pameyer · 2018-04-26T18:10:44Z

Took a quick look since I'm investigating #4560 in the same general area. I'm pretty sure that the parenthesis are coming from logger.info("unable to convert " + dateAsString + " into YYYY format and couldn't index it (" + dsfType.getName() + ")"); in IndexServiceBean.java; rather than indicating issues with the data.

pdurbin · 2018-08-08T16:28:18Z

#4906 is related and when we fix it hopefully this issue (#4558) will be resolved as well. Same error.

pdurbin · 2018-08-09T13:39:04Z

Some possible clues into how this regression was introduced: #4906 (comment)

matthew-a-dunlap · 2018-09-26T17:36:30Z

The same fix was used for this issue and #4906. They should be reviewed together.

pull non-display value for date #4558 #4906

pdurbin added Help Wanted: Code Mentor: pdurbin labels Apr 26, 2018

pdurbin mentioned this issue Jun 28, 2018

NPE in DatasetVersion.getPublicationDateAsString prevents dataset page from rendering #4788

Closed

pameyer mentioned this issue Aug 1, 2018

The 'Advanced Search' doesn't seem to work for publication date. #4908

Closed

pdurbin mentioned this issue Aug 8, 2018

Cannot add Time Period Covered as facet option in Dataverse #4906

Closed

pdurbin added the Type: Bug a defect label Aug 9, 2018

matthew-a-dunlap added a commit that referenced this issue Sep 26, 2018

pull non-display value for date #4558

f3efb4b

matthew-a-dunlap mentioned this issue Sep 26, 2018

pull non-display value for date #4558 #4906 #5103

Merged

5 tasks

matthew-a-dunlap added the Status: Code Review label Sep 26, 2018

scolapasta assigned scolapasta and unassigned scolapasta Sep 26, 2018

scolapasta added Status: QA and removed Status: Code Review labels Sep 26, 2018

kcondon self-assigned this Sep 26, 2018

kcondon added a commit that referenced this issue Sep 27, 2018

Merge pull request #5103 from IQSS/4558-date-solr-index

6af5c1f

pull non-display value for date #4558 #4906

kcondon closed this as completed Sep 27, 2018

kcondon removed the Status: QA label Sep 27, 2018

pdurbin removed Help Wanted: Code Mentor: pdurbin labels Sep 27, 2018

pdurbin added this to the 4.9.3 - Optional File PIDs, Initial Internationalization Work milestone Oct 1, 2018

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

unable to convert (2017) into YYYY format and couldn't index it (dsDescriptionDate) #4558

unable to convert (2017) into YYYY format and couldn't index it (dsDescriptionDate) #4558

andrewSC commented Mar 29, 2018

scolapasta commented Mar 29, 2018

pdurbin commented Mar 29, 2018

pameyer commented Mar 29, 2018

scolapasta commented Mar 30, 2018

pameyer commented Mar 30, 2018

scolapasta commented Mar 30, 2018

pameyer commented Mar 30, 2018

scolapasta commented Mar 30, 2018

bikramj commented Apr 26, 2018 •

edited

pdurbin commented Apr 26, 2018

pameyer commented Apr 26, 2018

pdurbin commented Aug 8, 2018

pdurbin commented Aug 9, 2018

matthew-a-dunlap commented Sep 26, 2018

unable to convert (2017) into YYYY format and couldn't index it (dsDescriptionDate) #4558

unable to convert (2017) into YYYY format and couldn't index it (dsDescriptionDate) #4558

Comments

andrewSC commented Mar 29, 2018

scolapasta commented Mar 29, 2018

pdurbin commented Mar 29, 2018

pameyer commented Mar 29, 2018

scolapasta commented Mar 30, 2018

pameyer commented Mar 30, 2018

scolapasta commented Mar 30, 2018

pameyer commented Mar 30, 2018

scolapasta commented Mar 30, 2018

bikramj commented Apr 26, 2018 • edited

pdurbin commented Apr 26, 2018

pameyer commented Apr 26, 2018

pdurbin commented Aug 8, 2018

pdurbin commented Aug 9, 2018

matthew-a-dunlap commented Sep 26, 2018

bikramj commented Apr 26, 2018 •

edited