-
Bug
-
Resolution: Done
-
Medium
-
None
-
None
-
None
As [https://lists.opendaylight.org/pipermail/aaa-dev/2017-October/001491.html|reported] on the mailing list, the exception below happens when making a NETCONF connection and is shown as an ERROR in the log with the full stack trace, when I believe it would be better to log as WARN, without the stack trace.
{{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
: 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}}