Improved logging in PCEP.
[bgpcep.git] / pcep / impl / src / main / java / org / opendaylight / protocol / pcep / impl / PCEPSessionImpl.java
1 /*
2  * Copyright (c) 2013 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.protocol.pcep.impl;
9
10 import io.netty.channel.Channel;
11 import io.netty.channel.ChannelFuture;
12 import io.netty.channel.ChannelFutureListener;
13 import io.netty.util.Timeout;
14 import io.netty.util.Timer;
15 import io.netty.util.TimerTask;
16 import io.netty.util.concurrent.Future;
17
18 import java.io.IOException;
19 import java.net.InetAddress;
20 import java.net.InetSocketAddress;
21 import java.util.Date;
22 import java.util.LinkedList;
23 import java.util.Queue;
24 import java.util.concurrent.TimeUnit;
25
26 import org.opendaylight.protocol.framework.AbstractProtocolSession;
27 import org.opendaylight.protocol.pcep.PCEPCloseTermination;
28 import org.opendaylight.protocol.pcep.PCEPSession;
29 import org.opendaylight.protocol.pcep.PCEPSessionListener;
30 import org.opendaylight.protocol.pcep.TerminationReason;
31 import org.opendaylight.protocol.pcep.spi.PCEPErrors;
32 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.message.rev131007.CloseBuilder;
33 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.message.rev131007.Keepalive;
34 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.message.rev131007.KeepaliveBuilder;
35 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.types.rev131005.CloseMessage;
36 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.types.rev131005.KeepaliveMessage;
37 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.types.rev131005.Message;
38 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.types.rev131005.OpenMessage;
39 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.types.rev131005.close.message.CCloseMessageBuilder;
40 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.types.rev131005.close.object.CCloseBuilder;
41 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.types.rev131005.keepalive.message.KeepaliveMessageBuilder;
42 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.types.rev131005.open.object.Open;
43 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.pcep.types.rev131005.open.object.open.Tlvs;
44 import org.slf4j.Logger;
45 import org.slf4j.LoggerFactory;
46
47 import com.google.common.annotations.VisibleForTesting;
48 import com.google.common.base.Objects;
49 import com.google.common.base.Objects.ToStringHelper;
50 import com.google.common.base.Preconditions;
51
52 /**
53  * Implementation of PCEPSession. (Not final for testing.)
54  */
55 @VisibleForTesting
56 public class PCEPSessionImpl extends AbstractProtocolSession<Message> implements PCEPSession, PCEPSessionRuntimeMXBean {
57         /**
58          * System.nanoTime value about when was sent the last message Protected to be updated also in tests.
59          */
60         @VisibleForTesting
61         protected volatile long lastMessageSentAt;
62
63         /**
64          * System.nanoTime value about when was received the last message
65          */
66         private long lastMessageReceivedAt;
67
68         @VisibleForTesting
69         protected final Queue<Long> unknownMessagesTimes = new LinkedList<Long>();
70
71         private final PCEPSessionListener listener;
72
73         /**
74          * Open Object with session characteristics that were accepted by another PCE (sent from this session).
75          */
76         private final Open localOpen;
77
78         /**
79          * Open Object with session characteristics for this session (sent from another PCE).
80          */
81         private final Open remoteOpen;
82
83         private static final Logger LOG = LoggerFactory.getLogger(PCEPSessionImpl.class);
84
85         /**
86          * Timer object grouping FSM Timers
87          */
88         private final Timer stateTimer;
89
90         private int sentMsgCount = 0;
91
92         private int receivedMsgCount = 0;
93
94         private int maxUnknownMessages;
95
96         // True if the listener should not be notified about events
97         private boolean closed = false;
98
99         private final Channel channel;
100
101         private final Keepalive kaMessage = new KeepaliveBuilder().setKeepaliveMessage(new KeepaliveMessageBuilder().build()).build();
102
103         PCEPSessionImpl(final Timer timer, final PCEPSessionListener listener, final int maxUnknownMessages, final Channel channel,
104                         final Open localOpen, final Open remoteOpen) {
105                 this.listener = Preconditions.checkNotNull(listener);
106                 this.stateTimer = Preconditions.checkNotNull(timer);
107                 this.channel = Preconditions.checkNotNull(channel);
108                 this.localOpen = Preconditions.checkNotNull(localOpen);
109                 this.remoteOpen = Preconditions.checkNotNull(remoteOpen);
110                 this.lastMessageReceivedAt = System.nanoTime();
111
112                 if (maxUnknownMessages != 0) {
113                         this.maxUnknownMessages = maxUnknownMessages;
114                 }
115
116                 if (getDeadTimerValue() != 0) {
117                         this.stateTimer.newTimeout(new TimerTask() {
118                                 @Override
119                                 public void run(final Timeout timeout) {
120                                         handleDeadTimer();
121                                 }
122                         }, getDeadTimerValue(), TimeUnit.SECONDS);
123                 }
124
125                 if (getKeepAliveTimerValue() != 0) {
126                         this.stateTimer.newTimeout(new TimerTask() {
127                                 @Override
128                                 public void run(final Timeout timeout) {
129                                         handleKeepaliveTimer();
130                                 }
131                         }, getKeepAliveTimerValue(), TimeUnit.SECONDS);
132                 }
133
134                 LOG.info("Session {}[{}] <-> {}[{}] started", channel.localAddress(), localOpen.getSessionId(), channel.remoteAddress(),
135                                 remoteOpen.getSessionId());
136         }
137
138         /**
139          * If DeadTimer expires, the session ends. If a message (whichever) was received during this period, the DeadTimer
140          * will be rescheduled by DEAD_TIMER_VALUE + the time that has passed from the start of the DeadTimer to the time at
141          * which the message was received. If the session was closed by the time this method starts to execute (the session
142          * state will become IDLE), that rescheduling won't occur.
143          */
144         private synchronized void handleDeadTimer() {
145                 final long ct = System.nanoTime();
146
147                 final long nextDead = this.lastMessageReceivedAt + TimeUnit.SECONDS.toNanos(getDeadTimerValue());
148
149                 if (this.channel.isActive()) {
150                         if (ct >= nextDead) {
151                                 LOG.debug("DeadTimer expired. " + new Date());
152                                 this.terminate(TerminationReason.ExpDeadtimer);
153                         } else {
154                                 this.stateTimer.newTimeout(new TimerTask() {
155                                         @Override
156                                         public void run(final Timeout timeout) {
157                                                 handleDeadTimer();
158                                         }
159                                 }, nextDead - ct, TimeUnit.NANOSECONDS);
160                         }
161                 }
162         }
163
164         /**
165          * If KeepAlive Timer expires, sends KeepAlive message. If a message (whichever) was send during this period, the
166          * KeepAlive Timer will be rescheduled by KEEP_ALIVE_TIMER_VALUE + the time that has passed from the start of the
167          * KeepAlive timer to the time at which the message was sent. If the session was closed by the time this method
168          * starts to execute (the session state will become IDLE), that rescheduling won't occur.
169          */
170         private synchronized void handleKeepaliveTimer() {
171                 final long ct = System.nanoTime();
172
173                 long nextKeepalive = this.lastMessageSentAt + TimeUnit.SECONDS.toNanos(getKeepAliveTimerValue());
174
175                 if (this.channel.isActive()) {
176                         if (ct >= nextKeepalive) {
177                                 this.sendMessage(this.kaMessage);
178                                 nextKeepalive = this.lastMessageSentAt + TimeUnit.SECONDS.toNanos(getKeepAliveTimerValue());
179                         }
180
181                         this.stateTimer.newTimeout(new TimerTask() {
182                                 @Override
183                                 public void run(final Timeout timeout) {
184                                         handleKeepaliveTimer();
185                                 }
186                         }, nextKeepalive - ct, TimeUnit.NANOSECONDS);
187                 }
188         }
189
190         /**
191          * Sends message to serialization.
192          *
193          * @param msg to be sent
194          */
195         @Override
196         public Future<Void> sendMessage(final Message msg) {
197                 final ChannelFuture f = this.channel.writeAndFlush(msg);
198                 this.lastMessageSentAt = System.nanoTime();
199                 if (!(msg instanceof KeepaliveMessage)) {
200                         LOG.debug("PCEP Message enqueued: {}", msg);
201                 }
202                 this.sentMsgCount++;
203
204                 f.addListener(new ChannelFutureListener() {
205                         @Override
206                         public void operationComplete(final ChannelFuture arg) {
207                                 if (arg.isSuccess()) {
208                                         LOG.trace("Message sent to socket: {}", msg);
209                                 } else {
210                                         LOG.debug("Message not sent: {}", msg, arg.cause());
211                                 }
212                         }
213                 });
214
215                 return f;
216         }
217
218         /**
219          * Closes PCEP session without sending a Close message, as the channel is no longer active.
220          */
221         @Override
222         public void close() {
223                 LOG.info("Closing PCEP session: {}", this);
224                 this.channel.close();
225         }
226
227         /**
228          * Closes PCEP session, cancels all timers, returns to state Idle, sends the Close Message. KeepAlive and DeadTimer
229          * are cancelled if the state of the session changes to IDLE. This method is used to close the PCEP session from
230          * inside the session or from the listener, therefore the parent of this session should be informed.
231          */
232         @Override
233         public synchronized void close(final TerminationReason reason) {
234                 LOG.info("Closing PCEP session: {}", this);
235                 this.closed = true;
236                 this.sendMessage(new CloseBuilder().setCCloseMessage(
237                                 new CCloseMessageBuilder().setCClose(new CCloseBuilder().setReason(reason.getShortValue()).build()).build()).build());
238                 this.channel.close();
239         }
240
241         @Override
242         public Tlvs getRemoteTlvs() {
243                 return this.remoteOpen.getTlvs();
244         }
245
246         @Override
247         public InetAddress getRemoteAddress() {
248                 return ((InetSocketAddress) this.channel.remoteAddress()).getAddress();
249         }
250
251         private synchronized void terminate(final TerminationReason reason) {
252                 LOG.info("Local PCEP session termination : {}", reason);
253                 this.listener.onSessionTerminated(this, new PCEPCloseTermination(reason));
254                 this.closed = true;
255                 this.sendMessage(new CloseBuilder().setCCloseMessage(
256                                 new CCloseMessageBuilder().setCClose(new CCloseBuilder().setReason(reason.getShortValue()).build()).build()).build());
257                 this.close();
258         }
259
260         @Override
261         public synchronized void endOfInput() {
262                 if (!this.closed) {
263                         this.listener.onSessionDown(this, new IOException("End of input detected. Close the session."));
264                         this.closed = true;
265                 }
266         }
267
268         private void sendErrorMessage(final PCEPErrors value) {
269                 this.sendErrorMessage(value, null);
270         }
271
272         /**
273          * Sends PCEP Error Message with one PCEPError and Open Object.
274          *
275          * @param value
276          * @param open
277          */
278         private void sendErrorMessage(final PCEPErrors value, final Open open) {
279                 this.sendMessage(Util.createErrorMessage(value, open));
280         }
281
282         /**
283          * The fact, that a message is malformed, comes from parser. In case of unrecognized message a particular error is
284          * sent (CAPABILITY_NOT_SUPPORTED) and the method checks if the MAX_UNKNOWN_MSG per minute wasn't overstepped.
285          * Second, any other error occurred that is specified by rfc. In this case, the an error message is generated and
286          * sent.
287          *
288          * @param error documented error in RFC5440 or draft
289          */
290         @VisibleForTesting
291         public void handleMalformedMessage(final PCEPErrors error) {
292                 final long ct = System.nanoTime();
293                 this.sendErrorMessage(error);
294                 if (error == PCEPErrors.CAPABILITY_NOT_SUPPORTED) {
295                         this.unknownMessagesTimes.add(ct);
296                         while (ct - this.unknownMessagesTimes.peek() > 60 * 1E9) {
297                                 this.unknownMessagesTimes.poll();
298                         }
299                         if (this.unknownMessagesTimes.size() > this.maxUnknownMessages) {
300                                 this.terminate(TerminationReason.TooManyUnknownMsg);
301                         }
302                 }
303         }
304
305         /**
306          * Handles incoming message. If the session is up, it notifies the user. The user is notified about every message
307          * except KeepAlive.
308          *
309          * @param msg incoming message
310          */
311         @Override
312         public void handleMessage(final Message msg) {
313                 // Update last reception time
314                 this.lastMessageReceivedAt = System.nanoTime();
315                 this.receivedMsgCount++;
316                 if (!(msg instanceof KeepaliveMessage)) {
317                         LOG.debug("PCEP message {} received.", msg);
318                 }
319                 // Internal message handling. The user does not see these messages
320                 if (msg instanceof KeepaliveMessage) {
321                         // Do nothing, the timer has been already reset
322                 } else if (msg instanceof OpenMessage) {
323                         this.sendErrorMessage(PCEPErrors.ATTEMPT_2ND_SESSION);
324                 } else if (msg instanceof CloseMessage) {
325                         /*
326                          * Session is up, we are reporting all messages to user. One notable
327                          * exception is CLOSE message, which needs to be converted into a
328                          * session DOWN event.
329                          */
330                         this.close();
331                 } else {
332                         // This message needs to be handled by the user
333                         this.listener.onMessage(this, msg);
334                 }
335         }
336
337         /**
338          * @return the sentMsgCount
339          */
340
341         @Override
342         public final Integer getSentMsgCount() {
343                 return this.sentMsgCount;
344         }
345
346         /**
347          * @return the receivedMsgCount
348          */
349
350         @Override
351         public final Integer getReceivedMsgCount() {
352                 return this.receivedMsgCount;
353         }
354
355         @Override
356         public final Integer getDeadTimerValue() {
357                 return Integer.valueOf(this.remoteOpen.getDeadTimer());
358         }
359
360         @Override
361         public final Integer getKeepAliveTimerValue() {
362                 return Integer.valueOf(this.localOpen.getKeepalive());
363         }
364
365         @Override
366         public final String getPeerAddress() {
367                 final InetSocketAddress a = (InetSocketAddress) this.channel.remoteAddress();
368                 return a.getHostName();
369         }
370
371         @Override
372         public void tearDown() {
373                 this.close();
374         }
375
376         @Override
377         public final String toString() {
378                 return addToStringAttributes(Objects.toStringHelper(this)).toString();
379         }
380
381         protected ToStringHelper addToStringAttributes(final ToStringHelper toStringHelper) {
382                 toStringHelper.add("channel", this.channel);
383                 toStringHelper.add("localOpen", this.localOpen);
384                 toStringHelper.add("remoteOpen", this.remoteOpen);
385                 return toStringHelper;
386         }
387
388         @Override
389         @VisibleForTesting
390         public void sessionUp() {
391                 this.listener.onSessionUp(this);
392         }
393
394         @Override
395         public String getNodeIdentifier() {
396                 return "";
397         }
398 }