Collect: Large number of submissions results in too many open files error

[yanokwa]

If you try to submit, say 1998 files, ODK Collect v1.4.16 will crash with the following stack trace.

If you need a test server, use https://nafundi-test.appspot.com. If you need 2000 submissions, use this odk folder.

While testing, you might need to delete the form from the server (it's the best way to delete all submissions). You can find the same blank form from /odk/forms/basic.xml.

03-06 13:27:18.960  4830  4879 I InstanceUploaderTask: Using Uri remap for submission 1682. Now: https://nafundi-test.appspot.com/submission
03-06 13:27:18.962  4830  4879 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_713.xml
03-06 13:27:18.963  4830  4879 I InstanceUploaderTask: Issuing POST request for 1682 to: https://nafundi-test.appspot.com/submission
03-06 13:27:19.687  4830  4879 I InstanceUploaderTask: Response code:201
03-06 13:27:19.698  4830  4879 I InstanceUploaderTask: Using Uri remap for submission 1683. Now: https://nafundi-test.appspot.com/submission
03-06 13:27:19.699  4830  4879 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_714.xml
03-06 13:27:19.699  4830  4879 I InstanceUploaderTask: Issuing POST request for 1683 to: https://nafundi-test.appspot.com/submission
03-06 13:27:20.004  4830  4879 W System.err: java.io.FileNotFoundException: /storage/emulated/0/odk/instances/basic_2017-03-06_10-39-48_714/basic_2017-03-06_10-39-48_714.xml (Too many open files)
03-06 13:27:20.005  4830  4879 W System.err:    at java.io.FileInputStream.open(Native Method)
03-06 13:27:20.005  4830  4879 W System.err:    at java.io.FileInputStream.<init>(FileInputStream.java:146)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.entity.mime.content.FileBody.writeTo(FileBody.java:116)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.entity.mime.AbstractMultipartForm.doWriteTo(AbstractMultipartForm.java:134)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.entity.mime.AbstractMultipartForm.writeTo(AbstractMultipartForm.java:157)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.entity.mime.MultipartFormEntity.writeTo(MultipartFormEntity.java:113)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.DefaultBHttpClientConnection.sendRequestEntity(DefaultBHttpClientConnection.java:158)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.conn.CPoolProxy.sendRequestEntity(CPoolProxy.java:162)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.protocol.HttpRequestExecutor.doSendRequest(HttpRequestExecutor.java:237)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:122)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.execchain.MainClientExec.execute(MainClientExec.java:271)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.execchain.RetryExec.execute(RetryExec.java:88)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
03-06 13:27:20.005  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
03-06 13:27:20.005  4830  4879 W System.err:    at org.odk.collect.android.tasks.InstanceUploaderTask.uploadOneSubmission(InstanceUploaderTask.java:476)
03-06 13:27:20.005  4830  4879 W System.err:    at org.odk.collect.android.tasks.InstanceUploaderTask.processChunk(InstanceUploaderTask.java:579)
03-06 13:27:20.005  4830  4879 W System.err:    at org.odk.collect.android.tasks.InstanceUploaderTask.doInBackground(InstanceUploaderTask.java:605)
03-06 13:27:20.005  4830  4879 W System.err:    at org.odk.collect.android.tasks.InstanceUploaderTask.doInBackground(InstanceUploaderTask.java:71)
03-06 13:27:20.005  4830  4879 W System.err:    at android.os.AsyncTask$2.call(AsyncTask.java:305)
03-06 13:27:20.005  4830  4879 W System.err:    at java.util.concurrent.FutureTask.run(FutureTask.java:237)
03-06 13:27:20.005  4830  4879 W System.err:    at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:243)
03-06 13:27:20.005  4830  4879 W System.err:    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
03-06 13:27:20.005  4830  4879 W System.err:    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
03-06 13:27:20.005  4830  4879 W System.err:    at java.lang.Thread.run(Thread.java:761)
03-06 13:27:20.005  4830  4879 E InstanceUploaderTask: java.io.FileNotFoundException: /storage/emulated/0/odk/instances/basic_2017-03-06_10-39-48_714/basic_2017-03-06_10-39-48_714.xml (Too many open files)
03-06 13:27:20.021  4830  4879 I InstanceUploaderTask: Using Uri remap for submission 1684. Now: https://nafundi-test.appspot.com/submission
03-06 13:27:20.022  4830  4879 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_715.xml
03-06 13:27:20.022  4830  4879 I InstanceUploaderTask: Issuing POST request for 1684 to: https://nafundi-test.appspot.com/submission
03-06 13:27:20.364  4830  4879 W System.err: java.io.FileNotFoundException: /storage/emulated/0/odk/instances/basic_2017-03-06_10-39-48_715/basic_2017-03-06_10-39-48_715.xml (Too many open files)
03-06 13:27:20.364  4830  4879 W System.err:    at java.io.FileInputStream.open(Native Method)
03-06 13:27:20.364  4830  4879 W System.err:    at java.io.FileInputStream.<init>(FileInputStream.java:146)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.entity.mime.content.FileBody.writeTo(FileBody.java:116)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.entity.mime.AbstractMultipartForm.doWriteTo(AbstractMultipartForm.java:134)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.entity.mime.AbstractMultipartForm.writeTo(AbstractMultipartForm.java:157)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.entity.mime.MultipartFormEntity.writeTo(MultipartFormEntity.java:113)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.DefaultBHttpClientConnection.sendRequestEntity(DefaultBHttpClientConnection.java:158)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.conn.CPoolProxy.sendRequestEntity(CPoolProxy.java:162)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.protocol.HttpRequestExecutor.doSendRequest(HttpRequestExecutor.java:237)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:122)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.execchain.MainClientExec.execute(MainClientExec.java:271)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.execchain.ProtocolExec.execute(ProtocolExec.java:184)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.execchain.RetryExec.execute(RetryExec.java:88)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.execchain.RedirectExec.execute(RedirectExec.java:110)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
03-06 13:27:20.364  4830  4879 W System.err:    at org.opendatakit.httpclientandroidlib.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:55)
03-06 13:27:20.364  4830  4879 W System.err:    at org.odk.collect.android.tasks.InstanceUploaderTask.uploadOneSubmission(InstanceUploaderTask.java:476)
03-06 13:27:20.364  4830  4879 W System.err:    at org.odk.collect.android.tasks.InstanceUploaderTask.processChunk(InstanceUploaderTask.java:579)
03-06 13:27:20.364  4830  4879 W System.err:    at org.odk.collect.android.tasks.InstanceUploaderTask.doInBackground(InstanceUploaderTask.java:605)
03-06 13:27:20.364  4830  4879 W System.err:    at org.odk.collect.android.tasks.InstanceUploaderTask.doInBackground(InstanceUploaderTask.java:71)
03-06 13:27:20.364  4830  4879 W System.err:    at android.os.AsyncTask$2.call(AsyncTask.java:305)
03-06 13:27:20.364  4830  4879 W System.err:    at java.util.concurrent.FutureTask.run(FutureTask.java:237)
03-06 13:27:20.364  4830  4879 W System.err:    at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:243)
03-06 13:27:20.364  4830  4879 W System.err:    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
03-06 13:27:20.365  4830  4879 W System.err:    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
03-06 13:27:20.365  4830  4879 W System.err:    at java.lang.Thread.run(Thread.java:761)
03-06 13:27:20.365  4830  4879 E InstanceUploaderTask: java.io.FileNotFoundException: /storage/emulated/0/odk/instances/basic_2017-03-06_10-39-48_715/basic_2017-03-06_10-39-48_715.xml (Too many open files)
03-06 13:27:20.378  4830  4879 I InstanceUploaderTask: Using Uri remap for submission 1685. Now: https://nafundi-test.appspot.com/submission

