Bug 573205 - JGit Clone via SSH opens more channels but bitbucket cloud does not support it
Summary: JGit Clone via SSH opens more channels but bitbucket cloud does not support it
Status: NEW
Alias: None
Product: JGit
Classification: Technology
Component: JGit (show other bugs)
Version: 5.11   Edit
Hardware: PC Windows 10
: P3 normal with 1 vote (vote)
Target Milestone: ---   Edit
Assignee: Project Inbox CLA
QA Contact:
URL:
Whiteboard:
Keywords:
Depends on:
Blocks:
 
Reported: 2021-04-28 02:11 EDT by Stefan Cordes CLA
Modified: 2021-07-23 03:23 EDT (History)
1 user (show)

See Also:


Attachments
Stacktrace from the error log (4.59 KB, text/plain)
2021-04-28 02:11 EDT, Stefan Cordes CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Stefan Cordes CLA 2021-04-28 02:11:31 EDT
Created attachment 286257 [details]
Stacktrace from the error log

When cloning via ssh some (not all) repositories from bitbucket cloud the eclipse clone fails with

Caused by: org.apache.sshd.common.channel.exception.SshChannelOpenException: cannot open additional channels
	at org.apache.sshd.client.channel.AbstractClientChannel.handleOpenFailure(AbstractClientChannel.java:388)

which is correct as bitbucket removed multichannel feature:
see https://jira.atlassian.com/browse/BCLOUD-13465?focusedCommentId=2247415&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-2247415

attached stacktrace shows a reopenConnection and so I guess the previous channel is not closed correctly.

	at org.eclipse.jgit.transport.TransportGitSsh.openFetch(TransportGitSsh.java:153)
	at org.eclipse.jgit.transport.FetchProcess.reopenConnection(FetchProcess.java:306)
	at org.eclipse.jgit.transport.FetchProcess.executeImp(FetchProcess.java:197)


the .ssh/config section for bitbucket is

Host bitbucket.org
  User git
  Port 22
  Hostname bitbucket.org
  IdentityFile "C:\Users\xxxx\.ssh\xxxx-bitbucket"
  TCPKeepAlive yes
  IdentitiesOnly yes
  PasswordAuthentication no

Here some versions:

eclipse.buildId=4.19.0.I20210303-1800
org.eclipse.egit (5.11.0.202103091610-r) "Git integration for Eclipse"
org.eclipse.jgit (5.11.0.202103091610-r) "JGit Core"
org.eclipse.jgit.ssh.apache (5.11.0.202103091610-r) "JGit SSH support based on Apache MINA sshd"

and information from the config:

/bundle_defaults/org.eclipse.egit.core/core_autoIgnoreDerivedResources=true
/bundle_defaults/org.eclipse.egit.core/core_autoShareProjects=true
/bundle_defaults/org.eclipse.egit.core/core_auto_stage_deletion=false
/bundle_defaults/org.eclipse.egit.core/core_auto_stage_moves=true
/bundle_defaults/org.eclipse.egit.core/core_defaultRepositoryDir=c\:\\users\\xxxx\\git
/bundle_defaults/org.eclipse.egit.core/core_deltaBaseCacheLimit=10485760
/bundle_defaults/org.eclipse.egit.core/core_gpg_signer=bc
/bundle_defaults/org.eclipse.egit.core/core_http_client=apache
/bundle_defaults/org.eclipse.egit.core/core_max_pull_threads_count=3
/bundle_defaults/org.eclipse.egit.core/core_packedGitLimit=10485760
/bundle_defaults/org.eclipse.egit.core/core_packedGitMMAP=false
/bundle_defaults/org.eclipse.egit.core/core_packedGitWindowSize=8192
/bundle_defaults/org.eclipse.egit.core/core_remote_connection_timeout=30
/bundle_defaults/org.eclipse.egit.core/core_save_credentials_in_secure_store=true
/bundle_defaults/org.eclipse.egit.core/core_streamFileThreshold=52428800

java.runtime.name=OpenJDK Runtime Environment
java.runtime.version=11.0.9.1+1
java.specification.name=Java Platform API Specification
java.specification.vendor=Oracle Corporation
java.specification.version=11

os.arch=amd64
os.name=Windows 10
os.version=10.0
osgi.arch=x86_64
Comment 1 Thomas Wolf CLA 2021-04-29 03:36:07 EDT
That's a though one.

