<pre style='margin:0'>
Clemens Lang (neverpanic) pushed a commit to branch master
in repository macports-base.

</pre>
<p><a href="https://github.com/macports/macports-base/commit/9577537835f6e039a1c91d31a34267e304c4bb2b">https://github.com/macports/macports-base/commit/9577537835f6e039a1c91d31a34267e304c4bb2b</a></p>
<pre style="white-space: pre; background: #F8F8F8"><span style='display:block; white-space:pre;color:#808000;'>commit 9577537835f6e039a1c91d31a34267e304c4bb2b
</span>Author: Clemens Lang <cal@macports.org>
AuthorDate: Thu Jan 20 00:57:48 2022 +0100

<span style='display:block; white-space:pre;color:#404040;'>    pextlib1.0: Cache trace lookup results for speed
</span><span style='display:block; white-space:pre;color:#404040;'>    
</span><span style='display:block; white-space:pre;color:#404040;'>    99% of all time spent in process_line() in tracelib.c happens in
</span><span style='display:block; white-space:pre;color:#404040;'>    dep_check(). In dep_check(), time is spent as follows:
</span><span style='display:block; white-space:pre;color:#404040;'>    
</span><span style='display:block; white-space:pre;color:#404040;'>    - 15-20 % is spent determining the filesystem's case sensitivity
</span><span style='display:block; white-space:pre;color:#404040;'>    - 50 % of the time is spent querying the port that provides the given
</span><span style='display:block; white-space:pre;color:#404040;'>      path
</span><span style='display:block; white-space:pre;color:#404040;'>    - 25 % of the time is used to translate the port ID into a port name
</span><span style='display:block; white-space:pre;color:#404040;'>    - ~8 % are in the binary search of the port name in the list of
</span><span style='display:block; white-space:pre;color:#404040;'>      dependencies
</span><span style='display:block; white-space:pre;color:#404040;'>    
</span><span style='display:block; white-space:pre;color:#404040;'>    In a test build of the yubico-pam port, 13884 iterations of dep_check()
</span><span style='display:block; white-space:pre;color:#404040;'>    were run. Among those, there are only a little more than 3000 unique
</span><span style='display:block; white-space:pre;color:#404040;'>    paths. This means that we can get a cache hit rate of about 78 % for
</span><span style='display:block; white-space:pre;color:#404040;'>    a cache that stores previous lookup results.
</span><span style='display:block; white-space:pre;color:#404040;'>    
</span><span style='display:block; white-space:pre;color:#404040;'>    This affects the time spent in dep_check() during a test build of
</span><span style='display:block; white-space:pre;color:#404040;'>    yubico-pam as follows (all numbers in return values of
</span><span style='display:block; white-space:pre;color:#404040;'>    mach_absolute_time()):
</span><span style='display:block; white-space:pre;color:#404040;'>    
</span><span style='display:block; white-space:pre;color:#404040;'>    without cache:
</span><span style='display:block; white-space:pre;color:#404040;'>      2131768084 total
</span><span style='display:block; white-space:pre;color:#404040;'>      14188 calls
</span><span style='display:block; white-space:pre;color:#404040;'>      ~ 150251 per call
</span><span style='display:block; white-space:pre;color:#404040;'>    with cache:
</span><span style='display:block; white-space:pre;color:#404040;'>      1054866053 total
</span><span style='display:block; white-space:pre;color:#404040;'>      14188 calls
</span><span style='display:block; white-space:pre;color:#404040;'>      ~ 74349 per call
</span><span style='display:block; white-space:pre;color:#404040;'>    
</span><span style='display:block; white-space:pre;color:#404040;'>    Caching thus reduces the duration by 50.5 %.
</span>---
 src/pextlib1.0/tracelib.c | 49 ++++++++++++++++++++++++++++++++++++++++++++---
 1 file changed, 46 insertions(+), 3 deletions(-)

<span style='display:block; white-space:pre;color:#808080;'>diff --git a/src/pextlib1.0/tracelib.c b/src/pextlib1.0/tracelib.c
</span><span style='display:block; white-space:pre;color:#808080;'>index fa96dfd69..b67d5a937 100644
</span><span style='display:block; white-space:pre;background:#e0e0ff;'>--- a/src/pextlib1.0/tracelib.c
</span><span style='display:block; white-space:pre;background:#e0e0ff;'>+++ b/src/pextlib1.0/tracelib.c
</span><span style='display:block; white-space:pre;background:#e0e0e0;'>@@ -113,6 +113,15 @@ static Tcl_Interp *interp;
</span> 
 static mount_cs_cache_t *mount_cs_cache;
 
