Issue while trying to get DIP export after correct request using API

fredericBregier commented 5 years ago

Bonjour,

Le scénario est assez simple:

un POST sur /dipexport avec un dsl correct
puis un GET sur /dipexport/{id}/dip où {id} vient de la réponse positive précédente

Cela produit, si c'est trop rapide, une erreur comme suit (une première erreur NOT FOUND, puis comme NOT FOUND provoque un VitamError, une erreur de writer qui s'attend à trouver un zip. Selon le modèle standard, on devrait avoir un NOT_FOUND ou selon l'API un 412. Mais on a une erreur 500.

A noter que via l'IHM Demo, le temps étant passé, le résultat est OK. Et si le temps est court (requête DSL retournant peu d'élément), alors le timing du GET étant décalé de quelques secondes, cela fonctionne. Ici le problème vient du fait que pour l'exemple la requête DSL demande "tout" (mais pas plus de 10 Mo).

(si l'on excepte qu'une collection devrait terminer avec un 's', dipexports) est-ce que ceci est un bug à corriger dans Vitam ?

 2019-09-18 09:46:40,712 [[vitam-thread-97]] [aeeaaaaabghqjh74abbwmalnipcerdaaaaaq] ERROR fr.gouv.vitam.access.internal.rest.AccessInternalResourceImpl - Caller+1   at fr.gouv.vitam.access.internal.rest.AccessInternalResourceImpl.findDIPByID(AccessInternalResourceImpl.java:508) : [vitam-demo:access-internal:251961340] Bad request Exception  fr.gouv.vitam.storage.engine.common.exception.StorageNotFoundException: 100516 : Not Found
at fr.gouv.vitam.storage.engine.client.StorageClientRest.getContainerAsync(StorageClientRest.java:510)
at fr.gouv.vitam.access.internal.core.AccessInternalModuleImpl.findDIPByOperationId(AccessInternalModuleImpl.java:1776)
... 49 common frames omitted

Wrapped by: fr.gouv.vitam.access.internal.common.exception.AccessInternalExecutionException: fr.gouv.vitam.storage.engine.common.exception.StorageNotFoundException: 100516 : Not Found at fr.gouv.vitam.access.internal.core.AccessInternalModuleImpl.findDIPByOperationId(AccessInternalModuleImpl.java:1780) at fr.gouv.vitam.access.internal.rest.AccessInternalResourceImpl.findDIPByID(AccessInternalResourceImpl.java:506) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:139) at org.jboss.resteasy.core.ResourceMethodInvoker.internalInvokeOnTarget(ResourceMethodInvoker.java:509) at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTargetAfterFilter(ResourceMethodInvoker.java:399) at org.jboss.resteasy.core.ResourceMethodInvoker.lambda$invokeOnTarget$0(ResourceMethodInvoker.java:363) at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:355) at org.jboss.resteasy.core.ResourceMethodInvoker.invokeOnTarget(ResourceMethodInvoker.java:365) at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:337) at org.jboss.resteasy.core.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:310) at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:439) at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:229) at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:135) at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:355) at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:138) at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:215) at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:227) at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56) at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51) at javax.servlet.http.HttpServlet.service(HttpServlet.java:750) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:873) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1623) at fr.gouv.vitam.common.security.filter.AuthorizationFilter.doFilter(AuthorizationFilter.java:68) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:174) at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:61) at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) at org.eclipse.jetty.server.Server.handle(Server.java:505) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:370) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:267) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) at fr.gouv.vitam.common.thread.VitamThreadPoolExecutor$VitamRunnable.run(VitamThreadPoolExecutor.java:153) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)

2019-09-18 09:46:40,718 [[vitam-thread-97]] [aeeaaaaabghqjh74abbwmalnipcerdaaaaaq] ERROR fr.gouv.vitam.common.server.application.GenericExceptionMapper - Caller+1 at fr.gouv.vitam.common.server.application.GenericExceptionMapper.toResponse(GenericExceptionMapper.java:94) : [vitam-demo:access-internal:251961340] {"httpCode":500,"code":"000200","context":"{\"Name\":\"vitam-demo\",\"Role\":\"access-internal\",\"ServerId\":654614524,\"SiteId\":1,\"GlobalPlatformId\":251961340}","state":"GLOBAL_INTERNAL_SERVER_ERROR","message":"Internal Server Error","description":"Could not find MessageBodyWriter for response object of type: fr.gouv.vitam.common.error.VitamError of media type: application/octet-stream"} org.jboss.resteasy.core.NoMessageBodyWriterFoundFailure: Could not find MessageBodyWriter for response object of type: fr.gouv.vitam.common.error.VitamError of media type: application/octet-stream at org.jboss.resteasy.core.ServerResponseWriter.lambda$writeNomapResponse$2(ServerResponseWriter.java:104) at org.jboss.resteasy.core.interception.ContainerResponseContextImpl.filter(ContainerResponseContextImpl.java:398) at org.jboss.resteasy.core.ServerResponseWriter.executeFilters(ServerResponseWriter.java:205) at org.jboss.resteasy.core.ServerResponseWriter.writeNomapResponse(ServerResponseWriter.java:82) at org.jboss.resteasy.core.ServerResponseWriter.writeNomapResponse(ServerResponseWriter.java:56) at org.jboss.resteasy.core.SynchronousDispatcher.writeResponse(SynchronousDispatcher.java:528) at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:459) at org.jboss.resteasy.core.SynchronousDispatcher.lambda$invoke$4(SynchronousDispatcher.java:229) at org.jboss.resteasy.core.SynchronousDispatcher.lambda$preprocess$0(SynchronousDispatcher.java:135) at org.jboss.resteasy.core.interception.PreMatchContainerRequestContext.filter(PreMatchContainerRequestContext.java:355) at org.jboss.resteasy.core.SynchronousDispatcher.preprocess(SynchronousDispatcher.java:138) at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:215) at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:227) at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:56) at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:51) at javax.servlet.http.HttpServlet.service(HttpServlet.java:750) at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:873) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1623) at fr.gouv.vitam.common.security.filter.AuthorizationFilter.doFilter(AuthorizationFilter.java:68) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1610) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:540) at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1345) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:480) at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1247) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:174) at org.eclipse.jetty.server.handler.HandlerList.handle(HandlerList.java:61) at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) at org.eclipse.jetty.server.Server.handle(Server.java:505) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:370) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:267) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117) at fr.gouv.vitam.common.thread.VitamThreadPoolExecutor$VitamRunnable.run(VitamThreadPoolExecutor.java:153) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748)

