Bug 8824 - NETCONF request hangs when rpc-rply has invalid xml
[netconf.git] / netconf / sal-netconf-connector / src / main / java / org / opendaylight / netconf / sal / connect / netconf / listener / NetconfDeviceCommunicator.java
1 /*
2  * Copyright (c) 2014 Cisco Systems, Inc. and others.  All rights reserved.
3  *
4  * This program and the accompanying materials are made available under the
5  * terms of the Eclipse Public License v1.0 which accompanies this distribution,
6  * and is available at http://www.eclipse.org/legal/epl-v10.html
7  */
8 package org.opendaylight.netconf.sal.connect.netconf.listener;
9
10 import com.google.common.base.Optional;
11 import com.google.common.base.Strings;
12 import com.google.common.collect.Lists;
13 import com.google.common.util.concurrent.Futures;
14 import com.google.common.util.concurrent.ListenableFuture;
15 import com.google.common.util.concurrent.SettableFuture;
16 import io.netty.util.concurrent.Future;
17 import java.util.ArrayDeque;
18 import java.util.Iterator;
19 import java.util.List;
20 import java.util.Queue;
21 import java.util.concurrent.Semaphore;
22 import java.util.concurrent.atomic.AtomicBoolean;
23 import java.util.concurrent.locks.Lock;
24 import java.util.concurrent.locks.ReentrantLock;
25
26 import org.opendaylight.controller.config.util.xml.DocumentedException;
27 import org.opendaylight.controller.config.util.xml.XmlElement;
28 import org.opendaylight.controller.config.util.xml.XmlUtil;
29 import org.opendaylight.netconf.api.FailedNetconfMessage;
30 import org.opendaylight.netconf.api.NetconfDocumentedException;
31 import org.opendaylight.netconf.api.NetconfMessage;
32 import org.opendaylight.netconf.api.NetconfTerminationReason;
33 import org.opendaylight.netconf.api.xml.XmlNetconfConstants;
34 import org.opendaylight.netconf.client.NetconfClientDispatcher;
35 import org.opendaylight.netconf.client.NetconfClientSession;
36 import org.opendaylight.netconf.client.NetconfClientSessionListener;
37 import org.opendaylight.netconf.client.conf.NetconfClientConfiguration;
38 import org.opendaylight.netconf.client.conf.NetconfReconnectingClientConfiguration;
39 import org.opendaylight.netconf.sal.connect.api.RemoteDevice;
40 import org.opendaylight.netconf.sal.connect.api.RemoteDeviceCommunicator;
41 import org.opendaylight.netconf.sal.connect.netconf.util.NetconfMessageTransformUtil;
42 import org.opendaylight.netconf.sal.connect.util.RemoteDeviceId;
43 import org.opendaylight.yangtools.yang.common.QName;
44 import org.opendaylight.yangtools.yang.common.RpcError;
45 import org.opendaylight.yangtools.yang.common.RpcResult;
46 import org.opendaylight.yangtools.yang.common.RpcResultBuilder;
47 import org.slf4j.Logger;
48 import org.slf4j.LoggerFactory;
49
50 public class NetconfDeviceCommunicator implements NetconfClientSessionListener, RemoteDeviceCommunicator<NetconfMessage> {
51
52     private static final Logger LOG = LoggerFactory.getLogger(NetconfDeviceCommunicator.class);
53
54     protected final RemoteDevice<NetconfSessionPreferences, NetconfMessage, NetconfDeviceCommunicator> remoteDevice;
55     private final Optional<UserPreferences> overrideNetconfCapabilities;
56     protected final RemoteDeviceId id;
57     private final Lock sessionLock = new ReentrantLock();
58
59     private final Semaphore semaphore;
60     private final int concurentRpcMsgs;
61
62     private final Queue<Request> requests = new ArrayDeque<>();
63     private NetconfClientSession session;
64
65     private Future<?> initFuture;
66     private final SettableFuture<NetconfDeviceCapabilities> firstConnectionFuture;
67
68     // isSessionClosing indicates a close operation on the session is issued and
69     // tearDown will surely be called later to finish the close.
70     // Used to allow only one thread to enter tearDown and other threads should
71     // NOT enter it simultaneously and should end its close operation without
72     // calling tearDown to release the locks they hold to avoid deadlock.
73     private final AtomicBoolean isSessionClosing = new AtomicBoolean(false);
74
75     public Boolean isSessionClosing() {
76         return isSessionClosing.get();
77     }
78
79     public NetconfDeviceCommunicator(final RemoteDeviceId id, final RemoteDevice<NetconfSessionPreferences, NetconfMessage, NetconfDeviceCommunicator> remoteDevice,
80             final UserPreferences NetconfSessionPreferences, final int rpcMessageLimit) {
81         this(id, remoteDevice, Optional.of(NetconfSessionPreferences), rpcMessageLimit);
82     }
83
84     public NetconfDeviceCommunicator(final RemoteDeviceId id,
85                                      final RemoteDevice<NetconfSessionPreferences, NetconfMessage, NetconfDeviceCommunicator> remoteDevice,
86                                      final int rpcMessageLimit) {
87         this(id, remoteDevice, Optional.<UserPreferences>absent(), rpcMessageLimit);
88     }
89
90     private NetconfDeviceCommunicator(final RemoteDeviceId id, final RemoteDevice<NetconfSessionPreferences, NetconfMessage, NetconfDeviceCommunicator> remoteDevice,
91                                       final Optional<UserPreferences> overrideNetconfCapabilities, final int rpcMessageLimit) {
92         this.concurentRpcMsgs = rpcMessageLimit;
93         this.id = id;
94         this.remoteDevice = remoteDevice;
95         this.overrideNetconfCapabilities = overrideNetconfCapabilities;
96         this.firstConnectionFuture = SettableFuture.create();
97         this.semaphore = rpcMessageLimit > 0 ? new Semaphore(rpcMessageLimit) : null;
98     }
99
100     @Override
101     public void onSessionUp(final NetconfClientSession session) {
102         sessionLock.lock();
103         try {
104             LOG.debug("{}: Session established", id);
105             this.session = session;
106
107             NetconfSessionPreferences netconfSessionPreferences =
108                                              NetconfSessionPreferences.fromNetconfSession(session);
109             LOG.trace("{}: Session advertised capabilities: {}", id,
110                     netconfSessionPreferences);
111
112             if (overrideNetconfCapabilities.isPresent()) {
113                 final NetconfSessionPreferences sessionPreferences = overrideNetconfCapabilities
114                         .get().getSessionPreferences();
115                 netconfSessionPreferences = overrideNetconfCapabilities.get().moduleBasedCapsOverrided()
116                         ? netconfSessionPreferences.replaceModuleCaps(sessionPreferences)
117                         : netconfSessionPreferences.addModuleCaps(sessionPreferences);
118
119                 netconfSessionPreferences = overrideNetconfCapabilities.get().nonModuleBasedCapsOverrided()
120                         ? netconfSessionPreferences.replaceNonModuleCaps(sessionPreferences)
121                         : netconfSessionPreferences.addNonModuleCaps(sessionPreferences);
122                 LOG.debug("{}: Session capabilities overridden, capabilities that will be used: {}", id,
123                         netconfSessionPreferences);
124             }
125
126             remoteDevice.onRemoteSessionUp(netconfSessionPreferences, this);
127             if (!firstConnectionFuture.isDone()) {
128                 firstConnectionFuture.set(netconfSessionPreferences.getNetconfDeviceCapabilities());
129             }
130         }
131         finally {
132             sessionLock.unlock();
133         }
134     }
135
136     /**
137      *
138      * @param dispatcher
139      * @param config
140      * @return future that returns succes on first succesfull connection and failure when the underlying
141      * reconnecting strategy runs out of reconnection attempts
142      */
143     public ListenableFuture<NetconfDeviceCapabilities> initializeRemoteConnection(final NetconfClientDispatcher dispatcher, final NetconfClientConfiguration config) {
144         if(config instanceof NetconfReconnectingClientConfiguration) {
145             initFuture = dispatcher.createReconnectingClient((NetconfReconnectingClientConfiguration) config);
146         } else {
147             initFuture = dispatcher.createClient(config);
148         }
149
150
151         initFuture.addListener(future -> {
152             if (!future.isSuccess() && !future.isCancelled()) {
153                 LOG.debug("{}: Connection failed", id, future.cause());
154                 NetconfDeviceCommunicator.this.remoteDevice.onRemoteSessionFailed(future.cause());
155                 if (firstConnectionFuture.isDone()) {
156                     firstConnectionFuture.setException(future.cause());
157                 }
158             }
159         });
160         return firstConnectionFuture;
161     }
162
163     public void disconnect() {
164         // If session is already in closing, no need to close it again
165         if(session != null && isSessionClosing.compareAndSet(false, true)) {
166             session.close();
167         }
168     }
169
170     private void tearDown(final String reason) {
171         if (!isSessionClosing()) {
172             LOG.warn("It's curious that no one to close the session but tearDown is called!");
173         }
174         LOG.debug("Tearing down {}", reason);
175         final List<UncancellableFuture<RpcResult<NetconfMessage>>> futuresToCancel = Lists.newArrayList();
176         sessionLock.lock();
177         try {
178             if( session != null ) {
179                 session = null;
180
181                 /*
182                  * Walk all requests, check if they have been executing
183                  * or cancelled and remove them from the queue.
184                  */
185                 final Iterator<Request> it = requests.iterator();
186                 while (it.hasNext()) {
187                     final Request r = it.next();
188                     if (r.future.isUncancellable()) {
189                         futuresToCancel.add( r.future );
190                         it.remove();
191                     } else if (r.future.isCancelled()) {
192                         // This just does some house-cleaning
193                         it.remove();
194                     }
195                 }
196
197                 remoteDevice.onRemoteSessionDown();
198             }
199         }
200         finally {
201             sessionLock.unlock();
202         }
203
204         // Notify pending request futures outside of the sessionLock to avoid unnecessarily
205         // blocking the caller.
206         for (final UncancellableFuture<RpcResult<NetconfMessage>> future : futuresToCancel) {
207             if( Strings.isNullOrEmpty( reason ) ) {
208                 future.set( createSessionDownRpcResult() );
209             } else {
210                 future.set( createErrorRpcResult( RpcError.ErrorType.TRANSPORT, reason ) );
211             }
212         }
213
214         isSessionClosing.set(false);
215     }
216
217     private RpcResult<NetconfMessage> createSessionDownRpcResult() {
218         return createErrorRpcResult( RpcError.ErrorType.TRANSPORT,
219                              String.format( "The netconf session to %1$s is disconnected", id.getName() ) );
220     }
221
222     private static RpcResult<NetconfMessage> createErrorRpcResult(final RpcError.ErrorType errorType,
223             final String message) {
224         return RpcResultBuilder.<NetconfMessage>failed()
225                 .withError(errorType, NetconfDocumentedException.ErrorTag.OPERATION_FAILED.getTagValue(), message).build();
226     }
227
228     @Override
229     public void onSessionDown(final NetconfClientSession session, final Exception e) {
230         // If session is already in closing, no need to call tearDown again.
231         if (isSessionClosing.compareAndSet(false, true)) {
232             LOG.warn("{}: Session went down", id, e);
233             tearDown( null );
234         }
235     }
236
237     @Override
238     public void onSessionTerminated(final NetconfClientSession session, final NetconfTerminationReason reason) {
239         // onSessionTerminated is called directly by disconnect, no need to compare and set isSessionClosing.
240         LOG.warn("{}: Session terminated {}", id, reason);
241         tearDown( reason.getErrorMessage() );
242     }
243
244     @Override
245     public void close() {
246         // Cancel reconnect if in progress
247         if(initFuture != null) {
248             initFuture.cancel(false);
249         }
250         // Disconnect from device
251         // tear down not necessary, called indirectly by the close in disconnect()
252         disconnect();
253     }
254
255     @Override
256     public void onMessage(final NetconfClientSession session, final NetconfMessage message) {
257         /*
258          * Dispatch between notifications and messages. Messages need to be processed
259          * with lock held, notifications do not.
260          */
261         if (isNotification(message)) {
262             processNotification(message);
263         } else {
264             processMessage(message);
265         }
266     }
267
268     private void processMessage(final NetconfMessage message) {
269         Request request = null;
270         sessionLock.lock();
271
272         try {
273             request = requests.peek();
274             if (request != null && request.future.isUncancellable()) {
275                 requests.poll();
276                 // we have just removed one request from the queue
277                 // we can also release one permit
278                 if(semaphore != null) {
279                     semaphore.release();
280                 }
281             } else {
282                 request = null;
283                 LOG.warn("{}: Ignoring unsolicited message {}", id,
284                         msgToS(message));
285             }
286         }
287         finally {
288             sessionLock.unlock();
289         }
290
291         if( request != null ) {
292
293             if (FailedNetconfMessage.class.isInstance(message)) {
294                 request.future.set(NetconfMessageTransformUtil.toRpcResult((FailedNetconfMessage) message));
295                 return;
296             }
297
298             LOG.debug("{}: Message received {}", id, message);
299
300             if(LOG.isTraceEnabled()) {
301                 LOG.trace( "{}: Matched request: {} to response: {}", id, msgToS( request.request ), msgToS( message ) );
302             }
303
304             try {
305                 NetconfMessageTransformUtil.checkValidReply( request.request, message );
306             } catch (final NetconfDocumentedException e) {
307                 LOG.warn(
308                         "{}: Invalid request-reply match, reply message contains different message-id, request: {}, response: {}",
309                         id, msgToS(request.request), msgToS(message), e);
310
311                 request.future.set( RpcResultBuilder.<NetconfMessage>failed()
312                         .withRpcError( NetconfMessageTransformUtil.toRpcError( e ) ).build() );
313
314                 //recursively processing message to eventually find matching request
315                 processMessage(message);
316
317                 return;
318             }
319
320             try {
321                 NetconfMessageTransformUtil.checkSuccessReply(message);
322             } catch(final NetconfDocumentedException e) {
323                 LOG.warn(
324                         "{}: Error reply from remote device, request: {}, response: {}",
325                         id, msgToS(request.request), msgToS(message), e);
326
327                 request.future.set( RpcResultBuilder.<NetconfMessage>failed()
328                         .withRpcError( NetconfMessageTransformUtil.toRpcError( e ) ).build() );
329                 return;
330             }
331
332             request.future.set( RpcResultBuilder.success( message ).build() );
333         }
334     }
335
336     private static String msgToS(final NetconfMessage msg) {
337         return XmlUtil.toString(msg.getDocument());
338     }
339
340     @Override
341     public ListenableFuture<RpcResult<NetconfMessage>> sendRequest(final NetconfMessage message, final QName rpc) {
342         sessionLock.lock();
343
344         if (semaphore != null && !semaphore.tryAcquire()) {
345             LOG.warn("Limit of concurrent rpc messages was reached (limit :" +
346                     concurentRpcMsgs + "). Rpc reply message is needed. Discarding request of Netconf device with id" + id.getName());
347             sessionLock.unlock();
348             return Futures.immediateFailedFuture(new NetconfDocumentedException("Limit of rpc messages was reached (Limit :" +
349                     concurentRpcMsgs + ") waiting for emptying the queue of Netconf device with id" + id.getName()));
350         }
351
352         try {
353             return sendRequestWithLock(message, rpc);
354         } finally {
355             sessionLock.unlock();
356         }
357     }
358
359     private ListenableFuture<RpcResult<NetconfMessage>> sendRequestWithLock(
360                                                final NetconfMessage message, final QName rpc) {
361         if(LOG.isTraceEnabled()) {
362             LOG.trace("{}: Sending message {}", id, msgToS(message));
363         }
364
365         if (session == null) {
366             LOG.warn("{}: Session is disconnected, failing RPC request {}",
367                     id, message);
368             return Futures.immediateFuture( createSessionDownRpcResult() );
369         }
370
371         final Request req = new Request(new UncancellableFuture<>(true), message);
372         requests.add(req);
373
374         session.sendMessage(req.request).addListener(future -> {
375             if( !future.isSuccess() ) {
376                 // We expect that a session down will occur at this point
377                 LOG.debug("{}: Failed to send request {}", id,
378                         XmlUtil.toString(req.request.getDocument()),
379                         future.cause());
380
381                 if( future.cause() != null ) {
382                     req.future.set( createErrorRpcResult( RpcError.ErrorType.TRANSPORT,
383                                                           future.cause().getLocalizedMessage() ) );
384                 } else {
385                     req.future.set( createSessionDownRpcResult() ); // assume session is down
386                 }
387                 req.future.setException( future.cause() );
388             }
389             else {
390                 LOG.trace("Finished sending request {}", req.request);
391             }
392         });
393
394         return req.future;
395     }
396
397     private void processNotification(final NetconfMessage notification) {
398         if(LOG.isTraceEnabled()) {
399             LOG.trace("{}: Notification received: {}", id, notification);
400         }
401
402         remoteDevice.onNotification(notification);
403     }
404
405     private static boolean isNotification(final NetconfMessage message) {
406         if (message.getDocument() == null) {
407             // We have no message, which mean we have a FailedNetconfMessage
408             return false;
409         }
410         final XmlElement xmle = XmlElement.fromDomDocument(message.getDocument());
411         return XmlNetconfConstants.NOTIFICATION_ELEMENT_NAME.equals(xmle.getName()) ;
412     }
413
414     private static final class Request {
415         final UncancellableFuture<RpcResult<NetconfMessage>> future;
416         final NetconfMessage request;
417
418         private Request(final UncancellableFuture<RpcResult<NetconfMessage>> future,
419                         final NetconfMessage request) {
420             this.future = future;
421             this.request = request;
422         }
423     }
424 }