* Might be a problem with closing SSH channels. C.f. [1]. We close the channel gracefully in JGit 5.12.0, i.e., we send a "close" message. Previously we just disconnected.
* Might be a problem with the new protocol V2.
* Might be a bug in Apache sshd 2.6.0.
* Might be a bug in bitbucket.

Can you try to obtain a debug log for a clone where it fails? See bug 572056 comment 1 for how to do that.

[1] https://git.eclipse.org/r/c/jgit/jgit/+/168537/2/org.eclipse.jgit.ssh.apache/src/org/eclipse/jgit/transport/sshd/SshdSession.java
Comment 2 Stefan Cordes CLA 2021-04-29 05:57:12 EDT
Hi Thomas,

I tried several combinations but no additional log appears (neither in the command line nor in the workspace log)

set _JAVA_OPTIONS=-Dlogback.configurationFile=file:///swd/eclipse/logback-debug.xml
and
eclipsec.exe -console -consoleLog -debug

(tried eclipse.exe -console -consoleLog -debug but then windows console is directly finished)

Even adding 
-vmargs
-Dlogback.configurationFile=file:///swd/eclipse/logback-debug.xml
to the eclipse.ini does not print any additional debug log-line.

Even
    <root level="DEBUG">
in C:\swd\eclipse>logback-debug.xml does not print any additional information.

