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.

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

SocketTimeoutException from fetching number of images deleted #1876

Closed
misaochan opened this issue Sep 3, 2018 · 10 comments
Closed

SocketTimeoutException from fetching number of images deleted #1876

misaochan opened this issue Sep 3, 2018 · 10 comments

Comments

@misaochan
Copy link
Member

misaochan commented Sep 3, 2018

Summary:

I logged in to Misaochan, went to Nearby, and the app crashed for me while I was searching for an image to upload to Nearby. Stack trace seems to point to getRevertRespObjectSingle() in ApacheHttpClientMediaWikiApi

Steps to reproduce:

Unsure of how to reproduce, it is not consistent. However, we should handle this exception more gracefully. I think catching it and outputting an error message is sufficient since that method is not essential (it's just used to get user revert rate). [Edit: After looking into it further, this is NOT true - this function is called whenever the user loads ContributionsActivity, and it is nonNull.]

Add System logs:

09-03 19:16:22.913 27648-27648/fr.free.nrw.commons W/System.err: Caused by: java.net.SocketTimeoutException: timeout
        at okhttp3.internal.http2.Http2Stream$StreamTimeout.newTimeoutException(Http2Stream.java:593)
        at okhttp3.internal.http2.Http2Stream$StreamTimeout.exitAndThrowIfTimedOut(Http2Stream.java:601)
09-03 19:16:22.914 27648-27648/fr.free.nrw.commons W/System.err:     at okhttp3.internal.http2.Http2Stream.takeResponseHeaders(Http2Stream.java:146)
        at okhttp3.internal.http2.Http2Codec.readResponseHeaders(Http2Codec.java:125)
        at okhttp3.internal.http.CallServerInterceptor.intercept(CallServerInterceptor.java:88)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
09-03 19:16:22.915 27648-27648/fr.free.nrw.commons W/System.err:     at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.java:45)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
09-03 19:16:22.916 27648-27648/fr.free.nrw.commons W/System.err:     at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.java:93)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
        at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.java:93)
09-03 19:16:22.917 27648-27648/fr.free.nrw.commons W/System.err:     at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.java:126)
09-03 19:16:22.918 27648-27648/fr.free.nrw.commons W/System.err:     at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:147)
        at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.java:121)
        at okhttp3.RealCall.getResponseWithInterceptorChain(RealCall.java:200)
        at okhttp3.RealCall.execute(RealCall.java:77)
09-03 19:16:22.919 27648-27648/fr.free.nrw.commons W/System.err:     at fr.free.nrw.commons.mwapi.ApacheHttpClientMediaWikiApi.lambda$getRevertRespObjectSingle$5$ApacheHttpClientMediaWikiApi(ApacheHttpClientMediaWikiApi.java:1018)
        at fr.free.nrw.commons.mwapi.ApacheHttpClientMediaWikiApi$$Lambda$9.call(Unknown Source:4)
        at io.reactivex.internal.operators.single.SingleFromCallable.subscribeActual(SingleFromCallable.java:35)
09-03 19:16:22.920 27648-27648/fr.free.nrw.commons W/System.err:     at io.reactivex.Single.subscribe(Single.java:2700)
        at com.tspoon.traceur.SingleOnAssembly.subscribeActual(SingleOnAssembly.java:43)
        at io.reactivex.Single.subscribe(Single.java:2700)
        at io.reactivex.internal.operators.single.SingleSubscribeOn$SubscribeOnObserver.run(SingleSubscribeOn.java:89)
09-03 19:16:22.921 27648-27648/fr.free.nrw.commons W/System.err:     at io.reactivex.Scheduler$DisposeTask.run(Scheduler.java:452)
        at io.reactivex.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:61)
09-03 19:16:22.922 27648-27648/fr.free.nrw.commons W/System.err:     at io.reactivex.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:52)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:301)
09-03 19:16:22.923 27648-27648/fr.free.nrw.commons W/System.err:     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
        at java.lang.Thread.run(Thread.java:764)
09-03 19:16:22.924 27648-27648/fr.free.nrw.commons W/System.err: Caused by: com.tspoon.traceur.TraceurException: Debug Exception generated at call site
        at dalvik.system.VMStack.getThreadStackTrace(Native Method)
        at java.lang.Thread.getStackTrace(Thread.java:1536)
        at io.reactivex.Single.fromCallable(Single.java:448)
