Closed Bug 1433851 Opened 7 years ago Closed 6 years ago

validate user environment before running tasks

Categories

(Taskcluster :: Workers, enhancement)

enhancement
Not set
normal

Tracking

(Not tracked)

RESOLVED FIXED

People

(Reporter: grenade, Unassigned)

References

Details

- in bug 1343049 we see that intermittently, the user registry hive has not been loaded at the time that a task is initiated
- in bug 1368241 we see that pip intermittently fails to run due to access issues. pip runs in user space (AppData) rather than machine/global space and i suspect that the user profile directory is inaccesible to the task user that owns it.

generic worker will need to check that both the HKCU hive and the user profile and APPDATA directories are readable and writable before running a task.

note that i have tried adding this functionality to the wrapper script which starts generic worker but at the time that script runs, the hive is not yet loaded, so the check needs to occur after gw has started but before it runs a task.

if the hive is not loaded or APPDATA is not readable and writable, the instance should be terminated as it will just cause issues that are difficult to debug in test failures.
(In reply to Rob Thijssen (:grenade UTC+2) from comment #0)
> - in bug 1343049 we see that intermittently, the user registry hive has not
> been loaded at the time that a task is initiated
> - in bug 1368241 we see that pip intermittently fails to run due to access
> issues. pip runs in user space (AppData) rather than machine/global space
> and i suspect that the user profile directory is inaccesible to the task
> user that owns it.
> 
> generic worker will need to check that both the HKCU hive and the user
> profile and APPDATA directories are readable and writable before running a
> task.

OK, that seems fair. I can implement this.

> note that i have tried adding this functionality to the wrapper script which
> starts generic worker but at the time that script runs, the hive is not yet
> loaded, so the check needs to occur after gw has started but before it runs
> a task.

I think this turned out to be a bug in the wrapper script, but in generic-worker 10 the wrapper script runs as LocalSystem rather than as the task user, so in the newer version of generic-worker it will be necessary to do this inside the worker anyway.
 
> if the hive is not loaded or APPDATA is not readable and writable, the
> instance should be terminated as it will just cause issues that are
> difficult to debug in test failures.

The worker will have an exit code that signals the environment is bad, and the calling code (wrapper script) can decide what to do. This will allows different handling based on the environment (e.g. on hardware pools we might not want to terminate, but in EC2 we probably do) and also provide a mechanism that any cleanup/reporting/alerting/teardown can take place outside of the worker.
(In reply to Rob Thijssen (:grenade UTC+2) from comment #0)
> generic worker will need to check that both the HKCU hive and the user
> profile and APPDATA directories are readable and writable before running a
> task.

It looks the check for user profile directory existence already exists in generic-worker 10 here:

  https://github.com/taskcluster/runlib/blob/7fa257e0aaed6b00edeea02f62c38e67ff4b4924/win32/extra_windows.go#L1094-L1110

We create the AppData folder passing KF_FLAG_CREATE to SHGetKnownFolderPath, so we can be sure it exists when we return from the syscall:

  https://msdn.microsoft.com/en-us/library/windows/desktop/bb762188(v=vs.85).aspx
  https://msdn.microsoft.com/en-us/library/windows/desktop/dd378447(v=vs.85).aspx
  https://github.com/taskcluster/runlib/blob/7fa257e0aaed6b00edeea02f62c38e67ff4b4924/win32/extra_windows.go#L543

So I think the only other check we potentially might be missing in generic-worker 10 at the moment is that the user registry hive might not be already mounted.
(In reply to Pete Moore [:pmoore][:pete] from comment #2)
> So I think the only other check we potentially might be missing in
> generic-worker 10 at the moment is that the user registry hive might not be
> already mounted.

It looks like this is already possible (even if not ideal) here:

  https://github.com/taskcluster/generic-worker/blob/5b35c739ccc01f9519dd5fde761a2fb571f32d8f/plat_windows.go#L127-L142

By providing this config option:

  https://github.com/taskcluster/generic-worker/blob/5b35c739ccc01f9519dd5fde761a2fb571f32d8f/main.go#L201-L206

The custom script could be a Powershell script that checks every second for up to e.g. 3 minutes, if the hive is mounted. When it detects it is mounted, it exits with a 0 exit code - otherwise after 3 minutes it exits with a non-zero exit code.

This would cause an AWS instance to terminate if the hive wasn't mounted in the 3 minute period. This is good.

Note, implementing this check as an external powershell script could be a useful workaround for now, while I work on a formal internal implementation inside the worker.

Note, the script will execute in the context of the newly created logon session, which is also what we would want.
(In reply to Pete Moore [:pmoore][:pete] from comment #3)

> By providing this config option:
> 
>  
> https://github.com/taskcluster/generic-worker/blob/
> 5b35c739ccc01f9519dd5fde761a2fb571f32d8f/main.go#L201-L206

Looks like I need to update the docs - they say the script is run immediately after user creation, but technically it is run after the user is created, the machine has been rebooted, and the new user has logged in, but before it tries to claim a task to run as that user. So this is the perfect place to put additional environment checks that should run as the task user, that will cause the worker to terminate if they return a non zero exit code.
QA Contact: pmoore
(In reply to Pete Moore [:pmoore][:pete] from comment #4)
> (In reply to Pete Moore [:pmoore][:pete] from comment #3)
> 
> > By providing this config option:
> > 
> >  
> > https://github.com/taskcluster/generic-worker/blob/
> > 5b35c739ccc01f9519dd5fde761a2fb571f32d8f/main.go#L201-L206
> 
> Looks like I need to update the docs - they say the script is run
> immediately after user creation, but technically it is run after the user is
> created, the machine has been rebooted, and the new user has logged in, but
> before it tries to claim a task to run as that user. So this is the perfect
> place to put additional environment checks that should run as the task user,
> that will cause the worker to terminate if they return a non zero exit code.

Docs updated in https://github.com/taskcluster/generic-worker/commit/85f9de3708df498ea5829186f8e767d9fdafd250

>          runAfterUserCreation              A string, that if non-empty, will be treated as a
>                                            command to be executed as the newly generated task
>                                            user, after the user has been created, the machine
>                                            has rebooted and the user has logged in, but before
>                                            a task is run as that user. This is a way to
>                                            provide generic user initialisation logic that
>                                            should apply to all generated users (and thus all
>                                            tasks) and be run as the task user itself. This
>                                            option does *not* support running a command as
>                                            Administrator.
1) Disabling task bar - StuckRects3 registry key not present
============================================================

It looks like on gecko-t-win10-64-gpu-b the registry key HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 is genuinely missing. I haven't checked the non-gpu worker type yet.

I've dumped sections of task user registry to logs using the following runAfterUserCreationScript (see comment 5):


> REM Task User initialisation script - this script runs as task user, not as administrator.
> REM It runs after task user has logged in, but before worker claims a task.
> 
> echo
> echo ................................................................................
> echo
> reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 /s
> echo
> echo ................................................................................
> echo
> reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects /s
> echo
> echo ................................................................................
> echo
> reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer /s
> echo
> echo ................................................................................
> echo
> 
> :CheckForUserProfile
> echo Checking user registry hive is loaded...
> set
> reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects /ve
> if %ERRORLEVEL% EQU 0 goto HideTaskBar
> echo User registry hive is not loaded
> timeout /t 1 >nul
> goto CheckForUserProfile
> 
> :HideTaskBar
> echo Hiding taskbar...
> set
> powershell -command "&{Write-Output $env:username; $p='HKCU:SOFTWARE\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3';$v=(Get-ItemProperty -Path $p).Settings;$v[8]=3;&Set-ItemProperty -Path $p -Name Settings -Value $v;&Stop-Process -ProcessName explorer}"



Output from this can be seen e.g. here:

https://papertrailapp.com/systems/1694210101/events?focus=911322989528789000&selected=911322989528789000


Here is a sample of the logs to show the missing key:

> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\Package Installation\Microsoft.Windows.Cortana_cw5n1h2txyewy 
>     InstallState    REG_DWORD    0xffffffff 
>     InstallProgress    REG_DWORD    0x64 
>     ErrorDetail    REG_DWORD    0x80070643 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\Package Installation\Microsoft.Windows.ShellExperienceHost_cw5n1h2txyewy 
>     InstallState    REG_DWORD    0xffffffff 
>     InstallProgress    REG_DWORD    0x64 
>     ErrorDetail    REG_DWORD    0x80070643 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\SearchPlatform 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\SearchPlatform\Preferences 
>     BreadCrumbBarSearchDefault    REG_SZ    MSNSearch 
>     DisableAutoNavigateURL    REG_DWORD    0x0 
>     DisableAutoResolveEmailAddrs    REG_DWORD    0x0 
>     DisableResultsInNewWindow    REG_DWORD    0x0 
>     DisableTabbedBrowsing    REG_DWORD    0x0 
>     EditSavedSearch    REG_DWORD    0x0 
>     IEAddressBarSearchDefault    REG_SZ    MSNSearch 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\Shell Folders 
>     !Do not use this registry key    REG_SZ    Use the SHGetFolderPath or SHGetKnownFolderPath function instead 
>     AppData    REG_SZ    Z:\task_1521213500\AppData\Roaming 
>     Local AppData    REG_SZ    Z:\task_1521213500\AppData\Local 
>     {1B3EA5DC-B587-4786-B4EF-BD1DC332AEAE}    REG_SZ    Z:\task_1521213500\AppData\Roaming\Microsoft\Windows\Libraries 
>     My Video    REG_SZ    C:\Users\task_1521213500\Videos 
>     My Pictures    REG_SZ    C:\Users\task_1521213500\Pictures 
>     Desktop    REG_SZ    C:\Users\task_1521213500\Desktop 
>     History    REG_SZ    C:\Users\task_1521213500\AppData\Local\Microsoft\Windows\History 
>     NetHood    REG_SZ    C:\Users\task_1521213500\AppData\Roaming\Microsoft\Windows\Network Shortcuts 
>     {56784854-C6CB-462B-8169-88E350ACB882}    REG_SZ    C:\Users\task_1521213500\Contacts 
>     {00BCFC5A-ED94-4E48-96A1-3F6217F21990}    REG_SZ    Z:\task_1521213500\AppData\Local\Microsoft\Windows\RoamingTiles 
>     Cookies    REG_SZ    C:\Users\task_1521213500\AppData\Local\Microsoft\Windows\INetCookies 
>     Favorites    REG_SZ    C:\Users\task_1521213500\Favorites 
>     SendTo    REG_SZ    C:\Users\task_1521213500\AppData\Roaming\Microsoft\Windows\SendTo 
>     Start Menu    REG_SZ    C:\Users\task_1521213500\AppData\Roaming\Microsoft\Windows\Start Menu 
>     My Music    REG_SZ    C:\Users\task_1521213500\Music 
>     Programs    REG_SZ    C:\Users\task_1521213500\AppData\Roaming\Microsoft\Windows\Start Menu\Programs 
>     Recent    REG_SZ    C:\Users\task_1521213500\AppData\Roaming\Microsoft\Windows\Recent 
>     CD Burning    REG_SZ    Z:\task_1521213500\AppData\Local\Microsoft\Windows\Burn\Burn 
>     PrintHood    REG_SZ    C:\Users\task_1521213500\AppData\Roaming\Microsoft\Windows\Printer Shortcuts 
>     {7D1D3A04-DEBB-4115-95CF-2F29DA2920DA}    REG_SZ    C:\Users\task_1521213500\Searches 
>     {374DE290-123F-4565-9164-39C4925E467B}    REG_SZ    C:\Users\task_1521213500\Downloads 
>     {A520A1A4-1780-4FF6-BD18-167343C5AF16}    REG_SZ    C:\Users\task_1521213500\AppData\LocalLow 
>     Startup    REG_SZ    C:\Users\task_1521213500\AppData\Roaming\Microsoft\Windows\Start Menu\Programs\Startup 
>     Administrative Tools    REG_SZ    C:\Users\task_1521213500\AppData\Roaming\Microsoft\Windows\Start Menu\Programs\Administrative Tools 
>     Personal    REG_SZ    C:\Users\task_1521213500\Documents 
>     {BFB9D5E0-C6A9-404C-B2B2-AE6DB6AF4968}    REG_SZ    C:\Users\task_1521213500\Links 
>     Cache    REG_SZ    C:\Users\task_1521213500\AppData\Local\Microsoft\Windows\INetCache 
>     Templates    REG_SZ    C:\Users\task_1521213500\AppData\Roaming\Microsoft\Windows\Templates 
>     {4C5C32FF-BB9D-43B0-B5B4-2D72E54EAAA4}    REG_SZ    C:\Users\task_1521213500\Saved Games 
>     Fonts    REG_SZ    C:\Windows\Fonts 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\StartPage 
>     StartMenu_Start_Time    REG_BINARY    184C8A1E3ABDD301 
>     Start_JumpListModernTime    REG_BINARY    45FBBA1E3ABDD301

<key should be here>

> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\User Shell Folders 
>     AppData    REG_EXPAND_SZ    Z:\task_1521213500\AppData\Roaming 
>     Cache    REG_EXPAND_SZ    %USERPROFILE%\AppData\Local\Microsoft\Windows\INetCache 
>     Cookies    REG_EXPAND_SZ    %USERPROFILE%\AppData\Local\Microsoft\Windows\INetCookies 
>     Desktop    REG_EXPAND_SZ    %USERPROFILE%\Desktop 
>     Favorites    REG_EXPAND_SZ    %USERPROFILE%\Favorites 
>     History    REG_EXPAND_SZ    %USERPROFILE%\AppData\Local\Microsoft\Windows\History 
>     Local AppData    REG_EXPAND_SZ    Z:\task_1521213500\AppData\Local 
>     My Music    REG_EXPAND_SZ    %USERPROFILE%\Music 
>     My Pictures    REG_EXPAND_SZ    %USERPROFILE%\Pictures 
>     My Video    REG_EXPAND_SZ    %USERPROFILE%\Videos 
>     NetHood    REG_EXPAND_SZ    %USERPROFILE%\AppData\Roaming\Microsoft\Windows\Network Shortcuts 
>     Personal    REG_EXPAND_SZ    %USERPROFILE%\Documents 
>     PrintHood    REG_EXPAND_SZ    %USERPROFILE%\AppData\Roaming\Microsoft\Windows\Printer Shortcuts 
>     Programs    REG_EXPAND_SZ    %USERPROFILE%\AppData\Roaming\Microsoft\Windows\Start Menu\Programs 
>     Recent    REG_EXPAND_SZ    %USERPROFILE%\AppData\Roaming\Microsoft\Windows\Recent 
>     SendTo    REG_EXPAND_SZ    %USERPROFILE%\AppData\Roaming\Microsoft\Windows\SendTo 
>     Start Menu    REG_EXPAND_SZ    %USERPROFILE%\AppData\Roaming\Microsoft\Windows\Start Menu 
>     Startup    REG_EXPAND_SZ    %USERPROFILE%\AppData\Roaming\Microsoft\Windows\Start Menu\Programs\Startup 
>     Templates    REG_EXPAND_SZ    %USERPROFILE%\AppData\Roaming\Microsoft\Windows\Templates 
>     {374DE290-123F-4565-9164-39C4925E467B}    REG_EXPAND_SZ    %USERPROFILE%\Downloads 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\UserAssist 


We can see that the batch script, and the powershell script it calls, are running as the task_1521213500 user.

AFAIU this registry key should exist.


2) Visual Effects
=================

From the logs, we see the visual effects on gecko-t-win10-64-gpu-b are configured as follows:

> Z:\task_1521213500>reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects /s  
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\AnimateMinMax 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\ComboBoxAnimation 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\ControlAnimations 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\CursorShadow 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\DragFullWindows 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\DropShadow 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\DWMAeroPeekEnabled 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\DWMEnabled 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\DWMSaveThumbnailEnabled 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\FontSmoothing 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\ListBoxSmoothScrolling 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\ListviewAlphaSelect 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\ListviewShadow 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\MenuAnimation 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\SelectionFade 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\TaskbarAnimations 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\Themes 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\ThumbnailsOrIcon 
>     DefaultApplied    REG_DWORD    0x1 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\TooltipAnimation 
>     DefaultApplied    REG_DWORD    0x1 

I'm currently not familiar with what the required settings are, I will check.
When I run a task to output the registry setting on the same worker type, I can see it is there:

https://tools.taskcluster.net/groups/Zf92VLdvTkO7TWIsDoaEIQ/tasks/Zf92VLdvTkO7TWIsDoaEIQ/runs/0/logs/public%2Flogs%2Flive.log

This suggests to me, that we just need to wait for it to exist, before trying to set it to something different.
(In reply to Pete Moore [:pmoore][:pete] from comment #7)
> When I run a task to output the registry setting on the same worker type, I
> can see it is there:
> 
> https://tools.taskcluster.net/groups/Zf92VLdvTkO7TWIsDoaEIQ/tasks/
> Zf92VLdvTkO7TWIsDoaEIQ/runs/0/logs/public%2Flogs%2Flive.log
> 
> This suggests to me, that we just need to wait for it to exist, before
> trying to set it to something different.

[taskcluster 2018-03-16T15:40:03.132Z] Worker Type (gecko-t-win10-64-gpu-b) settings:
[taskcluster 2018-03-16T15:40:03.132Z]   {
[taskcluster 2018-03-16T15:40:03.132Z]     "aws": {
[taskcluster 2018-03-16T15:40:03.132Z]       "ami-id": "ami-d92ebda1",
[taskcluster 2018-03-16T15:40:03.132Z]       "availability-zone": "us-west-2b",
[taskcluster 2018-03-16T15:40:03.132Z]       "instance-id": "i-02cd2a15eece33ca9",
[taskcluster 2018-03-16T15:40:03.132Z]       "instance-type": "g2.2xlarge",
[taskcluster 2018-03-16T15:40:03.132Z]       "local-ipv4": "10.144.43.80",
[taskcluster 2018-03-16T15:40:03.132Z]       "public-hostname": "ec2-54-202-254-131.us-west-2.compute.amazonaws.com",
[taskcluster 2018-03-16T15:40:03.132Z]       "public-ipv4": "54.202.254.131"
[taskcluster 2018-03-16T15:40:03.132Z]     },
[taskcluster 2018-03-16T15:40:03.132Z]     "config": {
[taskcluster 2018-03-16T15:40:03.132Z]       "deploymentId": "pmoore-taskinit4",
[taskcluster 2018-03-16T15:40:03.132Z]       "runTasksAsCurrentUser": false
[taskcluster 2018-03-16T15:40:03.132Z]     },
[taskcluster 2018-03-16T15:40:03.132Z]     "generic-worker": {
[taskcluster 2018-03-16T15:40:03.132Z]       "go-arch": "amd64",
[taskcluster 2018-03-16T15:40:03.132Z]       "go-os": "windows",
[taskcluster 2018-03-16T15:40:03.132Z]       "go-version": "go1.9.4",
[taskcluster 2018-03-16T15:40:03.132Z]       "release": "https://github.com/taskcluster/generic-worker/releases/tag/v10.7.3",
[taskcluster 2018-03-16T15:40:03.132Z]       "revision": "73722cee56213a3b4e03b87403eaf1adcea8fe3e",
[taskcluster 2018-03-16T15:40:03.132Z]       "source": "https://github.com/taskcluster/generic-worker/commits/73722cee56213a3b4e03b87403eaf1adcea8fe3e",
[taskcluster 2018-03-16T15:40:03.132Z]       "version": "10.7.3"
[taskcluster 2018-03-16T15:40:03.132Z]     },
[taskcluster 2018-03-16T15:40:03.132Z]     "machine-setup": {
[taskcluster 2018-03-16T15:40:03.132Z]       "ami-created": "2018-03-16 11:11:19.484Z",
[taskcluster 2018-03-16T15:40:03.132Z]       "manifest": "https://github.com/mozilla-releng/OpenCloudConfig/blob/72c9d5b1c674b495a5da5dd6b43c8d83c13b23e5/userdata/Manifest/gecko-t-win10-64-gpu-b.json"
[taskcluster 2018-03-16T15:40:03.132Z]     }
[taskcluster 2018-03-16T15:40:03.132Z]   }
[taskcluster 2018-03-16T15:40:03.134Z] Task ID: Zf92VLdvTkO7TWIsDoaEIQ
[taskcluster 2018-03-16T15:40:03.134Z] === Task Starting ===
[taskcluster 2018-03-16T15:40:04.253Z] Uploading redirect artifact public/logs/live.log to URL https://g3fp5ayaaaawel4bfbmtnfrsawpjxhslajsfbvv2eqcwdodc.taskcluster-worker.net:60023/log/EA6Sr2aXROaGh4M7ktm_Vw with mime type "text/plain; charset=utf-8" and expiry 2018-03-16T15:50:16.409Z
[taskcluster 2018-03-16T15:40:04.707Z] Executing command 0: reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 /s

Z:\task_1521213322>reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 /s 

HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3
    Settings    REG_BINARY    30000000FEFFFFFF03000000030000003E00000028000000000000008804000080070000B00400006000000001000000

[taskcluster 2018-03-16T15:40:04.793Z]    Exit Code: 0
[taskcluster 2018-03-16T15:40:04.793Z] Success Code: 0x0
[taskcluster 2018-03-16T15:40:04.793Z]    User Time: 15.625ms
[taskcluster 2018-03-16T15:40:04.793Z]  Kernel Time: 0s
[taskcluster 2018-03-16T15:40:04.793Z]    Wall Time: 83.0228ms
[taskcluster 2018-03-16T15:40:04.793Z]  Peak Memory: 5939200
[taskcluster 2018-03-16T15:40:04.793Z]       Result: SUCCEEDED
[taskcluster 2018-03-16T15:40:04.793Z] === Task Finished ===
[taskcluster 2018-03-16T15:40:04.793Z] Task Duration: 86.9825ms
[taskcluster 2018-03-16T15:40:05.341Z] Uploading redirect artifact public/logs/live.log to URL https://queue.taskcluster.net/v1/task/Zf92VLdvTkO7TWIsDoaEIQ/runs/0/artifacts/public/logs/live_backing.log with mime type "text/plain; charset=utf-8" and expiry 2019-03-16T18:39:48.642Z
And here is a task that couldn't find it (presumably because the task ran immediately after creating user):

https://tools.taskcluster.net/groups/V8M9OJ2hTmGfQc5q8uVsqw/tasks/V8M9OJ2hTmGfQc5q8uVsqw/runs/0/logs/public%2Flogs%2Flive.log

[taskcluster 2018-03-16T15:52:22.767Z] Worker Type (gecko-t-win10-64-gpu-b) settings:
[taskcluster 2018-03-16T15:52:22.767Z]   {
[taskcluster 2018-03-16T15:52:22.767Z]     "aws": {
[taskcluster 2018-03-16T15:52:22.767Z]       "ami-id": "ami-d92ebda1",
[taskcluster 2018-03-16T15:52:22.767Z]       "availability-zone": "us-west-2a",
[taskcluster 2018-03-16T15:52:22.767Z]       "instance-id": "i-0eb1c8ba3d6b4f465",
[taskcluster 2018-03-16T15:52:22.767Z]       "instance-type": "g2.2xlarge",
[taskcluster 2018-03-16T15:52:22.767Z]       "local-ipv4": "10.144.29.98",
[taskcluster 2018-03-16T15:52:22.767Z]       "public-hostname": "ec2-34-217-16-235.us-west-2.compute.amazonaws.com",
[taskcluster 2018-03-16T15:52:22.767Z]       "public-ipv4": "34.217.16.235"
[taskcluster 2018-03-16T15:52:22.767Z]     },
[taskcluster 2018-03-16T15:52:22.767Z]     "config": {
[taskcluster 2018-03-16T15:52:22.767Z]       "deploymentId": "pmoore-taskinit4",
[taskcluster 2018-03-16T15:52:22.767Z]       "runTasksAsCurrentUser": false
[taskcluster 2018-03-16T15:52:22.767Z]     },
[taskcluster 2018-03-16T15:52:22.767Z]     "generic-worker": {
[taskcluster 2018-03-16T15:52:22.767Z]       "go-arch": "amd64",
[taskcluster 2018-03-16T15:52:22.767Z]       "go-os": "windows",
[taskcluster 2018-03-16T15:52:22.767Z]       "go-version": "go1.9.4",
[taskcluster 2018-03-16T15:52:22.767Z]       "release": "https://github.com/taskcluster/generic-worker/releases/tag/v10.7.3",
[taskcluster 2018-03-16T15:52:22.767Z]       "revision": "73722cee56213a3b4e03b87403eaf1adcea8fe3e",
[taskcluster 2018-03-16T15:52:22.767Z]       "source": "https://github.com/taskcluster/generic-worker/commits/73722cee56213a3b4e03b87403eaf1adcea8fe3e",
[taskcluster 2018-03-16T15:52:22.767Z]       "version": "10.7.3"
[taskcluster 2018-03-16T15:52:22.767Z]     },
[taskcluster 2018-03-16T15:52:22.767Z]     "machine-setup": {
[taskcluster 2018-03-16T15:52:22.767Z]       "ami-created": "2018-03-16 11:11:19.484Z",
[taskcluster 2018-03-16T15:52:22.767Z]       "manifest": "https://github.com/mozilla-releng/OpenCloudConfig/blob/72c9d5b1c674b495a5da5dd6b43c8d83c13b23e5/userdata/Manifest/gecko-t-win10-64-gpu-b.json"
[taskcluster 2018-03-16T15:52:22.767Z]     }
[taskcluster 2018-03-16T15:52:22.767Z]   }
[taskcluster 2018-03-16T15:52:22.769Z] Task ID: V8M9OJ2hTmGfQc5q8uVsqw
[taskcluster 2018-03-16T15:52:22.769Z] === Task Starting ===
[taskcluster 2018-03-16T15:52:23.875Z] Uploading redirect artifact public/logs/live.log to URL https://elmrb2yaaaawel4mvxvv3qfeliwfndls5rderqdvhxetgejs.taskcluster-worker.net:60023/log/ZGaCul2zTnarUJ38G790DQ with mime type "text/plain; charset=utf-8" and expiry 2018-03-16T16:02:51.499Z
[taskcluster 2018-03-16T15:52:24.305Z] Executing command 0: reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 /s

Z:\task_1521213690>reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 /s 
ERROR: The system was unable to find the specified registry key or value.
[taskcluster:error]    Exit Code: 1
[taskcluster:error] Success Code: 0x0
[taskcluster:error]    User Time: 0s
[taskcluster:error]  Kernel Time: 15.625ms
[taskcluster:error]    Wall Time: 56.0681ms
[taskcluster:error]  Peak Memory: 4882432
[taskcluster:error]       Result: FAILED
[taskcluster 2018-03-16T15:52:24.365Z] === Task Finished ===
[taskcluster 2018-03-16T15:52:24.366Z] Task Duration: 59.969ms
[taskcluster 2018-03-16T15:52:24.921Z] Uploading redirect artifact public/logs/live.log to URL https://queue.taskcluster.net/v1/task/V8M9OJ2hTmGfQc5q8uVsqw/runs/0/artifacts/public/logs/live_backing.log with mime type "text/plain; charset=utf-8" and expiry 2019-03-16T18:52:20.500Z
[taskcluster:error] Task not successful due to following exception(s):
[taskcluster:error] Exception 1)
[taskcluster:error] []
[taskcluster:error] 
[taskcluster:error] Exit code: 1
[taskcluster:error] 



So we can see this is indeed something that we need to wait for.

I've updated the script as follows, and am testing:

> REM Task User initialisation script - this script runs as task user, not as administrator.
> REM It runs after task user has logged in, but before worker claims a task.
> 
> :CheckForStuckRects3
> echo Wait for registry setting to exist before changing it...
> reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 /ve
> if %ERRORLEVEL% EQU 0 goto HideTaskBar
> echo HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 does not yet exist
> timeout /t 1 >nul
> goto CheckForStuckRects3
> 
> :HideTaskBar
> echo Hiding taskbar...
> powershell -command "&{$p='HKCU:SOFTWARE\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3';$v=(Get-ItemProperty -Path $p).Settings;$v[8]=3;&Set-ItemProperty -Path $p -Name Settings -Value $v;&Stop-Process -ProcessName explorer}"
> echo Completed task user initialisation.
> Z:\task_1521216935>REM Task User initialisation script - this script runs as task user, not as administrator.  
> Z:\task_1521216935>REM It runs after task user has logged in, but before worker claims a task.  
> Z:\task_1521216935>echo Wait for registry setting to exist before changing it...  
> Wait for registry setting to exist before changing it... 
> Z:\task_1521216935>reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 /ve  
> ERROR: The system was unable to find the specified registry key or value. 
> Z:\task_1521216935>if 1 EQU 0 goto HideTaskBar  
> Z:\task_1521216935>echo HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 does not yet exist  
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 does not yet exist 
> Z:\task_1521216935>timeout /t 1  1>nul  

<snip>

> Z:\task_1521216935>goto CheckForStuckRects3  
> Z:\task_1521216935>echo Wait for registry setting to exist before changing it...  
> Wait for registry setting to exist before changing it... 
> Z:\task_1521216935>reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 /ve  
> ERROR: The system was unable to find the specified registry key or value. 
> Z:\task_1521216935>if 1 EQU 0 goto HideTaskBar  
> Z:\task_1521216935>echo HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 does not yet exist  
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 does not yet exist 
> Z:\task_1521216935>timeout /t 1  1>nul  
> Z:\task_1521216935>goto CheckForStuckRects3  
> Z:\task_1521216935>echo Wait for registry setting to exist before changing it...  
> Wait for registry setting to exist before changing it... 
> Z:\task_1521216935>reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 /ve  
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 
>     (Default)    REG_SZ    (value not set) 
> Z:\task_1521216935>if 0 EQU 0 goto HideTaskBar  
> Z:\task_1521216935>echo Hiding taskbar...


It took an additional **62** seconds before the registry key was available, after the registry had already been mounted....

I will now see if I also need to do anything else to disable desktop effects.
(In reply to Pete Moore [:pmoore][:pete] from comment #10)

> I will now see if I also need to do anything else to disable desktop effects.

I found the powershell to change the settings: https://hg.mozilla.org/try/rev/64ab7a3faff7#l1.48 from bug 1343049. However, this did not work for me:

> C:\Users\task_1521192426>"&{&Set-ItemProperty -Path 'HKCU:SOFTWARE\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects' -Name VisualFXSetting -Value 1}"
> The filename, directory name, or volume label syntax is incorrect.

I also tried with adding parameter `-Type DWord` but that did not help.



This is what I find under VisualEffects:

> PS C:\Users\task_1521192426> reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects /s
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\AnimateMinMax
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\ComboBoxAnimation
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\ControlAnimations
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\CursorShadow
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\DragFullWindows
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\DropShadow
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\DWMAeroPeekEnabled
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\DWMEnabled
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\DWMSaveThumbnailEnabled
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\FontSmoothing
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\ListBoxSmoothScrolling
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\ListviewAlphaSelect
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\ListviewShadow
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\MenuAnimation
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\SelectionFade
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\TaskbarAnimations
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\Themes
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\ThumbnailsOrIcon
>     DefaultApplied    REG_DWORD    0x1
> 
> HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects\TooltipAnimation
>     DefaultApplied    REG_DWORD    0x1

I couldn't see any reference to "VisualFXSetting" in the registry dump above, so I wonder if this is the problem, or if Set-ItemProperty actually creates it.

I ran the same reg query command against production win7 and win10 workers (i.e. the ones currently running generic-worker 8 as an admin user) by creating tasks in the taskcluster task creator, and I could see that the same command output also did not show `VisualFXSetting`, but that might be the reason that it is included in the test harness in bug 1343049.

I also noticed code in OCC to create the key in the default user profile: https://github.com/mozilla-releng/OpenCloudConfig/blob/2ac2ebc7c815205f161722de4795b460913d2f29/userdata/rundsc.ps1#L749-L800

Presumably, when new users are created, their repository hive should be initially created as a copy of the default user profile, so should contain this key, if this has run successfully, so I'm not sure why it doesn't exist.

I'm also aware bug 1343049 was solved, so it seems like this stuff must be working.

Rob, any ideas what's going on here, and why I don't see the registry key entry when I query for it?
Flags: needinfo?(rthijssen)
Note, I've updated the staging test worker types:

  * gecko-t-win7-32-beta
  * gecko-t-win7-32-gpu-b
  * gecko-t-win10-64-beta
  * gecko-t-win10-64-gpu-b

with the following runAfterUserCreation scripts (see comment 5):

Win 7
=====

> REM Task User initialisation script - this script runs as task user, not as administrator.
> REM It runs after task user has logged in, but before worker claims a task.
> 
> :CheckForStuckRects2
> echo Wait for registry setting to exist before changing it...
> reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects2 /ve
> if %ERRORLEVEL% EQU 0 goto HideTaskBar
> echo HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects2 does not yet exist
> timeout /t 1 >nul
> goto CheckForStuckRects2
> 
> :HideTaskBar
> echo Hiding taskbar...
> powershell -command "&{$p='HKCU:SOFTWARE\Microsoft\Windows\CurrentVersion\Explorer\StuckRects2';$v=(Get-ItemProperty -Path $p).Settings;$v[8]=3;&Set-ItemProperty -Path $p -Name Settings -Value $v;&Stop-Process -ProcessName explorer}"
> 
> echo Completed task user initialisation.


Win 10
======

> REM Task User initialisation script - this script runs as task user, not as administrator.
> REM It runs after task user has logged in, but before worker claims a task.
> 
> :CheckForStuckRects3
> echo Wait for registry setting to exist before changing it...
> reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 /ve
> if %ERRORLEVEL% EQU 0 goto HideTaskBar
> echo HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3 does not yet exist
> timeout /t 1 >nul
> goto CheckForStuckRects3
> 
> :HideTaskBar
> echo Hiding taskbar...
> powershell -command "&{$p='HKCU:SOFTWARE\Microsoft\Windows\CurrentVersion\Explorer\StuckRects3';$v=(Get-ItemProperty -Path $p).Settings;$v[8]=3;&Set-ItemProperty -Path $p -Name Settings -Value $v;&Stop-Process -ProcessName explorer}"
> 
> echo Completed task user initialisation.
(In reply to Pete Moore [:pmoore][:pete] from comment #11)

> Rob, any ideas what's going on here, and why I don't see the registry key
> entry when I query for it?

Looks like I can add it with:

REG ADD "HKCU\SOFTWARE\Microsoft\Windows\CurrentVersion\Explorer\VisualEffects" /v "VisualFXSetting" /t REG_DWORD /d 1

I'll give that a shot...
Flags: needinfo?(rthijssen)
OK I've added that to the scripts in comment 12 - so now we'll just see if the latest try push in the parent bug (https://bugzilla.mozilla.org/show_bug.cgi?id=1399401#c83) has any improvements...
I clearly broke something on win7 staging worker types with my change (tasks weren't starting), so I've rolled it back on Win 7.

There is now no runAfterUserCreation configured on:

  * gecko-t-win7-32-beta
  * gecko-t-win7-32-gpu-b
(In reply to Pete Moore [:pmoore][:pete] from comment #15)
> I clearly broke something on win7 staging worker types with my change (tasks
> weren't starting), so I've rolled it back on Win 7.


Among other things, win7 doesn't like timeout command - will need to replace this with a ping command instead.

Mar 16 21:29:23 i-057f9c9c43d45f84a.gecko-t-win7-32-beta.usw2.mozilla.com generic-worker: Z:\task_1521230291>timeout /t 1  1>nul  
Mar 16 21:29:23 i-057f9c9c43d45f84a.gecko-t-win7-32-beta.usw2.mozilla.com generic-worker: ERROR: Input redirection is not supported, exiting the process immediately.
I see two problems with the win 7 script:

1) The registry entry HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects2 does not exist by default - therefore we'll need to create it

I tried this, which worked:

reg add HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects2 /v Settings /t REG_BINARY /d 28000000ffffffff03000000030000006b0000002200000000000000de0200000004000000030000 /f

However, this is also applying a lot of other settings also contained in that key. I need to work out what the default settings are, so I can create it without changing other graphics settings. To do this I'll get an interactive worker, hide the taskbar manually, and then inspect the registry key, to see what the binary settings look like. 

2) On Windows 7, you can't use `timeout` in a non-interactive session. For example, if you run `echo 1 | timeout /t 1` you'll see the input redirection error e see in comment 16.
(In reply to Pete Moore [:pmoore][:pete] from comment #17)
 
> 2) On Windows 7, you can't use `timeout` in a non-interactive session. For
> example, if you run `echo 1 | timeout /t 1` you'll see the input redirection
> error e see in comment 16.

This can be worked around with this alternative command, which also sleeps for 1 second (not 2 seconds!):

ping -n 2 127.0.0.1 1>/nul
(In reply to Pete Moore [:pmoore][:pete] from comment #17)

> I tried this, which worked:
> 
> reg add HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects2
> /v Settings /t REG_BINARY /d
> 28000000ffffffff03000000030000006b0000002200000000000000de0200000004000000030
> 000 /f
> 
> However, this is also applying a lot of other settings also contained in
> that key. I need to work out what the default settings are, so I can create
> it without changing other graphics settings. To do this I'll get an
> interactive worker, hide the taskbar manually, and then inspect the registry
> key, to see what the binary settings look like. 


So I did that manually applying this setting sets the value to:

28000000ffffffff03000000030000003e0000002800000000000000d80300000005000000040000

Compare this the value I tried in comment 17:

28000000ffffffff03000000030000006b0000002200000000000000de0200000004000000030000


I was able to confirm the parent key does already exist, i.e.

HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer

Therefore I'll wait for the parent key to exist in the script, then set StuckRects2 to this new value.


Something like this should do it:

Win 7
=====

> :: Task User initialisation script - this script runs as task user, not as administrator.
> :: It runs after task user has logged in, but before worker claims a task.
> 
> :WaitForExplorerKey
> echo Wait for Explorer registry key to exist before adding sub key...
> reg query HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer /ve
> if %ERRORLEVEL% EQU 0 goto HideTaskBar
> echo HKEY_CURRENT_USER\Software\Microsoft\Windows\CurrentVersion\Explorer does not yet exist
> :: Cannot use timeout command from non-interactive process
> :: (try it yourself with e.g. `echo hello | timeout /t 1`)
> ping -n 2 127.0.0.1 1>/nul
> goto WaitForExplorerKey
> 
> :HideTaskBar
> echo Hiding taskbar...
> :: The value below was obtained simply by manually hiding taskbar, and then seeing what the setting was.
> :: Prior to hiding the task bar, the StuckRects2 key did not exist.
> reg add HKCU\Software\Microsoft\Windows\CurrentVersion\Explorer\StuckRects2 /v Settings /t REG_BINARY /d 28000000ffffffff03000000030000003e0000002800000000000000d80300000005000000040000 /f
> :: Need to stop and start explorer for change to take effect
> taskkill /im explorer.exe /f
> :: Wait 3 seconds before starting
> ping -n 4 127.0.0.1 1> nul
> start explorer.exe
> 
> echo Completed task user initialisation.
Rob, are you happy for us to close this, or are there any extra checks we should add?

The checks we have are pretty much just registry related - I wonder if there is anything else that happens on first login that we should monitor for.
Flags: needinfo?(rthijssen)
yes. +1 close vote
Flags: needinfo?(rthijssen)
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Blocks: 1461762
Component: Generic-Worker → Workers
You need to log in before you can comment on or make changes to this bug.