Any other possibilities to enable debug logging ?
Comment 3 Thomas Wolf CLA 2021-04-29 15:31:59 EDT
(In reply to Stefan Cordes from comment #2)
> Hi Thomas,
> 
> I tried several combinations but no additional log appears (neither in the
> command line nor in the workspace log)
> 
> set
> _JAVA_OPTIONS=-Dlogback.configurationFile=file:///swd/eclipse/logback-debug.
> xml
> and
> eclipsec.exe -console -consoleLog -debug
> 
> (tried eclipse.exe -console -consoleLog -debug but then windows console is
> directly finished)
> 
> Even adding 
> -vmargs
> -Dlogback.configurationFile=file:///swd/eclipse/logback-debug.xml
> to the eclipse.ini does not print any additional debug log-line.
> 
> Even
>     <root level="DEBUG">
> in C:\swd\eclipse>logback-debug.xml does not print any additional
> information.
> 
> Any other possibilities to enable debug logging ?

Sounds like it doesn't pick up the option, or the path is wrong.

If you start from a DOS prompt (Windows command shell), I suppose you have to use the "set" command to set _JAVA_OPTIONS:

  set _JAVA_OPTIONS=-Dlogback.configurationFile=file:/C:/swd/eclipse/logback-debug.xml

The second possible failure point is the file: URL. Try as above with the drive letter and with one or with three slashes. Or with the path directly instead of a URL: -Dlogback.configurationFile=C:\swd\eclipse\logback-debug.xml. 

I don't know how exactly logback reads this value.

Also check what version of logback is installed in your exact Eclipse version, or if your Eclipse uses a different logging back-end. The option itself also might have changed.

I have no Windows machine myself, so I can't experiment myself and then tell you exactly what would work.
Comment 4 Stefan Cordes CLA 2021-04-30 06:30:27 EDT
I changed the logback-debug.xml to have a file appender.

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="5 seconds">

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{40} - %msg%n</pattern>
        </encoder>
    </appender>

<appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>myApp.log</file>

    <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{40} - %msg%n</pattern>
    </encoder>
  </appender>

    <logger name="org.apache.sshd" level="DEBUG" additivity="true">
        <appender-ref ref="STDOUT" />
    </logger>

    <root level="DEBUG">
        <appender-ref ref="STDOUT" />
        <appender-ref ref="file" />
    </root>

</configuration>


The file myApp.log is created when starting eclipse but keeps empty.

So eclipse.ini with
-Dlogback.configurationFile=file:///swd/eclipse/logback-debug.xml
is pickung up the log-file config but no log-statements are created at all.

Do I need to place some jars in the plugin/ or dropins/ folder to make logging work?
Comment 5 Thomas Wolf CLA 2021-04-30 07:07:51 EDT
(In reply to Stefan Cordes from comment #4)
> I changed the logback-debug.xml to have a file appender.
> 
> <?xml version="1.0" encoding="UTF-8"?>
> <configuration scan="true" scanPeriod="5 seconds">
> 
>     <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
>         <encoder>
>             <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{40} -
> %msg%n</pattern>
>         </encoder>
>     </appender>
> 
> <appender name="FILE" class="ch.qos.logback.core.FileAppender">
>     <file>myApp.log</file>
> 
>     <encoder>
>             <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{40} -
> %msg%n</pattern>
>     </encoder>
>   </appender>
> 
>     <logger name="org.apache.sshd" level="DEBUG" additivity="true">
>         <appender-ref ref="STDOUT" />
>     </logger>
> 
>     <root level="DEBUG">
>         <appender-ref ref="STDOUT" />
>         <appender-ref ref="file" />
>     </root>
> 
> </configuration>
> 
> 
> The file myApp.log is created when starting eclipse but keeps empty.
> 
> So eclipse.ini with
> -Dlogback.configurationFile=file:///swd/eclipse/logback-debug.xml
> is pickung up the log-file config but no log-statements are created at all.
> 
> Do I need to place some jars in the plugin/ or dropins/ folder to make
> logging work?

Should that be <appender-ref ref="FILE" /> ?
Comment 6 Stefan Cordes CLA 2021-04-30 08:25:03 EDT
Yes, FILE would be better but file is working as well (still no logs).

In the meantime I took a look into
and faced that it has something to do with tags.

So I created a public repo
https://bitbucket.org/capublic/clone-fails/src/develop/
which fails when cloning
git@bitbucket.org:capublic/clone-fails.git

Please try on your side to clone.
Comment 7 Thomas Wolf CLA 2021-04-30 09:23:47 EDT
(In reply to Stefan Cordes from comment #6)
> Yes, FILE would be better but file is working as well (still no logs).
> 
> In the meantime I took a look into
> and faced that it has something to do with tags.
> 
> So I created a public repo
> https://bitbucket.org/capublic/clone-fails/src/develop/
> which fails when cloning
> git@bitbucket.org:capublic/clone-fails.git
> 
> Please try on your side to clone.

Thanks a lot for this. This will be super-useful if it fails for me, too :-). I'll try cloning that later.
Comment 8 Thomas Wolf CLA 2021-04-30 12:25:47 EDT
> Thanks a lot for this. This will be super-useful if it fails for me, too
> :-). I'll try cloning that later.

Can reproduce. The clone fails in EGit if:

* all branches are selected to be fetched
* "When fetching a commit, also fetch its tags" is set.

It succeeds if one either:

* de-selects one branch, or
* chooses "Fetch all tags"

The latter is a quick work-around: just select "Fetch all tags". But there is clearly a problem somewhere.
Comment 9 Thomas Wolf CLA 2021-04-30 12:29:27 EDT
To get a debugging log, I had to copy

  org.slf4j.binding.log4j12_1.7.30.v20201108-2042.jar

and

  org.slf4j.log4j_1.7.2.v20130115-1340.jar

downloaded from Orbit ( https://download.eclipse.org/tools/orbit/downloads/drops/R20210223232630/ ) into the Eclipse dropins folder.

The Bitbucket SSH server identifies as "SSH-2.0-conker_eaf7bc21ee 6ddc7e03fc8a".

  2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 ChannelExec:834 - handleEof(ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]) SSH_MSG_CHANNEL_EOF

Client receives an EOF message from bitbucket.

2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 ChannelExec:528 - handleClose(ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]) SSH_MSG_CHANNEL_CLOSE

Client receives a CLOSE message from bitbucket. Client initiates gracefully
closing the client side of the channel.

2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 ChannelExec:533 - handleClose(ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]) prevent sending EOF
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 ChannelExec:107 - close(ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]) Closing gracefully
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 ChannelExec:666 - close(ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]) prevent sending EOF
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 Window:356 - Closing Window[client/local](ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22])
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 Window:356 - Closing Window[client/remote](ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22])
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 ChannelExec:901 - sendEof(ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]) SSH_MSG_CHANNEL_EOF (state=Graceful)
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 JGitClientSession:1215 - encode(JGitClientSession[git@bitbucket.org/104.192.141.1:22]) packet #14 sending command=96[SSH_MSG_CHANNEL_EOF] len=5
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 Nio2Session:171 - writeBuffer(Nio2Session[local=/192.168.2.83:58913, remote=bitbucket.org/104.192.141.1:22]) writing 68 bytes

Hmmm. Client has logged twice it wouldn't send an EOF, but then sends one anyway? That looks like a bug in Apache MINA sshd. When it receives a CLOSE, it should just reply with a CLOSE, without EOF.

