From dbb635f96384aa204520ad7109fe072a7044ff6d Mon Sep 17 00:00:00 2001 From: Tomas Olvecky Date: Wed, 5 Feb 2014 11:55:39 +0100 Subject: [PATCH] Improve logging in NetconfClient, logging-bridge. Increase connection timeout in sal-netconf-connector. Stop polluting log file with unnecessary 'Exception' messages by logging-bridge, print stack trace with exceptions using slf4j. Increase connection timeout in sal-netconf-client from 5s to 20s. Include label in NetconfClient exceptions. Change-Id: If6819029fb79ea6ebead6b6745adf2c439d107da Signed-off-by: Tomas Olvecky --- opendaylight/logging/bridge/pom.xml | 116 ++++++++++-------- .../bridge/internal/LogListenerImpl.java | 8 +- .../bridge/internal/LogListenerImplTest.java | 67 ++++++++++ .../yang/odl-sal-netconf-connector-cfg.yang | 2 +- .../netconf/client/NetconfClient.java | 16 +-- .../client/SSHNetconfClientLiveTest.java | 62 ++++++++-- 6 files changed, 197 insertions(+), 74 deletions(-) create mode 100644 opendaylight/logging/bridge/src/test/java/org/opendaylight/controller/logging/bridge/internal/LogListenerImplTest.java diff --git a/opendaylight/logging/bridge/pom.xml b/opendaylight/logging/bridge/pom.xml index 0fd26dbbe3..3ceb5b1812 100644 --- a/opendaylight/logging/bridge/pom.xml +++ b/opendaylight/logging/bridge/pom.xml @@ -1,55 +1,71 @@ - - 4.0.0 - - org.opendaylight.controller - commons.opendaylight - 1.4.2-SNAPSHOT - ../../commons/opendaylight - - - scm:git:ssh://git.opendaylight.org:29418/controller.git - scm:git:ssh://git.opendaylight.org:29418/controller.git - https://wiki.opendaylight.org/view/OpenDaylight_Controller:Main - HEAD - + + 4.0.0 + + org.opendaylight.controller + commons.opendaylight + 1.4.2-SNAPSHOT + ../../commons/opendaylight + + + scm:git:ssh://git.opendaylight.org:29418/controller.git + scm:git:ssh://git.opendaylight.org:29418/controller.git + https://wiki.opendaylight.org/view/OpenDaylight_Controller:Main + HEAD + - logging.bridge - 0.4.2-SNAPSHOT - bundle + logging.bridge + 0.4.2-SNAPSHOT + bundle - - - org.slf4j - slf4j-api - - - equinoxSDK381 - org.eclipse.osgi - - + + + org.slf4j + slf4j-api + + + equinoxSDK381 + org.eclipse.osgi + + + junit + junit + test + + + org.opendaylight.yangtools + mockito-configuration + test + + + ch.qos.logback + logback-classic + test + + - - - - org.apache.felix - maven-bundle-plugin - ${bundle.plugin.version} - true - - - - org.slf4j, - org.osgi.framework, - org.osgi.service.log - - - org.opendaylight.controller.logging.bridge.internal.Activator - - - ${project.basedir}/META-INF - - - - + + + + org.apache.felix + maven-bundle-plugin + ${bundle.plugin.version} + true + + + + org.slf4j, + org.osgi.framework, + org.osgi.service.log + + + org.opendaylight.controller.logging.bridge.internal.Activator + + + ${project.basedir}/META-INF + + + + diff --git a/opendaylight/logging/bridge/src/main/java/org/opendaylight/controller/logging/bridge/internal/LogListenerImpl.java b/opendaylight/logging/bridge/src/main/java/org/opendaylight/controller/logging/bridge/internal/LogListenerImpl.java index 03719d567f..2f45c6f91b 100644 --- a/opendaylight/logging/bridge/src/main/java/org/opendaylight/controller/logging/bridge/internal/LogListenerImpl.java +++ b/opendaylight/logging/bridge/src/main/java/org/opendaylight/controller/logging/bridge/internal/LogListenerImpl.java @@ -26,19 +26,19 @@ public class LogListenerImpl implements LogListener { if (this.logger != null) { switch (entry.getLevel()) { case LogService.LOG_DEBUG: - this.logger.debug("Bundle:{} Message:{} Exception:{}", entry.getBundle() + this.logger.debug("Bundle:{} Message:{}", entry.getBundle() .getSymbolicName(), entry.getMessage(), entry.getException()); break; case LogService.LOG_INFO: - this.logger.info("Bundle:{} Message:{} Exception:{}", entry.getBundle() + this.logger.info("Bundle:{} Message:{}", entry.getBundle() .getSymbolicName(), entry.getMessage(), entry.getException()); break; case LogService.LOG_WARNING: - this.logger.warn("Bundle:{} Message:{} Exception:{}", entry.getBundle() + this.logger.warn("Bundle:{} Message:{}", entry.getBundle() .getSymbolicName(), entry.getMessage(), entry.getException()); break; case LogService.LOG_ERROR: - this.logger.error("Bundle:{} Message:{} Exception:{}", entry.getBundle() + this.logger.error("Bundle:{} Message:{}", entry.getBundle() .getSymbolicName(), entry.getMessage(), entry.getException()); break; } diff --git a/opendaylight/logging/bridge/src/test/java/org/opendaylight/controller/logging/bridge/internal/LogListenerImplTest.java b/opendaylight/logging/bridge/src/test/java/org/opendaylight/controller/logging/bridge/internal/LogListenerImplTest.java new file mode 100644 index 0000000000..2490c39171 --- /dev/null +++ b/opendaylight/logging/bridge/src/test/java/org/opendaylight/controller/logging/bridge/internal/LogListenerImplTest.java @@ -0,0 +1,67 @@ +/* + * Copyright (c) 2013 Cisco Systems, Inc. and others. All rights reserved. + * + * This program and the accompanying materials are made available under the + * terms of the Eclipse Public License v1.0 which accompanies this distribution, + * and is available at http://www.eclipse.org/legal/epl-v10.html + */ +package org.opendaylight.controller.logging.bridge.internal; + +import org.junit.Test; +import org.osgi.framework.Bundle; +import org.osgi.framework.ServiceReference; +import org.osgi.service.log.LogEntry; +import org.osgi.service.log.LogService; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import static org.mockito.Mockito.doReturn; +import static org.mockito.Mockito.mock; + +public class LogListenerImplTest { + private static final Logger logger = LoggerFactory.getLogger(LogListenerImplTest.class); + + @Test + public void test() { + LogListenerImpl tested = new LogListenerImpl(logger); + tested.logged(getEntry("m1", null)); + tested.logged(getEntry("m2", new RuntimeException())); + } + + private LogEntry getEntry(final String message, final Exception e) { + return new LogEntry() { + @Override + public Bundle getBundle() { + Bundle mock = mock(Bundle.class); + doReturn(null).when(mock).getSymbolicName(); + return mock; + } + + @Override + public ServiceReference getServiceReference() { + return null; + } + + @Override + public int getLevel() { + return LogService.LOG_INFO; + } + + @Override + public String getMessage() { + return message; + } + + @Override + public Throwable getException() { + return e; + } + + @Override + public long getTime() { + return 0; + } + }; + } + +} diff --git a/opendaylight/md-sal/sal-netconf-connector/src/main/yang/odl-sal-netconf-connector-cfg.yang b/opendaylight/md-sal/sal-netconf-connector/src/main/yang/odl-sal-netconf-connector-cfg.yang index b28e72eb80..f0fa452dc5 100644 --- a/opendaylight/md-sal/sal-netconf-connector/src/main/yang/odl-sal-netconf-connector-cfg.yang +++ b/opendaylight/md-sal/sal-netconf-connector/src/main/yang/odl-sal-netconf-connector-cfg.yang @@ -92,7 +92,7 @@ module odl-sal-netconf-connector-cfg { leaf connection-timeout-millis { description "Specifies timeout in milliseconds after which connection must be established."; type uint32; - default 5000; + default 20000; } leaf max-connection-attempts { diff --git a/opendaylight/netconf/netconf-client/src/main/java/org/opendaylight/controller/netconf/client/NetconfClient.java b/opendaylight/netconf/netconf-client/src/main/java/org/opendaylight/controller/netconf/client/NetconfClient.java index 4fcad2cbd6..b8951a4789 100644 --- a/opendaylight/netconf/netconf-client/src/main/java/org/opendaylight/controller/netconf/client/NetconfClient.java +++ b/opendaylight/netconf/netconf-client/src/main/java/org/opendaylight/controller/netconf/client/NetconfClient.java @@ -61,18 +61,18 @@ public class NetconfClient implements Closeable { try { return clientFuture.get(); } catch (CancellationException e) { - throw new RuntimeException("Netconf client interrupted", e); + throw new RuntimeException("Cancelling " + this, e); } catch (ExecutionException e) { - throw new IllegalStateException("Unable to create netconf client", e); + throw new IllegalStateException("Unable to create " + this, e); } } - public static NetconfClient clientFor(String clientLabelForLogging, InetSocketAddress address, ReconnectStrategy strat, NetconfClientDispatcher netconfClientDispatcher) throws InterruptedException { - return new NetconfClient(clientLabelForLogging,address,strat,netconfClientDispatcher); + public static NetconfClient clientFor(String clientLabelForLogging, InetSocketAddress address, ReconnectStrategy strategy, NetconfClientDispatcher netconfClientDispatcher) throws InterruptedException { + return new NetconfClient(clientLabelForLogging,address,strategy,netconfClientDispatcher); } - public static NetconfClient clientFor(String clientLabelForLogging, InetSocketAddress address, ReconnectStrategy strat, NetconfClientDispatcher netconfClientDispatcher,NetconfClientSessionListener listener) throws InterruptedException { - return new NetconfClient(clientLabelForLogging,address,strat,netconfClientDispatcher,listener); + public static NetconfClient clientFor(String clientLabelForLogging, InetSocketAddress address, ReconnectStrategy strategy, NetconfClientDispatcher netconfClientDispatcher,NetconfClientSessionListener listener) throws InterruptedException { + return new NetconfClient(clientLabelForLogging,address,strategy,netconfClientDispatcher,listener); } public NetconfClient(String clientLabelForLogging, InetSocketAddress address, int connectTimeoutMs, @@ -87,12 +87,12 @@ public class NetconfClient implements Closeable { DEFAULT_CONNECT_TIMEOUT), netconfClientDispatcher); } - public NetconfClient(String clientLabelForLogging, InetSocketAddress address, ReconnectStrategy strat, + public NetconfClient(String clientLabelForLogging, InetSocketAddress address, ReconnectStrategy strategy, NetconfClientDispatcher netconfClientDispatcher, NetconfClientSessionListener listener) throws InterruptedException{ this.label = clientLabelForLogging; dispatch = netconfClientDispatcher; sessionListener = listener; - Future clientFuture = dispatch.createClient(address, sessionListener, strat); + Future clientFuture = dispatch.createClient(address, sessionListener, strategy); this.address = address; clientSession = get(clientFuture); this.sessionId = clientSession.getSessionId(); diff --git a/opendaylight/netconf/netconf-client/src/test/java/org/opendaylight/controller/netconf/client/SSHNetconfClientLiveTest.java b/opendaylight/netconf/netconf-client/src/test/java/org/opendaylight/controller/netconf/client/SSHNetconfClientLiveTest.java index a3cc10417e..1357201f57 100644 --- a/opendaylight/netconf/netconf-client/src/test/java/org/opendaylight/controller/netconf/client/SSHNetconfClientLiveTest.java +++ b/opendaylight/netconf/netconf-client/src/test/java/org/opendaylight/controller/netconf/client/SSHNetconfClientLiveTest.java @@ -12,38 +12,78 @@ import io.netty.channel.nio.NioEventLoopGroup; import org.junit.Before; import org.junit.Ignore; import org.junit.Test; -import org.opendaylight.controller.netconf.api.NetconfMessage; -import org.opendaylight.controller.netconf.util.NetconfUtil; import org.opendaylight.controller.netconf.util.handler.ssh.authentication.LoginPassword; +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; +import java.io.IOException; import java.net.InetSocketAddress; +import java.util.concurrent.ExecutorService; +import java.util.concurrent.Executors; +import java.util.concurrent.TimeUnit; @Ignore public class SSHNetconfClientLiveTest { + private static final Logger logger = LoggerFactory.getLogger(SSHNetconfClientLiveTest.class); NioEventLoopGroup nettyThreadgroup; NetconfSshClientDispatcher netconfClientDispatcher; + InetSocketAddress address; + final int connectionAttempts = 10, attemptMsTimeout = 1000; + final int connectionTimeoutMillis = 20000; @Before public void setUp() { nettyThreadgroup = new NioEventLoopGroup(); + netconfClientDispatcher = new NetconfSshClientDispatcher(new LoginPassword( System.getProperty("username"), System.getProperty("password")), - nettyThreadgroup, nettyThreadgroup, 5000); + nettyThreadgroup, nettyThreadgroup, connectionTimeoutMillis); + + address = new InetSocketAddress(System.getProperty("host"), Integer.parseInt(System.getProperty("port"))); } + @Ignore @Test public void test() throws Exception { - InetSocketAddress address = new InetSocketAddress(System.getProperty("host"), 830); - int connectionAttempts = 10, attemptMsTimeout = 1000; + //runnable.run(); + } - NetconfClient netconfClient = new NetconfClient("client", address, connectionAttempts, - attemptMsTimeout, netconfClientDispatcher); + @Test + public void testInExecutor() throws Exception { + int threads = 4; + ExecutorService executorService = Executors.newFixedThreadPool(threads); + try { + for (int i= 0;i< threads;i++) { + InetSocketAddress address = new InetSocketAddress(System.getProperty("host"), + Integer.parseInt(System.getProperty("port"))); + NetconfRunnable runnable = new NetconfRunnable(address); + executorService.execute(runnable); + } + executorService.shutdown(); + executorService.awaitTermination(1, TimeUnit.MINUTES); - netconfClient.getCapabilities(); - NetconfMessage netconfMessage = NetconfUtil.createMessage(getClass().getResourceAsStream("/get_schema.xml")); - NetconfMessage response = netconfClient.sendMessage(netconfMessage); - NetconfUtil.checkIsMessageOk(response); + } finally { + executorService.shutdownNow(); + } } + + class NetconfRunnable implements Runnable { + private final InetSocketAddress address; + + NetconfRunnable(InetSocketAddress address) { + this.address = address; + } + + @Override + public void run() { + try (NetconfClient netconfClient = new NetconfClient(address.toString(), address, connectionAttempts, + attemptMsTimeout, netconfClientDispatcher);) { + logger.info("OK {}", address); + } catch (InterruptedException | IOException e) { + logger.error("Failed {}", address, e); + } + } + }; } -- 2.36.6