Errors when saving a dataset

[grantj-re3]

For dev-local v1.6.1: When editing a dataset (eg. in the Metadata Review stage) which has been created in the main workflow, I sometimes (eg. 20% of the time) experience one or both of the following two errors when clicking "Save & close". As far as I can tell, dataset fields are saved ok (but an error while saving is disconcerting).

To detect these errors I usually:

1. edit a dataset in the main workflow, change a field (eg. the Title field in the General tab)

2. monitor main.log with:
   tail -f main.log |egrep -i "error|fail|denied|expired"

3. click "Save and close"

4. watch the web app for errors while saving

5. watch the main.log after saving

The two errors are:

1. ReDBox GUI flashes a message something like "failed to save... error... retrieving workflow...". The main.log says "DEBUG namicPageServiceImpl Error retrieving workflow configuration". See excerpt below. Note that OID 06f8c40fc4c2ff17ca223669efb00766 is the dataset being edited (& I don't know what type of object OID cb505935f85d641f3ad4030a5a291b47 corresponds to).

2013-06-20 12:53:14,873          DEBUG  SecureStorage        Elapsed time: 73811
2013-06-20 12:53:14,875          DEBUG  SecureStorage        Cache entry 06f8c40fc4c2ff17ca223669efb00766:admin expired!
2013-06-20 12:53:14,875          DEBUG  SolrSearcher         URL:http://localhost:9000/solr/fascinator/select, POSTDATA:[name=q, value=storage_id:06f8c40fc4c2ff17ca223669efb00766, name=fl, value=id, name=wt, value=json, name=fq, value=owner:admin OR security_filter:(admin OR reviewer OR librarian OR researcher OR guest) OR security_exception:(admin)]
2013-06-20 12:53:14,878          DEBUG  SecureStorage        Elapsed time: 3
2013-06-20 12:53:14,882          DEBUG  SecureStorage        Cached entry 06f8c40fc4c2ff17ca223669efb00766:admin=false
2013-06-20 12:53:14,885          DEBUG  SecureStorage        Elapsed time: 73814
2013-06-20 12:53:14,885          DEBUG  namicPageServiceImpl Error retrieving workflow configuration
2013-06-20 12:53:14,889          DEBUG  SecureStorage        Cache entry cb505935f85d641f3ad4030a5a291b47:admin expired!
2013-06-20 12:53:14,889          DEBUG  SolrSearcher         URL:http://localhost:9000/solr/fascinator/select, POSTDATA:[name=q, value=storage_id:cb505935f85d641f3ad4030a5a291b47, name=fl, value=id, name=wt, value=json, name=fq, value=owner:admin OR security_filter:(admin OR reviewer OR librarian OR researcher OR guest) OR security_exception:(admin)]
2013-06-20 12:53:15,105          DEBUG  namicPageServiceImpl func='update-package-meta', oid='06f8c40fc4c2ff17ca223669efb00766', id='None'
2013-06-20 12:53:15,105          DEBUG  namicPageServiceImpl ** dataset update-package-meta **
2013-06-20 12:53:15,108          DEBUG  SecureStorage        Elapsed time: 233
2013-06-20 12:53:15,108          DEBUG  SecureStorage        Cached entry 06f8c40fc4c2ff17ca223669efb00766:admin=true
2013-06-20 12:53:15,109          DEBUG  namicPageServiceImpl   currentStep='metadata-review'
2013-06-20 12:53:15,111          DEBUG  Indexer              Adding security to Solr request: SearchRequest[query: id:"06f8c40fc4c2ff17ca223669efb00766", params: {fq=[item_type:"object"]}]

2. The main.log shows "WARN namicPageServiceImpl Failed to run script!" & "...StorageException: Access denied". See excerpt below:

2013-06-20 12:56:28,146          DEBUG  SecureStorage        Cache entry 06f8c40fc4c2ff17ca223669efb00766:admin expired!
2013-06-20 12:56:28,146          DEBUG  SolrSearcher         URL:http://localhost:9000/solr/fascinator/select, POSTDATA:[name=q, value=storage_id:06f8c40fc4c2ff17ca223669efb00766, name=fl, value=id, name=wt, value=json, name=fq, value=owner:admin OR security_filter:(admin OR reviewer OR librarian OR researcher OR guest) OR security_exception:(admin)]
2013-06-20 12:56:28,153          DEBUG  SecureStorage        Elapsed time: 32063
2013-06-20 12:56:28,156          DEBUG  SecureStorage        Cache entry cb505935f85d641f3ad4030a5a291b47:admin expired!
2013-06-20 12:56:28,156          DEBUG  SolrSearcher         URL:http://localhost:9000/solr/fascinator/select, POSTDATA:[name=q, value=storage_id:cb505935f85d641f3ad4030a5a291b47, name=fl, value=id, name=wt, value=json, name=fq, value=owner:admin OR security_filter:(admin OR reviewer OR librarian OR researcher OR guest) OR security_exception:(admin)]
2013-06-20 12:56:28,158          DEBUG  SecureStorage        Elapsed time: 2
2013-06-20 12:56:28,158          DEBUG  SecureStorage        Cached entry cb505935f85d641f3ad4030a5a291b47:admin=false
2013-06-20 12:56:28,171          WARN   namicPageServiceImpl Failed to run script!
=====
Traceback (most recent call last):
  File "default/redbox/scripts/actions/workflow.py", line 42, in __activate__
  File "default/redbox/scripts/actions/workflow.py", line 226, in _WorkflowData__updateWorkflow
  File "/opt/ands/redbox-builds/1.6.1/portal/default/default/scripts/workflow.py", line 197, in prepareTemplate
    jsonObject = self.vc("Services").storage.getObject(objMeta.get("jsonConfigOid"))
  File "/opt/ands/redbox-builds/1.6.1/portal/default/default/scripts/workflow.py", line 197, in prepareTemplate
    jsonObject = self.vc("Services").storage.getObject(objMeta.get("jsonConfigOid"))
        at com.googlecode.fascinator.redbox.SecureStorage.getObject(SecureStorage.java:86)
        at sun.reflect.GeneratedMethodAccessor263.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)

com.googlecode.fascinator.api.storage.StorageException: com.googlecode.fascinator.api.storage.StorageException: Access denied

=====