Uploaded image for project: 'Qpid Dispatch'
  1. Qpid Dispatch
  2. DISPATCH-1373

the log system mutex is held far too long

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Open
    • Priority: Major
    • Resolution: Unresolved
    • Affects Version/s: 1.8.0, 1.9.0
    • Fix Version/s: None
    • Component/s: Router Node
    • Labels:

      Description

      The log code holds the log mutex(s) too long.  Depending on the log level (trace+ is worst) the lock has been observed being held for > 30 milliseconds.

      The log lock is a singleton that is acquired by all calls to qd_log (active log level only) - which means it is a global lock.

      It appears as if the lock is held while doing I/O and alloc/dealloc'ing memory - which may be expensive (in qd_vlog_impl() in log.c):

       

          // Bounded buffer of log entries, keep most recent.
          sys_mutex_lock(log_lock);
          qd_log_entry_t *entry = new_qd_log_entry_t();
          DEQ_ITEM_INIT(entry);
          entry->module = source->module;
          entry->level  = level;
          entry->file   = file ? strdup(file) : 0;
          entry->line   = line;
          gettimeofday(&entry->time, NULL);
          vsnprintf(entry->text, TEXT_MAX, fmt, ap);
          write_log(source, entry);
          DEQ_INSERT_TAIL(entries, entry);
          if (DEQ_SIZE(entries) > LIST_MAX)
              qd_log_entry_free_lh(DEQ_HEAD(entries));
          sys_mutex_unlock(log_lock);{{}}

       

        Attachments

          Activity

            People

            • Assignee:
              Unassigned
              Reporter:
              kgiusti Ken Giusti
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated: