]> git.ipfire.org Git - thirdparty/squid.git/commitdiff
ext_time_quota_acl: convert to c++ (#1847)
authorFrancesco Chemolli <5175948+kinkie@users.noreply.github.com>
Tue, 13 Aug 2024 00:32:44 +0000 (00:32 +0000)
committerSquid Anubis <squid-anubis@squid-cache.org>
Tue, 13 Aug 2024 00:45:08 +0000 (00:45 +0000)
Make use of dynamically-allocated strings
instead of static buffers, and convert debug output
to use Squid's Debug API

Inspired by addressing Coverity CID  1461163
"Invalid type in argument to printf format specifier"

doc/debug-sections.txt
src/Makefile.am
src/acl/external/time_quota/Makefile.am
src/acl/external/time_quota/ext_time_quota_acl.cc

index 4ef6627bc98c3fbed18769dbfdd29ec723727fab..892042ae2c73143ebc0b6e25235d1cb6f3402765 100644 (file)
@@ -130,6 +130,7 @@ section 80    WCCP Support
 section 81    Store HEAP Removal Policies
 section 81    aio_xxx() POSIX emulation on Windows
 section 82    External ACL
+section 82    External ACL Helpers
 section 83    SSL accelerator support
 section 83    SSL-Bump Server/Peer negotiation
 section 83    TLS I/O
index 3dca80df761fffba0ac105dcf3bc4aff43509da1..3058e6f5f08fa8d800168a825f6465b1994b7b88 100644 (file)
@@ -16,7 +16,8 @@ LOADABLE_MODULES_SOURCES = \
        LoadableModules.cc \
        LoadableModules.h
 
-SUBDIRS = mem time debug base anyp helper dns html ftp parser comm error eui acl format clients sbuf servers fs repl store DiskIO proxyp
+# subdir Y that requires a file built in subdir X must appear after X
+SUBDIRS = mem time debug base anyp helper dns html ftp parser comm error eui sbuf acl format clients servers fs repl store DiskIO proxyp
 
 if ENABLE_AUTH
 SUBDIRS += auth
index 21cec6a5ce47a74f31f97ca56ab917541f3a5b50..26eddb573cf16e365e7c7266f411c4054069e032 100644 (file)
@@ -14,7 +14,15 @@ DEFS += -DDEFAULT_QUOTA_DB=\"$(localstatedir)/ext_time_quota.db\"
 
 ext_time_quota_acl_SOURCES = \
        ext_time_quota_acl.cc
+
 ext_time_quota_acl_LDADD = \
+       $(top_builddir)/src/sbuf/libsbuf.la \
+       $(top_builddir)/src/debug/libdebug.la \
+       $(top_builddir)/src/error/liberror.la \
+       $(top_builddir)/src/comm/libminimal.la \
+       $(top_builddir)/src/mem/libminimal.la \
+       $(top_builddir)/src/base/libbase.la \
+       $(top_builddir)/src/time/libtime.la \
        $(COMPAT_LIB) \
        $(LIBTDB_LIBS)
 
index 5158e8f4584f8b7cd2989cd86376359bfd814457..6a8796a18cb891795cbc93ba7b7b43ee1cd210b4 100644 (file)
  * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111, USA.
  */
 
+/* DEBUG: section 82    External ACL Helpers */
+
 #include "squid.h"
+#include "debug/Stream.h"
 #include "helper/protocol_defines.h"
+#include "sbuf/Stream.h"
 
-#include <cstdlib>
-#include <cstring>
 #include <ctime>
-#include <sys/types.h>
-#include <sys/stat.h>
-#include <fcntl.h>
-#if HAVE_UNISTD_H
-#include <unistd.h>
-#endif
 #if HAVE_GETOPT_H
 #include <getopt.h>
 #endif
 #error "Please define DEFAULT_QUOTA_DB preprocessor constant."
 #endif
 
+static const auto MY_DEBUG_SECTION = 82;
 const char *db_path = DEFAULT_QUOTA_DB;
 const char *program_name;
 
 TDB_CONTEXT *db = nullptr;
 
-#define KEY_LAST_ACTIVITY            "last-activity"
-#define KEY_PERIOD_START             "period-start"
-#define KEY_PERIOD_LENGTH_CONFIGURED "period-length-configured"
-#define KEY_TIME_BUDGET_LEFT         "time-budget-left"
-#define KEY_TIME_BUDGET_CONFIGURED   "time-budget-configured"
+static const auto KeyLastActivity = "last-activity";
+static const auto KeyPeriodStart = "period-start";
+static const auto KeyPeriodLengthConfigured = "period-length-configured";
+static const auto KeyTimeBudgetLeft = "time-budget-left";
+static const auto KeyTimeBudgetConfigured = "time-budget-configured";
 
 /** Maximum size of buffers used to read or display lines. */
-#define TQ_BUFFERSIZE                     1024
+static const size_t TQ_BUFFERSIZE = 1024;
 
 /** If there is more than this given number of seconds between two
  * successive requests, than the second request will be treated as a
@@ -73,65 +70,17 @@ TDB_CONTEXT *db = nullptr;
  */
 static int pauseLength = 300;
 
-static FILE *logfile = stderr;
-static int tq_debug_enabled = false;
-
-static void vlog(const char *level, const char *format, va_list args)
-{
-    time_t now = time(NULL);
-
-    fprintf(logfile, "%ld %s| %s: ", static_cast<long int>(now),
-            program_name, level);
-    vfprintf (logfile, format, args);
-    fflush(logfile);
-}
-
-static void log_debug(const char *format, ...)
-{
-    va_list args;
-
-    if ( tq_debug_enabled ) {
-        va_start (args, format);
-        vlog("DEBUG", format, args);
-        va_end (args);
-    }
-}
-
-static void log_info(const char *format, ...)
-{
-    va_list args;
-
-    va_start (args, format);
-    vlog("INFO", format, args);
-    va_end (args);
-}
-
-static void log_error(const char *format, ...)
-{
-    va_list args;
-
-    va_start (args, format);
-    vlog("ERROR", format, args);
-    va_end (args);
-}
-
-static void log_fatal(const char *format, ...)
-{
-    va_list args;
-
-    va_start (args, format);
-    vlog("FATAL", format, args);
-    va_end (args);
-}
-
 static void init_db(void)
 {
-    log_info("opening time quota database \"%s\".\n", db_path);
+    debugs(MY_DEBUG_SECTION, 2, "opening time quota database \"" << db_path << "\".");
+
     db = tdb_open(db_path, 0, TDB_CLEAR_IF_FIRST, O_CREAT | O_RDWR, 0666);
     if (!db) {
-        log_fatal("Failed to open time_quota db '%s'\n", db_path);
+        debugs(MY_DEBUG_SECTION, DBG_CRITICAL, "FATAL: Failed to open time_quota db '" << db_path << '\'');
         exit(EXIT_FAILURE);
     }
+    // count the number of entries in the database, only used for debugging
+    debugs(MY_DEBUG_SECTION, 2, "Database contains " << tdb_traverse(db, nullptr, nullptr) << " entries");
 }
 
 static void shutdown_db(void)
@@ -139,65 +88,53 @@ static void shutdown_db(void)
     tdb_close(db);
 }
 
