Download submissions with pictures failed && aggregate error 500 when asking for binaryData (thumnails, csv, kml etc.)

Hugo_Roussaffa · May 17, 2018, 10:58pm

We are trying ODK for our organization. We have installed aggregate 1.5 under Tomcat 7 and apache2 with Postgresql 9.3 and the security is set to REQUIRES_SECURE_CHANNEL so we only connect throught HTTPS. We also set a reverse proxy for redirecting http->https (so we can't use ANY_CHANNEL because Collect can't follow the 302 redirection when submitting).

With this config, all works fine with ODK Collect. We can use sample like BIRDS.
Submitting pictures to aggregate works fine, pictures are stored under binary field in the database and we can extract it manually to check it. So no trouble on this side.

The trouble is on the way back : when we try to get submissions with aggregate's web interface or Briefcase : the download failed.

Under aggregate, we get "Internal server error 500" when we ask the thumbnail or when we use this request :

https://qualif.psud.nc/odkweb/view/binaryData?blobKey=Birds[%40version%3Dnull+and+%40uiVersion%3Dnull]%2Fnm[%40key%3Duuid%3A6539b7fb-06b6-440c-8275-a98b480366a2]%2Frepeat_observation[%40ordinal%3D2]%2Fimage&previewImage=true

here is the complete log (from tomcat start)
catalina.out.zip (6.4 KB)

Under Briefcase this is the error we get :

        [briefcase-pull-2-thread-1] INFO org.opendatakit.briefcase.util.ServerFetcher - Fetched instanceID=uuid:6539b7fb-06b6-440c-8275-a98b480366a2
    	[briefcase-pull-2-thread-1] ERROR org.opendatakit.briefcase.util.AggregateUtils - Fetch of /home/yogis/Documents/odk/ODK Briefcase Storage/forms/Birds/instances/uuid6539b7fb-06b6-440c-8275-a98b480366a2/1526444871289.jpg failed. Detailed reason: Internal Server Error (500)
    	[pool-1-thread-1] ERROR org.opendatakit.briefcase.util.ServerFetcher - failure during submission download
    	java.util.concurrent.ExecutionException: org.opendatakit.briefcase.model.TransmissionException: Fetch of /home/yogis/Documents/odk/ODK Briefcase Storage/forms/Birds/instances/uuid6539b7fb-06b6-440c-8275-a98b480366a2/1526444871289.jpg failed. Detailed reason: Internal Server Error (500)
    		at java.util.concurrent.FutureTask.report(FutureTask.java:122)
    		at java.util.concurrent.FutureTask.get(FutureTask.java:192)
    		at org.opendatakit.briefcase.util.ServerFetcher.downloadAllSubmissionsForForm(ServerFetcher.java:345)
    		at org.opendatakit.briefcase.util.ServerFetcher.downloadFormAndSubmissionFiles(ServerFetcher.java:194)
    		at org.opendatakit.briefcase.util.TransferFromServer.doAction(TransferFromServer.java:43)
    		at org.opendatakit.briefcase.util.TransferAction$GatherTransferRunnable.run(TransferAction.java:90)
    		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)
    	       Caused by: org.opendatakit.briefcase.model.TransmissionException: Fetch of /home/yogis/Documents/odk/ODK Briefcase Storage/forms/Birds/instances/uuid6539b7fb-06b6-440c-8275-a98b480366a2/1526444871289.jpg failed. Detailed reason: Internal Server Error (500)
    		at org.opendatakit.briefcase.util.AggregateUtils.commonDownloadFile(AggregateUtils.java:137)
    		at org.opendatakit.briefcase.util.ServerFetcher.downloadMediaFileIfChanged(ServerFetcher.java:610)
    		at org.opendatakit.briefcase.util.ServerFetcher.downloadSubmission(ServerFetcher.java:517)
    		at org.opendatakit.briefcase.util.ServerFetcher.access$100(ServerFetcher.java:59)
    		at org.opendatakit.briefcase.util.ServerFetcher$SubmissionDownload.call(ServerFetcher.java:424)
    		at org.opendatakit.briefcase.util.ServerFetcher$SubmissionDownload.call(ServerFetcher.java:406)
    		at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    		at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    		at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    		... 3 more

From logs, Catalina.out give no trace of that error. And I don't see any tomcat's stdout.log file
Maybe we don't look where we should.
For now we are staying without any idea of what's happend so if anybody has an idea, it's will be great.

