Loading...

Type: Bug
Resolution: Done
Priority: Blocker
Fix Version/s: None
Affects Version/s: AMQ 7.1.0.GA
Component/s: amqp-protocol, security
Labels:
- FailedQA
- automated

Target Release:

AMQ 7.1.0.GA
Workaround Description:

Hide

Initiate first connection on random/tmp queue.
OR
Don't use super-secured patched IBM JDK...

Show
Initiate first connection on random/tmp queue. OR Don't use super-secured patched IBM JDK...
Steps to Reproduce:
Hide

Set up Kerberos, install ibm jdk + patch for aes 256 ciphers (see linked/related issue for details).

Create queue (not needed)

Use any AMQP client with GSSAPI authentication (should not fail)

Repeat previous step - authentication passes
Show
Set up Kerberos, install ibm jdk + patch for aes 256 ciphers (see linked/related issue for details). Create queue (not needed) Use any AMQP client with GSSAPI authentication (should not fail) Repeat previous step - authentication passes

SFDC Cases Counter:
SFDC Cases Open:
SFDC Cases Links:

Right after broker is started, the first connection from any client is automatically refused by broker. Any other subsequent connection is fine. This only happens when IBM JDK is used for broker.

broker log

18:24:53.257 FINE  [javax.security.sasl] SASLIMPL01:Preferred qop property: null
18:24:53.257 FINE  [javax.security.sasl] SASLIMPL02:Preferred qop mask: 1
18:24:53.258 FINE  [javax.security.sasl] SASLIMPL03:Preferred qops : 1 
18:24:53.258 FINE  [javax.security.sasl] SASLIMPL04:Preferred strength property: null
18:24:53.258 FINE  [javax.security.sasl] SASLIMPL05:Cipher strengths: 4 2 1 
18:24:53.258 FINE  [javax.security.sasl] KRB5SRV01:Using service name: null
18:24:53.292 FINE  [javax.security.sasl] KRB5SRV02:Initialization complete
18:24:53.343 FINE  [javax.security.sasl] KRB5SRV05:Peer name is : charlie@MSGQE.COM, my name is : amqp/amq-server.msgqe.com@MSGQE.COM
18:24:53.347 FINE  [javax.security.sasl] KRB5SRV06:Supported protections: 1; recv max buf size: 65,536
18:24:53.358 INFO  [org.apache.activemq.artemis.protocol.amqp.sasl.GSSAPIServerSASL] Error on sasl input: java.security.PrivilegedActionException: javax.security.sasl.SaslException: Final handshake step failed [Caused by org.ietf.jgss.GSSException, major code: 11, minor code: 0
        major string: General failure, unspecified at GSSAPI level
        minor string: Error while decoding token: java.lang.ArrayIndexOutOfBoundsException: Array index out of range: 0]: java.security.PrivilegedActionException: javax.security.sasl.SaslException: Final handshake step failed [Caused by org.ietf.jgss.GSSException, major code: 11, minor code: 0
        major string: General failure, unspecified at GSSAPI level
        minor string: Error while decoding token: java.lang.ArrayIndexOutOfBoundsException: Array index out of range: 0]
        at java.security.AccessController.doPrivileged(AccessController.java:692) [vm.jar:1.8.0]
        at javax.security.auth.Subject.doAs(Subject.java:569) [rt.jar:1.8.0]
        at org.apache.activemq.artemis.protocol.amqp.sasl.GSSAPIServerSASL.processSASL(GSSAPIServerSASL.java:77) [artemis-amqp-protocol-2.4.0.amq-710001-redhat-1.jar:]
        at org.apache.activemq.artemis.protocol.amqp.proton.handler.ProtonHandler.checkSASL(ProtonHandler.java:315) [artemis-amqp-protocol-2.4.0.amq-710001-redhat-1.jar:]
        at org.apache.activemq.artemis.protocol.amqp.proton.handler.ProtonHandler.flush(ProtonHandler.java:274) [artemis-amqp-protocol-2.4.0.amq-710001-redhat-1.jar:]
        at org.apache.activemq.artemis.protocol.amqp.proton.handler.ProtonHandler.inputBuffer(ProtonHandler.java:243) [artemis-amqp-protocol-2.4.0.amq-710001-redhat-1.jar:]
        at org.apache.activemq.artemis.protocol.amqp.proton.AMQPConnectionContext.inputBuffer(AMQPConnectionContext.java:150) [artemis-amqp-protocol-2.4.0.amq-710001-redhat-1.jar:]
        at org.apache.activemq.artemis.protocol.amqp.broker.ActiveMQProtonRemotingConnection.bufferReceived(ActiveMQProtonRemotingConnection.java:141) [artemis-amqp-protocol-2.4.0.amq-710001-redhat-1.jar:]
        at org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl$DelegatingBufferHandler.bufferReceived(RemotingServiceImpl.java:642) [artemis-server-2.4.0.amq-710001-redhat-1.jar:2.4.0.amq-710001-redhat-1]
        at org.apache.activemq.artemis.core.remoting.impl.netty.ActiveMQChannelHandler.channelRead(ActiveMQChannelHandler.java:68) [artemis-core-client-2.4.0.amq-710001-redhat-1.jar:2.4.0.amq-710001-redhat-1]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.16.Final-redhat-1.jar:4.1.16.Final-redhat-1]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.16.Final-redhat-1.jar:4.1.16.Final-redhat-1]
        at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340) [netty-all-4.1.16.Final-redhat-1.jar:4.1.16.Final-redhat-1]
        at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1359) [netty-all-4.1.16.Final-redhat-1.jar:4.1.16.Final-redhat-1]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362) [netty-all-4.1.16.Final-redhat-1.jar:4.1.16.Final-redhat-1]
        at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348) [netty-all-4.1.16.Final-redhat-1.jar:4.1.16.Final-redhat-1]
        at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:935) [netty-all-4.1.16.Final-redhat-1.jar:4.1.16.Final-redhat-1]
        at io.netty.channel.epoll.AbstractEpollStreamChannel$EpollStreamUnsafe.epollInReady(AbstractEpollStreamChannel.java:797) [netty-all-4.1.16.Final-redhat-1.jar:4.1.16.Final-redhat-1]
        at io.netty.channel.epoll.EpollEventLoop.processReady(EpollEventLoop.java:404) [netty-all-4.1.16.Final-redhat-1.jar:4.1.16.Final-redhat-1]
        at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:304) [netty-all-4.1.16.Final-redhat-1.jar:4.1.16.Final-redhat-1]
        at io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858) [netty-all-4.1.16.Final-redhat-1.jar:4.1.16.Final-redhat-1]
        at java.lang.Thread.run(Thread.java:785) [vm.jar:2.6 (07-22-2017)]