-static char *KeyString(int &len, const char *user_key, const char *sub_key)
+static SBuf KeyString(const char *user_key, const char *sub_key)
 {
-    static char keybuffer[TQ_BUFFERSIZE];
-    *keybuffer = 0;
-
-    len = snprintf(keybuffer, sizeof(keybuffer), "%s-%s", user_key, sub_key);
-    if (len < 0) {
-        log_error("Cannot add entry: %s-%s", user_key, sub_key);
-        len = 0;
-
-    } else if (static_cast<size_t>(len) >= sizeof(keybuffer)) {
-        log_error("key too long (%s,%s)\n", user_key, sub_key);
-        len = 0;
-    }
-
-    return keybuffer;
+    return ToSBuf(user_key, "-", sub_key);
 }
 
 static void writeTime(const char *user_key, const char *sub_key, time_t t)
 {
-    int len = 0;
-    if (/* const */ char *keybuffer = KeyString(len, user_key, sub_key)) {
-
-        TDB_DATA key, data;
-
-        key.dptr = reinterpret_cast<unsigned char *>(keybuffer);
-        key.dsize = len;
-
-        data.dptr = reinterpret_cast<unsigned char *>(&t);
-        data.dsize = sizeof(t);
-
-        tdb_store(db, key, data, TDB_REPLACE);
-        log_debug("writeTime(\"%s\", %d)\n", keybuffer, t);
-    }
+    auto ks = KeyString(user_key, sub_key);
+    const TDB_DATA key {
+        reinterpret_cast<unsigned char *>(const_cast<char *>(ks.rawContent())),
+        ks.length()
+    };
+    const TDB_DATA data {
+        reinterpret_cast<unsigned char *>(&t),
+        sizeof(t)
+    };
+
+    tdb_store(db, key, data, TDB_REPLACE);
+    debugs(MY_DEBUG_SECTION, 3, "writeTime(\"" << ks << "\", " << t << ')');
 }
 
 static time_t readTime(const char *user_key, const char *sub_key)
 {
-    int len = 0;
-    if (/* const */ char *keybuffer = KeyString(len, user_key, sub_key)) {
-
-        TDB_DATA key;
-        key.dptr = reinterpret_cast<unsigned char *>(keybuffer);
-        key.dsize = len;
-
-        auto data = tdb_fetch(db, key);
-
-        time_t t = 0;
-        if (data.dsize != sizeof(t)) {
-            log_error("CORRUPTED DATABASE (%s)\n", keybuffer);
-        } else {
-            memcpy(&t, data.dptr, sizeof(t));
-        }
+    auto ks = KeyString(user_key, sub_key);
+    const TDB_DATA key {
+        reinterpret_cast<unsigned char *>(const_cast<char *>(ks.rawContent())),
+        ks.length()
+    };
+    auto data = tdb_fetch(db, key);
+
+    if (!data.dptr) {
+        debugs(MY_DEBUG_SECTION, 3, "no data found for key \"" << ks << "\".");
+        return 0;
+    }
 
-        log_debug("readTime(\"%s\")=%d\n", keybuffer, t);
-        return t;
+    time_t t = 0;
+    if (data.dsize == sizeof(t)) {
+        memcpy(&t, data.dptr, sizeof(t));
+    } else {
+        debugs(MY_DEBUG_SECTION, DBG_IMPORTANT, "ERROR: Incompatible or corrupted database. " <<
+               "key: '" << ks <<
+               "', expected time value size: " << sizeof(t) <<
+               ", actual time value size: " << data.dsize);
     }
 
-    return 0;
+    debugs(MY_DEBUG_SECTION, 3, "readTime(\"" << ks << "\")=" << t);
+    return t;
 }
 
 static void parseTime(const char *s, time_t *secs, time_t *start)
@@ -235,7 +172,7 @@ static void parseTime(const char *s, time_t *secs, time_t *start)
         *start += 24 * 3600;         // in europe, the week starts monday
         break;
     default:
-        log_error("Wrong time unit \"%c\". Only \"m\", \"h\", \"d\", or \"w\" allowed.\n", unit);
+        debugs(MY_DEBUG_SECTION, DBG_IMPORTANT, "ERROR: Wrong time unit \"" << unit << "\". Only \"m\", \"h\", \"d\", or \"w\" allowed");
         break;
     }
 
