Post subject: Lua command to control the tracelogger
dan
He/Him
Joined: 9/23/2016
Posts: 25
I would like to create frame-specific trace logs for semi-automated analysis of existing TASes. My idea is to have a separate process grep for a couple things from each trace log, save that information elsewhere, and delete the frame-specific trace log. That way, I can start the Lua script, play a section of the TAS, go do something, and have results to look at when I come back. From there, I can identify frames of interest for further analysis. Some ideas include calculating the percentage of idle instructions in each frame for lag reduction, as well as identifying the multiple areas of code where the game reads the RNG variable. I read the Lua documentation and did not see a Lua method available to control the tracelogging. Would it be difficult to change lsnes-bsnes to expose this via a Lua command? In the past, I have copy-pasted the output from the tracelogger window, and cut the tracelog apart via a script. This still requires some manual effort. Having separate trace log files would require less disk space, and maybe even cause less I/O overhead too. Sample Lua script
local PROCID_CPU=0; 
function on_frame()
  -- Not valid Lua
  debug_context::tracelog(PROCID_CPU, string.format("C:\\Path\\To\\My\\Trace\\Logs\\frame-%06d.trace", movie.currentframe()));
end
on_frame_emulated()
  -- Not valid Lua
  debug_context::tracelog(PROCID_CPU, "");
end
Sample Log output
Loaded 'C:\Path\To\Someone\Elses\TAS\finished-tas.lsmv' in 549032 microseconds.
Tracelogging processor #0 to 'C:\Path\To\My\Trace\Logs\frame-000165.trace'
Stopped tracelogging processor #0
Tracelogging processor #0 to 'C:\Path\To\My\Trace\Logs\frame-000166.trace'
Stopped tracelogging processor #0
Tracelogging processor #0 to 'C:\Path\To\My\Trace\Logs\frame-000167.trace'
Stopped tracelogging processor #0
  .
  :
Thanks.
Amaraticando
It/Its
Editor, Player (157)
Joined: 1/10/2012
Posts: 673
Location: Brazil
Take a look at memory.settrace(filename) If filename is non-empty, output trace to that file. If "", stop tracing. For some reason it's not in the pdf. You can also tracelog to a file with the internal command
tracelog:
    <cpuid> <file>: Start tracing <cpuid> to <file>
    <cpuid>: End tracing <cpuid>
Internal commands can be manually typed in the message window and invoked from Lua using exec(string command). I hope that helps. If not, the best place to ask is at #lsnes IRC.
dan
He/Him
Joined: 9/23/2016
Posts: 25
That was incredibly helpful. Thank you. Finished script:
local FILENAME_PATTERN="C:\\ALL\\YOUR\\TRACE\\LOGS\\GO\\HERE\\%s\\frame-%06d.trace";
local DIRECTORY="TESTING"; 
-- Directory C:\ALL\YOUR\TRACE\LOGS\GO\HERE\TESTING must already exist

function on_frame()
  exec("tracelog cpu " .. string.format(FILENAME_PATTERN, DIRECTORY, movie.currentframe()));
end
function on_frame_emulated()
  exec("tracelog cpu");
end
Editor, Player (132)
Joined: 4/7/2015
Posts: 328
Location: Porto Alegre, RS, Brazil
Btw, just an editing tip: you can make syntax highlights here, with [code=lua] your code here [/code]
Language: lua

local FILENAME_PATTERN="C:\\ALL\\YOUR\\TRACE\\LOGS\\GO\\HERE\\%s\\frame-%06d.trace"; local DIRECTORY="TESTING"; -- Directory C:\ALL\YOUR\TRACE\LOGS\GO\HERE\TESTING must already exist function on_frame() exec("tracelog cpu " .. string.format(FILENAME_PATTERN, DIRECTORY, movie.currentframe())); end function on_frame_emulated() exec("tracelog cpu"); end
Games are basically math with a visual representation of this math, that's why I make the scripts, to re-see games as math. My things: YouTube, GitHub, Pastebin, Twitter
Site Admin, Skilled player (1234)
Joined: 4/17/2010
Posts: 11251
Location: RU
Or even neater, downloadable file: [code=script.lua]] your code here [/code] Download script.lua
Language: lua

