Problems with Cache

Todd Miller 41 Reputation points
2020-09-16T22:01:20.88+00:00

I am running CM v1910
Lately I have been having widespread trouble with package caching on client machines.
When I push out a package set to download and run, I am having a fail rate of ~10%.
Looking in the CAS.LOG, I can see that the download is working and I can see the content hash succeeded which proves the content is on the client - but it never makes it into the cache.

Download completed for content HLT0048F.8 under context System  ContentAccess   9/16/2020 3:54:11 PM    6984 (0x1B48)
Hash verification succeeded for content HLT0048F.8 downloaded under context System  ContentAccess   9/16/2020 3:54:12 PM    6984 (0x1B48)
Saved Content ID Mapping HLT0048F.8, C:\WINDOWS\ccmcache\f  ContentAccess   9/16/2020 3:54:12 PM    6984 (0x1B48)
CacheManager: ADD new cache entry for id:HLT0048F Version : 8 Size : 33846K RefCount:1 LastRef Minutes : 0 State : ACTIVE PinDuration : 15058 Location : C:\WINDOWS\ccmcache\f  ContentAccess   9/16/2020 3:54:12 PM    6984 (0x1B48)
Download succeeded for download request {C99E38DA-90AA-4A7D-B052-66B1957D905A}  ContentAccess   9/16/2020 3:54:12 PM    6984 (0x1B48)
Error: DeleteDirectory:- Failed to delete Directory  with Error 0x00000003. ContentAccess   9/16/2020 3:54:12 PM    6984 (0x1B48)
Saved Content ID Mapping HLT0048F.8, C:\WINDOWS\ccmcache\f  ContentAccess   9/16/2020 3:54:13 PM    6308 (0x18A4)

But then over in the execmgr.log the content cant be located and looking in CCMCache there is no "f" folder.

I can often just use clientcenter to force the advertisement to rerun and the download/cache/run will succeed -- though it will be cached in the next higher folder ie "g"

Looking in the c:\windows\ccmcache\ it just skips over that failed "f" caching attempt and the files are all just fine in "g"

The security team swears that they have excluded C:\windows\ccmcache from AV scans - that is the first thing I thought of - and there are no records of blocked files in any AV logs.

In execmgr.log when it fails I get this error.

MTC signaled SWD execution request with program id: I-Install software, package id: HLT0048F for execution. execmgr 9/16/2020 3:54:13 PM 6308 (0x18A4)
GetContentRequest failed 0x87d01107 execmgr 9/16/2020 3:54:13 PM 6308 (0x18A4)

when it works, I see

MTC signaled SWD execution request with program id: I-Install Software, package id: HLT0048F for execution. execmgr 9/16/2020 3:57:20 PM 8720 (0x2210)
Sending ack to MTC for task with id: {628DEF35-F85E-4E38-BF3B-D7821935CE4D} execmgr 9/16/2020 3:57:20 PM 8720 (0x2210)
Executing program Install.exe in Admin context execmgr 9/16/2020 3:57:20 PM 8720 (0x2210)

It feels like a timing problem of some kind and it is driving me a little crazy. For large deployments - it is really tedious to have to attempt to rerun on all the fail to cache. I am tempted to just use run from DP on things and avoid the cache all together.

I cant think of any recent changes that might be interfering. I would think if there was an AV problem, then the files would get stopped at the temp folder and would not Hash correctly. That they are hashing right shows the client is downloading the files and the files are making it to the local disk intact and correct. So whats going on with not copying into the assigned ccmcache subfolder?

Anyone with ideas?

Microsoft Configuration Manager Application
Microsoft Configuration Manager Application
Microsoft Configuration Manager: An integrated solution for for managing large groups of personal computers and servers.Application: A computer program designed to carry out a specific task other than one relating to the operation of the computer itself, typically to be used by end users.
467 questions
0 comments

6 answers

