[netconf-dev] javax.crypto.IllegalBlockSizeException: Input length must be multiple of 16 when decrypting with padded cipher


Atul Gosain <agosain@...>
 

Hi Lori 

This comes as a result of a certain enhancements done during Carbon SR1 for netconf password encryption. If the password is not encrypted, the code still tries to decrypt and though it doesnt impact anything and same password is used, an exception is thrown from AAA module on this. It couldnt be curtailed during that time because change in AAA was impacting some downstream projects. It should not the case with releases after Carbon SR1. If not, please file a bug to show a warning here instead of error. 

Thanks
Atul

On Thu, Oct 19, 2017 at 2:38 PM, Lori Jakab <lorand.jakab+odl@...> wrote:
Hi,

I'm using GBP to connect to Honeycomb over NETCONF for configuring a VPP instance. For each connection, I see the below exception, although the connection completes successfully.

I would like to ask both AAA and NETCONF developers if this is shown because of a real bug, which needs to be fixed in either of the projects (in which case please tell me agains which project should I file a bug), or this is actually not an ERROR, in which case please don't throw an exception with a stack trace, just log a warning perhaps.

Thanks and best regards,
-Lori

2017-10-20 00:18:59,328 | INFO  | n-dispatcher-210 | VppNodeManager                   | 291 - org.opendaylight.groupbasedpolicy.vpp-renderer - 0.7.0.SNAPSHOT | Node synchronization completed. Connecting device compute0 ...
2017-10-20 00:18:59,342 | INFO  | lt-dispatcher-45 | RemoteDeviceConnectorImpl        | 343 - org.opendaylight.netconf.topology-singleton - 1.4.0.SNAPSHOT | RemoteDevice{compute0}: Concurrent rpc limit is smaller than 1, no limit will be enforced.
2017-10-20 00:18:59,368 | INFO  | lt-dispatcher-45 | PublicKeyAuth                    | 333 - org.opendaylight.netconf.netty-util - 1.4.0.SNAPSHOT | Private key path not specified in the config file.
2017-10-20 00:18:59,890 | INFO  | 0]-nio2-thread-1 | ClientSessionImpl                | 184 - org.apache.sshd.core - 0.14.0 | Client session created
2017-10-20 00:18:59,915 | ERROR | 0]-nio2-thread-1 | AAAEncryptionServiceImpl         | 231 - org.opendaylight.aaa.encrypt-service - 0.7.0.SNAPSHOT | Failed to decrypt encoded data
javax.crypto.IllegalBlockSizeException: Input length must be multiple of 16 when decrypting with padded cipher
at com.sun.crypto.provider.CipherCore.doFinal(CipherCore.java:934)[sunjce_provider.jar:1.8.0_112]
at com.sun.crypto.provider.CipherCore.doFinal(CipherCore.java:845)[sunjce_provider.jar:1.8.0_112]
at com.sun.crypto.provider.AESCipher.engineDoFinal(AESCipher.java:446)[sunjce_provider.jar:1.8.0_112]
at javax.crypto.Cipher.doFinal(Cipher.java:2165)[:1.8.0_121]
at org.opendaylight.aaa.encrypt.AAAEncryptionServiceImpl.decrypt(AAAEncryptionServiceImpl.java:162)[231:org.opendaylight.aaa.encrypt-service:0.7.0.SNAPSHOT]
at Proxyf2821ed0_cc18_41b8_a67e_5a0af6139b4d.decrypt(Unknown Source)
at Proxy655e0e01_aff1_4963_85b8_298214f1f11c.decrypt(Unknown Source)
at org.opendaylight.netconf.nettyutil.handler.ssh.authentication.LoginPassword.authenticate(LoginPassword.java:43)[333:org.opendaylight.netconf.netty-util:1.4.0.SNAPSHOT]
at org.opendaylight.netconf.nettyutil.handler.ssh.authentication.PublicKeyAuth.authenticate(PublicKeyAuth.java:49)[333:org.opendaylight.netconf.netty-util:1.4.0.SNAPSHOT]
at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler.handleSshSessionCreated(AsyncSshHandler.java:133)[333:org.opendaylight.netconf.netty-util:1.4.0.SNAPSHOT]
at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler.access$000(AsyncSshHandler.java:37)[333:org.opendaylight.netconf.netty-util:1.4.0.SNAPSHOT]
at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler$1.operationComplete(AsyncSshHandler.java:120)[333:org.opendaylight.netconf.netty-util:1.4.0.SNAPSHOT]
at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler$1.operationComplete(AsyncSshHandler.java:116)[333:org.opendaylight.netconf.netty-util:1.4.0.SNAPSHOT]
at org.apache.sshd.common.future.DefaultSshFuture.notifyListener(DefaultSshFuture.java:269)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.future.DefaultSshFuture.notifyListeners(DefaultSshFuture.java:254)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.future.DefaultSshFuture.setValue(DefaultSshFuture.java:173)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.client.future.DefaultConnectFuture.setSession(DefaultConnectFuture.java:68)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.SshClient$4.operationComplete(SshClient.java:307)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.SshClient$4.operationComplete(SshClient.java:298)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.future.DefaultSshFuture.notifyListener(DefaultSshFuture.java:269)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.future.DefaultSshFuture.notifyListeners(DefaultSshFuture.java:254)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.future.DefaultSshFuture.setValue(DefaultSshFuture.java:173)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.io.nio2.Nio2Connector$DefaultIoConnectFuture.setSession(Nio2Connector.java:96)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.io.nio2.Nio2Connector$1.onCompleted(Nio2Connector.java:59)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.io.nio2.Nio2Connector$1.onCompleted(Nio2Connector.java:53)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:32)[184:org.apache.sshd.core:0.14.0]
at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_144]
at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:30)[184:org.apache.sshd.core:0.14.0]
at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)[:1.8.0_144]
at sun.nio.ch.Invoker$2.run(Invoker.java:218)[:1.8.0_144]
at sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)[:1.8.0_144]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)[:1.8.0_144]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)[:1.8.0_144]
at java.lang.Thread.run(Thread.java:748)[:1.8.0_144]
2017-10-20 00:19:00,296 | INFO  | 0]-nio2-thread-1 | ClientSessionImpl                | 184 - org.apache.sshd.core - 0.14.0 | Start flagging packets as pending until key exchange is done
2017-10-20 00:19:00,303 | INFO  | 0]-nio2-thread-1 | ClientSessionImpl                | 184 - org.apache.sshd.core - 0.14.0 | Server version string: SSH-2.0-SSHD-CORE-0.14.0

