Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

ParseFile uploads multiple times #1178

Open
4 tasks done
alexandersokol opened this issue Aug 11, 2022 · 2 comments
Open
4 tasks done

ParseFile uploads multiple times #1178

alexandersokol opened this issue Aug 11, 2022 · 2 comments
Labels
type:bug Impaired feature or lacking behavior that is likely assumed

Comments

@alexandersokol
Copy link

New Issue Checklist

Issue Description

Hello! I faced an issue when attached to an object file is uploaded several times.
Previously users reported an issue that some of them have an "infinite uploading spinner" on the screen. We decided to add progress and found this problem.

We have the following structure of the objects:

Video:

videoFile : ParseFile
Image:

thumbnailFile : ParseFile
originFile : ParseFile

So to get the uploading progress the idea was to upload files first and calculate the average by taking the progress data callback of each file.

The code:

suspend fun createVideo(previewImage: ImageResource, videoResource: VideoResource, callback: (Int) -> (Unit)): Video {
        var progress = 0

        val previewFile = previewImage.parseFile {
            progress += it
            callback(progress / 2)
            Timber.v("[INV] MediaRepository:createVideo:234 - PREVIEW PROGRESS $it")
        }
        Timber.d("[INV] MediaRepository:createVideo:237 - Preview uploaded")

        val videoFile = videoResource.parseFile {
            progress += it
            callback(progress / 2)
            Timber.v("[INV] MediaRepository:createVideo:239 - VIDEO PROGRESS $it")
        }
        Timber.d("[INV] MediaRepository:createVideo:244 - Video Uploaded")

        val video = ParseObject.create(Video::class.java)
        Timber.d("[INV] MediaRepository:createVideo:247 - Video object created")
        video.previewImage = ParseObject.create(Image::class.java).apply {
            thumbnailFile = previewFile
            originalFile = thumbnailFile
            Timber.d("[INV] MediaRepository:createVideo:251 - image object created")
        }
        Timber.d("[INV] MediaRepository:createVideo:253 - Image object linked")
        video.originalFile = videoFile
        Timber.d("[INV] MediaRepository:createVideo:254 - Video file linked")
        video.suspendSave()
        Timber.d("[INV] MediaRepository:createVideo:257 - Video object saved")
        return video
    }

For the previewFile & videoFile progress should be in the range [0..200] so the progress value should be [0..100], but it is out of range (see logs below)

    private suspend fun ImageResource.parseFile(callback: (Int) -> (Unit)): ParseFile = parseFile(uri, mimeType, callback)

    private suspend fun VideoResource.parseFile(callback: (Int) -> (Unit)): ParseFile = parseFile(uri, mimeType, callback)

    private suspend fun parseFile(uri: Uri, mimeType: MimeType, callback: (Int) -> (Unit)): ParseFile {
        val file = context.getAsFile(uri, mimeType)
        Timber.w("[INV] MediaRepository:parseFile:291 - FILE SIZE: ${file.length()} bytes")
        val parseFile = ParseFile(file, mimeType.type)
        parseFile.suspendSave(callback)
        return parseFile
    }

The suspendSave extension is pretty much the same that ParseSDK-ktx uses but with a callback

suspend fun ParseFile.suspendSave(callback: (suspend (Int) -> (Unit))) {
    return suspendCoroutine { continuation ->
        saveInBackground({
            if (it == null) {
                Timber.i("[INV] ParseFile:suspendSave:35 - file saved ${this.file}")
                continuation.resume(Unit)
            } else continuation.resumeWithException(it)
        }) { runBlocking { callback(it) } }
    }
}

Pretty sure that callbacks are not the best option for the coroutine suspend functions, but I believe that is has no effect on this issue.

    suspend fun removeVideo(videoId: String) {
        val video = getVideo(videoId)
        video.previewImage?.suspendDelete()
        video.suspendDelete()
    }

suspend fun ParseObject.suspendDelete() {
    return suspendCoroutine { continuation ->
        deleteInBackground {
            if (it == null) continuation.resume(Unit)
            else continuation.resumeWithException(it)
        }
    }
}

Steps to reproduce

Create ParseFile and save it with a progress callback, put the saved file into a new ParseObject, and save the object. It isn't reproducing on the object that doesn't have nested ParseObjects inside like Image and mostly with files larger than 20MB.
It isn't reproducing with a 100% chance, once it can happen when uploading is the first action user does and in another case (more frequently) when a user removes the video object before uploading (references, file paths of a new and an old object are different).

Actual Outcome

ParseFile uploads several times.

Expected Outcome

ParseFile uploads once, calling save() on an object doesn't trigger uploading files again.

