Fixed deadlock in AsyncSshHandlerWriter
[netconf.git] / netconf / netconf-netty-util / src / main / java / org / opendaylight / netconf / nettyutil / handler / ssh / client / AsyncSshHandlerWriter.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
9 package org.opendaylight.netconf.nettyutil.handler.ssh.client;
10
11 import com.google.common.base.Preconditions;
12 import io.netty.buffer.ByteBuf;
13 import io.netty.channel.ChannelHandlerContext;
14 import io.netty.channel.ChannelPromise;
15 import java.io.IOException;
16 import java.nio.charset.StandardCharsets;
17 import java.util.Deque;
18 import java.util.LinkedList;
19 import java.util.Queue;
20 import org.apache.sshd.common.io.IoOutputStream;
21 import org.apache.sshd.common.io.WritePendingException;
22 import org.apache.sshd.common.util.buffer.Buffer;
23 import org.apache.sshd.common.util.buffer.ByteArrayBuffer;
24 import org.checkerframework.checker.lock.qual.GuardedBy;
25 import org.slf4j.Logger;
26 import org.slf4j.LoggerFactory;
27
28 /**
29  * Async Ssh writer. Takes messages(byte arrays) and sends them encrypted to remote server.
30  * Also handles pending writes by caching requests until pending state is over.
31  */
32 public final class AsyncSshHandlerWriter implements AutoCloseable {
33
34     private static final Logger LOG = LoggerFactory
35             .getLogger(AsyncSshHandlerWriter.class);
36
37     // public static final int MAX_PENDING_WRITES = 1000;
38     // TODO implement Limiting mechanism for pending writes
39     // But there is a possible issue with limiting:
40     // 1. What to do when queue is full ? Immediate Fail for every request ?
41     // 2. At this level we might be dealing with Chunks of messages(not whole messages)
42     // and unexpected behavior might occur when we send/queue 1 chunk and fail the other chunks
43
44     private final Object asyncInLock = new Object();
45     private volatile IoOutputStream asyncIn;
46
47     // Order has to be preserved for queued writes
48     private final Deque<PendingWriteRequest> pending = new LinkedList<>();
49
50     public AsyncSshHandlerWriter(final IoOutputStream asyncIn) {
51         this.asyncIn = asyncIn;
52     }
53
54     @GuardedBy("asyncInLock")
55     private boolean isWriteExecuted = false;
56
57     public void write(final ChannelHandlerContext ctx,
58             final Object msg, final ChannelPromise promise) {
59         if (asyncIn == null) {
60             promise.setFailure(new IllegalStateException("Channel closed"));
61             return;
62         }
63         // synchronized block due to deadlock that happens on ssh window resize
64         // writes and pending writes would lock the underlyinch channel session
65         // window resize write would try to write the message on an already locked channelSession
66         // while the pending write was in progress from the write callback
67         synchronized (asyncInLock) {
68             // TODO check for isClosed, isClosing might be performed by mina SSH internally and is not required here
69             // If we are closed/closing, set immediate fail
70             if (asyncIn.isClosed() || asyncIn.isClosing()) {
71                 promise.setFailure(new IllegalStateException("Channel closed"));
72             } else {
73                 final ByteBuf byteBufMsg = (ByteBuf) msg;
74                 if (isWriteExecuted) {
75                     queueRequest(ctx, byteBufMsg, promise);
76                     return;
77                 }
78
79                 writeWithPendingDetection(ctx, promise, byteBufMsg, false);
80             }
81         }
82     }
83
84     //sending message with pending
85     //if resending message not succesfull, then attribute wasPending is true
86     private void writeWithPendingDetection(final ChannelHandlerContext ctx, final ChannelPromise promise,
87                                            final ByteBuf byteBufMsg, final boolean wasPending) {
88         try {
89
90             if (LOG.isTraceEnabled()) {
91                 LOG.trace("Writing request on channel: {}, message: {}", ctx.channel(), byteBufToString(byteBufMsg));
92             }
93
94             isWriteExecuted = true;
95
96             asyncIn.writePacket(toBuffer(byteBufMsg)).addListener(future -> {
97                 // synchronized block due to deadlock that happens on ssh window resize
98                 // writes and pending writes would lock the underlyinch channel session
99                 // window resize write would try to write the message on an already locked channelSession,
100                 // while the pending write was in progress from the write callback
101                 synchronized (asyncInLock) {
102                     if (LOG.isTraceEnabled()) {
103                         LOG.trace(
104                             "Ssh write request finished on channel: {} with result: {}: and ex:{}, message: {}",
105                             ctx.channel(), future.isWritten(), future.getException(), byteBufToString(byteBufMsg));
106                     }
107
108                     // Notify success or failure
109                     if (future.isWritten()) {
110                         promise.setSuccess();
111                     } else {
112                         LOG.warn("Ssh write request failed on channel: {} for message: {}", ctx.channel(),
113                                 byteBufToString(byteBufMsg), future.getException());
114                         promise.setFailure(future.getException());
115                     }
116
117                     //rescheduling message from queue after successfully sent
118                     if (wasPending) {
119                         byteBufMsg.resetReaderIndex();
120                         pending.remove();
121                     }
122
123                     // Not needed anymore, release
124                     byteBufMsg.release();
125                 }
126
127                 // Check pending queue and schedule next
128                 // At this time we are guaranteed that we are not in pending state anymore
129                 // so the next request should succeed
130                 writePendingIfAny();
131             });
132
133         } catch (final IOException | WritePendingException e) {
134             if (!wasPending) {
135                 queueRequest(ctx, byteBufMsg, promise);
136             }
137         }
138     }
139
140     private void writePendingIfAny() {
141         synchronized (asyncInLock) {
142             if (pending.peek() == null) {
143                 isWriteExecuted = false;
144                 return;
145             }
146
147             final PendingWriteRequest pendingWrite = pending.peek();
148             final ByteBuf msg = pendingWrite.msg;
149             if (LOG.isTraceEnabled()) {
150                 LOG.trace("Writing pending request on channel: {}, message: {}",
151                         pendingWrite.ctx.channel(), byteBufToString(msg));
152             }
153
154             writeWithPendingDetection(pendingWrite.ctx, pendingWrite.promise, msg, true);
155         }
156     }
157
158     public static String byteBufToString(final ByteBuf msg) {
159         final String s = msg.toString(StandardCharsets.UTF_8);
160         msg.resetReaderIndex();
161         return s;
162     }
163
164     private void queueRequest(final ChannelHandlerContext ctx, final ByteBuf msg, final ChannelPromise promise) {
165 //        try {
166         LOG.debug("Write pending on channel: {}, queueing, current queue size: {}", ctx.channel(), pending.size());
167         if (LOG.isTraceEnabled()) {
168             LOG.trace("Queueing request due to pending: {}", byteBufToString(msg));
169         }
170         new PendingWriteRequest(ctx, msg, promise).pend(pending);
171 //        } catch (final Exception ex) {
172 //            LOG.warn("Unable to queue write request on channel: {}. Setting fail for the request: {}",
173 //                    ctx.channel(), ex, byteBufToString(msg));
174 //            msg.release();
175 //            promise.setFailure(ex);
176 //        }
177     }
178
179     @Override
180     public void close() {
181         asyncIn = null;
182     }
183
184     private static Buffer toBuffer(final ByteBuf msg) {
185         // TODO Buffer vs ByteBuf translate, Can we handle that better ?
186         msg.resetReaderIndex();
187         final byte[] temp = new byte[msg.readableBytes()];
188         msg.readBytes(temp, 0, msg.readableBytes());
189         return new ByteArrayBuffer(temp);
190     }
191
192     private static final class PendingWriteRequest {
193         private final ChannelHandlerContext ctx;
194         private final ByteBuf msg;
195         private final ChannelPromise promise;
196
197         PendingWriteRequest(final ChannelHandlerContext ctx, final ByteBuf msg, final ChannelPromise promise) {
198             this.ctx = ctx;
199             // Reset reader index, last write (failed) attempt moved index to the end
200             msg.resetReaderIndex();
201             this.msg = msg;
202             this.promise = promise;
203         }
204
205         public void pend(final Queue<PendingWriteRequest> pending) {
206             // Preconditions.checkState(pending.size() < MAX_PENDING_WRITES,
207             // "Too much pending writes(%s) on channel: %s, remote window is not getting read or is too small",
208             // pending.size(), ctx.channel());
209             Preconditions.checkState(pending.offer(this),
210                 "Cannot pend another request write (pending count: %s) on channel: %s", pending.size(), ctx.channel());
211         }
212     }
213 }