Caused by: javax.security.sasl.SaslException: Final handshake step failed [Caused by org.ietf.jgss.GSSException, major code: 11, minor code: 0
        major string: General failure, unspecified at GSSAPI level
        minor string: Error while decoding token: java.lang.ArrayIndexOutOfBoundsException: Array index out of range: 0]
        at com.ibm.security.sasl.gsskerb.GssKrb5Server.doHandshake2(GssKrb5Server.java:347) [ibmsaslprovider.jar:8.0 build_20150506]
        at com.ibm.security.sasl.gsskerb.GssKrb5Server.evaluateResponse(GssKrb5Server.java:178) [ibmsaslprovider.jar:8.0 build_20150506]
        at org.apache.activemq.artemis.protocol.amqp.sasl.GSSAPIServerSASL.lambda$processSASL$1(GSSAPIServerSASL.java:77) [artemis-amqp-protocol-2.4.0.amq-710001-redhat-1.jar:]
        at org.apache.activemq.artemis.protocol.amqp.sasl.GSSAPIServerSASL$$Lambda$36.0000000020287D60.run(Unknown Source)
        at java.security.AccessController.doPrivileged(AccessController.java:686) [vm.jar:1.8.0]
        ... 21 more
Caused by: org.ietf.jgss.GSSException, major code: 11, minor code: 0
        major string: General failure, unspecified at GSSAPI level
        minor string: Error while decoding token: java.lang.ArrayIndexOutOfBoundsException: Array index out of range: 0
        at com.ibm.security.jgss.i18n.I18NException.throwGSSException(Unknown Source) [ibmjgssprovider.jar:8.0 build_20170710]
        at com.ibm.security.jgss.mech.krb5.X.g(Unknown Source) [ibmjgssprovider.jar:8.0 build_20170710]
        at com.ibm.security.jgss.mech.krb5.X.b(Unknown Source) [ibmjgssprovider.jar:8.0 build_20170710]
        at com.ibm.security.jgss.mech.krb5.g.unwrap(Unknown Source) [ibmjgssprovider.jar:8.0 build_20170710]
        at com.ibm.security.jgss.GSSContextImpl.unwrap(Unknown Source) [ibmjgssprovider.jar:8.0 build_20170710]
        at com.ibm.security.sasl.gsskerb.GssKrb5Server.doHandshake2(GssKrb5Server.java:270) [ibmsaslprovider.jar:8.0 build_20150506]
        ... 25 more

