Async SQL + SSdbcore (#15007)

* Initial Commit - Async SQL

* First batch of queries

* More progress

* Nukes DB Polls

* More work

* oops

* One push

* Notes work now

* Ok these work

* Watchlist done

* Async Bans!

* Async Permissions

* Async client procs

* I officially hate preference datums

* Also these

* Async Custom Items

* Async Karma

* Async Library

* Async TOS

* Cleans out the old SQL code

* CI Sanity

* Apparently MySQL doesnt support this

* What about this

* Maybe this

* Review pass 1

* This too

* Fixes job ban loading

* Fix undeleted queries

* Prevents sensitive queries being logged

* Documentation + tweaks

* Adds a verb to force reconnect the DB

* More review tweaks

* Farie tweaks

* Fixes this
This commit is contained in:
AffectedArc07
2020-12-16 15:46:25 -05:00
committed by GitHub
parent e003d552b0
commit 2bad70717c
55 changed files with 2251 additions and 2445 deletions
+10 -12
View File
@@ -268,6 +268,12 @@
/// URL for the CentCom Ban DB API
var/centcom_ban_db_url = null
/// Timeout (seconds) for async SQL queries
var/async_sql_query_timeout = 10 SECONDS
/// Limit of how many SQL threads can run at once
var/rust_sql_thread_limit = 50
/datum/configuration/New()
for(var/T in subtypesof(/datum/game_mode))
var/datum/game_mode/M = T
@@ -872,21 +878,13 @@
sqlfdbktableprefix = value
if("db_version")
sql_version = text2num(value)
if("async_query_timeout")
async_sql_query_timeout = text2num(value)
if("rust_sql_thread_limit")
config.rust_sql_thread_limit = text2num(value)
else
log_config("Unknown setting in configuration: '[name]'")
// The unit tests have their own version of this check, which wont hold the server up infinitely, so this is disabled if we are running unit tests
#ifndef UNIT_TESTS
if(config.sql_enabled && sql_version != SQL_VERSION)
config.sql_enabled = 0
log_config("WARNING: DB_CONFIG DEFINITION MISMATCH!")
spawn(60)
if(SSticker.current_state == GAME_STATE_PREGAME)
SSticker.ticker_going = FALSE
spawn(600)
to_chat(world, "<span class='alert'>DB_CONFIG MISMATCH, ROUND START DELAYED. <BR>Please check database version for recent upstream changes!</span>")
#endif
/datum/configuration/proc/loadoverflowwhitelist(filename)
var/list/Lines = file2list(filename)
for(var/t in Lines)
+43 -36
View File
@@ -21,19 +21,18 @@ SUBSYSTEM_DEF(changelog)
/datum/controller/subsystem/changelog/Initialize()
// This entire subsystem relies on SQL being here.
if(!GLOB.dbcon.IsConnected())
if(!SSdbcore.IsConnected())
return ..()
var/DBQuery/latest_cl_date = GLOB.dbcon.NewQuery("SELECT UNIX_TIMESTAMP(date_merged) AS ut FROM [format_table_name("changelog")] ORDER BY date_merged DESC LIMIT 1")
if(!latest_cl_date.Execute())
var/err = latest_cl_date.ErrorMsg()
log_game("SQL ERROR during SSchangelog initialization L24. Error: \[[err]\]\n")
message_admins("SQL ERROR during SSchangelog initialization L24. Error: \[[err]\]\n")
var/datum/db_query/latest_cl_date = SSdbcore.NewQuery("SELECT CAST(UNIX_TIMESTAMP(date_merged) AS CHAR) AS ut FROM [format_table_name("changelog")] ORDER BY date_merged DESC LIMIT 1")
if(!latest_cl_date.warn_execute())
qdel(latest_cl_date)
// Abort if we cant do this
return ..()
while(latest_cl_date.NextRow())
current_cl_timestamp = latest_cl_date.item[1]
qdel(latest_cl_date)
if(!GenerateChangelogHTML()) // if this failed to generate
to_chat(world, "<span class='alert'>WARNING: Changelog failed to generate. Please inform a coder/server dev</span>")
@@ -62,18 +61,22 @@ SUBSYSTEM_DEF(changelog)
else
winset(C, "rpane.changelog", "background-color=none;font-style=none")
C.prefs.lastchangelog = current_cl_timestamp
var/DBQuery/updatePlayerCLTime = GLOB.dbcon.NewQuery("UPDATE [format_table_name("player")] SET lastchangelog='[sanitizeSQL(current_cl_timestamp)]' WHERE ckey='[C.ckey]'")
if(!updatePlayerCLTime.Execute())
var/err = updatePlayerCLTime.ErrorMsg()
log_game("SQL ERROR during lastchangelog updating. Error: \[[err]\]\n")
message_admins("SQL ERROR during lastchangelog updating. Error: \[[err]\]\n")
to_chat(C, "Couldn't update your last seen changelog, please try again later.")
return FALSE
return TRUE
var/datum/db_query/updatePlayerCLTime = SSdbcore.NewQuery(
"UPDATE [format_table_name("player")] SET lastchangelog=:lastchangelog WHERE ckey=:ckey",
list(
"lastchangelog" = current_cl_timestamp,
"ckey" = C.ckey
)
)
// We dont do anything with this query so we dont care about errors too much
updatePlayerCLTime.warn_execute()
qdel(updatePlayerCLTime)
/datum/controller/subsystem/changelog/proc/UpdatePlayerChangelogButton(client/C)
// If SQL aint even enabled, just set the button to default style
if(!GLOB.dbcon.IsConnected())
if(!SSdbcore.IsConnected())
if(C.prefs.toggles & PREFTOGGLE_UI_DARKMODE)
winset(C, "rpane.changelog", "background-color=#40628a;text-color=#FFFFFF")
else
@@ -104,7 +107,7 @@ SUBSYSTEM_DEF(changelog)
/datum/controller/subsystem/changelog/proc/OpenChangelog(client/C)
// If SQL isnt enabled, dont even queue them, just tell them it wont work
if(!GLOB.dbcon.IsConnected())
if(!SSdbcore.IsConnected())
to_chat(C, "<span class='notice'>This server is not running with an SQL backend. Changelog is unavailable.</span>")
return
@@ -173,15 +176,14 @@ SUBSYSTEM_DEF(changelog)
var/list/prs_to_process = list()
// Grab all from last 30 days
var/DBQuery/pr_list_query = GLOB.dbcon.NewQuery("SELECT DISTINCT pr_number FROM changelog WHERE date_merged BETWEEN NOW() - INTERVAL 30 DAY AND NOW() ORDER BY date_merged DESC")
if(!pr_list_query.Execute())
var/err = pr_list_query.ErrorMsg()
log_game("SQL ERROR during CL generation L143. Error: \[[err]\]\n")
message_admins("SQL ERROR during CL generation L143. Error: \[[err]\]\n")
var/datum/db_query/pr_list_query = SSdbcore.NewQuery("SELECT DISTINCT pr_number FROM changelog WHERE date_merged BETWEEN NOW() - INTERVAL 30 DAY AND NOW() ORDER BY date_merged DESC")
if(!pr_list_query.warn_execute())
qdel(pr_list_query)
return FALSE
while(pr_list_query.NextRow())
prs_to_process += text2num(pr_list_query.item[1])
qdel(pr_list_query)
// Load in the header
changelogHTML += changelog_header
@@ -194,35 +196,40 @@ SUBSYSTEM_DEF(changelog)
var/merge_date = "" // Timestamp of when the PR was merged
// Now we gather the data from the DB
// Also we probably dont need to sanitize the PR number but you never know
var/DBQuery/pr_meta = GLOB.dbcon.NewQuery("SELECT author,DATE(date_merged) AS date FROM changelog WHERE pr_number = [sanitizeSQL(pr_number)] LIMIT 1")
if(!pr_meta.Execute())
var/err = pr_meta.ErrorMsg()
log_game("SQL ERROR during CL generation L190. Error: \[[err]\]\n")
message_admins("SQL ERROR during CL generation L190. Error: \[[err]\]\n")
var/datum/db_query/pr_meta = SSdbcore.NewQuery(
"SELECT author, DATE(date_merged) AS date FROM changelog WHERE pr_number = :prnum LIMIT 1",
list("prnum" = pr_number)
)
if(!pr_meta.warn_execute())
qdel(pr_meta)
return FALSE
while(pr_meta.NextRow())
author = pr_meta.item[1]
merge_date = pr_meta.item[2]
// Now for each actual entry
var/DBQuery/db_entries = GLOB.dbcon.NewQuery("SELECT cl_type, cl_entry FROM changelog WHERE pr_number = [sanitizeSQL(pr_number)]")
if(!db_entries.Execute())
var/err = db_entries.ErrorMsg()
log_game("SQL ERROR during CL generation L204. Error: \[[err]\]\n")
message_admins("SQL ERROR during CL generation L204. Error: \[[err]\]\n")
return FALSE
qdel(pr_meta)
// Now for each actual entry
var/datum/db_query/pr_cl_entries = SSdbcore.NewQuery(
"SELECT cl_type, cl_entry FROM changelog WHERE pr_number = :prnum",
list("prnum" = pr_number)
)
if(!pr_cl_entries.warn_execute())
qdel(pr_cl_entries)
return FALSE
// Now we make a changelog block
pr_block += "<div class='statusDisplay'>"
// If the github URL in the config has a trailing slash, it doesnt matter here, thankfully github accepts having a double slash: https://github.com/org/repo//pull/1
pr_block += "<p class='white'><a href='?src=[UID()];openPR=[pr_number]'>#[pr_number]</a> by <b>[author]</b> (Merged on [merge_date])</span>"
while(db_entries.NextRow())
pr_block += "<p>[Text2Icon(db_entries.item[1])] [db_entries.item[2]]</p>"
while(pr_cl_entries.NextRow())
pr_block += "<p>[Text2Icon(pr_cl_entries.item[1])] [pr_cl_entries.item[2]]</p>"
qdel(pr_cl_entries)
pr_block += "</div><br>"
changelogHTML += pr_block
+437
View File
@@ -0,0 +1,437 @@
SUBSYSTEM_DEF(dbcore)
name = "Database"
flags = SS_BACKGROUND
wait = 1 MINUTES
init_order = INIT_ORDER_DBCORE
/// Is the DB schema valid
var/schema_valid = TRUE
/// Timeout of failed connections
var/failed_connection_timeout = 0
/// Amount of failed connections
var/failed_connections = 0
/// Last error to occur
var/last_error
/// List of currenty processing queries
var/list/active_queries = list()
/// SQL errors that have occured mid round
var/total_errors = 0
/// Connection handle. This is an arbitrary handle returned from rust_g.
var/connection
offline_implications = "The server will no longer check for undeleted SQL Queries. No immediate action is needed."
/datum/controller/subsystem/dbcore/stat_entry()
..("A: [length(active_queries)]")
// This is in Initialize() so that its actually seen in chat
/datum/controller/subsystem/dbcore/Initialize()
if(!schema_valid)
to_chat(world, "<span class='boldannounce'>Database schema ([sql_version]) doesn't match the latest schema version ([SQL_VERSION]). Roundstart has been delayed.</span>")
return ..()
/datum/controller/subsystem/dbcore/fire()
for(var/I in active_queries)
var/datum/db_query/Q = I
if(world.time - Q.last_activity_time > 5 MINUTES)
message_admins("Found undeleted query, please check the server logs and notify coders.")
log_sql("Undeleted query: \"[Q.sql]\" LA: [Q.last_activity] LAT: [Q.last_activity_time]")
qdel(Q)
if(MC_TICK_CHECK)
return
/datum/controller/subsystem/dbcore/Recover()
connection = SSdbcore.connection
//nu
/datum/controller/subsystem/dbcore/can_vv_get(var_name)
return var_name != NAMEOF(src, connection) && var_name != NAMEOF(src, active_queries) && ..()
/datum/controller/subsystem/dbcore/vv_edit_var(var_name, var_value)
if(var_name == NAMEOF(src, connection))
return FALSE
return ..()
/**
* Connection Creator
*
* This proc basically does a few sanity checks before connecting, then attempts to make a connection
* When connecting, RUST_G will initialize a thread pool for queries to use to run asynchronously
*/
/datum/controller/subsystem/dbcore/proc/Connect()
if(IsConnected())
return TRUE
if(!config.sql_enabled)
return FALSE
if(failed_connection_timeout <= world.time) //it's been more than 5 seconds since we failed to connect, reset the counter
failed_connections = 0
if(failed_connections > 5) //If it failed to establish a connection more than 5 times in a row, don't bother attempting to connect for 5 seconds.
failed_connection_timeout = world.time + 50
return FALSE
var/result = json_decode(rustg_sql_connect_pool(json_encode(list(
"host" = sqladdress,
"port" = text2num(sqlport),
"user" = sqlfdbklogin,
"pass" = sqlfdbkpass,
"db_name" = sqlfdbkdb,
"read_timeout" = config.async_sql_query_timeout,
"write_timeout" = config.async_sql_query_timeout,
"max_threads" = config.rust_sql_thread_limit,
))))
. = (result["status"] == "ok")
if(.)
connection = result["handle"]
else
connection = null
last_error = result["data"]
log_sql("Connect() failed | [last_error]")
++failed_connections
/**
* Schema Version Checker
*
* Basically verifies that the DB schema in the config is the same as the version the game is expecting.
* If it is a valid version, the DB will then connect.
*/
/datum/controller/subsystem/dbcore/proc/CheckSchemaVersion()
if(config.sql_enabled)
// The unit tests have their own version of this check, which wont hold the server up infinitely, so this is disabled if we are running unit tests
#ifndef UNIT_TESTS
if(config.sql_enabled && sql_version != SQL_VERSION)
config.sql_enabled = FALSE
schema_valid = FALSE
SSticker.ticker_going = FALSE
log_world("Database connection failed: Invalid SQL Versions")
return FALSE
#endif
if(Connect())
log_world("Database connection established")
else
// log_sql() because then an error will be logged in the same place
log_sql("Your server failed to establish a connection with the database")
else
log_sql("Database is not enabled in configuration")
/**
* Disconnection Handler
*
* Tells the DLL to clean up any open connections.
* This will also reset the failed connection counter
*/
/datum/controller/subsystem/dbcore/proc/Disconnect()
failed_connections = 0
if(connection)
rustg_sql_disconnect_pool(connection)
connection = null
/**
* IsConnected Helper
*
* Short helper to check if the DB is connected or not.
* Does a few sanity checks, then asks the DLL if we are properly connected
*/
/datum/controller/subsystem/dbcore/proc/IsConnected()
if(!config.sql_enabled)
return FALSE
if(!schema_valid)
return FALSE
if(!connection)
return FALSE
return json_decode(rustg_sql_connected(connection))["status"] == "online"
/**
* Error Message Helper
*
* Returns the last error that the subsystem encountered.
* Will always report "Database disabled by configuration" if the DB is disabled.
*/
/datum/controller/subsystem/dbcore/proc/ErrorMsg()
if(!config.sql_enabled)
return "Database disabled by configuration"
return last_error
/**
* Error Reporting Helper
*
* Pretty much just sets `last_error` to the error argument
*
* Arguments:
* * error - Error text to set `last_error` to
*/
/datum/controller/subsystem/dbcore/proc/ReportError(error)
last_error = error
/**
* New Query Invoker
*
* Checks to make sure this query isnt being invoked by admin fuckery, then returns a new [/datum/db_query]
*
* Arguments:
* * sql_query - SQL query to be ran, with :parameter placeholders
* * arguments - Associative list of parameters to be inserted into the query
*/
/datum/controller/subsystem/dbcore/proc/NewQuery(sql_query, arguments)
if(IsAdminAdvancedProcCall())
to_chat(usr, "<span class='boldannounce'>DB query blocked: Advanced ProcCall detected.</span>")
message_admins("[key_name(usr)] attempted to create a DB query via advanced proc-call")
log_admin("[key_name(usr)] attempted to create a DB query via advanced proc-call")
return FALSE
return new /datum/db_query(connection, sql_query, arguments)
/**
* Handler to allow many queries to be executed en masse
*
* Feed this proc a list of queries and it will execute them all at once, by the power of async magic!
*
* Arguments:
* * querys - List of queries to execute
* * warn - Boolean to warn on query failure
* * qdel - Boolean to enable auto qdel of queries
*/
/datum/controller/subsystem/dbcore/proc/MassExecute(list/querys, warn = FALSE, qdel = FALSE)
if(!islist(querys))
if(!istype(querys, /datum/db_query))
CRASH("Invalid query passed to MassExecute: [querys]")
querys = list(querys)
for(var/thing in querys)
var/datum/db_query/query = thing
if(warn)
INVOKE_ASYNC(query, /datum/db_query.proc/warn_execute)
else
INVOKE_ASYNC(query, /datum/db_query.proc/Execute)
for(var/thing in querys)
var/datum/db_query/query = thing
UNTIL(!query.in_progress)
if(qdel)
qdel(query)
/**
* # db_query
*
* Datum based handler for all database queries
*
* Holds information regarding inputs, status, and outputs
*/
/datum/db_query
// Inputs
/// The connection being used with this query
var/connection
/// The SQL statement being executed with :parameter placeholders
var/sql
/// An associative list of parameters to be substituted into the statement
var/arguments
// Status information
/// Is the query currently in progress
var/in_progress
/// What was our last error, if any
var/last_error
/// What was our last activity
var/last_activity
/// When was our last activity
var/last_activity_time
// Output
/// List of all rows returned
var/list/list/rows
/// Counter of the next row to take
var/next_row_to_take = 1
/// How many rows were affected by the query
var/affected
/// ID of the last inserted row
var/last_insert_id
/// List of data values populated by NextRow()
var/list/item
// Sets up some vars and throws it into the SS active query list
/datum/db_query/New(connection, sql, arguments)
SSdbcore.active_queries[src] = TRUE
Activity("Created")
item = list()
src.connection = connection
src.sql = sql
src.arguments = arguments
// Takes it out of the active query list, as well as closing it up
/datum/db_query/Destroy()
Close()
SSdbcore.active_queries -= src
return ..()
/datum/db_query/CanProcCall(proc_name)
// go away
return FALSE
/**
* Activity Update Handler
*
* Sets the last activity text to the argument input, as well as updating the activity time
*
* Arguments:
* * activity - Last activity text
*/
/datum/db_query/proc/Activity(activity)
last_activity = activity
last_activity_time = world.time
/**
* Wrapped for warning on execution
*
* You should use this proc when running the SQL statement. It will auto inform the user and the online admins if a query fails
*
* Arguments:
* * async - Are we running this query asynchronously
* * log_error - Do we want to log errors this creates? Disable this if you are running sensitive queries where you dont want errors logged in plain text (EG: Auth token stuff)
*/
/datum/db_query/proc/warn_execute(async = TRUE, log_error = TRUE)
. = Execute(async, log_error)
if(!.)
SSdbcore.total_errors++
if(usr)
to_chat(usr, "<span class='danger'>A SQL error occurred during this operation, please inform an admin or a coder.</span>")
message_admins("An SQL error has occured. Please check the server logs, with the following timestamp ID: \[[time_stamp()]]")
/**
* Main Execution Handler
*
* Invoked by [warn_execute()]
* This handles query error logging, as well as invoking the actual runner
* Arguments:
* * async - Are we running this query asynchronously
* * log_error - Do we want to log errors this creates? Disable this if you are running sensitive queries where you dont want errors logged in plain text (EG: Auth token stuff)
*/
/datum/db_query/proc/Execute(async = TRUE, log_error = TRUE)
Activity("Execute")
if(in_progress)
CRASH("Attempted to start a new query while waiting on the old one")
if(!SSdbcore.IsConnected())
last_error = "No connection!"
return FALSE
var/start_time
if(!async)
start_time = REALTIMEOFDAY
Close()
. = run_query(async)
var/timed_out = !. && findtext(last_error, "Operation timed out")
if(!. && log_error)
log_sql("[last_error] | Query used: [sql] | Arguments: [json_encode(arguments)]")
if(!async && timed_out)
log_sql("Query execution started at [start_time]")
log_sql("Query execution ended at [REALTIMEOFDAY]")
log_sql("Slow query timeout detected.")
log_sql("Query used: [sql]")
slow_query_check()
/**
* Actual Query Runner
*
* This does the main query with the database and the rust calls themselves
*
* Arguments:
* * async - Are we running this query asynchronously
*/
/datum/db_query/proc/run_query(async)
var/job_result_str
if(async)
var/job_id = rustg_sql_query_async(connection, sql, json_encode(arguments))
in_progress = TRUE
UNTIL((job_result_str = rustg_sql_check_query(job_id)) != RUSTG_JOB_NO_RESULTS_YET)
in_progress = FALSE
if(job_result_str == RUSTG_JOB_ERROR)
last_error = job_result_str
return FALSE
else
job_result_str = rustg_sql_query_blocking(connection, sql, json_encode(arguments))
var/result = json_decode(job_result_str)
switch(result["status"])
if("ok")
rows = result["rows"]
affected = result["affected"]
last_insert_id = result["last_insert_id"]
return TRUE
if("err")
last_error = result["data"]
return FALSE
if("offline")
last_error = "offline"
return FALSE
// Just tells the admins if a query timed out, and asks if the server hung to help error reporting
/datum/db_query/proc/slow_query_check()
message_admins("HEY! A database query timed out. Did the server just hang? <a href='?_src_=holder;slowquery=yes'>\[YES\]</a>|<a href='?_src_=holder;slowquery=no'>\[NO\]</a>")
/**
* Proc to get the next row in a DB query
*
* Cycles `item` to the next row in the DB query, if multiple were fetched
*/
/datum/db_query/proc/NextRow()
Activity("NextRow")
if(rows && next_row_to_take <= length(rows))
item = rows[next_row_to_take]
next_row_to_take++
return !!item
else
return FALSE
// Simple helper to get the last error a query had
/datum/db_query/proc/ErrorMsg()
return last_error
// Simple proc to null out data to aid GC
/datum/db_query/proc/Close()
rows = null
item = null
// Verb that lets admins force reconnect the DB
/client/proc/reestablish_db_connection()
set category = "Debug"
set name = "Reestablish DB Connection"
if(!config.sql_enabled)
to_chat(usr, "<span class='warning'>The Database is not enabled in the server configuration!</span>")
return
if(SSdbcore.IsConnected())
if(!check_rights(R_DEBUG, FALSE))
to_chat(usr, "<span class='warning'>The database is already connected! (Only those with +DEBUG can force a reconnection)</span>")
return
var/reconnect = alert("The database is already connected! If you *KNOW* that this is incorrect, you can force a reconnection", "The database is already connected!", "Force Reconnect", "Cancel")
if(reconnect != "Force Reconnect")
return
SSdbcore.Disconnect()
log_admin("[key_name(usr)] has forced the database to disconnect")
message_admins("[key_name_admin(usr)] has <b>forced</b> the database to disconnect!!!")
log_admin("[key_name(usr)] is attempting to re-establish the DB Connection")
message_admins("[key_name_admin(usr)] is attempting to re-establish the DB Connection")
feedback_add_details("admin_verb", "FRDBC") //If you are copy-pasting this, ensure the 2nd parameter is unique to the new proc!
SSdbcore.failed_connections = 0 // Reset this
if(!SSdbcore.Connect())
message_admins("Database connection failed: [SSdbcore.ErrorMsg()]")
else
message_admins("Database connection re-established")
+10 -10
View File
@@ -14,15 +14,15 @@ SUBSYSTEM_DEF(statistics)
sql_poll_players()
/datum/controller/subsystem/statistics/proc/sql_poll_players()
if(!config.sql_enabled)
if(!SSdbcore.IsConnected())
return
var/playercount = GLOB.clients.len
var/admincount = GLOB.admins.len
if(!GLOB.dbcon.IsConnected())
log_game("SQL ERROR during player polling. Failed to connect.")
else
var/sqltime = time2text(world.realtime, "YYYY-MM-DD hh:mm:ss")
var/DBQuery/query = GLOB.dbcon.NewQuery("INSERT INTO [format_table_name("legacy_population")] (playercount, admincount, time) VALUES ([playercount], [admincount], '[sqltime]')")
if(!query.Execute())
var/err = query.ErrorMsg()
log_game("SQL ERROR during playercount polling. Error: \[[err]\]\n")
var/datum/db_query/statquery = SSdbcore.NewQuery(
"INSERT INTO [format_table_name("legacy_population")] (playercount, admincount, time) VALUES (:playercount, :admincount, NOW())",
list(
"playercount" = length(GLOB.clients),
"admincount" = length(GLOB.admins)
)
)
statquery.warn_execute()
qdel(statquery)