search

instacart / truetime-android

Android NTP time library. Get the true current time impervious to device clock time changes
https://tech.instacart.com/truetime/
Apache License 2.0
1.41k stars 194 forks source link

requestTime error in production app #101

Open SonhnLab opened 5 years ago

SonhnLab commented 5 years ago

Hi all, this is the log I got from my production app

io.reactivex.exceptions.UndeliverableException: 
  at io.reactivex.plugins.RxJavaPlugins.onError (RxJavaPlugins.java:367)
  at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.innerError (FlowableFlatMap.java:607)
  at io.reactivex.internal.operators.flowable.FlowableFlatMap$InnerSubscriber.onError (FlowableFlatMap.java:668)
  at io.reactivex.internal.operators.flowable.FlowableRetryPredicate$RetrySubscriber.onError (FlowableRetryPredicate.java:83)
  at io.reactivex.internal.operators.flowable.FlowableDoOnEach$DoOnEachSubscriber.onError (FlowableDoOnEach.java:111)
  at io.reactivex.internal.operators.flowable.FlowableSubscribeOn$SubscribeOnSubscriber.onError (FlowableSubscribeOn.java:102)
  at io.reactivex.internal.operators.flowable.FlowableCreate$BaseEmitter.error (FlowableCreate.java:293)
  at io.reactivex.internal.operators.flowable.FlowableCreate$BufferAsyncEmitter.drain (FlowableCreate.java:541)
  at io.reactivex.internal.operators.flowable.FlowableCreate$BufferAsyncEmitter.tryOnError (FlowableCreate.java:491)
  at com.instacart.library.truetime.TrueTimeRx$4$1$2.subscribe (TrueTimeRx.java:200)
  at io.reactivex.internal.operators.flowable.FlowableCreate.subscribeActual (FlowableCreate.java:72)
  at io.reactivex.Flowable.subscribe (Flowable.java:14349)
  at io.reactivex.Flowable.subscribe (Flowable.java:14295)
  at io.reactivex.internal.operators.flowable.FlowableSubscribeOn$SubscribeOnSubscriber.run (FlowableSubscribeOn.java:82)
  at io.reactivex.internal.schedulers.ScheduledRunnable.run (ScheduledRunnable.java:66)
  at io.reactivex.internal.schedulers.ScheduledRunnable.call (ScheduledRunnable.java:57)
  at java.util.concurrent.FutureTask.run (FutureTask.java:266)
  at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run (ScheduledThreadPoolExecutor.java:301)
  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)
Caused by: java.io.IOException: 
  at libcore.io.IoBridge.maybeThrowAfterSendto (IoBridge.java:603)
  at libcore.io.IoBridge.sendto (IoBridge.java:571)
  at java.net.PlainDatagramSocketImpl.send (PlainDatagramSocketImpl.java:124)
  at java.net.DatagramSocket.send (DatagramSocket.java:721)
  at com.instacart.library.truetime.SntpClient.requestTime (SntpClient.java:116)
  at com.instacart.library.truetime.TrueTime.requestTime (TrueTime.java:122)
  at com.instacart.library.truetime.TrueTimeRx$4$1$2.subscribe (TrueTimeRx.java:197)
Caused by: android.system.ErrnoException: 
  at libcore.io.Linux.sendtoBytes (Native Method)
  at libcore.io.Linux.sendto (Linux.java:225)
  at libcore.io.BlockGuardOs.sendto (BlockGuardOs.java:304)
  at libcore.io.IoBridge.sendto (IoBridge.java:569)

I got this error many time starting from October 1st

screen shot 2018-11-02 at 2 12 45 am

Please let me know how to fix it. This is the version I'm using

implementation 'com.github.instacart.truetime-android:library-extension-rx:09087b6a6e'

private void initRxTrueTime() {
    TrueTimeRx.build()
            .withSharedPreferences(getApplicationContext())
            .initializeRx("time.google.com")
            .subscribeOn(Schedulers.io())
            .observeOn(AndroidSchedulers.mainThread())
            .subscribe(
                    date -> Log.e(this.getClass().getSimpleName(), "" + date),
                    throwable -> Log.e(this.getClass().getSimpleName(), throwable.toString())
            );
}
seth-gravy commented 5 years ago