[nribeka]

This could be as simple as closing the response object in a finally block.

[lakshyagupta21]

@yanokwa I would like to fix it !!

[yanokwa]

@lakshyagupta21 Please go ahead.

[lakshyagupta21]

@yanokwa I tried running app for the above odk directory but didn't get anything related to above error. And all my files are getting uploaded but somewhere in last i am getting sql error in uploadingComplete method in InstanceUploaderActivity. I request you to please check one more time by reinstalling the app and replacing the previous odk directory by the above directory. I am using Marshmallow for testing , will you please tell me about the device on which you are testing. I will try in that device too.

Is there any limit on maximum request that we can make to https://nafundi-test.appspot.com/ because i wasn't able to access this link yesterday.

03-09 20:27:50.588 30674-30921/org.odk.collect.android I/InstanceUploaderTask: Issuing POST request for 1997 to: https://nafundi-test.appspot.com/submission
03-09 20:27:51.959 30674-30921/org.odk.collect.android I/InstanceUploaderTask: Response code:201
03-09 20:27:52.048 30674-30921/org.odk.collect.android I/InstanceUploaderTask: Using Uri remap for submission 1998. Now: https://nafundi-test.appspot.com/submission
03-09 20:27:52.059 30674-30921/org.odk.collect.android I/InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_999.xml
03-09 20:27:52.062 30674-30921/org.odk.collect.android I/InstanceUploaderTask: Issuing POST request for 1998 to: https://nafundi-test.appspot.com/submission
03-09 20:27:53.590 30674-30921/org.odk.collect.android I/InstanceUploaderTask: Response code:201
03-09 20:27:53.711 30674-30674/org.odk.collect.android I/InstanceUploaderActiv: uploadingComplete: Processing results (1998) from upload of 1998 instances!
03-09 20:27:53.755 30674-30674/org.odk.collect.android E/SQLiteLog: (1) Expression tree is too large (maximum depth 1000)
03-09 20:27:53.763 30674-30674/org.odk.collect.android E/EXCEPTION: android.database.sqlite.SQLiteException: Expression tree is too large (maximum depth 1000) (code 1): , while compiling: SELECT canEditWhenComplete, deletedDate, status, jrVersion, jrFormId, instanceFilePath, date, submissionUri, displayName, _id, displaySubtext FROM instances WHERE (_id=? or _id=? or _id=? or _id=? or _id=? or _id=? or _id=? or _id=? or _id=? or _id=? or _i

[lakshyagupta21]

If i see about response code in logcat i am getting Response code:201 for every file but on server i am only able to see one file. All files have same label so i think it is treated as primary key over server. If i change label in any of the files i am able to see the new file added but with same label it doesn't get reflected there.

[yanokwa]

@lakshyagupta21 I've added more quota to https://nafundi-test.appspot.com so it shouldn't go down.

First, file an issue with the "Expression tree is too large" bug so we have a record. Then please try to reproduce the issue on a Pixel running API 25 in the Android emulator.

[yanokwa]

@lakshyagupta21 I've also added a new ODK folder in the original post that doesn't have the unique instanceID. When you submit, you should now see multiple submissions on the server. Be sure to delete the test form (and thus the submissions) and wait a few minutes between each run.

[lakshyagupta21]

@yanokwa There is one more point that i want to discuss. Actually now a days service is being used for all the backend related things like file upload, file download, etc. So what if we write services for uploading files as when user tries to upload any number of files he has to wait till all his files first gets uploaded on server, then only he is allowed to move to other activities of Application. I mean there is no functionality to run the uploading process to go in background so that user can fill,edit or send other forms too. While testing it took me around 30 minutes - 1 hour to upload all 2000 files. And while uploading say 1998 number of files the dialog box is showing status like this "1 out of 999 files" and after completing all 999 it again starts with 1 for the rest of 999 files. The expected behaviour should be like "1 out of 1998".
Correct me if i am wrong.

[nribeka]

@lakshyagupta21 ah that status is a bug. I think it's publishing based on the query number, not the current position of the uploading process.

I missed that one when I update the uploader to allow more than 1000 instances.

[nribeka]

I think you can create a separate issue for that one and create a PR to fix that status counter.

Regarding the background service to do the upload, I think it would be a nice refactor to do the uploading asynchronously (and should go into separate issue as well).

[nribeka]

@lakshyagupta21 i created a separate bug for the dialog box issue #585.

[lakshyagupta21]

@nribeka Thanks !!

[lakshyagupta21]

@yanokwa I created the emulator having PIXEL running API 25 and tried running the app on it. While running it gets stuck somewhere in the middle of uploading files. It doesn't show anything in logcat also i tried it 3-4 times but couldn't produce the above error. I tried in Nexus 5 running API 23 in that it was working fine, what should i do ?

[lakshyagupta21]

@nribeka I need help in this issue.

[yanokwa]

Hi @lakshyagupta21, I'm sorry about the delay on this issue!

I've tested this on a Pixel emulator running API 25 and for 1998 files, it fails at 1466. Given that this is so painful to test on a slow connection, I think @nribeka should give it go.

And to make the test go faster, @nribeka, I'd recommend using a local VM instead of running it against App Engine. https://github.com/nafundi/odk-aggregate-box makes it easy to get Aggregate up and running.

04-21 16:31:12.195  5223  5315 I InstanceUploaderTask: Using Uri remap for submission 1466. Now: https://nafundi-test.appspot.com/submission
04-21 16:31:12.197  5223  5315 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_519.xml
04-21 16:31:12.197  5223  5315 I InstanceUploaderTask: Issuing POST request for 1466 to: https://nafundi-test.appspot.com/submission
04-21 16:31:12.827  5223  5315 I InstanceUploaderTask: Response code:201
04-21 16:31:12.839  5223  5315 I InstanceUploaderTask: Using Uri remap for submission 1467. Now: https://nafundi-test.appspot.com/submission
04-21 16:31:12.841  5223  5315 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_52.xml
04-21 16:31:12.842  5223  5315 I InstanceUploaderTask: Issuing POST request for 1467 to: https://nafundi-test.appspot.com/submission
04-21 16:31:13.337  5223  5315 I InstanceUploaderTask: Response code:201
04-21 16:31:13.341  5223  5315 E SQLiteLog: (14) cannot open file at line 30188 of [bda77dda96]
04-21 16:31:13.341  5223  5315 E SQLiteLog: (14) os_unix.c:30188: (24) open(/storage/emulated/0/odk/metadata) -
04-21 16:31:13.345  5223  5315 I InstanceUploaderTask: Using Uri remap for submission 1468. Now: https://nafundi-test.appspot.com/submission
04-21 16:31:13.345  5223  5315 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_520.xml
04-21 16:31:13.346  5223  5315 I InstanceUploaderTask: Issuing POST request for 1468 to: https://nafundi-test.appspot.com/submission
04-21 16:31:13.348  5223  5315 E InstanceUploaderTask: org.opendatakit.httpclientandroidlib.conn.HttpHostConnectException: Connect to nafundi-test.appspot.com:443 [nafundi-test.appspot.com/216.58.193.212, nafundi-test.appspot.com/2607:f8b0:4007:80b::2014] failed: Too many open files
04-21 16:31:13.363  5223  5315 E SQLiteLog: (14) cannot open file at line 30188 of [bda77dda96]
04-21 16:31:13.363  5223  5315 E SQLiteLog: (14) os_unix.c:30188: (24) open(/storage/emulated/0/odk/metadata) -
04-21 16:31:13.368  5223  5315 I InstanceUploaderTask: Using Uri remap for submission 1469. Now: https://nafundi-test.appspot.com/submission
04-21 16:31:13.368  5223  5315 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_521.xml
04-21 16:31:13.369  5223  5315 I InstanceUploaderTask: Issuing POST request for 1469 to: https://nafundi-test.appspot.com/submission
04-21 16:31:13.371  5223  5315 E InstanceUploaderTask: org.opendatakit.httpclientandroidlib.conn.HttpHostConnectException: Connect to nafundi-test.appspot.com:443 [nafundi-test.appspot.com/216.58.193.212, nafundi-test.appspot.com/2607:f8b0:4007:80b::2014] failed: Too many open files
04-21 16:31:13.379  5223  5315 E SQLiteLog: (14) cannot open file at line 30188 of [bda77dda96]
04-21 16:31:13.379  5223  5315 E SQLiteLog: (14) os_unix.c:30188: (24) open(/storage/emulated/0/odk/metadata) -
04-21 16:31:13.386  5223  5315 I InstanceUploaderTask: Using Uri remap for submission 1470. Now: https://nafundi-test.appspot.com/submission
04-21 16:31:13.395  5223  5223 E SQLiteLog: (14) cannot open file at line 32456 of [bda77dda96]
04-21 16:31:13.395  5223  5223 E SQLiteLog: (14) os_unix.c:32456: (24) open(/storage/emulated/0/odk/metadata/instances.db-journal) -
04-21 16:31:13.395  5223  5223 E SQLiteLog: (14) cannot open file at line 32456 of [bda77dda96]
04-21 16:31:13.395  5223  5223 E SQLiteLog: (14) os_unix.c:32456: (24) open(/storage/emulated/0/odk/metadata/instances.db-journal) -
04-21 16:31:13.395  5223  5223 E SQLiteLog: (14) statement aborts at 40: [SELECT canEditWhenComplete, deletedDate, status, jrVersion, jrFormId, instanceFilePath, date, submissionUri, displayName, _id, displaySubtext FROM instances WHERE (status !=? ) ORDER B
04-21 16:31:13.395  5223  5223 E SQLiteQuery: exception: unable to open database file (code 14); query: SELECT canEditWhenComplete, deletedDate, status, jrVersion, jrFormId, instanceFilePath, date, submissionUri, displayName, _id, displaySubtext FROM instances WHERE (status !=? ) ORDER BY status DESC, displayName ASC
04-21 16:31:13.396  5223  5223 D AndroidRuntime: Shutting down VM
--------- beginning of crash
04-21 16:31:13.396  5223  5223 E AndroidRuntime: FATAL EXCEPTION: main
04-21 16:31:13.396  5223  5223 E AndroidRuntime: Process: org.odk.collect.android, PID: 5223
04-21 16:31:13.396  5223  5223 E AndroidRuntime: android.database.sqlite.SQLiteCantOpenDatabaseException: unable to open database file (code 14)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at android.database.sqlite.SQLiteConnection.nativeExecuteForCursorWindow(Native Method)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at android.database.sqlite.SQLiteConnection.executeForCursorWindow(SQLiteConnection.java:845)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at android.database.sqlite.SQLiteSession.executeForCursorWindow(SQLiteSession.java:836)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at android.database.sqlite.SQLiteQuery.fillWindow(SQLiteQuery.java:62)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at android.database.sqlite.SQLiteCursor.fillWindow(SQLiteCursor.java:143)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at android.database.sqlite.SQLiteCursor.getCount(SQLiteCursor.java:132)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at android.database.CursorWrapper.getCount(CursorWrapper.java:60)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at org.odk.collect.android.activities.MainMenuActivity.updateButtons(MainMenuActivity.java:581)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at org.odk.collect.android.activities.MainMenuActivity.access$100(MainMenuActivity.java:75)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at org.odk.collect.android.activities.MainMenuActivity$IncomingHandler.handleMessage(MainMenuActivity.java:694)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at android.os.Handler.dispatchMessage(Handler.java:102)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at android.os.Looper.loop(Looper.java:154)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at android.app.ActivityThread.main(ActivityThread.java:6119)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at java.lang.reflect.Method.invoke(Native Method)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:886)
04-21 16:31:13.396  5223  5223 E AndroidRuntime:    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:776)
04-21 16:31:13.398  1597  1792 W ActivityManager:   Force finishing activity org.odk.collect.android/.activities.InstanceUploaderActivity
04-21 16:31:13.400  5223  5315 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_522.xml
04-21 16:31:13.401  5223  5315 I InstanceUploaderTask: Issuing POST request for 1470 to: https://nafundi-test.appspot.com/submission
04-21 16:31:13.428  1327  1365 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
04-21 16:31:13.436  5223  5315 E NativeCrypto: AppData::create pipe(2) failed: Too many open files
04-21 16:31:13.437  5223  5315 E InstanceUploaderTask: javax.net.ssl.SSLException: Unable to create application data
04-21 16:31:13.460  5223  5315 I InstanceUploaderTask: Using Uri remap for submission 1471. Now: https://nafundi-test.appspot.com/submission
04-21 16:31:13.461  5223  5315 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_523.xml
04-21 16:31:13.462  5223  5315 I InstanceUploaderTask: Issuing POST request for 1471 to: https://nafundi-test.appspot.com/submission
04-21 16:31:13.484  1327  1365 D gralloc_ranchu: gralloc_alloc: format 1 and usage 0x900 imply creation of host color buffer
04-21 16:31:13.485  1597  5906 D         : HostConnection::get() New Host Connection established 0x8858b2c0, tid 5906
04-21 16:31:13.490  1327  1365 D gralloc_ranchu: gralloc_alloc: format 1 and usage 0x900 imply creation of host color buffer
04-21 16:31:13.494  1327  1365 D gralloc_ranchu: gralloc_alloc: format 1 and usage 0x900 imply creation of host color buffer
04-21 16:31:13.494  5223  5315 E NativeCrypto: AppData::create pipe(2) failed: Too many open files
04-21 16:31:13.496  5223  5315 E InstanceUploaderTask: javax.net.ssl.SSLException: Unable to create application data
04-21 16:31:13.497  1597  5906 I OpenGLRenderer: Initialized EGL, version 1.4
04-21 16:31:13.497  1597  5906 D OpenGLRenderer: Swap behavior 1
04-21 16:31:13.497  1597  5906 W OpenGLRenderer: Failed to choose config with EGL_SWAP_BEHAVIOR_PRESERVED, retrying without...
04-21 16:31:13.497  1597  5906 D OpenGLRenderer: Swap behavior 0
04-21 16:31:13.507  5223  5315 I InstanceUploaderTask: Using Uri remap for submission 1472. Now: https://nafundi-test.appspot.com/submission
04-21 16:31:13.507  5223  5315 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_524.xml
04-21 16:31:13.508  5223  5315 I InstanceUploaderTask: Issuing POST request for 1472 to: https://nafundi-test.appspot.com/submission
04-21 16:31:13.540  5223  5315 E NativeCrypto: AppData::create pipe(2) failed: Too many open files
04-21 16:31:13.541  5223  5315 E InstanceUploaderTask: javax.net.ssl.SSLException: Unable to create application data
04-21 16:31:13.548  5223  5315 I InstanceUploaderTask: Using Uri remap for submission 1473. Now: https://nafundi-test.appspot.com/submission
04-21 16:31:13.550  5223  5315 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_525.xml
04-21 16:31:13.551  5223  5315 I InstanceUploaderTask: Issuing POST request for 1473 to: https://nafundi-test.appspot.com/submission
04-21 16:31:13.583  5223  5315 E NativeCrypto: AppData::create pipe(2) failed: Too many open files
04-21 16:31:13.584  5223  5315 E InstanceUploaderTask: javax.net.ssl.SSLException: Unable to create application data

