pBlueG / SA-MP-MySQL

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

INFO log level makes crash. #195

Closed Dayrion closed 6 years ago

Dayrion commented 6 years ago

Hello there. On my test & local server, I've set INFO log level since a long time and recently, for apparently no reason, it makes crash my server with the error bellow. I'm using MySQL R41-4. I got no problem with that in the past.

On linux (test server) [05/21/18 10:58:57] [log-core] signal 11 (SIGSEGV) catched; shutting log-core down (errno: 0, signal code: 1, exit status: -620786841) On windows (w8.1 - local server) [05/21/18 11:20:41] [log-core] exception 0XC0000005 (ACCESS_VIOLATION) from Unhandled Exception Handler catched; shutting log-core down

The line of code: mysql_log(ERROR | WARNING | INFO);

maddinat0r commented 6 years ago

Could you provide (upload it here or send me an email) your mysql.log file? Can you reliably reproduce the crash?

Dayrion commented 6 years ago

It doesn't provide any useful informations. The error isn't even written in the errors.log file, only on log-core.log It happens only with this gamemode. I tried with an another one enabling ALL logs and I don't get any crash. The crash occurs at the same time, everytime. removed

Edit: I tried some configurations and only INFO log level makes crash.

maddinat0r commented 6 years ago

This might be related to #189. If I correctly understood, it also crashes with full logging enabled. Can you delete your log files, enable full logging, reproduce this again and provide the new mysql.log file again?

Dayrion commented 6 years ago

I took a look about "Crashes when using non existant callback" but, unfortunaly, every public functions exist and they are called correctly without INFO log level. Don't mind me if I'm completly wrong. Log file with ALL debug levels: mysql.log

maddinat0r commented 6 years ago

Seems like your OnWeaponsEquipementLoading callback has a negative index. Are you sure it exists in your gamemode?

Sunehildeep commented 6 years ago

Same problem here, crashing after I log in. It didn't happen before, now happening all of a sudden.

maddinat0r commented 6 years ago

@Sunehildeep Can you reliably reproduce this crash? If so, delete your MySQL plugin log file, enable full logging, reproduce this and provide me your mysql.log file.

Dayrion commented 6 years ago

That's right. I'm so stupid lmao. I compiled with the "preprocessed" mode to check out and callback existed but the file where it was supposed existed wasn't included for some reasons. So it's just exactly the same thing as #189. I'm so sorry for the wasted time.

Sunehildeep commented 6 years ago

Okay so, here it is, first of all the MySQL.log keeps logging the old data first of the loading of vehicles, business, etc from database for a while and I get stuck on the class request screen after logging in, then after around 2 minutes, it starts loading my data and starts calling the callback of the player load data, after loading it crashes.

[21:40:38] [DEBUG] cache_get_value_name_int: assigned value: '0' (\script.pwn:4422)
[21:40:38] [DEBUG] cache_get_value_name_int: return value: '1' (\script.pwn:4422)
[21:40:38] [DEBUG] cache_get_value_name_int(0, "pOwnedVehicles5", 0x04B40E70) (\script.pwn:4422)
[21:40:38] [DEBUG] cache_get_value_name_int: assigned value: '0' (\script.pwn:4422)
[21:40:38] [DEBUG] cache_get_value_name_int: return value: '1' (\script.pwn:4422)
[21:40:38] [DEBUG] mysql_tquery(1, "SELECT * FROM rp_chemical WHERE Owner = 6 LIMIT 10", "Chemical_Load", "i") (\script.pwn:4434)
[21:40:38] [DEBUG] CCallback::Create(amx=0x2a25b80, name='Chemical_Load', format='i', params=0x640f52c, param_offset=5)
[21:40:38] [DEBUG] CCallback::Create - callback index for 'Chemical_Load': 39
[21:40:38] [DEBUG] processing specifier 'i' with parameter index 0
[21:40:38] [DEBUG] retrieved and pushed value '0'
[21:40:38] [INFO] Callback 'Chemical_Load' set up for delayed execution.
[21:40:38] [DEBUG] created delayed callback with 1 parameter
[21:40:38] [DEBUG] CHandle::Execute(this=0x6725748, type=1, query=0x6b1f058)
[21:40:38] [DEBUG] CHandle::Execute - return value: true
[21:40:38] [DEBUG] mysql_tquery: return value: '1' (\script.pwn:4434)
[21:40:38] [DEBUG] CConnection::Execute(query=0x6b1f058, this=0x68a4020, connection=0x6751ae0)
[21:40:38] [DEBUG] CQuery::Execute(this=0x6b1f058, connection=0x6751ae0)
[21:40:38] [INFO] query "SELECT * FROM rp_chemical WHERE Owner = 6 LIMIT 10" successfully executed within 112.241 milliseconds
[21:40:38] [DEBUG] CResultSet::Create(connection=0x6751ae0, query_str='SELECT * FROM rp_chemical WHERE Owner = 6 LIMIT 10')
[21:40:38] [DEBUG] created new resultset '0x6bf79c0'
[21:40:38] [DEBUG] fetched MySQL result '0x6c034c8'
[21:40:38] [DEBUG] allocated 360 bytes for PAWN result

And this is the crash error from log-core


[21:40:38] [log-core] exception 0XC0000005 (ACCESS_VIOLATION) from Vectored Exception Handler catched; shutting log-core down
maddinat0r commented 6 years ago

@Dayrion No worries there. I'm glad we found the cause that quick! @Sunehildeep Does your crash happen if you disable the INFO loglevel?

Sunehildeep commented 6 years ago

Happens even without logging EDIT: I found the problem, it was a hooking problem, you can close it now

mhyunata commented 1 year ago

Happens even without logging EDIT: I found the problem, it was a hooking problem, you can close it now

what hookng you mean?