(next message)

18:24:53.372 FINE  [org.apache.qpid.proton.engine.impl.SaslImpl] SASL negotiation done: SaslImpl [_outcome=PN_SASL_AUTH, state=PN_SASL_FAIL, done=true, role=SERVER]
18:24:53.434 DEBUG [org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl] RemotingServiceImpl::removing connection ID 977275ab
18:24:55.438 DEBUG [org.apache.activemq.artemis.core.server.reload.ReloadManagerImpl] Validating lastModified 1512752949000 modified = 1512752949000 on file:/opt/jboss-amq-7-i0//etc/broker.xml
18:24:59.815 FINE  [javax.security.sasl] SASLIMPL01:Preferred qop property: null
18:24:59.816 FINE  [javax.security.sasl] SASLIMPL02:Preferred qop mask: 1
18:24:59.816 FINE  [javax.security.sasl] SASLIMPL03:Preferred qops : 1 
18:24:59.816 FINE  [javax.security.sasl] SASLIMPL04:Preferred strength property: null
18:24:59.816 FINE  [javax.security.sasl] SASLIMPL05:Cipher strengths: 4 2 1 
18:24:59.817 FINE  [javax.security.sasl] KRB5SRV01:Using service name: null
18:24:59.818 FINE  [javax.security.sasl] KRB5SRV02:Initialization complete
18:24:59.831 FINE  [javax.security.sasl] KRB5SRV05:Peer name is : charlie@MSGQE.COM, my name is : amqp/amq-server.msgqe.com@MSGQE.COM
18:24:59.834 FINE  [javax.security.sasl] KRB5SRV06:Supported protections: 1; recv max buf size: 65,536
18:24:59.841 FINE  [javax.security.sasl] KRB5SRV10:Selected protection: 1; privacy: false; integrity: false
18:24:59.841 FINE  [javax.security.sasl] KRB5SRV11:Client max recv size: 65,535; server max send size: 65,535; rawSendSize: 65,482
18:24:59.842 FINE  [javax.security.sasl] KRB5SRV12:Authzid: charlie@MSGQE.COM
18:24:59.842 FINE  [org.apache.qpid.proton.engine.impl.SaslImpl] SASL negotiation done: SaslImpl [_outcome=PN_SASL_OK, state=PN_SASL_PASS, done=true, role=SERVER]
18:24:59.847 FINE  [proton.trace] IN: CH[0] : Open{ containerId='a1666a4b-1fd4-4b1f-b1f7-5e098ff8dda0', hostname='null', maxFrameSize=4294967295, channelMax=32767, idleTimeOut=null, outgoingLocales=null, incomingLocales=null, offeredCapabilities=null, desiredCapabilities=null, properties={qpid.client_process=aac0_sender, qpid.client_pid=26527, qpid.client_ppid=18362}}
18:24:59.851 FINE  [proton.trace] IN: CH[0] : Begin{remoteChannel=null, nextOutgoingId=0, incomingWindow=2147483647, outgoingWindow=2147483647, handleMax=4294967295, offeredCapabilities=null, desiredCapabilities=null, properties=null}
18:24:59.869 DEBUG [org.apache.activemq.artemis.spi.core.security.jaas.Krb5LoginModule] login [charlie@MSGQE.COM]
18:24:59.871 DEBUG [org.apache.activemq.artemis.spi.core.security.jaas.PropertiesLoader] Initialized debug
18:24:59.876 DEBUG [org.apache.activemq.artemis.spi.core.security.jaas.ReloadableProperties] Load of: PropsFile=/opt/jboss-amq-7-i0/etc/artemis-users.properties
18:24:59.877 DEBUG [org.apache.activemq.artemis.spi.core.security.jaas.ReloadableProperties] Load of: PropsFile=/opt/jboss-amq-7-i0/etc/artemis-roles.properties
18:24:59.878 DEBUG [org.apache.activemq.artemis.spi.core.security.jaas.Krb5LoginModule] commit, result: true
18:24:59.878 DEBUG [org.apache.activemq.artemis.spi.core.security.jaas.PropertiesLoginModule] commit, result: false
18:24:59.899 FINE  [proton.trace] IN: CH[0] : Attach{name='lalaQ_b39766f5-6f49-4060-a65b-28bed4b335f7', handle=0, role=SENDER, sndSettleMode=MIXED, rcvSettleMode=FIRST, source=Source{address='lalaQ', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, distributionMode=null, filter=null, defaultOutcome=null, outcomes=null, capabilities=null}, target=Target{address='lalaQ', durable=NONE, expiryPolicy=SESSION_END, timeout=0, dynamic=false, dynamicNodeProperties=null, capabilities=null}, unsettled=null, incompleteUnsettled=false, initialDeliveryCount=0, maxMessageSize=0, offeredCapabilities=null, desiredCapabilities=null, properties=null}
18:24:59.910 DEBUG [org.apache.activemq.artemis.spi.core.security.jaas.Krb5LoginModule] login [charlie@MSGQE.COM]
18:24:59.910 DEBUG [org.apache.activemq.artemis.spi.core.security.jaas.PropertiesLoader] Initialized debug
18:24:59.911 DEBUG [org.apache.activemq.artemis.spi.core.security.jaas.Krb5LoginModule] commit, result: true
18:24:59.914 DEBUG [org.apache.activemq.artemis.spi.core.security.jaas.PropertiesLoginModule] commit, result: false
18:24:59.928 FINE  [proton.trace] IN: CH[0] : Transfer{handle=0, deliveryId=0, deliveryTag=\x00\x00\x00\x00, messageFormat=0, settled=false, more=false, rcvSettleMode=null, state=null, resume=false, aborted=false, batchable=false}[\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00]
18:24:59.948 DEBUG [org.apache.activemq.artemis.core.server.impl.QueueImpl] QueueImpl[name=lalaQ, postOffice=PostOfficeImpl [server=ActiveMQServerImpl::serverUUID=ae9a9103-dc32-11e7-97c8-5254000a0c36], temp=false]@b5f98aed doing deliver. messageReferences=0
18:24:59.949 FINE  [proton.trace] IN: CH[0] : End{error=null}
18:24:59.959 FINE  [proton.trace] IN: CH[0] : Close{error=null}
18:24:59.960 DEBUG [org.apache.activemq.artemis.core.remoting.server.impl.RemotingServiceImpl] RemotingServiceImpl::removing connection ID 20c28150

