upnp: refactor to improve handling of port mappings renewal

The two main changes are:

1) Renewal requests are now sent for both UPnP and NAT-PMP mappings, not
   just NAT-PMP. The old code asked for an infinite lifetime when
   creating UPnP mappings and assumed that it got it, but this is not a
   safe assumption. (See GitLab issue below for more information.)

2) The updateMappingList function was removed. This function used to be
   called every 30 seconds to handle a bunch of unrelated tasks (one of
   which was renewing port mappings) and generated mostly unnecessary
   network traffic every time when using UPnP (because of the call to
   pruneMappingList). These tasks are now performed separately instead
   of being bundled together, and only when needed (either based on a
   timer or on certain events occuring, depending on the task).

GitLab: #31
Change-Id: Id0f60ddb76fb8eb4517eadbb971892d125cebfc7
diff --git a/src/upnp/protocol/mapping.cpp b/src/upnp/protocol/mapping.cpp
index 846553f..fa9b6c7 100644
--- a/src/upnp/protocol/mapping.cpp
+++ b/src/upnp/protocol/mapping.cpp
@@ -33,9 +33,7 @@
     , state_(MappingState::PENDING)
     , notifyCb_(nullptr)
     , autoUpdate_(false)
-#if HAVE_LIBNATPMP
-    , renewalTime_(sys_clock::now())
-#endif
+    , renewalTime_(sys_clock::time_point::max())
 {}
 
 Mapping::Mapping(const Mapping& other)
@@ -51,9 +49,8 @@
     state_ = other.state_;
     notifyCb_ = other.notifyCb_;
     autoUpdate_ = other.autoUpdate_;
-#if HAVE_LIBNATPMP
     renewalTime_ = other.renewalTime_;
-#endif
+    expiryTime_ = other.expiryTime_;
 }
 
 void
@@ -326,7 +323,6 @@
     return autoUpdate_;
 }
 
-#if HAVE_LIBNATPMP
 sys_clock::time_point
 Mapping::getRenewalTime() const
 {
@@ -340,7 +336,20 @@
     std::lock_guard lock(mutex_);
     renewalTime_ = time;
 }
-#endif
+
+sys_clock::time_point
+Mapping::getExpiryTime() const
+{
+    std::lock_guard lock(mutex_);
+    return expiryTime_;
+}
+
+void
+Mapping::setExpiryTime(sys_clock::time_point time)
+{
+    std::lock_guard lock(mutex_);
+    expiryTime_ = time;
+}
 
 } // namespace upnp
 } // namespace dhtnet
diff --git a/src/upnp/protocol/natpmp/nat_pmp.cpp b/src/upnp/protocol/natpmp/nat_pmp.cpp
index 9d306bf..3c17e09 100644
--- a/src/upnp/protocol/natpmp/nat_pmp.cpp
+++ b/src/upnp/protocol/natpmp/nat_pmp.cpp
@@ -262,16 +262,6 @@
 void
 NatPmp::requestMappingAdd(const Mapping& mapping)
 {
-    // Process on nat-pmp thread.
-    /*if (not isValidThread()) {
-        ioContext->post([w = weak(), mapping] {
-            if (auto pmpThis = w.lock()) {
-                pmpThis->requestMappingAdd(mapping);
-            }
-        });
-        return;
-    }*/
-
     Mapping map(mapping);
     assert(map.getIgd());
     auto err = addPortMapping(map);
@@ -300,22 +290,12 @@
 void
 NatPmp::requestMappingRenew(const Mapping& mapping)
 {
-    // Process on nat-pmp thread.
-    /*if (not isValidThread()) {
-        ioContext->post([w = weak(), mapping] {
-            if (auto pmpThis = w.lock()) {
-                pmpThis->requestMappingRenew(mapping);
-            }
-        });
-        return;
-    }*/
-
     Mapping map(mapping);
     auto err = addPortMapping(map);
     if (err < 0) {
         if (logger_) logger_->warn("NAT-PMP: Renewal request for mapping {} on {} failed with error {:d}: {}",
-                  map.toString().c_str(),
-                  igd_->toString().c_str(),
+                  map.toString(),
+                  igd_->toString(),
                   err,
                   getNatPmpErrorStr(err));
         // Notify the listener.
@@ -327,8 +307,8 @@
         }
     } else {
         if (logger_) logger_->debug("NAT-PMP: Renewal request for mapping {} on {} succeeded",
-                 map.toString().c_str(),
-                 igd_->toString().c_str());
+                 map.toString(),
+                 igd_->toString());
         // Notify the listener.
         processMappingRenewed(map);
     }