[nribeka]

@yanokwa will look at this 👍

[nribeka]

I don't know if you're seeing this @yanokwa, but i'm getting a lot of exception when uploading.

04-25 16:11:42.955 19488-26186/org.odk.collect.android I/InstanceUploaderTask: Using Uri remap for submission 104. Now: https://nafundi-test.appspot.com/submission
04-25 16:11:42.956 19488-26186/org.odk.collect.android I/InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_1090.xml
04-25 16:11:42.957 19488-26186/org.odk.collect.android I/InstanceUploaderTask: Issuing POST request for 104 to: https://nafundi-test.appspot.com/submission
04-25 16:11:43.548 19488-26186/org.odk.collect.android E/WebUtils: Unable read the stream
java.io.IOException: Attempted read from closed stream.
    at org.opendatakit.httpclientandroidlib.impl.io.ContentLengthInputStream.read(ContentLengthInputStream.java:167)
    at org.opendatakit.httpclientandroidlib.conn.EofSensorInputStream.read(EofSensorInputStream.java:137)
    at libcore.io.Streams.skipByReading(Streams.java:159)
    at java.io.InputStream.skip(InputStream.java:229)
    at org.odk.collect.android.utilities.WebUtils.discardEntityBytes(WebUtils.java:290)
    at org.odk.collect.android.tasks.InstanceUploaderTask.uploadOneSubmission(InstanceUploaderTask.java:463)
    at org.odk.collect.android.tasks.InstanceUploaderTask.processChunk(InstanceUploaderTask.java:575)
    at org.odk.collect.android.tasks.InstanceUploaderTask.doInBackground(InstanceUploaderTask.java:599)
    at org.odk.collect.android.tasks.InstanceUploaderTask.doInBackground(InstanceUploaderTask.java:74)
    at android.os.AsyncTask$2.call(AsyncTask.java:295)
    at java.util.concurrent.FutureTask.run(FutureTask.java:237)
    at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:234)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1113)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:588)
    at java.lang.Thread.run(Thread.java:818)

