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

Signal forgets preferences after restart #11640

Closed
4 tasks done
oliv3r opened this issue Sep 22, 2021 · 5 comments
Closed
4 tasks done

Signal forgets preferences after restart #11640

oliv3r opened this issue Sep 22, 2021 · 5 comments
Labels
wontfix

Comments

@oliv3r
Copy link

oliv3r commented Sep 22, 2021 •
edited
Loading

Bug description

After restarting signal (force-kill, reboot, crash), signal looses/forgets preferences (dark theme, pin entry, messages) but remembers account details, identity etc.
Even sent messages are gone. Strangely, some initial messages (first ones sent after setup) do appear.
On a synced signal desktop all messages do 'stay'.

This started to happen after upgrading to v5.23.8, but even downgrading to v5.20.3 kept the same behavior.

Clearing all signal data (effectively a re-install) full re-install of the app, and even a full factory reset (including storage) did not resolve the issue.

Steps to reproduce

  • install signal
  • set dark theme and 'disable' pin
  • restart signal (force-kill, reboot, etc)

** Actual result. **
theme is white again, pin entry is asked again, message history is gone

Expected result:
signal remembers everything

Screenshots

N/A

Device info

Device: Samsung Galaxy Note 2 (n7100)
Android version: 7.1.2
Signal version: 5.23.8

Link to debug log

https://debuglogs.org/1dfb1e10ba0c3de47daf7f81dc89053d89e363f3c3c6e7ad28c118f9b83a5198

