Anshul Goyal
Anshul Goyal

Reputation: 76987

Understanding the output of mysql.log

I've enabled mysql query log to understand the flow of some mysql queries in my django app. The output of my log file for one flow looks like below, where there is a delay because of a manual debugger I introduced at a step:

160111 17:58:43   131 Connect   root@localhost on database
          131 Query SET NAMES utf8
          131 Query set autocommit=0
          131 Query set autocommit=1
          131 Query SET SQL_AUTO_IS_NULL = 0
          131 Query SELECT foo FROM bar WHERE condition_X
          132 Connect   root@localhost on database
          132 Query SET storage_engine=INNODB
          132 Query SET NAMES utf8
          132 Query set autocommit=0
          132 Query set autocommit=1
          132 Query SET SQL_AUTO_IS_NULL = 0
          132 Query set autocommit=0

160111 17:59:15   131 Query SELECT baz FROM bazbaz WHERE condition_Y
          131 Query SELECT baz FROM bazbaz WHERE condition_Y
          132 Query set autocommit=1
          132 Query set autocommit=0
          132 Query UPDATE bar SET foo = "something" WHERE condition_X
          132 Query commit
          132 Query set autocommit=1

What I can't figure out is, what the numbers 131 and 132 imply - it looks like the queries are related, but why is it being written into the log without order, even though there is a sufficient gap in between the statements? Is there something django specific that I'm missing here?

Upvotes: 1

Views: 66

Answers (1)

Sayse
Sayse

Reputation: 43320

Moving my comments to remove noise and hopefully explain my thinking.

It looks most likely that the 131/132 are an object id

Cut down versions of snippets

160111 17:58:43   131 Connect   root@localhost on database
          # Perform some queries with object 131
          131 Query SELECT foo FROM bar WHERE condition_X 

          # You have now selected a new object so use that id (132)
          132 Connect   root@localhost on database
          # Perform queries with 132

Your second query also follows this pattern, it would appear as though it does some initial actions on the initial parent object with an id of 131 but then you look up a foreign key of 132 to perform more actions.

I imagine it looks incremental as its most likely the fk object was created around the same time as its parent but there is one extra entry in the fk's table.

These logs if the above is correct are generated as instances of LogEntry

Upvotes: 1

Related Questions