Hello,

Can anyone shed any light on what is happening during this following process?  It occurs in our UpdatesDeployment.log file right after a Software Update Group has been deployed to a client.  The client is healthy and can get normal application, task sequence, etc. deployments.  However, some software update deployments don't seem to get past the acknowledgement step.

Assignment {a1ce0350-5328-4519-ab93-5e0c9f563c1e} has total CI = 303
Deadline received for assignment {{a1ce0350-5328-4519-ab93-5e0c9f563c1e}}
Detection job {{D2824A10-684E-4C08-BBFA-F00140ED0117}} started for assignment {{a1ce0350-5328-4519-ab93-5e0c9f563c1e}}
....

Assignment {{a1ce0350-5328-4519-ab93-5e0c9f563c1e}} already in progress state (AssignmentStateDetecting). No need to evaluate

We've tracked the assignment GUID back to the deployment unique ID and can confirm that this deployment is deadlined and should be installing on clients that need some of the updates contained within.  We have similar deployments that do work just fine and don't throw the "already in progress state" message, so it isn't a universal issue that would prevent all software update deployments.

We just have several deployments in our environment that will not even appear to evaluate on our clients and I'd like to rule out that the above message is not an indication as to why.  We are feeling like the client thinks something is in progress with evaluating/downloading/installing updates from this deployment, but something is hung or broken in the SUP or WSUS somewhere.

Any thoughts?

Thank you,
Ryan

What does the Monitoring node / Deployments tell for such a client?

just a theory...

maybe your detection/scan schedule is too aggressive (the schedule is too frequent), and because there are 303 CI's in this assignment, it is over-running itself (i.e. it is not getting a chance to complete the detection before it is signalled to scan again)?

if you consider setting detection schedule to be less frequent, or, split the assignment into smaller groupings?

Hi Torsten,

The Monitoring for this deployment shows the computer(s) in the Unknown section as Client check passed/Active.  When we compile several of the updates log files together and run the deployments through the configuration manager control panel utility, nothing seems to jump out as to what the issue might be.  It just reads like it's in progress and it's not going to take further action.

Hi Don,

I can say that we have known working deployments that have ~240 CI's in the assignment.  We also have known "broken" deployments that have ~100 CI's, so I'm not sure that the number of CI's is affecting things in our situation.  We can have the same updates in the known working and "broken" deployments and one will work and the other will say that it is already in progress state.

When you say to adjust the detection/scan schedule, do you mean in the Client Settings.  Our default that this computer is getting looks to be set to: scan every 1 day, deployment re-evaluation every 2 days.  Is that too frequent?

I just restarted the client to flush the client cache and re-ran the Scan Cycle so I could watch it in the ScanAgent.log/UpdatesDeployment.log files.  Here's what I see...

