mozilla-lockwise / lockwise-android

Firefox's Lockwise app for Android
https://mozilla-lockwise.github.io/lockwise-android/
Mozilla Public License 2.0
622 stars 104 forks source link

Stuck on loading and splash screen after changing password #753

Open eliserichards opened 5 years ago

eliserichards commented 5 years ago

Related to #711

User's steps:

  1. signed into test account on Thursday — then changed the password for that account on another platform (desktop?)
  2. I then opened lockwise again and I got that perma-syncing icon. So I eventually closed it.
  3. Today I did an update.
  4. And I then just opened it now to see if I’d still get the perma-sync, but instead just the frozen splash screen.

Logs:

06-11 19:32:34.696  3575 15088 D CustomFrequencyManagerService: releaseDVFSLockLocked : Getting Lock type frm List : DVFS_MIN_LIMIT  frequency : 2361600  uid : 1000  pid : 3575  tag : APP_LAUNCH@CPU_MIN@8
06-11 19:32:34.732  3575 13921 D WifiPermissionsUtil: canAccessScanResults: pkgName = android, uid = 1000
06-11 19:32:34.837  9235  9270 W fxa_client::ffi: Authentication error: Error(
06-11 19:32:34.837  9235  9270 W fxa_client::ffi: 
06-11 19:32:34.837  9235  9270 W fxa_client::ffi: Remote server error: '401' '110' 'Unauthorized' 'Invalid authentication token in request signature' 'https://github.com/mozilla/fxa-auth-server/blob/master/docs/api.md#response-format')
06-11 19:32:34.839  9235  9271 D fxaclient_ffi: fxa_get_access_token
06-11 19:32:34.842  9235  9271 I System.out: (HTTPLog)-Static: isSBSettingEnabled false
06-11 19:32:34.842  9235  9271 I System.out: (HTTPLog)-Static: isSBSettingEnabled false
06-11 19:32:34.991  9235  9271 W fxa_client::ffi: Authentication error: Error(
06-11 19:32:34.991  9235  9271 W fxa_client::ffi: 
06-11 19:32:34.991  9235  9271 W fxa_client::ffi: Remote server error: '401' '110' 'Unauthorized' 'Invalid authentication token in request signature' 'https://github.com/mozilla/fxa-auth-server/blob/master/docs/api.md#response-format')
06-11 19:32:35.699  3575 13922 D WifiStateMachine: enter getWifiLinkLayerStats
abodea commented 5 years ago

Hi @eliserichards , I added this issue https://github.com/mozilla-lockwise/lockwise-android/issues/924, my issue isn't really frozen splash screen. Maybe this is related to the fix you did? Based on the response I can close this issue and we follow up on my issue.

abodea commented 5 years ago

I also was able to reproduce this issue after I changed my password, there is infinite loading bar on the entries section. Note that after restart when refreshing the entries, the infinite loading bar appears, on my issue presented above it's only on the first login. log.txt


 --------- beginning of system
