Uploaded image for project: 'Qpid'
  1. Qpid
  2. QPID-7643

[Java Broker] Cannot login using SASL PLAIN against Base64MD5PasswordFilePrincipalDatabase

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: qpid-java-6.0.6, qpid-java-6.1.1
    • Component/s: Broker-J
    • Labels:
      None

      Description

      There is a defect in Base64MD5PasswordFilePrincipalDatabase that means that whilst the a authentication provider of type Base64MD5PasswordFile advertises PLAIN at attempt to use it fails later with following stack trace reported by the client.

      The user who wishes to use PLAIN can work around by using an alternative authentication provider that offers plain support e.g. SCRAM.

      /Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/bin/java -Dqpid.amqp.version=0-10 -Dqpid.sasl_mechs=PLAIN -Didea.launcher.port=7537 "-Didea.launcher.bin.path=/Applications/IntelliJ IDEA.app/Contents/bin" -Dfile.encoding=UTF-8 -classpath "/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/charsets.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/deploy.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/ext/cldrdata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/ext/dnsns.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/ext/jaccess.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/ext/jfxrt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/ext/localedata.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/ext/nashorn.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/ext/sunec.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/ext/sunjce_provider.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/ext/sunpkcs11.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/ext/zipfs.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/javaws.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/jce.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/jfr.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/jfxswt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/jsse.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/management-agent.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/plugin.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/resources.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/jre/lib/rt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/lib/ant-javafx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/lib/dt.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/lib/javafx-mx.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/lib/jconsole.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/lib/packager.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/lib/sa-jdi.jar:/Library/Java/JavaVirtualMachines/jdk1.8.0_121.jdk/Contents/Home/lib/tools.jar:/Users/keith/src/qpid-java/client/example/target/classes:/Users/keith/src/qpid-java/client/target/classes:/Users/keith/src/qpid-java/common/target/classes:/Users/keith/.m2/repository/org/apache/geronimo/specs/geronimo-jms_1.1_spec/1.1.1/geronimo-jms_1.1_spec-1.1.1.jar:/Users/keith/.m2/repository/org/slf4j/slf4j-api/1.7.12/slf4j-api-1.7.12.jar:/Applications/IntelliJ IDEA.app/Contents/lib/idea_rt.jar" com.intellij.rt.execution.application.AppMain org.apache.qpid.example.Hello
      SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
      SLF4J: Defaulting to no-operation (NOP) logger implementation
      SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
      javax.jms.JMSException: Error creating connection: Unsupported mechanism: PLAIN
      	at org.apache.qpid.client.AMQConnectionFactory.createConnection(AMQConnectionFactory.java:134)
      	at org.apache.qpid.client.AMQConnectionFactory.createConnection(AMQConnectionFactory.java:57)
      	at org.apache.qpid.example.Hello.runTest(Hello.java:60)
      	at org.apache.qpid.example.Hello.main(Hello.java:48)
      	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      	at java.lang.reflect.Method.invoke(Method.java:498)
      	at com.intellij.rt.execution.application.AppMain.main(AppMain.java:147)
      Caused by: org.apache.qpid.AMQConnectionFailureException: Unsupported mechanism: PLAIN
      	at org.apache.qpid.client.AMQConnection.makeConnection(AMQConnection.java:659)
      	at org.apache.qpid.client.AMQConnection.<init>(AMQConnection.java:509)
      	at org.apache.qpid.client.AMQConnectionFactory.createConnection(AMQConnectionFactory.java:130)
      	... 8 more
      Caused by: org.apache.qpid.AMQException: Cannot connect to broker (tcp://localhost:5672): Unsupported mechanism: PLAIN [error code 320: connection forced]
      	at org.apache.qpid.client.AMQConnectionDelegate_0_10.makeBrokerConnection(AMQConnectionDelegate_0_10.java:270)
      	at org.apache.qpid.client.AMQConnection.makeBrokerConnection(AMQConnection.java:804)
      	at org.apache.qpid.client.AMQConnection.makeConnection(AMQConnection.java:570)
      	... 10 more
      Caused by: org.apache.qpid.transport.ConnectionException: Unsupported mechanism: PLAIN
      	at org.apache.qpid.transport.ConnectionException.rethrow(ConnectionException.java:67)
      	at org.apache.qpid.transport.Connection.connect(Connection.java:278)
      	at org.apache.qpid.client.AMQConnectionDelegate_0_10.makeBrokerConnection(AMQConnectionDelegate_0_10.java:240)
      	... 12 more
      Caused by: org.apache.qpid.transport.ConnectionException: Unsupported mechanism: PLAIN
      	at org.apache.qpid.transport.Connection.closeCode(Connection.java:565)
      	at org.apache.qpid.transport.ConnectionDelegate.connectionClose(ConnectionDelegate.java:76)
      	at org.apache.qpid.transport.ConnectionDelegate.connectionClose(ConnectionDelegate.java:41)
      	at org.apache.qpid.transport.ConnectionClose.dispatch(ConnectionClose.java:91)
      	at org.apache.qpid.transport.ConnectionDelegate.control(ConnectionDelegate.java:50)
      	at org.apache.qpid.transport.ConnectionDelegate.control(ConnectionDelegate.java:41)
      	at org.apache.qpid.transport.Method.delegate(Method.java:157)
      	at org.apache.qpid.transport.Connection.received(Connection.java:401)
      	at org.apache.qpid.transport.network.Assembler.emit(Assembler.java:100)
      	at org.apache.qpid.transport.network.Assembler.assemble(Assembler.java:191)
      	at org.apache.qpid.transport.network.Assembler.frame(Assembler.java:134)
      	at org.apache.qpid.transport.network.Frame.delegate(Frame.java:128)
      	at org.apache.qpid.transport.network.Assembler.received(Assembler.java:105)
      	at org.apache.qpid.transport.network.InputHandler.next(InputHandler.java:206)
      	at org.apache.qpid.transport.network.InputHandler.received(InputHandler.java:121)
      	at org.apache.qpid.transport.network.io.IoReceiver.run(IoReceiver.java:164)
      	at java.lang.Thread.run(Thread.java:745)
      
      Process finished with exit code 0
      

      Protocol trace looks like this:

      2017-01-26 08:23:20,135 DEBUG [IO-/127.0.0.1:49724] (o.a.q.t.Connection) - SEND: [conn:5f4b2f78] ch=0 ConnectionStart(serverProperties={product=qpid, qpid.virtualhost_properties_supported=true, qpid.features=[qpid.jms-selector], qpid.message_compression_supported=true, qpid.federation_tag=af020393-6737-43c2-9614-000cf046ef2b, qpid.build=Unversioned directory, version=6.1.2-SNAPSHOT, qpid.queue_lifetime_supported=true, qpid.instance_name=Broker}, mechanisms=[CRAM-MD5-HASHED, CRAM-MD5-HEX, PLAIN], locales=[en_US])
      2017-01-26 08:23:20,135 DEBUG [IO-/127.0.0.1:49724] (o.a.q.t.Connection) - FLUSH: [conn:5f4b2f78]
      2017-01-26 08:23:20,135 DEBUG [IO-/127.0.0.1:49724] (o.a.q.s.t.NonBlockingConnection) - Written 424 bytes
      2017-01-26 08:23:20,136 DEBUG [IO-/127.0.0.1:49724] (o.a.q.s.t.NonBlockingConnection) - Read 0 byte(s)
      2017-01-26 08:23:20,149 DEBUG [IO-/127.0.0.1:49724] (o.a.q.s.t.NonBlockingConnection) - Read 343 byte(s)
      2017-01-26 08:23:20,150 DEBUG [IO-/127.0.0.1:49724] (o.a.q.t.Connection) - RECV: [conn:5f4b2f78] ch=0 ConnectionStartOk(clientProperties={qpid.session_flow=1, product=qpid, qpid.client_process=Apache Qpid JMS Client for AMQP 0-9-1/0-10, clientName=clientid, qpid.client_pid=1604, qpid.client_version=6.1.2-SNAPSHOT, platform=Java(TM) SE Runtime Environment, 1.8.0_121-b13, Oracle Corporation, x86_64, Mac OS X, 10.12.2, unknown}, mechanism=PLAIN, response="\x00guest\x00guest")
      2017-01-26 08:23:20,150 DEBUG [IO-/127.0.0.1:49724] (o.a.q.t.Connection) - SEND: [conn:5f4b2f78] ch=0 ConnectionClose(replyCode=CONNECTION_FORCED, replyText=Unsupported mechanism: PLAIN)
      2017-01-26 08:23:20,150 DEBUG [IO-/127.0.0.1:49724] (o.a.q.t.Connection) - FLUSH: [conn:5f4b2f78]
      

      This problem is already eliminated on trunk with the work of QPID-7283.

        Attachments

          Activity

            People

            • Assignee:
              Unassigned
              Reporter:
              k-wall Keith Wall
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: