Server 2.2: Caching server not caching content

I get a similar issue

2012/12/17 12:23:06:621 Caching server started

2012/12/17 12:23:06:628 Server GUID is XXXXXX-E717-XXXX-BXXA-XXXXXXXXXX (Guid preserved to protect the innocent)

2012/12/17 12:23:06:642 Cache manager initialized, cache limit = unlimited, current cache size = 0 bytes

2012/12/17 12:23:06:642 xpcListener should be running

2012/12/17 12:23:06:642 HTTPServer: Started HTTP server on port 55769

2012/12/17 12:23:06:645 Retrieving configuration

2012/12/17 12:23:07:305 Request for configuration from http://suconfig.apple.com/resource/registration/v1/config.plist succeeded

2012/12/17 12:23:07:371 computerModelRules missing from configuration http://suconfig.apple.com/resource/registration/v1/config.plist

2012/12/17 12:23:07:451 Cleaning cache

2012/12/17 12:23:07:535 Cleanup succeeded.

2012/12/17 12:23:07:535 Registering for notifications

2012/12/17 12:23:07:538 Registering for service

2012/12/17 12:23:08:933 Request for registration from https://lcdn-registration.apple.com/lcdn/register failed: HTTP response 400, body "INVALID_DEVICE"

2012/12/17 12:23:08:933 Registration rejected.

2012/12/17 12:23:08:934 Flushing cache.

2012/12/17 12:23:08:934 Server is suspended. Will re-register in 3600 seconds.

2012/12/17 12:23:11:866 Server shutting down (15)

I have selected a fresh partition of 250GB on a new disk. My network is NAT'ed and sits on 192.168.0.X. The second network card in my Macpro is unassigned. I mention this as somebody thought the issue was due to not being NAT'ed or having a second IP address equal to something or other.

My firewall allows all outgoing ports from my Mac.

I have a valid DNS and reverse DNS entry on my single public internet address, though it doesn't match my internal DNS name.

I've looked at the downloaded file http://suconfig.apple.com/resource/registration/v1/config.plist and it looks meaningless. plutil complains about it so it doesn't appear to be a real plist file. od -c provides no clues either.

I turned Software Update Server off as well, that made no difference.

If I connect to https://lcdn-registration.apple.com/lcdn/register I got the message back "Not Implemented" which could be simply due to me not providing the right args.

After this I ran out of ideas. Any suggestions welcomed.

Thanks,

Rob

Do you have the OS installed on a virtual machine?

Nope, I would have said if it was on a VMWare or Parallels session. It's running on a MacPro (as stated in post) with 16GB RAM, lots of disk and two CPU's.

Clearly it's OS X Server 2.2 on Mountain Lion.

What puzzles me is the fact nobody else appears to be having this problem. This should not just be me!

The reason I asked about virtualization is that I'm seeing the on a virtual machine install of 10.8.2.

<speculation>

The config.plist at sucatalog.apple.com is corrupt on one of the hosts in the cache.

or

The config.plist is called with a parameter that is either hardware based (virtualization) or a value in a plist that is corrupt.

etc

</speculation>

Interesting speculation.

The machine is an old MacPro. I wonder if thats got anything to do with it?

I'll try and sniff the output and see what parameters are passed.

I was missing complete .Log directory with appropriate user & rights and the .plist file for the caching service.

Should be inside /Library/Server/Software Update/Caching directory. But I'm on the road. Just remembering rough details.After correcting this faulty installation the caching service does work as supposed to do.

Ok, thats a good call. I'll have a look for that.

Am on the road myself but will check this evening when back.

Thanks

Rob

Wrong directory !
/Library/Server/Caching/

Logs is there…

server:Caching ladmin$ ls /Library/Server/Caching/

Config Logs

./Config/Config.plist:

Read&Write

Only Read
Only Read

Another source:

OS X Server: Advanced configuration of the Caching service

http://support.apple.com/kb/HT5590

Well, all the permissions look right.

I have deleted all the directries under Caching and it recreates them with the right permissions.

I've moved the logging level to verbose and run it again and that seems to make no difference.

I have two files in the directory Logs

macpro:Logs XXXXXX$ ls -l

total 16

-rw-r--r-- 1 _assetcache _assetcache 1235 17 Dec 20:56 Debug.log

-rw-r--r-- 1 root _assetcache 929 17 Dec 20:56 LastState.plist

macpro:Logs XXXXXXX$

Debug.Log looks like

and LastState.plist looks like

If I show the directory /Library/Server/Caching I get

macpro:Caching XXXXXX$ sudo ls -lR

Password:

total 0

drwxrwxr-x 3 _assetcache _assetcache 102 17 Dec 20:56 Config

drwxr-x--- 3 _assetcache _assetcache 102 17 Dec 20:56 Data

drwxr-xr-x 4 _assetcache _assetcache 136 17 Dec 20:56 Logs

./Config:

total 24

-rw-r--r-- 1 _assetcache _assetcache 10015 17 Dec 20:56 Config.plist

./Data:

total 40

-rw-r----- 1 _assetcache _assetcache 20480 17 Dec 20:56 AssetInfo.db

./Logs:

total 16

-rw-r--r-- 1 _assetcache _assetcache 1235 17 Dec 20:56 Debug.log

-rw-r--r-- 1 root _assetcache 929 17 Dec 20:56 LastState.plist

plutil -p looks OK (well to me it does)

macpro:Config rwillett$ plutil -p Config.plist

