face: implement close-on-idle and persistency change for Ethernet unicast

Change-Id: I255024990a72b8cea5a44fa89f515ad91aadba66
Refs: #4011
diff --git a/daemon/face/datagram-transport.hpp b/daemon/face/datagram-transport.hpp
index 2f76353..982e1f4 100644
--- a/daemon/face/datagram-transport.hpp
+++ b/daemon/face/datagram-transport.hpp
@@ -1,6 +1,6 @@
 /* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
 /**
- * Copyright (c) 2014-2016,  Regents of the University of California,
+ * Copyright (c) 2014-2017,  Regents of the University of California,
  *                           Arizona Board of Regents,
  *                           Colorado State University,
  *                           University Pierre & Marie Curie, Sorbonne University,
@@ -61,10 +61,10 @@
                   const boost::system::error_code& error);
 
 protected:
-  virtual void
+  void
   doClose() override;
 
-  virtual void
+  void
   doSend(Transport::Packet&& packet) override;
 
   void
@@ -152,13 +152,13 @@
   if (error)
     return processErrorCode(error);
 
-  NFD_LOG_FACE_TRACE("Received: " << nBytesReceived << " bytes");
+  NFD_LOG_FACE_TRACE("Received: " << nBytesReceived << " bytes from " << m_sender);
 
   bool isOk = false;
   Block element;
   std::tie(isOk, element) = Block::fromBuffer(buffer, nBytesReceived);
   if (!isOk) {
-    NFD_LOG_FACE_WARN("Failed to parse incoming packet");
+    NFD_LOG_FACE_WARN("Failed to parse incoming packet from " << m_sender);
     // This packet won't extend the face lifetime
     return;
   }
@@ -209,38 +209,37 @@
   if (getState() == TransportState::CLOSING ||
       getState() == TransportState::FAILED ||
       getState() == TransportState::CLOSED ||
-      error == boost::asio::error::operation_aborted)
+      error == boost::asio::error::operation_aborted) {
     // transport is shutting down, ignore any errors
     return;
+  }
 
-  if (getPersistency() == ndn::nfd::FacePersistency::FACE_PERSISTENCY_PERMANENT) {
+  if (getPersistency() == ndn::nfd::FACE_PERSISTENCY_PERMANENT) {
     NFD_LOG_FACE_DEBUG("Permanent face ignores error: " << error.message());
     return;
   }
 
-  if (error != boost::asio::error::eof)
-    NFD_LOG_FACE_WARN("Send or receive operation failed: " << error.message());
-
+  NFD_LOG_FACE_ERROR("Send or receive operation failed: " << error.message());
   this->setState(TransportState::FAILED);
   doClose();
 }
 
 template<class T, class U>
-inline bool
+bool
 DatagramTransport<T, U>::hasBeenUsedRecently() const
 {
   return m_hasBeenUsedRecently;
 }
 
 template<class T, class U>
-inline void
+void
 DatagramTransport<T, U>::resetRecentUsage()
 {
   m_hasBeenUsedRecently = false;
 }
 
 template<class T, class U>
-inline Transport::EndpointId
+Transport::EndpointId
 DatagramTransport<T, U>::makeEndpointId(const typename protocol::endpoint& ep)
 {
   return 0;
diff --git a/daemon/face/ethernet-transport.cpp b/daemon/face/ethernet-transport.cpp
index 9f6d465..a4c4006 100644
--- a/daemon/face/ethernet-transport.cpp
+++ b/daemon/face/ethernet-transport.cpp
@@ -47,6 +47,7 @@
   , m_srcAddress(localEndpoint.etherAddress)
   , m_destAddress(remoteEndpoint)
   , m_interfaceName(localEndpoint.name)
+  , m_hasBeenUsedRecently(false)
 #ifdef _DEBUG
   , m_nDropped(0)
 #endif
@@ -114,9 +115,10 @@
   // send the frame
   int sent = pcap_inject(m_pcap, buffer.buf(), buffer.size());
   if (sent < 0)
-    NFD_LOG_FACE_ERROR("pcap_inject failed: " << m_pcap.getLastError());
+    handleError("Send operation failed: " + m_pcap.getLastError());
   else if (static_cast<size_t>(sent) < buffer.size())
-    NFD_LOG_FACE_ERROR("Failed to send the full frame: size=" << buffer.size() << " sent=" << sent);
+    handleError("Failed to send the full frame: size=" + to_string(buffer.size()) +
+                " sent=" + to_string(sent));
   else
     // print block size because we don't want to count the padding in buffer
     NFD_LOG_FACE_TRACE("Successfully sent: " << block.size() << " bytes");
@@ -133,8 +135,17 @@
 void
 EthernetTransport::handleRead(const boost::system::error_code& error)
 {
-  if (error)
-    return processErrorCode(error);
+  if (error) {
+    // boost::asio::error::operation_aborted must be checked first: in that case, the Transport
+    // may already have been destructed, therefore it's unsafe to call getState() or do logging.
+    if (error != boost::asio::error::operation_aborted &&
+        getState() != TransportState::CLOSING &&
+        getState() != TransportState::FAILED &&
+        getState() != TransportState::CLOSED) {
+      handleError("Receive operation failed: " + error.message());
+    }
+    return;
+  }
 
   const uint8_t* pkt;
   size_t len;
@@ -142,14 +153,14 @@
   std::tie(pkt, len, err) = m_pcap.readNextPacket();
 
   if (pkt == nullptr) {
-    NFD_LOG_FACE_ERROR("Read error: " << err);
+    NFD_LOG_FACE_WARN("Read error: " << err);
   }
   else {
     const ether_header* eh;
     std::tie(eh, err) = ethernet::checkFrameHeader(pkt, len, m_srcAddress,
                                                    m_destAddress.isMulticast() ? m_destAddress : m_srcAddress);
     if (eh == nullptr) {
-      NFD_LOG_FACE_DEBUG(err);
+      NFD_LOG_FACE_WARN(err);
     }
     else {
       ethernet::Address sender(eh->ether_shost);
@@ -173,15 +184,17 @@
 EthernetTransport::receivePayload(const uint8_t* payload, size_t length,
                                   const ethernet::Address& sender)
 {
+  NFD_LOG_FACE_TRACE("Received: " << length << " bytes from " << sender);
+
   bool isOk = false;
   Block element;
   std::tie(isOk, element) = Block::fromBuffer(payload, length);
   if (!isOk) {
-    NFD_LOG_FACE_WARN("Received invalid packet from " << sender);
+    NFD_LOG_FACE_WARN("Failed to parse incoming packet from " << sender);
+    // This packet won't extend the face lifetime
     return;
   }
-
-  NFD_LOG_FACE_TRACE("Received: " << element.size() << " bytes from " << sender);
+  m_hasBeenUsedRecently = true;
 
   Transport::Packet tp(std::move(element));
   static_assert(sizeof(tp.remoteEndpoint) >= ethernet::ADDR_LEN,
@@ -193,19 +206,16 @@
 }
 
 void
-EthernetTransport::processErrorCode(const boost::system::error_code& error)
+EthernetTransport::handleError(const std::string& errorMessage)
 {
-  // boost::asio::error::operation_aborted must be checked first. In that situation, the Transport
-  // may already have been destructed, and it's unsafe to call getState() or do logging.
-  if (error == boost::asio::error::operation_aborted ||
-      getState() == TransportState::CLOSING ||
-      getState() == TransportState::FAILED ||
-      getState() == TransportState::CLOSED) {
-    // transport is shutting down, ignore any errors
+  if (getPersistency() == ndn::nfd::FACE_PERSISTENCY_PERMANENT) {
+    NFD_LOG_FACE_DEBUG("Permanent face ignores error: " << errorMessage);
     return;
   }
 
-  NFD_LOG_FACE_WARN("Receive operation failed: " << error.message());
+  NFD_LOG_FACE_ERROR(errorMessage);
+  this->setState(TransportState::FAILED);
+  doClose();
 }
 
 int
diff --git a/daemon/face/ethernet-transport.hpp b/daemon/face/ethernet-transport.hpp
index 575ea72..6dcad18 100644
--- a/daemon/face/ethernet-transport.hpp
+++ b/daemon/face/ethernet-transport.hpp
@@ -66,6 +66,18 @@
   void
   doClose() final;
 
+  bool
+  hasBeenUsedRecently() const
+  {
+    return m_hasBeenUsedRecently;
+  }
+
+  void
+  resetRecentUsage()
+  {
+    m_hasBeenUsedRecently = false;
+  }
+
 private:
   void
   doSend(Transport::Packet&& packet) final;
@@ -82,11 +94,8 @@
   void
   handleRead(const boost::system::error_code& error);
 
-  /**
-   * @brief Handles errors encountered by Boost.Asio on the receive path
-   */
   void