Sources are not current ScanAgent 5/24/2013 3:46:11 PM 3600 (0x0E10)
ScanJob({EDF944F2-83BD-42F2-A963-25D7B25E6380}): - - - - - -Locations requested for ScanJobID={EDF944F2-83BD-42F2-A963-25D7B25E6380} (LocationRequestID={1B97D959-CAEA-4A7B-9701-AE3737019D0E}), will process the scan request once locations are available. ScanAgent 5/24/2013 3:46:12 PM 3600 (0x0E10)
Sources are not current ScanAgent 5/24/2013 3:46:12 PM 3604 (0x0E14)
ScanJob({307E771E-A265-4E30-8ED9-8A5DADF291A9}): - - - - - -Locations requested for ScanJobID={307E771E-A265-4E30-8ED9-8A5DADF291A9} (LocationRequestID={B4C91219-3F2F-45D4-9668-4FCFD511096D}), will process the scan request once locations are available. ScanAgent 5/24/2013 3:46:12 PM 3604 (0x0E14)
Message received: '<?xml version='1.0' ?> <UpdateSourceMessage MessageType='ScanByUpdateSource'>
<ForceScan>TRUE</ForceScan>
<UpdateSourceIDs>
<ID>{409A9C41-D015-4A14-BB54-CE29CC557D4E} </ID>
</UpdateSourceIDs>
</UpdateSourceMessage>'
ScanAgent 5/24/2013 3:46:30 PM 3604 (0x0E14)
*****ScanByUpdateSource request received with ForceReScan=2, ScanOptions=0x0000000a,  WSUSLocationTimeout = 604800 ScanAgent 5/24/2013 3:46:30 PM 3604 (0x0E14)
Sources are current and valid. TTLs are however, invalid. ScanAgent 5/24/2013 3:46:30 PM 3604 (0x0E14)
User logon system task UpdatesDeploymentAgent 5/24/2013 3:46:31 PM 4048 (0x0FD0)
ScanJob({508932A1-1742-4395-AB81-DC1820271CAE}): - - - - - -Locations requested for ScanJobID={508932A1-1742-4395-AB81-DC1820271CAE} (LocationRequestID={65308859-0F27-462A-BF63-748EA5901321}), will process the scan request once locations are available. ScanAgent 5/24/2013 3:46:32 PM 3604 (0x0E14)
CUpdateAssignmentsManager received a SERVICEWINDOWEVENT START Event UpdatesDeploymentAgent 5/24/2013 3:46:41 PM 4004 (0x0FA4)
No current service window available to run updates assignment with time required = 1 UpdatesDeploymentAgent 5/24/2013 3:46:41 PM 4004 (0x0FA4)
CUpdateAssignmentsManager received a SERVICEWINDOWEVENT MODIFY Event UpdatesDeploymentAgent 5/24/2013 3:46:41 PM 3708 (0x0E7C)
No current service window available to run updates assignment with time required = 1 UpdatesDeploymentAgent 5/24/2013 3:46:41 PM 3708 (0x0E7C)
*****WSUSLocationUpdate received for location request guid={65308859-0F27-462A-BF63-748EA5901321} ScanAgent 5/24/2013 3:46:43 PM 4048 (0x0FD0)
Sources are current and valid. TTLs are however, invalid. ScanAgent 5/24/2013 3:46:43 PM 4004 (0x0FA4)
ScanJob({508932A1-1742-4395-AB81-DC1820271CAE}): Performing Full Scan. ScanAgent 5/24/2013 3:46:43 PM 4004 (0x0FA4)
ScanJob({508932A1-1742-4395-AB81-DC1820271CAE}): Scan Succeeded, Resetting Source to Current and TTLs to Valid ScanAgent 5/24/2013 3:47:00 PM 4048 (0x0FD0)
ScanJob({508932A1-1742-4395-AB81-DC1820271CAE}): CScanJob::OnScanComplete - Scan completed successfully, ScanType=1 ScanAgent 5/24/2013 3:47:00 PM 4048 (0x0FD0)
ScanJob({508932A1-1742-4395-AB81-DC1820271CAE}): CScanJobManager::OnScanComplete -ScanJob is completed. ScanAgent 5/24/2013 3:47:00 PM 4048 (0x0FD0)
ScanJob({508932A1-1742-4395-AB81-DC1820271CAE}): CScanJobManager::OnScanComplete - Reporting Scan request complete to clients... ScanAgent 5/24/2013 3:47:00 PM 4048 (0x0FD0)
- - Calling back to client on Scan request complete... ScanAgent 5/24/2013 3:47:00 PM 4048 (0x0FD0)
CScanAgent::ScanComplete- Scan completion received. ScanAgent 5/24/2013 3:47:00 PM 4048 (0x0FD0)
EnumerateUpdates for action (UpdateActionInstall) - Total actionable updates = 0 UpdatesDeploymentAgent 5/24/2013 3:47:09 PM 3580 (0x0DFC)

