Opened 6 months ago

Closed 4 months ago

Last modified 8 days ago

#2491 closed defect (fixed)

ANR android BaseTunnelPreferenceFragment

Reported by: Meeh Owned by: Meeh
Priority: minor Milestone: 0.9.41
Component: apps/android Version: 0.9.39
Keywords: Cc:
Parent Tickets: Sensitive: no

Description

"main" prio=5 tid=1 Waiting
  | group="main" sCount=1 dsCount=0 obj=0x76cc6598 self=0xb4364500
  | sysTid=21648 nice=0 cgrp=default sched=0/0 handle=0xb6f2fd54
  | state=S schedstat=( 6682544192 5588238747 8549 ) utm=535 stm=133 core=2 HZ=100
  | stack=0xbe10f000-0xbe111000 stackSize=8MB
  | held mutexes=
  at java.lang.Object.wait! (Native method)
- waiting on <0x0d6d7623> (a java.lang.Object)
  at java.lang.Thread.parkFor$ (Thread.java:1220)
- locked <0x0d6d7623> (a java.lang.Object)
  at sun.misc.Unsafe.park (Unsafe.java:299)
  at java.util.concurrent.locks.LockSupport.park (LockSupport.java:158)
  at java.util.concurrent.FutureTask.awaitDone (FutureTask.java:421)
  at java.util.concurrent.FutureTask.get (FutureTask.java:163)
  at android.os.AsyncTask.get (AsyncTask.java:498)
  at net.i2p.android.i2ptunnel.preferences.BaseTunnelPreferenceFragment.saveTunnel (BaseTunnelPreferenceFragment.java:91)
  at net.i2p.android.i2ptunnel.preferences.BaseTunnelPreferenceFragment.onStop (BaseTunnelPreferenceFragment.java:80)
  at android.support.v4.app.Fragment.performStop (Fragment.java:2662)
  at android.support.v4.app.FragmentManagerImpl.moveToState (FragmentManager.java:1519)
  at android.support.v4.app.FragmentManagerImpl.moveFragmentToExpectedState (FragmentManager.java:1784)
  at android.support.v4.app.BackStackRecord.executeOps (BackStackRecord.java:797)
  at android.support.v4.app.FragmentManagerImpl.executeOps (FragmentManager.java:2625)
  at android.support.v4.app.FragmentManagerImpl.executeOpsTogether (FragmentManager.java:2411)
  at android.support.v4.app.FragmentManagerImpl.removeRedundantOperationsAndExecute (FragmentManager.java:2366)
  at android.support.v4.app.FragmentManagerImpl.execPendingActions (FragmentManager.java:2273)
  at android.support.v4.app.FragmentManagerImpl$1.run (FragmentManager.java:733)
  at android.os.Handler.handleCallback (Handler.java:739)
  at android.os.Handler.dispatchMessage (Handler.java:95)
  at android.os.Looper.loop (Looper.java:148)
  at android.app.ActivityThread.main (ActivityThread.java:7406)
  at java.lang.reflect.Method.invoke! (Native method)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run (ZygoteInit.java:1230)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1120)
"Timestamper" tid=14 Sleeping 
"Timestamper" daemon prio=1 tid=14 Sleeping
  | group="main" sCount=1 dsCount=0 obj=0x12e44be0 self=0x9e626e00
  | sysTid=21714 nice=19 cgrp=bg_non_interactive sched=0/0 handle=0x9d23f930
  | state=S schedstat=( 99432148 543460698 253 ) utm=4 stm=5 core=1 HZ=100
  | stack=0x9d13d000-0x9d13f000 stackSize=1038KB
  | held mutexes=
  at java.lang.Thread.sleep! (Native method)
- sleeping on <0x0717517f> (a java.lang.Object)
  at java.lang.Thread.sleep (Thread.java:1031)
- locked <0x0717517f> (a java.lang.Object)
  at java.lang.Thread.sleep (Thread.java:985)
  at net.i2p.router.time.RouterTimestamper.run (RouterTimestamper.java:257)
  at java.lang.Thread.run (Thread.java:818)
  at net.i2p.util.I2PThread.run (I2PThread.java:103)
"YK Precalc" tid=17 Sleeping 
"YK Precalc" daemon prio=3 tid=17 Sleeping
  | group="main" sCount=1 dsCount=0 obj=0x12e404c0 self=0x9e627800
  | sysTid=21721 nice=13 cgrp=bg_non_interactive sched=0/0 handle=0x9ce89930
  | state=S schedstat=( 7884299883 70175837578 6353 ) utm=774 stm=14 core=0 HZ=100
  | stack=0x9cd87000-0x9cd89000 stackSize=1038KB
  | held mutexes=
  at java.lang.Thread.sleep! (Native method)
- sleeping on <0x055d0aaa> (a java.lang.Object)
  at java.lang.Thread.sleep (Thread.java:1031)
- locked <0x055d0aaa> (a java.lang.Object)
  at java.lang.Thread.sleep (Thread.java:985)
  at net.i2p.crypto.YKGenerator$YKPrecalcRunner.run (YKGenerator.java:233)
  at java.lang.Thread.run (Thread.java:818)
  at net.i2p.util.I2PThread.run (I2PThread.java:103)
