macOS caching server issues

[BigToeKnee810]

So, I am running a caching server on macOS 10.12.3. We are having issues with this server not caching anything. I ran a few things to see what the deal was. Anyone have any ideas? The thing that sticks out the most is "caching:Port=0"

sudo serveradmin settings caching

caching:ReservedVolumeSpace = 25000000000
caching:LogClientIdentity = "true"
caching:ListenRanges:_array_index:0:first = "10.1.121.10"
caching:ListenRanges:_array_index:0:last = "10.1.121.254"
caching:ListenRanges:_array_index:1:first = "10.1.119.10"
caching:ListenRanges:_array_index:1:last = "10.1.119.254"
caching:ListenRanges:_array_index:2:first = "10.127.184.10"
caching:ListenRanges:_array_index:2:last = "10.127.191.254"
caching:ListenRanges:_array_index:3:first = "10.1.120.10"
caching:ListenRanges:_array_index:3:last = "10.1.120.254"
caching:ListenRanges:_array_index:4:first = "127.0.0.1"
caching:ListenRanges:_array_index:4:last = "127.0.0.1"
caching:Port = 0
caching:PeerLocalSubnetsOnly = no
caching:CacheLimit = 0
caching:DataPath = "/Library/Server/Caching/Data"
caching:ListenRangesOnly = no
caching:PublicRanges:_array_index:0:first = "X.X.X.115"
caching:PublicRanges:_array_index:0:last = "X.X.X.115"
caching:PublicRanges:_array_index:1:first = "X.X.X.121"
caching:PublicRanges:_array_index:1:last = "X.X.X.121"
caching:ServerGUID = "XXXXXXXXXXXXXXXXXXXXXXXX"
caching:LocalSubnetsOnly = no
caching:ServerRoot = "/Library/Server"

sudo serveradmin fullstatus caching

caching:CacheLimit = 0
caching:StartupStatus = "OK"
caching:RegistrationStatus = 1
caching:CacheFree = 996619654656
caching:PersonalCacheUsed = 0
caching:TotalBytesDropped = 0
caching:CacheStatus = "OK"
caching:TotalBytesStoredFromOrigin = 0
caching:state = "RUNNING"
caching:Port = 49417
caching:Peers = _empty_array
caching:TotalBytesStoredFromPeers = 0
caching:RestrictedMedia = no
caching:CacheDetails:_array_index:0:BytesUsed = 0
caching:CacheDetails:_array_index:0:LocalizedType = "Mac Software"
caching:CacheDetails:_array_index:0:MediaType = "Mac Software"
caching:CacheDetails:_array_index:0:Language = "en"
caching:CacheDetails:_array_index:1:BytesUsed = 0
caching:CacheDetails:_array_index:1:LocalizedType = "iOS Software"
caching:CacheDetails:_array_index:1:MediaType = "iOS Software"
caching:CacheDetails:_array_index:1:Language = "en"
caching:CacheDetails:_array_index:2:BytesUsed = 0
caching:CacheDetails:_array_index:2:LocalizedType = "Apple TV Software"
caching:CacheDetails:_array_index:2:MediaType = "Apple TV Software"
caching:CacheDetails:_array_index:2:Language = "en"
caching:CacheDetails:_array_index:3:BytesUsed = 0
caching:CacheDetails:_array_index:3:LocalizedType = "iCloud"
caching:CacheDetails:_array_index:3:MediaType = "iCloud"
caching:CacheDetails:_array_index:3:Language = "en"
caching:CacheDetails:_array_index:4:BytesUsed = 0
caching:CacheDetails:_array_index:4:LocalizedType = "Books"
caching:CacheDetails:_array_index:4:MediaType = "Books"
caching:CacheDetails:_array_index:4:Language = "en"
caching:CacheDetails:_array_index:5:BytesUsed = 0
caching:CacheDetails:_array_index:5:LocalizedType = "iTunes U"
caching:CacheDetails:_array_index:5:MediaType = "iTunes U"
caching:CacheDetails:_array_index:5:Language = "en"
caching:CacheDetails:_array_index:6:BytesUsed = 0
caching:CacheDetails:_array_index:6:LocalizedType = "Movies"
caching:CacheDetails:_array_index:6:MediaType = "Movies"
caching:CacheDetails:_array_index:6:Language = "en"
caching:CacheDetails:_array_index:7:BytesUsed = 0
caching:CacheDetails:_array_index:7:LocalizedType = "Music"
caching:CacheDetails:_array_index:7:MediaType = "Music"
caching:CacheDetails:_array_index:7:Language = "en"
caching:CacheDetails:_array_index:8:BytesUsed = 0
caching:CacheDetails:_array_index:8:LocalizedType = "Other"
caching:CacheDetails:_array_index:8:MediaType = "Other"
caching:CacheDetails:_array_index:8:Language = "en"
caching:PersonalCacheLimit = 0
caching:CacheUsed = 0
caching:TotalBytesStored = 0
caching:TotalBytesImported = 0
caching:PersonalCacheFree = 996619654656
caching:Active = yes
caching:TotalBytesReturned = 0