[yanokwa]

It might be an issue with you guys killing my App Engine instance! Try with a local box: https://github.com/nafundi/odk-aggregate-box

[nribeka]

I'm in locked network, so can't use my phone. Tried using vagrant, and the emulator won't like the virtualbox running in the same instance. Have you run into this issue?

This exception is different though. So I looked into the code.

messageParser = new ResponseMessageParser(httpEntity);
WebUtils.discardEntityBytes(response);

When ResponseMessageParser gets created, it's also reading the response entity as a whole and then close the stream. But the following line of code will try to read this closed stream.

[yanokwa]

I used to have the problem of Virtualbox and the emulator not running simultaneously. The solution is to upgrade to the latest version of HAXM. I think 6.1.1 is when they fixed the problem.

Android Studio doesn't make it easy for you to upgrade HAXM, you might have to install it manually.

• Mac/Windows: https://software.intel.com/en-us/android/articles/intel-hardware-accelerated-execution-manager

[nribeka]

Tested locally and 9k + 2k instances were uploaded successfully. Maybe we need to close this?

I notice there are 2 issues that we need to address from this testing:

1. The exception mentioned above.
2. The observer in the MainMenuActivity is always trying to sync the number of instances by executing the count query on the instances table. This will be fine if the InstanceSyncTask is not running and syncing hundreds of instances from the file system. As soon as it reach a few hundreds instances, it will just bog down the application and making it not responsive. I think I posted the gif file in slack a while back where it's counting fast early on and then slowing down as the number grows to a few hundreds.