09-03 19:16:22.925 27648-27648/fr.free.nrw.commons W/System.err:     at fr.free.nrw.commons.mwapi.ApacheHttpClientMediaWikiApi.getRevertRespObjectSingle(ApacheHttpClientMediaWikiApi.java:1005)
        at fr.free.nrw.commons.quiz.QuizChecker.setRevertCount(QuizChecker.java:92)
        at fr.free.nrw.commons.quiz.QuizChecker.<init>(QuizChecker.java:55)
09-03 19:16:22.926 27648-27648/fr.free.nrw.commons W/System.err:     at fr.free.nrw.commons.contributions.ContributionsActivity.onCreate(ContributionsActivity.java:152)
        at android.app.Activity.performCreate(Activity.java:7174)
        at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1220)
09-03 19:16:22.927 27648-27648/fr.free.nrw.commons W/System.err:     at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:2910)
        at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:3032)
        at android.app.ActivityThread.-wrap11(Unknown Source:0)
        at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1696)
09-03 19:16:22.928 27648-27648/fr.free.nrw.commons W/System.err:     at android.os.Handler.dispatchMessage(Handler.java:105)
        at android.os.Looper.loop(Looper.java:164)
        at android.app.ActivityThread.main(ActivityThread.java:6944)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.Zygote$MethodAndArgsCaller.run(Zygote.java:327)
09-03 19:16:22.929 27648-27648/fr.free.nrw.commons W/System.err:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1374)
09-03 19:16:22.930 27648-27648/fr.free.nrw.commons W/System.err: Caused by: com.tspoon.traceur.TraceurException: Debug Exception generated at call site
        at dalvik.system.VMStack.getThreadStackTrace(Native Method)
        at java.lang.Thread.getStackTrace(Thread.java:1536)
09-03 19:16:22.931 27648-27648/fr.free.nrw.commons W/System.err:     at io.reactivex.Single.subscribeOn(Single.java:2768)
        at fr.free.nrw.commons.quiz.QuizChecker.setRevertCount(QuizChecker.java:93)
09-03 19:16:22.932 27648-27648/fr.free.nrw.commons W/System.err: 	... 14 more
    Caused by: com.tspoon.traceur.TraceurException: Debug Exception generated at call site
09-03 19:16:22.933 27648-27648/fr.free.nrw.commons W/System.err:     at dalvik.system.VMStack.getThreadStackTrace(Native Method)
        at java.lang.Thread.getStackTrace(Thread.java:1536)
        at io.reactivex.Single.observeOn(Single.java:2296)
        at fr.free.nrw.commons.quiz.QuizChecker.setRevertCount(QuizChecker.java:94)
09-03 19:16:22.934 27648-27648/fr.free.nrw.commons W/System.err: 	... 14 more
09-03 19:16:22.946 3646-8649/? W/ActivityManager: crash : fr.free.nrw.commons,0
09-03 19:16:22.948 3646-8649/? W/ActivityManager:   Force finishing activity fr.free.nrw.commons/.nearby.NearbyActivity

Device and Android version:

Android 8.0 Samsung Galaxy s7

Commons app version:

#1875 which is based on 2.8-release, but the error does not appear to be relevant to that PR at all, just coincidence

Would you like to work on the issue?

Pref not

@misaochan
Copy link
Member Author

misaochan commented Sep 4, 2018

Ugh, I just checked our Google Play stats and this appears to be a major cause of crashes - 60+ reports in the last 7 days. Unfortunately it seems that if we don't have time to find an ideal solution, we will have to remove the quiz checker in 2.8.3 and reinstate it once an ideal solution is found.

Full stacktrace:

Report 1

io.reactivex.exceptions.OnErrorNotImplementedException: 
  at io.reactivex.internal.functions.Functions$OnErrorMissingConsumer.accept (Functions.java:704)
  at io.reactivex.internal.functions.Functions$OnErrorMissingConsumer.accept (Functions.java:701)
  at io.reactivex.internal.observers.ConsumerSingleObserver.onError (ConsumerSingleObserver.java:45)
  at com.tspoon.traceur.SingleOnAssembly$OnAssemblySingleObserver.onError (SingleOnAssembly.java:75)
  at io.reactivex.internal.operators.single.SingleObserveOn$ObserveOnSingleObserver.run (SingleObserveOn.java:79)
  at io.reactivex.android.schedulers.HandlerScheduler$ScheduledRunnable.run (HandlerScheduler.java:109)
  at android.os.Handler.handleCallback (Handler.java:754)
  at android.os.Handler.dispatchMessage (Handler.java:95)
  at android.os.Looper.loop (Looper.java:163)
  at android.app.ActivityThread.main (ActivityThread.java:6228)
  at java.lang.reflect.Method.invoke (Native Method)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run (ZygoteInit.java:904)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:794)