-  processErrorCode(const boost::system::error_code& error);
+  handleError(const std::string& errorMessage);
 
   /**
    * @brief Returns the MTU of the underlying network interface
@@ -102,6 +111,7 @@
   std::string m_interfaceName;
 
 private:
+  bool m_hasBeenUsedRecently;
 #ifdef _DEBUG
   /// number of frames dropped by the kernel, as reported by libpcap
   size_t m_nDropped;
diff --git a/daemon/face/stream-transport.hpp b/daemon/face/stream-transport.hpp
index 30e7a94..cba7c78 100644
--- a/daemon/face/stream-transport.hpp
+++ b/daemon/face/stream-transport.hpp
@@ -1,6 +1,6 @@
 /* -*- Mode:C++; c-file-style:"gnu"; indent-tabs-mode:nil; -*- */
 /**
- * Copyright (c) 2014-2016,  Regents of the University of California,
+ * Copyright (c) 2014-2017,  Regents of the University of California,
  *                           Arizona Board of Regents,
  *                           Colorado State University,
  *                           University Pierre & Marie Curie, Sorbonne University,
@@ -52,13 +52,13 @@
   StreamTransport(typename protocol::socket&& socket);
 
 protected:
-  virtual void
+  void
   doClose() override;
 
   void
   deferredClose();
 
-  virtual void
+  void
   doSend(Transport::Packet&& packet) override;
 
   void
@@ -124,9 +124,9 @@
 
   // Ensure that the Transport stays alive at least until
   // all pending handlers are dispatched
-  getGlobalIoService().post(bind(&StreamTransport<T>::deferredClose, this));
+  getGlobalIoService().post([this] { deferredClose(); });
 
-  // Some bug or feature of Boost.Asio (see http://redmine.named-data.net/issues/1856):
+  // Some bug or feature of Boost.Asio (see https://redmine.named-data.net/issues/1856):
   //
   // When doClose is called from a socket event handler (e.g., from handleReceive),
   // m_socket.shutdown() does not trigger the cancellation of the handleSend callback.
@@ -221,12 +221,10 @@
   NFD_LOG_FACE_TRACE("Received: " << nBytesReceived << " bytes");
 
   m_receiveBufferSize += nBytesReceived;
-
   size_t offset = 0;
-
   bool isOk = true;
-  Block element;
   while (m_receiveBufferSize - offset > 0) {
+    Block element;
     std::tie(isOk, element) = Block::fromBuffer(m_receiveBuffer + offset, m_receiveBufferSize - offset);
     if (!isOk)
       break;
@@ -238,7 +236,7 @@
   }
 
   if (!isOk && m_receiveBufferSize == ndn::MAX_NDN_PACKET_SIZE && offset == 0) {
-    NFD_LOG_FACE_WARN("Failed to parse incoming packet or packet too large to process");
+    NFD_LOG_FACE_ERROR("Failed to parse incoming packet or packet too large to process");
     this->setState(TransportState::FAILED);
     doClose();
     return;
@@ -279,7 +277,7 @@
 StreamTransport<T>::handleError(const boost::system::error_code& error)
 {
   if (error != boost::asio::error::eof)
-    NFD_LOG_FACE_WARN("Send or receive operation failed: " << error.message());
+    NFD_LOG_FACE_ERROR("Send or receive operation failed: " << error.message());
 
   this->setState(TransportState::FAILED);
   doClose();
diff --git a/daemon/face/unicast-ethernet-transport.cpp b/daemon/face/unicast-ethernet-transport.cpp
index eb34648..05bab28 100644
--- a/daemon/face/unicast-ethernet-transport.cpp
+++ b/daemon/face/unicast-ethernet-transport.cpp
@@ -59,7 +59,45 @@
            m_srcAddress.toString().data());
   m_pcap.setPacketFilter(filter);
 
-  // TODO: implement close on idle and persistency change
+  if (getPersistency() == ndn::nfd::FACE_PERSISTENCY_ON_DEMAND &&
+      m_idleTimeout > time::nanoseconds::zero()) {
+    scheduleClosureWhenIdle();
+  }
+}
+
+bool
+UnicastEthernetTransport::canChangePersistencyToImpl(ndn::nfd::FacePersistency newPersistency) const
+{
+  return true;
+}
+
+void
+UnicastEthernetTransport::afterChangePersistency(ndn::nfd::FacePersistency oldPersistency)
+{
+  if (getPersistency() == ndn::nfd::FACE_PERSISTENCY_ON_DEMAND &&
+      m_idleTimeout > time::nanoseconds::zero()) {
+    scheduleClosureWhenIdle();
+  }
+  else {
+    m_closeIfIdleEvent.cancel();
+    setExpirationTime(time::steady_clock::TimePoint::max());
+  }
+}
+
+void
+UnicastEthernetTransport::scheduleClosureWhenIdle()
+{
+  m_closeIfIdleEvent = scheduler::schedule(m_idleTimeout, [this] {
+    if (!hasBeenUsedRecently()) {
+      NFD_LOG_FACE_INFO("Closing due to inactivity");
+      this->close();
+    }
+    else {
+      resetRecentUsage();
+      scheduleClosureWhenIdle();
+    }
+  });
+  setExpirationTime(time::steady_clock::now() + m_idleTimeout);
 }
 
 } // namespace face
diff --git a/daemon/face/unicast-ethernet-transport.hpp b/daemon/face/unicast-ethernet-transport.hpp
index b1a856b..d85dfc7 100644
--- a/daemon/face/unicast-ethernet-transport.hpp
+++ b/daemon/face/unicast-ethernet-transport.hpp
@@ -27,6 +27,7 @@
 #define NFD_DAEMON_FACE_UNICAST_ETHERNET_TRANSPORT_HPP
 
 #include "ethernet-transport.hpp"
+#include "core/scheduler.hpp"
 
 namespace nfd {
 namespace face {
@@ -45,8 +46,20 @@
                            ndn::nfd::FacePersistency persistency,
                            time::nanoseconds idleTimeout);
 
+protected:
+  bool
+  canChangePersistencyToImpl(ndn::nfd::FacePersistency newPersistency) const final;
+
+  void
+  afterChangePersistency(ndn::nfd::FacePersistency oldPersistency) final;
+
+private:
+  void
+  scheduleClosureWhenIdle();
+
 private:
   const time::nanoseconds m_idleTimeout;
+  scheduler::ScopedEventId m_closeIfIdleEvent;
 };
 
 } // namespace face
diff --git a/daemon/face/websocket-transport.cpp b/daemon/face/websocket-transport.cpp
index 68fd08a..d4bbbac 100644
--- a/daemon/face/websocket-transport.cpp
+++ b/daemon/face/websocket-transport.cpp
@@ -117,13 +117,13 @@
 {
   NFD_LOG_FACE_TRACE(__func__);
 
-  ++this->nOutPings;
-
   websocketpp::lib::error_code error;
   m_server.ping(m_handle, "NFD-WebSocket", error);
   if (error)
     return processErrorCode(error);
 
+  ++this->nOutPings;
+
   this->schedulePing();
 }
 
@@ -138,7 +138,7 @@
 void
 WebSocketTransport::handlePongTimeout()
 {
-  NFD_LOG_FACE_WARN(__func__);
+  NFD_LOG_FACE_ERROR("Pong timeout");
   this->setState(TransportState::FAILED);
   doClose();
 }
@@ -154,8 +154,7 @@
     // transport is shutting down, ignore any errors
     return;
 
-  NFD_LOG_FACE_WARN("Send or ping operation failed: " << error.message());
-
+  NFD_LOG_FACE_ERROR("Send or ping operation failed: " << error.message());
   this->setState(TransportState::FAILED);
   doClose();
 }