MOTOR-132 APM example

doc/examples/index.rst

@@ -7,6 +7,7 @@ Motor Examples
 
    callbacks-and-coroutines
    bulk
+   monitoring
    tailable-cursors
    authentication
    aiohttp_gridfs_example

doc/examples/monitoring.rst

@@ -0,0 +1,91 @@
+.. currentmodule:: motor.motor_tornado
+
+Application Performance Monitoring (APM)
+========================================
+
+Motor implements the same `Command Monitoring`_ and `Topology Monitoring`_ specifications as other MongoDB drivers.
+Therefore, you can register callbacks to be notified of every MongoDB query or command your program sends, and the server's reply to each, as well as getting a notification whenever the driver checks a server's status or detects a change in your replica set.
+
+Motor wraps PyMongo, and it shares PyMongo's API for monitoring. To receive notifications about events, you subclass one of PyMongo's four listener classes, :class:`~pymongo.monitoring.CommandListener`, :class:`~pymongo.monitoring.ServerListener`, :class:`~pymongo.monitoring.TopologyListener`, or :class:`~pymongo.monitoring.ServerHeartbeatListener`.
+
+Command Monitoring
+------------------
+
+Subclass :class:`~pymongo.monitoring.CommandListener` to be notified whenever a command starts, succeeds, or fails.
+
+.. literalinclude:: monitoring_example.py
+  :language: py3
+  :start-after: command logger start
+  :end-before: command logger end
+
+Register an instance of ``MyCommandLogger``:
+
+.. literalinclude:: monitoring_example.py
+  :language: py3
+  :start-after: command logger register start
+  :end-before: command logger register end
+
+You can register any number of listeners, of any of the four listener types.
+
+Although you use only APIs from PyMongo's :mod:`~pymongo.monitoring` module to configure monitoring, if you create a :class:`MotorClient` its commands are monitored, the same as a PyMongo :class:`~pymongo.mongo_client.MongoClient`.
+
+.. literalinclude::
+  :language: py3
+  :start-after: motorclient start
+  :end-before: motorclient end
+
+This logs something like:
+
+.. code-block:: text
+
+  Command insert with request id 50073 started on server ('localhost', 27017)
+  Command insert with request id 50073 on server ('localhost', 27017)
+  succeeded in 362 microseconds
+
+See PyMongo's :mod:`~pymongo.monitoring` module for details about the event data your callbacks receive.
+
+Server and Topology Monitoring
+------------------------------
+
+Subclass :class:`~pymongo.monitoring.ServerListener` to be notified whenever Motor detects a change in the state of a MongoDB server it is connected to.
+
+.. literalinclude:: monitoring_example.py
+  :language: py3
+  :start-after: server logger start
+  :end-before: server logger end
+
+Subclass :class:`~pymongo.monitoring.TopologyListener` to be notified whenever Motor detects a change in the state of your server topology. Examples of such topology changes are a replica set failover, or if you are connected to several mongos servers and one becomes unavailable.
+
+.. literalinclude:: monitoring_example.py
+  :language: py3
+  :start-after: topology logger start
+  :end-before: topology logger end
+
+Motor monitors MongoDB servers with periodic checks called "heartbeats".
+Subclass :class:`~pymongo.monitoring.ServerHeartbeatListener` to be notified whenever Motor begins a server check, and whenever a check succeeds or fails.
+
+.. literalinclude:: monitoring_example.py
+  :language: py3
+  :start-after: heartbeat logger start
+  :end-before: heartbeat logger end
+
+Thread Safety
+-------------
+
+Watch out: Your listeners' callbacks are executed on various background threads, *not* the main thread. To interact with Tornado or Motor from a listener callback, you must defer to the main thread using :meth:`IOLoop.add_callback <tornado.ioloop.IOLoop.add_callback>`, which is the only thread-safe :class:`~tornado.ioloop.IOLoop` method. Similarly, if you use asyncio instead of Tornado, defer your action to the main thread with :meth:`~asyncio.AbstractEventLoop.call_soon_threadsafe`. There is probably no need to be concerned about this detail, however: logging is the only reasonable thing to do from a listener, and `the Python logging module is thread-safe <https://docs.python.org/3/library/logging.html#thread-safety>`_.
+
+Further Information
+-------------------
+
+See also:
+
+* PyMongo's :mod:`~pymongo.monitoring` module
+* `The Command Monitoring Spec`_
+* `The Topology Monitoring Spec`_
+* The `monitoring.py`_ example file in the Motor repository
+
+.. _The Command Monitoring Spec:
+.. _Command Monitoring: https://github.com/mongodb/specifications/blob/master/source/command-monitoring/command-monitoring.rst
+.. _The Topology Monitoring Spec:
+.. _Topology Monitoring: https://github.com/mongodb/specifications/blob/master/source/server-discovery-and-monitoring/server-discovery-and-monitoring-monitoring.rst
+.. _monitoring.py: https://github.com/mongodb/motor/blob/master/doc/examples/monitoring.py

