Tracing the calls made to Mongo

[Chetan Mehrotra <ch...@gmail.com>]

Hi,

To get a better understanding about the nature of remote calls being made
to Mongo from Oak code I have modified the mongo java driver [1] to log
details of calls being made through it along with time taken. To make use
of that following steps would be required

A. Build forked driver code
---------

$ git clone https://github.com/chetanmeh/mongo-java-driver.git
$ cd mongo-java-driver
$ git checkout tracer
$ mvn clean install -DskipTests

This would install the modified version of the driver to local maven repo.

B. Use the modified build
----------
Modify the pom.xml of the module and change the version to
org.mongodb:mongo-java-driver:2.10.2-SNAPSHOT

C. Change log settings
----------
Update the <module>/src/test/resources/logback-test.xml to enable debug
logs for following category

 <logger name="com.mongodb.DBPort" level="DEBUG" />

Run the testcase now and you should be able to see query logs as shown below

...
16:28:53.415  Request : Id: 11 (0 ms) OP_QUERY, { "getlasterror" : 1}
16:28:53.417  Request : Id: 12 (0 ms) OP_QUERY, [NODES] { "_id" : "1:/test"}
16:28:53.419  Request : Id: 13 (0 ms) OP_INSERT, [NODES]
16:28:53.420  Request : Id: 14 (1 ms) OP_QUERY, { "getlasterror" : 1}
16:28:53.421  Request : Id: 15 (0 ms) OP_INSERT, [NODES]
16:28:53.422  Request : Id: 16 (0 ms) OP_QUERY, { "getlasterror" : 1}
16:28:53.424  Request : Id: 17 (0 ms) OP_QUERY, [NODES] { "_id" : "1:/test"}
16:28:53.429  Request : Id: 18 (1 ms) OP_QUERY, [NODES] { "_id" : { "$gte"
: "1:/" , "$lt" : "2:/"}}
16:28:53.433  Request : Id: 19 (1 ms) OP_QUERY, [NODES] { "_id" : { "$gte"
: "2:/test/" , "$lt" : "3:/test/"}}

This might help someone to make some sense of type of calls being performed

Chetan Mehrotra

[1] https://github.com/chetanmeh/mongo-java-driver/compare/tracer