The log is logcat from when the application would start 
09-22 14:17:18.827  2905  4901 I ActivityManager: START u0 {act=android.intent.action.MAIN cat=[android.intent.category.LAUNCHER] flg=0x10200000 cmp=org.thoughtcrime.securesms/.RoutingActivity bnds=[432,1134][566,1286] (has extras)} from uid 10030 on display 0
09-22 14:17:18.863  2905  3146 I ActivityManager: Start proc 4966:org.thoughtcrime.securesms/u0a74 for activity org.thoughtcrime.securesms/.RoutingActivity
09-22 14:17:18.934  2905  2930 E Notification: setLatestEventInfo() is deprecated and you should feel deprecated.
09-22 14:17:18.934  2905  2930 E Notification: java.lang.Throwable
09-22 14:17:18.934  2905  2930 E Notification: 	at android.app.Notification.setLatestEventInfo(Notification.java:2084)
09-22 14:17:18.934  2905  2930 E Notification: 	at com.android.server.am.ActivityManagerService$MainHandler.handleMessage(ActivityManagerService.java:2364)
09-22 14:17:18.934  2905  2930 E Notification: 	at android.os.Handler.dispatchMessage(Handler.java:102)
09-22 14:17:18.934  2905  2930 E Notification: 	at android.os.Looper.loop(Looper.java:154)
09-22 14:17:18.934  2905  2930 E Notification: 	at android.os.HandlerThread.run(HandlerThread.java:61)
09-22 14:17:18.934  2905  2930 E Notification: 	at com.android.server.ServiceThread.run(ServiceThread.java:46)
09-22 14:17:18.938  2905  2905 D ZenLog  : intercepted: 0|android|17039402|null|1000,alarmsOnly
09-22 14:17:18.940  2905  2905 V NotificationService: pkg=android canInterrupt=false intercept=true
09-22 14:17:19.018  4966  4966 I MultiDex: VM with version 2.1.0 has multidex support
09-22 14:17:19.018  4966  4966 I MultiDex: Installing application
09-22 14:17:19.018  4966  4966 I MultiDex: VM has multidex support, MultiDex support library is disabled.
09-22 14:17:19.021  4966  4983 D libEGL  : loaded /system/lib/egl/libEGL_mali.so
09-22 14:17:19.051  4966  4983 D libEGL  : loaded /system/lib/egl/libGLESv1_CM_mali.so
09-22 14:17:19.061  4966  4966 I FirebaseApp: Device unlocked: initializing all Firebase APIs for app [DEFAULT]
09-22 14:17:19.091  4966  4966 I FirebaseInitProvider: FirebaseApp initialization successful
09-22 14:17:19.106  4966  4983 D libEGL  : loaded /system/lib/egl/libGLESv2_mali.so
09-22 14:17:19.129  4966  4966 I BlobContentProvider: onCreate()
09-22 14:17:19.130  4966  4966 I PartProvider: onCreate()
09-22 14:17:19.176  4966  4966 I ApplicationContext: Installed AesGcmProvider: 1
09-22 14:17:19.441  4966  4966 V NativeCrypto: Registering org/conscrypt/NativeCrypto's 284 native methods...
09-22 14:17:19.455  4966  4966 I ApplicationContext: Installed Conscrypt provider: 2
09-22 14:17:19.540  4966  4966 I ApplicationContext: onCreate()
09-22 14:17:19.547  4966  4995 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.608  4966  4995 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.634  4966  4995 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.684  4966  4966 D ApplicationMigrations: Not an update. Skipping.
09-22 14:17:19.687  4966  4966 D CallManager: Loading ringrtc library
09-22 14:17:19.693  4966  4998 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.694  4966  4966 I CallManager: CallManager.initialize(): (release build)
09-22 14:17:19.695  4966  4966 I org.webrtc.Logging: NativeLibrary: Loading native library: jingle_peerconnection_so
09-22 14:17:19.696  4966  4966 I org.webrtc.Logging: PeerConnectionFactory: PeerConnectionFactory was initialized without an injected Loggable. Any existing Loggable will be deleted.
09-22 14:17:19.697  4966  4966 I CallManager: CallManager.initialize() returned
09-22 14:17:19.707  4966  4966 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.718  4966  4998 I JobDatabase: onOpen()
09-22 14:17:19.722  4966  4998 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.743  4966  4966 I KeyValueDatabase: onOpen()
09-22 14:17:19.746  4966  4966 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.758  4966  4999 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.760  4966  4998 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.775  4966  4966 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.835  4966  4999 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.845  4966  4973 I art     : Do partial code cache collection, code=20KB, data=31KB
09-22 14:17:19.846  4966  4973 I art     : After code cache collection, code=20KB, data=31KB
09-22 14:17:19.846  4966  4973 I art     : Increasing code cache capacity to 128KB
09-22 14:17:19.852  4966  4998 I IncomingMessageObserver: Initializing! (214327658)
09-22 14:17:19.856  4966  4966 D DynamicTheme: Setting to always day
09-22 14:17:19.858  4966  4966 D CachedInflater: Clearing view cache.
09-22 14:17:19.859  4966  5002 I IncomingMessageObserver: Waiting for websocket state change....
09-22 14:17:19.860  4966  4966 I FeatureFlags: No remote config stored. Skipping.
09-22 14:17:19.860  4966  4966 I FeatureFlags: No remote config stored. Skipping.
09-22 14:17:19.863  4966  4966 I FeatureFlags: init() {}
09-22 14:17:19.863  4966  5002 D IncomingMessageObserver: Network: true, Foreground: false, FCM: true, Censored: false, Registered: true, Websocket Registered: true, Proxy: false
09-22 14:17:19.865  4966  4966 D AppStartup: [init] security-provider: 281  sqlcipher-init: 8  logging: 77  crash-handling: 1  rx-init: 0  app-dependencies: 2  notification-channels: 23  first-launch: 0  app-migrations: 118  ring-rtc: 13  mark-registration: 147  lifecycle-observer: 0  message-retriever: 12  dynamic-theme: 3  vector-compat: 0  proxy-init: 0  blob-provider: 1  feature-flags: 3  schedule-non-blocking: 0  total: 689
09-22 14:17:19.865  4966  4966 D ApplicationContext: onCreate() took 698 ms
09-22 14:17:19.866  4966  4996 D BlobProvider: No attachment drafts exist. Skipping.
09-22 14:17:19.867  4966  4996 I BlobProvider: Initialized.
09-22 14:17:19.894  4966  4999 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.925  4966  5000 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.944  4966  4996 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:19.954  4966  4979 I art     : Background partial concurrent mark sweep GC freed 88081(3MB) AllocSpace objects, 4(1384KB) LOS objects, 39% free, 3MB/5MB, paused 4.999ms total 137.649ms
09-22 14:17:19.958  4966  4966 I AppStartup: Received first critical render event.
09-22 14:17:19.964  4966  4966 D DynamicTheme: Previous night mode has changed previous: 0 now: 16
09-22 14:17:19.964  4966  4966 D CachedInflater: Clearing view cache.
09-22 14:17:19.971  4966  4999 I PersistentAlarmManagerL: RotateSignedPreKeyListener#onReceive(null)
09-22 14:17:19.972  4966  5004 I ViewOnceMessageManager: No messages to schedule.
09-22 14:17:19.973  4966  4999 I PersistentAlarmManagerL: class org.thoughtcrime.securesms.service.RotateSignedPreKeyListener scheduling for: 1632485005942 action: null
09-22 14:17:19.974  4966  4966 D PassphraseRequiredActiv: routeApplicationState(), state: 0
09-22 14:17:19.974  4966  4966 D BaseActivity: [MainActivity] onCreate()
09-22 14:17:19.976  4966  4999 I PersistentAlarmManagerL: DirectoryRefreshListener#onReceive(null)
09-22 14:17:19.980  4966  4999 I PersistentAlarmManagerL: class org.thoughtcrime.securesms.service.DirectoryRefreshListener scheduling for: 1632485005946 action: null
09-22 14:17:19.982  4966  4966 W art     : Before Android 4.1, method android.graphics.PorterDuffColorFilter androidx.vectordrawable.graphics.drawable.VectorDrawableCompat.updateTintFilter(android.graphics.PorterDuffColorFilter, android.content.res.ColorStateList, android.graphics.PorterDuff$Mode) would have incorrectly overridden the package-private method in android.graphics.drawable.Drawable
09-22 14:17:19.982  4966  5000 I ApplicationContext: Deleted 0 abandoned attachments.
09-22 14:17:19.983  4966  4999 I PersistentAlarmManagerL: RotateSenderCertificateListener#onReceive(null)
09-22 14:17:19.983  4966  5000 I RefreshPreKeysJob: Scheduling a prekey refresh. Time since last schedule: 1632313039983 ms
09-22 14:17:19.986  4966  4999 I PersistentAlarmManagerL: class org.thoughtcrime.securesms.service.RotateSenderCertificateListener scheduling for: 1632398606147 action: null
09-22 14:17:19.988  4966  4996 D StorageSyncHelper: Scheduling a sync. Last sync was 1632313039988 ms ago.
09-22 14:17:19.991  4966  5006 D PendingRetryReceiptMana: No pending receipts to schedule.
09-22 14:17:19.993  4966  4999 I MessageProcessReceiver: Alarm scheduled to repeat at interval 21600000
09-22 14:17:20.039  4966  4966 D CachedInflater: Clearing view cache.
09-22 14:17:20.041  4966  4966 D BaseActivity: [MainActivity] onStart()
09-22 14:17:20.044  4966  4966 D LoggingFragment: [ConversationListFragmen] onCreate()
09-22 14:17:20.129  4966  5000 I Job     : [JOB::5f2ea253-766f-413f-bbe5-f9ef9edef5e6][RefreshPreKeysJob] onSubmit() (Time Since Submission: 146 ms, Lifespan: 2592000000 ms, Run Attempt: 1/Unlimited)
09-22 14:17:20.140  4966  4996 I Job     : [JOB::3eeebfd8-1ef1-417f-9568-c409ba30207e][StorageSyncJob] onSubmit() (Time Since Submission: 144 ms, Lifespan: 86400000 ms, Run Attempt: 1/3)
09-22 14:17:20.140  4966  5007 W art     : Long monitor contention with owner signal-bounded-2 (5000) at com.fasterxml.jackson.databind.ser.impl.ReadOnlyClassToSerializerMap com.fasterxml.jackson.databind.ser.SerializerCache.getReadOnlyLookupMap()(SerializerCache.java:50) waiters=1 in org.thoughtcrime.securesms.jobmanager.Job org.thoughtcrime.securesms.jobmanager.JobController.pullNextEligibleJobForExecution(org.thoughtcrime.securesms.jobmanager.JobPredicate) for 138ms
09-22 14:17:20.199  4966  4973 I art     : Do partial code cache collection, code=23KB, data=62KB
09-22 14:17:20.211  4966  4973 I art     : After code cache collection, code=23KB, data=62KB
09-22 14:17:20.211  4966  4973 I art     : Increasing code cache capacity to 256KB
09-22 14:17:20.251  4966  5012 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:20.262  4966  5013 D ConversationListDataSou: [size(), UnarchivedConversationListDataSource] 30 ms
09-22 14:17:20.310  4966  4979 I art     : Background sticky concurrent mark sweep GC freed 57531(2MB) AllocSpace objects, 2(40KB) LOS objects, 7% free, 4MB/5MB, paused 4.991ms total 170.867ms
09-22 14:17:20.315  4966  4966 D NetworkSecurityConfig: No Network Security Config specified, using platform default
09-22 14:17:20.328  4966  5012 I MegaphoneDatabase: onOpen()
09-22 14:17:20.343  4966  4966 D LoggingFragment: [ConversationListFragmen] onStart()
09-22 14:17:20.362  4966  4966 I ApplicationContext: App is now visible.
09-22 14:17:20.379  4966  5012 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:20.382  4966  4966 D FrameRateTracker: Beginning frame rate tracking. Screen refresh rate: 58.00 hz, or 17.24 ms per frame.
09-22 14:17:20.392  4966  4966 D ApplicationContext: onStart() took 32 ms
09-22 14:17:20.407  4966  5002 D IncomingMessageObserver: Network: true, Foreground: true, FCM: true, Censored: false, Registered: true, Websocket Registered: true, Proxy: false
09-22 14:17:20.407  4966  5002 I IncomingMessageObserver: Making websocket connection....
09-22 14:17:20.407  4966  4966 D MediaBrowserCompat: Connecting to a MediaBrowserService.
09-22 14:17:20.444  4966  5002 I WebSocketConnection: [normal:163473007] connect()
09-22 14:17:20.454  4966  4979 I art     : Background partial concurrent mark sweep GC freed 22830(1341KB) AllocSpace objects, 0(0B) LOS objects, 39% free, 4MB/7MB, paused 6.296ms total 139.379ms
09-22 14:17:20.460  4966  5017 W art     : Before Android 4.1, method boolean org.thoughtcrime.securesms.components.emoji.EmojiTextView.isSingleLine() would have incorrectly overridden the package-private method in android.widget.TextView
09-22 14:17:20.463  4966  5007 I JobRunner: [JOB::5f2ea253-766f-413f-bbe5-f9ef9edef5e6][RefreshPreKeysJob][1] Running job. (Time Since Submission: 473 ms, Lifespan: 2592000000 ms, Run Attempt: 1/Unlimited)
09-22 14:17:20.464  4966  5008 W art     : Long monitor contention with owner signal-bounded-2 (5000) at com.fasterxml.jackson.databind.ser.impl.ReadOnlyClassToSerializerMap com.fasterxml.jackson.databind.ser.SerializerCache.getReadOnlyLookupMap()(SerializerCache.java:50) waiters=4 in org.thoughtcrime.securesms.jobmanager.Job org.thoughtcrime.securesms.jobmanager.JobController.pullNextEligibleJobForExecution(org.thoughtcrime.securesms.jobmanager.JobPredicate) for 458ms
09-22 14:17:20.492  4966  5010 W art     : Long monitor contention with owner signal-bounded-2 (5000) at com.fasterxml.jackson.databind.ser.impl.ReadOnlyClassToSerializerMap com.fasterxml.jackson.databind.ser.SerializerCache.getReadOnlyLookupMap()(SerializerCache.java:50) waiters=5 in org.thoughtcrime.securesms.jobmanager.Job org.thoughtcrime.securesms.jobmanager.JobController.pullNextEligibleJobForExecution(org.thoughtcrime.securesms.jobmanager.JobPredicate) for 486ms
09-22 14:17:20.493  4966  5008 I JobRunner: [JOB::3eeebfd8-1ef1-417f-9568-c409ba30207e][StorageSyncJob][2] Running job. (Time Since Submission: 358 ms, Lifespan: 86400000 ms, Run Attempt: 1/3)
09-22 14:17:20.495  4966  5011 W art     : Long monitor contention with owner signal-bounded-2 (5000) at com.fasterxml.jackson.databind.ser.impl.ReadOnlyClassToSerializerMap com.fasterxml.jackson.databind.ser.SerializerCache.getReadOnlyLookupMap()(SerializerCache.java:50) waiters=6 in org.thoughtcrime.securesms.jobmanager.Job org.thoughtcrime.securesms.jobmanager.JobController.pullNextEligibleJobForExecution(org.thoughtcrime.securesms.jobmanager.JobPredicate) for 488ms
09-22 14:17:20.498  4966  5009 W art     : Long monitor contention with owner signal-JobRunner-1 (5007) at org.thoughtcrime.securesms.jobmanager.Job org.thoughtcrime.securesms.jobmanager.JobController.pullNextEligibleJobForExecution(org.thoughtcrime.securesms.jobmanager.JobPredicate)(JobController.java:-1) waiters=4 in org.thoughtcrime.securesms.jobmanager.Job org.thoughtcrime.securesms.jobmanager.JobController.pullNextEligibleJobForExecution(org.thoughtcrime.securesms.jobmanager.JobPredicate) for 356ms
09-22 14:17:20.499  4966  5008 I StorageSyncJob: Doesn't have a PIN. Skipping.
09-22 14:17:20.503  4966  5008 I JobRunner: [JOB::3eeebfd8-1ef1-417f-9568-c409ba30207e][StorageSyncJob][2] Job finished with result SUCCESS in 14 ms. (Time Since Submission: 372 ms, Lifespan: 86400000 ms, Run Attempt: 1/3)
09-22 14:17:20.505  4966  4966 I JobManager: onConstraintMet(CellServiceConstraintOb)
09-22 14:17:20.506  4966  5000 I FeatureFlags: Scheduling remote config refresh.
09-22 14:17:20.508  4966  4966 I JobManager: onConstraintMet(NetworkConstraintObserv)
09-22 14:17:20.540  4966  5000 I Job     : [JOB::3eb340f1-4fbc-4b71-876a-2ce66c5c4aff][RemoteConfigRefreshJob] onSubmit() (Time Since Submission: 28 ms, Lifespan: 86400000 ms, Run Attempt: 1/Unlimited)
09-22 14:17:20.550  4966  5009 I JobRunner: [JOB::3eb340f1-4fbc-4b71-876a-2ce66c5c4aff][RemoteConfigRefreshJob][3] Running job. (Time Since Submission: 14 ms, Lifespan: 86400000 ms, Run Attempt: 1/Unlimited)
09-22 14:17:20.595  4966  5018 E         : Device driver API match
09-22 14:17:20.595  4966  5018 E         : Device driver API version: 29
09-22 14:17:20.595  4966  5018 E         : User space API version: 29 
09-22 14:17:20.595  4966  5018 E         : mali: REVISION=Linux-r3p2-01rel3 BUILD_DATE=Tue Jul 22 19:59:34 KST 2014 
09-22 14:17:20.642  4966  5018 I OpenGLRenderer: Initialized EGL, version 1.4
09-22 14:17:20.642  4966  5018 D OpenGLRenderer: Swap behavior 1
09-22 14:17:20.751  4966  4979 I art     : Background sticky concurrent mark sweep GC freed 40226(1854KB) AllocSpace objects, 6(516KB) LOS objects, 14% free, 6MB/7MB, paused 4.409ms total 104.399ms
09-22 14:17:20.770  4966  4995 D LogDatabase: [trim] keepers-size: 100  binary-search: 1035  delete: 94  total: 1229
09-22 14:17:20.812  4966  5002 I WebSocketConnection: [unidentified:25413809] connect()
09-22 14:17:20.827  4966  4966 I ExoPlayerImpl: Init cd43122 [ExoPlayerLib/2.15.0] [t03g, GT-N7100, samsung, 25]
09-22 14:17:20.874  4966  4966 W FrameRateTracker: Bad frame! Took 362 ms (20 dropped frames, or 2.76 FPS)
09-22 14:17:20.945  2905  2947 I ActivityManager: Displayed org.thoughtcrime.securesms/.RoutingActivity: +2s100ms
09-22 14:17:21.016  4966  4979 I art     : Background partial concurrent mark sweep GC freed 20150(1172KB) AllocSpace objects, 1(376KB) LOS objects, 40% free, 6MB/10MB, paused 9.766ms total 176.491ms
09-22 14:17:21.022  4966  5002 D IncomingMessageObserver: Network: true, Foreground: true, FCM: true, Censored: false, Registered: true, Websocket Registered: true, Proxy: false
09-22 14:17:21.023  4966  5002 D IncomingMessageObserver: Reading message...
09-22 14:17:21.183  4966  4973 I art     : Do full code cache collection, code=79KB, data=125KB
09-22 14:17:21.185  4966  4973 I art     : Starting a blocking GC JitCodeCache
09-22 14:17:21.185  4966  4973 I art     : After code cache collection, code=57KB, data=51KB
09-22 14:17:21.209  4966  5027 I WebSocketConnection: [normal:163473007] onOpen() connected
09-22 14:17:21.226  4966  5002 I IncomingMessageObserver: Network was newly-drained. Enqueuing a job to listen for decryption draining.
09-22 14:17:21.238  4966  5002 I Job     : [JOB::81d727a0-30be-48c4-8132-ff66b39c2ab0][PushDecryptDrainedJob] onSubmit() (Time Since Submission: 10 ms, Lifespan: Immortal, Run Attempt: 1/1)
09-22 14:17:21.243  4966  5008 I JobRunner: [JOB::81d727a0-30be-48c4-8132-ff66b39c2ab0][PushDecryptDrainedJob][2] Running job. (Time Since Submission: 16 ms, Lifespan: Immortal, Run Attempt: 1/1)
09-22 14:17:21.246  4966  5002 D IncomingMessageObserver: Network: true, Foreground: true, FCM: true, Censored: false, Registered: true, Websocket Registered: true, Proxy: false
09-22 14:17:21.247  4966  5002 D IncomingMessageObserver: Reading message...
09-22 14:17:21.248  4966  5008 I PushDecryptDrainedJob: Decryptions are caught-up.
09-22 14:17:21.248  4966  5008 I IncomingMessageObserver: Decryptions newly drained.
09-22 14:17:21.248  4966  5008 I JobManager: onConstraintMet(DecryptionsDrainedConst)
09-22 14:17:21.254  4966  5008 I JobRunner: [JOB::81d727a0-30be-48c4-8132-ff66b39c2ab0][PushDecryptDrainedJob][2] Job finished with result SUCCESS in 10 ms. (Time Since Submission: 26 ms, Lifespan: Immortal, Run Attempt: 1/1)
09-22 14:17:21.343  4966  5012 W art     : Long monitor contention with owner signal-JobRunner-1 (5007) at org.whispersystems.signalservice.api.SignalServiceAccountManager org.thoughtcrime.securesms.dependencies.ApplicationDependencies.getSignalServiceAccountManager()(ApplicationDependencies.java:130) waiters=0 in org.thoughtcrime.securesms.recipients.LiveRecipientCache org.thoughtcrime.securesms.dependencies.ApplicationDependencies.getRecipientCache() for 847ms
09-22 14:17:21.345  4966  5000 W art     : Long monitor contention with owner signal-JobRunner-1 (5007) at org.whispersystems.signalservice.api.SignalServiceAccountManager org.thoughtcrime.securesms.dependencies.ApplicationDependencies.getSignalServiceAccountManager()(ApplicationDependencies.java:130) waiters=1 in org.thoughtcrime.securesms.recipients.LiveRecipientCache org.thoughtcrime.securesms.dependencies.ApplicationDependencies.getRecipientCache() for 802ms
09-22 14:17:21.347  4966  5009 W art     : Long monitor contention with owner signal-JobRunner-1 (5007) at org.whispersystems.signalservice.api.SignalServiceAccountManager org.thoughtcrime.securesms.dependencies.ApplicationDependencies.getSignalServiceAccountManager()(ApplicationDependencies.java:130) waiters=2 in org.whispersystems.signalservice.api.SignalServiceAccountManager org.thoughtcrime.securesms.dependencies.ApplicationDependencies.getSignalServiceAccountManager() for 796ms
09-22 14:17:21.350  4966  5016 W art     : Long monitor contention with owner signal-JobRunner-1 (5007) at org.whispersystems.signalservice.api.SignalServiceAccountManager org.thoughtcrime.securesms.dependencies.ApplicationDependencies.getSignalServiceAccountManager()(ApplicationDependencies.java:130) waiters=3 in org.thoughtcrime.securesms.recipients.LiveRecipientCache org.thoughtcrime.securesms.dependencies.ApplicationDependencies.getRecipientCache() for 725ms
09-22 14:17:21.377  4966  5016 D ConversationListDataSou: [load(0, 16), UnarchivedConversationListDataSource] cursor: 340  cache-recipients: 752  total: 1092
09-22 14:17:21.379  4966  5035 I WebSocketConnection: [unidentified:25413809] onOpen() connected
09-22 14:17:21.392  4966  5012 I PinsForAllSchedule: seenCount: 0,  lastSeen: 0,  firstVisible: 0,  currentTime: 1632313040495, result: true
09-22 14:17:21.443  4966  5000 D LiveRecipientCache: Warming up 16 thread recipients.
09-22 14:17:21.454  4966  5000 D LiveRecipientCache: Warmed up 1 contact recipient.
09-22 14:17:21.456  4966  5000 D LiveRecipientCache: [recipient-warm-up] thread: 101  contact: 8  total: 109
09-22 14:17:21.742  4966  5007 I RefreshPreKeysJob: Available keys: 93
09-22 14:17:21.742  4966  5007 I RefreshPreKeysJob: Available keys sufficient.
09-22 14:17:21.745  4966  5007 I JobRunner: [JOB::5f2ea253-766f-413f-bbe5-f9ef9edef5e6][RefreshPreKeysJob][1] Job finished with result SUCCESS in 1282 ms. (Time Since Submission: 1755 ms, Lifespan: 2592000000 ms, Run Attempt: 1/Unlimited)
09-22 14:17:21.774  4966  5009 I FeatureFlags: Triggering change listener for: android.senderKey.5
09-22 14:17:21.781  4966  5009 I Job     : [JOB::55c2cd49-1ceb-4e80-871b-49eccbe4b506][RefreshAttributesJob] onSubmit() (Time Since Submission: 7 ms, Lifespan: Immortal, Run Attempt: 1/1)
09-22 14:17:21.785  4966  5009 I FeatureFlags: [Memory] Before: {android.animatedStickerMinMemory=193, android.animatedStickerMinTotalMemory=3072, android.automaticSessionReset.2=true, android.automaticSessionResetInterval=3600, android.calling.groupCallRinging=false, android.defaultMaxBackoff=60, android.mediaQuality.levels=1:2,61:2,81:2,82:2,65:2,31:2,47:2,41:2,32:2,385:2,971:2,974:2,49:2,33:2,*:1, android.mp4GifSendSupport.2=false, android.okhttpAutomaticRetry=true, android.retryReceiptLifespan=3600000, android.retryReceipts=true, android.retryRespondMaxAge=1209600000, android.senderKey.5=true, android.suggestSmsBlacklist=91, cds.syncInterval.seconds=604800, global.calling.maxGroupCallRingSize=16}
09-22 14:17:21.785  4966  5009 I FeatureFlags: [Memory] After : {android.animatedStickerMinMemory=193, android.animatedStickerMinTotalMemory=3072, android.automaticSessionReset.2=true, android.automaticSessionResetInterval=3600, android.calling.groupCallRinging=false, android.defaultMaxBackoff=60, android.mediaQuality.levels=1:2,61:2,81:2,82:2,65:2,31:2,47:2,41:2,32:2,385:2,971:2,974:2,49:2,33:2,*:1, android.mp4GifSendSupport.2=false, android.okhttpAutomaticRetry=true, android.retryReceiptLifespan=3600000, android.retryReceipts=true, android.retryRespondMaxAge=1209600000, android.senderKey.5=true, android.suggestSmsBlacklist=91, cds.syncInterval.seconds=604800, global.calling.maxGroupCallRingSize=16}
09-22 14:17:21.785  4966  5009 I FeatureFlags: [Disk]   Before: {}
09-22 14:17:21.785  4966  5009 I FeatureFlags: [Disk]   After : {android.animatedStickerMinMemory=193, android.animatedStickerMinTotalMemory=3072, android.automaticSessionReset.2=true, android.automaticSessionResetInterval=3600, android.calling.groupCallRinging=false, android.defaultMaxBackoff=60, android.donate=false, android.internalUser=false, android.mediaQuality.levels=1:2,61:2,81:2,82:2,65:2,31:2,47:2,41:2,32:2,385:2,971:2,974:2,49:2,33:2,*:1, android.mp4GifSendSupport.2=false, android.okhttpAutomaticRetry=true, android.retryReceiptLifespan=3600000, android.retryReceipts=true, android.retryRespondMaxAge=1209600000, android.senderKey.5=true, android.suggestSmsBlacklist=91, android.usernames=false, cds.syncInterval.seconds=604800, global.calling.maxGroupCallRingSize=16, global.groupsv2.groupSizeHardLimit=1001, global.groupsv2.maxGroupSize=151}
09-22 14:17:21.791  4966  5008 I JobRunner: [JOB::55c2cd49-1ceb-4e80-871b-49eccbe4b506][RefreshAttributesJob][2] Running job. (Time Since Submission: 15 ms, Lifespan: Immortal, Run Attempt: 1/1)
09-22 14:17:21.792  4966  5009 I JobRunner: [JOB::3eb340f1-4fbc-4b71-876a-2ce66c5c4aff][RemoteConfigRefreshJob][3] Job finished with result SUCCESS in 1238 ms. (Time Since Submission: 1252 ms, Lifespan: 86400000 ms, Run Attempt: 1/Unlimited)
09-22 14:17:21.795  4966  5008 I RefreshAttributesJob: Calling setAccountAttributes() reglockV1? false, reglockV2? false, pin? false
09-22 14:17:21.795  4966  5008 I RefreshAttributesJob:     Phone number discoverable : true
09-22 14:17:21.795  4966  5008 I RefreshAttributesJob:   Capabilities:
09-22 14:17:21.795  4966  5008 I RefreshAttributesJob:     Storage? false
09-22 14:17:21.795  4966  5008 I RefreshAttributesJob:     GV2? true
09-22 14:17:21.795  4966  5008 I RefreshAttributesJob:     GV1 Migration? true
09-22 14:17:21.795  4966  5008 I RefreshAttributesJob:     Sender Key? true
09-22 14:17:21.795  4966  5008 I RefreshAttributesJob:     Announcement Groups? true
09-22 14:17:21.795  4966  5008 I RefreshAttributesJob:     Change Number? false
09-22 14:17:21.795  4966  5008 I RefreshAttributesJob:     UUID? false
09-22 14:17:21.872  4966  4973 I art     : Do partial code cache collection, code=105KB, data=123KB
09-22 14:17:21.874  4966  4973 I art     : After code cache collection, code=104KB, data=123KB
09-22 14:17:21.874  4966  4973 I art     : Increasing code cache capacity to 512KB
09-22 14:17:21.962  4966  5008 I Job     : [JOB::fa273617-ba76-43d8-9e34-17862c10fc19][RefreshOwnProfileJob] onSubmit() (Time Since Submission: 4 ms, Lifespan: Immortal, Run Attempt: 1/10)
09-22 14:17:21.969  4966  5008 I JobRunner: [JOB::55c2cd49-1ceb-4e80-871b-49eccbe4b506][RefreshAttributesJob][2] Job finished with result SUCCESS in 178 ms. (Time Since Submission: 193 ms, Lifespan: Immortal, Run Attempt: 1/1)
09-22 14:17:21.971  4966  5007 I JobRunner: [JOB::fa273617-ba76-43d8-9e34-17862c10fc19][RefreshOwnProfileJob][1] Running job. (Time Since Submission: 10 ms, Lifespan: Immortal, Run Attempt: 1/10)
09-22 14:17:21.972  4966  5000 I RetrieveProfileJob: Optimistically refreshing 16 eligible recipient(s).
09-22 14:17:22.087  4966  5000 W JobController: [JOB::ab120bfa-f16e-4135-84d0-c6617076047a][RefreshOwnProfileJob] Already at the max instance count. Factory limit: 1, Queue limit: -1. Skipping. (Time Since Submission: 1 ms, Lifespan: Immortal, Run Attempt: 1/10)
09-22 14:17:22.096  4966  5000 I Job     : [JOB::f629fdd1-5e04-4d94-af15-2eaf944097c9][RetrieveProfileJob] onSubmit() (Time Since Submission: 9 ms, Lifespan: Immortal, Run Attempt: 1/3)
09-22 14:17:22.103  4966  5009 I JobRunner: [JOB::f629fdd1-5e04-4d94-af15-2eaf944097c9][RetrieveProfileJob][3] Running job. (Time Since Submission: 12 ms, Lifespan: Immortal, Run Attempt: 1/3)
09-22 14:17:22.213  4966  4999 D EmojiFiles: Verifying all name files exist.
09-22 14:17:22.218  4966  4999 D EmojiFiles: All names exist? true
09-22 14:17:22.326  4966  5007 D RefreshOwnProfileJob: Saving empty about.
09-22 14:17:22.327  4966  5007 D RefreshOwnProfileJob: Saving empty emoji.
09-22 14:17:22.338  4966  5007 I Job     : [JOB::f5ba547b-1139-44dc-b00f-c9610ec7442c][RetrieveProfileAvatarJob] onSubmit() (Time Since Submission: 9 ms, Lifespan: 3600000 ms, Run Attempt: 1/1)
09-22 14:17:22.350  4966  5007 I JobRunner: [JOB::fa273617-ba76-43d8-9e34-17862c10fc19][RefreshOwnProfileJob][1] Job finished with result SUCCESS in 382 ms. (Time Since Submission: 392 ms, Lifespan: Immortal, Run Attempt: 1/10)
09-22 14:17:22.350  4966  5008 I JobRunner: [JOB::f5ba547b-1139-44dc-b00f-c9610ec7442c][RetrieveProfileAvatarJob][2] Running job. (Time Since Submission: 16 ms, Lifespan: 3600000 ms, Run Attempt: 1/1)
09-22 14:17:22.351  4966  5008 W RetrieveProfileAvatarJo: Already retrieved profile avatar: null
09-22 14:17:22.352  4966  5008 I JobRunner: [JOB::f5ba547b-1139-44dc-b00f-c9610ec7442c][RetrieveProfileAvatarJob][2] Job finished with result SUCCESS in 2 ms. (Time Since Submission: 18 ms, Lifespan: 3600000 ms, Run Attempt: 1/1)
09-22 14:17:22.476  4966  4979 I art     : Background sticky concurrent mark sweep GC freed 21948(904KB) AllocSpace objects, 0(0B) LOS objects, 7% free, 9MB/10MB, paused 6.467ms total 41.918ms
09-22 14:17:22.481  4966  5047 I libsignal-client: rust/bridge/jni/src/logging.rs:173: Initializing libsignal-client version:0.9.4
09-22 14:17:22.492  4966  5047 I IdentityDatabase: Could not find identity for UUID. Attempting E164.
09-22 14:17:22.494  4966  5047 I IdentityDatabase: Could not find identity for E164 either.
09-22 14:17:22.494  4966  5047 W RetrieveProfileJob: Still first use...
09-22 14:17:22.495  4966  5047 I RetrieveProfileJob: Marking recipient UD status as ENABLED after verification.
09-22 14:17:22.557  4966  5047 I Job     : [JOB::67b79c4f-24f6-423e-98d9-475d3c15dcf6][RetrieveProfileAvatarJob] onSubmit() (Time Since Submission: 5 ms, Lifespan: 3600000 ms, Run Attempt: 1/1)
09-22 14:17:22.563  4966  5008 I JobRunner: [JOB::67b79c4f-24f6-423e-98d9-475d3c15dcf6][RetrieveProfileAvatarJob][2] Running job. (Time Since Submission: 10 ms, Lifespan: 3600000 ms, Run Attempt: 1/1)
09-22 14:17:22.577  4966  5047 I RetrieveProfileJob: Marking recipient UD status as ENABLED after verification.
09-22 14:17:22.649  4966  5047 I RetrieveProfileJob: Marking recipient UD status as ENABLED after verification.
09-22 14:17:22.742  4966  5047 I IdentityDatabase: Could not find identity for UUID. Attempting E164.
09-22 14:17:22.744  4966  5047 I IdentityDatabase: Could not find identity for E164 either.
09-22 14:17:22.745  4966  5047 W RetrieveProfileJob: Still first use...
09-22 14:17:22.746  4966  5047 I RetrieveProfileJob: Marking recipient UD status as ENABLED after verification.
09-22 14:17:22.808  4966  4966 I AppStartup: First render has finished. Cold Start: 3644 ms, Render Time: 2849 ms
09-22 14:17:22.808  4966  4966 D ConversationListFragmen: [startup] data-set: 1341  first-render: 1423  total: 2764
09-22 14:17:22.808  4966  4966 I Choreographer: Skipped 82 frames!  The application may be doing too much work on its main thread.
09-22 14:17:22.809  4966  4966 W FrameRateTracker: Bad frame! Took 1431 ms (83 dropped frames, or 0.70 FPS)
09-22 14:17:22.815  4966  4999 I DownloadLatestEmojiData: Scheduling DownloadLatestEmojiDataJob.
09-22 14:17:22.820  4966  4999 I Job     : [JOB::f122c77c-fd69-477c-b3cb-8dcfd6a12628][DownloadLatestEmojiDataJob] onSubmit() (Time Since Submission: 5 ms, Lifespan: 86400000 ms, Run Attempt: 1/5)
09-22 14:17:22.853  4966  5008 I JobRunner: [JOB::67b79c4f-24f6-423e-98d9-475d3c15dcf6][RetrieveProfileAvatarJob][2] Job finished with result SUCCESS in 291 ms. (Time Since Submission: 301 ms, Lifespan: 3600000 ms, Run Attempt: 1/1)
09-22 14:17:22.854  4966  5000 I EmojiSearchIndexDownloa: Need to check. It's been 1632313042854 ms since the last check.
09-22 14:17:22.858  4966  5007 I JobRunner: [JOB::f122c77c-fd69-477c-b3cb-8dcfd6a12628][DownloadLatestEmojiDataJob][1] Running job. (Time Since Submission: 42 ms, Lifespan: 86400000 ms, Run Attempt: 1/5)
09-22 14:17:22.865  4966  5000 I Job     : [JOB::cbee827c-595c-4bd9-bf46-1b443639aa29][EmojiSearchIndexDownloadJob] onSubmit() (Time Since Submission: 8 ms, Lifespan: 86400000 ms, Run Attempt: 1/Unlimited)
09-22 14:17:22.871  4966  4993 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:22.883  4966  4979 I art     : Background partial concurrent mark sweep GC freed 121030(4MB) AllocSpace objects, 3(120KB) LOS objects, 39% free, 7MB/12MB, paused 6.849ms total 178.111ms
09-22 14:17:22.893  4966  5008 I JobRunner: [JOB::cbee827c-595c-4bd9-bf46-1b443639aa29][EmojiSearchIndexDownloadJob][2] Running job. (Time Since Submission: 35 ms, Lifespan: 86400000 ms, Run Attempt: 1/Unlimited)
09-22 14:17:22.933  4966  5047 I Job     : [JOB::e69f5f36-1ed3-4950-8472-0a8bc3715cfe][RetrieveProfileAvatarJob] onSubmit() (Time Since Submission: 7 ms, Lifespan: 3600000 ms, Run Attempt: 1/1)
09-22 14:17:22.974  4966  4993 I SQLiteConnection: Database keying operation returned:0
09-22 14:17:22.983  4966  5047 I IdentityDatabase: Could not find identity for UUID. Attempting E164.
09-22 14:17:22.988  4966  5047 I IdentityDatabase: Could not find identity for E164 either.
09-22 14:17:22.992  4966  5047 W RetrieveProfileJob: Still first use...
09-22 14:17:22.993  4966  5047 I RetrieveProfileJob: Marking recipient UD status as ENABLED after verification.
09-22 14:17:23.022  4966  4993 D LocalMetrics: [cold-start-conversation-list] total: 3640 | application-create: 698, start-activity: 93, data-loaded: 1427, render: 1422
09-22 14:17:23.092  4966  5047 I IdentityDatabase: Could not find identity for UUID. Attempting E164.
09-22 14:17:23.094  4966  5047 I IdentityDatabase: Could not find identity for E164 either.
09-22 14:17:23.100  4966  5047 W RetrieveProfileJob: Still first use...
09-22 14:17:23.101  4966  5047 I RetrieveProfileJob: Marking recipient UD status as ENABLED after verification.
09-22 14:17:23.141  4966  5048 I Job     : [JOB::32d92fd6-2363-4953-b3de-7308568e36f3][RetrieveProfileAvatarJob] onSubmit() (Time Since Submission: 10 ms, Lifespan: 3600000 ms, Run Attempt: 1/1)
09-22 14:17:23.171  4966  5048 I RetrieveProfileJob: Marking recipient UD status as ENABLED after verification.
09-22 14:17:23.188  4966  5008 D EmojiSearchIndexDownloa: Found an exact match: en
09-22 14:17:23.188  4966  5008 I EmojiSearchIndexDownloa: Need to get a new search index. Downloading version: 2, language: en
09-22 14:17:23.251  4966  5048 I Job     : [JOB::cdacf866-f91b-4055-9d2a-09ead495ee80][RetrieveProfileAvatarJob] onSubmit() (Time Since Submission: 5 ms, Lifespan: 3600000 ms, Run Attempt: 1/1)
09-22 14:17:23.292  4966  5048 I IdentityDatabase: Could not find identity for UUID. Attempting E164.
09-22 14:17:23.296  4966  5048 I IdentityDatabase: Could not find identity for E164 either.
09-22 14:17:23.298  4966  5048 W RetrieveProfileJob: Still first use...
09-22 14:17:23.299  4966  5048 I RetrieveProfileJob: Marking recipient UD status as ENABLED after verification.
09-22 14:17:23.300  4966  4979 I art     : Background sticky concurrent mark sweep GC freed 61235(2MB) AllocSpace objects, 6(556KB) LOS objects, 9% free, 11MB/12MB, paused 2.931ms total 204.288ms
09-22 14:17:23.464  4966  5048 I Job     : [JOB::da36ba04-b586-4fa3-87e2-b92994aa4ea8][RetrieveProfileAvatarJob] onSubmit() (Time Since Submission: 4 ms, Lifespan: 3600000 ms, Run Attempt: 1/1)
09-22 14:17:23.518  4966  4979 I art     : Background partial concurrent mark sweep GC freed 60495(2MB) AllocSpace objects, 8(1328KB) LOS objects, 40% free, 9MB/16MB, paused 3.652ms total 207.607ms
09-22 14:17:23.534  4966  5048 I IdentityDatabase: Could not find identity for UUID. Attempting E164.
09-22 14:17:23.553  4966  5048 I IdentityDatabase: Could not find identity for E164 either.
09-22 14:17:23.554  4966  5048 W RetrieveProfileJob: Still first use...
09-22 14:17:23.554  4966  5048 I RetrieveProfileJob: Marking recipient UD status as ENABLED after verification.
09-22 14:17:23.665  4966  5048 I IdentityDatabase: Could not find identity for UUID. Attempting E164.
09-22 14:17:23.667  4966  5048 I IdentityDatabase: Could not find identity for E164 either.
09-22 14:17:23.667  4966  5048 W RetrieveProfileJob: Still first use...
09-22 14:17:23.668  4966  5048 I RetrieveProfileJob: Marking recipient UD status as ENABLED after verification.
09-22 14:17:23.787  4966  4999 D EmojiFiles: Verifying all name files exist.
09-22 14:17:23.791  4966  5007 D EmojiFiles: Verifying all name files exist.
09-22 14:17:23.794  4966  4999 D EmojiFiles: All names exist? true
09-22 14:17:23.805  4966  5007 D EmojiFiles: All names exist? true
09-22 14:17:23.822  4966  5048 I Job     : [JOB::09ac99a3-0588-44b6-ac35-5db4ef71f8f8][RetrieveProfileAvatarJob] onSubmit() (Time Since Submission: 17 ms, Lifespan: 3600000 ms, Run Attempt: 1/1)
09-22 14:17:23.839  4966  5007 D DownloadLatestEmojiData: LocalVersion: 2, SeverVersion: 2, Bucket: xxhdpi
09-22 14:17:23.840  4966  5007 D DownloadLatestEmojiData: Already have latest emoji data. Skipping.
09-22 14:17:23.842  4966  5007 I JobRunner: [JOB::f122c77c-fd69-477c-b3cb-8dcfd6a12628][DownloadLatestEmojiDataJob][1] Job finished with result SUCCESS in 987 ms. (Time Since Submission: 1025 ms, Lifespan: 86400000 ms, Run Attempt: 1/5)
09-22 14:17:23.846  4966  4999 D EmojiFiles: Verifying all name files exist.
09-22 14:17:23.855  4966  5007 I JobRunner: [JOB::e69f5f36-1ed3-4950-8472-0a8bc3715cfe][RetrieveProfileAvatarJob][1] Running job. (Time Since Submission: 929 ms, Lifespan: 3600000 ms, Run Attempt: 1/1)
09-22 14:17:23.859  4966  4999 D EmojiFiles: All names exist? true
09-22 14:17:23.886  4966  4966 I Choreographer: Skipped 61 frames!  The application may be doing too much work on its main thread.
09-22 14:17:23.887  4966  4966 W FrameRateTracker: Bad frame! Took 1068 ms (62 dropped frames, or 0.94 FPS)
09-22 14:17:23.970  4966  4979 I art     : Background sticky concurrent mark sweep GC freed 57180(2MB) AllocSpace objects, 6(872KB) LOS objects, 22% free, 12MB/16MB, paused 4.742ms total 110.235ms
09-22 14:17:24.105  4966  4973 I art     : Do full code cache collection, code=200KB, data=251KB
09-22 14:17:24.107  4966  4973 I art     : Starting a blocking GC JitCodeCache
09-22 14:17:24.108  4966  4973 I art     : After code cache collection, code=185KB, data=170KB
@oliv3r
Copy link
Author

oliv3r commented Oct 21, 2021

So upgraded the android 9 and the issue went away; so looks like something with android version 7 is a miss. Sadly, android 7 is the last on that works best for the note2. Hope that helps a little in shedding some more information on the issue ...

@stale
Copy link

stale bot commented Jan 25, 2022

Is this still relevant? If so, what is blocking it? Is there anything you can do to help move it forward?

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.

@stale stale bot added the wontfix label Jan 25, 2022
@oliv3r
Copy link
Author

oliv3r commented Jan 26, 2022

Yeah upgrading from android 7 to android 9+ made it go away, so this would need to be reproduced on android 7 ...

@stale stale bot removed the wontfix label Jan 26, 2022
@oliv3r oliv3r mentioned this issue Feb 1, 2022
Closed
4 tasks
@stale
Copy link

stale bot commented Mar 27, 2022

Is this still relevant? If so, what is blocking it? Is there anything you can do to help move it forward?

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs.

@stale stale bot added the wontfix label Mar 27, 2022
@oliv3r
Copy link
Author

oliv3r commented Mar 31, 2022

I suppose for android 7 this is probably still relevant ...

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
wontfix
Milestone
No milestone
Development

No branches or pull requests
2 participants
@oliv3r @greyson-signal