doc/examples/monitoring_example.py

@@ -0,0 +1,132 @@
+# Copyright 2016 MongoDB, Inc.
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+
+"""Application Performance Monitoring (APM) example"""
+
+# command logger start
+import logging
+import sys
+
+from pymongo import monitoring
+
+logging.basicConfig(stream=sys.stdout, level=logging.INFO)
+
+
+class CommandLogger(monitoring.CommandListener):
+    def started(self, event):
+        logging.info("Command {0.command_name} with request id "
+                     "{0.request_id} started on server "
+                     "{0.connection_id}".format(event))
+
+    def succeeded(self, event):
+        logging.info("Command {0.command_name} with request id "
+                     "{0.request_id} on server {0.connection_id} "
+                     "succeeded in {0.duration_micros} "
+                     "microseconds".format(event))
+
+    def failed(self, event):
+        logging.info("Command {0.command_name} with request id "
+                     "{0.request_id} on server {0.connection_id} "
+                     "failed in {0.duration_micros} "
+                     "microseconds".format(event))
+# command logger end
+
+# command logger register start
+monitoring.register(CommandLogger())
+# command logger register end
+
+# motorclient start
+from tornado import gen, ioloop
+from motor import MotorClient
+
+client = MotorClient()
+
+
+async def do_insert():
+    await client.test.collection.insert({'message': 'hi!'})
+
+    # For this example, wait 10 seconds for more monitoring events to fire.
+    await gen.sleep(10)
+
+
+ioloop.IOLoop.current().run_sync(do_insert)
+# motorclient end
+
+# server logger start
+class ServerLogger(monitoring.ServerListener):
+    def opened(self, event):
+        logging.info("Server {0.server_address} added to topology "
+                     "{0.topology_id}".format(event))
+
+    def description_changed(self, event):
+        previous_server_type = event.previous_description.server_type
+        new_server_type = event.new_description.server_type
+        if new_server_type != previous_server_type:
+            logging.info(
+                "Server {0.server_address} changed type from "
+                "{0.previous_description.server_type_name} to "
+                "{0.new_description.server_type_name}".format(event))
+
+    def closed(self, event):
+        logging.warning("Server {0.server_address} removed from topology "
+                        "{0.topology_id}".format(event))
+
+
+monitoring.register(ServerLogger())
+# server logger end
+
+# topology logger start
+class TopologyLogger(monitoring.TopologyListener):
+    def opened(self, event):
+        logging.info("Topology with id {0.topology_id} "
+                     "opened".format(event))
+
+    def description_changed(self, event):
+        logging.info("Topology description updated for "
+                     "topology id {0.topology_id}".format(event))
+        previous_topology_type = event.previous_description.topology_type
+        new_topology_type = event.new_description.topology_type
+        if new_topology_type != previous_topology_type:
+            logging.info(
+                "Topology {0.topology_id} changed type from "
+                "{0.previous_description.topology_type_name} to "
+                "{0.new_description.topology_type_name}".format(event))
+
+    def closed(self, event):
+        logging.info("Topology with id {0.topology_id} "
+                     "closed".format(event))
+
+
+monitoring.register(TopologyLogger())
+# topology logger end
+
+# heartbeat logger start
+class HeartbeatLogger(monitoring.ServerHeartbeatListener):
+    def started(self, event):
+        logging.info("Heartbeat sent to server "
+                     "{0.connection_id}".format(event))
+
+    def succeeded(self, event):
+        logging.info("Heartbeat to server {0.connection_id} "
+                     "succeeded with reply "
+                     "{0.reply.document}".format(event))
+
+    def failed(self, event):
+        logging.warning("Heartbeat to server {0.connection_id} "
+                        "failed with error {0.reply}".format(event))
+
+
+monitoring.register(HeartbeatLogger())
+# heartbeat logger end