_______________________________________________
netconf-dev mailing list
netconf-dev@lists.opendaylight.org
https://lists.opendaylight.org/mailman/listinfo/netconf-dev




--

Thanks
Atul


Lori Jakab <lorand.jakab+odl@...>
 

Hi Atul,

Thanks for the explanation, I filed AAA-146 to track this.

-Lori 

On Fri, Oct 20, 2017 at 1:16 AM, Atul Gosain <agosain@...> wrote:
Hi Lori 

This comes as a result of a certain enhancements done during Carbon SR1 for netconf password encryption. If the password is not encrypted, the code still tries to decrypt and though it doesnt impact anything and same password is used, an exception is thrown from AAA module on this. It couldnt be curtailed during that time because change in AAA was impacting some downstream projects. It should not the case with releases after Carbon SR1. If not, please file a bug to show a warning here instead of error. 

Thanks
Atul

On Thu, Oct 19, 2017 at 2:38 PM, Lori Jakab <lorand.jakab+odl@...> wrote:
Hi,

I'm using GBP to connect to Honeycomb over NETCONF for configuring a VPP instance. For each connection, I see the below exception, although the connection completes successfully.

I would like to ask both AAA and NETCONF developers if this is shown because of a real bug, which needs to be fixed in either of the projects (in which case please tell me agains which project should I file a bug), or this is actually not an ERROR, in which case please don't throw an exception with a stack trace, just log a warning perhaps.

Thanks and best regards,
-Lori