2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 AbstractChannel$GracefulChannelCloseable:594 - close(ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22])[immediately=false] processing
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 AbstractChannel$GracefulChannelCloseable:602 - close(ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22])[immediately=false] send SSH_MSG_CHANNEL_CLOSE
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 JGitClientSession:1215 - encode(JGitClientSession[git@bitbucket.org/104.192.141.1:22]) packet #15 sending command=97[SSH_MSG_CHANNEL_CLOSE] len=5
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 Nio2Session:171 - writeBuffer(Nio2Session[local=/192.168.2.83:58913, remote=bitbucket.org/104.192.141.1:22]) writing 68 bytes
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 AbstractChannel$GracefulChannelCloseable:639 - handleClosePacketWritten(ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22])[immediately=false] SSH_MSG_CHANNEL_CLOSE written on channel

Client replies with a CLOSE message to the server. Client is now free to re-use the channel number.

2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 ClientConnectionService:453 - unregisterChannel(ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]) result=ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 SequentialCloseable:63 - doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@3c4bed41) signal close complete immediately=false
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 SequentialCloseable:63 - doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@69968d11) signal close complete immediately=false
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 SequentialCloseable:63 - doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@c89d96b) signal close complete immediately=false
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 AbstractChannel$GracefulChannelCloseable:594 - close(ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22])[immediately=true] processing
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 ClientConnectionService:453 - unregisterChannel(ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]) result=null
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 SequentialCloseable:63 - doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@570cd835) signal close complete immediately=true
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 SequentialCloseable:63 - doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@15cac5ab) signal close complete immediately=true
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 SequentialCloseable:63 - doClose(org.apache.sshd.common.util.closeable.SequentialCloseable$1@5104d85f) signal close complete immediately=true
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-3 ChannelExec:116 - close(ChannelExec[id=0, recipient=0]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]][Graceful] - operationComplete() closed

Here the Apache MINA sshd client has closed and unregistered channel 0.

2021-04-30 17:03:39 DEBUG Worker-174: Cloning from git@bitbucket.org:capublic/clone-fails.git ChannelExec:365 - init() service=ClientConnectionService[JGitClientSession[git@bitbucket.org/104.192.141.1:22]] session=JGitClientSession[git@bitbucket.org/104.192.141.1:22] id=1
2021-04-30 17:03:39 DEBUG Worker-174: Cloning from git@bitbucket.org:capublic/clone-fails.git Window:118 - init(Window[client/local](ChannelExec[id=1, recipient=-1]-JGitClientSession[git@bitbucket.org/104.192.141.1:22])) size=2097152, max=2097152, packet=32768

Here it wants to open channel 1. It doesn't re-use channel numbers?

2021-04-30 17:03:39 DEBUG Worker-174: Cloning from git@bitbucket.org:capublic/clone-fails.git ClientConnectionService:425 - registerChannel(ClientConnectionService[JGitClientSession[git@bitbucket.org/104.192.141.1:22]])[id=1] ChannelExec[id=1, recipient=-1]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]
2021-04-30 17:03:39 DEBUG Worker-174: Cloning from git@bitbucket.org:capublic/clone-fails.git JGitClientSession:342 - createExecChannel(JGitClientSession[git@bitbucket.org/104.192.141.1:22])[git-upload-pack 'capublic/clone-fails.git'] created id=1 - PTY=null
2021-04-30 17:03:39 DEBUG Worker-174: Cloning from git@bitbucket.org:capublic/clone-fails.git ChannelExec:325 - open(ChannelExec[id=1, recipient=-1]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]) Send SSH_MSG_CHANNEL_OPEN - type=session
2021-04-30 17:03:39 DEBUG Worker-174: Cloning from git@bitbucket.org:capublic/clone-fails.git JGitClientSession:1215 - encode(JGitClientSession[git@bitbucket.org/104.192.141.1:22]) packet #16 sending command=90[SSH_MSG_CHANNEL_OPEN] len=24
2021-04-30 17:03:39 DEBUG Worker-174: Cloning from git@bitbucket.org:capublic/clone-fails.git Nio2Session:171 - writeBuffer(Nio2Session[local=/192.168.2.83:58913, remote=bitbucket.org/104.192.141.1:22]) writing 84 bytes
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-5 ClientConnectionService:565 - channelOpenFailure(ChannelExec[id=1, recipient=-1]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]) Received SSH_MSG_CHANNEL_OPEN_FAILURE
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-5 ClientConnectionService:574 - channelOpenFailure(ChannelExec[id=1, recipient=-1]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]) unregistered ChannelExec[id=1, recipient=-1]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]
2021-04-30 17:03:39 DEBUG sshd-JGitSshClient[7c440ee8]-nio2-thread-5 ChannelExec:381 - handleOpenFailure(ChannelExec[id=1, recipient=-1]-JGitClientSession[git@bitbucket.org/104.192.141.1:22]) reason=SSH_OPEN_ADMINISTRATIVELY_PROHIBITED, lang=en, msg=cannot open additional channels

