Strange Lucune archive date

[qingl97]

Hi,

I was testing the trashcanCleaner module on my Alfresco one 5.0.0.3 running on Tomcat7.

The problem is about the time of the trigger of the clean action.

The preset time for the clean action is 04:00 per day and the protected days is set to 1. Last night(2015/03/26) at 18:10 I uploaded certains files into the repository then deleted them about minites later. According to the configuration, these files I justed deleted should stay at the trashcan for 1 day. But today(2015/03/27) at around 10:00 in the morning I found that those files were already deleted by the trashcanCleaner and the log for the trashcanCleaner class is below:

2015-03-27 07:31:08,717  DEBUG [content.cleanup.TrashcanCleaner] [DefaultScheduler_Worker-4] Trashcan cleaner query : 
2015-03-27 07:31:09,139  DEBUG [content.cleanup.TrashcanCleaner] [DefaultScheduler_Worker-4] @\{http\://www.alfresco.org/model/system/1.0\}archivedDate:[1970-01-01T00:00:00.000Z TO 2015-03-26T06:31:08.717Z] 
2015-03-27 07:31:15,662  INFO  [content.cleanup.TrashcanCleaner] [DefaultScheduler_Worker-4] Trashcan Cleaner is about to purge the following items :
2015-03-27 07:31:15,662  INFO  [content.cleanup.TrashcanCleaner] [DefaultScheduler_Worker-4]  - file1
2015-03-27 07:31:15,662  INFO  [content.cleanup.TrashcanCleaner] [DefaultScheduler_Worker-4]  - file2
2015-03-27 07:31:15,662  INFO  [content.cleanup.TrashcanCleaner] [DefaultScheduler_Worker-4]  - file3
‍‍‍‍‍‍‍‍

From the log above, the cleaner seems to be trigged at 2015-03-27 07:31:08 which is not as preset at 04:00 and those files haven't stayed in the trashcan for 1 day yet.
I am quite confused with the time set within the lucune search system and Alfresco's repository time calculation.

The archive data(time when being deleted) calculation is via the method
Below is the main code of getting the nodes to delete:

public void execute()
  {
    if (this.protectedDays > 0)
    {
      Date fromDate = new Date(0L);
      Date toDate = new Date(new Date().getTime() - 86400000L * Long.valueOf(this.protectedDays).longValue());

      if (toDate == null)
      {
        throw new RuntimeException("Error while building the query.");
      }

      String strFromDate = ISO8601DateFormat.format(fromDate);
      String strToDate = ISO8601DateFormat.format(toDate);
      StringBuilder buf = new StringBuilder(128);
      buf.append("@").append(Repository.escapeQName(ContentModel.PROP_ARCHIVED_DATE))
        .append(":").append("[").append(strFromDate)
        .append(" TO ").append(strToDate).append("] ");

      String query = buf.toString();

      SearchParameters sp = new SearchParameters();
      sp.setLanguage("lucene");
      sp.setQuery(query);

      NodeRef archiveRootRef = this.nodeArchiveService.getStoreArchiveNode(Repository.getStoreRef());
      sp.addStore(archiveRootRef.getStoreRef());
      if (logger.isDebugEnabled())
      {
        logger.debug("Trashcan cleaner query : ");
        logger.debug(query);
      }

      UserTransaction tx = null;
      ResultSet results = null;
      try
      {
        tx = this.transactionService.getNonPropagatingUserTransaction(false);
        tx.begin();

        results = this.searchService.query(sp);
        List<NodeRef> deletedItemsToPurge = results.getNodeRefs();
        if (logger.isInfoEnabled())
        {
          logger.info("Trashcan Cleaner is about to purge the following items :");
          for (NodeRef item : deletedItemsToPurge)
          {
            String itemName = (String)this.nodeService.getProperty(item, ContentModel.PROP_NAME);
            logger.info(" - " + itemName);
          }
        }
        this.nodeArchiveService.purgeArchivedNodes(deletedItemsToPurge);

        tx.commit();
      }
      catch (Throwable err)
      {
        if (logger.isWarnEnabled())
          logger.warn("Error while cleaning the trashcan : " + err.getMessage());
        try
        {
          if (tx != null)
          {
            tx.rollback();
          }
        }
        catch (Exception tex)
        {
          if (logger.isWarnEnabled())
            logger.warn("Error while during the rollback : " + tex.getMessage());
        }
      }
      finally
      {
        if (results != null)
        {
          results.close();
        }
      }
    }
  }
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

In order to figure out the archive date used by lucune, I made sevral tests:
I created a file TestFile.txt at 2015/03/27 18:26 through the Share UI in the root of the document library and then moved it to trashcan at 2015/03/27 18:29.

Then I tried to retrieve that file through <a>http://localhost:8080/alfresco/s/enterprise/admin/admin-nodebrowser</a> by using the lucune query: <strong>@\{http\://www.alfresco.org/model/system/1.0\}archivedDate:[1970-01-01T00:00:00.000Z TO 2015-03-26T23:00:00.000Z]</strong> in <strong>archive://SpacesStore</strong>.
I found that that file couldn't be retrieved if I changed the toDate to any timestamp before <strong>2015-03-26T23:00:00.000Z</strong>, for example <strong>2015-03-26T22:59:59.999Z</strong>. But any timestamp after or equals to <strong>2015-03-26T23:00:00.000Z</strong>, that file is retrieved successfully.

So why is <strong>2015-03-26T23:00:00.000Z</strong> but not the time when I actually deleted it? Any ideas on the time calculation of the archived date of content node?

I am in the time zone UTC-01. The method

ISO8601DateFormat.format(new Date())‍

is returing a timestamp one hour before the actual invoking time of this method.

[mitpatoliya]

"Z" in the end of ISO8601 date format represent UTC time zone that may be the reason for this. Check out this.

http://en.wikipedia.org/wiki/ISO_8601#UTC