Navigation Menu

Skip to content

Instantly share code, notes, and snippets.

@bjori
Created September 16, 2013 21:07
Show Gist options
  • Star 3 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save bjori/6586633 to your computer and use it in GitHub Desktop.
Save bjori/6586633 to your computer and use it in GitHub Desktop.
The MongoDB Profiling example, using the PHP Stream Notification API For more info, see: http://bjori.blogspot.com/2013/09/query-logging-and-profiling-in-mongodb.html
<?php
class MongoNotifications {
public $reqs = array();
/* Our callback function
* The prototype is define by the PHP Stream Notification system: http://php.net/stream_notification_callback
*/
function update($notification_code, $severity, $message, $message_code, $bytes_transferred, $bytes_max) {
switch($notification_code) {
/* For now, lets focus on the TYPE_LOG, and ignore the others */
case MONGO_STREAM_NOTIFY_TYPE_LOG:
/* This notification only uses two arguments, so we can ignore the rest */
return $this->logMessage($message_code, $message);
default:
}
}
/* Our logging function
* The $code describes the operation being executed,
* and $message is a json serialized array, packed with information
* Note: If ext/json is not available, $message with be PHP serialize()d instead
*/
function logMessage($code, $message) {
$data = json_decode($message, true);
switch($code) {
/* Write operations are a one way street in MongoDB, so these don't end with a
* MONGO_STREAM_NOTIFY_LOG_RESPONSE_HEADER.
* When using WriteConcern (defaults to 1), and additional query (command) is
* sent to check for errors, called getLastError*/
case MONGO_STREAM_NOTIFY_LOG_INSERT:
case MONGO_STREAM_NOTIFY_LOG_UPDATE:
case MONGO_STREAM_NOTIFY_LOG_DELETE:
case MONGO_STREAM_NOTIFY_LOG_GETMORE:
case MONGO_STREAM_NOTIFY_LOG_KILLCURSOR:
case MONGO_STREAM_NOTIFY_LOG_BATCHINSERT:
/* We only care about the query and response headers, for now */
break;
/* We´ve got a query */
case MONGO_STREAM_NOTIFY_LOG_QUERY:
/* Retrieve the Wire protocol Request ID, so we can match it with the
* Response headers once the query as executed */
$reqid = $data["server"]["request_id"];
/* Log all the metadata we have about the query, and add the start time */
$this->reqs[$reqid] = $data;
$this->reqs[$reqid]["start"] = microtime(true);
break;
/* The query has executed on the server, and now we are reading the
* response headers */
case MONGO_STREAM_NOTIFY_LOG_RESPONSE_HEADER:
// Get the Request ID this respose is for
$id = $data["server"]["request_id"];
/* The driver runs some commands internally, such as isMaster() to
* sanitycheck the connection to the server, these commands currently
* don't trigger the notification system - that may/will change in the
* future though */
if (!isset($this->reqs[$id])) {
return;
}
// Fetch the request info
$req = $this->reqs[$id];
// End the timer
$end = microtime(true);
// Add the ending time, and how long it took
$req["ended"] = $end;
$req["total"] = $end - $req["start"];
$this->reqs[$id] = $req;
break;
default:
// Unknown log message code, ignore
}
}
function getRequests() {
return $this->reqs;
}
}
/* Some Helper Functions */
/* Split a Server Hash to extract the server name from it */
function getServerName($hash) {
list($server, $replicaset, $dbname, $pid) = explode(";", $hash);
return $server;
}
/* Resolve the server type to a readable string */
function getServerType($type) {
switch($type) {
// FIXME: Do we not export these as constants?
case 0x01: return "STANDALONE";
case 0x02: return "PRIMARY";
case 0x04: return "SECONDARY";
case 0x10: return "MONGOS";
}
}
/* Resolve Cursor (Query) Options to something meaningful */
function getCursorOptions($opts) {
// FIXME: Do we not export these as constants?
if (($opts & 0x04) == 0x04) {
return "slaveOkay";
}
return "Primary Only";
}
/* Boilerplate stuff to setup a ReplicaSet connection */
// My replicaset seed list
$seeds = "toddler.local:30200,toddler.local:30201";
// MongoDB Connection options
$moptions = array(
// Don't wait to long on servers that are down
"connectTimeoutMS" => 300,
// Read from secondaries, if available
"readPreference" => MongoClient::RP_SECONDARY_PREFERRED,
// My local ReplicaSet name
"replicaSet" => "REPLICASET",
// Don't wait more then a second to confirm Replication
"wTimeoutMS" => 1000,
);
/* Registering a stream context! This is the fun part! */
// Create an instance of our callback object
$mn = new MongoNotifications;
// No Stream Context Options, for now
$coptions = array();
// Configure the Notification Stream Context Parameter to call MongoNotification->update()
$cparams = array("notification" => array($mn, "update"));
// Create the Stream Context
$ctx = stream_context_create($coptions, $cparams);
$doptions = array("context" => $ctx);
// Instanciate a MongoClient with all our options
$mc = new MongoClient($seeds, $moptions, $doptions);
// Query the example collection in the test database
// you should probably change this to something meaningful
$collection = $mc->selectCollection("test", "example");
// Random search criteria, you should change this to something meaningful
$criteria = array("search" => "criteria");
// Add some sorting & limit for the fun of it
$cursor = $collection->find($criteria)->skip(13)->limit(5)->sort(array("_id" => 1));
// Count on a secondary (we constructed the MongoClient with SECONDARY_PREFERRED)
$count = $cursor->count();
echo "We have $count results in total\n";
// Fetch the data from a primary
$cursor->setReadPreference(MongoClient::RP_PRIMARY);
/* The query isn't execute until we start iterating over it.. */
foreach($cursor as $doc) {
}
// Fetch our requests from our logger
$reqs = $mn->getRequests();
foreach($reqs as $request) {
printf("Hit %s (which is a %s, I asked for %s) with:\n%s\n",
getServerName($request["server"]["hash"]),
getServerType($request["server"]["type"]),
getCursorOptions($request["info"]["options"]),
json_encode($request["query"], JSON_PRETTY_PRINT)
);
printf("Skipping the first %d matches, limiting the results to %d documents..\n",
$request["info"]["skip"],
$request["info"]["limit"]
);
printf("Server execution time+network latency: %.8f sec\n\n", $request["total"]);
}
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment