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.

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

x/crypto/ssh: when ssh to network switch can not open secondary session #22465

Closed
duhaifeng opened this issue Oct 27, 2017 · 6 comments
Closed

Comments

@duhaifeng
Copy link

Please answer these questions before submitting your issue. Thanks!

What version of Go are you using (go version)?

1.9.1

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

windows / amd64

What did you do?

Connect via ssh to Cisco/Huawei/H3C switch.
Sample code as follows:

func SSHConnect(user, password, ip_port string) {
	PassWd := []ssh.AuthMethod{ssh.Password(password)}
	Conf := ssh.ClientConfig{
		User: user,
		Auth: PassWd,
		HostKeyCallback: func(hostname string, remote net.Addr, key ssh.PublicKey) error {
			return nil
		},
		Config: ssh.Config{
			Ciphers: []string{"aes128-cbc"},
		},
	}

	connection, err := ssh.Dial("tcp", ip_port, &Conf)
	if err != nil {
		return
	}
	defer connection.Close()

	counter := 0
	for {
		counter++
		session, err := connection.NewSession()
		if err != nil {
			// When counter == 2 then error occurs:
			// Huawei and H3C switch returns error: ssh: unexpected packet in response to channel open: <nil>
			// Cisco N7700 switch returns error: EOF
			fmt.Println("\nOpen ssh error:", err)
			return
		}
		defer session.Close()

		in := bufio.NewReader(os.Stdin)
		command, _, err := in.ReadLine()
		if err != nil {
			return
		}
		session.Stdout = os.Stdout
		session.Stderr = os.Stderr
		session.Run(string(command))
	}
}

What did you expect to see?

No error

What did you see instead?

When ssh to network switch device.
The connection can be dialed successfully and the first session can be opened normally too.
But from the secondary session it failed.
(Please see the code comment to get detail error)
If ssh to a ubuntu linux server every session can be opened normally.

@shenbowei
Copy link

I have this problem using version 1.8.1

@ianlancetaylor ianlancetaylor changed the title crypto/ssh: when ssh to network switch can not open secondary session x/crypto/ssh: when ssh to network switch can not open secondary session Oct 27, 2017
@gopherbot gopherbot added this to the Unreleased milestone Oct 27, 2017
@ianlancetaylor
Copy link
Contributor

CC @agl @hanwan

@hanwen
Copy link
Contributor

hanwen commented Nov 8, 2017

can you provide a trace by setting debugMux == true and running your repro?

What happens if you use openssh to open a second session? It's possible that the remote implementation simply doesnt support it.

@duhaifeng
Copy link
Author

duhaifeng commented Nov 14, 2017

Hi, I set debugMux = true which defined in x/crypto/ssh/mux.go. And some additional log appeared. The following log was collected from the console and wish it's helpful. Any other requirement just leave message to me.

Logs when connect to Huawei CE6851-48S6Q-HI:

2017/11/14 15:47:06 send global(1): ssh.channelOpenMsg{ChanType:"session", PeersId:0x1, PeersWindow:0x200000, MaxPacketSize:0x8000, TypeSpecificData:[]uint8(nil)}
2017/11/14 15:47:06 decoding(1): 91 &ssh.channelOpenConfirmMsg{PeersId:0x1, MyId:0x1, MyWindow:0x20000, 
2017/11/14 15:47:09 send(1): ssh.channelRequestMsg{PeersId:0x1, Request:"exec", WantReply:true, RequestSpecificData:[]
2017/11/14 15:47:09 decoding(1): 99 &ssh.channelRequestSuccessMsg{PeersId:0x1} - 5 bytes
2017/11/14 15:47:09 send(1): ssh.channelEOFMsg{PeersId:0x1}

2017/11/14 15:47:09 decoding(1): data packet - 11 bytes
2017/11/14 15:47:09 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x2}
2017/11/14 15:47:09 decoding(1): data packet - 201 bytes
2017/11/14 15:47:09 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0xc0}

2017/11/14 15:47:09 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x2}
2017/11/14 15:47:09 decoding(1): data packet - 45 bytes
2017/11/14 15:47:09 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x24}

2017/11/14 15:47:10 decoding(1): data packet - 11 bytes
2017/11/14 15:47:10 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x2}
2017/11/14 15:47:10 decoding(1): data packet - 266 bytes
2017/11/14 15:47:10 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x101}
2017/11/14 15:47:10 decoding(1): data packet - 477 bytes
2017/11/14 15:47:10 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x1d4}
2017/11/14 15:47:10 decoding(1): data packet - 45 bytes
2017/11/14 15:47:10 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x24}
2017/11/14 15:47:10 decoding(1): data packet - 100 bytes
2017/11/14 15:47:10 decoding(1): 97 &ssh.channelCloseMsg{PeersId:0x1} - 5 bytes
2017/11/14 15:47:10 send(1): ssh.channelCloseMsg{PeersId:0x1}
2017/11/14 15:47:10 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x5b}

