Logging seems to be broken again

[Meowcat285]

I'm running into a issue where VRC-LOG won't log any avatars at all since 2025.3.1 except for avatar's that I put on. I have --enable-sdk-log-levels enabled and it's still not logging avatars for other users

[ShayBox]

Looks like VRChat yet again broke it, removed avatar id logging... Thanks VRChat!

[ShayBox]

By the way if anyone is interested, this is the cache file structure.

It contains things like computer name, uptime, username, real name, gpu(s), os version & build, etc. VERY identifiable information.

I might add a setting to wipe it as fast as possible when scanning so VRChat doesn't have a chance to upload it, because this gets collected and uploaded every time you change worlds.

[BlackWolfWoof]

If you select the avatar in the big details menu, it still shows the avatsr id.

[Chayotea]

I never saw VRChat Logs "simply output" Avatars ID's. By that I mean just the logs not the amplitude analytics file. What I had discovered in May to get it to work. #21 (comment)
If what I had discovered was not just me then it means unless you did what I did everyone was only logging with the analytics file, Now I suspect the analytics file is not getting logged or maybe sometimes works.

Since the last update 0.13.3 I noticed that when I change worlds I don't see a flood of avatar submissions. Which is suspect sine that update was to fix the scanning. Just now checked analytics file and it indeed still has "avatarIdsEncountered": with all the avatar ID's of the previous instance.

[ShayBox]

The amplitude still works (or does for me), but the logs did also contain avatar ids if you added a launch option, but that's been patched now.

There's also a new thing being worked on, but it will be a bit until I can work on it and get it released.

I also want to add an option to clear the amplitude file after the logger reads it, because it's like 9mb of data that VRChat doesn't need, including identifiable information.

[Chayotea]

Yea that Is what I mean I never saw the in the logs output avatar ID's other than my favorites and I had all the launch options --enable-debug-gui --enable-sdk-log-levels --enable-udon-debug-logging --log-debug-levels=API. Maybe it was just me that had the issue but my fix of setting max decompress size to 0MB and rejoining the instance still works.

[ShayBox]

Supposedly you can also click view avatar details to log that one avatar, haven't tested that though.

[Chayotea]

It explains why it looked to me like it was randomly logging when I was not using my method or joined a world. Just now confirmed it does indeed log the ID by selecting avatar details. [API] Requesting Get avatars/

[Chayotea]

Just confirmed that my avatar amplitude.cache is not being scanned. Deleted it to see if VRC-LOG would throw some angry messages and indeed it did. So it knows it exists but does not log avatars.

I was in a busy world for a few hours then when to home world by myself but I had the amplitude file open in notepad++ so I got a copy when it refreshed. I waited 5 minutes and VRC-LOG did noting.
I then pasted the contents of the analytics file into a text file were the VRChat logs are saved. VRC-LOG comes to life and starts submitting a hundreds of avatars.

[ShayBox]

This release should fix it, let me know https://github.com/ShayBox/VRC-LOG/releases/tag/0.13.6
I've decreased the poll time for the amplitude file from 1s to 100ms, VRChat writes and uploads this file twice per world switch, and wipes it after the second, with about a 1s delay between writing and uploading, so the new opt-in clear_amplitude setting should always be able to catch it before it's been uploaded and wipe it so that VRChat can't upload it.

[Meowcat285]

As per our conversation on Discord:

I discovered that when VRChat first loads a avatar that isn't already in the cache, it will attempt to load the avatar from <VRChat Install Directory>\VRChat_Data\StreamingAssets\Avatars\<Avatar ID>_<version stuff>.vrca. VRChat does this regardless of if the file actually exists, and as a result we can listen for CreateFile operations that return NAME NOT FOUND and we can see what the avatar ID that VRC attempted to load based on the file name it attempts to load.

For example, VRC when loading the avtr ID avtr_10f518dd-ced3-49e7-b331-02ba3f271ec6, we parse this path (C:\Program Files (x86)\Steam\steamapps\common\VRChat\VRChat_Data\StreamingAssets\Avatars\avtr_10f518dd-ced3-49e7-b331-02ba3f271ec6_v147_u2019.4.31f1.vrca) and from that we can get the avatar ID

[Chayotea]

Tested 0.13.6 and success. My analytics file is being logged properly.

[BlackWolfWoof]

@Meowcat285 Does that mean we now have access to a live feed of (new) avatars that load in real-time?

As per our conversation on Discord:

I discovered that when VRChat first loads a avatar that isn't already in the cache, it will attempt to load the avatar from <VRChat Install Directory>\VRChat_Data\StreamingAssets\Avatars\<Avatar ID>_<version stuff>.vrca. VRChat does this regardless of if the file actually exists, and as a result we can listen for CreateFile operations that return NAME NOT FOUND and we can see what the avatar ID that VRC attempted to load based on the file name it attempts to load.

For example, VRC when loading the avtr ID avtr_10f518dd-ced3-49e7-b331-02ba3f271ec6, we parse this path (C:\Program Files (x86)\Steam\steamapps\common\VRChat\VRChat_Data\StreamingAssets\Avatars\avtr_10f518dd-ced3-49e7-b331-02ba3f271ec6_v147_u2019.4.31f1.vrca) and from that we can get the avatar ID

[ShayBox]

@Meowcat285 Does that mean we now have access to a live feed of (new) avatars that load in real-time?

Theoretically it's possible, I wrote code to recieve Windows ETW events which was working, but since has stopped working, either due to an EAC change or maybe because I was originally testing without having rebooted after installing VRChat/EAC and maybe it couldn't block the events yet (that's just a random theory), but ETW doesn't seem to work and it's over my head to figure out.

It seems like the only way to get these events now is using a kernel level filesystem filter driver like procmon, but that requires closing/opening procmon every time it needs to collect, which while it starts minimized, it still steals focus and pressing keys while it's focused interacts with the window.

I could just have it launch once with the logger and have the user manually close it when they want the logger to scan its captured events, which is the way I'm leaning right now, but there's no telling if they're just going to blacklist the procmon driver / process anyway.
I mean if you're gonna do that just send me a C&D already so I can blast you before archiving the project, more than I already do for the absurd amount of personally identifiable data collection you do.

There's always the CBFS Filter driver for $2500 a year :)
Or more realistically a FUSE file system that VRChat lives on to intercept all filesystem actions, but I would want to do both a Windows and Linux version, and I feel like that's out of the scope of this logger project.

I think I'm just going to add basic procmon support for the people that want to tinker with it, basically if you launch the logger with admin it will launch procmon pre-configured minimized (winget install if not available, fallback to UNC if winget's not available), and if you exit procmon it will process and re-start procmon.