Client logs

============== Qpid JMS client
1root@msgqa-26-rhel6x-0:~# java  -Djava.security.auth.login.config=/var/dtests/node_data/gssapi/msgqe.com/qpid-jms-client/ibm-jdk/alice.login.config  -Djava.security.krb5.conf=/var/dtests/node_data/gssapi/msgqe.com/msgqe_krb5.conf  -jar /var/dtests/node_data/clients/aac1.jar sender  --log-msgs dict --broker amq-server.msgqe.com:5672 --conn-auth-mechanisms GSSAPI --address lalaQ --count 1
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: debug=true
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: principal=alice
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: credsType=initiate and accept
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] config: useDefaultCcache=false
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] config: useCcache=null
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] config: useDefaultKeytab=false
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] config: useKeytab=/var/dtests/node_data/gssapi/msgqe.com/keytabs/alice.keytab
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: forwardable=false (default)
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: renewable=false (default)
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: proxiable=false (default)
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: tryFirstPass=false (default)
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: useFirstPass=false (default)
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: moduleBanner=false (default)
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: interactive login? no
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Try keytab for principal=alice
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Done retrieving Kerberos creds from keytab
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Retrieving Kerberos creds from cache for principal=alice
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Non-interactive login; no callbacks necessary.
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] No Kerberos creds in cache for principal alice
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Doing Kerberos login for principal alice@MSGQE.COM
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Kerberos login complete
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Login successful
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] kprincipal : alice@MSGQE.COM
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] alice@MSGQE.COM added to Subject
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Kerberos ticket added to Subject
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] KeyTab added to Subject
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] added key of type aes256-cts-hmac-sha1-96
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] added key of type aes128-cts-hmac-sha1-96 
18:35:54,073 ERROR Failed to connect to remote at: amqp://amq-server.msgqe.com:5672?amqp.saslMechanisms=GSSAPI
18:35:54,110 ERROR Client failed to authenticate using SASL: GSSAPI
javax.jms.JMSSecurityException: Client failed to authenticate using SASL: GSSAPI
	at org.apache.qpid.jms.provider.amqp.AmqpSaslAuthenticator.recordFailure(AmqpSaslAuthenticator.java:157)
	at org.apache.qpid.jms.provider.amqp.AmqpSaslAuthenticator.handleSaslFail(AmqpSaslAuthenticator.java:136)
	at org.apache.qpid.jms.provider.amqp.AmqpSaslAuthenticator.tryAuthenticate(AmqpSaslAuthenticator.java:68)
	at org.apache.qpid.jms.provider.amqp.AmqpProvider.processSaslAuthentication(AmqpProvider.java:954)
	at org.apache.qpid.jms.provider.amqp.AmqpProvider.processUpdates(AmqpProvider.java:938)
	at org.apache.qpid.jms.provider.amqp.AmqpProvider.access$1800(AmqpProvider.java:101)
	at org.apache.qpid.jms.provider.amqp.AmqpProvider$17.run(AmqpProvider.java:789)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:522)
	at java.util.concurrent.FutureTask.run(FutureTask.java:277)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:191)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1160)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.lang.Thread.run(Thread.java:785)