2017-10-20 00:18:59,328 | INFO  | n-dispatcher-210 | VppNodeManager                   | 291 - org.opendaylight.groupbasedpolicy.vpp-renderer - 0.7.0.SNAPSHOT | Node synchronization completed. Connecting device compute0 ...
2017-10-20 00:18:59,342 | INFO  | lt-dispatcher-45 | RemoteDeviceConnectorImpl        | 343 - org.opendaylight.netconf.topology-singleton - 1.4.0.SNAPSHOT | RemoteDevice{compute0}: Concurrent rpc limit is smaller than 1, no limit will be enforced.
2017-10-20 00:18:59,368 | INFO  | lt-dispatcher-45 | PublicKeyAuth                    | 333 - org.opendaylight.netconf.netty-util - 1.4.0.SNAPSHOT | Private key path not specified in the config file.
2017-10-20 00:18:59,890 | INFO  | 0]-nio2-thread-1 | ClientSessionImpl                | 184 - org.apache.sshd.core - 0.14.0 | Client session created
2017-10-20 00:18:59,915 | ERROR | 0]-nio2-thread-1 | AAAEncryptionServiceImpl         | 231 - org.opendaylight.aaa.encrypt-service - 0.7.0.SNAPSHOT | Failed to decrypt encoded data
javax.crypto.IllegalBlockSizeException: Input length must be multiple of 16 when decrypting with padded cipher
at com.sun.crypto.provider.CipherCore.doFinal(CipherCore.java:934)[sunjce_provider.jar:1.8.0_112]
at com.sun.crypto.provider.CipherCore.doFinal(CipherCore.java:845)[sunjce_provider.jar:1.8.0_112]
at com.sun.crypto.provider.AESCipher.engineDoFinal(AESCipher.java:446)[sunjce_provider.jar:1.8.0_112]
at javax.crypto.Cipher.doFinal(Cipher.java:2165)[:1.8.0_121]
at org.opendaylight.aaa.encrypt.AAAEncryptionServiceImpl.decrypt(AAAEncryptionServiceImpl.java:162)[231:org.opendaylight.aaa.encrypt-service:0.7.0.SNAPSHOT]
at Proxyf2821ed0_cc18_41b8_a67e_5a0af6139b4d.decrypt(Unknown Source)
at Proxy655e0e01_aff1_4963_85b8_298214f1f11c.decrypt(Unknown Source)
at org.opendaylight.netconf.nettyutil.handler.ssh.authentication.LoginPassword.authenticate(LoginPassword.java:43)[333:org.opendaylight.netconf.netty-util:1.4.0.SNAPSHOT]
at org.opendaylight.netconf.nettyutil.handler.ssh.authentication.PublicKeyAuth.authenticate(PublicKeyAuth.java:49)[333:org.opendaylight.netconf.netty-util:1.4.0.SNAPSHOT]
at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler.handleSshSessionCreated(AsyncSshHandler.java:133)[333:org.opendaylight.netconf.netty-util:1.4.0.SNAPSHOT]
at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler.access$000(AsyncSshHandler.java:37)[333:org.opendaylight.netconf.netty-util:1.4.0.SNAPSHOT]
at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler$1.operationComplete(AsyncSshHandler.java:120)[333:org.opendaylight.netconf.netty-util:1.4.0.SNAPSHOT]
at org.opendaylight.netconf.nettyutil.handler.ssh.client.AsyncSshHandler$1.operationComplete(AsyncSshHandler.java:116)[333:org.opendaylight.netconf.netty-util:1.4.0.SNAPSHOT]
at org.apache.sshd.common.future.DefaultSshFuture.notifyListener(DefaultSshFuture.java:269)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.future.DefaultSshFuture.notifyListeners(DefaultSshFuture.java:254)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.future.DefaultSshFuture.setValue(DefaultSshFuture.java:173)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.client.future.DefaultConnectFuture.setSession(DefaultConnectFuture.java:68)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.SshClient$4.operationComplete(SshClient.java:307)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.SshClient$4.operationComplete(SshClient.java:298)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.future.DefaultSshFuture.notifyListener(DefaultSshFuture.java:269)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.future.DefaultSshFuture.notifyListeners(DefaultSshFuture.java:254)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.future.DefaultSshFuture.setValue(DefaultSshFuture.java:173)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.io.nio2.Nio2Connector$DefaultIoConnectFuture.setSession(Nio2Connector.java:96)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.io.nio2.Nio2Connector$1.onCompleted(Nio2Connector.java:59)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.io.nio2.Nio2Connector$1.onCompleted(Nio2Connector.java:53)[184:org.apache.sshd.core:0.14.0]
at org.apache.sshd.common.io.nio2.Nio2CompletionHandler$1.run(Nio2CompletionHandler.java:32)[184:org.apache.sshd.core:0.14.0]
at java.security.AccessController.doPrivileged(Native Method)[:1.8.0_144]
at org.apache.sshd.common.io.nio2.Nio2CompletionHandler.completed(Nio2CompletionHandler.java:30)[184:org.apache.sshd.core:0.14.0]
at sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:126)[:1.8.0_144]
at sun.nio.ch.Invoker$2.run(Invoker.java:218)[:1.8.0_144]
at sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:112)[:1.8.0_144]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)[:1.8.0_144]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)[:1.8.0_144]
at java.lang.Thread.run(Thread.java:748)[:1.8.0_144]
2017-10-20 00:19:00,296 | INFO  | 0]-nio2-thread-1 | ClientSessionImpl                | 184 - org.apache.sshd.core - 0.14.0 | Start flagging packets as pending until key exchange is done
2017-10-20 00:19:00,303 | INFO  | 0]-nio2-thread-1 | ClientSessionImpl                | 184 - org.apache.sshd.core - 0.14.0 | Server version string: SSH-2.0-SSHD-CORE-0.14.0

_______________________________________________
netconf-dev mailing list
netconf-dev@....org
https://lists.opendaylight.org/mailman/listinfo/netconf-dev




--

Thanks
Atul