[Kaltsas]

If you run the following on a 10.12 client

/usr/bin/assetcachelocatorutil

Does it return found 0 servers or does it return something like

x.x.x.x:49472, valid until 2017-02-08 13:30:10; supports personal caching: no, and import: n/a, shared caching: yes

[BigToeKnee810]

2017-02-08 15:47:06.805 assetcachelocatorutil[8472:40412] assetcachelocatorutil version 31.2, framework version 31.2
2017-02-08 15:47:06.806 assetcachelocatorutil[8472:40412] --- Information for system services:
2017-02-08 15:47:06.806 assetcachelocatorutil[8472:40412] Checking whether there might be caching server(s) available...
2017-02-08 15:47:06.807 assetcachelocatorutil[8472:40412] There might be caching server(s) available.
2017-02-08 15:47:06.807 assetcachelocatorutil[8472:40412] Checking for saved servers supporting personal caching...
2017-02-08 15:47:06.808 assetcachelocatorutil[8472:40412] There is no saved result.  (This is not an error.)
2017-02-08 15:47:06.808 assetcachelocatorutil[8472:40412] Checking for saved servers supporting personal caching and import...
2017-02-08 15:47:06.808 assetcachelocatorutil[8472:40412] There is no saved result.  (This is not an error.)
2017-02-08 15:47:06.808 assetcachelocatorutil[8472:40412] Checking for saved servers supporting shared caching...
2017-02-08 15:47:06.808 assetcachelocatorutil[8472:40412] There is no saved result.  (This is not an error.)
2017-02-08 15:47:06.809 assetcachelocatorutil[8472:40412] Found total 0 saved servers
2017-02-08 15:47:06.809 assetcachelocatorutil[8472:40412] Checking for refreshed servers supporting personal caching...
2017-02-08 15:47:06.817 assetcachelocatorutil[8472:40412] Found 1 server
2017-02-08 15:47:06.817 assetcachelocatorutil[8472:40412] Checking for refreshed servers supporting personal caching and import...
2017-02-08 15:47:06.817 assetcachelocatorutil[8472:40412] Found 1 server
2017-02-08 15:47:06.817 assetcachelocatorutil[8472:40412] Checking for refreshed servers supporting shared caching...
2017-02-08 15:47:06.818 assetcachelocatorutil[8472:40412] Found 1 server
2017-02-08 15:47:06.818 assetcachelocatorutil[8472:40412] Found total 1 refreshed server
2017-02-08 15:47:06.818 assetcachelocatorutil[8472:40412] localhost:49417, valid until 2017-02-08 16:07:06; supports personal caching: yes, and import: yes, shared caching: yes
2017-02-08 15:47:06.818 assetcachelocatorutil[8472:40412] --- Information for user 501 (results for other users may be different):
2017-02-08 15:47:06.818 assetcachelocatorutil[8472:40412] Checking whether there might be caching server(s) available...
2017-02-08 15:47:06.819 assetcachelocatorutil[8472:40412] There might not be caching server(s) available.
2017-02-08 15:47:06.819 assetcachelocatorutil[8472:40412] Checking for saved servers supporting personal caching...
2017-02-08 15:47:06.820 assetcachelocatorutil[8472:40412] Found 0 servers
2017-02-08 15:47:06.820 assetcachelocatorutil[8472:40412] Checking for saved servers supporting personal caching and import...
2017-02-08 15:47:06.820 assetcachelocatorutil[8472:40412] Found 0 servers
2017-02-08 15:47:06.820 assetcachelocatorutil[8472:40412] Checking for saved servers supporting shared caching...
2017-02-08 15:47:06.821 assetcachelocatorutil[8472:40412] Found 0 servers
2017-02-08 15:47:06.821 assetcachelocatorutil[8472:40412] Found total 0 saved servers
2017-02-08 15:47:06.821 assetcachelocatorutil[8472:40412] Checking for refreshed servers supporting personal caching...
2017-02-08 15:47:06.823 assetcachelocatorutil[8472:40412] Found 1 server
2017-02-08 15:47:06.823 assetcachelocatorutil[8472:40412] Checking for refreshed servers supporting personal caching and import...
2017-02-08 15:47:06.824 assetcachelocatorutil[8472:40412] Found 1 server
2017-02-08 15:47:06.824 assetcachelocatorutil[8472:40412] Checking for refreshed servers supporting shared caching...
2017-02-08 15:47:06.824 assetcachelocatorutil[8472:40412] Found 1 server
2017-02-08 15:47:06.825 assetcachelocatorutil[8472:40412] Found total 1 refreshed server
2017-02-08 15:47:06.825 assetcachelocatorutil[8472:40412] localhost:49417, valid until 2017-02-08 16:07:06; supports personal caching: yes, and import: yes, shared caching: yes

