mrsarm / mongotail

Command line tool to log all MongoDB queries in a "tail"able way
https://pypi.org/project/mongotail/
GNU General Public License v3.0
192 stars 17 forks source link

mongotail just closes #19

Closed Parziphal closed 7 years ago

Parziphal commented 7 years ago

Hello, I installed mongotail and run it like:

mongotail myDbName

but nothing happens, the program just closes after less than a second. It's a local db, it has no password or anything. I don't know if mongotail logs anything, I did a quick search and found no logs.

mrsarm commented 7 years ago

Before execute Mongotail you have to active the MongoDB profiler of the database. You can achive this also with Mongotail executing:

mongotail myDbName -l 2

Then the MongoDB engine will start to record your queries, so you can execute:

mongotail myDbName

To see the latest 10 queries and exit, or execute the same command with the -f option to wait for more queries and see them in real time. More option check the --help option, of for a more complete guide see this post from my blog.

Tell me if this help you so I can close this issue or check what is wrong.

Parziphal commented 7 years ago

Yes I tried the -l 2 option, but I just realized it was another thing. I thought it would show real time logging by default, but I needed the -f option.

Now some queries are shown, but then the program still closes, not before showing this error trace:

Traceback (most recent call last):
  File "/usr/local/bin/mongotail", line 9, in <module>
    load_entry_point('mongotail==2.1.0', 'console_scripts', 'mongotail')()
  File "/usr/local/lib/python2.7/dist-packages/mongotail/mongotail.py", line 237, in main
    tail(client, db, args.n, args.follow, args.verbose, args.metadata)
  File "/usr/local/lib/python2.7/dist-packages/mongotail/mongotail.py", line 81, in tail
    print_obj(result, verbose, metadata, client.server_info()['version'])
  File "/usr/local/lib/python2.7/dist-packages/mongotail/out.py", line 51, in print_obj
    doc = obj['query']['find']
TypeError: string indices must be integers
mrsarm commented 7 years ago

So now we have a real bug :-)

  1. What OS do you have?
  2. What version of MongoDB do you have? (you can check it with mongotail myDbName -i)
  3. What version of PyMongo do you have? (you can check it with python -c 'import pymongo; print pymongo.__version__')
  4. What kind of DB operation you are trying to execute?

Try to execute also mongotail myDbName -v to see more details of the operations and send me, please.

Parziphal commented 7 years ago
  1. Ubuntu 14.04.2 LTS
  2. MongoDB v3.2.7
  3. Python v3.4.0
  4. I'm trying to log ParseServer queries.

mongotail myDbName -v output is very large. Is there a specific key you need?

Here are some test queries that are being performed:

{ skip: undefined, limit: 1, sort: {}, keys: {} }
{ _id: 'M35' }

{ skip: undefined, limit: undefined, sort: {}, keys: {} }
{ type: 'someType' }

{ skip: undefined, limit: 15, sort: { count: 1 }, keys: {} }
{ _p_lang: 'Lang$M35',
  used: { '$ne': true },
  _p_pic: 
   { '$in': [ very long string array (10k+ items)... ] } }

{ skip: undefined, limit: undefined, sort: {}, keys: {} }
{ _id: 
   { '$in': 
      [ string array...  ] } }
mrsarm commented 7 years ago

mm... I need the instruction that is crashing the app, it's happening after a specific action? like create a new kind of registry in your DB, the startup of the application... you can use the -v option to get the logs in verbose mode only when the error is triggered with that action.

Parziphal commented 7 years ago

I think it's because this weird query that uses a really long array of 10k+ strings in an $in. When this query is executed is when the error occurs. Maybe it's too much to handle for mongotail? I wouldn't blame it.

mrsarm commented 7 years ago

mm shouldn't be that, and I tested a query with the $in operator:

db.users.find({"origin": {"$in": ["site","mobile"]}})

And it's logged without problem:

2017-01-16 22:12:55.736 QUERY     [users] : {"origin": {"$in": ["site", "mobile"]}}. 18 returned.
mrsarm commented 7 years ago

Sorry, I didn't see the last part of one of your responses with this example:

{ skip: undefined, limit: 1, sort: {}, keys: {} }
{ _id: 'M35' }

{ skip: undefined, limit: undefined, sort: {}, keys: {} }
{ type: 'someType' }

{ skip: undefined, limit: 15, sort: { count: 1 }, keys: {} }
{ _p_lang: 'Lang$M35',
  used: { '$ne': true },
  _p_pic: 
   { '$in': [ very long string array (10k+ items)... ] } }

{ skip: undefined, limit: undefined, sort: {}, keys: {} }
{ _id: 
   { '$in': 
      [ string array...  ] } }

