Search Unity

  1. Welcome to the Unity Forums! Please take the time to read our Code of Conduct to familiarize yourself with the forum rules and how to post constructively.

Unity Accelerator - Editors upload to cache, but never download.

Discussion in 'Unity Accelerator' started by JJRivers, Feb 10, 2021.

  1. JJRivers

    JJRivers

    Joined:
    Oct 16, 2018
    Posts:
    137
    First time attempting for our project to use the Unity Accelerator for ADB2 caching with Unity Accelerator.
    I have gotten it to function in the sense that all remotes and locals do upload and logs show that the put requests go through and it is indeed creating artifacts in the cache when a user changes something.

    But we can't get editors to download said artifacts.

    Now obviously the tool is highly oriented towards Unity Collaborate but i've seen it posted in several places that we should be able to use the ADB2 caching functionality even if we do not use Unitys version of source control (we use Git).

    Most of the time we spend on asset imports (think texture crunches and the like) not with the transfer of source files which don't take much time.

    So have i misunderstood what the function of the ADB2 server is and if not, why aren't client editors recognizing the artifacts another user uploaded as the same file and fetching that instead of importing that.

    Tested with material / texture files.


    I have a simple wizard install of Accelerator with no encryption and have verified that the connections to / from the server work. Logs show clients successfully doing put requests to the database, but all get requests fail with:

    Code (CSharp):
    1.   {
    2.     "level": "debug",
    3.     "ts": "2021-02-10T11:48:30.174+0200",
    4.     "msg": "handled getRequest",
    5.     "agent_id": "DesktopWork_id",
    6.     "agent_name": "DesktopWork",
    7.     "component": "pbservice",
    8.     "subprocess_id": 6,
    9.     "conn_id": 2,
    10.     "remote": "edited out for obvious reasons",
    11.     "segment_id": 13592,
    12.     "namespace": "81e94844d19a16919208533e08183531",
    13.     "key": "2916b0e0f0dd01b28018ff1e88323dd5",
    14.     "status": "key not found",
    15.     "status_code": 3,
    16.     "size": 0
    17.   },
    This leads me to suspect there is something that must be done to ensure all editors use the same method of saving the artifacts but i haven't found any mention or documentation to this. If it exists then it would be great if you could point me to it.
     
    JJRivers, Feb 10, 2021
    #1

  2. henriksc

    henriksc

    Unity Technologies

    Joined:
    Aug 27, 2020
    Posts:
    30
    On the surface, your setup sounds good. And yes, the Accelerator can be used even if you are not using Collaborate. The "CacheServer" feature is completely source control independent, so you can use what ever VCS flavour you want.

    By default the editor should try to download import results and upload after an import. There are project settings and command line overrides to change this behaviour. Look at the "Configuring Editors to use an Accelerator" section in the Accelerator documentation https://docs.unity3d.com/2021.1/Documentation/Manual/UnityAccelerator.html

    If you send your editor.log and accelerator.log, then I can have a look at it and hopefully point you in a more specific direction.
     
    henriksc, Feb 11, 2021
    #2

  3. JJRivers

    JJRivers

    Joined:
    Oct 16, 2018
    Posts:
    137
    Thank you for your answer i will be posting logs tomorrow or at the latest over the weekend once i save some activity in the logs so you can actually see what the issue is.

    edit: And to clarify, current setup has all editors with download/upload both enabled, TLS off for both the Accelerator and the Editors.
     
    JJRivers, Feb 11, 2021
    #3

  4. JJRivers

    JJRivers

    Joined:
    Oct 16, 2018
    Posts:
    137
    Attached is a zip with the relevant logs and a very brief README on what were the actions taken to generate them.
     

    Attached Files:

    JJRivers, Feb 12, 2021
    #4

  5. henriksc

    henriksc

    Unity Technologies

    Joined:
    Aug 27, 2020
    Posts:
    30
    From your logs there are two things that stand out to me.

    1. It seems to take a very long time to actually get connected to the accelerator. Normally this happens right in the beginning when starting up an editor. But here it seems to fail the first attempt and eventually gets connected later on. It's difficult to say why this is, it's not something we've seen before. One thing you could try is to use the command line option "-cacheServerWaitForConnection 5000", it will force the editor wait for a connection for 5 seconds before continuing. You can also just pass "-cacheServerWaitForConnection" which will force it wait forever until a connection is established.

    2. Once it's connected, it seems to be working properly. Tries to download metadata and if not available it does the import and uploads the result.
    However if I look at an asset like "Assets/+RedStage/RawAssets/EnvironmentRaw/BushesRaw/Textures/T_Willow_Bush_02_Cross_A_T.png", its static dependency hash is different between the local and remote editor logs. Therefore it doesn't find it and ends up doing an import and upload. One reason for this, that I've seen before, is when line endings differ between machines. For instance, depending on configuration Git might select LF on one machine and CRLF on another. This would result in different hashes of the meta and content files.

    Let me know if any of this helps you.
     
    henriksc, Feb 17, 2021
    #5

  6. JJRivers

    JJRivers

    Joined:
    Oct 16, 2018
    Posts:
    137
    Apologies this was put on ice for the moment and i haven't tested yet. These sound something reasonable to test and i will do so within the coming week and get back to you. Thank you very much for your effort at helping us. Get back to you soonest we can!
     
    JJRivers, Mar 2, 2021
    #6

  7. jhughes2112

    jhughes2112

    Joined:
    Nov 20, 2014
    Posts:
    169
    So, two huge problems with this system.
    1. Every developer I know uses 'native' line endings when checking into git or most other VCSs.
    2. Most people who are efficient these days use docker to run random programs to keep their machine clean, which means the Unity Accelerator running in docker is essentially running in WSL/Linux.

    It sounds like the way the cache system works is useless. I'm going to ask a really obvious question and probably not like the answer but... what doesn't the CLIENT compute the hash of the contents and send the OUTPUT of the build process to the cache server? I don't see why there needs to be any agreement whatsoever between the client and the cache.
     
    jhughes2112, Sep 7, 2022
    #7

  8. jhughes2112

    jhughes2112

    Joined:
    Nov 20, 2014
    Posts:
    169
    For clarity, I'm running a cache server completely locally. And I spend 45 minutes building shaders constantly. I get logs like this:

    ShaderCacheRemote uploaded key '3e8dd706ae4c010d295355dbd2bee212'
    
    finished in 0.16 seconds. Local cache hits 0 (0.00s CPU time), remote cache hits 0 (0.00s CPU time), compiled 2 variants (0.32s CPU time), skipped 0 variants


    I can't for the life of me understand why shaders--the slowest resource to build--would never cache hit?
     
    jhughes2112, Sep 7, 2022
    #8

  9. jhughes2112

    jhughes2112

    Joined:
    Nov 20, 2014
    Posts:
    169
    Something interesting. I monitored the build (I had hours to sit and watch it NOT download shaders from the cache today). I enabled the excessive logging feature in the docker container, which is helpful. Here's something I saw (reduced to just the requests related to a single asset, for clarity):
    So, this shader was not found.
    Then it was pushed to the cache server, and it took about 1.5 seconds to process, from the timestamps.
    I have the folder structure bind-mounted from my PC into the docker container, so I can see whatever it's writing to the folder structure. There are definitely timestamps for all kinds of files being uploaded. However, this one does not show up:
    If I search for 6f51d nothing shows up at all. Seems broken to me.
     
    jhughes2112, Sep 8, 2022
    #9

  10. henriksc

    henriksc

    Unity Technologies

    Joined:
    Aug 27, 2020
    Posts:
    30
    The Accelerator doesn't contain any logic. It's purely a key/value store. All logic and hashing in done on the editor side.

    The line endings problem I mentioned, is when editors are doing the hashing. If one editor has a VCS checkout using CRLF and another editor has a VCS checkout using LF, then when each editor hashes the source assets it will generate different results. Because of this, they won't be able to look up a matching import result. At least not unless both versions of the import result has been uploaded to the Accelerator. The solution to this is to make sure the VCS controls the line ending so all users use the same.
     
    henriksc, Sep 8, 2022
    #10

  11. jhughes2112

    jhughes2112

    Joined:
    Nov 20, 2014
    Posts:
    169
    Thanks for the explanation. I probably should not post when I'm hungry. :rolleyes:

    Can anyone explain why the shaders are not catching properly though? If it's a dumb kv store, I would expect to see everything pushed to it to show up in the file structure, but it doesn't. And clearly the shaders are not catching bc they rebuild constantly.
     
    jhughes2112, Sep 8, 2022
    #11

  12. SockPuppetFriend

    SockPuppetFriend

    Unity Technologies

    Joined:
    Dec 3, 2021
    Posts:
    9
    Why are your shaders not caching properly? I don't know the answer immediately, but maybe I can still contribute here.

    First, the files in Accelerator are not stored using the same filename as they are in your app's library folder.
    Here is how you can check if a given file is in Accelerator's cache:

    