[yanokwa]

@nribeka Can you please file an issue on the observer in MainMenuActivity?

[yanokwa]

I think there is a bug and I can repro it on my Pixel emulator running API 25 and submitting to nafundi-test. I do not get the behavior when submitting to a local server.

I do not get it with a Nexus 5 emulator running API 22 and submitting to nafundi-test. What emulator did you use, @nribeka?

Run 1

04-28 18:44:35.121  5705  5754 I InstanceUploaderTask: Issuing POST request for 1678 to: https://nafundi-test.appspot.com/submission
04-28 18:44:35.697  5705  5754 I InstanceUploaderTask: Response code:201
04-28 18:44:35.712  5705  5754 I InstanceUploaderTask: Using Uri remap for submission 1679. Now: https://nafundi-test.appspot.com/submission
04-28 18:44:35.714  5705  5754 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_710.xml
04-28 18:44:35.714  5705  5754 I InstanceUploaderTask: Issuing POST request for 1679 to: https://nafundi-test.appspot.com/submission
04-28 18:44:36.139  5705  5754 I InstanceUploaderTask: Response code:201
04-28 18:44:36.157  5705  5754 I InstanceUploaderTask: Using Uri remap for submission 1680. Now: https://nafundi-test.appspot.com/submission
04-28 18:44:36.158  5705  5754 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_711.xml
04-28 18:44:36.159  5705  5754 I InstanceUploaderTask: Issuing POST request for 1680 to: https://nafundi-test.appspot.com/submission
04-28 18:44:36.643  5705  5754 I InstanceUploaderTask: Response code:201
04-28 18:44:36.646  5705  5754 E SQLiteLog: (14) cannot open file at line 30188 of [bda77dda96]
04-28 18:44:36.646  5705  5754 E SQLiteLog: (14) os_unix.c:30188: (24) open(/storage/emulated/0/odk/metadata) -
04-28 18:44:36.653  5705  5754 I InstanceUploaderTask: Using Uri remap for submission 1681. Now: https://nafundi-test.appspot.com/submission
--------- beginning of crash
04-28 18:44:36.657  5705  5754 E AndroidRuntime: FATAL EXCEPTION: AsyncTask #4
04-28 18:44:36.657  5705  5754 E AndroidRuntime: Process: org.odk.collect.android, PID: 5705
04-28 18:44:36.657  5705  5754 E AndroidRuntime: java.lang.RuntimeException: An error occurred while executing doInBackground()
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at android.os.AsyncTask$3.done(AsyncTask.java:325)
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:354)
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at java.util.concurrent.FutureTask.setException(FutureTask.java:223)
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at java.util.concurrent.FutureTask.run(FutureTask.java:242)
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:243)
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at java.lang.Thread.run(Thread.java:761)
04-28 18:44:36.657  5705  5754 E AndroidRuntime: Caused by: java.lang.NullPointerException: Attempt to get length of null array
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at org.odk.collect.android.tasks.InstanceUploaderTask.uploadOneSubmission(InstanceUploaderTask.java:291)
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at org.odk.collect.android.tasks.InstanceUploaderTask.processChunk(InstanceUploaderTask.java:587)
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at org.odk.collect.android.tasks.InstanceUploaderTask.doInBackground(InstanceUploaderTask.java:611)
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at org.odk.collect.android.tasks.InstanceUploaderTask.doInBackground(InstanceUploaderTask.java:76)
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at android.os.AsyncTask$2.call(AsyncTask.java:305)
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    at java.util.concurrent.FutureTask.run(FutureTask.java:237)
04-28 18:44:36.657  5705  5754 E AndroidRuntime:    ... 4 more
04-28 18:44:36.659  1600  1627 W ActivityManager:   Force finishing activity org.odk.collect.android/.activities.InstanceUploaderActivity
04-28 18:44:36.668  5705  5705 I InstanceUploaderActiv: onPause: Pausing upload of 1998 instances!
04-28 18:44:36.676  5705  6309 E SQLiteLog: (14) cannot open file at line 32456 of [bda77dda96]
04-28 18:44:36.676  5705  6309 E SQLiteLog: (14) os_unix.c:32456: (24) open(/data/user/0/org.odk.collect.android/databases/google_app_measurement_local.db-journal) -
04-28 18:44:36.676  5705  6309 E SQLiteLog: (14) cannot open file at line 32456 of [bda77dda96]
04-28 18:44:36.676  5705  6309 E SQLiteLog: (14) os_unix.c:32456: (24) open(/data/user/0/org.odk.collect.android/databases/google_app_measurement_local.db-journal) -
04-28 18:44:36.676  5705  6309 E SQLiteLog: (14) statement aborts at 10: [SELECT name FROM SQLITE_MASTER WHERE name=?] unable to open database file
04-28 18:44:36.676  5705  6309 E SQLiteQuery: exception: unable to open database file (code 14); query: SELECT name FROM SQLITE_MASTER WHERE name=?
04-28 18:44:36.679  5705  6309 W FA      : Error querying for table: messages, android.database.sqlite.SQLiteCantOpenDatabaseException: unable to open database file (code 14): com.google.android.gms.internal.zzasu.zza(Unknown Source)
04-28 18:44:36.680  5705  6309 E SQLiteLog: (14) cannot open file at line 32456 of [bda77dda96]
04-28 18:44:36.680  5705  6309 E SQLiteLog: (14) os_unix.c:32456: (24) open(/data/user/0/org.odk.collect.android/databases/google_app_measurement_local.db-journal) -
04-28 18:44:36.680  5705  6309 E SQLiteLog: (14) statement aborts at 9: [INSERT INTO messages(entry,type) VALUES (?,?)]
04-28 18:44:36.682  5705  6309 E FA      : Error writing entry to local database: android.database.sqlite.SQLiteCantOpenDatabaseException: unable to open database file (code 14): com.google.android.gms.internal.zzatg.zza(Unknown Source)
04-28 18:44:36.683  5705  5733 W art     : Large object allocation failed: ashmem_create_region failed for 'large object space allocation': Too many open files
04-28 18:44:36.683  5705  5733 I art     : Starting a blocking GC Alloc
04-28 18:44:36.683  5705  5733 I art     : Starting a blocking GC Alloc
04-28 18:44:36.694  5705  5733 I art     : Alloc partial concurrent mark sweep GC freed 64709(3MB) AllocSpace objects, 10(200KB) LOS objects, 27% free, 10MB/14MB, paused 602us total 10.648ms
04-28 18:44:36.694  5705  5733 W art     : Large object allocation failed: ashmem_create_region failed for 'large object space allocation': Too many open files
04-28 18:44:36.694  5705  5733 I art     : Starting a blocking GC Alloc
04-28 18:44:36.706  5705  5733 I art     : Alloc sticky concurrent mark sweep GC freed 75(2072B) AllocSpace objects, 0(0B) LOS objects, 26% free, 10MB/14MB, paused 1.246ms total 12.017m