My hunch is that the line "No current service window available to run updates assignment with time required = 1" may be the culprit but I'm not sure.  I'm just not certain what this means exactly.  I want to say from other forum posts this has to do with maintenance windows, but I had this client's collection set to two hours from 3am-5am.  I just reset the maintenance window on the client's collection to 23 hours of every day for testing purposes, but I didn't have a successful test.  I had the same log results, but maybe I didn't wait long enough between the change and the test. 

I've checked our ServiceWindowManager.log file and found the following.  Not sure what the Type=6 means or why it would be a runtime of 900 (minutes???) and why the maintenance window it sees doesn't suffice since it's set to 24 hours recurring daily...

OnIsServiceWindowAvailable called with: Runtime:900, Type:2 ServiceWindowManager 5/28/2013 10:57:53 AM 3600 (0x0E10)
No Service Windows exist for this type. Will check if the program can run in the All Programs window... ServiceWindowManager 5/28/2013 10:57:53 AM 3600 (0x0E10)
        Biggest Active Service Window has ID = {20199E81-9F9B-4EAE-953A-FC2D06BD8A77} having Starttime=5/28/2013 7:00:00 AM ServiceWindowManager 5/28/2013 10:57:53 AM 3600 (0x0E10)
            Duration is 1 days, 00 hours, 00 mins, 00 secs ServiceWindowManager 5/28/2013 10:57:53 AM 3600 (0x0E10)
ActiveServiceWindow has 72127 seconds left ServiceWindowManager 5/28/2013 10:57:53 AM 3600 (0x0E10)
Program can run! Setting *canProgramRun to TRUE ServiceWindowManager 5/28/2013 10:57:53 AM 3600 (0x0E10)
OnIsServiceWindowAvailable called with: Runtime:1, Type:6 ServiceWindowManager 5/28/2013 10:57:53 AM 2584 (0x0A18)
        Biggest Active Service Window for Type=6 not found ServiceWindowManager 5/28/2013 10:57:53 AM 2584 (0x0A18)
Program cannot Run! Setting *canProgramRun to FALSE ServiceWindowManager 5/28/2013 10:57:53 AM 2584 (0x0A18)
WillProgramRun called with: Runtime:1, Type:6 ServiceWindowManager 5/28/2013 10:57:53 AM 2584 (0x0A18)
A Service Window of this type exists. ServiceWindowManager 5/28/2013 10:57:53 AM 2584 (0x0A18)
There exists a Service Window of this Type, for this duration. The Program will run eventually. ServiceWindowManager 5/28/2013 10:57:53 AM 2584 (0x0A18)
ServiceWindowManager 5/28/2013 10:57:53 AM 2584 (0x0A18)
OnIsServiceWindowAvailable called with: Runtime:1, Type:4 ServiceWindowManager 5/28/2013 10:57:53 AM 2760 (0x0AC8)
No Service Windows exist for this type. Will check if the program can run in the All Programs window... ServiceWindowManager 5/28/2013 10:57:53 AM 2760 (0x0AC8)
        Biggest Active Service Window has ID = {20199E81-9F9B-4EAE-953A-FC2D06BD8A77} having Starttime=5/28/2013 7:00:00 AM ServiceWindowManager 5/28/2013 10:57:53 AM 2760 (0x0AC8)
            Duration is 1 days, 00 hours, 00 mins, 00 secs ServiceWindowManager 5/28/2013 10:57:53 AM 2760 (0x0AC8)
ActiveServiceWindow has 72127 seconds left ServiceWindowManager 5/28/2013 10:57:53 AM 2760 (0x0AC8)
Program can run! Setting *canProgramRun to TRUE ServiceWindowManager 5/28/2013 10:57:53 AM 2760 (0x0AC8)
OnIsServiceWindowAvailable called with: Runtime:1, Type:6 ServiceWindowManager 5/28/2013 10:57:53 AM 2760 (0x0AC8)
        Biggest Active Service Window for Type=6 not found ServiceWindowManager 5/28/2013 10:57:53 AM 2760 (0x0AC8)
