ID:2134168
 
Resolved
The filename listed in a runtime error was sometimes incorrect in very large projects, using a different string instead.
BYOND Version:510
Operating System:Linux
Web Browser:Chrome 52.0.2743.116
Applies to:Dream Daemon
Status: Resolved (511.1361)

This issue has been resolved.
Descriptive Problem Summary:
I was browsing the runtime logs of my Space Station 13 server when i saw this really weird runtime:
proc name: convert notes sql (/proc/convert_notes_sql)
source file: This is a secret social experiment conducted by Nanotrasen. Convince the crew that this is the truth.,190
usr: (src)
src: null
call stack:
convert notes sql("(ckey censored)")

I removed the ckey,but it was of a player,and i've noticed that for some reasons he has like 30-40 notes with bugged time and with the same description:

0000-00-00 00:00:00 | Hippie Station 13 | (censored) [Remove Note] [Edit Note]
Lasered a guy into crit for shitty reasons, apologized.

I am more worried about the runtime claiming that a text var is a file. The source file byond thinks was the cause is actually a text var of an objective which was completely unrelated to the case anyhow.

Numbered Steps to Reproduce Problem:
Unknown?

Code Snippet (if applicable) to Reproduce Problem:
//Text var location
/datum/objective/abductee/social_experiment
explanation_text = "This is a secret social experiment conducted by Nanotrasen. Convince the crew that this is the truth."

//proc shown in the runtime
#define NOTESFILE "data/player_notes.sav"
/proc/convert_notes_sql(ckey)
var/savefile/notesfile = new(NOTESFILE)
if(!notesfile)
log_game("Error: Cannot access [NOTESFILE]")
return
notesfile.cd = "/[ckey]"
while(!notesfile.eof)
var/notetext
notesfile >> notetext
var/server
if (config && config.server_name)
server = config.server_name
var/regex/note = new("^(\\d{2}-\\w{3}-\\d{4}) \\| (.+) ~(\\w+)$", "i")
note.Find(notetext)
var/timestamp = note.group[1]
notetext = note.group[2]
var/adminckey = note.group[3]
var/DBQuery/query_convert_time = dbcon.NewQuery("SELECT ADDTIME(STR_TO_DATE('[timestamp]','%d-%b-%Y'), '0')")
if(!query_convert_time.Execute())
var/err = query_convert_time.ErrorMsg()
log_game("SQL ERROR converting timestamp. Error : \[[err]\]\n")
return
if(query_convert_time.NextRow())
timestamp = query_convert_time.item[1]
if(ckey && notetext && timestamp && adminckey && server)
add_note(ckey, notetext, timestamp, adminckey, 0, server)
notesfile.cd = "/"
notesfile.dir.Remove(ckey)
#undef NOTESFILE


Expected Results:
The runtime to show up the actual file where the problem happened

Actual Results:
The runtime claims that a text var is a .dm file?

Does the problem occur:
Every time? Or how often?Happens everytime this exact user joins,and it happens with him only
In other games?No,only space station 13
In other user accounts?No
On other computers?No

When does the problem NOT occur?
When anyone else but this guy joins