Run 2

04-29 08:15:46.750  3033  3084 I InstanceUploaderTask: Using Uri remap for submission 1502. Now: https://nafundi-test.appspot.com/submission
04-29 08:15:46.752  3033  3084 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_551.xml
04-29 08:15:46.753  3033  3084 I InstanceUploaderTask: Issuing POST request for 1502 to: https://nafundi-test.appspot.com/submission
04-29 08:15:47.255  3033  3084 I InstanceUploaderTask: Response code:201
04-29 08:15:47.258  3033  3084 E SQLiteLog: (14) cannot open file at line 30188 of [bda77dda96]
04-29 08:15:47.258  3033  3084 E SQLiteLog: (14) os_unix.c:30188: (24) open(/storage/emulated/0/odk/metadata) -
04-29 08:15:47.264  3033  3084 I InstanceUploaderTask: Using Uri remap for submission 1503. Now: https://nafundi-test.appspot.com/submission
04-29 08:15:47.266  3033  3084 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_552.xml
04-29 08:15:47.266  3033  3084 I InstanceUploaderTask: Issuing POST request for 1503 to: https://nafundi-test.appspot.com/submission
04-29 08:15:47.267  3033  3033 E SQLiteLog: (14) cannot open file at line 32456 of [bda77dda96]
04-29 08:15:47.267  3033  3033 E SQLiteLog: (14) os_unix.c:32456: (24) open(/storage/emulated/0/odk/metadata/instances.db-journal) -
04-29 08:15:47.267  3033  3033 E SQLiteLog: (14) cannot open file at line 32456 of [bda77dda96]
04-29 08:15:47.267  3033  3033 E SQLiteLog: (14) os_unix.c:32456: (24) open(/storage/emulated/0/odk/metadata/instances.db-journal) -
04-29 08:15:47.267  3033  3033 E SQLiteLog: (14) statement aborts at 40: [SELECT canEditWhenComplete, deletedDate, status, jrVersion, jrFormId, instanceFilePath, date, submissionUri, displayName, _id, displaySubtext FROM instances WHERE (status !=? ) ORDER B
04-29 08:15:47.267  3033  3033 E SQLiteQuery: exception: unable to open database file (code 14); query: SELECT canEditWhenComplete, deletedDate, status, jrVersion, jrFormId, instanceFilePath, date, submissionUri, displayName, _id, displaySubtext FROM instances WHERE (status !=? ) ORDER BY status DESC, displayName ASC
04-29 08:15:47.268  3033  3033 D AndroidRuntime: Shutting down VM
04-29 08:15:47.268  3033  3084 E InstanceUploaderTask: org.opendatakit.httpclientandroidlib.conn.HttpHostConnectException: Connect to nafundi-test.appspot.com:443 [nafundi-test.appspot.com/216.58.194.84, nafundi-test.appspot.com/2607:f8b0:4000:803::2014] failed: Too many open files
--------- beginning of crash
04-29 08:15:47.268  3033  3033 E AndroidRuntime: FATAL EXCEPTION: main
04-29 08:15:47.268  3033  3033 E AndroidRuntime: Process: org.odk.collect.android, PID: 3033
04-29 08:15:47.268  3033  3033 E AndroidRuntime: android.database.sqlite.SQLiteCantOpenDatabaseException: unable to open database file (code 14)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at android.database.sqlite.SQLiteConnection.nativeExecuteForCursorWindow(Native Method)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at android.database.sqlite.SQLiteConnection.executeForCursorWindow(SQLiteConnection.java:845)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at android.database.sqlite.SQLiteSession.executeForCursorWindow(SQLiteSession.java:836)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at android.database.sqlite.SQLiteQuery.fillWindow(SQLiteQuery.java:62)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at android.database.sqlite.SQLiteCursor.fillWindow(SQLiteCursor.java:143)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at android.database.sqlite.SQLiteCursor.getCount(SQLiteCursor.java:132)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at android.database.CursorWrapper.getCount(CursorWrapper.java:60)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at org.odk.collect.android.activities.MainMenuActivity.updateButtons(MainMenuActivity.java:581)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at org.odk.collect.android.activities.MainMenuActivity.access$100(MainMenuActivity.java:75)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at org.odk.collect.android.activities.MainMenuActivity$IncomingHandler.handleMessage(MainMenuActivity.java:694)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at android.os.Handler.dispatchMessage(Handler.java:102)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at android.os.Looper.loop(Looper.java:154)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at android.app.ActivityThread.main(ActivityThread.java:6119)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at java.lang.reflect.Method.invoke(Native Method)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:886)
04-29 08:15:47.268  3033  3033 E AndroidRuntime:    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:776)
04-29 08:15:47.270  1607  1618 W ActivityManager:   Force finishing activity org.odk.collect.android/.activities.InstanceUploaderActivity
04-29 08:15:47.295  3033  3084 I InstanceUploaderTask: Using Uri remap for submission 1504. Now: https://nafundi-test.appspot.com/submission
04-29 08:15:47.296  3033  3084 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_553.xml
04-29 08:15:47.296  3033  3084 I InstanceUploaderTask: Issuing POST request for 1504 to: https://nafundi-test.appspot.com/submission
04-29 08:15:47.305  1328  1379 E SurfaceFlinger: ro.sf.lcd_density must be defined as a build property
04-29 08:15:47.325  3033  3084 E NativeCrypto: AppData::create pipe(2) failed: Too many open files
04-29 08:15:47.326  3033  3084 E InstanceUploaderTask: javax.net.ssl.SSLException: Unable to create application data
04-29 08:15:47.335  3033  3084 I InstanceUploaderTask: Using Uri remap for submission 1505. Now: https://nafundi-test.appspot.com/submission
04-29 08:15:47.336  3033  3084 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_554.xml
04-29 08:15:47.336  3033  3084 I InstanceUploaderTask: Issuing POST request for 1505 to: https://nafundi-test.appspot.com/submission
04-29 08:15:47.357  1607  3669 D         : HostConnection::get() New Host Connection established 0x8d21ed80, tid 3669
04-29 08:15:47.357  1328  1648 D gralloc_ranchu: gralloc_alloc: format 1 and usage 0x900 imply creation of host color buffer