local FILENAME_PATTERN="C:\\ALL\\YOUR\\TRACE\\LOGS\\GO\\HERE\\%s\\frame-%06d.trace"; local DIRECTORY="TESTING"; -- Directory C:\ALL\YOUR\TRACE\LOGS\GO\HERE\TESTING must already exist function on_frame() exec("tracelog cpu " .. string.format(FILENAME_PATTERN, DIRECTORY, movie.currentframe())); end function on_frame_emulated() exec("tracelog cpu"); end
Warning: When making decisions, I try to collect as much data as possible before actually deciding. I try to abstract away and see the principles behind real world events and people's opinions. I try to generalize them and turn into something clear and reusable. I hate depending on unpredictable and having to make lottery guesses. Any problem can be solved by systems thinking and acting.
dan
He/Him
Joined: 9/23/2016
Posts: 25
I figured it might be more helpful if I post my final solution, complete with the processing script too. Using Git Bash on Windows, it processes ~1,000 frames per hour. Linux is probably faster, but you can kick off both scripts, start a TAS, and collect all the data hands-off. I'm sure there's a better way to sync the scripts other than testing that a file exists, but it's good enough for now. Download trace-every-frame.lua
Language: lua

local FILENAME_PATTERN="C:\\ALL\\YOUR\\TRACE\\LOGS\\GO\\HERE\\%s\\frame-%06d.trace"; local DIRECTORY="TESTING"; -- Directory C:\ALL\YOUR\TRACE\LOGS\GO\HERE\TESTING must already exist function file_exists(file) local f = io.open(file, "r") -- Note: If you stop this Lua script at the wrong time, you may need to close lsnes in order to delete this file. if f then f:close() end return f ~= nil end function on_frame() local fiveFrameEarlier=(movie.currentframe()-5); if (fiveFrameEarlier > 0) then traceLogFile_fiveFramesEarlier=string.format(FILENAME_PATTERN, DIRECTORY, fiveFrameEarlier); local idle=file_exists(traceLogFile_fiveFramesEarlier); while idle do -- lsnes spits out the trace logs faster than the other script can process them -- if lsnes is more than 5 frames ahead of the processing script, -- then do nothing until the processing script catches up delay=123456; while (delay > 0) do delay=delay-1; end; idle=file_exists(traceLogFile_fiveFramesEarlier); end; end; exec("tracelog cpu " .. string.format(FILENAME_PATTERN, DIRECTORY, movie.currentframe())); end function on_frame_emulated() exec("tracelog cpu"); end
Download process-trace-logs.sh
Language: shell

function processTraceLog { traceLogToAnalyze="$1"; matchLines=$(grep '^[0-9a-f]\{6\} \(\(st\|ld\)a \$0123\|jsl $456789\)' $traceLogToAnalyze | grep -v '^\(123456\|789abc\|def012\)'); numMatches=$(echo "$matchLines" | grep -c '.'); echo "$traceLogToAnalyze:$numMatches"; if [ $numMatches -gt 0 ]; then echo "$matchLines" | cut -b -36 | sed 's/^/ /g'; fi; # cannot delete current file if the Lua script is checking to see if it exists while [ -f $traceLogToAnalyze ]; do rm 2>/dev/null $traceLogToAnalyze; sleep 1; done; } touch output.log; while [ 1 -eq 1 ]; # infinite loop do if [ $(ls -1 *.trace | wc -l) -gt 1 ]; then # the next trace file has started, so the previous is finished processTraceLog $(ls -1rt *.trace | grep -v 'output.log' | head -n 1) | tee -a output.log; fi; done;
Masterjun
He/Him
Site Developer, Skilled player (1968)
Joined: 10/12/2010
Posts: 1179
Location: Germany
For anyone reading this thread and wanting to have lines of trace log in the Lua itself (to avoid doing external processing, like above), use memory.registertrace and memory.unregistertrace, documented in the lua.pdf file.
Warning: Might glitch to credits I will finish this ACE soon as possible (or will I?)