apache2/persist_dbm.c

   1 /*
   2  * ModSecurity for Apache 2.x, http://www.modsecurity.org/
   3  * Copyright (c) 2004-2009 Breach Security, Inc. (http://www.breach.com/)
   4  *
   5  * This product is released under the terms of the General Public Licence,
   6  * version 2 (GPLv2). Please refer to the file LICENSE (included with this
   7  * distribution) which contains the complete text of the licence.
   8  *
   9  * There are special exceptions to the terms and conditions of the GPL
  10  * as it is applied to this software. View the full text of the exception in
  11  * file MODSECURITY_LICENSING_EXCEPTION in the directory of this software
  12  * distribution.
  13  *
  14  * If any of the files related to licensing are missing or if you have any
  15  * other questions related to licensing please contact Breach Security, Inc.
  16  * directly using the email address support@breach.com.
  17  *
  18  */
  19 #include "persist_dbm.h"
  20 #include "apr_sdbm.h"
  21
  22 /**
  23  *
  24  */
  25 static apr_table_t *collection_unpack(modsec_rec *msr, const unsigned char *blob, unsigned int blob_size,
  26     int log_vars)
  27 {
  28     apr_table_t *col = NULL;
  29     unsigned int blob_offset;
  30
  31     col = apr_table_make(msr->mp, 32);
  32     if (col == NULL) return NULL;
  33
  34     /* ENH verify the first 3 bytes (header) */
  35
  36     blob_offset = 3;
  37     while (blob_offset + 1 < blob_size) {
  38         msc_string *var = apr_pcalloc(msr->mp, sizeof(msc_string));
  39
  40         var->name_len = (blob[blob_offset] << 8) + blob[blob_offset + 1];
  41         if (var->name_len == 0) {
  42             /* Is the length a name length, or just the end of the blob? */
  43             if (blob_offset < blob_size - 2) {
  44                 /* This should never happen as the name length
  45                  * includes the terminating NUL and should be 1 for ""
  46                  */
  47                 if (msr->txcfg->debuglog_level >= 9) {
  48                     msr_log(msr, 9, "BLOB[%d]: %s", blob_offset, log_escape_hex(msr->mp, blob + blob_offset, blob_size - blob_offset));
  49                 }
  50                 msr_log(msr, 4, "Possibly corrupted database: var name length = 0 at blob offset %u-%u.", blob_offset, blob_offset + 1);
  51             }
  52             break;
  53         }
  54         else if (var->name_len > 65536) {
  55             /* This should never happen as the length is restricted on store
  56              * to 65536.
  57              */
  58             if (msr->txcfg->debuglog_level >= 9) {
  59                 msr_log(msr, 9, "BLOB[%d]: %s", blob_offset, log_escape_hex(msr->mp, blob + blob_offset, blob_size - blob_offset));
  60             }
  61             msr_log(msr, 4, "Possibly corrupted database: var name length > 65536 (0x%04x) at blob offset %u-%u.", var->name_len, blob_offset, blob_offset + 1);
  62             break;
  63         }
  64
  65         blob_offset += 2;
  66         if (blob_offset + var->name_len > blob_size) return NULL;
  67         var->name = apr_pstrmemdup(msr->mp, (const char *)blob + blob_offset, var->name_len - 1);
  68         blob_offset += var->name_len;
  69         var->name_len--;
  70
  71         var->value_len = (blob[blob_offset] << 8) + blob[blob_offset + 1];
  72         blob_offset += 2;
  73
  74         if (blob_offset + var->value_len > blob_size) return NULL;
  75         var->value = apr_pstrmemdup(msr->mp, (const char *)blob + blob_offset, var->value_len - 1);
  76         blob_offset += var->value_len;
  77         var->value_len--;
  78
  79         if (log_vars && (msr->txcfg->debuglog_level >= 9)) {
  80             msr_log(msr, 9, "Read variable: name \"%s\", value \"%s\".",
  81                 log_escape_ex(msr->mp, var->name, var->name_len),
  82                 log_escape_ex(msr->mp, var->value, var->value_len));
  83         }
  84
  85         apr_table_addn(col, var->name, (void *)var);
  86     }
  87
  88     return col;
  89 }
  90
  91 /**
  92  *
  93  */
  94 static apr_table_t *collection_retrieve_ex(apr_sdbm_t *existing_dbm, modsec_rec *msr, const char *col_name,
  95     const char *col_key, int col_key_len)
  96 {
  97     char *dbm_filename = NULL;
  98     apr_status_t rc;
  99     apr_sdbm_datum_t key;
 100     apr_sdbm_datum_t *value = NULL;
 101     apr_sdbm_t *dbm = NULL;
 102     apr_table_t *col = NULL;
 103     const apr_array_header_t *arr;
 104     apr_table_entry_t *te;
 105     int expired = 0;
 106     int i;
 107
 108     if (msr->txcfg->data_dir == NULL) {
 109         msr_log(msr, 1, "Unable to retrieve collection (name \"%s\", key \"%s\"). Use "
 110             "SecDataDir to define data directory first.", log_escape(msr->mp, col_name),
 111             log_escape_ex(msr->mp, col_key, col_key_len));
 112         goto cleanup;
 113     }
 114
 115     dbm_filename = apr_pstrcat(msr->mp, msr->txcfg->data_dir, "/", col_name, NULL);
 116
 117     key.dptr = (char *)col_key;
 118     key.dsize = col_key_len + 1;
 119
 120     if (existing_dbm == NULL) {
 121         rc = apr_sdbm_open(&dbm, dbm_filename, APR_READ | APR_SHARELOCK,
 122             CREATEMODE, msr->mp);
 123         if (rc != APR_SUCCESS) {
 124             dbm = NULL;
 125             goto cleanup;
 126         }
 127     }
 128     else {
 129         dbm = existing_dbm;
 130     }
 131
 132     value = (apr_sdbm_datum_t *)apr_pcalloc(msr->mp, sizeof(apr_sdbm_datum_t));
 133     rc = apr_sdbm_fetch(dbm, value, key);
 134     if (rc != APR_SUCCESS) {
 135         msr_log(msr, 1, "Failed to read from DBM file \"%s\": %s", log_escape(msr->mp,
 136             dbm_filename), get_apr_error(msr->mp, rc));
 137         goto cleanup;
 138     }
 139
 140     if (value->dptr == NULL) { /* Key not found in DBM file. */
 141         goto cleanup;
 142     }
 143
 144     /* ENH Need expiration (and perhaps other metadata) accessible in blob
 145      * form to determine if converting to a table is needed.  This will
 146      * save some cycles.
 147      */
 148
 149     /* Transform raw data into a table. */
 150     col = collection_unpack(msr, (const unsigned char *)value->dptr, value->dsize, 1);
 151     if (col == NULL) {
 152         goto cleanup;
 153     }
 154
 155     /* Close after "value" used from fetch or memory may be overwritten. */
 156     if (existing_dbm == NULL) {
 157         apr_sdbm_close(dbm);
 158         dbm = NULL;
 159     }
 160
 161     /* Remove expired variables. */
 162     do {
 163         arr = apr_table_elts(col);
 164         te = (apr_table_entry_t *)arr->elts;
 165         for (i = 0; i < arr->nelts; i++) {
 166             if (strncmp(te[i].key, "__expire_", 9) == 0) {
 167                 msc_string *var = (msc_string *)te[i].val;
 168                 int expiry_time = atoi(var->value);
 169
 170                 if (expiry_time <= apr_time_sec(msr->request_time)) {
 171                     char *key_to_expire = te[i].key;
 172
 173                     /* Done early if the col expired */
 174                     if (strcmp(key_to_expire, "__expire_KEY") == 0) {
 175                         expired = 1;
 176                     }
 177                     if (msr->txcfg->debuglog_level >= 9) {
 178                         msr_log(msr, 9, "Removing key \"%s\" from collection.", key_to_expire + 9);
 179                         msr_log(msr, 9, "Removing key \"%s\" from collection.", key_to_expire);
 180                     }
 181                     apr_table_unset(col, key_to_expire + 9);
 182                     apr_table_unset(col, key_to_expire);
 183                     if (msr->txcfg->debuglog_level >= 4) {
 184                         msr_log(msr, 4, "Removed expired variable \"%s\".", key_to_expire + 9);
 185                     }
 186                     break;
 187                 }
 188             }
 189         }
 190     } while(!expired && (i != arr->nelts));
 191
 192     /* Delete the collection if the variable "KEY" does not exist.
 193      *
 194      * ENH It would probably be more efficient to hold the DBM
 195      * open until determined if it needs deleted than to open a second
 196      * time.
 197      */
 198     if (apr_table_get(col, "KEY") == NULL) {
 199         if (existing_dbm == NULL) {
 200             rc = apr_sdbm_open(&dbm, dbm_filename, APR_CREATE | APR_WRITE | APR_SHARELOCK,
 201                 CREATEMODE, msr->mp);
 202             if (rc != APR_SUCCESS) {
 203                 msr_log(msr, 1, "Failed to access DBM file \"%s\": %s",
 204                     log_escape(msr->mp, dbm_filename), get_apr_error(msr->mp, rc));
 205                 dbm = NULL;
 206                 goto cleanup;
 207             }
 208         }
 209         else {
 210             dbm = existing_dbm;
 211         }
 212
 213         rc = apr_sdbm_delete(dbm, key);
 214         if (rc != APR_SUCCESS) {
 215             msr_log(msr, 1, "Failed deleting collection (name \"%s\", "
 216                 "key \"%s\"): %s", log_escape(msr->mp, col_name),
 217                 log_escape_ex(msr->mp, col_key, col_key_len), get_apr_error(msr->mp, rc));
 218             goto cleanup;
 219         }
 220
 221
 222         if (existing_dbm == NULL) {
 223             apr_sdbm_close(dbm);
 224             dbm = NULL;
 225         }
 226
 227         if (expired && (msr->txcfg->debuglog_level >= 9)) {
 228             msr_log(msr, 9, "Collection expired (name \"%s\", key \"%s\").", col_name, log_escape_ex(msr->mp, col_key, col_key_len));
 229         }
 230         if (msr->txcfg->debuglog_level >= 4) {
 231             msr_log(msr, 4, "Deleted collection (name \"%s\", key \"%s\").",
 232                 log_escape(msr->mp, col_name), log_escape_ex(msr->mp, col_key, col_key_len));
 233         }
 234         goto cleanup;
 235     }
 236
 237     /* Update UPDATE_RATE */
 238     {
 239         msc_string *var;
 240         int create_time, counter;
 241
 242         var = (msc_string *)apr_table_get(col, "CREATE_TIME");
 243         if (var == NULL) {
 244             /* Error. */
 245         } else {
 246             create_time = atoi(var->value);
 247             var = (msc_string *)apr_table_get(col, "UPDATE_COUNTER");
 248             if (var == NULL) {
 249                 /* Error. */
 250             } else {
 251                 apr_time_t td;
 252                 counter = atoi(var->value);
 253
 254                 /* UPDATE_RATE is removed on store, so add it back here */
 255                 var = (msc_string *)apr_pcalloc(msr->mp, sizeof(msc_string));
 256                 var->name = "UPDATE_RATE";
 257                 var->name_len = strlen(var->name);
 258                 apr_table_setn(col, var->name, (void *)var);
 259
 260                 /* NOTE: No rate if there has been no time elapsed */
 261                 td = (apr_time_sec(apr_time_now()) - create_time);
 262                 if (td == 0) {
 263                     var->value = apr_psprintf(msr->mp, "%d", 0);
 264                 }
 265                 else {
 266                     var->value = apr_psprintf(msr->mp, "%" APR_TIME_T_FMT,
 267                         (apr_time_t)((60 * counter)/td));
 268                 }
 269                 var->value_len = strlen(var->value);
 270             }
 271         }
 272     }
 273
 274     if (msr->txcfg->debuglog_level >= 4) {
 275         msr_log(msr, 4, "Retrieved collection (name \"%s\", key \"%s\").",
 276                 log_escape(msr->mp, col_name), log_escape_ex(msr->mp, col_key, col_key_len));
 277     }
 278
 279     if ((existing_dbm == NULL) && dbm) {
 280         /* Should not ever get here */
 281         msr_log(msr, 1, "Internal Error: Collection remained open (name \"%s\", key \"%s\").",
 282                 log_escape(msr->mp, col_name), log_escape_ex(msr->mp, col_key, col_key_len));
 283
 284         apr_sdbm_close(dbm);
 285     }
 286
 287     return col;
 288
 289 cleanup:
 290
 291     if ((existing_dbm == NULL) && dbm) {
 292         apr_sdbm_close(dbm);
 293     }
 294
 295     return NULL;
 296 }
 297
 298 /**
 299  *
 300  */
 301 apr_table_t *collection_retrieve(modsec_rec *msr, const char *col_name,
 302     const char *col_key, int col_key_len) {
 303     return collection_retrieve_ex(NULL, msr, col_name, col_key, col_key_len);
 304 }
 305
 306
 307 /**
 308  *
 309  */
 310 int collection_store(modsec_rec *msr, apr_table_t *col) {
 311     char *dbm_filename = NULL;
 312     msc_string *var_name = NULL, *var_key = NULL;
 313     unsigned char *blob = NULL;
 314     unsigned int blob_size, blob_offset;
 315     apr_status_t rc;
 316     apr_sdbm_datum_t key;
 317     apr_sdbm_datum_t value;
 318     apr_sdbm_t *dbm = NULL;
 319     const apr_array_header_t *arr;
 320     apr_table_entry_t *te;
 321     int i;
 322     const apr_table_t *stored_col = NULL;
 323     const apr_table_t *orig_col = NULL;
 324
 325     var_name = (msc_string *)apr_table_get(col, "__name");
 326     if (var_name == NULL) {
 327         goto error;
 328     }
 329
 330     var_key = (msc_string *)apr_table_get(col, "__key");
 331     if (var_key == NULL) {
 332         goto error;
 333     }
 334
 335     if (msr->txcfg->data_dir == NULL) {
 336         msr_log(msr, 1, "Unable to store collection (name \"%s\", key \"%s\"). Use "
 337             "SecDataDir to define data directory first.",
 338             log_escape_ex(msr->mp, var_name->value, var_name->value_len), log_escape_ex(msr->mp, var_key->value, var_key->value_len));
 339         goto error;
 340     }
 341
 342     // ENH: lowercase the var name in the filename
 343     dbm_filename = apr_pstrcat(msr->mp, msr->txcfg->data_dir, "/", var_name->value, NULL);
 344
 345     /* Delete IS_NEW on store. */
 346     apr_table_unset(col, "IS_NEW");
 347
 348     /* Delete UPDATE_RATE on store to save space as it is calculated */
 349     apr_table_unset(col, "UPDATE_RATE");
 350
 351     /* Update the timeout value. */
 352     {
 353         msc_string *var = (msc_string *)apr_table_get(col, "TIMEOUT");
 354         if (var != NULL) {
 355             int timeout = atoi(var->value);
 356             var = (msc_string *)apr_table_get(col, "__expire_KEY");
 357             if (var != NULL) {
 358                 var->value = apr_psprintf(msr->mp, "%" APR_TIME_T_FMT, (apr_time_t)(apr_time_sec(apr_time_now()) + timeout));
 359                 var->value_len = strlen(var->value);
 360             }
 361         }
 362     }
 363
 364     /* LAST_UPDATE_TIME */
 365     {
 366         msc_string *var = (msc_string *)apr_table_get(col, "LAST_UPDATE_TIME");
 367         if (var == NULL) {
 368             var = (msc_string *)apr_pcalloc(msr->mp, sizeof(msc_string));
 369             var->name = "LAST_UPDATE_TIME";
 370             var->name_len = strlen(var->name);
 371             apr_table_setn(col, var->name, (void *)var);
 372         }
 373         var->value = apr_psprintf(msr->mp, "%" APR_TIME_T_FMT, (apr_time_t)(apr_time_sec(apr_time_now())));
 374         var->value_len = strlen(var->value);
 375     }
 376
 377     /* UPDATE_COUNTER */
 378     {
 379         msc_string *var = (msc_string *)apr_table_get(col, "UPDATE_COUNTER");
 380         int counter = 0;
 381         if (var == NULL) {
 382             var = (msc_string *)apr_pcalloc(msr->mp, sizeof(msc_string));
 383             var->name = "UPDATE_COUNTER";
 384             var->name_len = strlen(var->name);
 385             apr_table_setn(col, var->name, (void *)var);
 386         } else {
 387             counter = atoi(var->value);
 388         }
 389         var->value = apr_psprintf(msr->mp, "%d", counter + 1);
 390         var->value_len = strlen(var->value);
 391     }
 392
 393     /* ENH Make the expiration timestamp accessible in blob form so that
 394      * it is easier/faster to determine expiration without having to
 395      * convert back to table form
 396      */
 397
 398     rc = apr_sdbm_open(&dbm, dbm_filename, APR_CREATE | APR_WRITE | APR_SHARELOCK,
 399         CREATEMODE, msr->mp);
 400     if (rc != APR_SUCCESS) {
 401         msr_log(msr, 1, "Failed to access DBM file \"%s\": %s", log_escape(msr->mp, dbm_filename),
 402             get_apr_error(msr->mp, rc));
 403         dbm = NULL;
 404         goto error;
 405     }
 406
 407     /* Need to lock to pull in the stored data again and apply deltas. */
 408     rc = apr_sdbm_lock(dbm, APR_FLOCK_EXCLUSIVE);
 409     if (rc != APR_SUCCESS) {
 410         msr_log(msr, 1, "Failed to exclusivly lock DBM file \"%s\": %s", log_escape(msr->mp, dbm_filename),
 411             get_apr_error(msr->mp, rc));
 412         goto error;
 413     }
 414
 415     /* If there is an original value, then create a delta and
 416      * apply the delta to the current value */
 417     orig_col = (const apr_table_t *)apr_table_get(msr->collections_original, var_name->value);
 418     if (orig_col != NULL) {
 419         if (msr->txcfg->debuglog_level >= 9) {
 420             msr_log(msr, 9, "Re-retrieving collection prior to store: %s", apr_psprintf(msr->mp, "%.*s", var_name->value_len, var_name->value));
 421         }
 422
 423         stored_col = (const apr_table_t *)collection_retrieve_ex(dbm, msr, var_name->value, var_key->value, var_key->value_len);
 424     }
 425
 426     /* Merge deltas and calculate the size first. */
 427     blob_size = 3 + 2;
 428     arr = apr_table_elts(col);
 429     te = (apr_table_entry_t *)arr->elts;
 430     for (i = 0; i < arr->nelts; i++) {
 431         msc_string *var = (msc_string *)te[i].val;
 432         int len;
 433
 434         /* If there is an original value, then apply the delta
 435          * to the latest stored value */
 436         if (stored_col != NULL) {
 437             const msc_string *orig_var = (const msc_string *)apr_table_get(orig_col, var->name);
 438             if (orig_var != NULL) {
 439                 const msc_string *stored_var = (const msc_string *)apr_table_get(stored_col, var->name);
 440                 if (stored_var != NULL) {
 441                     int origval = atoi(orig_var->value);
 442                     int ourval = atoi(var->value);
 443                     int storedval = atoi(stored_var->value);
 444                     int delta = ourval - origval;
 445                     int newval = storedval + delta;
 446
 447                     if (newval < 0) newval = 0; /* Counters never go below zero. */
 448
 449                     var->value = apr_psprintf(msr->mp, "%d", newval);
 450                     var->value_len = strlen(var->value);
 451                     if (msr->txcfg->debuglog_level >= 9) {
 452                         msr_log(msr, 9, "Delta applied for %s.%s %d->%d (%d): %d + (%d) = %d [%s,%d]",
 453                         log_escape_ex(msr->mp, var_name->value, var_name->value_len),
 454                         log_escape_ex(msr->mp, var->name, var->name_len),
 455                         origval, ourval, delta, storedval, delta, newval, var->value, var->value_len);
 456                     }
 457                 }
 458             }
 459         }
 460
 461         len = var->name_len + 1;
 462         if (len >= 65536) len = 65536;
 463         blob_size += len + 2;
 464
 465         len = var->value_len + 1;
 466         if (len >= 65536) len = 65536;
 467         blob_size += len + 2;
 468     }
 469
 470     /* Now generate the binary object. */
 471     blob = apr_pcalloc(msr->mp, blob_size);
 472     if (blob == NULL) {
 473         goto error;
 474     }
 475
 476     blob[0] = 0x49;
 477     blob[1] = 0x52;
 478     blob[2] = 0x01;
 479
 480     blob_offset = 3;
 481     arr = apr_table_elts(col);
 482     te = (apr_table_entry_t *)arr->elts;
 483     for (i = 0; i < arr->nelts; i++) {
 484         msc_string *var = (msc_string *)te[i].val;
 485         int len;
 486
 487         len = var->name_len + 1;
 488         if (len >= 65536) len = 65536;
 489
 490         blob[blob_offset + 0] = (len & 0xff00) >> 8;
 491         blob[blob_offset + 1] = len & 0x00ff;
 492         memcpy(blob + blob_offset + 2, var->name, len - 1);
 493         blob[blob_offset + 2 + len - 1] = '\0';
 494         blob_offset += 2 + len;
 495
 496         len = var->value_len + 1;
 497         if (len >= 65536) len = 65536;
 498
 499         blob[blob_offset + 0] = (len & 0xff00) >> 8;
 500         blob[blob_offset + 1] = len & 0x00ff;
 501         memcpy(blob + blob_offset + 2, var->value, len - 1);
 502         blob[blob_offset + 2 + len - 1] = '\0';
 503         blob_offset += 2 + len;
 504
 505         if (msr->txcfg->debuglog_level >= 9) {
 506             msr_log(msr, 9, "Wrote variable: name \"%s\", value \"%s\".",
 507                 log_escape_ex(msr->mp, var->name, var->name_len),
 508                 log_escape_ex(msr->mp, var->value, var->value_len));
 509         }
 510     }
 511
 512     blob[blob_offset] = 0;
 513     blob[blob_offset + 1] = 0;
 514
 515     /* And, finally, store it. */
 516     key.dptr = var_key->value;
 517     key.dsize = var_key->value_len + 1;
 518
 519     value.dptr = (char *)blob;
 520     value.dsize = blob_size;
 521
 522     rc = apr_sdbm_store(dbm, key, value, APR_SDBM_REPLACE);
 523     if (rc != APR_SUCCESS) {
 524         msr_log(msr, 1, "Failed to write to DBM file \"%s\": %s", dbm_filename,
 525             get_apr_error(msr->mp, rc));
 526         goto error;
 527     }
 528
 529     apr_sdbm_close(dbm);
 530
 531     if (msr->txcfg->debuglog_level >= 4) {
 532         msr_log(msr, 4, "Persisted collection (name \"%s\", key \"%s\").",
 533             log_escape_ex(msr->mp, var_name->value, var_name->value_len), log_escape_ex(msr->mp, var_key->value, var_key->value_len));
 534     }
 535
 536     return 0;
 537
 538 error:
 539
 540     if (dbm) {
 541         apr_sdbm_close(dbm);
 542     }
 543
 544     return -1;
 545 }
 546
 547 /**
 548  *
 549  */
 550 int collections_remove_stale(modsec_rec *msr, const char *col_name) {
 551     char *dbm_filename = NULL;
 552     apr_sdbm_datum_t key, value;
 553     apr_sdbm_t *dbm = NULL;
 554     apr_status_t rc;
 555     apr_array_header_t *keys_arr;
 556     char **keys;
 557     apr_time_t now = apr_time_sec(msr->request_time);
 558     int i;
 559
 560     if (msr->txcfg->data_dir == NULL) {
 561         /* The user has been warned about this problem enough times already by now.
 562          * msr_log(msr, 1, "Unable to access collection file (name \"%s\"). Use SecDataDir to "
 563          *     "define data directory first.", log_escape(msr->mp, col_name));
 564          */
 565         goto error;
 566     }
 567
 568     dbm_filename = apr_pstrcat(msr->mp, msr->txcfg->data_dir, "/", col_name, NULL);
 569
 570     rc = apr_sdbm_open(&dbm, dbm_filename, APR_CREATE | APR_WRITE | APR_SHARELOCK,
 571         CREATEMODE, msr->mp);
 572     if (rc != APR_SUCCESS) {
 573         msr_log(msr, 1, "Failed to access DBM file \"%s\": %s", log_escape(msr->mp, dbm_filename),
 574             get_apr_error(msr->mp, rc));
 575         dbm = NULL;
 576         goto error;
 577     }
 578
 579     /* First get a list of all keys. */
 580     keys_arr = apr_array_make(msr->mp, 256, sizeof(char *));
 581     rc = apr_sdbm_lock(dbm, APR_FLOCK_SHARED);
 582     if (rc != APR_SUCCESS) {
 583         msr_log(msr, 1, "Failed to lock DBM file \"%s\": %s", log_escape(msr->mp, dbm_filename),
 584             get_apr_error(msr->mp, rc));
 585         goto error;
 586     }
 587
 588     /* No one can write to the file while doing this so
 589      * do it as fast as possible.
 590      */
 591     rc = apr_sdbm_firstkey(dbm, &key);
 592     while(rc == APR_SUCCESS) {
 593         char *s = apr_pstrmemdup(msr->mp, key.dptr, key.dsize - 1);
 594         *(char **)apr_array_push(keys_arr) = s;
 595         rc = apr_sdbm_nextkey(dbm, &key);
 596     }
 597     apr_sdbm_unlock(dbm);
 598
 599     if (msr->txcfg->debuglog_level >= 9) {
 600         msr_log(msr, 9, "Found %d record(s) in file \"%s\".", keys_arr->nelts,
 601             log_escape(msr->mp, dbm_filename));
 602     }
 603
 604     /* Now retrieve the entires one by one. */
 605     keys = (char **)keys_arr->elts;
 606     for (i = 0; i < keys_arr->nelts; i++) {
 607         key.dptr = keys[i];
 608         key.dsize = strlen(key.dptr) + 1;
 609
 610         rc = apr_sdbm_fetch(dbm, &value, key);
 611         if (rc != APR_SUCCESS) {
 612             msr_log(msr, 1, "Failed reading DBM file \"%s\": %s",
 613                 log_escape(msr->mp, dbm_filename), get_apr_error(msr->mp, rc));
 614             goto error;
 615         }
 616
 617         if (value.dptr != NULL) {
 618             apr_table_t *col = NULL;
 619             msc_string *var = NULL;
 620
 621             col = collection_unpack(msr, (const unsigned char *)value.dptr, value.dsize, 0);
 622             if (col == NULL) {
 623                 goto error;
 624             }
 625
 626             var = (msc_string *)apr_table_get(col, "__expire_KEY");
 627             if (var == NULL) {
 628                 msr_log(msr, 1, "Collection cleanup discovered entry with no "
 629                     "__expire_KEY (name \"%s\", key \"%s\").",
 630                     log_escape(msr->mp, col_name), log_escape_ex(msr->mp, key.dptr, key.dsize - 1));
 631             } else {
 632                 unsigned int expiry_time = atoi(var->value);
 633
 634                 if (msr->txcfg->debuglog_level >= 9) {
 635                     msr_log(msr, 9, "Record (name \"%s\", key \"%s\") set to expire in %" APR_TIME_T_FMT " seconds.",
 636                         log_escape(msr->mp, col_name), log_escape_ex(msr->mp, key.dptr, key.dsize - 1),
 637                         expiry_time - now);
 638                 }
 639
 640                 if (expiry_time <= now) {
 641                     rc = apr_sdbm_delete(dbm, key);
 642                     if (rc != APR_SUCCESS) {
 643                         msr_log(msr, 1, "Failed deleting collection (name \"%s\", "
 644                             "key \"%s\"): %s", log_escape(msr->mp, col_name),
 645                             log_escape_ex(msr->mp, key.dptr, key.dsize - 1), get_apr_error(msr->mp, rc));
 646                         goto error;
 647                     }
 648                     if (msr->txcfg->debuglog_level >= 4) {
 649                         msr_log(msr, 4, "Removed stale collection (name \"%s\", "
 650                                 "key \"%s\").", log_escape(msr->mp, col_name),
 651                                 log_escape_ex(msr->mp, key.dptr, key.dsize - 1));
 652                     }
 653                 }
 654             }
 655         } else {
 656             /* Ignore entry not found - it may have been removed in the meantime. */
 657         }
 658     }
 659
 660     apr_sdbm_close(dbm);
 661
 662     return 1;
 663
 664 error:
 665
 666     if (dbm) {
 667         apr_sdbm_close(dbm);
 668     }
 669
 670     return -1;
 671 }