gssapi icon indicating copy to clipboard operation
gssapi copied to clipboard

Published 20 hours ago • verified publisher icon zenchild

Stack tracing failure on gssapi_with_mic authentication

Open HenluStarke opened this issue 2 years ago • 1 comments

Hi there, I am encountering the following error when attempting to authenticate using gssapi via SSH. I have traced it down to the following line. If i comment out this line I am able to successfully authenticate. Below are the steps to reproduce the error:

OS

MacBook Air (M2, 2022) ProductName: macOS ProductVersion: 12.6 BuildVersion: 21G115

Runtime

ruby 2.7.6p219 (2022-04-12 revision c9c2245c0a) [arm64-darwin21] LibreSSL 2.8.3

*** LOCAL GEMS *** faraday-net_http (1.0.1) faraday-net_http_persistent (1.2.0) net-pop (default: 0.1.0) net-sftp (2.1.2) net-smtp (default: 0.1.0) net-ssh (7.0.1, 4.2.0) net-ssh-krb (0.5.1) net-telnet (0.2.0) netaddr (2.0.6) *** LOCAL GEMS *** gssapi (1.3.1)

Steps

gem install net-ssh --version 7.0.1
gem install net-ssh-krb --version 0.5.1

[REDACTED]@MBAM2-[REDACTED] ~ % irb     
irb(main):001:0> require 'net/ssh'
=> true
irb(main):002:0> require 'net/ssh/krb'
=> true
irb(main):003:0> require 'logger'
=> false
irb(main):004:0> a = Net::SSH.start('[REDACTED]', 'root', {:port=> 22, :auth_methods => ["gssapi-with-mic"], :verbose => Logger::DEBUG})
D, [2022-11-17T15:16:31.615226 #25961] DEBUG -- net.ssh.transport.session[2a8]: establishing connection to [REDACTED]:22
D, [2022-11-17T15:16:31.655720 #25961] DEBUG -- net.ssh.transport.session[2a8]: connection established
I, [2022-11-17T15:16:31.655859 #25961]  INFO -- net.ssh.transport.server_version[2bc]: negotiating protocol version
D, [2022-11-17T15:16:31.655891 #25961] DEBUG -- net.ssh.transport.server_version[2bc]: local is `SSH-2.0-Ruby/Net::SSH_7.0.1 arm64-darwin21'
D, [2022-11-17T15:16:31.714017 #25961] DEBUG -- net.ssh.transport.server_version[2bc]: remote is `SSH-2.0-OpenSSH_7.9p1'
I, [2022-11-17T15:16:31.714454 #25961]  INFO -- net.ssh.transport.algorithms[2d0]: sending KEXINIT
D, [2022-11-17T15:16:31.714675 #25961] DEBUG -- socket[2e4]: queueing packet nr 0 type 20 len 804
D, [2022-11-17T15:16:31.714735 #25961] DEBUG -- socket[2e4]: sent 808 bytes
D, [2022-11-17T15:16:31.756939 #25961] DEBUG -- socket[2e4]: read 1080 bytes
D, [2022-11-17T15:16:31.756982 #25961] DEBUG -- socket[2e4]: received packet nr 0 type 20 len 1076
I, [2022-11-17T15:16:31.757000 #25961]  INFO -- net.ssh.transport.algorithms[2d0]: got KEXINIT from server
I, [2022-11-17T15:16:31.757034 #25961]  INFO -- net.ssh.transport.algorithms[2d0]: negotiating algorithms
D, [2022-11-17T15:16:31.757076 #25961] DEBUG -- net.ssh.transport.algorithms[2d0]: negotiated:
* kex: ecdh-sha2-nistp521
* host_key: ecdsa-sha2-nistp256
* encryption_server: aes256-ctr
* encryption_client: aes256-ctr
* hmac_client: [email protected]
* hmac_server: [email protected]
* compression_client: none
* compression_server: none
* language_client: 
* language_server: 
D, [2022-11-17T15:16:31.757084 #25961] DEBUG -- net.ssh.transport.algorithms[2d0]: exchanging keys
D, [2022-11-17T15:16:31.760563 #25961] DEBUG -- socket[2e4]: queueing packet nr 1 type 30 len 148
D, [2022-11-17T15:16:31.760584 #25961] DEBUG -- socket[2e4]: sent 152 bytes
D, [2022-11-17T15:16:31.851297 #25961] DEBUG -- socket[2e4]: read 376 bytes
D, [2022-11-17T15:16:31.851346 #25961] DEBUG -- socket[2e4]: received packet nr 1 type 31 len 356
D, [2022-11-17T15:16:31.855606 #25961] DEBUG -- socket[2e4]: queueing packet nr 2 type 21 len 20
D, [2022-11-17T15:16:31.855665 #25961] DEBUG -- socket[2e4]: sent 24 bytes
D, [2022-11-17T15:16:31.855695 #25961] DEBUG -- socket[2e4]: received packet nr 2 type 21 len 12
D, [2022-11-17T15:16:31.855869 #25961] DEBUG -- net.ssh.authentication.session[2f8]: beginning authentication of `root'
D, [2022-11-17T15:16:31.855897 #25961] DEBUG -- socket[2e4]: using encrypt-then-mac
D, [2022-11-17T15:16:31.855932 #25961] DEBUG -- socket[2e4]: queueing packet nr 3 type 5 len 32
D, [2022-11-17T15:16:31.855947 #25961] DEBUG -- socket[2e4]: sent 100 bytes
D, [2022-11-17T15:16:32.003602 #25961] DEBUG -- socket[2e4]: read 100 bytes
D, [2022-11-17T15:16:32.003897 #25961] DEBUG -- socket[2e4]: received packet nr 3 type 6 len 32
D, [2022-11-17T15:16:32.004161 #25961] DEBUG -- net.ssh.authentication.session[2f8]: trying gssapi-with-mic
D, [2022-11-17T15:16:32.004332 #25961] DEBUG -- net.ssh.authentication.methods.gssapi_with_mic[30c]: trying kerberos authentication
D, [2022-11-17T15:16:32.004547 #25961] DEBUG -- socket[2e4]: using encrypt-then-mac
D, [2022-11-17T15:16:32.004687 #25961] DEBUG -- socket[2e4]: queueing packet nr 4 type 50 len 80
D, [2022-11-17T15:16:32.004822 #25961] DEBUG -- socket[2e4]: sent 148 bytes
D, [2022-11-17T15:16:32.085946 #25961] DEBUG -- socket[2e4]: read 100 bytes
D, [2022-11-17T15:16:32.086233 #25961] DEBUG -- socket[2e4]: received packet nr 4 type 60 len 32
D, [2022-11-17T15:16:32.086326 #25961] DEBUG -- net.ssh.authentication.methods.gssapi_with_mic[30c]: gssapi-with-mic proceeding
D, [2022-11-17T15:16:32.107449 #25961] DEBUG -- net.ssh.authentication.methods.gssapi_with_mic[30c]: gssapi-with-mic handshaking
D, [2022-11-17T15:16:32.144739 #25961] DEBUG -- socket[2e4]: using encrypt-then-mac
D, [2022-11-17T15:16:32.144797 #25961] DEBUG -- socket[2e4]: queueing packet nr 5 type 61 len 864
D, [2022-11-17T15:16:32.144853 #25961] DEBUG -- socket[2e4]: sent 932 bytes
D, [2022-11-17T15:16:32.232223 #25961] DEBUG -- socket[2e4]: read 244 bytes
D, [2022-11-17T15:16:32.232455 #25961] DEBUG -- socket[2e4]: received packet nr 5 type 61 len 176
D, [2022-11-17T15:16:32.232730 #25961] DEBUG -- net.ssh.authentication.methods.gssapi_with_mic[30c]: gssapi-with-mic authenticating
D, [2022-11-17T15:16:32.232904 #25961] DEBUG -- socket[2e4]: using encrypt-then-mac
D, [2022-11-17T15:16:32.232955 #25961] DEBUG -- socket[2e4]: queueing packet nr 6 type 66 len 48
D, [2022-11-17T15:16:32.233028 #25961] DEBUG -- socket[2e4]: sent 116 bytes
D, [2022-11-17T15:16:32.280487 #25961] DEBUG -- socket[2e4]: read 84 bytes
D, [2022-11-17T15:16:32.280649 #25961] DEBUG -- socket[2e4]: received packet nr 6 type 52 len 16
I, [2022-11-17T15:16:32.280711 #25961]  INFO -- net.ssh.authentication.methods.gssapi_with_mic[30c]: gssapi-with-mic success
/Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/gssapi-1.3.1/lib/gssapi/lib_gssapi.rb:175: [BUG] Bus Error at 0x0100000203b01c29
ruby 2.7.6p219 (2022-04-12 revision c9c2245c0a) [arm64-darwin21]
-- Control frame information -----------------------------------------------
c:0028 p:---- s:0145 e:000144 CFUNC  :gss_release_name
c:0027 p:0063 s:0139 e:000138 METHOD /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/gssapi-1.3.1/lib/gssapi/lib_gssapi.rb:175
c:0026 p:0085 s:0132 e:000131 METHOD /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/gssapi-1.3.1/lib/gssapi/lib_gssapi.rb:165
c:0025 p:0007 s:0127 e:000126 METHOD /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/ffi-1.15.5/lib/ffi/autopointer.rb:162
c:0024 p:0016 s:0122 e:000121 METHOD /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/ffi-1.15.5/lib/ffi/autopointer.rb:150 [FINISH]
c:0023 p:---- s:0117 e:000116 CFUNC  :encode
c:0022 p:0017 s:0112 e:000111 METHOD /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/reline/unicode.rb:76
c:0021 p:0073 s:0107 e:000105 BLOCK  /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/reline/unicode.rb:108 [FINISH]
c:0020 p:---- s:0102 e:000101 CFUNC  :scan
c:0019 p:0048 s:0097 e:000096 METHOD /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/reline/unicode.rb:99
c:0018 p:0217 s:0088 e:000087 METHOD /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/irb.rb:767
c:0017 p:0063 s:0074 e:000073 BLOCK  /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/irb.rb:545
c:0016 p:0024 s:0071 e:000070 METHOD /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/irb.rb:704
c:0015 p:0007 s:0065 e:000064 BLOCK  /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/irb.rb:538
c:0014 p:0114 s:0060 e:000059 BLOCK  /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/irb/ruby-lex.rb:166 [FINISH]
c:0013 p:---- s:0056 e:000055 CFUNC  :loop
c:0012 p:0005 s:0052 e:000051 BLOCK  /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/irb/ruby-lex.rb:151 [FINISH]
c:0011 p:---- s:0049 e:000048 CFUNC  :catch
c:0010 p:0010 s:0044 e:000043 METHOD /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/irb/ruby-lex.rb:150
c:0009 p:0046 s:0040 E:000638 METHOD /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/irb.rb:537
c:0008 p:0004 s:0035 e:000034 BLOCK  /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/irb.rb:472 [FINISH]
c:0007 p:---- s:0032 e:000031 CFUNC  :catch
c:0006 p:0057 s:0027 E:0005d8 METHOD /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/irb.rb:471
c:0005 p:0104 s:0022 e:000021 METHOD /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/2.7.0/irb.rb:400
c:0004 p:0019 s:0016 e:000015 TOP    /Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/irb-1.2.6/exe/irb:11 [FINISH]
c:0003 p:---- s:0013 e:000012 CFUNC  :load
c:0002 p:0112 s:0008 E:000ec0 EVAL   /Users/[REDACTED]/.rbenv/versions/2.7.6/bin/irb:23 [FINISH]
c:0001 p:0000 s:0003 E:000990 (none) [FINISH]

-- Ruby level backtrace information ----------------------------------------
/Users/[REDACTED]/.rbenv/versions/2.7.6/bin/irb:23:in `<main>'
/Users/[REDACTED]/.rbenv/versions/2.7.6/bin/irb:23:in `load'
/Users/[REDACTED]/.rbenv/versions/2.7.6/lib/ruby/gems/2.7.0/gems/irb-1.2.6/exe/irb:11:in `<top (required)>'

If i comment out the line 175 as mentioned above I am able to successfully login and make use of the connection. I added debug output in order to assist in this report:

[REDACTED]@MBAM2-[REDACTED] hieradata % irb
irb(main):001:0> require 'net/ssh'
=> true
irb(main):002:0> require 'net/ssh/krb'
=> true
irb(main):003:0> a = Net::SSH.start('[REDACTED]', 'root', {:port=> 22, :auth_methods => ["gssapi-with-mic"], :verbose => Logger::DEBUG})
D, [2022-11-17T15:26:05.421682 #27923] DEBUG -- net.ssh.transport.session[2a8]: establishing connection to [REDACTED]:22
D, [2022-11-17T15:26:05.461376 #27923] DEBUG -- net.ssh.transport.session[2a8]: connection established
I, [2022-11-17T15:26:05.461642 #27923]  INFO -- net.ssh.transport.server_version[2bc]: negotiating protocol version
D, [2022-11-17T15:26:05.461682 #27923] DEBUG -- net.ssh.transport.server_version[2bc]: local is `SSH-2.0-Ruby/Net::SSH_7.0.1 arm64-darwin21'
D, [2022-11-17T15:26:05.519387 #27923] DEBUG -- net.ssh.transport.server_version[2bc]: remote is `SSH-2.0-OpenSSH_7.9p1'
I, [2022-11-17T15:26:05.519762 #27923]  INFO -- net.ssh.transport.algorithms[2d0]: sending KEXINIT
D, [2022-11-17T15:26:05.519944 #27923] DEBUG -- socket[2e4]: queueing packet nr 0 type 20 len 804
D, [2022-11-17T15:26:05.519998 #27923] DEBUG -- socket[2e4]: sent 808 bytes
D, [2022-11-17T15:26:05.589123 #27923] DEBUG -- socket[2e4]: read 1080 bytes
D, [2022-11-17T15:26:05.589188 #27923] DEBUG -- socket[2e4]: received packet nr 0 type 20 len 1076
I, [2022-11-17T15:26:05.589204 #27923]  INFO -- net.ssh.transport.algorithms[2d0]: got KEXINIT from server
I, [2022-11-17T15:26:05.589236 #27923]  INFO -- net.ssh.transport.algorithms[2d0]: negotiating algorithms
D, [2022-11-17T15:26:05.589276 #27923] DEBUG -- net.ssh.transport.algorithms[2d0]: negotiated:
* kex: ecdh-sha2-nistp521
* host_key: ecdsa-sha2-nistp256
* encryption_server: aes256-ctr
* encryption_client: aes256-ctr
* hmac_client: [email protected]
* hmac_server: [email protected]
* compression_client: none
* compression_server: none
* language_client: 
* language_server: 
D, [2022-11-17T15:26:05.589283 #27923] DEBUG -- net.ssh.transport.algorithms[2d0]: exchanging keys
D, [2022-11-17T15:26:05.591844 #27923] DEBUG -- socket[2e4]: queueing packet nr 1 type 30 len 148
D, [2022-11-17T15:26:05.591873 #27923] DEBUG -- socket[2e4]: sent 152 bytes
D, [2022-11-17T15:26:05.703802 #27923] DEBUG -- socket[2e4]: read 376 bytes
D, [2022-11-17T15:26:05.703876 #27923] DEBUG -- socket[2e4]: received packet nr 1 type 31 len 356
D, [2022-11-17T15:26:05.707351 #27923] DEBUG -- socket[2e4]: queueing packet nr 2 type 21 len 20
D, [2022-11-17T15:26:05.707412 #27923] DEBUG -- socket[2e4]: sent 24 bytes
D, [2022-11-17T15:26:05.707447 #27923] DEBUG -- socket[2e4]: received packet nr 2 type 21 len 12
D, [2022-11-17T15:26:05.707609 #27923] DEBUG -- net.ssh.authentication.session[2f8]: beginning authentication of `root'
D, [2022-11-17T15:26:05.707636 #27923] DEBUG -- socket[2e4]: using encrypt-then-mac
D, [2022-11-17T15:26:05.707667 #27923] DEBUG -- socket[2e4]: queueing packet nr 3 type 5 len 32
D, [2022-11-17T15:26:05.707687 #27923] DEBUG -- socket[2e4]: sent 100 bytes
D, [2022-11-17T15:26:05.841172 #27923] DEBUG -- socket[2e4]: read 100 bytes
D, [2022-11-17T15:26:05.841348 #27923] DEBUG -- socket[2e4]: received packet nr 3 type 6 len 32
D, [2022-11-17T15:26:05.841480 #27923] DEBUG -- net.ssh.authentication.session[2f8]: trying gssapi-with-mic
D, [2022-11-17T15:26:05.841573 #27923] DEBUG -- net.ssh.authentication.methods.gssapi_with_mic[30c]: trying kerberos authentication
D, [2022-11-17T15:26:05.841673 #27923] DEBUG -- socket[2e4]: using encrypt-then-mac
D, [2022-11-17T15:26:05.841729 #27923] DEBUG -- socket[2e4]: queueing packet nr 4 type 50 len 80
D, [2022-11-17T15:26:05.841807 #27923] DEBUG -- socket[2e4]: sent 148 bytes
D, [2022-11-17T15:26:05.935998 #27923] DEBUG -- socket[2e4]: read 100 bytes
D, [2022-11-17T15:26:05.936257 #27923] DEBUG -- socket[2e4]: received packet nr 4 type 60 len 32
D, [2022-11-17T15:26:05.936335 #27923] DEBUG -- net.ssh.authentication.methods.gssapi_with_mic[30c]: gssapi-with-mic proceeding
D, [2022-11-17T15:26:05.953049 #27923] DEBUG -- net.ssh.authentication.methods.gssapi_with_mic[30c]: gssapi-with-mic handshaking
D, [2022-11-17T15:26:06.002661 #27923] DEBUG -- socket[2e4]: using encrypt-then-mac
D, [2022-11-17T15:26:06.002730 #27923] DEBUG -- socket[2e4]: queueing packet nr 5 type 61 len 864
D, [2022-11-17T15:26:06.002779 #27923] DEBUG -- socket[2e4]: sent 932 bytes
D, [2022-11-17T15:26:06.164218 #27923] DEBUG -- socket[2e4]: read 244 bytes
D, [2022-11-17T15:26:06.164561 #27923] DEBUG -- socket[2e4]: received packet nr 5 type 61 len 176
D, [2022-11-17T15:26:06.164981 #27923] DEBUG -- net.ssh.authentication.methods.gssapi_with_mic[30c]: gssapi-with-mic authenticating
D, [2022-11-17T15:26:06.165270 #27923] DEBUG -- socket[2e4]: using encrypt-then-mac
D, [2022-11-17T15:26:06.165340 #27923] DEBUG -- socket[2e4]: queueing packet nr 6 type 66 len 48
D, [2022-11-17T15:26:06.165553 #27923] DEBUG -- socket[2e4]: sent 116 bytes
D, [2022-11-17T15:26:06.249257 #27923] DEBUG -- socket[2e4]: read 84 bytes
D, [2022-11-17T15:26:06.249632 #27923] DEBUG -- socket[2e4]: received packet nr 6 type 52 len 16
I, [2022-11-17T15:26:06.249790 #27923]  INFO -- net.ssh.authentication.methods.gssapi_with_mic[30c]: gssapi-with-mic success
Releasing gss_name_t with min_stat #<FFI::MemoryPointer address=0x0000000148e70710 size=4>
Releasing gss_name_t at 129005500
=> #<Net::SSH::Connection::Session:0x0000000149ab57d0 @logger=#<Logger:0x000000014c89b410 @level=0, @progname=nil, @default_formatter=#<Logger::Formatter:0x000000014c89b3e8 @datetime_format=nil>, @formatter=nil, @logdev=#<Logger::LogDevice:0x000000014c89b398 @shift_period_suffix=nil, @shift_si...
irb(main):004:0>

Please can you assist, I make use of this gem to interact with hosts via SSH to automate many tasks. If you need any additional information/debug output do let me know.

HenluStarke avatar Nov 17 '22 14:11 HenluStarke

I also ran into this issue. I found a fairly hacky workaround:

  1. Install krb5 from homebrew (brew install krb5)
  2. In your gssapi gem install location, change the path of the library that is defined here https://github.com/zenchild/gssapi/blob/00965291b00c0e0f6627e93306ca9cbb76d80c8a/lib/gssapi/lib_gssapi_loader.rb#L26 to the homebrew library: /opt/homebrew/opt/krb5/lib/libgssapi_krb5.dylib

The path in the gem right now does not exist. I couldn't find the equivalent dylib for Ventura on my system, so I'm guessing Apple changed how they are doing kerberos in a way that is incompatible with this gem.

petracvv avatar Sep 18 '23 17:09 petracvv