[yanokwa]

Testing on a Moto G4 with Android 7.0 submitting to nafundi-test also gets errors.

04-29 12:04:33.567 24573 24776 I InstanceUploaderTask: Response code:201
04-29 12:04:33.595 24573 24776 I InstanceUploaderTask: Using Uri remap for submission 1604. Now: https://nafundi-test.appspot.com/submission
04-29 12:04:33.599 24573 24776 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_643.xml
04-29 12:04:33.601 24573 24776 I InstanceUploaderTask: Issuing POST request for 1604 to: https://nafundi-test.appspot.com/submission
04-29 12:04:33.640 24573 24776 E NativeCrypto: AppData::create pipe(2) failed: Too many open files
04-29 12:04:33.644 24573 24776 E InstanceUploaderTask: javax.net.ssl.SSLException: Unable to create application data
04-29 12:04:33.670 24573 24776 I InstanceUploaderTask: Using Uri remap for submission 1605. Now: https://nafundi-test.appspot.com/submission
04-29 12:04:33.673 24573 24776 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_644.xml
04-29 12:04:33.674 24573 24776 I InstanceUploaderTask: Issuing POST request for 1605 to: https://nafundi-test.appspot.com/submission
04-29 12:04:33.705 24573 24776 E NativeCrypto: AppData::create pipe(2) failed: Too many open files
04-29 12:04:33.708 24573 24776 E InstanceUploaderTask: javax.net.ssl.SSLException: Unable to create application data
04-29 12:04:33.730 24573 24776 I InstanceUploaderTask: Using Uri remap for submission 1606. Now: https://nafundi-test.appspot.com/submission
04-29 12:04:33.732 24573 24776 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_645.xml
04-29 12:04:33.733 24573 24776 I InstanceUploaderTask: Issuing POST request for 1606 to: https://nafundi-test.appspot.com/submission
04-29 12:04:33.764 24573 24776 E NativeCrypto: AppData::create pipe(2) failed: Too many open files
04-29 12:04:33.766 24573 24776 E InstanceUploaderTask: javax.net.ssl.SSLException: Unable to create application data
04-29 12:04:33.785 24573 24776 I InstanceUploaderTask: Using Uri remap for submission 1607. Now: https://nafundi-test.appspot.com/submission
04-29 12:04:33.788 24573 24776 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_646.xml
04-29 12:04:33.789 24573 24776 I InstanceUploaderTask: Issuing POST request for 1607 to: https://nafundi-test.appspot.com/submission
04-29 12:04:33.819 24573 24776 E NativeCrypto: AppData::create pipe(2) failed: Too many open files
04-29 12:04:33.821 24573 24776 E InstanceUploaderTask: javax.net.ssl.SSLException: Unable to create application data
04-29 12:04:33.841 24573 24776 I InstanceUploaderTask: Using Uri remap for submission 1608. Now: https://nafundi-test.appspot.com/submission
04-29 12:04:33.844 24573 24776 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_647.xml
04-29 12:04:33.845 24573 24776 I InstanceUploaderTask: Issuing POST request for 1608 to: https://nafundi-test.appspot.com/submission
04-29 12:04:33.875 24573 24776 E NativeCrypto: AppData::create pipe(2) failed: Too many open files
04-29 12:04:33.877 24573 24776 E InstanceUploaderTask: javax.net.ssl.SSLException: Unable to create application data
04-29 12:04:33.900 24573 24776 I InstanceUploaderTask: Using Uri remap for submission 1609. Now: https://nafundi-test.appspot.com/submission
04-29 12:04:33.904 24573 24776 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_648.xml
04-29 12:04:33.905 24573 24776 I InstanceUploaderTask: Issuing POST request for 1609 to: https://nafundi-test.appspot.com/submission
04-29 12:04:33.936 24573 24776 E NativeCrypto: AppData::create pipe(2) failed: Too many open files
04-29 12:04:33.939 24573 24776 E InstanceUploaderTask: javax.net.ssl.SSLException: Unable to create application data
04-29 12:04:33.956 24573 24776 I InstanceUploaderTask: Using Uri remap for submission 1610. Now: https://nafundi-test.appspot.com/submission
04-29 12:04:33.961 24573 24776 I InstanceUploaderTask: added xml_submission_file: basic_2017-03-06_10-39-48_649.xml
04-29 12:04:33.962 24573 24776 I InstanceUploaderTask: Issuing POST request for 1610 to: https://nafundi-test.appspot.com/submission
04-29 12:04:33.964 24573 24573 E SQLiteLog: (14) cannot open file at line 32504 of [bda77dda96]
04-29 12:04:33.964 24573 24573 E SQLiteLog: (14) os_unix.c:32504: (24) open(/storage/emulated/0/odk/metadata/instances.db-journal) -
04-29 12:04:33.964 24573 24573 E SQLiteLog: (14) cannot open file at line 32504 of [bda77dda96]
04-29 12:04:33.964 24573 24573 E SQLiteLog: (14) os_unix.c:32504: (24) open(/storage/emulated/0/odk/metadata/instances.db-journal) -
04-29 12:04:33.964 24573 24573 E SQLiteLog: (14) statement aborts at 39: [SELECT canEditWhenComplete, deletedDate, status, jrVersion, jrFormId, instanceFilePath, date, submissionUri, displayName, _id, displaySubtext FROM instances WHERE (status =? ) ORDER BY
04-29 12:04:33.965 24573 24573 E SQLiteQuery: exception: unable to open database file (code 14); query: SELECT canEditWhenComplete, deletedDate, status, jrVersion, jrFormId, instanceFilePath, date, submissionUri, displayName, _id, displaySubtext FROM instances WHERE (status =? ) ORDER BY displayName ASC
04-29 12:04:33.965 24573 24573 D AndroidRuntime: Shutting down VM
04-29 12:04:33.969 24573 24573 E AndroidRuntime: FATAL EXCEPTION: main
04-29 12:04:33.969 24573 24573 E AndroidRuntime: Process: org.odk.collect.android, PID: 24573
04-29 12:04:33.969 24573 24573 E AndroidRuntime: android.database.sqlite.SQLiteCantOpenDatabaseException: unable to open database file (code 14)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at android.database.sqlite.SQLiteConnection.nativeExecuteForCursorWindow(Native Method)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at android.database.sqlite.SQLiteConnection.executeForCursorWindow(SQLiteConnection.java:845)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at android.database.sqlite.SQLiteSession.executeForCursorWindow(SQLiteSession.java:836)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at android.database.sqlite.SQLiteQuery.fillWindow(SQLiteQuery.java:62)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at android.database.sqlite.SQLiteCursor.fillWindow(SQLiteCursor.java:143)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at android.database.sqlite.SQLiteCursor.getCount(SQLiteCursor.java:132)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at android.database.CursorWrapper.getCount(CursorWrapper.java:60)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at org.odk.collect.android.activities.MainMenuActivity.updateButtons(MainMenuActivity.java:597)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at org.odk.collect.android.activities.MainMenuActivity.access$100(MainMenuActivity.java:75)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at org.odk.collect.android.activities.MainMenuActivity$IncomingHandler.handleMessage(MainMenuActivity.java:694)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at android.os.Handler.dispatchMessage(Handler.java:102)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at android.os.Looper.loop(Looper.java:154)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at android.app.ActivityThread.main(ActivityThread.java:6123)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at java.lang.reflect.Method.invoke(Native Method)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:867)
04-29 12:04:33.969 24573 24573 E AndroidRuntime:    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:757)
04-29 12:04:34.004  4057  9926 W ActivityManager:   Force finishing activity org.odk.collect.android/.activities.InstanceUploaderActivity
04-29 12:04:34.026  4057  4384 I WindowManager: window type TYPE_AOD_DREAM:
04-29 12:04:34.028 24573 24573 I Process : Sending signal. PID: 24573 SIG: 9
04-29 12:04:34.080  4057  6127 W InputDispatcher: channel '983ada0 org.odk.collect.android/org.odk.collect.android.activities.InstanceUploaderActivity (server)' ~ Consumer closed input channel or an error occurred.  events=0x9
04-29 12:04:34.080  4057  6127 E InputDispatcher: channel '983ada0 org.odk.collect.android/org.odk.collect.android.activities.InstanceUploaderActivity (server)' ~ Channel is unrecoverably broken and will be disposed!
04-29 12:04:34.081  4057  6127 W InputDispatcher: channel '5de5d2 Sending Form (server)' ~ Consumer closed input channel or an error occurred.  events=0x9
04-29 12:04:34.081  4057  6127 E InputDispatcher: channel '5de5d2 Sending Form (server)' ~ Channel is unrecoverably broken and will be disposed!
04-29 12:04:34.081  4057  6127 W InputDispatcher: channel '621bfe5 org.odk.collect.android/org.odk.collect.android.activities.InstanceUploaderList (server)' ~ Consumer closed input channel or an error occurred.  events=0x9
04-29 12:04:34.081  4057  6127 E InputDispatcher: channel '621bfe5 org.odk.collect.android/org.odk.collect.android.activities.InstanceUploaderList (server)' ~ Channel is unrecoverably broken and will be disposed!
04-29 12:04:34.081  4057  6127 W InputDispatcher: channel '536c3ac org.odk.collect.android/org.odk.collect.android.activities.MainMenuActivity (server)' ~ Consumer closed input channel or an error occurred.  events=0x9
04-29 12:04:34.081  4057  6127 E InputDispatcher: channel '536c3ac org.odk.collect.android/org.odk.collect.android.activities.MainMenuActivity (server)' ~ Channel is unrecoverably broken and will be disposed!
04-29 12:04:34.084  4057 10945 I WindowManager: WIN DEATH: Window{983ada0 u0 org.odk.collect.android/org.odk.collect.android.activities.InstanceUploaderActivity}
04-29 12:04:34.085  4057 10945 W InputDispatcher: Attempted to unregister already unregistered input channel '983ada0 org.odk.collect.android/org.odk.collect.android.activities.InstanceUploaderActivity (server)'
04-29 12:04:34.085  4057  7167 D GraphicsStats: Buffer count: 9
04-29 12:04:34.086  4057 10716 I ActivityManager: Process org.odk.collect.android (pid 24573) has died
04-29 12:04:34.086  4057 10716 D ActivityManager: cleanUpApplicationRecord -- 24573

[getodk-bot]

Hello @nribeka, you have been unassigned from this issue because you have not updated this issue or any referenced pull requests for over 10 days.

You can reclaim this issue or claim any other issue by commenting @opendatakit-bot claim on that issue.

Thanks for your contributions, and hope to see you again soon!

[grzesiek2010]

It's the same issue: https://github.com/opendatakit/collect/issues/2626