And bitbucket refuses this.

This starts to look like either:

1. perhaps caused by Apache MINA sshd sending EOF-CLOSE instead of just CLOSE
   when it receives a CLOSE?
2. perhaps a bug in the bitbucket SSH server, refusing any channel with a
   number > 0? (That would be an overly simplistic implementation, though.)
3. perhaps caused by the bitbucket SSH server refusing any but the first channel
   open request on a session? (That would be an even worse implementation.)
4. the bitbucket SSH server somehow has on its side not unregistered its end
   of channel 0 (even though it should have gotten a CLOSE on that channel)
   when it receives the request to open channel 1?

(I'm speculating here. I have _no_ knowledge about how exactly the bitbucket SSH server is implemented or configured.)

Adding a Thread.sleep(2000) before the FetchProcess.reopenConnection() doesn't help, so I guess it's not (4).

If it's (2) or (3) I'm not sure we can even do something about it on the client side. Maybe if it's (2) a change in Apache MINA sshd to reuse channel numbers more aggressively to use 0 for the second channel might help.

I'll try to build a custom version of Apache MINA sshd with (1) fixed. If that solves this problem, the final fix will have to happen upstream in Apache MINA sshd.
Comment 10 Thomas Wolf CLA 2021-05-01 05:06:25 EDT
(In reply to Thomas Wolf from comment #9)
> 1. perhaps caused by Apache MINA sshd sending EOF-CLOSE instead of just CLOSE
>    when it receives a CLOSE?

This _is_ a bug in Apache MINA sshd (reported as SSHD-1158[1]), but if fixed the clone still fails.

> 2. perhaps a bug in the bitbucket SSH server, refusing any channel with a
>    number > 0? (That would be an overly simplistic implementation, though.)

That's not it; making Apache MINA sshd re-use channel ids (such that the second channel gets also id 0) doesn't change anything. The bitbucket server still refuses the second channel open.

> 4. the bitbucket SSH server somehow has on its side not unregistered its end
>    of channel 0 (even though it should have gotten a CLOSE on that channel)
>    when it receives the request to open channel 1?

Doesn't look it; adding various delays doesn't change anything.

Forcing git protocol V0 doesn't change anything; JGit still goes into this FetchProcess.repoenConnection() case and tries to open a second channel.

That leaves us with (3).

> 3. perhaps caused by the bitbucket SSH server refusing any but the first
> channel open request on a session?

IMO a bug in the bitbucket SSH server. It should perhaps forbid multiple concurrent channels, but not multiple successive channels. I don't see what we could do client-side to cater to such crippled server implementations.

[1] https://issues.apache.org/jira/browse/SSHD-1158
Comment 11 Thomas Wolf CLA 2021-05-01 07:54:25 EDT
This also fails to clone with EGit 5.10/Apache MINA sshd 2.4.0 from Eclipse 4.18.

It works with EGit 5.7.0/sshd 2.2.0 from Eclipse 4.15. That version doesn't even seem to go into that FetchProcess.reopenConnection() branch.

So somewhere there's a regression since then, but not immediate in the last release. And it might be a regression in JGit after all. I'll have to try more versions and bisect and try to figure out since when and why we're even getting into that FetchProcess.reopenConnection() branch.

Fixing that would bypass this bitbucket "one channel only" restriction, but it would not _solve_ it. There might be other repos for which one absolutely needs to take that reopenConnection branch, and then it'd still fail.
Comment 12 Thomas Wolf CLA 2021-05-01 10:47:48 EDT
(In reply to Thomas Wolf from comment #11)
> This also fails to clone with EGit 5.10/Apache MINA sshd 2.4.0 from Eclipse
> 4.18.
> 
> It works with EGit 5.7.0/sshd 2.2.0 from Eclipse 4.15. That version doesn't
> even seem to go into that FetchProcess.reopenConnection() branch.
> 
> So somewhere there's a regression since then, but not immediate in the last
> release. And it might be a regression in JGit after all. I'll have to try
> more versions and bisect and try to figure out since when and why we're even
> getting into that FetchProcess.reopenConnection() branch.

Not really a regression. JGit 5.7 just used "Fetch all tags" by default; 5.8 introduced explicit settings. Not sure what the best fix is here. We could simply change the default in EGit to "Fetch all tags".

But that will just side-step the underlying problem with bitbucket.
Comment 13 Stefan Cordes CLA 2021-05-03 12:41:06 EDT
Hi Thomas,
I checked with an older Eclipse 2019-12 which has JGit 5.6.0 bundled and there is no possibility to select whether to clone all tags or just some and it is failing as well with

git@bitbucket.org:capublic/clone-fails.git

Caused by: org.apache.sshd.common.channel.exception.SshChannelOpenException: cannot open additional channels
	at org.apache.sshd.client.channel.AbstractClientChannel.handleOpenFailure(AbstractClientChannel.java:380)

(another line as Apache Mina sshd looks like to be version 2.2.0).

So for workaround it is really helpful to have "Fetch all tags" in current eclipse version.


As bitbucket removed the ssh multiplexing long before (approx 2016) eclipse 2019-12 came out  here probably was another change done in the ssh implementation on bitbucket side.


For "fixing" this it would be fine (for me) to have

(*) ​Fetch all tags and their commits
to be default selection

( ) Don't fetch any tags
for those people who really have many tags and clone would become too slow.

Both of above options work well with bitbucket "single-channel"

And the third option:
( ) When fetching a commit, also fetch the tags (may not work on bitbucket ssh)
For all other people interested in tags of the checked out branch commits only.
Comment 14 Thomas Wolf CLA 2021-05-04 02:13:31 EDT
Unfortunately it's not that easy.

1. Changing the default in EGit to FETCH_ALL would also write git config

     remote.origin.tags = --tags

   making all future fetches also fetch all annotated tags. Which is a bit a
   drastic change to make by default just because bitbucket uses a crippled
   SSH server. (It would be OK for bitbucket, but overkill for other better
   git servers.)

2. Keeping the default as AUTO_FOLLOW but using for the first fetch that is
   done as part of a clone FETCH_ALL internally *if all branches are fetched
   anyway* might be possible in JGit. But the clone might still fail if not
   all branches are to be cloned, or later fetches might also fail with that
   bitbucket server since they'd use AUTO_FOLLOW.

3. One could change the default if the URL is SSH and goes to bitbucket.org,
   but I'd hate to add such special casing to either EGit or JGit.

4. We could use (2) and additionally improve the error reporting such that it
   actually says "Server configuration forbids operation: ..." (i.e., make the
   underlying server error reason code SSH_OPEN_ADMINISTRATIVELY_PROHIBITED
   explicit), and then have a paragraph in the EGit User's Guide that explains
   that the user could try setting "remote.<name>.tags = --tags" himself in
   the git config, switch to HTTPS, or even better move to a git repo
   provider without such restrictions :-)

5. Raise hell at BCLOUD-13465 until bitbucket Cloud supports multiple successive
   SSH channels. Until they do, have a paragraph in the EGit USer's Guide...
   (as above).

   Note that JGit does _not_ try to do SSH multiplexing -- it's just using
   consecutive SSH channels.
   
6. Do nothing at all in EGit/JGit; whenever this problem is reported, point
   reporters to this bug and let them set "Fetch all tags" explicitly.

Maybe (5) and (6) is the way to go.

Cloning this repository from Github works perfectly fine.
Comment 15 Stefan Cordes CLA 2021-05-27 05:01:50 EDT
From bitbucket-users point of view (my view ;-)
the "​Fetch all tags and their commits" should not be default.

I have asked our bitbucket support and the result is:

Due to security reasons the bitbucket team stopped (not implement?) the feature for re-using a channel.

They may support it in future, see
https://jira.atlassian.com/browse/BCLOUD-21087
Comment 16 Stefan Cordes CLA 2021-07-23 03:23:45 EDT
Unfortunately Bitbucket:
"...We do not currently have plans to implement SSH channel re-use - for now, we only support running one command per SSH session.."
(see https://jira.atlassian.com/browse/BCLOUD-21087 )

So maybe a solution here (e.g. creating new channel for each session) ?