Environment

AGP: 7.2.1
kotlin: 1.7.10
coroutines: 1.6.3

Parse Android SDK

  • SDK version: 4.0.0
  • Operating system version: 12

Server

  • Parse Server version: 4.2.0
  • Operating system: no info
  • Local or remote host (AWS, Azure, Google Cloud, Heroku, Digital Ocean, etc): no info

Database

  • System (MongoDB or Postgres): no info
  • Database version: no info
  • Local or remote host (MongoDB Atlas, mLab, AWS, Azure, Google Cloud, etc): no info

Logs

total progress output:

D: [INV] NoteViewModel:onVideoAdded:631 - video progress: 1567773
D: [INV] NoteViewModel:onVideoAdded:631 - video progress: 1567822
D: [INV] NoteViewModel:onVideoAdded:631 - video progress: 1567872
D: [INV] NoteViewModel:onVideoAdded:631 - video progress: 1567921
D: [INV] NoteViewModel:onVideoAdded:631 - video progress: 1567971
D: [INV] NoteViewModel:onVideoAdded:631 - video progress: 1568020
D: [INV] NoteViewModel:onVideoAdded:631 - video progress: 1568070
D: [INV] NoteViewModel:onVideoAdded:631 - video progress: 1568119
D: [INV] NoteViewModel:onVideoAdded:631 - video progress: 1568169
D: [INV] NoteViewModel:onVideoAdded:631 - video progress: 1568219

Files uploading log:

08-11 20:44:01.349 17817 17892 W MediaRepository: [INV] MediaRepository:parseFile:291 - FILE SIZE: 336288 bytes
08-11 20:44:01.353 17817 17817 V MediaRepository$createVideo$previewFile: [INV] MediaRepository:createVideo:234 - PREVIEW PROGRESS 1
......
08-11 20:44:01.368 17817 17817 V MediaRepository$createVideo$previewFile: [INV] MediaRepository:createVideo:234 - PREVIEW PROGRESS 100
08-11 20:44:02.760 17817 17817 I ParseObjectExtensionsKt$suspendSave: [INV] ParseFile:suspendSave:35 - file saved /data/user/0/com.awesome.beta/cache/com.parse/files/09fde51bf74480e2545c8cc43f804449_ed11cf82-8df8-4f80-910e-18b4f182fcf6.png
08-11 20:44:02.760 17817 17892 D MediaRepository: [INV] MediaRepository:createVideo:237 - Preview uploaded
08-11 20:44:02.956 17817 17892 W MediaRepository: [INV] MediaRepository:parseFile:291 - FILE SIZE: 86386876 bytes
08-11 20:44:02.960 17817 17817 V MediaRepository$createVideo$videoFile: [INV] MediaRepository:createVideo:239 - VIDEO PROGRESS 0
......
08-11 20:44:24.729 17817 17817 V MediaRepository$createVideo$videoFile: [INV] MediaRepository:createVideo:239 - VIDEO PROGRESS 100

// Problem begins here, it starts uploading file one more time
08-11 20:44:36.955 17817 17817 V MediaRepository$createVideo$videoFile: [INV] MediaRepository:createVideo:239 - VIDEO PROGRESS 0
......
08-11 20:44:50.728 17817 17817 V MediaRepository$createVideo$videoFile: [INV] MediaRepository:createVideo:239 - VIDEO PROGRESS 100
08-11 20:45:04.050 17817 17817 V MediaRepository$createVideo$videoFile: [INV] MediaRepository:createVideo:239 - VIDEO PROGRESS 0
......
08-11 20:45:32.422 17817 17817 V MediaRepository$createVideo$videoFile: [INV] MediaRepository:createVideo:239 - VIDEO PROGRESS 100
08-11 20:45:42.383 17817 17817 I ParseObjectExtensionsKt$suspendSave: [INV] ParseFile:suspendSave:35 - file saved /data/user/0/com.awesome.beta/cache/com.parse/files/c85623fa132bbeb6aee73d450f8fd980_8b324a8e-4e94-47e0-8144-56b8a5b9a249.mp4
08-11 20:45:42.383 17817 17892 D MediaRepository: [INV] MediaRepository:createVideo:244 - Video Uploaded
08-11 20:45:42.384 17817 17892 D MediaRepository: [INV] MediaRepository:createVideo:247 - Video object created
08-11 20:45:42.384 17817 17892 D MediaRepository: [INV] MediaRepository:createVideo:251 - image object created
08-11 20:45:42.384 17817 17892 D MediaRepository: [INV] MediaRepository:createVideo:253 - Image object linked
08-11 20:45:42.384 17817 17892 D MediaRepository: [INV] MediaRepository:createVideo:254 - Video file linked
08-11 20:45:42.724 17817 17892 D MediaRepository: [INV] MediaRepository:createVideo:257 - Video object saved
@parse-github-assistant
Copy link

