This is a work in progress branch to add high-ish speed and remote-monitoring logging capabilities to memcached.

Features

New logging will allow remote connections to monitor events, or subset of events.

Monitor incoming commands, or details of items which are being evicted. Further work on the branch will add more options.

Infrastructure in place for different types of watchers: "log to stderr", "log to networked client", or "log to syslog" should all be possible.

The final code should allow monitoring subsets of logs as well: "show me 1 out of every 4 evictions"

Logging code cannot block internally. If the logging thread gets behind, new entries are not written from the worker threads until it catches back up.

Demo

As of this writing:

$ telnet localhost 11211
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
watch fetchers

Connect again:

$ telnet localhost 11211
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
get foo
END

First connection will output:

ts=1466120156.99667 gid=1 type=item_get key=foo status=not_found

watch evictions can show details about evicted items:

ts=1466120156.304163 gid=57180 type=eviction key=n%2Cfoo1539 fetch=no ttl=-1 la=0

(ttl: time remaining before expiration. la: last access time. fetch: whether or not it was ever read)

Implementation

Each thread in the system gets a local "logger" object. Logger objects contain a circular buffer and flags for which log events to write. The flags and buffer are allocated within each thread, to help allow NUMA aware accesses. Loggers are also pinned to a thread via pthread_setspecific. getspecific|setspecific are slower than a direct reference, so the logger reference should be brought into a function via argument passing or from fetching from another structure where possible.

Callers of the logging code are able to hide as much complexity as possible into the logging code. See the eviction logger for an example of this: one line added to lru_pull_tail() instead of formatting inline.

A background thread is created which iterates over every active logger and writes found log entries (flattening timestamp and GID) into scratch space, then copying it into the buffers for any subscribed watchers. keys (and arbitrary strings) are "URI encoded" before sending to watchers. (ie: %NN replaces odd characters).

Watchers can be remote clients. They can also be stderr, or other things as implementations are added.

Remote clients are removed from a worker thread and sent to the logger thread to be managed (via a poll() loop). The only way to stop receiving logs is to disconnect.

When no watchers are active, should have no performance impact compared to the current "verbose logging to stderr".

Work In Progress

This is ready for a first release. Only a handful of logging endpoints are done to start with, and more refactoring is needed in the code. In adhering to "early and often", it's already useful and should evolve with time.

The full implementation should have a lot more logging points. Able to subscribe to system event type logs, as well as detailed logs for fetches and sets (if a get worked, or if it missed because the object was expired, flushed, etc). The watch command will allow fine grained access to which events you wish to subscribe to.

Not all current stderr logs will be converted to the new system. Many will be left to stderr only as debugging prints. IE: dumps of binprot formats, connection state transitions, etc. Logging entries are targeted toward end users more than developers.

An unordered list of remaining TODO items are below:

• Tests added to the main test suite
• Full option parser for watch command (done until extensions are needed)
• Watchers see individualized stream of events
• Stats output (# of loglines written, skipped, read, etc)
• Clean, simplify, document code better. Done three rounds now. Needs one more.
• Decide on final logging format(s)?
  (doing a "key=value key=value" + uriencoded keys format, but not hard to allow multiple formats)
• Benchmarks to document performance impact
• Add all potential logging endpoints and threads (sticking with get/store/eviction endpoints for first release)

Some optional tasks (confirmed for another PR):

• Able to subscribe to subsets of events (1 out of every N fetchers/sets/evictions)
• "strict mode" where loggers block when out of space. Avoid missing any entries.
• Some kind of status display for logging thread (what events are being watched, how many watchers, etc?)