thanks!

yanokwa · May 17, 2018, 11:49pm

Hi @Hugo_Roussaffa!

If there is an Internal Server Error as Briefcase reports, there should be something in the Aggregate log. I agree with you that it's not in the log you attached and that's strange. @ggalmazor do you have any ideas?

Hugo_Roussaffa · May 18, 2018, 12:44am

thanks to reply @yanokwa

I can get the image if I try to get it directly from the server :

 wget http://localhost:32500/odkweb/view/binaryData\?blobKey\=Birds%5B%40version%3Dnull+and+%40uiVersion%3Dnull%5D%2Fnm%5B%40key%3Duuid%3A6539b7fb-06b6-440c-8275-a98b480366a2%5D%2Frepeat_observation%5B%40ordinal%3D2%5D%2Fimage -O 'images.jpg'

.

--2018-05-18 11:22:30--  http://localhost:32500/odkweb/view/binaryData?blobKey=Birds%5B%40version%3Dnull+and+%40uiVersion%3Dnull%5D%2Fnm%5B%40key%3Duuid%3A6539b7fb-06b6-440c-8275-a98b480366a2%5D%2Frepeat_observation%5B%40ordinal%3D2%5D%2Fimage
Résolution de localhost (localhost)… ::1, 127.0.0.1
Connexion à localhost (localhost)|::1|:32500… connecté.
requête HTTP transmise, en attente de la réponse… 200 OK
Taille : 3330216 (3,2M) [image/jpeg]
Sauvegarde en : « images.jpg »

images.jpg                         100%[===============================================================>]   3,18M  --.-KB/s    in 0,01s   

En-tête de dernière modification incorrect — horodatage ignoré.
2018-05-18 11:22:31 (293 MB/s) — « images.jpg » sauvegardé [3330216/3330216]

To make it work I need to change the Security to ANY_CHANNEL because the server not support https protocol for itself. Has I told you before, it's not possible to work with this config cause Collect get a 302 redirect (reverse proxy redirection config) and as I understood it only waiting for a 201 reply.

You can also see in the gif the tail -f of catalina.out when the error occurs.

trouble_500

Hugo_Roussaffa · May 18, 2018, 4:06am

Finaly we find the problem and hopefully a solution.

We used ajp beetwen our reverse proxy and aggregate and it seem to make our trouble.

Logs were inside Apache and no Tomcat.

[Fri May 18 13:51:17.145934 2018] [http:error] [pid 25763:tid 139674551056128] [client 10.1.1.56:38418] AH02429: Response header name 'Expires:' contains invalid characters, aborting request

or

[Fri May 18 13:59:06.277604 2018] [http:error] [pid 794:tid 139674534270720] [client 10.30.5.20:59606] AH02429: Response header name 'Last-Modified:' contains invalid characters, aborting request

depending the request.

it's similar to this issue https://forum.getodk.org/t/invalid-character-in-last-modified-header-tomcat8-with-odk-aggregate/9162/3

But for us the solution was not possible, unsecuring the proxy is

added "HttpProtocolOptions unsafe"

So what we do is to use http instead of ajp (that's work directly if the securitychannel in security.properties is set to ANY_CHANNEL, but we use REQUIRES_SECURE_CHANNEL to work with Collect.

So, we change tomcat conf/server.xml to this :

     <Connector port="32500" protocol="HTTP/1.1" URIEncoding="UTF-8"  proxyName="qualif.psud.nc"  proxyPort="443" secure="true" ></Connector>

With that conf tomcat guess connection are secured between himself and the reverse proxy, and he doesn't send redirection. Obviously connections are not secured inside but still secure behind the reverse proxy.

hope this could help anyone.

Maybe it could be nice to make ajp works with the new apache security.

thx

ggalmazor · May 18, 2018, 8:23am

Hi! It seems that the original problem has been solved, does it? I've checked the link and I get a thumbnail (no errors)

Hugo_Roussaffa · May 21, 2018, 9:05pm

Actually it's an alternative solution cause we should use http than ajp (and also the tomcat's bypass)

We think you should correcting the aggregate code to match the new security rules of Apache.

Thanks.

yanokwa · June 21, 2018, 12:18am

@Hugo_Roussaffa I'm unclear what "new Apache security". What would really help us make this change is if you filed an issue at https://github.com/opendatakit/aggregate/issues describing precisely the changes.