[Kaltsas]

did you run this on a client or the server itself, i.e. it found a server at localhost:49417 (or did you replace the ip with local host)

[BigToeKnee810]

@Kaltsas I ran this on the server itself. Here are the results on a client machine.

2017-02-08 16:12:56.555 assetcachelocatorutil[1954:24141] assetcachelocatorutil version 31.2, framework version 31.2
2017-02-08 16:12:56.555 assetcachelocatorutil[1954:24141] --- Information for system services:
2017-02-08 16:12:56.555 assetcachelocatorutil[1954:24141] Checking whether there might be caching server(s) available...
2017-02-08 16:12:56.597 assetcachelocatorutil[1954:24141] There might be caching server(s) available.
2017-02-08 16:12:56.597 assetcachelocatorutil[1954:24141] Checking for saved servers supporting personal caching...
2017-02-08 16:12:56.599 assetcachelocatorutil[1954:24141] There is no saved result.  (This is not an error.)
2017-02-08 16:12:56.599 assetcachelocatorutil[1954:24141] Checking for saved servers supporting personal caching and import...
2017-02-08 16:12:56.600 assetcachelocatorutil[1954:24141] There is no saved result.  (This is not an error.)
2017-02-08 16:12:56.600 assetcachelocatorutil[1954:24141] Checking for saved servers supporting shared caching...
2017-02-08 16:12:56.600 assetcachelocatorutil[1954:24141] There is no saved result.  (This is not an error.)
2017-02-08 16:12:56.600 assetcachelocatorutil[1954:24141] Found total 0 saved servers
2017-02-08 16:12:56.600 assetcachelocatorutil[1954:24141] Checking for refreshed servers supporting personal caching...
2017-02-08 16:12:56.877 assetcachelocatorutil[1954:24141] Found 0 servers
2017-02-08 16:12:56.877 assetcachelocatorutil[1954:24141] Checking for refreshed servers supporting personal caching and import...
2017-02-08 16:12:56.877 assetcachelocatorutil[1954:24141] Found 0 servers
2017-02-08 16:12:56.877 assetcachelocatorutil[1954:24141] Checking for refreshed servers supporting shared caching...
2017-02-08 16:12:56.878 assetcachelocatorutil[1954:24141] Found 0 servers
2017-02-08 16:12:56.878 assetcachelocatorutil[1954:24141] Found total 0 refreshed servers
2017-02-08 16:12:56.878 assetcachelocatorutil[1954:24141] --- Information for user 881483982 (results for other users may be different):
2017-02-08 16:12:56.878 assetcachelocatorutil[1954:24141] Checking whether there might be caching server(s) available...
2017-02-08 16:12:56.908 assetcachelocatorutil[1954:24141] There might be caching server(s) available.
2017-02-08 16:12:56.908 assetcachelocatorutil[1954:24141] Checking for saved servers supporting personal caching...
2017-02-08 16:12:56.910 assetcachelocatorutil[1954:24141] There is no saved result.  (This is not an error.)
2017-02-08 16:12:56.910 assetcachelocatorutil[1954:24141] Checking for saved servers supporting personal caching and import...
2017-02-08 16:12:56.911 assetcachelocatorutil[1954:24141] There is no saved result.  (This is not an error.)
2017-02-08 16:12:56.911 assetcachelocatorutil[1954:24141] Checking for saved servers supporting shared caching...
2017-02-08 16:12:56.911 assetcachelocatorutil[1954:24141] There is no saved result.  (This is not an error.)
2017-02-08 16:12:56.911 assetcachelocatorutil[1954:24141] Found total 0 saved servers
2017-02-08 16:12:56.911 assetcachelocatorutil[1954:24141] Checking for refreshed servers supporting personal caching...
2017-02-08 16:12:57.066 assetcachelocatorutil[1954:24141] Found 0 servers
2017-02-08 16:12:57.066 assetcachelocatorutil[1954:24141] Checking for refreshed servers supporting personal caching and import...
2017-02-08 16:12:57.067 assetcachelocatorutil[1954:24141] Found 0 servers
2017-02-08 16:12:57.067 assetcachelocatorutil[1954:24141] Checking for refreshed servers supporting shared caching...
2017-02-08 16:12:57.067 assetcachelocatorutil[1954:24141] Found 0 servers
2017-02-08 16:12:57.067 assetcachelocatorutil[1954:24141] Found total 0 refreshed servers