We're getting the same error, running the latest version:

Android: 8.0.0
Manufacturer: samsung
Model: SM-G960U
Thread: RxCachedThreadScheduler-28-23505

io.reactivex.exceptions.UndeliverableException: java.io.IOException: sendto failed: EPERM (Operation not permitted)
    at io.reactivex.plugins.RxJavaPlugins.onError(RxJavaPlugins.java:367)
    at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.innerError(FlowableFlatMap.java:607)
    at io.reactivex.internal.operators.flowable.FlowableFlatMap$InnerSubscriber.onError(FlowableFlatMap.java:668)
    at io.reactivex.internal.subscribers.BasicFuseableSubscriber.onError(BasicFuseableSubscriber.java:101)
    at io.reactivex.internal.operators.flowable.FlowableToList$ToListSubscriber.onError(FlowableToList.java:81)
    at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.checkTerminate(FlowableFlatMap.java:566)
    at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drainLoop(FlowableFlatMap.java:374)
    at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drain(FlowableFlatMap.java:366)
    at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.innerError(FlowableFlatMap.java:605)
    at io.reactivex.internal.operators.flowable.FlowableFlatMap$InnerSubscriber.onError(FlowableFlatMap.java:668)
    at io.reactivex.internal.operators.flowable.FlowableRetryPredicate$RetrySubscriber.onError(FlowableRetryPredicate.java:83)
    at io.reactivex.internal.operators.flowable.FlowableDoOnEach$DoOnEachSubscriber.onError(FlowableDoOnEach.java:111)
    at io.reactivex.internal.operators.flowable.FlowableSubscribeOn$SubscribeOnSubscriber.onError(FlowableSubscribeOn.java:102)
    at io.reactivex.internal.operators.flowable.FlowableCreate$BaseEmitter.error(FlowableCreate.java:293)
    at io.reactivex.internal.operators.flowable.FlowableCreate$BufferAsyncEmitter.drain(FlowableCreate.java:541)
    at io.reactivex.internal.operators.flowable.FlowableCreate$BufferAsyncEmitter.tryOnError(FlowableCreate.java:491)
    at com.instacart.library.truetime.TrueTimeRx$4$1$2.subscribe(TrueTimeRx.java:214)
    at io.reactivex.internal.operators.flowable.FlowableCreate.subscribeActual(FlowableCreate.java:72)
    at io.reactivex.Flowable.subscribe(Flowable.java:14349)
    at io.reactivex.Flowable.subscribe(Flowable.java:14295)
    at io.reactivex.internal.operators.flowable.FlowableSubscribeOn$SubscribeOnSubscriber.run(FlowableSubscribeOn.java:82)
    at io.reactivex.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:66)
    at io.reactivex.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:57)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:301)
    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)
Caused by: java.io.IOException: sendto failed: EPERM (Operation not permitted)
    at libcore.io.IoBridge.maybeThrowAfterSendto(IoBridge.java:603)
    at libcore.io.IoBridge.sendto(IoBridge.java:571)
    at java.net.PlainDatagramSocketImpl.send(PlainDatagramSocketImpl.java:124)
    at java.net.DatagramSocket.send(DatagramSocket.java:721)
    at com.instacart.library.truetime.SntpClient.requestTime(SntpClient.java:116)
    at com.instacart.library.truetime.TrueTime.requestTime(TrueTime.java:133)
    at com.instacart.library.truetime.TrueTimeRx$4$1$2.subscribe(TrueTimeRx.java:211)
    ... 11 more
Caused by: android.system.ErrnoException: sendto failed: EPERM (Operation not permitted)
    at libcore.io.Linux.sendtoBytes(Native Method)
    at libcore.io.Linux.sendto(Linux.java:225)
    at libcore.io.BlockGuardOs.sendto(BlockGuardOs.java:304)
    at libcore.io.IoBridge.sendto(IoBridge.java:569)
    ... 16 more
