v0.2.54..v0.2.55 changeset UnifyingConflator.cpp

diff --git a/hoot-core/src/main/cpp/hoot/core/conflate/UnifyingConflator.cpp b/hoot-core/src/main/cpp/hoot/core/conflate/UnifyingConflator.cpp
index 25f233f..61d3bed 100644
--- a/hoot-core/src/main/cpp/hoot/core/conflate/UnifyingConflator.cpp
+++ b/hoot-core/src/main/cpp/hoot/core/conflate/UnifyingConflator.cpp
@@ -45,8 +45,8 @@
 #include <hoot/core/util/Log.h>
 #include <hoot/core/util/StringUtils.h>
 #include <hoot/core/criterion/NotCriterion.h>
-#include <hoot/core/criterion/ElementInIdListCriterion.h>
 #include <hoot/core/ops/CopyMapSubsetOp.h>
+#include <hoot/core/util/MemoryUsageChecker.h>
 
 // standard
 #include <algorithm>
@@ -56,6 +56,9 @@
 #include <tgs/System/Time.h>
 #include <tgs/System/Timer.h>
 
+// Qt
+#include <QElapsedTimer>
+
 using namespace std;
 using namespace Tgs;
 
@@ -168,9 +171,10 @@ void UnifyingConflator::apply(OsmMapPtr& map)
   {
     _matchFactory.createMatches(map, _matches, _bounds);
   }
-  LOG_DEBUG("Match count: " << _matches.size());
+  MemoryUsageChecker::getInstance().check();
+  LOG_DEBUG("Match count: " << StringUtils::formatLargeNumber(_matches.size()));
   LOG_VART(_matches);
-  LOG_TRACE(SystemInfo::getMemoryUsageString());
+  LOG_DEBUG(SystemInfo::getCurrentProcessMemoryUsageString());
   OsmMapWriterFactory::writeDebugMap(map, "after-matching");
 
   double findMatchesTime = timer.getElapsedAndRestart();
@@ -184,15 +188,18 @@ void UnifyingConflator::apply(OsmMapPtr& map)
   // add review tags to all matches that have some review component
   _addReviewTags(map, allMatches);
 
-  LOG_DEBUG("Pre-constraining match count: " << allMatches.size());
+  LOG_DEBUG("Pre-constraining match count: " << StringUtils::formatLargeNumber(allMatches.size()));
   _stats.append(SingleStat("Number of Matches Before Whole Groups", _matches.size()));
-  LOG_DEBUG("Number of Matches Before Whole Groups: " << _matches.size());
+  LOG_DEBUG(
+    "Number of Matches Before Whole Groups: " << StringUtils::formatLargeNumber(_matches.size()));
   // If there are groups of matches that should not be optimized, remove them before optimization.
   MatchSetVector matchSets;
   _removeWholeGroups(_matches, matchSets, map);
+  MemoryUsageChecker::getInstance().check();
   _stats.append(SingleStat("Number of Whole Groups", matchSets.size()));
-  LOG_DEBUG("Number of Whole Groups: " << matchSets.size());
-  LOG_DEBUG("Number of Matches After Whole Groups: " << _matches.size());
+  LOG_DEBUG("Number of Whole Groups: " << StringUtils::formatLargeNumber(matchSets.size()));
+  LOG_DEBUG(
+    "Number of Matches After Whole Groups: " << StringUtils::formatLargeNumber(_matches.size()));
   LOG_VART(_matches);
   OsmMapWriterFactory::writeDebugMap(map, "after-whole-group-removal");
 
@@ -218,15 +225,17 @@ void UnifyingConflator::apply(OsmMapPtr& map)
       {
         LOG_WARN(exp.what());
       }
+      MemoryUsageChecker::getInstance().check();
       LOG_TRACE("CM took: " << Time::getTime() - cmStart << "s.");
       LOG_DEBUG("CM Score: " << cm.getScore());
-      LOG_TRACE(SystemInfo::getMemoryUsageString());
+      LOG_DEBUG(SystemInfo::getCurrentProcessMemoryUsageString());
     }
 
     GreedyConstrainedMatches gm(map);
     gm.addMatches(_matches.begin(), _matches.end());
     double gmStart = Time::getTime();
     vector<ConstMatchPtr> gmMatches = gm.calculateSubset();
+    MemoryUsageChecker::getInstance().check();
     LOG_TRACE("GM took: " << Time::getTime() - gmStart << "s.");
     LOG_DEBUG("GM Score: " << gm.getScore());
 
@@ -249,9 +258,7 @@ void UnifyingConflator::apply(OsmMapPtr& map)
   _stats.append(SingleStat("Number of Optimized Matches", _matches.size()));
   _stats.append(SingleStat("Number of Matches Optimized per Second",
     (double)allMatches.size() / optimizeMatchesTime));
-  LOG_TRACE(SystemInfo::getMemoryUsageString());
-  //#warning validateConflictSubset is on, this is slow.
-  //_validateConflictSubset(map, _matches);
+  LOG_DEBUG(SystemInfo::getCurrentProcessMemoryUsageString());
   // TODO: this stat isn't right for Network
   LOG_DEBUG("Post constraining match count: " << _matches.size());
   LOG_VART(_matches);
@@ -264,7 +271,7 @@ void UnifyingConflator::apply(OsmMapPtr& map)
     mg.addMatches(_matches.begin(), _matches.end());
     vector<set<ConstMatchPtr, MatchPtrComparator>> tmpMatchSets = mg.findSubgraphs(map);
     matchSets.insert(matchSets.end(), tmpMatchSets.begin(), tmpMatchSets.end());