Thanks for opening this issue!

  • 🚀 You can help us to fix this issue faster by opening a pull request with a failing test. See our Contribution Guide for how to make a pull request, or read our New Contributor's Guide if this is your first time contributing.

@alexandersokol
Copy link
Author

UPD:
Add some logs to the parse client and found out that I'm receiving socketTimeout Exception exactly at the moment when file uploading progress reaches 100%.

adding huge write timeout has no effect

val client = OkHttpClient.Builder()
            .writeTimeout(5, TimeUnit.MINUTES)

08-11 22:27:36.678 23442 24003 E PARSE   : java.net.SocketTimeoutException: timeout
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okio.SocketAsyncTimeout.newTimeoutException(JvmOkio.kt:143)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okio.AsyncTimeout.access$newTimeoutException(AsyncTimeout.kt:162)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okio.AsyncTimeout$source$1.read(AsyncTimeout.kt:335)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okio.RealBufferedSource.indexOf(RealBufferedSource.kt:427)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okio.RealBufferedSource.readUtf8LineStrict(RealBufferedSource.kt:320)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.http1.HeadersReader.readLine(HeadersReader.kt:29)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.http1.Http1ExchangeCodec.readResponseHeaders(Http1ExchangeCodec.kt:178)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.connection.Exchange.readResponseHeaders(Exchange.kt:106)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.kt:79)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:34)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.ParsePlugins.lambda$restClient$0$com-parse-ParsePlugins(ParsePlugins.java:156)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.ParsePlugins$$ExternalSyntheticLambda0.intercept(Unknown Source:2)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okhttp3.internal.connection.RealCall.execute(RealCall.kt:154)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.ParseHttpClient.executeInternal(ParseHttpClient.java:66)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.ParseHttpClient.execute(ParseHttpClient.java:52)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.ParseRequest.lambda$sendOneRequestAsync$0$com-parse-ParseRequest(ParseRequest.java:148)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.ParseRequest$$ExternalSyntheticLambda1.then(Unknown Source:8)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.boltsinternal.Task.lambda$completeAfterTask$9(Task.java:500)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.boltsinternal.Task$$ExternalSyntheticLambda2.run(Unknown Source:8)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.boltsinternal.BoltsExecutors$ImmediateExecutor.execute(BoltsExecutors.java:109)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.boltsinternal.Task.completeAfterTask(Task.java:492)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.boltsinternal.Task.continueWithTask(Task.java:775)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.boltsinternal.Task.continueWithTask(Task.java:786)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.boltsinternal.Task.lambda$onSuccessTask$15(Task.java:879)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.boltsinternal.Task$$ExternalSyntheticLambda7.then(Unknown Source:4)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.boltsinternal.Task.lambda$completeAfterTask$9(Task.java:500)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.parse.boltsinternal.Task$$ExternalSyntheticLambda2.run(Unknown Source:8)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at java.lang.Thread.run(Thread.java:920)
08-11 22:27:36.678 23442 24003 E PARSE   : Caused by: java.net.SocketException: Socket closed
08-11 22:27:36.678 23442 24003 E PARSE   : 	at java.net.SocketInputStream.read(SocketInputStream.java:209)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at java.net.SocketInputStream.read(SocketInputStream.java:144)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.android.org.conscrypt.ConscryptEngineSocket$SSLInputStream.readFromSocket(ConscryptEngineSocket.java:945)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.android.org.conscrypt.ConscryptEngineSocket$SSLInputStream.processDataFromSocket(ConscryptEngineSocket.java:909)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.android.org.conscrypt.ConscryptEngineSocket$SSLInputStream.readUntilDataAvailable(ConscryptEngineSocket.java:824)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at com.android.org.conscrypt.ConscryptEngineSocket$SSLInputStream.read(ConscryptEngineSocket.java:797)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okio.InputStreamSource.read(JvmOkio.kt:90)
08-11 22:27:36.678 23442 24003 E PARSE   : 	at okio.AsyncTimeout$source$1.read(AsyncTimeout.kt:129)
08-11 22:27:36.678 23442 24003 E PARSE   : 	... 37 more

@mtrezza mtrezza added the type:bug Impaired feature or lacking behavior that is likely assumed label Aug 25, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
type:bug Impaired feature or lacking behavior that is likely assumed
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@alexandersokol @mtrezza