All these registries are unknown for me, it must be that, but I don't understand why this registries are logged, what is for example skip: undefined ? I can add these patterns to the list of exceptions when Mongotail reads from the profiler's collection.

This line in the example is the full line or just a part?:

{ _id: 'M35' }

I need the full line to understand what kind of logging is. If there is a sensitive data logged you can change the value anyway, but please don't remove "columns" from the JSON.

Parziphal commented 7 years ago

Oh no, those aren't logs by mongotail, those are actually "console.log" outputs (with some edits) of the queries that I was performing, I posted them because you asked me what operations I was doing. As you can see in the third query, there's an $in operator but that array has over 10000+ items (not 2, 5, 10, but 10000+), and when that query is run is when mongotail crashes.

mrsarm commented 7 years ago

Ok @Parziphal, I understand you, but i don't think that the problem is the big array. At the bottom of the error is described what error is and where is launched:

    doc = obj['query']['find']
TypeError: string indices must be integers

The TypeError error is launched when you are trying to access a position from a string in Python without an integer. Eg:

obj = 'Hello world'
obj['query']

A correct access in this case is obj[0]. But in the case of Mongotail, the object obj and the object pointed by obj['query'] must allways been dict instances.

I made a commit in the repo to avoid exit the program on TypeError exceptions, and dump the output with warn messages instead.

This patch is not released yet, but can try this version cloning the Mongotail repo and installing it with sudo python setup.py install, or without cloning, just executing: sudo pip install https://github.com/mrsarm/mongotail/archive/master.zip

Parziphal commented 7 years ago

I'm performing explain() operations too, and I get these EXCEPTIONS:

Mongotail EXCEPTION - Unknown command operation
Dump: {"ns": "myDb.Photo", "command": {"explain": {"filter": {"type": "post"}, "sort": {}, "find": "Photo"}}, "ts": ISODate("2017-01-18T14:10:46.505Z"), "op": "command"}
Mongotail EXCEPTION - Unknown registry
Dump: {"ns": "myDb.Photo", "command": {"explain": {"filter": {"type": "post"}, "sort": {}, "find": "Photo"}}, "ts": ISODate("2017-01-18T14:10:46.505Z"), "op": "command"}
Mongotail EXCEPTION - Unknown command operation
Dump: {"ns": "myDb._SCHEMA", "command": {"explain": {"filter": {"_id": "Post"}, "limit": 1, "find": "_SCHEMA"}}, "ts": ISODate("2017-01-18T14:10:48.334Z"), "op": "command"}
Mongotail EXCEPTION - Unknown registry
Dump: {"ns": "myDb._SCHEMA", "command": {"explain": {"filter": {"_id": "Post"}, "limit": 1, "find": "_SCHEMA"}}, "ts": ISODate("2017-01-18T14:10:48.334Z"), "op": "command"}
2017-01-18 14:10:48.335 QUERY     [_SCHEMA] : {"_id": "Post"}. 1 returned.

I installed the master version and Mongotail no longer crashes and the error is shown in the console, but I can't get the whole output because the long array fills the screen completely.

The problem query looks like this with the $in array empty:

2017-01-18 14:37:08.727 QUERY     [Post] : {"used": {"$ne": true}, "_p_photo": {"$in": []}, "_p_language": "C6zD77sSNR"}, sort: {"count": 1}. 0 returned.

When it's empty it works. When it's not, it doesn't.

I've also modified my data so I get one id in the $in array (instead of 10k) and the query works fine. I think the error is definitely caused by the length of the array.

I think I've noticed something interesting. Here's the last line of the error that is thrown by Mongotail (the master version) when the problem query is performed:

6cqD7\", \"Photo$aiAoeuUGt2\", \"Photo$9JqPMZPr...", "ns": "myDB.Post", "ts": ISODate("2017-01-18T14:50:34.372Z"), "nreturned": 15, "op": "query"}

The value of the previous key is a string that ends with three dots. It seems like the query is converted to string due to the length of the array? I don't know if that makes sense... I actually have no idea.

Well, that's all the info I could get.

mrsarm commented 7 years ago

Thanks @Parziphal for your help. I thinking you have right, maybe the PyMongo controller or the MongoDB engine itself changes the type of the obj['query'] to a str type instead of a dict type to save memory. Unfortunately I cannot format properly the output in these cases so I have to log them as the latest patch with a:

Mongotail EXCEPTION - Unknown command operation
Dump: {"ns": "myDb.Photo", "command": {"explain": {"fil...

But anyway you can see the query in this way instead of get mongotail crashed.

I released the version 2.1.1 with this fix, and with a fix to filter the explain commands too.