unity-accelerator cache head <accelerator-ip:host> <namespace> <filename, but with the extension removed>

    Here's an example from my local setup:

    
# File is in Library:
    
$ ls Library/ShaderCache/builtin/unity_builtin_extra0000/00/0e8cf0ba0ff0f2ce0dd80e76f584ea9d.bin -ltrha
    
-rw-rw-r-- 1 oldman oldman 2.6K Sep  8 15:30 Library/ShaderCache/builtin/unity_builtin_extra0000/00/0e8cf0ba0ff0f2ce0dd80e76f584ea9d.bin
    

    
# And it's in the Accelerator cache:
    
$ unity-accelerator cache head 192.168.77.115:10080 defaultshadercache 0e8cf0ba0ff0f2ce0dd80e76f584ea9d
    
2620

    I did a little messing around so I could identify the messages you'd see in editor.log.

    
#This is what you'll see if the file is read from Accelerator:
    
ShaderCacheRemote downloaded 2620 bytes for key '0e8cf0ba0ff0f2ce0dd80e76f584ea9d'
    

    
#This is what you'll see if it isn't present and instead it gets uploaded to Accelerator:
    
ShaderCacheRemote uploaded key '0e8cf0ba0ff0f2ce0dd80e76f584ea9d'

    If you are interested in experimenting, you can delete the file from Accelerator and/or your app's Library folder like so:

    