2019-09-17 09:59:59.627 5392-5461/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0
2019-09-17 10:00:00.000 5719-5855/? D/SamsungAlarmManager: Expired : 8
2019-09-17 10:00:00.001 5719-5855/? V/SamsungAlarmManager: Sending to uid : 1000 action=android.intent.action.TIME_TICK alarm=Alarm{db3628d type 3 when 87559538 android}
2019-09-17 10:00:00.004 5719-5855/? I/SamsungAlarmManager: setLocked to kernel - T:2 / 20190917T100023, SetElapsed=87582670, nowELAPSED=87559541
2019-09-17 10:00:00.005 5719-5719/? D/SamsungAlarmManager: setExact Intent (T:3/F:1/AC:false) 20190917T100100 - CU:1000/CP:5719
2019-09-17 10:00:00.005 5719-5719/? I/SamsungAlarmManager: setLocked to kernel - T:2 / 20190917T100023, SetElapsed=87582670, nowELAPSED=87559543
2019-09-17 10:00:00.009 6078-6078/? D/KeyguardUpdateMonitor: handleTimeUpdate
2019-09-17 10:00:00.009 6078-6078/? D/KeyguardServiceBoxContainer: refreshTime() 1
2019-09-17 10:00:00.015 6078-6078/? D/QSClockBellTower: He is ready to ring the bell. (((timeText:10:00, skipUpdateForDemo:false, dateText:Tue, September 17)))
2019-09-17 10:00:00.015 6078-6078/? D/QSClock: status_bar_clock notifyTimeChanged(currentTime:10:00) mClockVisibleByPolicy:true, mClockVisibleByUser:true, visible?true, parent:android.widget.LinearLayout{1c41d7e V.E...... ......ID 0,0-148,110 #7f0a02db app:id/left_clock_container}
2019-09-17 10:00:00.016 6078-6078/? D/QSClockBellTower: Everyone heard the bell. run(currentTime:1568703600014,   getTime():Tue Sep 17 10:00:00 GMT+03:00 2019,   getTimeZone():libcore.util.ZoneInfo[id="Europe/Bucharest",mRawOffset=7200000,mEarliestRawOffset=7200000,mUseDst=true,mDstSavings=3600000,transitions=137])
2019-09-17 10:00:00.035 6078-6078/? I/StackScroller: ADJUST STACK.TRANSLATION
2019-09-17 10:00:00.053 6078-6078/? I/chatty: uid=10009(com.samsung.android.app.aodservice) com.android.systemui identical 4 lines
2019-09-17 10:00:00.053 6078-6078/? I/StackScroller: ADJUST STACK.TRANSLATION
2019-09-17 10:00:00.076 5719-5908/? D/WifiStateMachine: enter getWifiLinkLayerStats
2019-09-17 10:00:00.077 5719-5908/? I/WifiVendorHal: getWifiLinkLayerStats(l.2965) before calling iface.getLinkLayerStats
2019-09-17 10:00:00.077 5226-5226/? I/android.hardware.wifi@1.0-service: enter getLinkLayerStats
2019-09-17 10:00:00.077 5226-5226/? I/android.hardware.wifi@1.0-service: enter getLinkLayerStatsInternal
2019-09-17 10:00:00.095 5226-5226/? I/android.hardware.wifi@1.0-service: Successfully getLinkLayerStats.
2019-09-17 10:00:00.096 5719-5908/? I/WifiVendorHal: getWifiLinkLayerStats(l.2965) after calling iface.getLinkLayerStats
2019-09-17 10:00:00.136 5719-5908/? I/WifiStateMachine: checkScoreBasedQuality -  mPreviousScore[0]:63 mPreviousScore[1]:63 mPreviousScore[2]:64 s2Score:64mPrevoiusScoreAverage:63
2019-09-17 10:00:00.554 5719-5907/? D/WifiTrafficPoller: TrafficStats TxPkts=109000 RxPkts=385477 TxBytes=9671526 RxBytes=312468020 , Foreground uid=10246 pkgName=mozilla.lockbox TxPackets=4359 RxPackets=5284 TxBytes=776153 RxBytes=5441237
2019-09-17 10:00:00.555 5719-5907/? D/WifiPermissionsUtil: canAccessScanResults: pkgName = android, uid = 1000
2019-09-17 10:00:00.604 5719-5882/? D/InputReader: Input event(10): value=1 when=48715.632174
2019-09-17 10:00:00.604 5719-5882/? D/InputReader: Input event(10): value=1 when=48715.632174
2019-09-17 10:00:00.605 5719-5882/? I/InputReader: Touch event's action is 0x0 (deviceType=0) [pCnt=1, s=0.1375 ] when=48715.632174
2019-09-17 10:00:00.606 5719-5881/? I/InputDispatcher: Delivering touch to (6078): action: 0x4, displayId: 0, 'b15e226', toolType: 1
2019-09-17 10:00:00.606 5719-5881/? I/InputDispatcher: Delivering touch to (6078): action: 0x4, displayId: 0, '8c5fcf3', toolType: 1
2019-09-17 10:00:00.606 5719-5881/? I/clp-JNI: Add pinfo.  (channel) ff2b8ce mozilla.lockbox/mozilla.lockbox.view.RootActivity (server) (pkg) AppWindowToken{e807341 token=Token{6eaca28 ActivityRecord{594204b u0 mozilla.lockbox/.view.RootActivity t48}}} 16334 10246 (action) 0
2019-09-17 10:00:00.606 5719-5881/? I/clp-JNI: Add pinfo end.
2019-09-17 10:00:00.606 5719-5881/? I/InputDispatcher: Delivering touch to (16334): action: 0x0, displayId: 0, 'ff2b8ce', toolType: 1
2019-09-17 10:00:00.607 16334-16334/? D/ViewRootImpl@9f33481[RootActivity]: ViewPostIme pointer 0
2019-09-17 10:00:00.609 5719-5752/? D/Sprites: image state surfaceDrawn w:116 h:116
2019-09-17 10:00:00.623 5242-5242/? I/SurfaceFlinger: Display 0 HWC layers:
        type    |    handle    | flag |  format   |   source crop (l,t,r,b)    |         frame       | name 
    ------------+--------------+------+-----------+----------------------------+---------------------+------
         Device | 0x78b52191c0 | 0082 | RGBA_8888 |   0.0    0.0 1440.0 3040.0 |    0    0 1440 3040 | mozilla.lockbox/mozilla.lockbox.view.RootActivity[16334]#0
         Device | 0x78bc44a7a0 | 0000 | RGBA_8888 |   0.0    0.0 1440.0  142.0 |    0    0 1440  142 | StatusBar[6078]#0
         Device | 0x78bc44a6c0 | 0000 | RGBA_8888 |   0.0    0.0   67.0  576.0 | 1373  498 1440 1074 | com.samsung.android.app.cocktailbars[...]arservice.CocktailBarService[8752]#0
         Device | 0x78bca44100 | 0000 | RGBA_8888 |   0.0    0.0 1440.0  168.0 |    0 2872 1440 3040 | NavigationBar[6078]#0
         Device | 0x78bc44a0a0 | 0000 | RGBA_8888 |   0.0    0.0  116.0  116.0 |   44 1406  160 1522 | Sprite#4
2019-09-17 10:00:00.813 5719-5882/? D/InputReader: Input event(10): value=0 when=48715.841104
2019-09-17 10:00:00.813 5719-5882/? D/InputReader: Input event(10): value=0 when=48715.841104
2019-09-17 10:00:00.813 5719-5882/? I/InputReader: Touch event's action is 0x1 (deviceType=0) [pCnt=1, s=] when=48715.841104
2019-09-17 10:00:00.813 5719-5881/? I/clp-JNI: Add pinfo.  (channel) ff2b8ce mozilla.lockbox/mozilla.lockbox.view.RootActivity (server) (pkg) AppWindowToken{e807341 token=Token{6eaca28 ActivityRecord{594204b u0 mozilla.lockbox/.view.RootActivity t48}}} 16334 10246 (action) 1
2019-09-17 10:00:00.813 5719-5881/? I/clp-JNI: Add pinfo end.
2019-09-17 10:00:00.813 5719-5881/? I/InputDispatcher: Delivering touch to (16334): action: 0x1, displayId: 0, 'ff2b8ce', toolType: 1
2019-09-17 10:00:00.814 16334-16334/? D/ViewRootImpl@9f33481[RootActivity]: ViewPostIme pointer 1
2019-09-17 10:00:00.815 5719-5719/? D/CustomFrequencyManagerService: acquireDVFSLockLocked : type : DVFS_MIN_LIMIT  frequency : 1144000  uid : 1000  pid : 5719  pkgName : SMOOTH_SCROLL@CPU_MIN@26
2019-09-17 10:00:00.818 5719-5719/? D/CustomFrequencyManagerService: releaseDVFSLockLocked : Getting Lock type frm List : DVFS_MIN_LIMIT  frequency : 1144000  uid : 1000  pid : 5719  tag : SMOOTH_SCROLL@CPU_MIN@26
2019-09-17 10:00:00.820 5719-5719/? D/CustomFrequencyManagerService: acquireDVFSLockLocked : type : DVFS_MIN_LIMIT  frequency : 1144000  uid : 1000  pid : 5719  pkgName : SMOOTH_SCROLL@CPU_MIN@26
2019-09-17 10:00:00.822 5719-5719/? D/GameManagerService: identifyGamePackage. mozilla.lockbox
2019-09-17 10:00:00.822 5719-5719/? D/GamePkgDataHelper: getGamePkgData(). mozilla.lockbox
2019-09-17 10:00:00.823 5719-5719/? D/CustomFrequencyManagerService: acquireDVFSLockLocked : type : DVFS_MIN_LIMIT  frequency : 175500  uid : 1000  pid : 5719  pkgName : GESTURE_DETECTED@CPU_MIN@34
2019-09-17 10:00:00.823 5719-5719/? D/CustomFrequencyManagerService: releaseDVFSLockLocked : Getting Lock type frm List : DVFS_MIN_LIMIT  frequency : 1144000  uid : 1000  pid : 5719  tag : SMOOTH_SCROLL@CPU_MIN@26
2019-09-17 10:00:01.041 5242-5242/? I/SurfaceFlinger: Display 0 HWC layers:
        type    |    handle    | flag |  format   |   source crop (l,t,r,b)    |         frame       | name 
    ------------+--------------+------+-----------+----------------------------+---------------------+------
         Device | 0x78bca473c0 | 0082 | RGBA_8888 |   0.0    0.0 1440.0 3040.0 |    0    0 1440 3040 | mozilla.lockbox/mozilla.lockbox.view.RootActivity[16334]#0
         Device | 0x78bc44a7a0 | 0000 | RGBA_8888 |   0.0    0.0 1440.0  142.0 |    0    0 1440  142 | StatusBar[6078]#0
         Device | 0x78bc44a6c0 | 0000 | RGBA_8888 |   0.0    0.0   67.0  576.0 | 1373  498 1440 1074 | com.samsung.android.app.cocktailbars[...]arservice.CocktailBarService[8752]#0
         Device | 0x78bca44100 | 0000 | RGBA_8888 |   0.0    0.0 1440.0  168.0 |    0 2872 1440 3040 | NavigationBar[6078]#0
2019-09-17 10:00:01.058 6078-6516/? D/NetworkController.MobileSignalController(0/-2): onSignalStrengthsChanged signalStrength=SignalStrength: 30 99 -30 -200 -30 -200 -1 99 2147483647 2147483647 2147483647 2147483647 0 2147483647 30 67 -53 0x4 P gsm|lte use_rsrp_and_rssnr_for_lte_level  [-128, -118, -108, -98] [-115, -105, -95, -85] level=4
2019-09-17 10:00:01.058 6078-6516/? D/NetworkController.MobileSignalController(0/-2): getMobileIconGroup(): 0
2019-09-17 10:00:01.557 5719-5907/? D/WifiPermissionsUtil: canAccessScanResults: pkgName = android, uid = 1000
2019-09-17 10:00:01.659 6832-6832/? D/io_stats: !@   8,0 r 119731 9174712 w 216093 5238528 d 19043 2407476 f 277117 307678 iot 566176 169614 th 102400 0 0 pt 0 inp 0 0 48716.684
2019-09-17 10:00:01.846 5719-20834/? D/WifiPermissionsUtil: canAccessScanResults: pkgName = com.google.android.gms, uid = 10044
2019-09-17 10:00:01.927 5719-5719/? D/CustomFrequencyManagerService: releaseDVFSLockLocked : Getting Lock type frm List : DVFS_MIN_LIMIT  frequency : 175500  uid : 1000  pid : 5719  tag : GESTURE_DETECTED@CPU_MIN@34
2019-09-17 10:00:02.319 5719-20834/? D/CustomFrequencyManagerService: FrequencyrequestList.getNextSchedTuneBoostRequest, index: 0
2019-09-17 10:00:02.559 5719-5907/? D/WifiPermissionsUtil: canAccessScanResults: pkgName = android, uid = 1000```

I will remove the `qa needed` as I can still reproduce this issue.
ekager commented 4 years ago

I recently reproduced this and think Lockwise needs to implement the flow to re login when we hit the "needs reauth" FxA error state

eliserichards commented 4 years ago

@changecourse do you have thoughts on how you'd like the user to be notified to reauthenticate when this happens?

changecourse commented 4 years ago

If someone gets into a frozen or unusable state, and we tie it back to needing to reauthenticate, we could display a system menu popover to communicate our apologies, with a single action redirect back to the welcome screen... something similar to this:

Screen Shot 2019-11-13 at 11 51 31 AM
ekager commented 4 years ago

Okay interesting update. I logged out and logged back in to reauth myself. And now I can't open Lockwise at all. Like the original comment step 4. I'm just trapped on the splash screen.

And I then just opened it now to see if I’d still get the perma-sync, but instead just the frozen splash screen.
ddurst commented 4 years ago

Okay interesting update. I logged out and logged back in to reauth myself. And now I can't open Lockwise at all. Like the original comment step 4. I'm just trapped on the splash screen.

I experienced something like this, and clearing the data cache fixed it. (Note: I have no idea what the root cause was, and it's only possible that that could help here. See #1021.)

changecourse commented 4 years ago

Error State

@eliserichards above copy approved and ready to go.

Bonus points if hitting the Continue button opens the webview, instead of someone then having to hit [Get Started]. Double bonus points if we can pass the email previously used through the webview, so they don't have to enter that in again too.

eliserichards commented 4 years ago
  1. Log in to account on Lockwise
  2. Log in to account on desktop
  3. Change password on desktop
  4. Initiate a sync on Lockwise, see SyncTelemetryPing response (almost immediately):
    Hashed UID: SyncTelemetryPing(version=1, uid=c2628058d94a90f588b260d98f21f3d7, events=[], syncs=[SyncInfo(at=1574365406, took=247, engines=[EngineInfo(name=passwords, at=1574365406, took=247, incoming=IncomingInfo(applied=27, failed=0, newFailed=0, reconciled=0), outgoing=[OutgoingInfo(sent=0, failed=0)], failureReason=null, validation=null)], failureReason=null)])

DataStoreSupport and syncConfig are registering as the same as they were before (because nothing in the state of the app has changed).

Todo

lnicola commented 4 years ago

A small note: my Lockwise stopped syncing and I logged out, then back in. The first launch after that went fine (or was it the same session), but now it's stuck at the splash screen. Clearing the cache has no effect.

I cleared the app storage, logged back in, waited for it to sync, then tried pull-to-refresh and got stuck in perma-sync. After killing the app, a resync went fine.

I wonder, would it be possible to use the Android accounts thing for Lockwise, Fenix and Notes? It used to be more reliable.