@@ -259,7 +196,7 @@ static void readConfig(const char *filename)
     time_t budgetSecs, periodSecs;
     time_t start;
 
-    log_info("reading config file \"%s\".\n", filename);
+    debugs(MY_DEBUG_SECTION, 2, "reading config file \"" << filename << "\".");
 
     FH = fopen(filename, "r");
     if ( FH ) {
@@ -274,30 +211,30 @@ static void readConfig(const char *filename)
                 /* chop \n characters */
                 *cp = '\0';
             }
-            log_debug("read config line %u: \"%s\".\n", lineCount, line);
+            debugs(MY_DEBUG_SECTION, 3, "read config line " << lineCount << ": \"" << line << '\"');
             if ((username = strtok(line, "\t ")) != NULL) {
 
                 /* get the time budget */
                 if ((budget = strtok(nullptr, "/")) == NULL) {
-                    fprintf(stderr, "ERROR: missing 'budget' field on line %u of '%s'.\n", lineCount, filename);
+                    debugs(MY_DEBUG_SECTION, DBG_IMPORTANT, "ERROR: missing 'budget' field on line " << lineCount << " of '" << filename << '\'');
                     continue;
                 }
                 if ((period = strtok(nullptr, "/")) == NULL) {
-                    fprintf(stderr, "ERROR: missing 'period' field on line %u of '%s'.\n", lineCount, filename);
+                    debugs(MY_DEBUG_SECTION, DBG_IMPORTANT, "ERROR: missing 'period' field on line " << lineCount << " of '" << filename << '\'');
                     continue;
                 }
 
                 parseTime(budget, &budgetSecs, &start);
                 parseTime(period, &periodSecs, &start);
 
-                log_debug("read time quota for user \"%s\": %lds / %lds starting %lds\n",
-                          username, budgetSecs, periodSecs, start);
+                debugs(MY_DEBUG_SECTION, 3, "read time quota for user \"" << username << "\": " <<
+                       budgetSecs << "s / " << periodSecs << "s starting " << start);
 
-                writeTime(username, KEY_PERIOD_START, start);
-                writeTime(username, KEY_PERIOD_LENGTH_CONFIGURED, periodSecs);
-                writeTime(username, KEY_TIME_BUDGET_CONFIGURED, budgetSecs);
-                t = readTime(username, KEY_TIME_BUDGET_CONFIGURED);
-                writeTime(username, KEY_TIME_BUDGET_LEFT, t);
+                writeTime(username, KeyPeriodStart, start);
+                writeTime(username, KeyPeriodLengthConfigured, periodSecs);
+                writeTime(username, KeyTimeBudgetConfigured, budgetSecs);
+                t = readTime(username, KeyTimeBudgetConfigured);
+                writeTime(username, KeyTimeBudgetLeft, t);
             }
         }
         fclose(FH);