Program cannot Run! Setting *canProgramRun to FALSE ServiceWindowManager 5/28/2013 10:57:53 AM 2760 (0x0AC8)
WillProgramRun called with: Runtime:1, Type:6 ServiceWindowManager 5/28/2013 10:57:53 AM 2760 (0x0AC8)
A Service Window of this type exists. ServiceWindowManager 5/28/2013 10:57:53 AM 2760 (0x0AC8)
There exists a Service Window of this Type, for this duration. The Program will run eventually. ServiceWindowManager 5/28/2013 10:57:53 AM 2760 (0x0AC8)
ServiceWindowManager 5/28/2013 10:57:53 AM 2760 (0x0AC8)
OnIsServiceWindowAvailable called with: Runtime:1, Type:4 ServiceWindowManager 5/28/2013 10:57:53 AM 1036 (0x040C)
No Service Windows exist for this type. Will check if the program can run in the All Programs window... ServiceWindowManager 5/28/2013 10:57:53 AM 1036 (0x040C)
        Biggest Active Service Window has ID = {20199E81-9F9B-4EAE-953A-FC2D06BD8A77} having Starttime=5/28/2013 7:00:00 AM ServiceWindowManager 5/28/2013 10:57:53 AM 1036 (0x040C)
            Duration is 1 days, 00 hours, 00 mins, 00 secs ServiceWindowManager 5/28/2013 10:57:53 AM 1036 (0x040C)
ActiveServiceWindow has 72127 seconds left ServiceWindowManager 5/28/2013 10:57:53 AM 1036 (0x040C)
Program can run! Setting *canProgramRun to TRUE ServiceWindowManager 5/28/2013 10:57:53 AM 1036 (0x040C)
OnIsServiceWindowAvailable called with: Runtime:1, Type:6 ServiceWindowManager 5/28/2013 10:57:53 AM 1036 (0x040C)
        Biggest Active Service Window for Type=6 not found ServiceWindowManager 5/28/2013 10:57:53 AM 1036 (0x040C)
Program cannot Run! Setting *canProgramRun to FALSE ServiceWindowManager 5/28/2013 10:57:53 AM 1036 (0x040C)
WillProgramRun called with: Runtime:1, Type:6 ServiceWindowManager 5/28/2013 10:57:53 AM 1036 (0x040C)
A Service Window of this type exists. ServiceWindowManager 5/28/2013 10:57:53 AM 1036 (0x040C)
There exists a Service Window of this Type, for this duration. The Program will run eventually. ServiceWindowManager 5/28/2013 10:57:53 AM 1036 (0x040C)
ServiceWindowManager 5/28/2013 10:57:53 AM 1036 (0x040C)
OnIsServiceWindowAvailable called with: Runtime:900, Type:6 ServiceWindowManager 5/28/2013 10:57:53 AM 828 (0x033C)
        Biggest Active Service Window for Type=6 not found ServiceWindowManager 5/28/2013 10:57:53 AM 828 (0x033C)
Program cannot Run! Setting *canProgramRun to FALSE ServiceWindowManager 5/28/2013 10:57:53 AM 828 (0x033C)
OnIsServiceWindowAvailable called with: Runtime:900, Type:6 ServiceWindowManager 5/28/2013 10:57:53 AM 3600 (0x0E10)
        Biggest Active Service Window for Type=6 not found ServiceWindowManager 5/28/2013 10:57:53 AM 3600 (0x0E10)
Program cannot Run! Setting *canProgramRun to FALSE ServiceWindowManager 5/28/2013 10:57:53 AM 3600 (0x0E10)

Yes, I know this is an old post, but Im trying to clean them up. Did you solve this problem, if so what was the solution?

Since no one has answer this post, I recommend opening  a support case with Microsoft Customer Support Services (CSS) as they can work with you to solve this problem.