pBlueG / SA-MP-MySQL

MySQL plugin for San Andreas Multiplayer
BSD 3-Clause "New" or "Revised" License
196 stars 80 forks source link

Callback set up for delayed execution #214

Closed maziluradu closed 5 years ago

maziluradu commented 5 years ago

Hello,

I am having an issue with a query which is having a very slow execution time: ~4.5 seconds for a SELECT query, which when I call from an ASP.NET WebApi it only takes a couple of hundred of ms.

These are the logs:

[05/19/19 16:15:14] [DEBUG] mysql_tquery(1, "SELECT * FROM players WHERE user_login='Radu' LIMIT 1", "OnPlayerCheckAccount", "d") (gamemodes\redzmax.pwn:17 -> gamemodes\redzmax.pwn:16)
[05/19/19 16:15:14] [DEBUG] CCallback::Create(amx=0x85d2950, name='OnPlayerCheckAccount', format='d', params=0xf5320d14, param_offset=5)
[05/19/19 16:15:14] [DEBUG] CCallback::Create - callback index for 'OnPlayerCheckAccount': 1846
[05/19/19 16:15:14] [DEBUG] processing specifier 'd' with parameter index 0
[05/19/19 16:15:14] [DEBUG] retrieved and pushed value '0'
[05/19/19 16:15:14] [INFO] Callback 'OnPlayerCheckAccount' set up for delayed execution.
[05/19/19 16:15:14] [DEBUG] created delayed callback with 1 parameter
[05/19/19 16:15:14] [DEBUG] CHandle::Execute(this=0x8766248, type=1, query=0x886515c)
[05/19/19 16:15:14] [DEBUG] CConnection::Execute(query=0x886515c, this=0xf2ed0008, connection=0x8789718)
[05/19/19 16:15:14] [DEBUG] CQuery::Execute(this=0x886515c, connection=0x8789718)
[05/19/19 16:15:14] [DEBUG] CHandle::Execute - return value: true
[05/19/19 16:15:14] [DEBUG] mysql_tquery: return value: '1' (gamemodes\redzmax.pwn:17 -> gamemodes\redzmax.pwn:16)
[05/19/19 16:15:14] [INFO] query "SELECT * FROM players WHERE user_login='Radu' LIMIT 1" successfully executed within 4.394 milliseconds

What I noticed is this: "Callback 'OnPlayerCheckAccount' set up for delayed execution". In what circumstances does this happen and why? And how can I avoid this?

maddinat0r commented 5 years ago

It's 4.394 (~4) milliseconds, not 4.394 seconds. The callback info log message is just that - an info. It's not an error or warning, it only reports that it did what it was supposed to do: prepare the specified callback to be executed at a later time (i.e. after the query finishes as the result callback).