yarkh commented 5 years ago

The same in production for multiple devices

screenshot 2018-11-15 at 19 19 51

io.reactivex.exceptions.UndeliverableException: 
  at io.reactivex.plugins.RxJavaPlugins.onError (RxJavaPlugins.java:367)
  at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.innerError (FlowableFlatMap.java:607)
  at io.reactivex.internal.operators.flowable.FlowableFlatMap$InnerSubscriber.onError (FlowableFlatMap.java:668)
  at io.reactivex.internal.subscribers.BasicFuseableSubscriber.onError (BasicFuseableSubscriber.java:101)
  at io.reactivex.internal.operators.flowable.FlowableToList$ToListSubscriber.onError (FlowableToList.java:81)
  at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.checkTerminate (FlowableFlatMap.java:566)
  at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drainLoop (FlowableFlatMap.java:374)
  at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.drain (FlowableFlatMap.java:366)
  at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.innerError (FlowableFlatMap.java:605)
  at io.reactivex.internal.operators.flowable.FlowableFlatMap$InnerSubscriber.onError (FlowableFlatMap.java:668)
  at io.reactivex.internal.operators.flowable.FlowableRetryPredicate$RetrySubscriber.onError (FlowableRetryPredicate.java:83)
  at io.reactivex.internal.operators.flowable.FlowableDoOnEach$DoOnEachSubscriber.onError (FlowableDoOnEach.java:111)
  at io.reactivex.internal.operators.flowable.FlowableSubscribeOn$SubscribeOnSubscriber.onError (FlowableSubscribeOn.java:102)
  at io.reactivex.internal.operators.flowable.FlowableCreate$BaseEmitter.error (FlowableCreate.java:293)
  at io.reactivex.internal.operators.flowable.FlowableCreate$BufferAsyncEmitter.drain (FlowableCreate.java:541)
  at io.reactivex.internal.operators.flowable.FlowableCreate$BufferAsyncEmitter.tryOnError (FlowableCreate.java:491)
  at com.instacart.library.truetime.TrueTimeRx$4$1$2.subscribe (TrueTimeRx.java:214)
  at io.reactivex.internal.operators.flowable.FlowableCreate.subscribeActual (FlowableCreate.java:72)
  at io.reactivex.Flowable.subscribe (Flowable.java:14349)
  at io.reactivex.Flowable.subscribe (Flowable.java:14295)
  at io.reactivex.internal.operators.flowable.FlowableSubscribeOn$SubscribeOnSubscriber.run (FlowableSubscribeOn.java:82)
  at io.reactivex.internal.schedulers.ScheduledRunnable.run (ScheduledRunnable.java:66)
  at io.reactivex.internal.schedulers.ScheduledRunnable.call (ScheduledRunnable.java:57)
  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:761)
Caused by: java.io.IOException: 
  at java.net.PlainDatagramSocketImpl.send (PlainDatagramSocketImpl.java)
  at java.net.DatagramSocket.send (DatagramSocket.java:696)
  at com.instacart.library.truetime.SntpClient.requestTime (SntpClient.java:116)
  at com.instacart.library.truetime.TrueTime.requestTime (TrueTime.java:133)
  at com.instacart.library.truetime.TrueTimeRx$4$1$2.subscribe (TrueTimeRx.java:211)
  at io.reactivex.internal.operators.flowable.FlowableCreate.subscribeActual (FlowableCreate.java:72)
  at io.reactivex.Flowable.subscribe (Flowable.java:14349)
  at io.reactivex.Flowable.subscribe (Flowable.java:14295)
  at io.reactivex.internal.operators.flowable.FlowableSubscribeOn$SubscribeOnSubscriber.run (FlowableSubscribeOn.java:82)
  at io.reactivex.internal.schedulers.ScheduledRunnable.run (ScheduledRunnable.java:66)
  at io.reactivex.internal.schedulers.ScheduledRunnable.call (ScheduledRunnable.java:57)
  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:761)