2017/11/14 15:47:10 send global(1): ssh.channelOpenMsg{ChanType:"session", PeersId:0x1, PeersWindow:0x200000, MaxPacketSize:0x8000, TypeSpecificData:[]uint8(nil)}
2017/11/14 15:47:10 decoding(1): data packet - 11 bytes

2017/11/14 15:47:10 loop exit ssh: disconnect, reason 2: The connection is closed by SSH Server
2017/11/14 15:47:10 send(1): ssh.channelCloseMsg{PeersId:0x1}

Logs when connect to H3C S5500:

2017/11/14 15:49:32 send global(1): ssh.channelOpenMsg{ChanType:"session", PeersId:0x1, PeersWindow:0x200000, MaxPacketSize:0x8000, TypeSpecificData:[]uint8(nil)}

2017/11/14 15:49:32 decoding(1): 91 &ssh.channelOpenConfirmMsg{PeersId:0x1, MyId:0x1, MyWindow:0x20000, MaxPacketSize:0x7ef0, TypeSpecificData:[]uint8{}} - 17 bytes

2017/11/14 15:49:35 send(1): ssh.channelRequestMsg{PeersId:0x1, Request:"exec", WantReply:true, RequestSpecificData:[]uint8{0x0, 0x0, 0x0, 0x7, 0x64, 0x69, 0x73, 0x20, 0x76, 0x65, 0x72}}
2017/11/14 15:49:35 decoding(1): 99 &ssh.channelRequestSuccessMsg{PeersId:0x1} - 5 bytes
2017/11/14 15:49:35 send(1): ssh.channelEOFMsg{PeersId:0x1}
2017/11/14 15:49:35 decoding(1): data packet - 411 bytes
2017/11/14 15:49:35 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x192}

2017/11/14 15:49:35 decoding(1): 98 &ssh.channelRequestMsg{PeersId:0x1, Request:"exit-status", WantReply:false, RequestSpecificData:[]uint8{0x0, 0x0, 0x0, 0x0}} - 25 bytes
2017/11/14 15:49:35 decoding(1): 97 &ssh.channelCloseMsg{PeersId:0x1} - 5 bytes
2017/11/14 15:49:35 send(1): ssh.channelCloseMsg{PeersId:0x1}
2017/11/14 15:49:35 send global(1): ssh.channelOpenMsg{ChanType:"session", PeersId:0x1, PeersWindow:0x200000, MaxPacketSize:0x8000, TypeSpecificData:[]uint8(nil)}

2017/11/14 15:49:35 decoding(1): data packet - 32 bytes
2017/11/14 15:49:35 decoding(1): data packet - 90 bytes
2017/11/14 15:49:35 decoding(1): data packet - 32 bytes
2017/11/14 15:49:35 loop exit EOF
2017/11/14 15:49:35 send(1): ssh.channelCloseMsg{PeersId:0x1}

Logs when connect to Cisco 2960:

2017/11/14 15:40:09 send global(1): ssh.channelOpenMsg{ChanType:"session", PeersId:0x1, PeersWindow:0x200000, MaxPacketSize:0x8000, TypeSpecificData:[]uint8(nil)}
2017/11/14 15:40:09 decoding(1): 91 &ssh.channelOpenConfirmMsg{PeersId:0x1, MyId:0x3, MyWindow:0x400, MaxPacketSize:0x1000, TypeSpecificData:[]uint8{}} - 17 bytes
2017/11/14 15:40:13 send(1): ssh.channelRequestMsg{PeersId:0x3, Request:"exec", WantReply:true, RequestSpecificData:[]uint8{0x0, 0x0, 0x0, 0x8, 0x73, 0x68, 0x6f, 0x77, 0x20, 0x76, 0x65, 0x72}}
2017/11/14 15:40:13 decoding(1): 99 &ssh.channelRequestSuccessMsg{PeersId:0x1} - 5 bytes
2017/11/14 15:40:13 send(1): ssh.channelEOFMsg{PeersId:0x3}
2017/11/14 15:40:13 decoding(1): data packet - 1033 bytes
2017/11/14 15:40:13 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x400}
2017/11/14 15:40:13 decoding(1): data packet - 1033 bytes
2017/11/14 15:40:13 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x400}
2017/11/14 15:40:13 decoding(1): data packet - 859 bytes
2017/11/14 15:40:13 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x352}
2017/11/14 15:40:13 decoding(1): 98 &ssh.channelRequestMsg{PeersId:0x1, Request:"exit-status", WantReply:false, RequestSpecificData:[]uint8{0x0, 0x0, 0x0, 0x0}} - 25 bytes
2017/11/14 15:40:13 decoding(1): 96 &ssh.channelEOFMsg{PeersId:0x1} - 5 bytes
2017/11/14 15:40:13 decoding(1): 97 &ssh.channelCloseMsg{PeersId:0x1} - 5 bytes
2017/11/14 15:40:13 send(1): ssh.channelCloseMsg{PeersId:0x3}
2017/11/14 15:40:13 decoding(1): 98 &ssh.channelRequestMsg{PeersId:0x1, Request:"exit-status", WantReply:false, RequestSpecificData:[]uint8{0x0, 0x0, 0x0, 0x0}} - 25 bytes
2017/11/14 15:40:13 send global(1): ssh.channelOpenMsg{ChanType:"session", PeersId:0x1, PeersWindow:0x200000, MaxPacketSize:0x8000, TypeSpecificData:[]uint8(nil)}
2017/11/14 15:40:13 loop exit EOF
2017/11/14 15:40:13 send(1): ssh.channelCloseMsg{PeersId:0x3}