@@ -316,85 +253,89 @@ static void processActivity(const char *user_key)
     time_t userPeriodLength;
     time_t timeBudgetCurrent;
     time_t timeBudgetConfigured;
-    char message[TQ_BUFFERSIZE];
 
-    log_debug("processActivity(\"%s\")\n", user_key);
+    debugs(MY_DEBUG_SECTION, 3, "processActivity(\"" << user_key << "\")");
 
     // [1] Reset period if over
-    periodStart = readTime(user_key, KEY_PERIOD_START);
+    periodStart = readTime(user_key, KeyPeriodStart);
     if ( periodStart == 0 ) {
         // This is the first period ever.
         periodStart = now;
-        writeTime(user_key, KEY_PERIOD_START, periodStart);
+        writeTime(user_key, KeyPeriodStart, periodStart);
     }
 
     periodLength = now - periodStart;
-    userPeriodLength = readTime(user_key, KEY_PERIOD_LENGTH_CONFIGURED);
+    userPeriodLength = readTime(user_key, KeyPeriodLengthConfigured);
     if ( userPeriodLength == 0 ) {
         // This user is not configured. Allow anything.
-        log_debug("No period length found for user \"%s\". Quota for this user disabled.\n", user_key);
-        writeTime(user_key, KEY_TIME_BUDGET_LEFT, pauseLength);
+        debugs(MY_DEBUG_SECTION, 3, "disabling user quota for user '" <<
+               user_key << "': no period length found");
+        writeTime(user_key, KeyTimeBudgetLeft, pauseLength);
     } else {
         if ( periodLength >= userPeriodLength ) {
             // a new period has started.
-            log_debug("New time period started for user \"%s\".\n", user_key);
+            debugs(MY_DEBUG_SECTION, 3, "New time period started for user \"" << user_key << '\"');
             while ( periodStart < now ) {
                 periodStart += periodLength;
             }
-            writeTime(user_key, KEY_PERIOD_START, periodStart);
-            timeBudgetConfigured = readTime(user_key, KEY_TIME_BUDGET_CONFIGURED);
+            writeTime(user_key, KeyPeriodStart, periodStart);
+            timeBudgetConfigured = readTime(user_key, KeyTimeBudgetConfigured);
             if ( timeBudgetConfigured == 0 ) {
-                log_debug("No time budget configured for user \"%s\". Quota for this user disabled.\n", user_key);
-                writeTime(user_key, KEY_TIME_BUDGET_LEFT, pauseLength);
+                debugs(MY_DEBUG_SECTION, 3, "No time budget configured for user \"" << user_key  <<
+                       "\". Quota for this user disabled.");
+                writeTime(user_key, KeyTimeBudgetLeft, pauseLength);
             } else {
-                writeTime(user_key, KEY_TIME_BUDGET_LEFT, timeBudgetConfigured);
+                writeTime(user_key, KeyTimeBudgetLeft, timeBudgetConfigured);
             }
         }
     }
 
     // [2] Decrease time budget iff activity
-    lastActivity = readTime(user_key, KEY_LAST_ACTIVITY);
+    lastActivity = readTime(user_key, KeyLastActivity);
     if ( lastActivity == 0 ) {
         // This is the first request ever
-        writeTime(user_key, KEY_LAST_ACTIVITY, now);
+        writeTime(user_key, KeyLastActivity, now);
     } else {
         activityLength = now - lastActivity;
         if ( activityLength >= pauseLength ) {
             // This is an activity pause.
-            log_debug("Activity pause detected for user \"%s\".\n", user_key);
-            writeTime(user_key, KEY_LAST_ACTIVITY, now);
+            debugs(MY_DEBUG_SECTION, 3, "Activity pause detected for user \"" << user_key << "\".");
+            writeTime(user_key, KeyLastActivity, now);
         } else {
             // This is real usage.
-            writeTime(user_key, KEY_LAST_ACTIVITY, now);
+            writeTime(user_key, KeyLastActivity, now);
 
-            log_debug("Time budget reduced by %ld for user \"%s\".\n",
-                      activityLength, user_key);
-            timeBudgetCurrent = readTime(user_key, KEY_TIME_BUDGET_LEFT);
+            debugs(MY_DEBUG_SECTION, 3, "Time budget reduced by " << activityLength <<
+                   " for user \"" << user_key << "\".");
+            timeBudgetCurrent = readTime(user_key, KeyTimeBudgetLeft);
             timeBudgetCurrent -= activityLength;
-            writeTime(user_key, KEY_TIME_BUDGET_LEFT, timeBudgetCurrent);
+            writeTime(user_key, KeyTimeBudgetLeft, timeBudgetCurrent);
         }
     }
 
