Bug #3799

Storage - Error in delete item on next in NextNext

Added by Giancarlo Panichi over 3 years ago. Updated over 3 years ago.

Status:ClosedStart date:Apr 27, 2016
Priority:NormalDue date:
Assignee:Valentina Marioli% Done:

100%

Category:content-management
Sprint:zz - Storage - Strengthen the storage behavior
Milestones:
Duration:

Description

When I try to delete a item in the Next portal the following error is raised:

2016-04-26 16:00:05,777 DEBUG impl.DefaultScopeProvider [TP-Processor7,set:38] %[PORTAL] 350720071 [TP-Processor7] DEBUG org.gcube.common.scope.impl.DefaultScopeProvider  - setting scope /gcube/devNext/NextNext in thread 91
2016-04-26 16:00:05,777 DEBUG session.ASLSession [TP-Processor7,getSecurityToken:458] %[PORTAL] 350720071 [TP-Processor7] DEBUG org.gcube.application.framework.core.session.ASLSession  - Getting security token: 7b5cc69d-1a77-4ab1-902c-ded6a4dde296 in thread 91
2016-04-26 16:00:05,777 DEBUG session.ASLSession [TP-Processor7,getSecurityToken:458] %[PORTAL] 350720071 [TP-Processor7] DEBUG org.gcube.application.framework.core.session.ASLSession  - Getting security token: 7b5cc69d-1a77-4ab1-902c-ded6a4dde296 in thread 91
2016-04-26 16:00:05,778 DEBUG session.SessionManager [TP-Processor7,getASLSession:44] %[PORTAL] 350720072 [TP-Processor7] DEBUG org.gcube.application.framework.core.session.SessionManager  - Setting SecurityTokenProvider to: 7b5cc69d-1a77-4ab1-902c-ded6a4dde296 in thread 91
2016-04-26 16:00:05,778 DEBUG session.ASLSession [TP-Processor7,getSecurityToken:458] %[PORTAL] 350720072 [TP-Processor7] DEBUG org.gcube.application.framework.core.session.ASLSession  - Getting security token: 7b5cc69d-1a77-4ab1-902c-ded6a4dde296 in thread 91
2016-04-26 16:00:05,779 DEBUG provider.SecurityTokenProvider [TP-Processor7,set:30] %[PORTAL] 350720073 [TP-Processor7] DEBUG org.gcube.common.authorization.library.provider.SecurityTokenProvider  - setting securityToken 7b5cc69d-1a77-4ab1-902c-ded6a4dde296 in thread 91
2016-04-26 16:00:05,779 INFO  util.SessionUtil [TP-Processor7,getASLSession:74] %[PORTAL] 252954 [TP-Processor7] INFO  org.gcube.portlets.user.dataminermanager.server.util.SessionUtil  - SessionUtil: aslSession giancarlo.panichi /gcube/devNext/NextNext
2016-04-26 16:00:05,779 DEBUG server.DataMinerManagerServiceImpl [TP-Processor7,deleteItem:356] %[PORTAL] 350720073 [TP-Processor7] DEBUG org.gcube.portlets.user.dataminermanager.server.DataMinerManagerServiceImpl  - DeleteItem(): ItemDescription [id=a5a20334-61e5-4cdd-8f96-e9e4139aad78, name=ASCII Maps of the environmental layers for checking features aligments_[MAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df], owner=Giancarlo Panichi, path=/Workspace/DataMiner/Output Data Sets/ASCII Maps of the environmental layers for checking features aligments_[MAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df], type=EXTERNAL_FILE, publicLink=null]
2016-04-26 16:00:05,780 DEBUG storage.StorageUtil [TP-Processor7,deleteItem:266] %[PORTAL] 252955 [TP-Processor7] DEBUG org.gcube.portlets.user.dataminermanager.server.storage.StorageUtil  - User: giancarlo.panichi, a5a20334-61e5-4cdd-8f96-e9e4139aad78
[PORTAL] 350720074 [TP-Processor7] INFO  HomeManageFactory  - loading home. (Username: giancarlo.panichi, scope: /gcube/devNext/NextNext)
[PORTAL] 350720074 [TP-Processor7] INFO  HomeManageFactory  - getHomeManagerFactory
2016-04-26 16:00:05,780 DEBUG jcr.JCRHomeManagerFactory [TP-Processor7,getHomeManager:123] %[PORTAL] 350720074 [TP-Processor7] DEBUG org.gcube.common.homelibrary.jcr.JCRHomeManagerFactory  - getHomeManager
2016-04-26 16:00:05,781 INFO  jcr.JCRHomeManager [TP-Processor7,getUser:48] %[PORTAL] 350720075 [TP-Processor7] INFO  org.gcube.common.homelibrary.jcr.JCRHomeManager  - getUser portalLogin: giancarlo.panichi
2016-04-26 16:00:05,781 INFO  jcr.JCRHomeManager [TP-Processor7,getHome:93] %[PORTAL] 350720075 [TP-Processor7] INFO  org.gcube.common.homelibrary.jcr.JCRHomeManager  - getHome user: giancarlo.panichi
2016-04-26 16:00:05,781 DEBUG jcr.JCRHomeManager [TP-Processor7,getHome:97] %[PORTAL] 350720075 [TP-Processor7] DEBUG org.gcube.common.homelibrary.jcr.JCRHomeManager  -  User is already logged
2016-04-26 16:00:05,814 INFO  servlet.JCRServlets [TP-Processor7,getItemByPath:238] %[PORTAL] 350720108 [TP-Processor7] INFO  org.gcube.common.homelibrary.jcr.workspace.servlet.JCRServlets  - Calling Servlet GetItemByPath /Home/giancarlo.panichi/Workspace/Trash by giancarlo.panichi
2016-04-26 16:00:05,839 INFO  servlet.JCRServlets [TP-Processor7,getItemById:267] %[PORTAL] 350720133 [TP-Processor7] INFO  org.gcube.common.homelibrary.jcr.workspace.servlet.JCRServlets  - Servlet getItemById a5a20334-61e5-4cdd-8f96-e9e4139aad78
2016-04-26 16:00:05,862 TRACE workspace.JCRWorkspace [TP-Processor7,removeItems:633] %[PORTAL] 350720156 [TP-Processor7] TRACE org.gcube.common.homelibrary.jcr.workspace.JCRWorkspace  - Move to trash node /Home/giancarlo.panichi/Workspace/DataMiner/Output Data Sets/ASCII Maps of the environmental layers for checking features aligments_%5BMAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df%5D
2016-04-26 16:00:05,862 INFO  workspace.JCRWorkspace [TP-Processor7,getRoot:315] %[PORTAL] 350720156 [TP-Processor7] INFO  org.gcube.common.homelibrary.jcr.workspace.JCRWorkspace  - Getting Workspace of user: giancarlo.panichi
2016-04-26 16:00:05,875 INFO  servlet.JCRServlets [TP-Processor7,getItemByPath:238] %[PORTAL] 350720169 [TP-Processor7] INFO  org.gcube.common.homelibrary.jcr.workspace.servlet.JCRServlets  - Calling Servlet GetItemByPath /Home/giancarlo.panichi/Workspace/ by giancarlo.panichi
2016-04-26 16:00:05,903 TRACE external.GCUBEStorage [TP-Processor7,moveRemoteFile:336] %[PORTAL] 350720197 [TP-Processor7] TRACE org.gcube.common.homelibrary.jcr.repository.external.GCUBEStorage  - GCUBE Storage - storage.moveFile().from(/Home/giancarlo.panichi/Workspace/DataMiner/Output Data Sets/ASCII Maps of the environmental layers for checking features aligments_%5BMAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df%5D).to(/Workspace/Trash/a5a20334-61e5-4cdd-8f96-e9e4139aad78)
2016-04-26 16:00:05,904 DEBUG impl.ServiceEngine [TP-Processor7,moveFile:762] %[PORTAL] 350720198 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.service.impl.ServiceEngine  - put() - start
2016-04-26 16:00:05,904 INFO  impl.ServiceEngine [TP-Processor7,to:19] %[PORTAL] 350720198 [TP-Processor7] INFO  org.gcube.contentmanagement.blobstorage.service.impl.ServiceEngine  - file gCube parameter before: null null
2016-04-26 16:00:05,904 DEBUG directoryOperation.BucketCoding [TP-Processor7,bucketFileCoding:32] %[PORTAL] 350720198 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.service.directoryOperation.BucketCoding  - Coding name: path:  /Workspace/Trash/a5a20334-61e5-4cdd-8f96-e9e4139aad78 rootArea /gcube/home/org.gcube.portlets.user/test-home-library/
2016-04-26 16:00:05,905 DEBUG directoryOperation.BucketCoding [TP-Processor7,bucketFileCoding:42] %[PORTAL] 350720199 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.service.directoryOperation.BucketCoding  - coding name done
2016-04-26 16:00:05,905 DEBUG impl.ServiceEngine [TP-Processor7,setGenericProperties:62] %[PORTAL] 350720199 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.service.impl.ServiceEngine  - path(String) - name: a5a20334-61e5-4cdd-8f96-e9e4139aad78
2016-04-26 16:00:05,905 DEBUG impl.ServiceEngine [TP-Processor7,setGenericProperties:72] %[PORTAL] 350720199 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.service.impl.ServiceEngine  - path(String) - path: /gcube/home/org.gcube.portlets.user/test-home-library/Workspace/Trash/
2016-04-26 16:00:05,906 INFO  impl.ServiceEngine [TP-Processor7,to:27] %[PORTAL] 350720200 [TP-Processor7] INFO  org.gcube.contentmanagement.blobstorage.service.impl.ServiceEngine  - file gCube parameter after: null null
2016-04-26 16:00:05,906 DEBUG operation.OperationManager [TP-Processor7,startOperation:67] %[PORTAL] 350720200 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.service.operation.OperationManager  - connection(boolean) - start
2016-04-26 16:00:05,906 INFO  operation.OperationManager [TP-Processor7,startOperation:69] %[PORTAL] 350720200 [TP-Processor7] INFO  org.gcube.contentmanagement.blobstorage.service.operation.OperationManager  - startOpertion getResource..getGcubeAccessType()= null file..getGcubeAccessType() null
2016-04-26 16:00:05,907 INFO  operation.OperationFactory [TP-Processor7,getOperation:39] %[PORTAL] 350720201 [TP-Processor7] INFO  org.gcube.contentmanagement.blobstorage.service.operation.OperationFactory  - getOperation(String) - start move
2016-04-26 16:00:05,907 DEBUG operation.OperationFactory [TP-Processor7,getOperation:97] %[PORTAL] 350720201 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.service.operation.OperationFactory  - getOperation(String) - end
2016-04-26 16:00:05,907 DEBUG directoryOperation.BucketCoding [TP-Processor7,bucketFileCoding:32] %[PORTAL] 350720201 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.service.directoryOperation.BucketCoding  - Coding name: path:  /Home/giancarlo.panichi/Workspace/DataMiner/Output Data Sets/ASCII Maps of the environmental layers for checking features aligments_%5BMAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df%5D rootArea /gcube/home/org.gcube.portlets.user/test-home-library/
2016-04-26 16:00:05,908 DEBUG directoryOperation.BucketCoding [TP-Processor7,bucketFileCoding:42] %[PORTAL] 350720202 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.service.directoryOperation.BucketCoding  - coding name done
2016-04-26 16:00:05,908 DEBUG directoryOperation.BucketCoding [TP-Processor7,bucketFileCoding:32] %[PORTAL] 350720202 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.service.directoryOperation.BucketCoding  - Coding name: path:  /Workspace/Trash/a5a20334-61e5-4cdd-8f96-e9e4139aad78 rootArea /gcube/home/org.gcube.portlets.user/test-home-library/
2016-04-26 16:00:05,908 DEBUG directoryOperation.BucketCoding [TP-Processor7,bucketFileCoding:42] %[PORTAL] 350720202 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.service.directoryOperation.BucketCoding  - coding name done
2016-04-26 16:00:05,909 DEBUG transport.TransportManagerFactory [TP-Processor7,getTransport:39] %[PORTAL] 350720203 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.transport.TransportManagerFactory  - getOperation(String) - start
2016-04-26 16:00:05,910 INFO  transport.TransportManagerFactory [TP-Processor7,load:54] %[PORTAL] 350720204 [TP-Processor7] INFO  org.gcube.contentmanagement.blobstorage.transport.TransportManagerFactory  -  0 implementation found. Load default implementation of TransportManager
2016-04-26 16:00:05,910 DEBUG backend.MongoIO [TP-Processor7,getDB:77] %[PORTAL] 350720204 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.transport.backend.MongoIO  -  open mongo connection 
[PORTAL] 350720205 [TP-Processor7] INFO  org.mongodb.driver.cluster  - Cluster created with settings {hosts=[mongo2-d-d4s.d4science.org:27017, mongo3-d-d4s.d4science.org:27017], mode=MULTIPLE, requiredClusterType=UNKNOWN, serverSelectionTimeout='30000 ms', maxWaitQueueSize=150}
[PORTAL] 350720205 [TP-Processor7] INFO  org.mongodb.driver.cluster  - Adding discovered server mongo2-d-d4s.d4science.org:27017 to client view of cluster
[PORTAL] 350720206 [TP-Processor7] INFO  org.mongodb.driver.cluster  - Adding discovered server mongo3-d-d4s.d4science.org:27017 to client view of cluster
2016-04-26 16:00:05,913 DEBUG backend.MongoIO [TP-Processor7,getDB:85] %[PORTAL] 350720207 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.transport.backend.MongoIO  - Istantiate MongoDB with options: MongoClientOptions{description='null', readPreference=primaryPreferred, writeConcern=WriteConcern{w=1, wtimeout=0, fsync=false, j=false, codecRegistry=org.bson.codecs.configuration.ProvidersCodecRegistry@4db765dd, minConnectionsPerHost=0, maxConnectionsPerHost=30, threadsAllowedToBlockForConnectionMultiplier=5, serverSelectionTimeout=30000, maxWaitTime=120000, maxConnectionIdleTime=0, maxConnectionLifeTime=0, connectTimeout=30000, socketTimeout=0, socketKeepAlive=false, sslEnabled=false, sslInvalidHostNamesAllowed=false, alwaysUseMBeans=false, heartbeatFrequency=10000, minHeartbeatFrequency=500, heartbeatConnectTimeout=20000, heartbeatSocketTimeout=20000, localThreshold=15, requiredReplicaSetName='null', dbDecoderFactory=com.mongodb.DefaultDBDecoder$1@68df5aaa, dbEncoderFactory=com.mongodb.DefaultDBEncoder$1@1fb984b0, socketFactory=javax.net.DefaultSocketFactory@4cb64f15, cursorFinalizerEnabled=true, connectionPoolSettings=ConnectionPoolSettings{maxSize=30, minSize=0, maxWaitQueueSize=150, maxWaitTimeMS=120000, maxConnectionLifeTimeMS=0, maxConnectionIdleTimeMS=0, maintenanceInitialDelayMS=0, maintenanceFrequencyMS=60000}, socketSettings=SocketSettings{connectTimeoutMS=30000, readTimeoutMS=0, keepAlive=false, receiveBufferSize=0, sendBufferSize=0}, serverSettings=ServerSettings{heartbeatFrequencyMS=10000, minHeartbeatFrequencyMS=500}, heartbeatSocketSettings=SocketSettings{connectTimeoutMS=20000, readTimeoutMS=20000, keepAlive=false, receiveBufferSize=0, sendBufferSize=0}}
2016-04-26 16:00:05,914 INFO  backend.MongoIO [TP-Processor7,getDB:106] %[PORTAL] 350720208 [TP-Processor7] INFO  org.gcube.contentmanagement.blobstorage.transport.backend.MongoIO  - new mongo connection pool opened
[PORTAL] 350720208 [TP-Processor7] INFO  org.mongodb.driver.cluster  - No server chosen by PrimaryServerSelector from cluster description ClusterDescription{type=UNKNOWN, connectionMode=MULTIPLE, all=[ServerDescription{address=mongo2-d-d4s.d4science.org:27017, type=UNKNOWN, state=CONNECTING}, ServerDescription{address=mongo3-d-d4s.d4science.org:27017, type=UNKNOWN, state=CONNECTING}]}. Waiting for 30000 ms before timing out
[PORTAL] 350720264 [cluster-ClusterId{value='571f90850523dc1de7f16b69', description='null'}-mongo2-d-d4s.d4science.org:27017] INFO  org.mongodb.driver.connection  - Opened connection [connectionId{localValue:181, serverValue:126884}] to mongo2-d-d4s.d4science.org:27017
[PORTAL] 350720265 [cluster-ClusterId{value='571f90850523dc1de7f16b69', description='null'}-mongo2-d-d4s.d4science.org:27017] INFO  org.mongodb.driver.cluster  - Monitor thread successfully connected to server with description ServerDescription{address=mongo2-d-d4s.d4science.org:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 0, 8]}, minWireVersion=0, maxWireVersion=3, electionId=null, maxDocumentSize=16777216, roundTripTimeNanos=1160040, setName='storagedev', canonicalAddress=mongo2-d-d4s.d4science.org:27017, hosts=[mongo2-d-d4s.d4science.org:27017, mongo3-d-d4s.d4science.org:27017], passives=[mongo4-d-d4s.d4science.org:27017], arbiters=[mongo1-d-d4s.d4science.org:27017], primary='mongo3-d-d4s.d4science.org:27017', tagSet=TagSet{[]}}
[PORTAL] 350720267 [cluster-ClusterId{value='571f90850523dc1de7f16b69', description='null'}-mongo2-d-d4s.d4science.org:27017] INFO  org.mongodb.driver.cluster  - Discovered cluster type of REPLICA_SET
[PORTAL] 350720267 [cluster-ClusterId{value='571f90850523dc1de7f16b69', description='null'}-mongo2-d-d4s.d4science.org:27017] INFO  org.mongodb.driver.cluster  - Adding discovered server mongo4-d-d4s.d4science.org:27017 to client view of cluster
[PORTAL] 350720268 [cluster-ClusterId{value='571f90850523dc1de7f16b69', description='null'}-mongo2-d-d4s.d4science.org:27017] INFO  org.mongodb.driver.cluster  - Adding discovered server mongo1-d-d4s.d4science.org:27017 to client view of cluster
[PORTAL] 350720269 [cluster-ClusterId{value='571f90850523dc1de7f16b69', description='null'}-mongo3-d-d4s.d4science.org:27017] INFO  org.mongodb.driver.connection  - Opened connection [connectionId{localValue:182, serverValue:1725534}] to mongo3-d-d4s.d4science.org:27017
[PORTAL] 350720271 [cluster-ClusterId{value='571f90850523dc1de7f16b69', description='null'}-mongo3-d-d4s.d4science.org:27017] INFO  org.mongodb.driver.cluster  - Monitor thread successfully connected to server with description ServerDescription{address=mongo3-d-d4s.d4science.org:27017, type=REPLICA_SET_PRIMARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 0, 8]}, minWireVersion=0, maxWireVersion=3, electionId=56c481dca32e5d3f9711532d, maxDocumentSize=16777216, roundTripTimeNanos=1154243, setName='storagedev', canonicalAddress=mongo3-d-d4s.d4science.org:27017, hosts=[mongo2-d-d4s.d4science.org:27017, mongo3-d-d4s.d4science.org:27017], passives=[mongo4-d-d4s.d4science.org:27017], arbiters=[mongo1-d-d4s.d4science.org:27017], primary='mongo3-d-d4s.d4science.org:27017', tagSet=TagSet{[]}}
[PORTAL] 350720271 [cluster-ClusterId{value='571f90850523dc1de7f16b69', description='null'}-mongo3-d-d4s.d4science.org:27017] INFO  org.mongodb.driver.cluster  - Discovered replica set primary mongo3-d-d4s.d4science.org:27017
[PORTAL] 350720273 [cluster-ClusterId{value='571f90850523dc1de7f16b69', description='null'}-mongo1-d-d4s.d4science.org:27017] INFO  org.mongodb.driver.connection  - Opened connection [connectionId{localValue:184, serverValue:2019497}] to mongo1-d-d4s.d4science.org:27017
[PORTAL] 350720274 [cluster-ClusterId{value='571f90850523dc1de7f16b69', description='null'}-mongo1-d-d4s.d4science.org:27017] INFO  org.mongodb.driver.cluster  - Monitor thread successfully connected to server with description ServerDescription{address=mongo1-d-d4s.d4science.org:27017, type=REPLICA_SET_ARBITER, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 0, 8]}, minWireVersion=0, maxWireVersion=3, electionId=null, maxDocumentSize=16777216, roundTripTimeNanos=716720, setName='storagedev', canonicalAddress=mongo1-d-d4s.d4science.org:27017, hosts=[mongo2-d-d4s.d4science.org:27017, mongo3-d-d4s.d4science.org:27017], passives=[mongo4-d-d4s.d4science.org:27017], arbiters=[mongo1-d-d4s.d4science.org:27017], primary='mongo3-d-d4s.d4science.org:27017', tagSet=TagSet{[]}}
[PORTAL] 350720318 [cluster-ClusterId{value='571f90850523dc1de7f16b69', description='null'}-mongo4-d-d4s.d4science.org:27017] INFO  org.mongodb.driver.connection  - Opened connection [connectionId{localValue:183, serverValue:1433088}] to mongo4-d-d4s.d4science.org:27017
[PORTAL] 350720319 [cluster-ClusterId{value='571f90850523dc1de7f16b69', description='null'}-mongo4-d-d4s.d4science.org:27017] INFO  org.mongodb.driver.cluster  - Monitor thread successfully connected to server with description ServerDescription{address=mongo4-d-d4s.d4science.org:27017, type=REPLICA_SET_SECONDARY, state=CONNECTED, ok=true, version=ServerVersion{versionList=[3, 0, 7]}, minWireVersion=0, maxWireVersion=3, electionId=null, maxDocumentSize=16777216, roundTripTimeNanos=971935, setName='storagedev', canonicalAddress=mongo4-d-d4s.d4science.org:27017, hosts=[mongo2-d-d4s.d4science.org:27017, mongo3-d-d4s.d4science.org:27017], passives=[mongo4-d-d4s.d4science.org:27017], arbiters=[mongo1-d-d4s.d4science.org:27017], primary='mongo3-d-d4s.d4science.org:27017', tagSet=TagSet{[]}}
[PORTAL] 350720331 [TP-Processor7] INFO  org.mongodb.driver.connection  - Opened connection [connectionId{localValue:185, serverValue:1725535}] to mongo3-d-d4s.d4science.org:27017
2016-04-26 16:00:06,042 INFO  backend.DefaultMongoClient [TP-Processor7,move:702] %[PORTAL] 350720336 [TP-Processor7] INFO  org.gcube.contentmanagement.blobstorage.transport.backend.DefaultMongoClient  - move operation on Mongo backend, parameters: source path: /gcube/home/org.gcube.portlets.user/test-home-library/Home/giancarlo.panichi/Workspace/DataMiner/Output Data Sets/ASCII Maps of the environmental layers for checking features aligments_%5BMAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df%5D destination path: /gcube/home/org.gcube.portlets.user/test-home-library/Workspace/Trash/a5a20334-61e5-4cdd-8f96-e9e4139aad78
2016-04-26 16:00:06,043 DEBUG backend.DefaultMongoClient [TP-Processor7,move:703] %[PORTAL] 350720337 [TP-Processor7] DEBUG org.gcube.contentmanagement.blobstorage.transport.backend.DefaultMongoClient  - MOVE OPERATION operation defined: MOVE
2016-04-26 16:00:06,045 ERROR impl.ServiceEngine [TP-Processor7,to:35] %[PORTAL] 350720339 [TP-Processor7] ERROR org.gcube.contentmanagement.blobstorage.service.impl.ServiceEngine  - get()
java.lang.IllegalArgumentException: invalid hexadecimal representation of an ObjectId: [/gcube/home/org.gcube.portlets.user/test-home-library/Home/giancarlo.panichi/Workspace/DataMiner/Output Data Sets/ASCII Maps of the environmental layers for checking features aligments_%5BMAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df%5D]
    at org.bson.types.ObjectId.parseHexString(ObjectId.java:519)
    at org.bson.types.ObjectId.<init>(ObjectId.java:233)
    at org.gcube.contentmanagement.blobstorage.transport.backend.MongoIO.findMetaCollectionObject(MongoIO.java:276)
    at org.gcube.contentmanagement.blobstorage.transport.backend.DefaultMongoClient.move(DefaultMongoClient.java:705)
    at org.gcube.contentmanagement.blobstorage.service.operation.Move.doIt(Move.java:45)
    at org.gcube.contentmanagement.blobstorage.service.operation.Move.doIt(Move.java:16)
    at org.gcube.contentmanagement.blobstorage.service.operation.OperationManager.startOperation(OperationManager.java:76)
    at org.gcube.contentmanagement.blobstorage.service.impl.RemoteResourceDestination.to(RemoteResourceDestination.java:30)
    at org.gcube.common.homelibrary.jcr.repository.external.GCUBEStorage.moveRemoteFile(GCUBEStorage.java:338)
    at org.gcube.common.homelibrary.jcr.workspace.JCRWorkspace.removeItems(JCRWorkspace.java:642)
    at org.gcube.portlets.user.dataminermanager.server.storage.StorageUtil.deleteItem(StorageUtil.java:269)
    at org.gcube.portlets.user.dataminermanager.server.DataMinerManagerServiceImpl.deleteItem(DataMinerManagerServiceImpl.java:357)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.google.gwt.user.server.rpc.RPC.invokeAndEncodeResponse(RPC.java:561)
    at com.google.gwt.user.server.rpc.RemoteServiceServlet.processCall(RemoteServiceServlet.java:208)
    at com.google.gwt.user.server.rpc.RemoteServiceServlet.processPost(RemoteServiceServlet.java:248)
    at com.google.gwt.user.server.rpc.AbstractRemoteServiceServlet.doPost(AbstractRemoteServiceServlet.java:62)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:555)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
    at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
    at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
    at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:774)
    at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:703)
    at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:896)
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
    at java.lang.Thread.run(Thread.java:744)
