android-password-store / Android-Password-Store

Android application compatible with ZX2C4's Pass command line application
https://passwordstore.app
GNU General Public License v3.0
2.59k stars 270 forks source link

[BUG] Timeout expired and Socket closed errors trying to sync the repo #2248

Closed WhiteBlackGoose closed 2 years ago

WhiteBlackGoose commented 2 years ago

Describe the bug

Trying to clone the repo using SSH yields these errors (works on 1.13.5)

Steps to reproduce

Steps to reproduce the behavior:

  1. Install the latest snapshot
  2. Fill in the details, add the public ssh keys to github
  3. Press clone
  4. It gives either of those two errors

Expected behavior

It clones

Screenshots

No response

Device information

Additional context

Basically now it showed me "timeout expired error". I recorded it. Then I swiped again and it gave me socket error. I recorded both logs pw-store-socket-closed.log pw-store-timeout-expired.log

Here's the diff between them (so it shows the lines which appeared after I requested cloning for the second time)

11-13 00:14:35.811 26328 26328 I ViewRootImpl@267fbbc[PasswordStore]: ViewPostIme pointer 0
11-13 00:14:35.813 26328 26328 I GestureDetector: obtain mCurrentDownEvent. id: 949876300 caller: androidx.recyclerview.selection.EventRouter.onInterceptTouchEvent:102 me.zhanghai.android.fastscroll.FixOnItemTouchListenerRecyclerView$OnItemTouchDispatcher.onInterceptTouchEvent:23 androidx.recyclerview.widget.RecyclerView.findInterceptingOnItemTouchListener:21 
11-13 00:14:35.822 26328 26328 I GestureDetector: obtain mCurrentMotionEventRaw. action: 2 id: 203902996
11-13 00:14:36.038 26328 26328 I ViewRootImpl@267fbbc[PasswordStore]: ViewPostIme pointer 1
11-13 00:14:36.354 26328 26328 I ViewRootImpl@267fbbc[PasswordStore]: MSG_WINDOW_FOCUS_CHANGED 0 1
11-13 00:14:36.366 26328 26328 D InputTransport: Input channel destroyed: 'ClientS', fd=97
11-13 00:14:36.915 26328 26430 I BiometricPrompt: onAuthenticationSucceeded: 2
11-13 00:14:36.933 26328 26328 D InsetsSourceConsumer: ensureControlAlpha: for ITYPE_NAVIGATION_BAR on app.passwordstore/app.passwordstore.ui.passwords.PasswordStore
11-13 00:14:36.934 26328 26328 D InsetsSourceConsumer: ensureControlAlpha: for ITYPE_STATUS_BAR on app.passwordstore/app.passwordstore.ui.passwords.PasswordStore
11-13 00:14:36.941 26328 26328 I ViewRootImpl@267fbbc[PasswordStore]: MSG_WINDOW_FOCUS_CHANGED 1 1
11-13 00:14:36.942 26328 26382 D SshjSessionFactory: Pinned host key: SHA256:+DiY3wvvV6TuJJhbpZisF/zLDA0zPMSvHdkr4UvCOqU=
11-13 00:14:36.942 26328 26328 D InputMethodManager: startInputInner - Id : 0
11-13 00:14:36.942 26328 26328 I InputMethodManager: startInputInner - mService.startInputOrWindowGainedFocus
11-13 00:14:37.062 26328 26382 I net.schmizz.sshj.transport.TransportImpl: Client identity string: SSH-2.0-OpenSSH_8.2p1 Ubuntu-4ubuntu0.1
11-13 00:14:37.348 26328 26382 I net.schmizz.sshj.transport.TransportImpl: Server identity string: SSH-2.0-babeld-d975cc25
11-13 00:14:37.349 26328 26382 D net.schmizz.concurrent.Promise: Setting <<kex done>> to `null`
11-13 00:14:37.350 26328 26382 D net.schmizz.sshj.transport.KeyExchanger: Sending SSH_MSG_KEXINIT
11-13 00:14:37.350 26328 26706 D net.schmizz.sshj.transport.KeyExchanger: Received SSH_MSG_KEXINIT
11-13 00:14:37.350 26328 26706 D net.schmizz.concurrent.Promise: Awaiting <<kexinit sent>>
11-13 00:14:37.351 26328 26382 D net.schmizz.concurrent.Promise: Setting <<kexinit sent>> to `SOME`
11-13 00:14:37.351 26328 26382 D net.schmizz.concurrent.Promise: Awaiting <<kex done>>
11-13 00:14:37.352 26328 26706 D net.schmizz.sshj.transport.KeyExchanger: Negotiated algorithms: [ kex=curve25519-sha256; sig=ssh-ed25519; c2sCipher=aes128-gcm@openssh.com; s2cCipher=aes128-gcm@openssh.com; c2sMAC=hmac-sha2-512-etm@openssh.com; s2cMAC=hmac-sha2-512-etm@openssh.com; c2sComp=none; s2cComp=none;  ]
11-13 00:14:37.645 26328 26706 D net.schmizz.sshj.transport.KeyExchanger: Received kex followup data
11-13 00:14:37.651 26328 26706 D net.schmizz.sshj.transport.KeyExchanger: Trying to verify host key with FingerprintVerifier{digestAlgorithm='SHA-256'}
11-13 00:14:37.651 26328 26706 D net.schmizz.sshj.transport.KeyExchanger: Sending SSH_MSG_NEWKEYS
11-13 00:14:37.652 26328 26706 D net.schmizz.sshj.transport.KeyExchanger: Received SSH_MSG_NEWKEYS
11-13 00:14:37.652 26328 26706 D net.schmizz.concurrent.Promise: Setting <<kexinit sent>> to `null`
11-13 00:14:37.653 26328 26706 D net.schmizz.concurrent.Promise: Setting <<kex done>> to `SOME`
11-13 00:14:37.653 26328 26382 D net.schmizz.sshj.SSHClient: Key exchange took 0.304 seconds
11-13 00:14:37.654 26328 26382 D net.schmizz.concurrent.Promise: Setting <<service accept>> to `null`
11-13 00:14:37.655 26328 26382 D net.schmizz.sshj.transport.TransportImpl: Sending SSH_MSG_SERVICE_REQUEST for ssh-userauth
11-13 00:14:37.656 26328 26382 D net.schmizz.concurrent.Promise: Awaiting <<service accept>>
11-13 00:14:37.844 26328 26706 D net.schmizz.sshj.transport.TransportImpl: Received SSH_MSG_EXT_INFO
11-13 00:14:37.943 26328 26706 D net.schmizz.sshj.transport.TransportImpl: Setting active service to ssh-userauth
11-13 00:14:37.943 26328 26706 D net.schmizz.concurrent.Promise: Setting <<service accept>> to `SOME`
11-13 00:14:37.944 26328 26382 D net.schmizz.concurrent.Promise: Setting <<authenticated>> to `null`
11-13 00:14:37.945 26328 26382 D net.schmizz.sshj.userauth.UserAuthImpl: Trying `publickey` auth...
11-13 00:14:37.945 26328 26382 D net.schmizz.sshj.userauth.method.AuthPublickey: Attempting authentication using coil.Coil@5bf4969
11-13 00:14:37.948 26328 26382 D net.schmizz.concurrent.Promise: Awaiting <<authenticated>>
11-13 00:14:38.151 26328 26706 D net.schmizz.sshj.userauth.UserAuthImpl: Asking `publickey` method to handle USERAUTH_60 packet
11-13 00:14:38.152 26328 26706 D net.schmizz.sshj.userauth.method.AuthPublickey: Key acceptable, sending signed request
11-13 00:14:38.152 26328 26706 D net.schmizz.sshj.userauth.method.AuthPublickey: Attempting authentication using coil.Coil@5bf4969
11-13 00:14:38.157 26328 26706 E net.schmizz.sshj.transport.TransportImpl: Dying because - User not authenticated
11-13 00:14:38.157 26328 26706 I net.schmizz.sshj.transport.TransportImpl: Disconnected - UNKNOWN
11-13 00:14:38.159 26328 26706 D net.schmizz.sshj.transport.KeyExchanger: Got notified of net.schmizz.sshj.common.SSHException: User not authenticated
11-13 00:14:38.160 26328 26706 D net.schmizz.sshj.userauth.UserAuthImpl: Notified of net.schmizz.sshj.common.SSHException: User not authenticated
11-13 00:14:38.160 26328 26706 D net.schmizz.sshj.transport.TransportImpl: Setting active service to null-service
11-13 00:14:38.161 26328 26382 E net.schmizz.concurrent.Promise: <<authenticated>> woke to: net.schmizz.sshj.userauth.UserAuthException: User not authenticated
11-13 00:14:38.162 26328 26706 D net.schmizz.concurrent.Promise: Setting <<transport close>> to `SOME`
11-13 00:14:38.162 26328 26382 D net.schmizz.concurrent.Promise: Setting <<service accept>> to `null`
11-13 00:14:38.163 26328 26706 D net.schmizz.sshj.transport.Reader: Stopping
11-13 00:14:38.163 26328 26382 D net.schmizz.sshj.transport.TransportImpl: Sending SSH_MSG_SERVICE_REQUEST for ssh-userauth
11-13 00:14:38.169 26328 26328 D PasswordStore: net.schmizz.sshj.transport.TransportException: Socket closed
11-13 00:14:38.169 26328 26328 D PasswordStore:     at net.schmizz.sshj.transport.TransportImpl.write(SourceFile:104)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at net.schmizz.sshj.AbstractService.request(SourceFile:85)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at net.schmizz.sshj.userauth.UserAuthImpl.authenticate(SourceFile:9)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at net.schmizz.sshj.SSHClient.auth(SourceFile:53)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at app.passwordstore.util.git.sshj.SshjSessionFactory.getSession(SourceFile:640)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at org.eclipse.jgit.transport.SshTransport.getSession(SourceFile:31)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at org.eclipse.jgit.transport.TransportGitSsh$SshFetchConnection.<init>(SourceFile:2)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at org.eclipse.jgit.transport.TransportGitSsh.openFetch(Unknown Source:2)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at org.pgpainless.policy.Policy.executeImp(SourceFile:8)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at org.eclipse.jgit.transport.Transport.fetch(SourceFile:128)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at org.eclipse.jgit.api.FetchCommand.call(SourceFile:17)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at org.eclipse.jgit.api.PullCommand.call(SourceFile:34)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at app.passwordstore.util.git.GitCommandExecutor$execute$2$result$1.invokeSuspend(Unknown Source:7)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(SourceFile:9)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at kotlinx.coroutines.DispatchedTask.run(SourceFile:109)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at kotlinx.coroutines.internal.LimitedDispatcher.run(SourceFile:13)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at kotlinx.coroutines.scheduling.TaskImpl.run(SourceFile:3)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(SourceFile:77)
11-13 00:14:38.169 26328 26328 D PasswordStore: Caused by: java.net.SocketException: Socket closed
11-13 00:14:38.169 26328 26328 D PasswordStore:     at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:119)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at java.net.SocketOutputStream.write(SocketOutputStream.java:156)
11-13 00:14:38.169 26328 26328 D PasswordStore:     at net.schmizz.sshj.transport.TransportImpl.write(SourceFile:85)
11-13 00:14:38.169 26328 26328 D PasswordStore:     ... 17 more
11-13 00:14:38.170 26328 26328 I Dialog  : mIsDeviceDefault = false, mIsSamsungBasicInteraction = false, isMetaDataInActivity = false
11-13 00:14:38.171 26328 26328 I DecorView: [INFO] isPopOver=false, config=false
11-13 00:14:38.171 26328 26328 I DecorView: updateCaptionType >> DecorView@adc3a5d[], isFloating=true, isApplication=true, hasWindowControllerCallback=false, hasWindowDecorCaption=false
11-13 00:14:38.171 26328 26328 D DecorView: setCaptionType = 0, this = DecorView@adc3a5d[]
11-13 00:14:38.174 26328 26328 D ScrollView: initGoToTop
11-13 00:14:38.178 26328 26328 I DecorView: notifyKeepScreenOnChanged: keepScreenOn=false
11-13 00:14:38.182 26328 26328 I ViewRootImpl@1c574cd[PasswordStore]: setView = com.android.internal.policy.DecorView@adc3a5d TM=true
11-13 00:14:38.188 26328 26328 I BufferQueueConsumer: [](id:66d800000005,api:0,p:-1,c:26328) connect: controlledByApp=false
11-13 00:14:38.189 26328 26328 I BLASTBufferQueue: [ViewRootImpl@1c574cd[PasswordStore]#5] constructor()
11-13 00:14:38.189 26328 26328 D InsetsSourceConsumer: ensureControlAlpha: for ITYPE_NAVIGATION_BAR on app.passwordstore/app.passwordstore.ui.passwords.PasswordStore
11-13 00:14:38.190 26328 26328 D InsetsSourceConsumer: ensureControlAlpha: for ITYPE_STATUS_BAR on app.passwordstore/app.passwordstore.ui.passwords.PasswordStore
11-13 00:14:38.190 26328 26328 I ViewRootImpl@1c574cd[PasswordStore]: Relayout returned: old=(0,113,1080,2273) new=(27,677,1053,1709) req=(1026,1032)0 dur=4 res=0x7 s={true -5476376612787146752} ch=true fn=-1
11-13 00:14:38.191 26328 26386 I BufferQueueProducer: [ViewRootImpl@1c574cd[PasswordStore]#5(BLAST Consumer)5](id:66d800000005,api:1,p:26328,c:26328) connect: api=1 producerControlledByApp=true
11-13 00:14:38.191 26328 26386 D OpenGLRenderer: eglCreateWindowSurface
11-13 00:14:38.191 26328 26328 D ScrollView:  onsize change changed 
11-13 00:14:38.192 26328 26328 I ViewRootImpl@1c574cd[PasswordStore]: [DP] dp(1) 1 android.view.ViewRootImpl.reportNextDraw:11442 android.view.ViewRootImpl.performTraversals:4198 android.view.ViewRootImpl.doTraversal:2924 
11-13 00:14:38.192 26328 26328 D ViewRootImpl@1c574cd[PasswordStore]: Creating frameDrawingCallback nextDrawUseBlastSync=false reportNextDraw=true hasBlurUpdates=false
11-13 00:14:38.192 26328 26328 D ViewRootImpl@1c574cd[PasswordStore]: Creating frameCompleteCallback
11-13 00:14:38.194 26328 26416 D ViewRootImpl@1c574cd[PasswordStore]: Received frameDrawingCallback frameNum=1. Creating transactionCompleteCallback=false
11-13 00:14:38.197 26328 26386 D ViewRootImpl@1c574cd[PasswordStore]: Received frameCompleteCallback  lastAcquiredFrameNum=1 lastAttemptedDrawFrameNum=1
11-13 00:14:38.197 26328 26328 I ViewRootImpl@1c574cd[PasswordStore]: [DP] pdf(0) 1 android.view.ViewRootImpl.lambda$addFrameCompleteCallbackIfNeeded$3$ViewRootImpl:5000 android.view.ViewRootImpl$$ExternalSyntheticLambda16.run:6 android.os.Handler.handleCallback:938 
11-13 00:14:38.197 26328 26328 I ViewRootImpl@1c574cd[PasswordStore]: [DP] rdf()
11-13 00:14:38.197 26328 26328 D ViewRootImpl@1c574cd[PasswordStore]: reportDrawFinished (fn: -1) 
11-13 00:14:38.206 26328 26328 I ViewRootImpl@267fbbc[PasswordStore]: MSG_WINDOW_FOCUS_CHANGED 0 1
11-13 00:14:38.209 26328 26328 I ViewRootImpl@1c574cd[PasswordStore]: MSG_WINDOW_FOCUS_CHANGED 1 1
msfjarvis commented 2 years ago

I also use GitHub with SSH for my personal repository and I have never hit this issue. All the logs I received for this (#2236, #2224) have ended up being things that needed to be fixed on the user's end rather than it being a bug in the app.

If you are able to provide me with reproduction steps that let me recreate the bug on my end I can try to investigate it, but at this point this is unactionable.

WhiteBlackGoose commented 2 years ago

Hm, there isn't really anything I do besides installing the apk.

Perms of the two apps (old and new) (2.0 can't read files, but both have full network access):

groceryheist commented 2 years ago

Just tried to setup this app for the first time and ran into this error.

msfjarvis commented 2 years ago

Like I said earlier, "+1" comments are not particularly helpful when no reporter has so far given me reliable reproduction steps. I can't fix what I can't see failing myself.

groceryheist commented 2 years ago

I'm just here to let you know that people want to use the app but can't because of this bug.

msfjarvis commented 2 years ago

I'm just here to let you know that people want to use the app but can't because of this bug.

There's a perfectly fine stable release available that does work for people who want to use the app for the first time. You installed a development build, and have discovered one of many reasons why it's not available on the regular distribution channels.

groceryheist commented 2 years ago

No I installed it from F-droid

On Mon, Nov 14, 2022, 00:10 Harsh Shandilya @.***> wrote:

I'm just here to let you know that people want to use the app but can't because of this bug.

There's a perfectly fine stable release available that does work for people who want to use the app for the first time. You installed a development build, and have discovered one of many reasons why it's not available on the regular distribution channels.

— Reply to this email directly, view it on GitHub https://github.com/android-password-store/Android-Password-Store/issues/2248#issuecomment-1313252934, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAA3VH67G3DDWVUV7SFX2RDWIHXXXANCNFSM6AAAAAAR6NYXWA . You are receiving this because you commented.Message ID: <android-password-store/Android-Password-Store/issues/2248/1313252934@ github.com>

WhiteBlackGoose commented 2 years ago

If it's from F-Droid,check out the issues linked above. People had the exact same issue from F-Droid, and solved them

groceryheist commented 2 years ago

Oh sorry, I didn't notice that detail in the bug report. I get "socket closed" errors. I checked the file permissions but that wasn't the issue.

On Mon, Nov 14, 2022, 00:12 WhiteBlackGoose @.***> wrote:

If it's from F-Droid,check out the issues linked above. People had the exact same issue from F-Droid, and solved them

— Reply to this email directly, view it on GitHub https://github.com/android-password-store/Android-Password-Store/issues/2248#issuecomment-1313255775, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAA3VH4RBXD7HDU5OD5FNE3WIHX6VANCNFSM6AAAAAAR6NYXWA . You are receiving this because you commented.Message ID: <android-password-store/Android-Password-Store/issues/2248/1313255775@ github.com>