-    timeBudgetCurrent = readTime(user_key, KEY_TIME_BUDGET_LEFT);
-    snprintf(message, TQ_BUFFERSIZE, "message=\"Remaining quota for '%s' is %d seconds.\"", user_key, (int)timeBudgetCurrent);
+    timeBudgetCurrent = readTime(user_key, KeyTimeBudgetLeft);
+
+    const auto message = ToSBuf(HLP_MSG("Remaining quota for '"), user_key, "' is ", timeBudgetCurrent, " seconds.");
     if ( timeBudgetCurrent > 0 ) {
-        log_debug("OK %s.\n", message);
         SEND_OK(message);
     } else {
-        log_debug("ERR %s\n", message);
         SEND_ERR("Time budget exceeded.");
     }
 }
 
 static void usage(void)
 {
-    fprintf(stderr, "Usage: %s [-d] [-b dbpath] [-p pauselen] [-h] configfile\n", program_name);
-    fprintf(stderr, "  -d            enable debugging output\n");
-    fprintf(stderr, "  -b dbpath     Path where persistent session database will be kept\n");
-    fprintf(stderr, "                If option is not used, then " DEFAULT_QUOTA_DB " will be used.\n");
-    fprintf(stderr, "  -p pauselen   length in seconds to describe a pause between 2 requests.\n");
-    fprintf(stderr, "  -h            show show command line help.\n");
-    fprintf(stderr, "configfile is a file containing time quota definitions.\n");
+    debugs(MY_DEBUG_SECTION, DBG_CRITICAL, "Wrong usage. Please reconfigure in squid.conf.");
+
+    std::cerr <<
+              "Usage: " << program_name << " [-d] [-b dbpath] [-p pauselen] [-h] configfile\n"
+              "        -d            enable debugging output\n"
+              "        -l logfile    log messages to logfile\n"
+              "        -b dbpath     Path where persistent session database will be kept\n"
+              "                      If option is not used, then " DEFAULT_QUOTA_DB " will be used.\n"
+              "        -p pauselen   length in seconds to describe a pause between 2 requests.\n"
+              "        -h            show show command line help.\n"
+              "configfile is a file containing time quota definitions.\n";
 }
 
 int main(int argc, char **argv)
@@ -403,11 +344,12 @@ int main(int argc, char **argv)
     int opt;
 
     program_name = argv[0];
+    Debug::NameThisHelper("ext_time_quota_acl");
 
     while ((opt = getopt(argc, argv, "dp:b:h")) != -1) {
         switch (opt) {
         case 'd':
-            tq_debug_enabled = true;
+            Debug::Levels[MY_DEBUG_SECTION] = DBG_DATA;
             break;
         case 'b':
             db_path = optarg;
@@ -427,7 +369,7 @@ int main(int argc, char **argv)
         }
     }
 
-    log_info("Starting %s\n", __FILE__);
+    debugs(MY_DEBUG_SECTION, DBG_IMPORTANT, "Starting " << program_name);
     setbuf(stdout, nullptr);
 
     init_db();
@@ -439,7 +381,7 @@ int main(int argc, char **argv)
         readConfig(argv[optind]);
     }
 
-    log_info("Waiting for requests...\n");
+    debugs(MY_DEBUG_SECTION, 2, "Waiting for requests...");
     while (fgets(request, HELPER_INPUT_BUFFER, stdin)) {
         // we expect the following line syntax: %LOGIN
         const char *user_key = strtok(request, " \n");
@@ -449,7 +391,7 @@ int main(int argc, char **argv)
         }
         processActivity(user_key);
     }
-    log_info("Ending %s\n", __FILE__);
+    debugs(MY_DEBUG_SECTION, DBG_IMPORTANT, "Ending " << program_name);
     shutdown_db();
     return EXIT_SUCCESS;
 }