hakowork/rojo
3
0
Fork 0
mirror of https://github.com/rojo-rbx/rojo.git synced 2026-10-23 05:51:39 +00:00
Code Issues Projects Releases Packages Wiki Activity Actions

Enhance logging for syncback operations and patch applications

Browse source 
- Added detailed logging for syncback operations, including additions, removals, and updates, to improve traceability and debugging.
- Implemented summary logs for patch applications in both the client and server, capturing the number of changes made.
- Enhanced logging in the ChangeBatcher and ApiService to provide insights into property changes and instance updates during syncback processes.
- Improved error handling and logging for VFS events to ensure better visibility of file operations.
This commit is contained in:
Joe 2026-01-31 12:06:27 -06:00
parent d3d914e660
commit 6dc8f219bd
7 changed files with 242 additions and 6 deletions
Download patch file Download diff file Expand all files Collapse all files

37
plugin/src/ApiContext.lua
View file

@ -177,6 +177,43 @@ end
function ApiContext:write(patch)
local url = ("%s/api/write"):format(self.__baseUrl)
-- Log what we're sending to the server (syncback/pull)
local addedCount = 0
for _ in pairs(patch.added) do
addedCount += 1
end
-- Only log summary at debug level to reduce verbosity
if #patch.removed > 0 or addedCount > 0 or #patch.updated > 0 then
Log.debug(
"Sending to server: {} removals, {} additions, {} updates",
#patch.removed,
addedCount,
#patch.updated
)
end
-- Log individual operations at trace level (very detailed)
for _, removed in ipairs(patch.removed) do
Log.trace("[Syncback] Remove ID: {}", tostring(removed))
end
for _, addedInstance in pairs(patch.added) do
local instanceName = addedInstance.name or addedInstance.Name or "unknown"
local instanceClass = addedInstance.className or addedInstance.ClassName or "unknown"
Log.trace("[Syncback] Add {} ({})", instanceName, instanceClass)
end
for _, update in ipairs(patch.updated) do
local propCount = 0
if update.changedProperties then
for _ in pairs(update.changedProperties) do
propCount += 1
end
end
Log.trace("[Syncback] Update ID {} ({} properties)", update.id, propCount)
end
local updated = {}
for _, update in ipairs(patch.updated) do
local fixedUpdate = {

17
plugin/src/ChangeBatcher/encodeInstance.lua
View file

@ -173,6 +173,11 @@ encodeInstance = function(instance, parentId, _skipPathCheck)
return nil
end
-- Log encoding at trace level (very detailed)
if not _skipPathCheck then
Log.trace("Encoding for syncback: {} ({})", instance:GetFullName(), instance.ClassName)
end
local properties = {}
-- Always try to encode Attributes and Tags for any instance type
@ -262,6 +267,18 @@ encodeInstance = function(instance, parentId, _skipPathCheck)
end
end
-- Log property count for debugging
local propCount = 0
for _ in pairs(properties) do
propCount += 1
end
Log.trace(
" Encoded {} with {} properties, {} children",
instance.Name,
propCount,
#children
)
return {
parent = parentId,
name = instance.Name,

18
plugin/src/ChangeBatcher/init.lua
View file

@ -5,6 +5,9 @@
local RunService = game:GetService("RunService")
local Packages = script.Parent.Parent.Packages
local Log = require(Packages.Log)
local PatchSet = require(script.Parent.PatchSet)
local createPatchSet = require(script.createPatchSet)
@ -64,8 +67,10 @@ function ChangeBatcher:add(instance, propertyName)
if not properties then
properties = {}
self.__pendingPropertyChanges[instance] = properties
Log.trace("ChangeBatcher: tracking changes to {}", instance:GetFullName())
end
Log.trace("ChangeBatcher: property '{}' changed on {}", propertyName, instance:GetFullName())
properties[propertyName] = true
end
@ -96,11 +101,24 @@ function ChangeBatcher:__flush()
end
local patch = createPatchSet(self.__instanceMap, self.__pendingPropertyChanges, self.__syncSourceOnly)
self.__pendingPropertyChanges = {}
if PatchSet.isEmpty(patch) then
return nil
end
-- Log summary at debug level
local addedCount = 0
for _ in pairs(patch.added) do
addedCount += 1
end
Log.debug(
"Two-way sync: {} updates, {} additions, {} removals",
#patch.updated,
addedCount,
#patch.removed
)
return patch
end

42
plugin/src/Reconciler/applyPatch.lua
View file

@ -27,6 +27,20 @@ local function applyPatch(instanceMap, patch)
-- to ensure that referents can be mapped to instances correctly.
local deferredRefs = {}
-- Log summary of patch being applied (debug level for summary)
local addCount = 0
for _ in pairs(patch.added) do
addCount += 1
end
if #patch.removed > 0 or addCount > 0 or #patch.updated > 0 then
Log.debug(
"Applying patch to Studio: {} removals, {} additions, {} updates",
#patch.removed,
addCount,
#patch.updated
)
end
for _, removedIdOrInstance in ipairs(patch.removed) do
-- Skip auto-created instances that shouldn't be synced
local instance = if Types.RbxId(removedIdOrInstance)
@ -36,6 +50,11 @@ local function applyPatch(instanceMap, patch)
continue
end
-- Log the removal (info level for major operations)
local instancePath = if instance then instance:GetFullName() else tostring(removedIdOrInstance)
local instanceClass = if instance then instance.ClassName else "unknown"
Log.info("[Studio] Remove: {} ({})", instancePath, instanceClass)
local removeInstanceSuccess = pcall(function()
if Types.RbxId(removedIdOrInstance) then
instanceMap:destroyId(removedIdOrInstance)
@ -44,6 +63,7 @@ local function applyPatch(instanceMap, patch)
end
end)
if not removeInstanceSuccess then
Log.warn("[Studio] Remove failed: {}", instancePath)
table.insert(unappliedPatch.removed, removedIdOrInstance)
end
end
@ -81,9 +101,14 @@ local function applyPatch(instanceMap, patch)
)
end
-- Log the addition (info level for major operations)
local parentPath = parentInstance:GetFullName()
Log.info("[Studio] Add: {}.{} ({})", parentPath, virtualInstance.Name, virtualInstance.ClassName)
local failedToReify = reifyInstance(deferredRefs, instanceMap, patch.added, id, parentInstance)
if not PatchSet.isEmpty(failedToReify) then
Log.warn("[Studio] Add failed: {}.{}", parentPath, virtualInstance.Name)
Log.debug("Failed to reify as part of applying a patch: {:#?}", failedToReify)
PatchSet.assign(unappliedPatch, failedToReify)
end
@ -94,10 +119,27 @@ local function applyPatch(instanceMap, patch)
if instance == nil then
-- We can't update an instance that doesn't exist.
Log.warn("[Studio] Update failed: Instance with ID {} not found", update.id)
table.insert(unappliedPatch.updated, update)
continue
end
-- Log the update (debug level for property details to reduce verbosity)
local instancePath = instance:GetFullName()
local propList = {}
if update.changedName then
table.insert(propList, "Name")
end
if update.changedClassName then
table.insert(propList, "ClassName")
end
if update.changedProperties then
for propName, _ in pairs(update.changedProperties) do
table.insert(propList, propName)
end
end
Log.debug("[Studio] Update: {} - {}", instancePath, table.concat(propList, ", "))
-- Pause updates on this instance to avoid picking up our changes when
-- two-way sync is enabled.
instanceMap:pauseInstance(instance)

59
plugin/src/ServeSession.lua
View file

@ -669,6 +669,24 @@ function ServeSession:__confirmAndApplyInitialPatch(catchUpPatch, serverInfo)
-- New: Apply based on per-item selections
local selections = userDecision.selections or {}
-- Log selection summary (debug level)
local pushCount, pullCount, ignoreCount = 0, 0, 0
for _, selection in pairs(selections) do
if selection == "push" then
pushCount += 1
elseif selection == "pull" then
pullCount += 1
else
ignoreCount += 1
end
end
Log.debug(
"User selections: {} push, {} pull, {} ignored",
pushCount,
pullCount,
ignoreCount
)
-- Build partial patches based on selections
local pushPatch = PatchSet.newEmpty() -- Items to apply to Studio
local pullPatch = PatchSet.newEmpty() -- Items to send back to Rojo
@ -676,12 +694,15 @@ function ServeSession:__confirmAndApplyInitialPatch(catchUpPatch, serverInfo)
-- Process updated items
for _, change in catchUpPatch.updated do
local selection = selections[change.id]
local instance = self.__instanceMap.fromIds[change.id]
local instancePath = if instance then instance:GetFullName() else "ID:" .. tostring(change.id)
if selection == "push" then
-- Apply Rojo changes to Studio
Log.trace("[Push] Update: {}", instancePath)
table.insert(pushPatch.updated, change)
elseif selection == "pull" and self.__twoWaySync then
-- Send Studio state back to Rojo
local instance = self.__instanceMap.fromIds[change.id]
if instance then
local propertiesToSync = change.changedProperties
if self.__syncSourceOnly then
@ -691,6 +712,7 @@ function ServeSession:__confirmAndApplyInitialPatch(catchUpPatch, serverInfo)
continue
end
end
Log.trace("[Pull] Update: {}", instancePath)
local update = encodePatchUpdate(instance, change.id, propertiesToSync)
if update then
table.insert(pullPatch.updated, update)
@ -716,8 +738,12 @@ function ServeSession:__confirmAndApplyInitialPatch(catchUpPatch, serverInfo)
-- If we don't have an ID, use the instance itself as the key
local selection = if id then selections[id] else selections[idOrInstance]
local instancePath = if instance then instance:GetFullName() else "ID:" .. tostring(idOrInstance)
local instanceClass = if instance then instance.ClassName else "unknown"
if selection == "push" then
-- Apply Rojo removal to Studio (delete the instance)
Log.trace("[Push] Delete: {}", instancePath)
table.insert(pushPatch.removed, idOrInstance)
elseif selection == "pull" and self.__twoWaySync then
-- Syncback: Create file in Rojo from Studio instance
@ -731,7 +757,8 @@ function ServeSession:__confirmAndApplyInitialPatch(catchUpPatch, serverInfo)
local guid = HttpService:GenerateGUID(false)
local tempRef = string.gsub(guid, "-", ""):lower()
pullPatch.added[tempRef] = encoded
Log.info("Syncback: encoding {:?} for creation in Rojo", instance)
-- Log at info level since this is a major file creation operation
Log.info("[Pull] Create file: {} ({})", instancePath, instanceClass)
end
else
Log.warn("Cannot syncback {:?}: parent not in Rojo tree", instance)
@ -744,11 +771,19 @@ function ServeSession:__confirmAndApplyInitialPatch(catchUpPatch, serverInfo)
-- Process added items
for id, change in catchUpPatch.added do
local selection = selections[id]
local instanceName = change.Name or "unknown"
local instanceClass = change.ClassName or "unknown"
local parentInstance = self.__instanceMap.fromIds[change.Parent]
local parentPath = if parentInstance then parentInstance:GetFullName() else "ID:" .. tostring(change.Parent)
if selection == "push" then
-- Apply Rojo addition to Studio
Log.trace("[Push] Add: {}.{}", parentPath, instanceName)
pushPatch.added[id] = change
elseif selection == "pull" and self.__twoWaySync then
-- Don't add in Studio, remove from Rojo
-- Log at info level since this is a major file deletion operation
Log.info("[Pull] Delete file: {}.{} ({})", parentPath, instanceName, instanceClass)
table.insert(pullPatch.removed, id)
end
-- "ignore" items are skipped
@ -760,11 +795,31 @@ function ServeSession:__confirmAndApplyInitialPatch(catchUpPatch, serverInfo)
-- Apply push items to Studio
if not PatchSet.isEmpty(pushPatch) then
local addCount = 0
for _ in pairs(pushPatch.added) do
addCount += 1
end
Log.debug(
"Applying to Studio: {} additions, {} removals, {} updates",
addCount,
#pushPatch.removed,
#pushPatch.updated
)
self:__applyPatch(pushPatch)
end
-- Send pull items back to Rojo server
if self.__twoWaySync and not PatchSet.isEmpty(pullPatch) then
local addCount = 0
for _ in pairs(pullPatch.added) do
addCount += 1
end
Log.info(
"Sending to Rojo: {} file creations, {} file deletions, {} updates",
addCount,
#pullPatch.removed,
#pullPatch.updated
)
return self.__apiContext:write(pullPatch)
end

52
src/change_processor.rs
View file

@ -158,7 +158,13 @@ impl JobThreadContext {
}
fn handle_vfs_event(&self, event: VfsEvent) {
log::trace!("Vfs event: {:?}", event);
// Log VFS events at debug level (not too verbose, but visible when needed)
match &event {
VfsEvent::Create(path) => log::debug!("VFS: File created: {}", path.display()),
VfsEvent::Write(path) => log::debug!("VFS: File modified: {}", path.display()),
VfsEvent::Remove(path) => log::debug!("VFS: File removed: {}", path.display()),
_ => log::trace!("VFS: Other event: {:?}", event),
}
// Update the VFS immediately with the event.
self.vfs
@ -169,7 +175,19 @@ impl JobThreadContext {
// of the tree. Calculate and apply all of these changes.
let applied_patches = match event {
VfsEvent::Create(path) | VfsEvent::Write(path) => {
self.apply_patches(self.vfs.canonicalize(&path).unwrap())
// The path might have been deleted before we could process this event
// (e.g., during syncback when directories are being removed).
// In that case, just skip this event.
match self.vfs.canonicalize(&path) {
Ok(canonical_path) => self.apply_patches(canonical_path),
Err(_) => {
log::trace!(
"Skipping create/write event for {:?} - path no longer exists",
path
);
Vec::new()
}
}
}
VfsEvent::Remove(path) => {
// MemoFS does not track parent removals yet, so we can canonicalize
@ -196,13 +214,34 @@ impl JobThreadContext {
}
};
// Log patch application summary at debug level
if !applied_patches.is_empty() {
let total_added: usize = applied_patches.iter().map(|p| p.added.len()).sum();
let total_removed: usize = applied_patches.iter().map(|p| p.removed.len()).sum();
let total_updated: usize = applied_patches.iter().map(|p| p.updated.len()).sum();
if total_added > 0 || total_removed > 0 || total_updated > 0 {
log::debug!(
"VFS event applied: {} added, {} removed, {} updated",
total_added,
total_removed,
total_updated
);
}
}
// Notify anyone listening to the message queue about the changes we
// just made.
self.message_queue.push_messages(&applied_patches);
}
fn handle_tree_event(&self, patch_set: PatchSet) {
log::trace!("Applying PatchSet from client: {:#?}", patch_set);
// Log incoming patch summary at debug level
log::debug!(
"Processing client patch: {} removed, {} added, {} updated",
patch_set.removed_instances.len(),
patch_set.added_instances.len(),
patch_set.updated_instances.len()
);
let applied_patch = {
let mut tree = self.tree.lock().unwrap();
@ -212,6 +251,7 @@ impl JobThreadContext {
if let Some(instigating_source) = &instance.metadata().instigating_source {
match instigating_source {
InstigatingSource::Path(path) => {
log::info!("Two-way sync: Removing file {}", path.display());
if let Err(err) = fs::remove_file(path) {
log::error!(
"Failed to remove file {:?} for instance {:?}: {}",
@ -264,6 +304,10 @@ impl JobThreadContext {
match instigating_source {
InstigatingSource::Path(path) => {
if let Some(Variant::String(value)) = changed_value {
log::info!(
"Two-way sync: Writing Source to {}",
path.display()
);
if let Err(err) = fs::write(path, value) {
log::error!(
"Failed to write Source to {:?} for instance {:?}: {}",
@ -290,7 +334,7 @@ impl JobThreadContext {
);
}
} else {
log::warn!("Cannot change properties besides BaseScript.Source.");
log::trace!("Skipping non-Source property change: {}", key);
}
}
} else {

23
src/web/api.rs
View file

@ -264,6 +264,29 @@ impl ApiService {
}
}
// Log property updates being synced back
for update in &request.updated {
let prop_names: Vec<&str> = update
.changed_properties
.keys()
.map(|k| k.as_str())
.collect();
if !prop_names.is_empty() {
log::info!(
"Syncback: Updating properties for instance {:?}: {}",
update.id,
prop_names.join(", ")
);
}
if update.changed_name.is_some() {
log::info!(
"Syncback: Renaming instance {:?} to {:?}",
update.id,
update.changed_name
);
}
}
let updated_instances = request
.updated
.into_iter()