org.gcube.common.homelibrary.home.exceptions.InternalErrorException: org.gcube.contentmanagement.blobstorage.transport.backend.RemoteBackendException:  Remote backend problem: impossible to complete operation  Error in move operation: invalid hexadecimal representation of an ObjectId: [/gcube/home/org.gcube.portlets.user/test-home-library/Home/giancarlo.panichi/Workspace/DataMiner/Output Data Sets/ASCII Maps of the environmental layers for checking features aligments_%5BMAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df%5D]
    at org.gcube.common.homelibrary.jcr.workspace.JCRWorkspace.removeItems(JCRWorkspace.java:653)
    at org.gcube.portlets.user.dataminermanager.server.storage.StorageUtil.deleteItem(StorageUtil.java:269)
    at org.gcube.portlets.user.dataminermanager.server.DataMinerManagerServiceImpl.deleteItem(DataMinerManagerServiceImpl.java:357)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.google.gwt.user.server.rpc.RPC.invokeAndEncodeResponse(RPC.java:561)
    at com.google.gwt.user.server.rpc.RemoteServiceServlet.processCall(RemoteServiceServlet.java:208)
    at com.google.gwt.user.server.rpc.RemoteServiceServlet.processPost(RemoteServiceServlet.java:248)
    at com.google.gwt.user.server.rpc.AbstractRemoteServiceServlet.doPost(AbstractRemoteServiceServlet.java:62)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:555)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
    at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
    at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
    at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:774)
    at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:703)
    at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:896)
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
    at java.lang.Thread.run(Thread.java:744)