fredericBregier commented 5 years ago

Précision: Vitam 2.6.3-1, Démo VM

fredericBregier commented 5 years ago

NB: du point de vue Access-External, il n'y a pas d'erreur (le VitamError est vu comme un ZIP normal). Du coup, le retour est totalement faux. Normalement, Access-Internal devrait retourner une erreur (sans doute NOT_FOUND = 404) et Access-Eternal de même (même erreur mais pas un code 200) : 127.0.0.1 - - 18/Sep/2019:09:46:40 +0000 "GET /access-external/v1/dipexport/aeeaaaaabghqjh74abbwmalnipccwoiaaaaq/dip HTTP/1.1" **200** **395** "-" "Apache-HttpClient/4.5.7 (Java/1.8.0_212)" 591 - 9

Le message retourné est clairement une erreur (et pas un zip):

{"httpCode":500,"code":"000200","context":"{\"Name\":\"vitam-demo\",\"Role\":\"access-internal\",\"ServerId\":654614524,\"SiteId\":1,\"GlobalPlatformId":251961340}","state":"GLOBAL_INTERNAL_SERVER_ERROR","message":"Internal Server Error","description":"Could not find MessageBodyWriter for response object of type: fr.gouv.vitam.common.error.VitamError of media type: application/octet-stream"}

A noter enfin que la documentation indique aussi que le code retour est 202 mais il est 200 (ce qui est logique, donc erreur de documentation).

get /dipexport/{id}/dip/

Requête qui retourne les résultate composés des métadonnées et des objets binaires dans un fichier zip 'Accept' header est 'application/octet-stream'
Request
Response
HTTP status code 202

Returns the generated zip file

naddame commented 5 years ago

Bonjour Frédéric,

Nous avons crée un bug en interne pour traiter les différentes remarques relevées.

Et pour info : Tous les workflows de VITAM nécessitent du pooling pour attendre la fin afin de pouvoir télécharger le rapport ou autre chose (DIP par exemple).

Tout comportement avant la fin de wokflow (State COMPLETED) est indéterminé. Par exemple télécharger un rapport en cours d'écriture peut renvoyer un rapport non complet ou une erreur de lecture.

On va donc améliorer les retours de certaines API en cas d'erreur.

Bien cordialement Djamel

fredericBregier commented 5 years ago

Merci Djamel, c'est noté. Je change donc pour utiliser cette procédure.

fredericBregier commented 5 years ago

Ceci dit, j'aurais trouvé logique qu'une réponde 404 (en dehors du fait qu'elle soit propagée) soit logique en interne, à savoir, sans faire de pooling explicite sur /operations, quand on demande le résultat d'une opération asynchrone, si celle-ci n'est pas terminée (ou n'existe pas), que l'API fasse le travail pour moi (développeur fainéant) de faire la requête interne à HEAD /operations/id avant de faire la requête GET demandée. Cela permettrait selon moi un comportement simple et rassurant.

fredericBregier commented 5 years ago

Pour info, grâce à vos retours (y compris celui-ci), j'ai enfin une solution complète OpenSource d'intégration de Waarp à Vitam:

Ingest: Waarp reçoit le SIP pour Vitam, puis le transmet (local ingest) à Vitam, puis retourne l'id d'entrée ; si la tâche est configurée pour, Waarp continue et spool Vitam jusqu'à obtenir le ATR et le retourne à son partenaire (ou 1 erreur à chaque étape)
DIP export: Waarp reçoit un fichier DSL pour Vitam, le transmet à dipexport, puis attend la fin de l'export pour retourner le résultat (zip) (ou 1 erreur à chaque étape)

Il est possible d'envisager d'autres applications (en remplacement donc d'un transport HTTPS) pour d'autres besoins.

Si cela intéresse qq1, je suis preneur bien sûr... Il sera publié prochainement avec la 3.2.0 de Waarp sur Github.

fredericBregier commented 4 years ago

Pour info:

Waarp-Vitam: https://github.com/waarp/WaarpVitam
la dernière version de Waarp: https://github.com/waarp/Waarp-All ;-)

fredericBregier commented 4 years ago

J'avais suggéré une évolution mineure sur le comportement des API pour être homogène (et penser au développeur fainéant qui a l'habitude d'un comportement usuel):

Ceci dit, j'aurais trouvé logique qu'une réponde 404 (en dehors du fait qu'elle soit propagée) soit logique en interne, à savoir, sans faire de pooling explicite sur /operations, quand on demande le résultat d'une opération asynchrone, si celle-ci n'est pas terminée (ou n'existe pas), que l'API fasse le travail pour moi (développeur fainéant) de faire la requête interne à HEAD /operations/id avant de faire la requête GET demandée. Cela permettrait selon moi un comportement simple et rassurant.

Qu'en est-il ? (d'où la non clôture de mon côté)

ProgrammeVitam / vitam

Issue while trying to get DIP export after correct request using API #19