1root@msgqa-26-rhel6x-0:~# java  -Djava.security.auth.login.config=/var/dtests/node_data/gssapi/msgqe.com/qpid-jms-client/ibm-jdk/alice.login.config  -Djava.security.krb5.conf=/var/dtests/node_data/gssapi/msgqe.com/msgqe_krb5.conf  -jar /var/dtests/node_data/clients/aac1.jar sender  --log-msgs dict --broker amq-server.msgqe.com:5672 --conn-auth-mechanisms GSSAPI --address lalaQ --count 1
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: debug=true
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: principal=alice
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: credsType=initiate and accept
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] config: useDefaultCcache=false
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] config: useCcache=null
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] config: useDefaultKeytab=false
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] config: useKeytab=/var/dtests/node_data/gssapi/msgqe.com/keytabs/alice.keytab
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: forwardable=false (default)
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: renewable=false (default)
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: proxiable=false (default)
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: tryFirstPass=false (default)
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: useFirstPass=false (default)
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: moduleBanner=false (default)
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] JAAS config: interactive login? no
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Try keytab for principal=alice
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Done retrieving Kerberos creds from keytab
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Retrieving Kerberos creds from cache for principal=alice
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Non-interactive login; no callbacks necessary.
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] No Kerberos creds in cache for principal alice
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Doing Kerberos login for principal alice@MSGQE.COM
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Kerberos login complete
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Login successful
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] kprincipal : alice@MSGQE.COM
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] alice@MSGQE.COM added to Subject
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] Kerberos ticket added to Subject
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] KeyTab added to Subject
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] added key of type aes256-cts-hmac-sha1-96
[JGSS_DBG_CRED]  AmqpProvider :(1):[amqp://amq-server.msgqe.com:5672] added key of type aes128-cts-hmac-sha1-96 
{'address': 'lalaQ', 'group-id': None, 'subject': None, 'user-id': None, 'correlation-id': None, 'content-encoding': None, 'priority': 4, 'type': None, 'ttl': 0, 'absolute-expiry-time': 0, 'content': None, 'redelivered': False, 'reply-to-group-id': None, 'durable': True, 'delivery-time': 1512754562200, 'group-sequence': '0', 'creation-time': 1512754562200, 'content-type': None, 'id': 'a9b7bc66-7644-445d-8617-1d09c7864af9:1:1:1-1', 'reply-to': None, 'properties': {'JMSXDeliveryCount': 1}}

============== Qpid Proton python
root@msgqa-26-rhel6x-0:~# KRB5_CONFIG=/var/dtests/node_data/gssapi/msgqe.com/msgqe_krb5.conf  /var/dtests/node_data/clients/aac5_sender.py  --broker-url "amq-server.msgqe.com:5672/lalaQ" --log-msgs dict --count 1
Traceback (most recent call last):
  File "/var/dtests/node_data/clients/aac5_sender.py", line 374, in <module>
    main()
  File "/var/dtests/node_data/clients/aac5_sender.py", line 367, in main
    container.run()
  File "/usr/lib64/python2.6/site-packages/proton/reactor.py", line 148, in run
    while self.process(): pass
  File "/usr/lib64/python2.6/site-packages/proton/reactor.py", line 174, in process
    self._check_errors()
  File "/usr/lib64/python2.6/site-packages/proton/reactor.py", line 170, in _check_errors
    _compat.raise_(exc, value, tb)
  File "/usr/lib64/python2.6/site-packages/proton/__init__.py", line 4081, in dispatch
    ev.dispatch(self.handler)
  File "/usr/lib64/python2.6/site-packages/proton/__init__.py", line 3990, in dispatch
    result = dispatch(handler, type.method, self)
  File "/usr/lib64/python2.6/site-packages/proton/__init__.py", line 3870, in dispatch
    return handler.on_unhandled(method, *args)
  File "/var/dtests/node_data/clients/python/Aac5CoreClient.py", line 307, in on_unhandled
    raise ClientException(err_message)
Aac5CoreClient.ClientException: Transport error: amqp:unauthorized-access - Authentication failed [mech=GSSAPI]

1root@msgqa-26-rhel6x-0:~# KRB5_CONFIG=/var/dtests/node_data/gssapi/msgqe.com/msgqe_krb5.conf  /var/dtests/node_data/clients/aac5_sender.py  --broker-url "amq-server.msgqe.com:5672/lalaQ" --log-msgs dict --count 1
{'address': None, 'annotations': None, 'body': 'None', 'content': 'None', 'content_encoding': 'None', 'content_type': 'text/plain', 'correlation_id': None, 'creation_time': 0.000000, 'delivery_count': 0, 'durable': False, 'expiration': 0, 'first_acquirer': False, 'group_id': None, 'group_sequence': 0, 'id': None, 'inferred': False, 'instructions': None, 'priority': 4, 'properties': {}, 'reply_to': None, 'reply_to_group_id': None, 'subject': None, 'ttl': 0, 'user_id': ''}

root@msgqa-26-rhel6x-0:~# KRB5_TRACE=/dev/stdout PN_TRACE_FRM=1 KRB5_CONFIG=/var/dtests/node_data/gssapi/msgqe.com/msgqe_krb5.conf  /var/dtests/node_data/clients/aac0_sender  --log-msgs dict --broker amq-server.msgqe.com:5672 --connection-options "{  sasl_mechanisms : 'GSSAPI', protocol : 'amqp1.0' }" --address lalaQ --count 1
[26518] 1512753892.93214: ccselect module realm chose cache FILE:/tmp/krb5cc_0 with client principal charlie@MSGQE.COM for server principal amqp/amq-server.msgqe.com@MSGQE.COM
[26518] 1512753892.93373: Retrieving charlie@MSGQE.COM -> krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from FILE:/tmp/krb5cc_0 with result: -1765328243/Matching credential not found
[26518] 1512753892.93412: Getting credentials charlie@MSGQE.COM -> amqp/amq-server.msgqe.com@MSGQE.COM using ccache FILE:/tmp/krb5cc_0
[26518] 1512753892.93494: Retrieving charlie@MSGQE.COM -> amqp/amq-server.msgqe.com@MSGQE.COM from FILE:/tmp/krb5cc_0 with result: 0/Success
[26518] 1512753892.93636: Creating authenticator for charlie@MSGQE.COM -> amqp/amq-server.msgqe.com@MSGQE.COM, seqnum 188997331, subkey aes256-cts/DE8C, session key aes256-cts/CF05
[26518] 1512753893.351856: ccselect module realm chose cache FILE:/tmp/krb5cc_0 with client principal charlie@MSGQE.COM for server principal amqp/amq-server.msgqe.com@MSGQE.COM
[26518] 1512753893.351919: Retrieving charlie@MSGQE.COM -> krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from FILE:/tmp/krb5cc_0 with result: -1765328243/Matching credential not found
[26518] 1512753893.352031: Read AP-REP, time 1512753892.93651, subkey aes256-cts/DE8C, seqnum 42
Authentication failed



1root@msgqa-26-rhel6x-0:~# KRB5_TRACE=/dev/stdout PN_TRACE_FRM=1 KRB5_CONFIG=/var/dtests/node_data/gssapi/msgqe.com/msgqe_krb5.conf  /var/dtests/node_data/clients/aac0_sender  --log-msgs dict --broker amq-server.msgqe.com:5672 --connection-options "{  sasl_mechanisms : 'GSSAPI', protocol : 'amqp1.0' }" --address lalaQ --count 1
[26527] 1512753899.783548: ccselect module realm chose cache FILE:/tmp/krb5cc_0 with client principal charlie@MSGQE.COM for server principal amqp/amq-server.msgqe.com@MSGQE.COM
[26527] 1512753899.783678: Retrieving charlie@MSGQE.COM -> krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from FILE:/tmp/krb5cc_0 with result: -1765328243/Matching credential not found
[26527] 1512753899.783716: Getting credentials charlie@MSGQE.COM -> amqp/amq-server.msgqe.com@MSGQE.COM using ccache FILE:/tmp/krb5cc_0
[26527] 1512753899.783796: Retrieving charlie@MSGQE.COM -> amqp/amq-server.msgqe.com@MSGQE.COM from FILE:/tmp/krb5cc_0 with result: 0/Success
[26527] 1512753899.783934: Creating authenticator for charlie@MSGQE.COM -> amqp/amq-server.msgqe.com@MSGQE.COM, seqnum 747952340, subkey aes256-cts/B7F7, session key aes256-cts/CF05
[26527] 1512753899.833096: ccselect module realm chose cache FILE:/tmp/krb5cc_0 with client principal charlie@MSGQE.COM for server principal amqp/amq-server.msgqe.com@MSGQE.COM
[26527] 1512753899.833155: Retrieving charlie@MSGQE.COM -> krb5_ccache_conf_data/proxy_impersonator@X-CACHECONF: from FILE:/tmp/krb5cc_0 with result: -1765328243/Matching credential not found
[26527] 1512753899.833292: Read AP-REP, time 1512753899.783949, subkey aes256-cts/B7F7, seqnum 947
[0x1ff6220]:  -> AMQP
[0x1ff6220]:  <- AMQP
[0x1ff6220]:0 -> @open(16) [container-id="a1666a4b-1fd4-4b1f-b1f7-5e098ff8dda0", channel-max=32767, properties={:"qpid.client_process"=:"aac0_sender", :"qpid.client_pid"=26527, :"qpid.client_ppid"=18362}]
[0x1ff6220]:0 <- @open(16) [container-id="amq", max-frame-size=4294967295, channel-max=65535, idle-time-out=30000, offered-capabilities=@PN_SYMBOL[:"sole-connection-for-container", :"DELAYED_DELIVERY", :"SHARED-SUBS", :"ANONYMOUS-RELAY"], properties={:product="apache-activemq-artemis", :version="2.4.0.amq-710001-redhat-1"}]
[0x1ff6220]:0 -> @begin(17) [next-outgoing-id=0, incoming-window=2147483647, outgoing-window=2147483647]
[0x1ff6220]:0 <- @begin(17) [remote-channel=0, next-outgoing-id=1, incoming-window=2147483647, outgoing-window=2147483647, handle-max=65535]
[0x1ff6220]:0 -> @attach(18) [name="lalaQ_b39766f5-6f49-4060-a65b-28bed4b335f7", handle=0, role=false, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="lalaQ", durable=0, timeout=0, dynamic=false], target=@target(41) [address="lalaQ", durable=0, timeout=0, dynamic=false], initial-delivery-count=0, max-message-size=0]
[0x1ff6220]:0 <- @attach(18) [name="lalaQ_b39766f5-6f49-4060-a65b-28bed4b335f7", handle=0, role=true, snd-settle-mode=2, rcv-settle-mode=0, source=@source(40) [address="lalaQ"], target=@target(41) [address="lalaQ"]]
[0x1ff6220]:0 <- @flow(19) [next-incoming-id=0, incoming-window=2147483647, next-outgoing-id=1, outgoing-window=2147483647, handle=0, delivery-count=0, link-credit=1000]
{'redelivered': False, 'reply_to': None, 'subject': None, 'content_type': None, 'id': None, 'user_id': None, 'correlation_id': None, 'priority': 0, 'durable': False, 'ttl': 0, 'properties': {}, 'content': None}
[0x1ff6220]:0 -> @transfer(20) [handle=0, delivery-id=0, delivery-tag=b"\x00\x00\x00\x00", message-format=0, settled=false, more=false, resume=false, aborted=false, batchable=false] (15) "\x00Sp\xc0\x04\x02BP\x00\x00St\xc1\x01\x00"
[0x1ff6220]:0 <- @disposition(21) [role=true, first=0, last=0, settled=true, state=@accepted(36) []]
[0x1ff6220]:0 -> @end(23) []
[0x1ff6220]:0 <- @end(23) []
[0x1ff6220]:0 -> @close(24) []
[0x1ff6220]:  -> EOS
[0x1ff6220]:0 <- @close(24) []
[0x1ff6220]:  <- EOS

- - Sort By Name
  - Sort By Date
  - Ascending
  - Descending
  - Thumbnails
  - List
  - Download All

artemis_debug_gssapi_both.log
632 kB
2017/12/11 8:26 AM
artemis_debug_gssapi_both.log
596 kB
2017/12/11 8:24 AM
artemis_debug_gssapi.log
596 kB
2017/12/11 8:19 AM
artemis.log
52 kB
2017/12/11 7:46 AM
clients.log
152 kB
2017/12/11 7:46 AM

blocks

ENTMQBR-789 Add support for Ldap role mapping of kerberos authenticated users

Closed

ENTMQBR-790 Add support for authentication to ldap via kerberos for ldapLoginModule

Closed

Details

Description

Attachments

Attachments

Issue Links

Easy Agile Planning Poker

Activity

People

Dates