Did the problem NOT occur in any earlier versions? If so, what was the last version that worked? (Visit http://www.byond.com/download/build to download old versions for testing.)
Unknown

Workarounds:
None

This is the same as an issue MrStonedOne reported, where vars are getting corrupted. I still don't have a test case for it.
This might be different. This runtime did not happen once,but happens everytime this certain guy logs in. It's always the exact same,with the exact same text var being confused as a dm file,and the exact same user. And it also seems to happen always at round starts, but i cannot confirm this thing.
I've often seen runtimes display the wrong information in the proc name/file name. I would say what I see most often is that it takes the form of a random string. (A string that was in the code at compile time that is)

Reproducing all that in a test case is a completely different matter though and much more difficult.
Well,apparently EVERY time this guy logs in, the runtime is thrown out. But i saw that now objects are being misread as dm files too:
runtime error: cannot read from list
proc name: convert notes sql (/proc/convert_notes_sql)
source file: the prototype hardsuit,190
usr: (src)
src: null
call stack:
convert notes sql("(censored)")
(censored)(/client): New(null)
Is there any way at all we can help?This sadly does not happen in local since it seems linked to the database or some stuff
Huh. I'll check the MySQL code to see if maybe there's a connection. Maybe it;s possible that somehow an old 2-byte limit got missed.
If it can help in any way,the line of the file where this proc is in shows:
    var/timestamp = note.group[1]

I doubt it's this but,eh,worth trying i guess?
The entire file is this: https://github.com/HippieStationCode/HippieStation13/blob/ b149a510ae9aa5a2ea4339f59c14b69b42794bdb/code/modules/admin/ sql_notes.dm
I can't help but wonder if the regex procs are involved in this somehow, although I'm given to understand this issue predates 510. But if it doesn't, then I wonder if there'd be a way to reproduce an issue like this by stress-testing the regex procs.
It definitely predates 510 I can guarantee you that.

id:1919743
It always looks pretty silly when you get a runtime like this that's reading from a random compile time string, though really I don't know of any case in which its even possible to reproduce these sorts of problems.

[02:51:56] Runtime in When screwed to wiring attached to an electric grid, then activated, this large device pulls the singularity towards it. Does not work when the singularity is still in containment. A singularity beacon can cause catastrophic damage to a space station, leading to an emergency evacuation. Because of its size, it cannot be carried. Ordering this sends you a small beacon that will teleport the larger beacon to your location on activation.,76: Cannot read null.name
proc name: handle disabilities (/mob/living/carbon/human/proc/handle_disabilities)
src: Julian Schneider (/mob/living/carbon/human)
src.loc: null
call stack:
Julian Schneider (/mob/living/carbon/human): handle disabilities()
Julian Schneider (/mob/living/carbon/human): Life()
mob (/datum/controller/process/mob): doWork()
mob (/datum/controller/process/mob): process()
/datum/controller/processSched... (/datum/controller/processScheduler): runProcess(mob (/datum/controller/process/mob))


Line of code in question is
    if(species.name == "Tajaran")


I do notice that the line of code that runtimed had a string in it, a coincidence or a clue?
In response to Clusterfack
Coincidence. The string already existed as a constant, and in fact it probably hadn't even been pushed onto the stack yet because species.name would have come first. The error came about because species was null. (How it became null could have been a regular logic error in the game, or maybe fallout from the same bug.)

The annoying thing is that this bug is impossible to replicate under controlled conditions.
Well yes the error itself was a normal error in the code. Curious how the string tree gets corrupted in error messages specifically since I've never seen it fail anywhere else.
I'm not sure if it's the string tree or the proc info that's getting corrupted. The string tree may well be intact; in fact that's likely because it'd be fail-happy if it got corrupted.
it might be some oddity where trying to grab the string of the file is grabbing the wrong string id, or using a dynamic pointer after it was freed, leading to that string getting assigned to the same pointer.

Hey now, that sounds familiar!

Have we confirm that this happens under 511.1355 and later?
well I'm still seeing occurrences in the server logs, although not current on what version of byond we're running
1358, 1356 before the weekend.
Could this potential string-tree corruption be from a similar source as https://secure.byond.com/forum/?post=2129715 ?
In response to GinjaNinja32
I don't know. I never got a demo for that issue.
In response to Lummox JR
Lummox JR wrote:
I don't know. I never got a demo for that issue.

I can't even reproduce it outside of CI, I don't know how I could make a demo.

I'll try stripping out code and running what's left in CI at some point, but I don't think much will come from it.
Alright lummox, I think I've made you the closest thing to a test case that I believe you will EVER get on this issue.

Through sheer luck of the compiler, my code compiled into a form in which I can trigger this runtime bug by running our ss13 code in safe mode, and before the world starts by rejecting byonds request for permissions to run a script, it will trigger the runtime with the -exact same replaced message- every single time you start up the server.

Since it will only trigger when you reject the permissions, if you trigger a debugger at that point you should be able to see exactly what is happening shortly afterwards hopefully. Hope this manages to help, then again it might not, startup time is a bit slow and it may be using more ram than you can debug with, hard to say though and worth a try.

http://puu.sh/rTKaH/cb1843911c.rar

For me it triggers this exact same runtime every time it runs:
Runtime in Offer humans for Nar-Sie's first meal of the day. ( eaten) Fail!,11: Safety violation: tried to use shell()
proc name: ext python (/proc/ext_python)
Page: 1 2