Caused by: org.gcube.contentmanagement.blobstorage.transport.backend.RemoteBackendException:  Remote backend problem: impossible to complete operation  Error in move operation: invalid hexadecimal representation of an ObjectId: [/gcube/home/org.gcube.portlets.user/test-home-library/Home/giancarlo.panichi/Workspace/DataMiner/Output Data Sets/ASCII Maps of the environmental layers for checking features aligments_%5BMAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df%5D]
    at org.gcube.common.homelibrary.jcr.repository.external.GCUBEStorage.moveRemoteFile(GCUBEStorage.java:340)
    at org.gcube.common.homelibrary.jcr.workspace.JCRWorkspace.removeItems(JCRWorkspace.java:642)
    ... 28 more
2016-04-26 16:00:06,062 ERROR server.DataMinerManagerServiceImpl [TP-Processor7,deleteItem:361] %org.gcube.portlets.user.dataminermanager.shared.exception.ServiceException: org.gcube.contentmanagement.blobstorage.transport.backend.RemoteBackendException:  Remote backend problem: impossible to complete operation  Error in move operation: invalid hexadecimal representation of an ObjectId: [/gcube/home/org.gcube.portlets.user/test-home-library/Home/giancarlo.panichi/Workspace/DataMiner/Output Data Sets/ASCII Maps of the environmental layers for checking features aligments_%5BMAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df%5D]
    at org.gcube.portlets.user.dataminermanager.server.storage.StorageUtil.deleteItem(StorageUtil.java:276)
    at org.gcube.portlets.user.dataminermanager.server.DataMinerManagerServiceImpl.deleteItem(DataMinerManagerServiceImpl.java:357)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.google.gwt.user.server.rpc.RPC.invokeAndEncodeResponse(RPC.java:561)
    at com.google.gwt.user.server.rpc.RemoteServiceServlet.processCall(RemoteServiceServlet.java:208)
    at com.google.gwt.user.server.rpc.RemoteServiceServlet.processPost(RemoteServiceServlet.java:248)
    at com.google.gwt.user.server.rpc.AbstractRemoteServiceServlet.doPost(AbstractRemoteServiceServlet.java:62)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:555)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
    at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
    at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
    at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:774)
    at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:703)
    at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:896)
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
    at java.lang.Thread.run(Thread.java:744)