[Kaltsas]

It's not caching anything because the client doesn't think there's a registered caching server available. Caching Server only downloads something when a GET request is made from an applicable client.

If you look at /Library/Server/Caching/Logs/Debug.log on the server you'll notice when a client makes a request. It will look something like

2017-02-08 15:08:12.345 #QjR9rbVtP1fs Received GET request by "MacAppStore/2.2" for /apple-assets-us-std-000001/Purple111/v4/a8/cb/24/a8cb24bb-75f5-eede-73db-e3627320e109/dwr2030657491772019283.pkg

Are the client and the server currently on the same subnet? If not you'll have to modify your DNS records to accommodate.

https://help.apple.com/serverapp/mac/5.2/#/apd6015d9573

Basically on NAT, on the same subnet it will all work automagically. Out side of that you'll need to make some modifications so Apple knows where to point clients when they make a request.

[BigToeKnee810]

@Kaltsas Do we need to modify the DNS on the Apple Server or in our DNS server?

[Kaltsas]

You will need to configure the applicable networks in server.app (serve clients with public addresses on other networks). You will then be able to generate the necessary records for your DNS server from the caching service. See the above link. It's pretty straightforward (assuming your network folks give you adequately defined ranges and are willing to update your DNS records)

[BigToeKnee810]

@kaltsas Added the new entries to DNS following the directions in the link you provided. Still not caching. The client is still getting 0 servers and the log on the server says the following:

2017-02-16 11:26:40.857 Cleanup succeeded.
2017-02-16 11:26:41.107 Request for registration from https://lcdn-registration.apple.com/lcdn/register succeeded
2017-02-16 11:26:41.107 Got back public IP X.X.X.121
2017-02-16 11:26:41.110 This server knows about 0 other caching servers
2017-02-16 12:21:41.237 Request for configuration from http://suconfig.apple.com/resource/registration/v1/config.plist succeeded
2017-02-16 12:21:41.248 Registering with local address: 10.1.88.147 (1000 Mbit/sec wired); listen ranges only: 10.1.121.10-10.1.121.254, 10.1.119.10-10.1.119.254, 10.127.184.10-10.127.191.254, 10.1.120.10-10.1.120.254, 127.0.0.1; public ranges: X.X.X.115, X.X.X.121; on AC power: yes; cache size: ~990 GB; capabilities: im,ns,pc,qp,sc,ur; portable: no
2017-02-16 12:21:41.271 Cleanup succeeded.
2017-02-16 12:21:41.446 Request for registration from https://lcdn-registration.apple.com/lcdn/register succeeded
2017-02-16 12:21:41.446 Got back public IP X.X.X.121
2017-02-16 12:21:41.448 This server knows about 0 other caching servers

[nkuhl30]

I'm really hoping that the caching service is more solid in 10.12. Ever since it's inception, it never worked nearly as well as Software Update service. And yes, I know they're different but Software Update is being depreciated. Even when everything is configured perfectly, we'd see random computers not use it for one reason or another. Apple's focus on management is severely lacking.

[Kaltsas]

If by better you mean not. :)

http://www.openradar.me/30311121

I also have an enterprise case open for this.

[AVmcclint]

My Caching server seemed to be working just fine up until I upgraded the server to 10.12. Then it stopped working. I'm getting the same symptoms you are where the server doesn't show any attempts to connect to it and nothing is cached or served out.

[BigToeKnee810]

I am glad I am not the only one experiencing this problem. Thanks guys! I guess we will have to wait for Apple on this one.

[anverhousseini]

I found out, that you will have to set up DNS on the server itself. Create the primary zone and just make the entry for your server. In the network settings point the DNS to your own machine (static IP = DNS IP). I had some caching servers which were not working while using an another DNS server then the one on the same machine.

[AVmcclint]

Setup DNS on the Mac server itself? Does that assume we then need to add that Mac server as a DNS server to all the client Macs? If so, that definitely won't work in my environment. We have to use the company's DNS servers (Non-Mac server OS) and getting the network admins to add anything to static entries requires an act of Congress.

It's just very odd that everything was working fine under 10.11, then broke as soon as 10.12 was installed with no changes to any of the services' configurations.