fix(libs): bug in _pymongo (#558)

- clear logging format
- fix #557

DOC/PY/Readme.md

@@ -6,10 +6,9 @@
 
 Dependency| Version| More
 ---|----|---
-python |2.7,3+ | (async must 3.7.1+)
+python |3+ | (async must 3.7.1+)
 GO | | 
 gcc|gcc 4.7+| c++11
-cmake| 3.1+| 
 *inux|  | `windows` is on the way
 pinpoint| 2.0+(GRPC)|
 collector-agent| [installed ?](../collector-agent/readme.md)
@@ -40,6 +39,11 @@ app.wsgi_app = PinPointMiddleWare(app,app.wsgi_app)
 settings.py
 
 ```python
+from pinpointPy import set_agent, monkey_patch_for_pinpoint, use_thread_local_context
+use_thread_local_context()
+monkey_patch_for_pinpoint()
+set_agent("cd.dev.test.py", "cd.dev.test.py",
+          'tcp:dev-collector:10000', -1)
 
 MIDDLEWARE = [
     'pinpointPy.Django.DjangoMiddleWare',
@@ -50,8 +54,6 @@ MIDDLEWARE = [
 #### 1.3 Fastapi
 Settings in app/main.py:
 ```
-# pinpoint
-##############################################
 from starlette_context.middleware import ContextMiddleware
 from starlette_context import context, plugins
 
@@ -64,9 +66,12 @@ middleware = [
     Middleware(ContextMiddleware),
     Middleware(PinPointMiddleWare)
 ]
-asyn_monkey_patch_for_pinpoint()
-set_agent("fastapi-redis", "fastapi-redis", 'tcp:collect-agent:9999', -1, True)
-##############################################
+set_agent("cd.dev.test.py", "cd.dev.test.py", 'tcp:dev-collector:10000')
+use_starlette_context()
+## patch for synchronous libraries, such as requests,myql-connector-python ...
+# support lists https://github.com/pinpoint-apm/pinpoint-c-agent/tree/dev/plugins/PY/pinpointPy/libs
+monkey_patch_for_pinpoint()
+async_monkey_patch_for_pinpoint()
 ```
 Example: [fastapi-redis-pinpoint](https://github.com/EyelynSu/fastapi-redis-pinpoint)
 
@@ -111,19 +116,6 @@ Todo....
 > Example [py-web2](https://github.com/eeliu/pinpoint-in-pyweb2)
 
 
-### 2. Configuration
-
-
-```py
-
-# enable auto-interceptor plugins
-monkey_patch_for_pinpoint()
-# set pinpoint related environment
-set_agent("flask-agent","FLASK-AGENT",'tcp:dev-collector:9999',-1)
-
-```
-
-
 ## Performance Test Result
 
 ### Case: flask/test_mysql

plugins/PY/pinpointPy/Fastapi/__init__.py

@@ -18,6 +18,8 @@
 # ------------------------------------------------------------------------------
 
 import importlib
+import warnings
+
 from pinpointPy.Fastapi.PinTranscation import PinTransaction, PinStarlettePlugin
 from pinpointPy.Fastapi.AsyCommonPlugin import CommonPlugin
 from pinpointPy.Fastapi.AsyCommon import AsyncTraceContext
@@ -38,8 +40,15 @@ def __monkey_patch(*args, **kwargs):
                 monkey_patch()
 
 
-def async_monkey_patch_for_pinpoint(AioRedis=True, MotorMongo=True, httpx=True):
-    __monkey_patch(_aioredis=AioRedis, _MotorMongo=MotorMongo, _httpx=httpx)
+def async_monkey_patch_for_pinpoint(AioRedis=True, httpx=True):
+    __monkey_patch(_aioredis=AioRedis, _httpx=httpx)
+
+
+def asyn_monkey_patch_for_pinpoint(
+        AioRedis=True, httpx=True):
+    warnings.warn(
+        "deprecated try to use `async_monkey_patch_for_pinpoint`", DeprecationWarning)
+    async_monkey_patch_for_pinpoint(AioRedis, httpx)
 
 
 def use_starlette_context():
@@ -48,5 +57,5 @@ def use_starlette_context():
 
 __version__ = '0.0.2'
 __author__ = '[email protected]'
-__all__ = ['async_monkey_patch_for_pinpoint', 'use_starlette_context', 'PinPointMiddleWare',
+__all__ = ['async_monkey_patch_for_pinpoint', 'asyn_monkey_patch_for_pinpoint', 'use_starlette_context', 'PinPointMiddleWare',
            'CommonPlugin', 'PinTransaction', 'PinHeader', 'GenPinHeader', 'PinStarlettePlugin']

plugins/PY/pinpointPy/Fastapi/_aioredis/__init__.py

@@ -36,7 +36,7 @@ def monkey_patch():
             interceptor.enable()
 
     except ImportError as e:
-        get_logger().debug(f"not found aioredis. {e}")
+        get_logger().info(f"exception at {e}")
 
 
 __all__ = ['monkey_patch']

plugins/PY/pinpointPy/Fastapi/_httpx/__init__.py

@@ -35,9 +35,7 @@ def monkey_patch():
         for interceptor in Interceptors:
             interceptor.enable()
     except ImportError as e:
-        get_logger().debug(f"import httpx:{e}")
-    except:
-        get_logger().info(f"unknown error in httpx module")
+        get_logger().info(f"exception at {e}")
 
 
 __all__ = ['monkey_patch']

plugins/PY/pinpointPy/libs/_MysqlConnector/__init__.py

@@ -48,7 +48,7 @@ def monkey_patch():
         for interceptor in Interceptors:
             interceptor.enable()
     except ImportError as e:
-        get_logger().warning(f'import _mysql_connector {e}')
+        get_logger().info(f"exception at {e}")
         import sys
         if 'unittest' in sys.modules.keys():
             raise e

plugins/PY/pinpointPy/libs/__init__.py

@@ -26,7 +26,7 @@ def __monkey_patch(*args, **kwargs):
                 try:
                     monkey_patch()
                 except Exception as e:
-                    get_logger().info(f'exception at {e}')
+                    get_logger().info(f'monkey_patch exception:{e}')
 
 
 def monkey_patch_for_pinpoint(pymongo=True,

plugins/PY/pinpointPy/libs/_pyRedis/__init__.py

@@ -38,7 +38,7 @@ def monkey_patch():
             interceptor.enable()
 
     except ImportError as e:
-        get_logger().info(f'redis interceptor at {e}')
+        get_logger().info(f'exception at {e}')
 
 
 __all__ = ['monkey_patch']

plugins/PY/pinpointPy/libs/_pymongo/MongoClientPlugin.py

@@ -19,37 +19,67 @@
 
 # Created by eeliu at 8/20/20
 
-from pinpointPy import Common
-from pinpointPy import pinpoint
-from pinpointPy import Defines
+from pinpointPy import Common, pinpoint, Defines, get_logger
+from pymongo import monitoring
 
 
 class MongoClientPlugin(Common.PinTrace):
     def __init__(self, name):
         super().__init__(name)
+        self.trace_id = -1
 
     def onBefore(self, parentId, *args, **kwargs):
         traceId, args, kwargs = super().onBefore(parentId, *args, **kwargs)
-        collection = args[0]
-        try:
-            dst = str(collection.__database.address)
-        except AttributeError:
-            dst = collection.name
+        event = args[0]
+        assert isinstance(event, monitoring.CommandStartedEvent)
         pinpoint.add_trace_header(
-            Defines.PP_INTERCEPTOR_NAME, self.getUniqueName(), traceId)
+            Defines.PP_INTERCEPTOR_NAME, event.command_name, traceId)
         pinpoint.add_trace_header(
             Defines.PP_SERVER_TYPE, Defines.PP_MONGDB_EXE_QUERY, traceId)
-        pinpoint.add_trace_header(Defines.PP_DESTINATION, dst, traceId)
+        pinpoint.add_trace_header(
+            Defines.PP_DESTINATION, event.database_name, traceId)
+        self.trace_id = traceId
         return traceId, args, kwargs
 
     def onEnd(self, traceId, ret):
-        # disable PP_RETURN
-        # unreadable format
-        # pymongo.cursor.Cursor object at 0x7f9dc76adaf0
-        # InsertManyResult([ObjectId('6553441f7ef332013afc40a2'), ObjectId('6553441f7ef332013afc40a3')], acknowledged=True)
-        # pinpoint.add_trace_header_v2(Defines.PP_RETURN, str(ret), traceId)
-        super().onEnd(traceId, ret)
+        super().onEnd(self.trace_id, ret)
         return ret
 
     def onException(self, traceId, e):
-        pinpoint.add_trace_header(Defines.PP_ADD_EXCEPTION, str(e), traceId)
+        pinpoint.add_trace_header(
+            Defines.PP_ADD_EXCEPTION, str(e), self.trace_id)
+
+
+class CommandLogger(monitoring.CommandListener):
+
+    def __init__(self) -> None:
+        self.request_id_map = {}
+
+    def started(self, event):
+        sampled, parentId, _, _ = MongoClientPlugin.isSample()
+        if not sampled:
+            return
+        request_id = event.request_id
+
+        if request_id in self.request_id_map:
+            get_logger().info("started listener called with wrong order, maybe a bug")
+            return
+
+        watcher = MongoClientPlugin("monitoring.CommandListener")
+        watcher.onBefore(parentId, event)
+        self.request_id_map[request_id] = watcher
+
+    def succeeded(self, event):
+        request_id = event.request_id
+        if request_id in self.request_id_map:
+            watcher = self.request_id_map[request_id]
+            watcher.onEnd(0, None)
+            del self.request_id_map[request_id]
+
+    def failed(self, event):
+        request_id = event.request_id
+        if request_id in self.request_id_map:
+            watcher = self.request_id_map[request_id]
+            watcher.onException(0, event.failure)
+            watcher.onEnd(0, None)
+            del self.request_id_map[request_id]

plugins/PY/pinpointPy/libs/_pymongo/__init__.py

@@ -26,27 +26,14 @@
 def monkey_patch():
 
     try:
-        from pymongo.collection import Collection
-        from .MongoClientPlugin import MongoClientPlugin
-        Interceptors = [
-            Interceptor(Collection, 'find', MongoClientPlugin),
-            # Interceptor(Collection, 'insert', MongoClientPlugin),
-            # Interceptor(Collection, 'update', MongoClientPlugin),
-            Interceptor(Collection, 'update_many', MongoClientPlugin),
-            Interceptor(Collection, 'delete_one', MongoClientPlugin),
-            Interceptor(Collection, 'delete_many', MongoClientPlugin),
-            Interceptor(Collection, 'insert_many', MongoClientPlugin),
-            Interceptor(Collection, 'insert_one', MongoClientPlugin),
-        ]
-
-        for interceptor in Interceptors:
-            interceptor.enable()
-
+        from pymongo import monitoring
+        from .MongoClientPlugin import CommandLogger
+        monitoring.register(CommandLogger())
     except ImportError as e:
         get_logger().info(f'exception at {e}')
 
 
 __all__ = ['monkey_patch']
 
-__version__ = '0.0.2'
+__version__ = '0.0.4'
 __author__ = '[email protected]'

plugins/PY/pinpointPy/libs/_sqlalchemy/__init__.py

@@ -35,7 +35,7 @@ def monkey_patch():
         for interceptor in Interceptors:
             interceptor.enable()
     except ImportError as e:
-        get_logger().debug(f"import _sqlalchemy: {e}")
+        get_logger().info(f"exception at {e}")
 
 
 __all__ = ['monkey_patch']