[PORTAL] 350720356 [TP-Processor7] ERROR org.gcube.portlets.user.dataminermanager.server.DataMinerManagerServiceImpl  - org.gcube.contentmanagement.blobstorage.transport.backend.RemoteBackendException:  Remote backend problem: impossible to complete operation  Error in move operation: invalid hexadecimal representation of an ObjectId: [/gcube/home/org.gcube.portlets.user/test-home-library/Home/giancarlo.panichi/Workspace/DataMiner/Output Data Sets/ASCII Maps of the environmental layers for checking features aligments_%5BMAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df%5D]
org.gcube.portlets.user.dataminermanager.shared.exception.ServiceException: org.gcube.contentmanagement.blobstorage.transport.backend.RemoteBackendException:  Remote backend problem: impossible to complete operation  Error in move operation: invalid hexadecimal representation of an ObjectId: [/gcube/home/org.gcube.portlets.user/test-home-library/Home/giancarlo.panichi/Workspace/DataMiner/Output Data Sets/ASCII Maps of the environmental layers for checking features aligments_%5BMAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df%5D]
    at org.gcube.portlets.user.dataminermanager.server.storage.StorageUtil.deleteItem(StorageUtil.java:276)
    at org.gcube.portlets.user.dataminermanager.server.DataMinerManagerServiceImpl.deleteItem(DataMinerManagerServiceImpl.java:357)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.google.gwt.user.server.rpc.RPC.invokeAndEncodeResponse(RPC.java:561)
    at com.google.gwt.user.server.rpc.RemoteServiceServlet.processCall(RemoteServiceServlet.java:208)
    at com.google.gwt.user.server.rpc.RemoteServiceServlet.processPost(RemoteServiceServlet.java:248)
    at com.google.gwt.user.server.rpc.AbstractRemoteServiceServlet.doPost(AbstractRemoteServiceServlet.java:62)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:555)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
    at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
    at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
    at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:774)
    at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:703)
    at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:896)
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
    at java.lang.Thread.run(Thread.java:744)