# Delete it from cache:
    
unity-accelerator cache delete 192.168.77.115:10080 defaultshadercache 0e8cf0ba0ff0f2ce0dd80e76f584ea9d
    

    
# Delete it from your app's Library folder:
    
rm Library/ShaderCache/builtin/unity_builtin_extra0000/00/0e8cf0ba0ff0f2ce0dd80e76f584ea9d.bin

    Also, the issue could be related to Accelerator's eviction mechanism, as possibly your instance is full.
    You can see how many bytes have been evicted like so:

    
$ curl -s <accelerator-ip:port>/metrics | grep -e "^uta_agent_cache_bytes_evicted "
    
uta_agent_cache_bytes_evicted 0

    If the number is non-zero and seems to be increasing over time, then this could be the problem.
    You can configure the eviction policy via Accelerator's config file or via its web-ui here:

    
<accelerator-ip:port>/dashboard/#/config-page

    Hopefully this is useful!
     
    SockPuppetFriend, Sep 9, 2022
    #12

  13. jhughes2112

    jhughes2112

    Joined:
    Nov 20, 2014
    Posts:
    169
    Hi! Thanks for the extensive rundown. If you notice, I quoted logs from the accelerator itself failing to get a specific hash filename, then a little while later putting it and a second or so later claiming it was "handled". I searched the file system and it was not stored there. I understand pretty well how it works. It's not complicated. There is zero eviction bytes and files, since it's sharing my hard drive via bind mount. I have 250gb free.

    From what I can tell, it just doesn't work reliably. I see files with current timestamps so I know it stores some files. Why not all of them? I mean, if the log says it is writing the file I would expect to see it there, but it's clearly not.
     
    jhughes2112, Sep 9, 2022
    #13

  14. SockPuppetFriend

    SockPuppetFriend

    Unity Technologies

    Joined:
    Dec 3, 2021
    Posts:
    9
    Howdy!

    > If you notice, I quoted logs from the accelerator itself failing to get a specific hash filename, then a little while later putting it and a second or so later claiming it was "handled". I searched the file system and it was not stored there.

    Ah, so the first part of my post was to show you how to properly check for the existence of that item in Accelerator's cache - you cannot directly examine the filesystem to determine if it is stored there. You need to use "unity-accelerator cache head ...".

    Then, for next troubleshooting steps, I am interested in what happens if you track the behavior between the Editor and Accelerator for a particular asset that you think is being rebuild/cached incorrectly.

    The sequence you shared was:
    1. Editor queries Accelerator for some specific asset (w/ key: 6f51d78c130e5f75b39c8c65f7d7d61b)
    2. Accelerator say: not found
    3. Editor uploads the asset to Accelerator; it looks successful to me (e.g. "msg": "handled putRequest" & "status": "ok")

    Next steps are:
    4. Correctly check for this asset in Accelerator by using "unity-accelerator cache head ..." as I demo'd. If it doesn't exist, then there is some problem uploading the asset to Accelerator.

    If the asset exists in Accelerator, then let's see what happens if we restart the editor - does the asset get properly loaded from Accelerator? Here is how I would continue:

    5. Shutdown the Editor.
    6. Locate the specific asset in the Library folder for your application. E.g. "find Library -name 6f51d78c130e5f75b39c8c65f7d7d61b*"
    7. Capture its MD5 sum, or use "unity-accelerator tool blob-hash <filename>" to get the "blob hash".
    8. Delete or move the asset file out of the Library folder.
    9. Restart the Editor.
    10. Observe the Editor logs - is the asset found in Accelerator or is it re-uploaded?
    a) If it is found in Accelerator, then things are working correctly.
    b) If it is not found in Accelerator, then we need to know: did this asset change or is it exactly the same as before? You can determine this by comparing the MD5 sum or the "blob hash" between the previous version of this asset and the current version.

    These troubleshooting steps should isolate the issue into one of two categories:
    * There is some problem uploading/retrieving the asset into/from Accelerator.
    or
    * The issue is that the asset is being recomputed each time and it is somehow different, thus making caching not useful.
     
    SockPuppetFriend, Sep 9, 2022
    #14

  15. jhughes2112

    jhughes2112

    Joined:
    Nov 20, 2014
    Posts:
    169
    Thank you so much for the help with this. I quickly skimmed your original message and missed some details. I've been looking at what gets stored and what does not. I am finding some anomolies, which does not appear to indicate the cache system itself, but the build process. I did verify that items get cached and seem to be stored properly (verified with the `cache head` parameters). Aside: Given this is a relatively simple KV store, why not simply support some of the very powerful and standard ones that would allow individuals or teams to launch them locally or shared on a LAN or stored in a cloud? Redis, Couchbase, Cassandra, MongoDB, CockroachDB... the list goes on. Each of which have excellent and mature tools, and less cognitive load placed on your users. At the very least, supporting those would be better than forcing a one-off tool to be the only choice.

    Anyway, here's what I think I'm seeing that is frustrating about the shader caching. It turns out that during my build process, the first build caches a whole bunch of things. The subsequent builds do not because a lot of the content is cached locally (in the /Library/ presumably). The only hits I get in the logs are a long stream of these:

    This goes on for 1400 lines of `key not found` and zero of these ever get published to the cache. That leads me to believe that the build process either fails for them entirely, or at some point the build is too slow and it times out trying to send? Not certain. But another interesting thing is that there are numerous places along the log where the exact same key is requested multiple times simultaneously:

    Randomly clicking around, I found a few keys that are requested 8-10 times in a row, followed by a long gap in time, then another set of 8-10 requests. These items are never uploaded to the cache. From what I can tell, generating the shader variant texts are about 25% of the cost of builds, but it is concerning that multiple attempts at the very same content is being made in rapid succession or even simultaneously. Clearly something is going wrong in the build. What I can say is that items that are put into the cache do show up in the /Library/Artifacts folder:
    But the ones that get multiple requests without a put, do not. So they are taking up build time and producing nothing.

    Thanks again for the explanation of how the cache server works. It's hard to focus during the week when everything else is constantly on fire.

    Best,
    JH
     
    jhughes2112, Sep 11, 2022
    #15

  16. SockPuppetFriend

    SockPuppetFriend

    Unity Technologies

    Joined:
    Dec 3, 2021
    Posts:
    9
    Howdy again JH.

    It sounds like Accelerator is working correctly here then, but maybe something weird is going on with the build process. I'm referring to the symptom of, during a build, seeing the Editor request the same key from Accelerator multiple times, but then never uploading that key... did it generate that resource or not?

    However the Unity Editor build process is outside of my wheelhouse, so I'm not familiar with the expected patterns there. I don't have any specific suggestions for how to proceed, other than by digging into the logs on the Editor side to try and understand what these resources are that are being queried for multiple times, but never uploaded.
     
    SockPuppetFriend, Sep 13, 2022
    #16

  17. jhughes2112

    jhughes2112

    Joined:
    Nov 20, 2014
    Posts:
    169
    Yep, that's what it looks like. Most things appear to get cached. The things that get constantly requested but do not seem to generate assets, actually do not generate anything in the /Library/Artifacts folder, so nothing gets put into the accelerator cache either. Something wrong with some assets in the build process, likely, but I haven't had time to determine what.

    Maybe when I have another free weekend to look at it.
     
    jhughes2112, Sep 13, 2022
    #17

  18. jhughes2112

    jhughes2112

    Joined:
    Nov 20, 2014
    Posts:
    169
    So, it's Build Day. I go to launch the accelerator, and sure enough, it has 3.6GB worth of data from my last build sitting in there. I'm watching the logs as the command line build is uploading more shaders, getting zero hits on pre-existing ones. Two hours lost again. This is not so much about the acclerator now, but that something in the unity build seems to be time-sensitive or environmentally-sensitive, causing the shaders to constantly produce a different hash. I wish there was a better way to debug that. Any ideas?
     
    jhughes2112, Sep 16, 2022
    #18

  19. osgseb

    osgseb

    Joined:
    Jan 17, 2022
    Posts:
    16
    Hello @henriksc

    I'm experiencing the same issue as the author of this post and found no way to understand what's going on.

    On the Acclerator Log section I can see of lot of entries like the following :

    Code (CSharp):
    1. {
    2.     "level": "debug",
    3.     "ts": "2023-02-03T10:28:42.446Z",
    4.     "msg": "handled getRequest",
    5.     "agent_id": "unitytechnologies-accelerator1_id",
    6.     "agent_name": "unitytechnologies-accelerator1",
    7.     "component": "pbservice",
    8.     "subprocess_id": 6,
    9.     "conn_id": 11,
    10.     "remote": "172.17.0.1:46116",
    11.     "segment_id": 11952,
    12.     "namespace": "defaultmetadata",
    13.     "key": "df4c38c695e1dbbf0361f5687a17e055",
    14.     "status": "key not found",
    15.     "status_code": 3,
    16.     "size": 0,
    17.     "blob_hash": 0
    18.   },
    Editor log side, what should I search for ? How can I check the editor is correctly trying to find and download an asset from the remote cache ?

    Thanks
     
    osgseb, Feb 3, 2023
    #19

  20. whj_pwrd

    whj_pwrd

    Joined:
    Oct 27, 2021
    Posts:
    1
    hello @SockPuppetFriend @henriksc

    I also encountered the same problem, my Unity Library folder was generated on the same computer and uploaded to Accelerator, but when I deleted the Library and tried to re-import all resources, it was prompted: "status":" key not found", "status_code": 3, how can I fix this problem?
     

    Attached Files:

    whj_pwrd, Mar 3, 2023
    #20