But when connect to Cisco 9364 the second session is ok:

2017/11/14 16:05:38 send global(1): ssh.channelOpenMsg{ChanType:"session", PeersId:0x1, PeersWindow:0x200000, MaxPacketSize:0x8000, TypeSpecificData:[]uint8(nil)}
2017/11/14 16:05:38 decoding(1): 80 &ssh.globalRequestMsg{Type:"hostkeys-00@openssh.com", WantReply:false, Data:[]uint8{0x0, 0x0, 0x0, 0x97, 0x0, 0x0, 0x0, 0x7, 0x73, 0x73, 0x68, 0x2d, 0x72, 0x73, 0x61, 0x0, 0x0, 0x0, 0x3, 0x1, 0x0, 0x1, 0x0, 0x0, 0x0, 0x81, 0x0, 0x9f, 0x32, 0xa0, 0x11, 0x30, 0x74, 0x2e, 0x9b, 0x52, 0x7e, 0x78, 0x74, 0x10, 0xb6, 0x90, 0xb8, 0xd4, 0xef, 0x62, 0x3d, 0xda, 0xe1, 0x89, 0xb9, 0xbf, 0xfa, 0xd, 0x7e, 0xca, 0xd8, 0x97, 0x90, 0xaf, 0x7f, 0x6f, 0x0, 0x1d, 0xb5, 0xfa, 0x9f, 0x24, 0xf6, 0x71, 0x39, 0xf0, 0xcc, 0x4b, 0x21, 0xac, 0xb4, 0x8f, 0x19, 0x87, 0xfc, 0x97, 0x49, 0xe5, 0x2b, 0xb6, 0x5c, 0xf6, 0x13, 0x3f, 0x1b, 0xab, 0xfa, 0x17, 0xa1, 0xd5, 0x9a, 0x13, 0x4c, 0x9f, 0xf5, 0xbd, 0x2a, 0x8c, 0x68, 0xcb, 0x93, 0x9c, 0xe2, 0xda, 0xd0, 0x7c, 0x7e, 0x3d, 0xaa, 0xc5, 0x4c, 0x6d, 0xb2, 0x2a, 0xa7, 0x14, 0x4b, 0x9e, 0xba, 0x52, 0x6f, 0xe7, 0x82, 0xf1, 0x3f, 0xe9, 0x40, 0x38, 0x1a, 0x6b, 0x8d, 0x28, 0xbf, 0xd, 0x5d, 0x43, 0xaf, 0x55, 0x53, 0x17, 0xbc, 0xac, 0x4c, 0xc2, 0x8c, 0x10, 0xac, 0xec, 0xbd}} - 184 bytes
2017/11/14 16:05:38 decoding(1): 91 &ssh.channelOpenConfirmMsg{PeersId:0x1, MyId:0x0, MyWindow:0x0, MaxPacketSize:0x8000, TypeSpecificData:[]uint8{}} - 17 bytes
2017/11/14 16:05:44 send(1): ssh.channelRequestMsg{PeersId:0x0, Request:"exec", WantReply:true, RequestSpecificData:[]uint8{0x0, 0x0, 0x0, 0xa, 0x73, 0x68, 0x6f, 0x77, 0x20, 0x63, 0x6c, 0x6f, 0x63, 0x6b}}
2017/11/14 16:05:44 decoding(1): 93 &ssh.windowAdjustMsg{PeersId:0x1, AdditionalBytes:0x200000} - 9 bytes
2017/11/14 16:05:44 decoding(1): 99 &ssh.channelRequestSuccessMsg{PeersId:0x1} - 5 bytes
2017/11/14 16:05:44 send(1): ssh.channelEOFMsg{PeersId:0x0}
2017/11/14 16:05:45 decoding(1): data packet - 61 bytes