org.gcube.portlets.user.dataminermanager.shared.exception.ServiceException: org.gcube.contentmanagement.blobstorage.transport.backend.RemoteBackendException:  Remote backend problem: impossible to complete operation  Error in move operation: invalid hexadecimal representation of an ObjectId: [/gcube/home/org.gcube.portlets.user/test-home-library/Home/giancarlo.panichi/Workspace/DataMiner/Output Data Sets/ASCII Maps of the environmental layers for checking features aligments_%5BMAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df%5D]
    at org.gcube.portlets.user.dataminermanager.server.storage.StorageUtil.deleteItem(StorageUtil.java:276)
    at org.gcube.portlets.user.dataminermanager.server.DataMinerManagerServiceImpl.deleteItem(DataMinerManagerServiceImpl.java:357)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:606)
    at com.google.gwt.user.server.rpc.RPC.invokeAndEncodeResponse(RPC.java:561)
    at com.google.gwt.user.server.rpc.RemoteServiceServlet.processCall(RemoteServiceServlet.java:208)
    at com.google.gwt.user.server.rpc.RemoteServiceServlet.processPost(RemoteServiceServlet.java:248)
    at com.google.gwt.user.server.rpc.AbstractRemoteServiceServlet.doPost(AbstractRemoteServiceServlet.java:62)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:555)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
    at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:190)
    at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:291)
    at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:774)
    at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:703)
    at org.apache.jk.common.ChannelSocket$SocketConnection.runIt(ChannelSocket.java:896)
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:690)
    at java.lang.Thread.run(Thread.java:744)