Caused by: java.net.UnknownHostException: 
  at java.net.Inet6AddressImpl.lookupHostByName (Inet6AddressImpl.java:95)
  at java.net.Inet6AddressImpl.lookupAllHostAddr (Inet6AddressImpl.java:74)
  at java.net.InetAddress.getAllByName (InetAddress.java:752)
  at okhttp3.Dns$1.lookup (Dns.java:40)
  at okhttp3.internal.connection.RouteSelector.resetNextInetSocketAddress (RouteSelector.java:185)
  at okhttp3.internal.connection.RouteSelector.nextProxy (RouteSelector.java:149)
  at okhttp3.internal.connection.RouteSelector.next (RouteSelector.java:84)
  at okhttp3.internal.connection.StreamAllocation.findConnection (StreamAllocation.java:214)
  at okhttp3.internal.connection.StreamAllocation.findHealthyConnection (StreamAllocation.java:135)
  at okhttp3.internal.connection.StreamAllocation.newStream (StreamAllocation.java:114)
  at okhttp3.internal.connection.ConnectInterceptor.intercept (ConnectInterceptor.java:42)
  at okhttp3.internal.http.RealInterceptorChain.proceed (RealInterceptorChain.java:147)
  at okhttp3.internal.http.RealInterceptorChain.proceed (RealInterceptorChain.java:121)
  at okhttp3.internal.cache.CacheInterceptor.intercept (CacheInterceptor.java:93)
  at okhttp3.internal.http.RealInterceptorChain.proceed (RealInterceptorChain.java:147)
  at okhttp3.internal.http.RealInterceptorChain.proceed (RealInterceptorChain.java:121)
  at okhttp3.internal.http.BridgeInterceptor.intercept (BridgeInterceptor.java:93)
  at okhttp3.internal.http.RealInterceptorChain.proceed (RealInterceptorChain.java:147)
  at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept (RetryAndFollowUpInterceptor.java:126)
  at okhttp3.internal.http.RealInterceptorChain.proceed (RealInterceptorChain.java:147)
  at okhttp3.internal.http.RealInterceptorChain.proceed (RealInterceptorChain.java:121)
  at okhttp3.RealCall.getResponseWithInterceptorChain (RealCall.java:200)
  at okhttp3.RealCall.execute (RealCall.java:77)
  at fr.free.nrw.commons.mwapi.ApacheHttpClientMediaWikiApi.lambda$getRevertRespObjectSingle$5$ApacheHttpClientMediaWikiApi (ApacheHttpClientMediaWikiApi.java:1009)
  at fr.free.nrw.commons.mwapi.ApacheHttpClientMediaWikiApi$$Lambda$9.call (Unknown Source)
  at io.reactivex.internal.operators.single.SingleFromCallable.subscribeActual (SingleFromCallable.java:35)
  at io.reactivex.Single.subscribe (Single.java:2700)
  at com.tspoon.traceur.SingleOnAssembly.subscribeActual (SingleOnAssembly.java:43)
  at io.reactivex.Single.subscribe (Single.java:2700)
  at io.reactivex.internal.operators.single.SingleSubscribeOn$SubscribeOnObserver.run (SingleSubscribeOn.java:89)
  at io.reactivex.Scheduler$DisposeTask.run (Scheduler.java:452)
  at io.reactivex.internal.schedulers.ScheduledRunnable.run (ScheduledRunnable.java:61)
  at io.reactivex.internal.schedulers.ScheduledRunnable.call (ScheduledRunnable.java:52)
  at java.util.concurrent.FutureTask.run (FutureTask.java:237)
  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run (ScheduledThreadPoolExecutor.java:272)
  at java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1133)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:607)
  at java.lang.Thread.run (Thread.java:760)