@@ -376,10 +356,8 @@
 }
 
 int
-NatPmp::sendMappingRequest(const Mapping& mapping, uint32_t& lifetime)
+NatPmp::sendMappingRequest(Mapping& mapping, uint32_t& lifetime)
 {
-    //CHECK_VALID_THREAD();
-
     int err = sendnewportmappingrequest(&natpmpHdl_,
                                         mapping.getType() == PortType::UDP ? NATPMP_PROTOCOL_UDP
                                                                            : NATPMP_PROTOCOL_TCP,
@@ -415,9 +393,24 @@
             continue;
         }
 
-        lifetime = response.pnu.newportmapping.lifetime;
-        // Done.
-        break;
+        uint16_t newExternalPort = response.pnu.newportmapping.mappedpublicport;
+        uint32_t newLifetime = response.pnu.newportmapping.lifetime;
+        if (lifetime > 0) {
+            // We requested the creation/renewal of a mapping and didn't get an error, so at this point
+            // newExternalPort and newLifetime should both be nonzero. However, that's not always the case
+            // in practice (presumably because some routers don't implement NAT-PMP correctly).
+            if (newExternalPort == 0 || newLifetime == 0) {
+                if (logger_) logger_->warn("NAT-PMP: mapping request returned without error but the response"
+                                           " contains invalid data (external port: {}, lifetime: {})",
+                                           newExternalPort,
+                                           newLifetime);
+                err = NATPMP_ERR_INVALIDARGS;
+            } else {
+                lifetime = newLifetime;
+                mapping.setExternalPort(newExternalPort);
+            }
+        }
+       break;
     }
 
     return err;
@@ -446,7 +439,7 @@
     }
 
     // Set the renewal time and update.
-    mapping.setRenewalTime(sys_clock::now() + std::chrono::seconds(lifetime * 4 / 5));
+    mapping.setRenewalTime(sys_clock::now() + std::chrono::seconds(lifetime / 2));
     mapping.setState(MappingState::OPEN);
 
     return 0;