{

"ReservedVolumeSpace" => 25000000000

"LastConfigURL" => "http://suconfig.apple.com/resource/registration/v1/config.plist"

"SingleMachineMode" => 0

"Port" => 0

"SavedCacheSize" => 0

"LastPort" => 53484

"Version" => 1

"CacheLimit" => 0

"DataPath" => "/Library/Server/Caching/Data"

"LastConfigData" => <LOTS AND LOTS OF RANDOM DATA REMOVED AS I HAVE NO IDEA WHAT IT IS 🙂>

"ServerGUID" => "882E672A-0172-4A21-84E0-0C1FC08DBC53"

"ServerRoot" => "/Library/Server"

}

After all this good stuff, I still have the same error of

2012/12/17 20:56:19:750 Caching server started

2012/12/17 20:56:19:768 Server GUID is 882E672A-0172-4A21-84E0-0C1FC08DBC53

2012/12/17 20:56:19:787 Cache manager initialized, cache limit = unlimited, current cache size = 0 bytes

2012/12/17 20:56:19:787 xpcListener should be running

2012/12/17 20:56:19:788 HTTPServer: Started HTTP server on port 53484

2012/12/17 20:56:19:797 Retrieving configuration

2012/12/17 20:56:19:950 Request for configuration from http://suconfig.apple.com/resource/registration/v1/config.plist succeeded

2012/12/17 20:56:20:027 computerModelRules missing from configuration http://suconfig.apple.com/resource/registration/v1/config.plist

2012/12/17 20:56:20:112 Cleaning cache

2012/12/17 20:56:20:185 Cleanup succeeded.

2012/12/17 20:56:20:185 Registering for notifications

2012/12/17 20:56:20:188 Registering for service

2012/12/17 20:56:21:432 Request for registration from https://lcdn-registration.apple.com/lcdn/register failed: HTTP response 400, body "INVALID_DEVICE"

2012/12/17 20:56:21:436 Registration rejected.

2012/12/17 20:56:21:440 Flushing cache.

2012/12/17 20:56:21:440 Server is suspended. Will re-register in 3600 seconds.

2012/12/17 20:56:25:055 Server shutting down (15)

I'm surprised I'm the only person having this. It looks as if the system makes a connection to Apple, downloads some stuff and then rejects my registration.

I'm very puzzled.

This error message puzzles me. Are you very sure about the correct setup of your reverse DNS and (maybe) proxy setup ?

Looks like the request you send doesn't match the query the SUS server does expect.

Request for registration from https://lcdn-registration.apple.com/lcdn/register failed: HTTP response 400, body "INVALID_DEVICE"
Registration rejected.

My thinking here is that either certificates are screwed (I never understood Apples implementation) or as you say, DNS and/or reverse DNS. I've updated the DNS settings earlier this morning and am going to try to work through this again this evening.

Checked reverse DNS and changed it from my ADSL provided name to the name of the Mac server (macpro.robertwillett,com). Checked it again and it now returns macpro.robertwillett.com.

Started caching server and now I get

Dec 19 06:57:44 macpro.robertwillett.com AssetCache[8759]: Caching server started

Dec 19 06:57:46 macpro.robertwillett.com AssetCache[8759]: Request for registration from https://lcdn-registration.apple.com/lcdn/register failed: HTTP response 400, body "INVALID_DEVICE"

Dec 19 06:57:46 macpro.robertwillett.com AssetCache[8759]: Registration rejected.

Dec 19 06:57:46 macpro.robertwillett.com AssetCache[8759]: Server is suspended. Will re-register in 3600 seconds.

Dec 19 06:57:49 macpro.robertwillett.com AssetCache[8759]: Server shutting down (15)

Dec 19 06:57:49 macpro com.apple.launchd[1] (com.apple.AssetCache[8759]): Exited with code: 1

Removed /Library/Server/Caching

Ran again

Dec 19 07:01:14 macpro.robertwillett.com AssetCache[8924]: Caching server started

Dec 19 07:01:17 macpro.robertwillett.com AssetCache[8924]: Request for registration from https://lcdn-registration.apple.com/lcdn/register failed: HTTP response 400, body "INVALID_DEVICE"

Dec 19 07:01:17 macpro.robertwillett.com AssetCache[8924]: Registration rejected.

Dec 19 07:01:17 macpro.robertwillett.com AssetCache[8924]: Server is suspended. Will re-register in 3600 seconds.

Dec 19 07:01:20 macpro.robertwillett.com AssetCache[8924]: Server shutting down (15)

Dec 19 07:01:20 macpro com.apple.launchd[1] (com.apple.AssetCache[8924]): Exited with code: 15

So reverse DNS looks OK yet nothing is working.

I'm running a 'normal' home network (if there is such a thing). My IP address is static and so doesn;t change from day to day. I have a Smoothwall firewall to protect things. I haven't opened up any ports specifically for the caching server.

I run NAT behind the firewall and until now, after 12 years, haven't had any issues with NAT. I do run my own DNS server for internal machines, e.g. macpro.robertwillett.com resolves to 192.168.0.8 on the NAT side of the network but resolves to a real IP address on the external side. Thats the same system for my mail server, dedicated Linux box.

I suppose the next step is checking certificates.

Any and all suggestions welcomed.

The 400 Bad Request HTTP status code means that the request you sent to the website server (for example, a request to load a web page) was somehow malformed.

Since the server couldn't understand the request, it couldn't process it and instead gave you the 400 error.

I'm in the same boat, except that my external IP address is dynamic and my DNS supports only internal zones, no split DNS. Not changed the firewall rules for caching service.