[
https://issues.apache.org/jira/browse/QPIDJMS-33?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Robbie Gemmell resolved QPIDJMS-33.
-----------------------------------
Resolution: Fixed
Assignee: Robbie Gemmell
Resolving, verified against qpidd 0.32 that the change allows the
authentication to complete when using EXTERNAL.
> SASL EXTERNAL doesn't seem to work against the C++ broker
> ---------------------------------------------------------
>
> Key: QPIDJMS-33
> URL: https://issues.apache.org/jira/browse/QPIDJMS-33
> Project: Qpid JMS
> Issue Type: Bug
> Components: qpid-jms-client
> Affects Versions: 0.1.0
> Reporter: JAkub Scholz
> Assignee: Robbie Gemmell
> Fix For: 0.2.0
>
>
> It looks like the client selects the EXTERNAL mechanism when it is offered by
> the broker, but it looks like it never responds to the challenge sent by the
> broker (Qpid C++ 0.22 / MRG-M 3.0).
> Broker log:
> {noformat}
> 2015-03-26 11:38:41 [Network] trace Accepting SSL connection.
> 2015-03-26 11:38:41 [Network] info Set TCP_NODELAY on connection to
> 172.23.39.79:53580
> 2015-03-26 11:38:41 [Network] trace Accepting SSL connection.
> 2015-03-26 11:38:41 [System] debug RECV
> [qpid.172.16.153.11:10126-172.23.39.79:53580]: INIT(1-0)
> 2015-03-26 11:38:41 [Broker] info Using AMQP 1.0 (with SASL layer)
> 2015-03-26 11:38:41 [Security] debug External ssf=128 and
> auth=CBKFR_TESTCALMMACC1
> 2015-03-26 11:38:41 [Security] debug min_ssf: 0, max_ssf: 0, external_ssf: 128
> 2015-03-26 11:38:41 [Security] debug external auth detected and set to
> CBKFR_TESTCALMMACC1
> 2015-03-26 11:38:41 [Model] trace Mgmt create connection.
> id:qpid.172.16.153.11:10126-172.23.39.79:53580
> 2015-03-26 11:38:41 [Management] debug Management object (V1) added:
> org.apache.qpid.broker:connection:qpid.172.16.153.11:10126-172.23.39.79:53580
> 2015-03-26 11:38:41 [Security] trace ACL ConnectionCounter new connection:
> qpid.172.16.153.11:10126-172.23.39.79:53580
> 2015-03-26 11:38:41 [Security] info SASL: Mechanism list: EXTERNAL
> 2015-03-26 11:38:41 [Security] trace Completed encoding of frame of 30 bytes
> 2015-03-26 11:38:41 [Protocol] debug
> qpid.172.16.153.11:10126-172.23.39.79:53580 Sent SASL-MECHANISMS(EXTERNAL) 30
> 2015-03-26 11:38:41 [Protocol] debug
> qpid.172.16.153.11:10126-172.23.39.79:53580 writing protocol header: 1-0
> 2015-03-26 11:38:41 [Security] trace
> qpid.172.16.153.11:10126-172.23.39.79:53580 Sasl::encode(65536): 38
> 2015-03-26 11:38:41 [Security] trace
> qpid.172.16.153.11:10126-172.23.39.79:53580 Sasl::decode(1): 0
> 2015-03-26 11:38:41 [Security] trace Reading SASL frame of size 24
> 2015-03-26 11:38:41 [Security] trace Reading SASL-INIT
> 2015-03-26 11:38:41 [Protocol] debug
> qpid.172.16.153.11:10126-172.23.39.79:53580 Received SASL-INIT(EXTERNAL, )
> 2015-03-26 11:38:41 [Security] info SASL: Starting authentication with
> mechanism: EXTERNAL
> 2015-03-26 11:38:41 [Security] trace Completed encoding of frame of 22 bytes
> 2015-03-26 11:38:41 [Protocol] debug
> qpid.172.16.153.11:10126-172.23.39.79:53580 Sent SASL-CHALLENGE() 22
> 2015-03-26 11:38:41 [Security] info
> qpid.172.16.153.11:10126-172.23.39.79:53580 Challenge issued
> 2015-03-26 11:38:41 [Security] trace
> qpid.172.16.153.11:10126-172.23.39.79:53580 Sasl::decode(24): 24
> 2015-03-26 11:38:41 [Security] trace
> qpid.172.16.153.11:10126-172.23.39.79:53580 Sasl::encode(65536): 22
> {noformat}
> Client log:
> {noformat}
> 2015-03-26 12:50:31 +0100 [main] TRACE org.apache.qpid.jms.util.IdGenerator -
> Using port 0
> 2015-03-26 12:50:31 +0100 [main] DEBUG
> io.netty.util.internal.logging.InternalLoggerFactory - Using SLF4J as the
> default logging framework
> 2015-03-26 12:50:31 +0100 [main] DEBUG
> io.netty.channel.MultithreadEventLoopGroup - -Dio.netty.eventLoopThreads: 8
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent - Platform: Windows
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent - Java version: 7
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent - -Dio.netty.noUnsafe: false
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent0 - java.nio.ByteBuffer.cleaner:
> available
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent0 - java.nio.Buffer.address: available
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent0 - sun.misc.Unsafe.theUnsafe:
> available
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent0 - sun.misc.Unsafe.copyMemory:
> available
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent0 - java.nio.Bits.unaligned: true
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent - sun.misc.Unsafe: available
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent - -Dio.netty.noJavassist: false
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent - Javassist: unavailable
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent - You don't have Javassist in your
> class path or you don't have enough permission to load dynamically generated
> classes. Please check the configuration for better performance.
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent - -Dio.netty.tmpdir:
> C:\Users\schojak\AppData\Local\Temp (java.io.tmpdir)
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent - -Dio.netty.bitMode: 32
> (sun.arch.data.model)
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.PlatformDependent - -Dio.netty.noPreferDirect: false
> 2015-03-26 12:50:32 +0100 [main] DEBUG io.netty.channel.nio.NioEventLoop -
> -Dio.netty.noKeySetOptimization: false
> 2015-03-26 12:50:32 +0100 [main] DEBUG io.netty.channel.nio.NioEventLoop -
> -Dio.netty.selectorAutoRebuildThreshold: 512
> 2015-03-26 12:50:32 +0100 [main] TRACE io.netty.channel.nio.NioEventLoop -
> Instrumented an optimized java.util.Set into:
> sun.nio.ch.WindowsSelectorImpl@1249338
> 2015-03-26 12:50:32 +0100 [main] DEBUG io.netty.buffer.PooledByteBufAllocator
> - -Dio.netty.allocator.numHeapArenas: 2
> 2015-03-26 12:50:32 +0100 [main] DEBUG io.netty.buffer.PooledByteBufAllocator
> - -Dio.netty.allocator.numDirectArenas: 2
> 2015-03-26 12:50:32 +0100 [main] DEBUG io.netty.buffer.PooledByteBufAllocator
> - -Dio.netty.allocator.pageSize: 8192
> 2015-03-26 12:50:32 +0100 [main] DEBUG io.netty.buffer.PooledByteBufAllocator
> - -Dio.netty.allocator.maxOrder: 11
> 2015-03-26 12:50:32 +0100 [main] DEBUG io.netty.buffer.PooledByteBufAllocator
> - -Dio.netty.allocator.chunkSize: 16777216
> 2015-03-26 12:50:32 +0100 [main] DEBUG
> io.netty.util.internal.ThreadLocalRandom - -Dio.netty.initialSeedUniquifier:
> 0x0f38d78456072178
> 2015-03-26 12:50:32 +0100 [main] DEBUG io.netty.channel.ChannelOutboundBuffer
> - -Dio.netty.threadLocalDirectBufferSize: 65536
> 2015-03-26 12:50:32 +0100 [main] DEBUG io.netty.buffer.ByteBufUtil -
> -Dio.netty.allocator.type: unpooled
> 2015-03-26 12:50:32 +0100 [nioEventLoopGroup-2-1] TRACE
> org.apache.qpid.jms.transports.TransportSupport - Attempt to load KeyStore
> from location
> c:/opt/!_AMQP/IdeaProjects/Qpid-JMS-1.0/src/main/resources/CBKFR_TESTCALMMACC1.keystore
> of type jks
> 2015-03-26 12:50:32 +0100 [nioEventLoopGroup-2-1] TRACE
> org.apache.qpid.jms.transports.TransportSupport - Attempt to load TrustStore
> from location
> c:/opt/!_AMQP/IdeaProjects/Qpid-JMS-1.0/src/main/resources/truststore_eurex
> of type jks
> 2015-03-26 12:50:32 +0100 [nioEventLoopGroup-2-1] DEBUG
> io.netty.util.ResourceLeakDetector - -Dio.netty.leakDetectionLevel: simple
> 2015-03-26 12:50:32 +0100 [nioEventLoopGroup-2-1] TRACE
> org.apache.qpid.jms.transports.netty.NettyTcpTransport - Channel has become
> active! Channel is [id: 0x99d9b94d, /172.23.39.79:54111 =>
> cbgc01.xeop.de/172.16.153.11:10126]
> 2015-03-26 12:50:32 +0100 [nioEventLoopGroup-2-1] TRACE
> org.apache.qpid.jms.transports.netty.NettySslTransport - SSL Handshake has
> completed: [id: 0x99d9b94d, /172.23.39.79:54111 =>
> cbgc01.xeop.de/172.16.153.11:10126]
> 2015-03-26 12:50:32 +0100
> [AmqpProvider:(1):[amqps://cbgc01.xeop.de:10126?transport.keyStorePassword=123456&transport.trustStorePassword=123456&transport.verifyHost=false&transport.keyStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252FCBKFR_TESTCALMMACC1.keystore&transport.trustStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252Ftruststore_eurex]]
> TRACE org.apache.qpid.jms.transports.netty.NettyTcpTransport - Attempted
> write of: 8 bytes
> 2015-03-26 12:50:32 +0100 [nioEventLoopGroup-2-1] TRACE
> org.apache.qpid.jms.transports.netty.NettyTcpTransport - New data read: 38
> bytes incoming: UnpooledHeapByteBuf(ridx: 0, widx: 38, cap: 1024)
> 2015-03-26 12:50:32 +0100
> [AmqpProvider:(1):[amqps://cbgc01.xeop.de:10126?transport.keyStorePassword=123456&transport.trustStorePassword=123456&transport.verifyHost=false&transport.keyStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252FCBKFR_TESTCALMMACC1.keystore&transport.trustStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252Ftruststore_eurex]]
> TRACE org.apache.qpid.jms.provider.amqp.AmqpProvider - Received from Broker
> 38 bytes: UnpooledHeapByteBuf(ridx: 0, widx: 38, cap: 1024)
> 2015-03-26 12:50:32 +0100
> [AmqpProvider:(1):[amqps://cbgc01.xeop.de:10126?transport.keyStorePassword=123456&transport.trustStorePassword=123456&transport.verifyHost=false&transport.keyStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252FCBKFR_TESTCALMMACC1.keystore&transport.trustStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252Ftruststore_eurex]]
> TRACE org.apache.qpid.jms.provider.amqp.AmqpProvider - New Proton Event:
> CONNECTION_INIT
> 2015-03-26 12:50:32 +0100
> [AmqpProvider:(1):[amqps://cbgc01.xeop.de:10126?transport.keyStorePassword=123456&transport.trustStorePassword=123456&transport.verifyHost=false&transport.keyStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252FCBKFR_TESTCALMMACC1.keystore&transport.trustStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252Ftruststore_eurex]]
> TRACE org.apache.qpid.jms.provider.amqp.AmqpProvider - New Proton Event:
> SESSION_INIT
> 2015-03-26 12:50:32 +0100
> [AmqpProvider:(1):[amqps://cbgc01.xeop.de:10126?transport.keyStorePassword=123456&transport.trustStorePassword=123456&transport.verifyHost=false&transport.keyStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252FCBKFR_TESTCALMMACC1.keystore&transport.trustStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252Ftruststore_eurex]]
> TRACE org.apache.qpid.jms.provider.amqp.AmqpProvider - New Proton Event:
> CONNECTION_LOCAL_OPEN
> 2015-03-26 12:50:32 +0100
> [AmqpProvider:(1):[amqps://cbgc01.xeop.de:10126?transport.keyStorePassword=123456&transport.trustStorePassword=123456&transport.verifyHost=false&transport.keyStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252FCBKFR_TESTCALMMACC1.keystore&transport.trustStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252Ftruststore_eurex]]
> INFO org.apache.qpid.jms.sasl.SaslMechanismFinder - Best match for SASL auth
> was: SASL-EXTERNAL
> 2015-03-26 12:50:32 +0100
> [AmqpProvider:(1):[amqps://cbgc01.xeop.de:10126?transport.keyStorePassword=123456&transport.trustStorePassword=123456&transport.verifyHost=false&transport.keyStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252FCBKFR_TESTCALMMACC1.keystore&transport.trustStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252Ftruststore_eurex]]
> TRACE org.apache.qpid.jms.transports.netty.NettyTcpTransport - Attempted
> write of: 24 bytes
> 2015-03-26 12:50:32 +0100 [nioEventLoopGroup-2-1] TRACE
> org.apache.qpid.jms.transports.netty.NettyTcpTransport - New data read: 22
> bytes incoming: UnpooledHeapByteBuf(ridx: 0, widx: 22, cap: 53)
> 2015-03-26 12:50:32 +0100
> [AmqpProvider:(1):[amqps://cbgc01.xeop.de:10126?transport.keyStorePassword=123456&transport.trustStorePassword=123456&transport.verifyHost=false&transport.keyStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252FCBKFR_TESTCALMMACC1.keystore&transport.trustStoreLocation=c%253A%252Fopt%252F%2521_AMQP%252FIdeaProjects%252FQpid-JMS-1.0%252Fsrc%252Fmain%252Fresources%252Ftruststore_eurex]]
> TRACE org.apache.qpid.jms.provider.amqp.AmqpProvider - Received from Broker
> 22 bytes: UnpooledHeapByteBuf(ridx: 0, widx: 22, cap: 53)
> {noformat}
> To compare, broker log when the prototype AMQP 1.0 client from Rob is used:
> {noformat}
> 2015-03-26 11:42:05 [Network] trace Accepting SSL connection.
> 2015-03-26 11:42:05 [Network] info Set TCP_NODELAY on connection to
> 172.23.39.79:53601
> 2015-03-26 11:42:05 [Network] trace Accepting SSL connection.
> 2015-03-26 11:42:05 [System] debug RECV
> [qpid.172.16.153.11:10126-172.23.39.79:53601]: INIT(1-0)
> 2015-03-26 11:42:05 [Broker] info Using AMQP 1.0 (with SASL layer)
> 2015-03-26 11:42:05 [Security] debug External ssf=128 and
> auth=CBKFR_TESTCALMMACC1
> 2015-03-26 11:42:05 [Security] debug min_ssf: 0, max_ssf: 0, external_ssf: 128
> 2015-03-26 11:42:05 [Security] debug external auth detected and set to
> CBKFR_TESTCALMMACC1
> 2015-03-26 11:42:05 [Model] trace Mgmt create connection.
> id:qpid.172.16.153.11:10126-172.23.39.79:53601
> 2015-03-26 11:42:05 [Management] debug Management object (V1) added:
> org.apache.qpid.broker:connection:qpid.172.16.153.11:10126-172.23.39.79:53601
> 2015-03-26 11:42:05 [Security] trace ACL ConnectionCounter new connection:
> qpid.172.16.153.11:10126-172.23.39.79:53601
> 2015-03-26 11:42:05 [Security] info SASL: Mechanism list: EXTERNAL
> 2015-03-26 11:42:05 [Security] trace Completed encoding of frame of 30 bytes
> 2015-03-26 11:42:05 [Protocol] debug
> qpid.172.16.153.11:10126-172.23.39.79:53601 Sent SASL-MECHANISMS(EXTERNAL) 30
> 2015-03-26 11:42:05 [Protocol] debug
> qpid.172.16.153.11:10126-172.23.39.79:53601 writing protocol header: 1-0
> 2015-03-26 11:42:05 [Security] trace
> qpid.172.16.153.11:10126-172.23.39.79:53601 Sasl::encode(65536): 38
> 2015-03-26 11:42:05 [Security] trace
> qpid.172.16.153.11:10126-172.23.39.79:53601 Sasl::decode(1): 0
> 2015-03-26 11:42:05 [Security] trace Reading SASL frame of size 41
> 2015-03-26 11:42:05 [Security] trace Reading SASL-INIT
> 2015-03-26 11:42:05 [Protocol] debug
> qpid.172.16.153.11:10126-172.23.39.79:53601 Received SASL-INIT(EXTERNAL, )
> 2015-03-26 11:42:05 [Security] info SASL: Starting authentication with
> mechanism: EXTERNAL
> 2015-03-26 11:42:05 [Security] trace Completed encoding of frame of 22 bytes
> 2015-03-26 11:42:05 [Protocol] debug
> qpid.172.16.153.11:10126-172.23.39.79:53601 Sent SASL-CHALLENGE() 22
> 2015-03-26 11:42:05 [Security] info
> qpid.172.16.153.11:10126-172.23.39.79:53601 Challenge issued
> 2015-03-26 11:42:05 [Security] trace
> qpid.172.16.153.11:10126-172.23.39.79:53601 Sasl::decode(41): 41
> 2015-03-26 11:42:05 [Security] trace
> qpid.172.16.153.11:10126-172.23.39.79:53601 Sasl::encode(65536): 22
> 2015-03-26 11:42:05 [Security] trace
> qpid.172.16.153.11:10126-172.23.39.79:53601 Sasl::decode(1): 0
> 2015-03-26 11:42:05 [Security] trace Reading SASL frame of size 16
> 2015-03-26 11:42:05 [Security] trace Reading SASL-RESPONSE (\xA0\x00) 1
> elements
> 2015-03-26 11:42:05 [Protocol] debug
> qpid.172.16.153.11:10126-172.23.39.79:53601 Received SASL-RESPONSE()
> 2015-03-26 11:42:05 [Security] trace ACL: Connection quota for user
> CBKFR_TESTCALMMACC1@QPID0126 chosen through value for 'all' : 65530
> 2015-03-26 11:42:05 [Security] trace ACL ConnectionApprover totalLimit=500
> curValue=2 result=allow
> 2015-03-26 11:42:05 [Security] trace ACL ConnectionApprover
> user=CBKFR_TESTCALMMACC1@QPID0126 limit=65530 curValue=1 result=allow
> 2015-03-26 11:42:05 [Security] trace Completed encoding of frame of 16 bytes
> 2015-03-26 11:42:05 [Protocol] debug
> qpid.172.16.153.11:10126-172.23.39.79:53601 Sent SASL-OUTCOME(0) 16
> 2015-03-26 11:42:05 [Security] info
> qpid.172.16.153.11:10126-172.23.39.79:53601 Authenticated as
> CBKFR_TESTCALMMACC1@QPID0126
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