Caused by: com.tspoon.traceur.TraceurException: 
  at dalvik.system.VMStack.getThreadStackTrace (Native Method)
  at java.lang.Thread.getStackTrace (Thread.java:1565)
  at io.reactivex.Single.fromCallable (Single.java:448)
  at fr.free.nrw.commons.mwapi.ApacheHttpClientMediaWikiApi.getRevertRespObjectSingle (ApacheHttpClientMediaWikiApi.java:996)
  at fr.free.nrw.commons.quiz.QuizChecker.setRevertCount (QuizChecker.java:92)
  at fr.free.nrw.commons.quiz.QuizChecker.<init> (QuizChecker.java:55)
  at fr.free.nrw.commons.contributions.ContributionsActivity.onCreate (ContributionsActivity.java:152)
  at android.app.Activity.performCreate (Activity.java:6860)
  at android.app.Instrumentation.callActivityOnCreate (Instrumentation.java:1119)
  at android.app.ActivityThread.performLaunchActivity (ActivityThread.java:2674)
  at android.app.ActivityThread.handleLaunchActivity (ActivityThread.java:2782)
  at android.app.ActivityThread.-wrap12 (ActivityThread.java)
  at android.app.ActivityThread$H.handleMessage (ActivityThread.java:1521)
  at android.os.Handler.dispatchMessage (Handler.java:102)
  at android.os.Looper.loop (Looper.java:163)
  at android.app.ActivityThread.main (ActivityThread.java:6228)
  at java.lang.reflect.Method.invoke (Native Method)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run (ZygoteInit.java:904)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:794)
Caused by: com.tspoon.traceur.TraceurException: 
  at dalvik.system.VMStack.getThreadStackTrace (Native Method)
  at java.lang.Thread.getStackTrace (Thread.java:1565)
  at io.reactivex.Single.subscribeOn (Single.java:2768)
  at fr.free.nrw.commons.quiz.QuizChecker.setRevertCount (QuizChecker.java:93)
Caused by: com.tspoon.traceur.TraceurException: 
  at dalvik.system.VMStack.getThreadStackTrace (Native Method)
  at java.lang.Thread.getStackTrace (Thread.java:1565)
  at io.reactivex.Single.observeOn (Single.java:2296)
  at fr.free.nrw.commons.quiz.QuizChecker.setRevertCount (QuizChecker.java:94)

@nicolas-raoul
Copy link
Member

How catching the exception and such cases considering that the quiz is not needed (which is the less intrusive option)?

@misaochan
Copy link
Member Author

@nicolas-raoul The main problem with doing that is, what do we return as the value of Single<JSONObject> getRevertRespObjectSingle() in the case of client.newCall(request).execute(); timing out? The function is @NonNull so it will not be as simple as returning null. Certainly still doable but would take more time and going through more of the code.

@misaochan
Copy link
Member Author

I created a PR. If anyone wants to take this up and fix the crash properly (please bear in mind that you cannot just ignore the timeout or return null), please feel free. We can re-release the quiz as soon as it is fixed.

@neslihanturan
Copy link
Collaborator

neslihanturan commented Sep 4, 2018

@misaochan I have read the comments and your PR but, couldn't understand why we cannot just catch the exception and cancel quiz if caught. Can you please explain in more detail?

@ashishkumar468
Copy link
Collaborator

ashishkumar468 commented Sep 4, 2018

@misaochan I had the same doubt as @neslihanturan. Why cant we just handle the exception and delegate the flow accordingly, ie. log the exception for reference purposes and maybe set isRevertCountFetched=false [Just to stay safe] ensuring that callQuiz() is never called. Is there something I am missing ?

@maskaravivek
Copy link
Member

I have added a PR refactoring some of the error-prone code pieces. Will take a final look at these modules tomorrow and makes any changes if necessary. The basic flow works well.

PS: Personally I was feeling bad about reverting some of @tanvidadu's changes so I decided to pitch in. :)

@misaochan
Copy link
Member Author

misaochan commented Sep 5, 2018

@neslihanturan @maskaravivek @neslihanturan My main concern is that we really need to get this fix out ASAP (i.e. by Thursday) due to the 12% crash rate for users. I didn't have the time to spend a few hours going over the code, and I didn't want to pressure anyone else to work overtime to fix it. ;)

However, if you guys are willing to put in the time to ensure that this fix is done (and thoroughly tested) so that we can release 2.8.3 by Thursday at the latest, we can definitely push the proper fix instead of the stopgap measure. Unfortunately I will be travelling most of next week, and unable to push any fixes then. We need to give it a bit of a buffer because we need people to test the beta before we can push to prod.

@misaochan
Copy link
Member Author

misaochan commented Sep 6, 2018

Hmm, my Achievements are not working after #1881 was merged. I am always Level 1, and images uploaded are 0/20 despite them registering correctly on ContributionsActivity's action bar. This happens for both misaochan2 and misaochan, logging out and in again does not fix it. @maskaravivek do they work for you?

@misaochan
Copy link
Member Author

Everything should hopefully be sorted now, so will close this and reopen if needed. Thanks for volunteering to fix it @maskaravivek . :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

5 participants