Merlinkoss commented 5 years ago

Up! Same shit with this issue!

hoanglm4 commented 5 years ago

The same with issue: Caused by android.system.ErrnoException: sendto failed: EPERM (Operation not permitted) at libcore.io.Linux.sendtoBytes(Linux.java) at libcore.io.Linux.sendto(Linux.java:227) at libcore.io.BlockGuardOs.sendto(BlockGuardOs.java:304) at libcore.io.IoBridge.sendto(IoBridge.java:569) at java.net.PlainDatagramSocketImpl.send(PlainDatagramSocketImpl.java:124) at java.net.DatagramSocket.send(DatagramSocket.java:721) at com.instacart.library.truetime.SntpClient.requestTime(SntpClient.java:116) at com.instacart.library.truetime.TrueTime.requestTime(TrueTime.java:133) at com.instacart.library.truetime.TrueTimeRx$4$1$2.subscribe(TrueTimeRx.java:211) at io.reactivex.internal.operators.flowable.FlowableCreate.subscribeActual(FlowableCreate.java:72) at io.reactivex.Flowable.subscribe(Flowable.java:14409) at io.reactivex.Flowable.subscribe(Flowable.java:14356) at io.reactivex.internal.operators.flowable.FlowableSubscribeOn$SubscribeOnSubscriber.run(FlowableSubscribeOn.java:82) at io.reactivex.internal.schedulers.ScheduledRunnable.run(ScheduledRunnable.java:66) at io.reactivex.internal.schedulers.ScheduledRunnable.call(ScheduledRunnable.java:57) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:301) 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)

seth-gravy commented 5 years ago

Some exceptions are deemed fatal by RxJava, causing it to crash instead of calling your error handler.

One potential fix is to wrap exceptions to prevent crashes. If your application truly needs a synced time to function properly, you can choose how to handle those cases in the catch.

Here's an example in Kotlin:

Single
    .fromCallable {
        Log.d(javaClass.simpleName, "Running sync().")
    }
    .flatMap {
        try {
            TrueTimeRx.build()
                    .withSharedPreferencesCache(applicationContext)
                    .initializeNtp("time.google.com")
            // To test with a fatal exception here: throw ThreadDeath()
        } catch (t: Throwable) {
            // Wrap exception in case it's fatal
            Single.error<LongArray>(t)
        }
    }
    .subscribeOn(Schedulers.io())
    .subscribe(
            {
                Log.e(javaClass.simpleName, "" + it)
            },
            {
                Log.e(javaClass.simpleName, it.toString())
            }
    )
toddhodes commented 5 years ago

we're seeing the same issue; didn't appear in the phones we developed with, but, appears once we went to 1% rollout to real customers. Looked really bad as our customer (B2B2C) hosts the app and sees the crashlytics, bit us hard.

:(

obviously instacart doesn't care about this library anymore, needs a fork

seth-gravy commented 5 years ago

The try/catch approach didn't seem to help us that much.

Setting a global RxJava error handler, however, is working for us! We haven't seen a crash related to this issue since.

RxJavaPlugins.setErrorHandler {
    // Log, eat error, etc.
    // Note: this likely is not executed on the main thread
}

Reference: https://github.com/ReactiveX/RxJava/wiki/What's-different-in-2.0#error-handling

We are still receiving a few of these errors, though:

java.lang.RuntimeException: expected SNTP time from last boot to be cached. couldn't find it.
    at com.instacart.library.truetime.TrueTime._getCachedSntpTime(TrueTime.java:170)
    at com.instacart.library.truetime.TrueTime.now(TrueTime.java:32)
dradding commented 5 years ago

Does anyone know the cause of this error re: "Operation not permitted"? We'd prefer to fix the actual issue instead of just swallowing the error.

guyromb commented 5 years ago

This has to be solved, not muted. Any suggestions?

LosDanieloss commented 5 years ago

I've posted my finding in here: https://github.com/instacart/truetime-android/issues/119#issuecomment-510043102