Sort by: Most helpful
Most helpful Newest Oldest
  1. Fiona Yan-MSFT 2,311 Reputation points
    2020-09-17T05:49:16.163+00:00

    @ToddMiller-7887

    Could we change the configuration of our looging options like enabling the verbose log?If there is a problem,then we will see more details in the log after we change the logging options.
    For more details,please refer to this article:
    https://video2.skills-academy.com/en-us/mem/configmgr/core/plan-design/hierarchy/about-log-files#bkmk_reg-client

    If the response is helpful, please click "Accept Answer" and upvote it.
    Note: Please follow the steps in our documentation to enable e-mail notifications if you want to receive the related email notification for this thread.

    0 comments
  2. Todd Miller 41 Reputation points
    2020-09-17T15:55:34.213+00:00

    I turned on verbose logging. I am not sure it has helped to locate the problem, but I did find something in the CAS log.
    With global verbose logging enabled and using CMtrace to merge CAS, exec, and DTS logs... When the caching fails, this appears in the log -- no lines between these two lines.

    Saved Content ID Mapping HLT003BD.1, C:\WINDOWS\ccmcache\d ContentAccess 9/17/2020 9:42:13 AM 10552 (0x2938)
    Removed Content ID Mapping for HLT003BD.1 ContentAccess 9/17/2020 9:42:14 AM 10552 (0x2938)

    I looked back through the merged logs and there are no other instances of "Removed Content ID Mapping"
    This line only appears on the failure.

    I tried pushing 5 packages to this client all cached correctly and executed successfully. Then on this 5th package, I finaly got a failure. Rerunning the same advert/package on the client using the clientcenter succeeded.

    Something in the client process appears to be removing the content one second after saving it?

    I am attaching a "success" and "failure" log. The lines look basically the same... there appears to be a race condition between the cache manager and the signal to the execmgr. Like the execmgr tries to execute the process prior to cachemgr fully releasing it for execution.25578-failure.txt25579-success.txt

    When the "MTC signaled SWD execution request with program id:" in execmgr.log happens BEFORE "Saved Content ID Mapping" in CAS.log there is a failure. And there is an extra line "Removed Content ID Mapping" -

    When CAS reports "saved content ID mapping" BEFORE execmgr reports "MTC signaled SWD execution" the process succeeds.

    0 comments
  3. Fiona Yan-MSFT 2,311 Reputation points
    2020-09-21T09:59:40.85+00:00

    @ToddMiller-7887

    25969-capture.png
    Could we know whether the failed client is stable or random?
    If the client is stable,maybe we could try to uninstall and then reinstall it.Maybe we could cache it to see if it works.

    If the response is helpful, please click "Accept Answer" and upvote it.
    Note: Please follow the steps in our documentation to enable e-mail notifications if you want to receive the related email notification for this thread.

    0 comments
  4. Todd Miller 41 Reputation points
    2020-09-22T02:49:17.487+00:00

    I don’t understand. As I stated, this is a widespread problem across all endpoints. A client will cache and install multiple packages in a row and then fail as shown. Also, I stated that a retry via client center will usually result in a success. When I push a package to 1000 clients I can expect the cache to fail on about 9% of clients. It is not a broken client as this problem is not isolated to a particular package or client. It is random packages and random clients And the fail rate is ~9%
    The downloaded package downloads into a working temp folder, hashes OK, and then fails to copy into the final cache sub-folder.

    0 comments
  5. Todd Miller 41 Reputation points
    2020-09-22T21:35:21.38+00:00

    I don't know if this is a contributing factor or not, but the instances where this happens, the client is being added to a collection that has an advertisement that happens in the past.

    So there could be a package/program to install Chrome browser. There is an advertisement to "collection A" that has a mandatory install time of Feb 2, 2020 (some time in the past.)
    In September - long after the advertisement mandatory time, clients are added to "Collection A" or a query rule adds them to Collection A. This force the client, on its next policy refresh to learn that it has an active advertisement assignment and the client needs to download and run a package/program right away.

    In cases where the mandatory advertisement is in the future, where the client may pre-cache but is not set to run the advertisement until some time later, we do not see this problem.