2016-04-26 16:00:19,605 DEBUG impl.DefaultScopeProvider [TP-Processor2,set:38] %[PORTAL] 350733899 [TP-Processor2] DEBUG org.gcube.common.scope.impl.DefaultScopeProvider  - setting scope /gcube in thread 79
2016-04-26 16:00:19,605 DEBUG session.ASLSession [TP-Processor2,getSecurityToken:458] %[PORTAL] 350733899 [TP-Processor2] DEBUG org.gcube.application.framework.core.session.ASLSession  - Getting security token: 0c63f586-427b-46cc-a103-5825bc65b309 in thread 79
2016-04-26 16:00:19,605 DEBUG session.ASLSession [TP-Processor2,getSecurityToken:458] %[PORTAL] 350733899 [TP-Processor2] DEBUG org.gcube.application.framework.core.session.ASLSession  - Getting security token: 0c63f586-427b-46cc-a103-5825bc65b309 in thread 79
2016-04-26 16:00:19,606 DEBUG session.SessionManager [TP-Processor2,getASLSession:44] %[PORTAL] 350733900 [TP-Processor2] DEBUG org.gcube.application.framework.core.session.SessionManager  - Setting SecurityTokenProvider to: 0c63f586-427b-46cc-a103-5825bc65b309 in thread 79
2016-04-26 16:00:19,606 DEBUG session.ASLSession [TP-Processor2,getSecurityToken:458] %[PORTAL] 350733900 [TP-Processor2] DEBUG org.gcube.application.framework.core.session.ASLSession  - Getting security token: 0c63f586-427b-46cc-a103-5825bc65b309 in thread 79
2016-04-26 16:00:19,606 DEBUG provider.SecurityTokenProvider [TP-Processor2,set:30] %[PORTAL] 350733900 [TP-Processor2] DEBUG org.gcube.common.authorization.library.provider.SecurityTokenProvider  - setting securityToken 0c63f586-427b-46cc-a103-5825bc65b309 in thread 79
2016-04-26 16:00:19,607 TRACE server.SessionCheckerServiceImpl [TP-Processor2,checkSession:75] %[PORTAL] 11111623 [TP-Processor2] TRACE org.gcube.portlets.widgets.sessionchecker.server.SessionCheckerServiceImpl  - Session check OK for valentina.marioli at Tue Apr 26 16:00:19 GMT 2016


History

#1 Updated by Roberto Cirillo over 3 years ago

  • Status changed from New to In Progress

#2 Updated by Roberto Cirillo over 3 years ago

  • Tracker changed from Feature to Bug

#3 Updated by Roberto Cirillo over 3 years ago

The problem is due to a mismatch from the filename on the storage and the file name reported on your log.
I've found the following filename on the storage:

ASCII Maps of the environmental layers for checking features aligments_[MAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df]

while in your log I see:

ASCII Maps of the environmental layers for checking features aligments_%5BMAX_ENT_NICHE_MODELLING_ID_4f65798b-a27d-4ab8-a5e9-cd25a31182df%5D]

#4 Updated by Roberto Cirillo over 3 years ago

  • Assignee changed from Roberto Cirillo to Valentina Marioli

#5 Updated by Valentina Marioli over 3 years ago

  • % Done changed from 0 to 100
  • Status changed from In Progress to Closed

The issue has been solved and the fix has been deployed on next.d4science.org.

Also available in: Atom PDF