"BWRefiller" tid=23 Sleeping 
"BWRefiller" daemon prio=6 tid=23 Sleeping
  | group="main" sCount=1 dsCount=0 obj=0x12ed2c40 self=0x9dcbc300
  | sysTid=21727 nice=-2 cgrp=default sched=0/0 handle=0x9c86b930
  | state=S schedstat=( 4056981851 9789154828 25542 ) utm=238 stm=167 core=3 HZ=100
  | stack=0x9c769000-0x9c76b000 stackSize=1038KB
  | held mutexes=
  at java.lang.Thread.sleep! (Native method)
- sleeping on <0x005641e4> (a java.lang.Object)
  at java.lang.Thread.sleep (Thread.java:1031)
- locked <0x005641e4> (a java.lang.Object)
  at java.lang.Thread.sleep (Thread.java:985)
  at net.i2p.router.transport.FIFOBandwidthRefiller.run (FIFOBandwidthRefiller.java:117)
  at java.lang.Thread.run (Thread.java:818)
  at net.i2p.util.I2PThread.run (I2PThread.java:103)
"RouterWatchdog" tid=29 Sleeping 
"RouterWatchdog" daemon prio=6 tid=29 Sleeping
  | group="main" sCount=1 dsCount=0 obj=0x12f2c520 self=0x9dcbe100
  | sysTid=21733 nice=-2 cgrp=default sched=0/0 handle=0x9c24d930
  | state=S schedstat=( 7067385 860769 19 ) utm=0 stm=0 core=0 HZ=100
  | stack=0x9c14b000-0x9c14d000 stackSize=1038KB
  | held mutexes=
  at java.lang.Thread.sleep! (Native method)
- sleeping on <0x08b82e13> (a java.lang.Object)
  at java.lang.Thread.sleep (Thread.java:1031)
- locked <0x08b82e13> (a java.lang.Object)
  at java.lang.Thread.sleep (Thread.java:985)
  at net.i2p.router.tasks.RouterWatchdog.run (RouterWatchdog.java:127)
  at java.lang.Thread.run (Thread.java:818)
  at net.i2p.util.I2PThread.run (I2PThread.java:103)
"DH Precalc" tid=35 Sleeping 
"DH Precalc" prio=4 tid=35 Sleeping
  | group="main" sCount=1 dsCount=0 obj=0x12edd180 self=0xb2efd300
  | sysTid=21741 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0x9b728930
  | state=S schedstat=( 949652619 3033693242 611 ) utm=92 stm=2 core=3 HZ=100
  | stack=0x9b626000-0x9b628000 stackSize=1038KB
  | held mutexes=
  at java.lang.Thread.sleep! (Native method)
- sleeping on <0x0c25725a> (a java.lang.Object)
  at java.lang.Thread.sleep (Thread.java:1031)
- locked <0x0c25725a> (a java.lang.Object)
  at java.lang.Thread.sleep (Thread.java:985)
  at net.i2p.router.transport.crypto.DHSessionKeyBuilder$PrecalcRunner.run (DHSessionKeyBuilder.java:526)
"XDH Precalc" tid=36 Sleeping 
"XDH Precalc" prio=4 tid=36 Sleeping
  | group="main" sCount=1 dsCount=0 obj=0x12edd280 self=0xb2efd800
  | sysTid=21742 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0x9b623930
  | state=S schedstat=( 3552228068 2542147326 1276 ) utm=354 stm=1 core=3 HZ=100
  | stack=0x9b521000-0x9b523000 stackSize=1038KB
  | held mutexes=
  at java.lang.Thread.sleep! (Native method)
- sleeping on <0x00654c8b> (a java.lang.Object)
  at java.lang.Thread.sleep (Thread.java:1031)
- locked <0x00654c8b> (a java.lang.Object)
  at java.lang.Thread.sleep (Thread.java:985)
  at net.i2p.router.transport.crypto.X25519KeyFactory.run (X25519KeyFactory.java:107)

Subtickets

#2460: Broadcast of Intent { act=android.intent.action.TIME_TICK flg=0x50200014 (has extras) }closedmeeh

Change History (7)

comment:1 Changed 6 months ago by zzz

Already marked with a TODO in BaseTunnelPreferenceFragment? late 2017.
Possibly related: #2486

comment:2 Changed 4 months ago by zzz

Sensitive: unset
    // TODO: There used to be a possible ANR here, because the underlying I2P code
    // checks if the session is open as part of updating its config. We may need to save
    // completely asynchronously (and ensure we do actually save before the app closes).
    task.execute().get();

TunnelUtil? extends GeneralHelper?
GeneralHelper?.saveTunnel() calls
updateTunnelConfig() calls
TunnelController?.setConfig() calls
session.isClosed() to see if it should call
session.updateOptions()

isClosed() locks on stateLock but that shouldn't be for long.
stack trace above doesn't show what it's waiting for
don't know how to ensure an AsyncTask? completes before the app closes.

comment:3 Changed 4 months ago by Meeh

This has happened like 5 times. In terms of the list of ANRs from google, this is the leading one (happen most).

comment:4 Changed 4 months ago by zzz

see also #2460 at same line

comment:5 Changed 4 months ago by idk

This can be reproduced reliably by launching the app, waiting for tunnels to start, creating a new tunnel and *immediately* editing the tunnel and touching the "back" icon in the upper left corner of the screen.

comment:6 Changed 4 months ago by idk

Milestone: undecided0.9.41
Resolution: fixed
Status: newclosed

comment:7 Changed 8 days ago by zzz

Add a subticket #2460 (Broadcast of Intent { act=android.intent.action.TIME_TICK flg=0x50200014 (has extras) }).

Note: See TracTickets for help on using tickets.