@@ -495,8 +488,6 @@
 void
 NatPmp::getIgdPublicAddress()
 {
-    //CHECK_VALID_THREAD();
-
     // Set the public address for this IGD if it does not
     // have one already.
     if (igd_->getPublicIp()) {
@@ -558,8 +549,6 @@
 void
 NatPmp::removeAllMappings()
 {
-    //CHECK_VALID_THREAD();
-
     if (logger_) logger_->warn("NAT-PMP: Send request to close all existing mappings to IGD {}",
               igd_->toString().c_str());
 
diff --git a/src/upnp/protocol/natpmp/nat_pmp.h b/src/upnp/protocol/natpmp/nat_pmp.h
index fbc2fc0..5102533 100644
--- a/src/upnp/protocol/natpmp/nat_pmp.h
+++ b/src/upnp/protocol/natpmp/nat_pmp.h
@@ -36,7 +36,7 @@
 namespace upnp {
 
 // Requested lifetime in seconds. The actual lifetime might be different.
-constexpr static unsigned int MAPPING_ALLOCATION_LIFETIME {60 * 60};
+constexpr static unsigned int MAPPING_ALLOCATION_LIFETIME {7200};
 // Max number of IGD search attempts before failure.
 constexpr static unsigned int MAX_RESTART_SEARCH_RETRIES {3};
 // Time-out between two successive read response.
@@ -101,7 +101,7 @@
     void getIgdPublicAddress();
     void removeAllMappings();
     int readResponse(natpmp_t& handle, natpmpresp_t& response);
-    int sendMappingRequest(const Mapping& mapping, uint32_t& lifetime);
+    int sendMappingRequest(Mapping& mapping, uint32_t& lifetime);
 
     // Adds a port mapping.
     int addPortMapping(Mapping& mapping);
diff --git a/src/upnp/protocol/pupnp/pupnp.cpp b/src/upnp/protocol/pupnp/pupnp.cpp
index dbb05f1..1df8219 100644
--- a/src/upnp/protocol/pupnp/pupnp.cpp
+++ b/src/upnp/protocol/pupnp/pupnp.cpp
@@ -442,7 +442,7 @@
              "    Service ID   : {}\n"
              "    Base URL     : {}\n"
              "    Location URL : {}\n"
-             "    control URL  : {}\n"
+             "    Control URL  : {}\n"
              "    Event URL    : {}",
              igd_candidate->getUID(),
              igd_candidate->getFriendlyName(),
@@ -556,6 +556,9 @@
                 return;
             Mapping mapRes(mapping);
             if (upnpThis->actionAddPortMapping(mapRes)) {
+                auto now = sys_clock::now();
+                mapRes.setRenewalTime(now + std::chrono::seconds(MAPPING_LEASE_DURATION / 2));
+                mapRes.setExpiryTime(now + std::chrono::seconds(MAPPING_LEASE_DURATION));
                 mapRes.setState(MappingState::OPEN);
                 mapRes.setInternalAddress(upnpThis->getHostAddress().toString());
                 upnpThis->processAddMapAction(mapRes);
@@ -569,6 +572,38 @@
 }
 
 void
+PUPnP::requestMappingRenew(const Mapping& mapping)
+{
+    ioContext->post([w = weak(), mapping] {
+        if (auto upnpThis = w.lock()) {
+            if (not upnpThis->isRunning())
+                return;
+            Mapping mapRes(mapping);
+            if (upnpThis->actionAddPortMapping(mapRes)) {
+                if (upnpThis->logger_)
+                    upnpThis->logger_->debug("PUPnP: Renewal request for mapping {} on {} succeeded",
+                                             mapRes.toString(),
+                                             mapRes.getIgd()->toString());
+                auto now = sys_clock::now();
+                mapRes.setRenewalTime(now + std::chrono::seconds(MAPPING_LEASE_DURATION / 2));
+                mapRes.setExpiryTime(now + std::chrono::seconds(MAPPING_LEASE_DURATION));
+                mapRes.setState(MappingState::OPEN);
+                mapRes.setInternalAddress(upnpThis->getHostAddress().toString());
+                upnpThis->processMappingRenewed(mapRes);
+            } else {
+                if (upnpThis->logger_)
+                    upnpThis->logger_->debug("PUPnP: Renewal request for mapping {} on {} failed",
+                                             mapRes.toString(),
+                                             mapRes.getIgd()->toString());
+                upnpThis->incrementErrorsCounter(mapRes.getIgd());
+                mapRes.setState(MappingState::FAILED);
+                upnpThis->processRequestMappingFailure(mapRes);
+            }
+        }
+    });
+}
+
+void
 PUPnP::requestMappingRemove(const Mapping& mapping)
 {
     // Send remove request using the matching IGD
@@ -625,6 +660,20 @@
 }
 
 void
+PUPnP::processMappingRenewed(const Mapping& map)
+{
+    if (observer_ == nullptr)
+        return;
+
+    ioContext->post([w = weak(), map] {
+        if (auto upnpThis = w.lock()) {
+            if (upnpThis->observer_)
+                upnpThis->observer_->onMappingRenewed(map.getIgd(), std::move(map));
+        }
+    });
+}
+
+void
 PUPnP::processRequestMappingFailure(const Mapping& map)
 {
     if (observer_ == nullptr)
@@ -632,8 +681,6 @@
 
     ioContext->post([w = weak(), map] {
         if (auto upnpThis = w.lock()) {
-            if (upnpThis->logger_) upnpThis->logger_->debug("PUPnP: Closed mapping {}", map.toString());
-            // JAMI_DBG("PUPnP: Failed to request mapping %s", map.toString().c_str());
             if (upnpThis->observer_)
                 upnpThis->observer_->onMappingRequestFailed(map);
         }
@@ -1278,6 +1325,7 @@
             break;
         }
 
+        auto timeIgdRequestSent = sys_clock::now();
         int upnp_err = UpnpSendAction(ctrlptHandle_,
                                       upnpIgd->getControlURL().c_str(),
                                       upnpIgd->getServiceType().c_str(),
@@ -1330,8 +1378,7 @@
         std::string transport(getFirstDocItem(response.get(), "NewProtocol"));
 
         if (port_internal.empty() || port_external.empty() || transport.empty()) {
-            // if (logger_) logger_->e("PUPnP: GetGenericPortMappingEntry returned an invalid entry at index %i",
-            //          entry_idx);
+            // Invalid entry, ignore
             continue;
         }
 
@@ -1340,8 +1387,14 @@
         auto ePort = to_int<uint16_t>(port_external);
         auto iPort = to_int<uint16_t>(port_internal);
 
+        auto leaseDurationStr = getFirstDocItem(response.get(), "NewLeaseDuration");
+        auto leaseDuration = to_int<uint32_t>(leaseDurationStr);
+        auto expiryTime = (leaseDuration == 0) ? sys_clock::time_point::max()
+                                               : timeIgdRequestSent + std::chrono::seconds(leaseDuration);
+
         Mapping map(type, ePort, iPort);
         map.setIgd(igd);
+        map.setExpiryTime(expiryTime);
 
         mapList.emplace(map.getMapKey(), std::move(map));
     }
@@ -1514,7 +1567,7 @@
                     ACTION_ADD_PORT_MAPPING,
                     igd->getServiceType().c_str(),
                     "NewLeaseDuration",
-                    "0");
+                    std::to_string(MAPPING_LEASE_DURATION).c_str());
 
     action.reset(action_container_ptr);
 
diff --git a/src/upnp/protocol/pupnp/pupnp.h b/src/upnp/protocol/pupnp/pupnp.h
index e29e01d..32fe19a 100644
--- a/src/upnp/protocol/pupnp/pupnp.h
+++ b/src/upnp/protocol/pupnp/pupnp.h
@@ -51,6 +51,8 @@
 namespace dhtnet {
 namespace upnp {
 
+constexpr static unsigned int MAPPING_LEASE_DURATION {604800};
+
 class PUPnP : public UPnPProtocol
 {
 public:
@@ -100,8 +102,7 @@
     void requestMappingAdd(const Mapping& mapping) override;
 
     // Renew an allocated mapping.
-    // Not implemented. Currently, UPNP allocations do not have expiration time.
-    void requestMappingRenew([[maybe_unused]] const Mapping& mapping) override { assert(false); };
+    void requestMappingRenew(const Mapping& mapping) override;
 
     // Removes a mapping.
     void requestMappingRemove(const Mapping& igdMapping) override;
@@ -153,6 +154,9 @@
     // Process the reception of an add mapping action answer.
     void processAddMapAction(const Mapping& map);
 
+    // Called after a successful mapping renewal
+    void processMappingRenewed(const Mapping& map);
+
     // Process the a mapping request failure.
     void processRequestMappingFailure(const Mapping& map);