<span style='display:block; white-space:pre;background:#e0ffe0;'>+typedef struct path_cache_value {
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+    char answer;
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+} path_cache_value_t;
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+/* Querying the SQLite database is surprisingly expensive. Cache all previous
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+ * lookups we've done in a hash map to avoid hitting the database multiple
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+ * times for the same entries. */
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+static Tcl_HashTable path_cache;
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+static bool path_cache_initialized = false;
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+
</span> /**
  * Mutex that shall be acquired to exclusively lock checking and acting upon
  * the value of kq, indicating whether the event loop has started. If it has
<span style='display:block; white-space:pre;background:#e0e0e0;'>@@ -611,13 +620,23 @@ static int pointer_strcmp(const char** a, const char** b) {
</span> static void dep_check(int sock, char *path) {
     char *port = 0;
     int fs_cs = -1;
<span style='display:block; white-space:pre;background:#e0ffe0;'>+    int is_new = 0;
</span>     reg_registry *reg;
     reg_entry entry;
     reg_error error;
 
<span style='display:block; white-space:pre;background:#e0ffe0;'>+    Tcl_HashEntry *cache_entry = Tcl_FindHashEntry(&path_cache, path);
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+    if (cache_entry) {
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        const char* cache_value = Tcl_GetHashValue(cache_entry);
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        if (cache_value != NULL) {
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+            answer(sock, cache_value);
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+            return;
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        }
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+    }
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+
</span>     if (NULL == (reg = registry_for(interp, reg_attached))) {
         ui_error(interp, "%s", Tcl_GetStringResult(interp));
<span style='display:block; white-space:pre;background:#ffe0e0;'>-        /* send unexpected output to make the build fail */
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        /* send unexpected output to make the build fail; do not cache */
</span>         answer(sock, "#");
     }
 
<span style='display:block; white-space:pre;background:#e0e0e0;'>@@ -642,14 +661,17 @@ static void dep_check(int sock, char *path) {
</span>     entry.proc = NULL;
     entry.id = reg_entry_owner_id(reg, path, fs_cs);
     if (entry.id == 0) {
<span style='display:block; white-space:pre;background:#ffe0e0;'>-        /* file isn't known to MacPorts */
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        /* file isn't known to MacPorts, cache this result */
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        Tcl_HashEntry *cache_entry = Tcl_CreateHashEntry(&path_cache, path, &is_new);
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        Tcl_SetHashValue(cache_entry, "?");
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+
</span>         answer(sock, "?");
         return;
     }
 
     /* find the port's name to compare with out list */
     if (!reg_entry_propget(&entry, "name", &port, &error)) {
<span style='display:block; white-space:pre;background:#ffe0e0;'>-        /* send unexpected output to make the build fail */
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        /* send unexpected output to make the build fail, but do not cache this result */
</span>         ui_error(interp, "%s", error.description);
         answer(sock, "#");
     }
<span style='display:block; white-space:pre;background:#e0e0e0;'>@@ -658,9 +680,17 @@ static void dep_check(int sock, char *path) {
</span>     if (NULL != bsearch(&port, depends, dependsLength, sizeof(*depends),
                         (int (*)(const void*, const void*)) pointer_strcmp)) {
         free(port);
<span style='display:block; white-space:pre;background:#e0ffe0;'>+        /* access granted, cache this result */
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        Tcl_HashEntry *cache_entry = Tcl_CreateHashEntry(&path_cache, path, &is_new);
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        Tcl_SetHashValue(cache_entry, "+");
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+
</span>         answer(sock, "+");
     } else {
         free(port);
<span style='display:block; white-space:pre;background:#e0ffe0;'>+        /* access denied, cache this result */
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        Tcl_HashEntry *cache_entry = Tcl_CreateHashEntry(&path_cache, path, &is_new);
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        Tcl_SetHashValue(cache_entry, "!");
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+
</span>         answer(sock, "!");
     }
 }
<span style='display:block; white-space:pre;background:#e0e0e0;'>@@ -739,6 +769,13 @@ static int TracelibRunCmd(Tcl_Interp *in) {
</span>         mount_cs_cache = new_mount_cs_cache();
     }
 
<span style='display:block; white-space:pre;background:#e0ffe0;'>+    /* (Re-)initialize path cache */
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+    if (path_cache_initialized) {
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        Tcl_DeleteHashTable(&path_cache);
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+    }
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+    Tcl_InitHashTable(&path_cache, TCL_STRING_KEYS);
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+    path_cache_initialized = true;
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+
</span>     pthread_mutex_lock(&evloop_mutex);
     /* bring all variables into a defined state so the cleanup code can be
      * called from anywhere */
<span style='display:block; white-space:pre;background:#e0e0e0;'>@@ -952,6 +989,12 @@ error_locked:
</span>         mount_cs_cache = NULL;
     }
 
<span style='display:block; white-space:pre;background:#e0ffe0;'>+    /* Free path cache. */
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+    if (path_cache_initialized) {
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        Tcl_DeleteHashTable(&path_cache);
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+        path_cache_initialized = false;
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+    }
</span><span style='display:block; white-space:pre;background:#e0ffe0;'>+
</span>     return retval;
 }
 
</pre><pre style='margin:0'>

</pre>