2017/11/14 16:05:45 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x34}
2017/11/14 16:05:45 decoding(1): data packet - 75 bytes
2017/11/14 16:05:45 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x42}

2017/11/14 16:05:45 decoding(1): 98 &ssh.channelRequestMsg{PeersId:0x1, Request:"exit-status", WantReply:false, RequestSpecificData:[]uint8{0x0, 0x0, 0x0, 0x0}} - 25 bytes
2017/11/14 16:05:45 decoding(1): 96 &ssh.channelEOFMsg{PeersId:0x1} - 5 bytes
2017/11/14 16:05:45 decoding(1): 97 &ssh.channelCloseMsg{PeersId:0x1} - 5 bytes
2017/11/14 16:05:45 send(1): ssh.channelCloseMsg{PeersId:0x0}
2017/11/14 16:05:45 send global(1): ssh.channelOpenMsg{ChanType:"session", PeersId:0x1, PeersWindow:0x200000, MaxPacketSize:0x8000, TypeSpecificData:[]uint8(nil)}
2017/11/14 16:05:45 decoding(1): 91 &ssh.channelOpenConfirmMsg{PeersId:0x1, MyId:0x0, MyWindow:0x0, MaxPacketSize:0x8000, TypeSpecificData:[]uint8{}} - 17 bytes

2017/11/14 16:05:54 send(1): ssh.channelRequestMsg{PeersId:0x0, Request:"exec", WantReply:true, RequestSpecificData:[]uint8{0x0, 0x0, 0x0, 0xa, 0x73, 0x68, 0x6f, 0x77, 0x20, 0x63, 0x6c, 0x6f, 0x63, 0x6b}}
2017/11/14 16:05:54 decoding(1): 93 &ssh.windowAdjustMsg{PeersId:0x1, AdditionalBytes:0x200000} - 9 bytes
2017/11/14 16:05:54 decoding(1): 99 &ssh.channelRequestSuccessMsg{PeersId:0x1} - 5 bytes
2017/11/14 16:05:54 send(1): ssh.channelEOFMsg{PeersId:0x0}

2017/11/14 16:05:54 decoding(1): data packet - 61 bytes
2017/11/14 16:05:54 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x34}
2017/11/14 16:05:54 decoding(1): data packet - 75 bytes
2017/11/14 16:05:54 send(1): ssh.windowAdjustMsg{PeersId:0x0, AdditionalBytes:0x42}

2017/11/14 16:05:54 decoding(1): 98 &ssh.channelRequestMsg{PeersId:0x1, Request:"exit-status", WantReply:false, RequestSpecificData:[]uint8{0x0, 0x0, 0x0, 0x0}} - 25 bytes
2017/11/14 16:05:54 decoding(1): 96 &ssh.channelEOFMsg{PeersId:0x1} - 5 bytes
2017/11/14 16:05:54 decoding(1): 97 &ssh.channelCloseMsg{PeersId:0x1} - 5 bytes
2017/11/14 16:05:54 send(1): ssh.channelCloseMsg{PeersId:0x0}
2017/11/14 16:05:54 send global(1): ssh.channelOpenMsg{ChanType:"session", PeersId:0x1, PeersWindow:0x200000, MaxPacketSize:0x8000, TypeSpecificData:[]uint8(nil)}
2017/11/14 16:05:54 decoding(1): 91 &ssh.channelOpenConfirmMsg{PeersId:0x1, MyId:0x1, MyWindow:0x0, MaxPacketSize:0x8000, TypeSpecificData:[]uint8{}} - 17 bytes

@hanwen
Copy link
Contributor

hanwen commented Nov 14, 2017

yeah, looks like the remote end doesn't support this. If this is bothering you, you should complain to H3C/Cisco/etc.

@duhaifeng
Copy link
Author

I prepare change my solution. I will make a session pool and once a session opened I will hold and reuse it for many times, until it's idle time exceed 10 minutes. I hope this solution can work stable.
Anyway thanks a lot.

@hanwen hanwen closed this as completed Nov 15, 2017
@golang golang locked and limited conversation to collaborators Nov 15, 2018
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

5 participants