-    LOG_TRACE(SystemInfo::getMemoryUsageString());
+    LOG_DEBUG(SystemInfo::getCurrentProcessMemoryUsageString());
   }
   LOG_DEBUG("Match sets count: " << matchSets.size());
   OsmMapWriterFactory::writeDebugMap(map, "after-match-optimization-2");
@@ -286,31 +293,36 @@ void UnifyingConflator::apply(OsmMapPtr& map)
 
     _mergerFactory->createMergers(map, matchSets[i], _mergers);
 
-    LOG_DEBUG(
+    LOG_TRACE(
       "Converted match set " << StringUtils::formatLargeNumber(i + 1) << " to " <<
       StringUtils::formatLargeNumber(_mergers.size()) << " merger(s).")
   }
+  MemoryUsageChecker::getInstance().check();
   LOG_VART(_mergers.size());
 
-  LOG_TRACE(SystemInfo::getMemoryUsageString());
+  LOG_DEBUG(SystemInfo::getCurrentProcessMemoryUsageString());
   // don't need the matches any more
   allMatches.clear();
   _matches.clear();
 
-  LOG_TRACE(SystemInfo::getMemoryUsageString());
+  LOG_DEBUG(SystemInfo::getCurrentProcessMemoryUsageString());
   _mapElementIdsToMergers();
-  LOG_TRACE(SystemInfo::getMemoryUsageString());
+  LOG_DEBUG(SystemInfo::getCurrentProcessMemoryUsageString());
 
   _stats.append(SingleStat("Create Mergers Time (sec)", timer.getElapsedAndRestart()));
 
-  LOG_DEBUG("Applying " << StringUtils::formatLargeNumber(_mergers.size()) << " mergers...");
+  QElapsedTimer mergersTimer;
+  mergersTimer.start();
+
+  LOG_INFO("Applying " << StringUtils::formatLargeNumber(_mergers.size()) << " mergers...");
   vector<pair<ElementId, ElementId>> replaced;
   for (size_t i = 0; i < _mergers.size(); ++i)
   {
+    MergerPtr merger = _mergers[i];
     const QString msg =
-      "Applying merger: " + StringUtils::formatLargeNumber(i + 1) + " / " +
-      StringUtils::formatLargeNumber(_mergers.size());
-    if (i % 100 == 0)
+      "Applying merger: " + merger->getName() + " " + StringUtils::formatLargeNumber(i + 1) +
+      " / " + StringUtils::formatLargeNumber(_mergers.size());
+    if (i != 0 && i % 10 == 0)
     {
       PROGRESS_INFO(msg);
     }
@@ -319,7 +331,7 @@ void UnifyingConflator::apply(OsmMapPtr& map)
       LOG_TRACE(msg);
     }
 
-    _mergers[i]->apply(map, replaced);
+    merger->apply(map, replaced);
 
     LOG_VART(replaced);
     LOG_VART(map->size());
@@ -327,22 +339,32 @@ void UnifyingConflator::apply(OsmMapPtr& map)
     // update any mergers that reference the replaced values
     _replaceElementIds(replaced);
     replaced.clear();
+    LOG_VART(merger->getImpactedElementIds());
 
     // WARNING: Enabling this could result in a lot of files being generated.
-    //OsmMapWriterFactory::writeDebugMap(map, "after-merging-" + _mergers[i]->toString().right(50));
+    //if (i % 30 == 0)
+//    {
+//      OsmMapWriterFactory::writeDebugMap(
+//        map, "after-merge-" + merger->getName() + "-#" + StringUtils::formatLargeNumber(i + 1));
+//    }
   }
+  MemoryUsageChecker::getInstance().check();
   OsmMapWriterFactory::writeDebugMap(map, "after-merging");
 
-  LOG_TRACE(SystemInfo::getMemoryUsageString());
+  LOG_DEBUG(SystemInfo::getCurrentProcessMemoryUsageString());
   size_t mergerCount = _mergers.size();
   // free up any used resources.
   _reset();
-  LOG_TRACE(SystemInfo::getMemoryUsageString());
+  LOG_DEBUG(SystemInfo::getCurrentProcessMemoryUsageString());
 
   double mergersTime = timer.getElapsedAndRestart();
   _stats.append(SingleStat("Apply Mergers Time (sec)", mergersTime));
   _stats.append(SingleStat("Mergers Applied per Second", (double)mergerCount / mergersTime));
 
+  LOG_INFO(
+    "Applied " << StringUtils::formatLargeNumber(mergerCount) << " mergers in " <<
+    StringUtils::millisecondsToDhms(mergersTimer.elapsed()) << ".");
+
   currentStep++;
 }
 
@@ -469,23 +491,6 @@ void UnifyingConflator::_reset()
   _mergers.clear();
 }
 
-void UnifyingConflator::_validateConflictSubset(const ConstOsmMapPtr& map,
-                                                std::vector<ConstMatchPtr> matches)
-{
-  for (size_t i = 0; i < matches.size(); i++)
-  {
-    for (size_t j = 0; j < matches.size(); j++)
-    {
-      if (i < j && MergerFactory::getInstance().isConflicting(map, matches[i], matches[j]))
-      {
-        LOG_TRACE("Conflict");
-        LOG_TRACE(matches[i]->toString());
-        LOG_TRACE(matches[j]->toString());
-      }
-    }
-  }
-}
-
 void UnifyingConflator::_printMatches(std::vector<ConstMatchPtr> matches)
 {
   for (size_t i = 0; i < matches.size(); i++)