windows_exporter service failed to start on reboot

[f1-outsourcing]

After updates and rebooting the server, the windows_exporter service was not running

The windows_exporter service failed to start due to the following error: The service did not respond to the start or control request in a timely fashion.

When I look at the recovery options of the windows_exporter service they are not as other 'standard' windows services. Looks like none has set reset fail count after:0 and restart service after: 0

exporter:

other examples:

I am not really an expert on the settings of recovery of services, but maybe someone should look at these. Maybe it is better to put this minutes on 3 or 5?

https://docs.microsoft.com/en-us/archive/blogs/jcalev/some-tricks-with-service-restart-logic https://social.microsoft.com/Forums/ro-RO/3db76753-4607-4a20-97a0-790c73e379cc/the-actions-after-system-service-failure?forum=winserver8gen

[repl-mike-roest]

Another piece on questionably helpful data. I attempted using @bpickhardt workaround of changing the dependency to be directly on WMI and using auto start and was still getting the failures to start on every reboot not just with windows updates (windows 2019 on T2 in AWS). Switching out to using the WMI dependency and delayed start I seem to be getting consistent startup behaviour. This was using 0.16.0

--Edit March 15 Once this deployed to production (100's of instances a day cycling in and out in AWS) Even this configuration is causing some machines to not startup successfully. I've added a manual service start as the last stage in our software deployment script and that has handled the majority of the instances (a handful have still not been caught so I'm further debugging)

[tbiles]

I've personally not made any manual changes to services, nor do I want to. My dependency shows "WMI Performance Adapter". Is that what you are talking about or something else?

I've never seen windows_exporter not start up on a normal reboot, but I do have a limited test environment (OS 2008R2, 2012R2, 2016, 2019 Core and Full GUI) of only 10 machines. My start up issues have only been seen after Microsoft updates w/reboot. The service will then start manually or doing another reboot (no updates).

Tim

On Wed, Mar 3, 2021 at 11:14 AM Mike Roest notifications@github.com wrote:

Another piece on questionably helpful data. I attempted using @bpickhardt https://github.com/bpickhardt workaround of changing the dependency to be directly on WMI and using auto start and was still getting the failures to start on every reboot not just with windows updates (windows 2019 on T2 in AWS). Switching out to using the WMI dependency and delayed start I seem to be getting consistent startup behaviour.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/prometheus-community/windows_exporter/issues/551#issuecomment-789899096, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADUP2G5GRVQH54YTFS2TTTDTBZU6JANCNFSM4OD2L4ZA .

-- Tim Biles Sys/Database Design/Admin 3 | ITSS | itss.d.umn.edu Storage Champion | z.umn.edu/scn University of Minnesota Duluth | www.d.umn.edu tbiles@d.umn.edu | 218-726-6959

[tbiles]

With the 0.16.0 release available, can we test with that, or should we continue using 0.15.1 to troubleshoot startup issues?

On Mon, Feb 22, 2021 at 2:01 PM Calle Pettersson notifications@github.com wrote:

New binary https://ci.appveyor.com/api/buildjobs/5ukospmcrjnfyf47/artifacts/output%2Famd64%2Fwindows_exporter-0.15.1-immediate-service-run.1%2B51-amd64.exe

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/prometheus-community/windows_exporter/issues/551#issuecomment-783636287, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADUP2G42SP6FOSDTPL7IKK3TAKZY3ANCNFSM4OD2L4ZA .

-- Tim Biles Sys/Database Design/Admin 3 | ITSS | itss.d.umn.edu Storage Champion | z.umn.edu/scn University of Minnesota Duluth | www.d.umn.edu tbiles@d.umn.edu | 218-726-6959

[AIXruth]

Same issue with 0.16. Every now and then the exporter won't start after a reboot. So what are the recommended settings, so that the service will start reliable and after any reboot time?

[repl-mike-roest]

@AIXruth Ours has become "reliable" with the following tweaks in our AMI's

sc.exe config windows_exporter start=delayed-auto
sc.exe config windows_exporter depend=Winmgmt

Along with the final step of our UserData script:

  $exporter=Get-Service -Name "windows_exporter" -ErrorAction SilentlyContinue
  $count=0
  while ($exporter -And $exporter.Status -ne "Running" -And $count -le 5) {
    Log ("Automatic Kicking Machine for windows_exporter engaged. Current Status "+ ($exporter.Status))
    if ( $exporter.Status -eq "Stopped") {
      Start-Service -Name "windows_exporter" -ErrorAction SilentlyContinue
    }
    $exporter=Get-Service -Name "windows_exporter" -ErrorAction SilentlyContinue
    Start-Sleep -s 10
  }

[DeveloperSasmita]

Hi, I am also experiencing the same issue even after setting start after 1 minute for windows exporter 0.15, I have tried setting delayed automatic start too. Kindly let me know if anyone has found a viable solution for this.

[tbiles]

I've been on 0.16 code for 2 Microsoft patch cycles. I've adjusted all my test systems to Automatic Delayed Start. While I saw some improvement with delayed start, it only fixed some of the systems and not others. Some OS versions would start windows_exporter after a Microsoft Update and reboot, other OS versions it didn't make any difference.

Tim

On Thu, May 6, 2021 at 3:11 AM susmitameher @.***> wrote:

Hi, I am also experiencing the same issue even after setting start after 1 minute for windows exporter 0.15, I have tried setting delayed automatic start too. Kindly let me know if anyone has found a viable solution for this.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/prometheus-community/windows_exporter/issues/551#issuecomment-833324693, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADUP2G5AEHISA3JP5NUGWM3TMJFJ3ANCNFSM4OD2L4ZA .

-- Tim Biles Sys/Database Design/Admin 3 | ITSS | itss.d.umn.edu Storage Champion | z.umn.edu/scn University of Minnesota Duluth | www.d.umn.edu @.*** | 218-726-6959

[compilenix]

I've got the same issue with a significant amount of servers, but not all. The Service may or may not start automatically after reboots. Windows Eventlog shows these timeout messages as well.

When manually starting it sometimes does start after a couple of seconds and sometimes times out too. I have to repeat this several times.

Once the service is running, restarting it multiple times does not redproduce the same issue. I've only seen this for the first service start after a windows reboot. This is also true when the service was set to manual startup and after an hour or so got manually started.

I've had similar issues with other applications / services, where either the application runtime (i.e. .Net Runtime) took to long to reach the application / service entry point or / and application startup got held up by anti-virus so much that the timeout was reached.

[chriswiggins]

Chiming in here - we're seeing the same issue. Strangely it only seems to happen during the patching cycle.

Is there any extra information we can gather to help with this?

[tbiles]

I have the same basic pattern repeated every month, it is pretty frustrating. I won't be rolling it out widely until we get a stable release.

Tim

On Wednesday, June 16, 2021, Chris Wiggins @.***> wrote:

Chiming in here - we're seeing the same issue. Strangely it only seems to happen during the patching cycle.

Is there any extra information we can gather to help with this?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.< https://ci5.googleusercontent.com/proxy/ruJMvFMGkcDWODzxwgEJEaT6hELvR945RqaoZwAxMMqmZ7XXEiWD7UHAsyHULd0aLyJaGQ8RJhc3GOmwQ-u5m16FADeDVD3g9NKRlpvRrbLwfyT8OFcQffUkK89gkGvKeH6A_CLtEIFIAjBRyjqvbEXqCS8WHtf03NMRjEhnIUwMtlbNaqERTAsVEKqgbx2mWyRmm7SMiTn_wQpqM6PouaRUYsQ0-moHv03p9ohyVA=s0-d-e1-ft#https://github.com/notifications/beacon/ADUP2G4FXMK6H4XDTV7PUGLTTEZ2NA5CNFSM4OD2L4ZKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOGNWV54A.gif

-- Sent from Gmail Mobile

[dmaziuk]

+1: we have mostly 2012 servers, and couple of 2016's where this is happening on patch reboots -- not on our all servers. The error is timeout and on manual start it logs No filters specified for process collector. This will generate a very large number of metrics!

[hashi825]

We are also encountering this on reboots specifically after patching, our work around at the moment is a scheduled task to continuously ensure the exporter is started which is not really ideal.

[akunzai]

My Workaround

Register-ScheduledTask -TaskName RecoverWindowsExporter `
-Trigger (New-JobTrigger -Once -At 0am -RepetitionInterval (New-TimeSpan -Hour 1) -RepeatIndefinitely) `
-User SYSTEM `
-RunLevel Highest `
-Action (New-ScheduledTaskAction `
 -Execute powershell `
 -Argument '-NoProfile -ExecutionPolicy Bypass -Command "Start-Service windows_exporter' `
 )

[per-lind]

We are also seeing this and the feeling is that it happens on machines that experience a high load at startup. For example on a small vm after patchning or also when the underlying host is loaded like when multiple machines is coming up.

[devopsusr-tech]

Same issue here, whenever we have to execute the upgrades. the windows exporter does not start

[Andy-Techical]

I see this issue frequently, occurring typically when there are alot of Windows updates released and available for install.

After the updates are installed and the server is restarted, if the server is under heavy CPU load whilst the updates are installing, then the Windows_exporter service does not start up.

Usually, it is the Windows Modules Installer Worker(TiWorker.exe) service which is using up high CPU on the server to install the updates. I use mainly Windows Server 2016.

Would it be possible to put some logic in whereby the "Windows_exporter" service is checked every x minutes to check its up and running, and if not, to start it up?

[Andy-Techical]

Hello all, just wondering if I can help provide anything to help resolve this issue? I'm just an end user but can help with getting any dump files or logs when the issue occurs as we see this frequently when there are alot of windows updates which have been installed and the servers have restarted as a result of the update.

[IKroppach]

Hey everyone, we are using version 0.16 and have the same problem. It happens to different kind of windows servres and only happens after reboot during a windows patch. Does version 0.17 help? What kind of information can i deliver to help? Thanks for all the work and good look fixing this problem.

[Andy-Techical]

Hello

We've also tested on v0.17 but still have the same issue unfortunately. The issue can be reproduced any time there are a large number of windows updates installed. Upon restart of the server (we use mainly Windows Server 2016), the Windows Modules Installer service starts running to install the updates, and this typically causes the Windows Exporter service to fail to start up.

We have tried adding a delay in the startup (i.e. start up after X minutes) and also placed the service in Automatic (Delayed start) startup, but still face the same issue.

[Andy-Techical]

Hello All

Would it be possible to prioritise this issue somehow? Happy to help with troubleshooting and testing

Thank you

[audriuz]

Same issue keeps happening in our environment since implementation as well, no matter which Windows Exporter version being used. Windows Server 2012 R2 and Windows Server 2016 machines are impacted for sure. The only workaround is to use scheduled task to keep starting windows_exporter service, but it doesn't look serious.

[martohub]

It really would be great if we could have this issue prioritized - it's over an year old and affects Server 2012R2, 2016, 2019. We have the agent implemented for over an year and this occurs after every patching.

Can confirm that none of the workarounds in all threads about this issue are working (apart from the scheduled task @audriuz mentioned about, but as noted - this is just not serious for any environment)

[tbiles]

I'd like to see fixing this prioritized as well. I've been dragging my feet on rolling this out as a production monitoring service due to it not being stable in these situations. Setting to delayed start seems to help somewhat, but not on all my test systems, which range from 2008R2 to 2019.

Tim

On Tue, Jan 25, 2022 at 4:43 AM Martin @.***> wrote:

It really would be great if we could have this issue prioritized - it's over an year old and affects Server 2012R2, 2016, 2019. We have the agent implemented for over an year and this occurs after every patching.

Can confirm that none of the workarounds in all threads about this issue are working (apart from the scheduled task @audriuz https://github.com/audriuz mentioned about, but as noted - this is just not serious for any environment)

— Reply to this email directly, view it on GitHub https://github.com/prometheus-community/windows_exporter/issues/551#issuecomment-1021049899, or unsubscribe https://github.com/notifications/unsubscribe-auth/ADUP2G6SHV7OO6HOJFLBH33UXZ5G3ANCNFSM4OD2L4ZA . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

You are receiving this because you were mentioned.Message ID: @.***>

-- Tim Biles DevOps Engineering 3 | ITSS | itss.d.umn.edu Research Cyberinfrastructure Champion | rcc.umn.edu University of Minnesota Duluth | www.d.umn.edu @.***| 218-726-6959

https://www.credly.com/badges/e8624746-cda4-4eab-9d2e-bc9be9cd036c/public_url

[dmaziuk]

I wonder if

No filters specified for process collector. This will generate a very large number of metrics!

is a hint: don't try to enumerate everything at startup, give it a second or three.

[Andy-Techical]

Hi All

Would it be possible to remove the "info needed" tag of this thread as I think we have enough info now as to why the issue is occurring.

It occurs whenever there are a large number of Windows updates being installed. Upon reboot of the server, CPU may be high on the server as the Windows Modules Installer service runs to install the updates. During this time, the Windows Exporter service fails to start.

Thanks

[per-lind]

This feels related https://github.com/golang/go/issues/23479

[JDA88]

This feels related golang/go#23479

This thread is extremely interesting. windows_exporter should (if it can):

• Start the process
• Report back to windows the service starting state (ASAP)
• Initialization all the object it needs
• Report back to windows the service started state
• Start the main loop

[Andy-Techical]

Thanks breed808 for removing the "info needed" tag. Hopefully this issue will be looked at soon. thanks.

[m49808]

Same problem here. Cant reliably use this until this is solved. Or at least some workaround. I recall the prior way of setting up the "wmi_exporter" was to use something like nssm. Not sure if that is a valid option anymore.

[shohidur-rahman]

we faced the same issue with the 0.18.1 version as well.

[t0mcat1337]

Same issue for us with 0.18.1 on Windows Server 2019 Standard Edition. The service used to run without any problems for many weeks but from one day to another it can't be started any more with the same "timeout" errors in event logs.

We tried to start the exe manually on an Admin - CMD and noticed that there is a delay of 2-3 minutes until even the first line of output comes from the exe:

C:\Windows\system32>echo %DATE% %TIME% & "C:\Program Files\windows_exporter\windows_exporter.exe" --log.format=logger:stdout --log.level=debug
30.03.2022 15:25:49,30
time="2022-03-30T15:28:17+02:00" level=debug msg="Initializing SWbemServices" source="exporter.go:249"
time="2022-03-30T15:28:17+02:00" level=warning msg="No where-clause specified for service collector. This will generate a very large number of metrics!" source="service.go:48"
time="2022-03-30T15:28:17+02:00" level=debug msg="Detected Windows version 6.300000\n" source="collector.go:48"
time="2022-03-30T15:28:17+02:00" level=info msg="Enabled collectors: system, textfile, cpu, cs, logical_disk, net, os, service" source="exporter.go:348"
time="2022-03-30T15:28:17+02:00" level=info msg="Starting windows_exporter (version=0.18.1, branch=heads/tags/v0.18.1, revision=e07b2053af3ca708db3489f41e2fcde9941860f4)" source="exporter.go:400"
time="2022-03-30T15:28:17+02:00" level=info msg="Build context (go=go1.17.6, user=runneradmin@fv-az177-985, date=20220205-08:18:35)" source="exporter.go:401"
time="2022-03-30T15:28:17+02:00" level=info msg="Starting server on :9182" source="exporter.go:404"
time="2022-03-30T15:28:17+02:00" level=info msg="TLS is disabled." source="gokit_adapter.go:38"

Notice the very first date / time echo saying "15:25:49,30" and the first output from the exporter at "15:28:17".

This is of course much higher than the service managers 30sec timeout ....

But once started this way, the exporter works as it should.

We have absolutly no idea what could cause this startup - delay. For us it looks like as the exporter tries sth. right after being started, waits for whatever until an internal timeout and after that starts finally...

[tbiles]

@AIXruth Ours has become "reliable" with the following tweaks in our AMI's

sc.exe config windows_exporter start=delayed-auto
sc.exe config windows_exporter depend=Winmgmt

Along with the final step of our UserData script:

  $exporter=Get-Service -Name "windows_exporter" -ErrorAction SilentlyContinue
  $count=0
  while ($exporter -And $exporter.Status -ne "Running" -And $count -le 5) {
    Log ("Automatic Kicking Machine for windows_exporter engaged. Current Status "+ ($exporter.Status))
    if ( $exporter.Status -eq "Stopped") {
      Start-Service -Name "windows_exporter" -ErrorAction SilentlyContinue
    }
    $exporter=Get-Service -Name "windows_exporter" -ErrorAction SilentlyContinue
    Start-Sleep -s 10
  }

So, someone commented on this which I saw in an email, but not here. I had not seen this previously, but it made me curious so I checked how my windows_exporter is configured: sc.exe qc windows_exporter [SC] QueryServiceConfig SUCCESS

SERVICE_NAME: windows_exporter TYPE : 10 WIN32_OWN_PROCESS START_TYPE : 2 AUTO_START (DELAYED) ERROR_CONTROL : 1 NORMAL BINARY_PATH_NAME : "C:\Program Files\windows_exporter\windows_exporter.exe" --log.format logger:eventlog?name=windows_exporter LOAD_ORDER_GROUP : TAG : 0 DISPLAY_NAME : windows_exporter DEPENDENCIES : wmiApSrv SERVICE_START_NAME : LocalSystem

It appears the default dependency (at least through 0.18.1) is different, so could we request that the installation behavior change the dependency to "Winmgmt" instead of "wmiApSrv" if that indeed is the stable option? I'm thinking I'll switch my 0.18.1 installs over to use this dependency and see if everything survives patch Tuesday. As they stand right now, 30-50% of my windows_exporter services have to be manually restarted each month after patch Tuesday.

[tbiles]

I switched all my systems to use Winmgmt sc.exe qc windows_exporter [SC] QueryServiceConfig SUCCESS

SERVICE_NAME: windows_exporter TYPE : 10 WIN32_OWN_PROCESS START_TYPE : 2 AUTO_START (DELAYED) ERROR_CONTROL : 1 NORMAL BINARY_PATH_NAME : "C:\Program Files\windows_exporter\windows_exporter.exe" --log.format logger:eventlog?name=windows_exporter LOAD_ORDER_GROUP : TAG : 0 DISPLAY_NAME : windows_exporter DEPENDENCIES : Winmgmt SERVICE_START_NAME : LocalSystem

Just one note on the sc.exe commands... if you need a consistent script that works on older OS versions, you need to add a space after the "=" sign, or you will get an error on 2008R2. This works on everything 2008R2 through 2019.

sc.exe config windows_exporter depend= Winmgmt

[bpickhardt]

My solution was just to create a scheduled task to attempt to start the service after the machine starts up. I set the timeout on this to 10 minutes because when it was 5 minutes I had mixed results. The 10 minutes one has been more successful at starting the service correctly. Its no silver-bullet but it has worked for me so far. Clearly you need to also make sure your prometheus alerting, if you have any, about when machines are not reporting also waits 10-15 minutes before telling you so it isn't ideal for all environments.

if(Get-Service windows_exporter -ErrorAction Ignore){
    if(Get-ScheduledTask | Where-Object {$_.TaskName -eq "Start windows_exporter"}){
        Unregister-ScheduledTask -TaskName "Start windows_exporter" -Confirm:$false
    }

    $action = New-ScheduledTaskAction -Execute 'Powershell.exe' -Argument '-NoProfile -WindowStyle Hidden -command "sleep 600; Start-Service windows_exporter"'
    $trigger =  New-ScheduledTaskTrigger -AtStartup
    Register-ScheduledTask -Action $action -Trigger $trigger -TaskName "Start windows_exporter" -Description "Verify windows_exporter is started" -User 'NT AUTHORITY\SYSTEM' -RunLevel Highest
}

[tbiles]

My solution was just to create a scheduled task to attempt to start the service after the machine starts up. I set the timeout on this to 10 minutes because when it was 5 minutes I had mixed results. The 10 minutes one has been more successful at starting the service correctly. Its no silver-bullet but it has worked for me so far. Clearly you need to also make sure your prometheus alerting, if you have any, about when machines are not reporting also waits 10-15 minutes before telling you so it isn't ideal for all environments.

if(Get-Service windows_exporter -ErrorAction Ignore){
  if(Get-ScheduledTask | Where-Object {$_.TaskName -eq "Start windows_exporter"}){
      Unregister-ScheduledTask -TaskName "Start windows_exporter" -Confirm:$false
  }

  $action = New-ScheduledTaskAction -Execute 'Powershell.exe' -Argument '-NoProfile -WindowStyle Hidden -command "sleep 600; Start-Service windows_exporter"'
  $trigger =  New-ScheduledTaskTrigger -AtStartup
  Register-ScheduledTask -Action $action -Trigger $trigger -TaskName "Start windows_exporter" -Description "Verify windows_exporter is started" -User 'NT AUTHORITY\SYSTEM' -RunLevel Highest
}

This is good, but I would prefer that the app be stabilized so that we don't need to write work arounds to keep it running. I'm looking forward to patch Tuesday to see if the service dependency change works.

[tbiles]

After patch Tuesday reboots overnight, I had similar results to previous months, so the dependency service setting doesn't seem to have any affect on reliability. Event log entries look similar to past failures when using the WMI dependency.

1 - 2008R2 - failed 4 - 2012R2 - 3 started, 1 failed 1 - 2016 - started 1 2019 Core - started 3 - 2019 Standard - 1 started, 2 failed

[safster123]

I've been able to replicate the issue fairly consistently on test EC2 instances. Created servers using the previous months AMIs and then installed patches, rebooted, then found windows exporter failed to start on boot. (Windows server 2019 full)

I attempted the following which all failed: 1) Install windows_exporter - no modifications - install patches and reboot 2) Install windows_exporter - change dependency to WinMgmt - install patches and reboot 3) Install windows_exporter - remove all dependencies - install patches and reboot

I attempted 3) due to the fact that the dependency looks like it was only added to attempt to fix this problem in the first place from version 0.15.0 onwards, before that, there were no dependencies. The last working version I'm aware of that didn't have this startup issue was v0.13.x.

Another thing that may prove useful is that windows_exporter seems to start fine if I wait for the event log entry that shows the patch has installed successfully. The on boot start attempts happen before this message. It could be co-incidental of course.

As a work around, I've simply gone with @bpickhardt method of running a scheduled start on boot but I've set the initial wait time of 6 minutes then start a loop if it's not started which will attempt to restart every 1 minute after that for a further 6 attempts.

Of course, this is not something anyone should have to do, we really need this issue fixed, it's been well over a year of patching hell...

[JsBergbau]

sc.exe config windows_exporter depend= Winmgmt Thanks that and in addtion setting service to delayed start worked for me on Windows Server 2019.

[breed808]

How would everyone feel if we set the MSI service defaults to a delayed start, with Winmgmt as a dependency? I'm aware this is a workaround to the real issue, but I feel it's better to at least improve the user experience with the exporter service.

[tbiles]

I would be in favor of this, though I have to say it hasn't been 100% successful in remedying the issue.

Tim

On Saturday, May 28, 2022, Ben Reedy @.***> wrote:

How would everyone feel if we set the MSI service defaults to a delayed start, with Winmgmt as a dependency? I'm aware this is a workaround to the real issue, but I feel it's better to at least improve the user experience with the exporter service.

— Reply to this email directly, view it on GitHub, or unsubscribe. You are receiving this because you were mentioned.< https://ci6.googleusercontent.com/proxy/MPsapr_LfFsOPYu5l1v05JmjiPfvSRgHCRObjFLahPwbsiK3KRBgPWLpzNp9CDLFYYb7aH02YnBqdet76KsxXlcUOFQ02tmHIod_GGrPfuA9APo5kdwSqMg8HsGdQhd3gj5WrsqzdBcwvvkmfB89ADRXq4GMVy7hVv8axzpoRqyMx2GJ9ZxpLvO4OLnpkfgXLW0bT8LBX9Mvz3HbDUEYe26bF0ik-NrDZfQSDyh7yg=s0-d-e1-ft#https://github.com/notifications/beacon/ADUP2G3GOCALC56GDVEKHGTVMK4ETA5CNFSM4OD2L4ZKYY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOIP4F3VY.gif>Message ID: @.***>

-- Sent from Gmail Mobile

[martohub]

Gents, I've been following this thread for quite some time and I can see it going in loops. This appears to be a golang runtime issue as was already mentioned.

There are 2 workarounds that have proven to be working 100%, both could be very uncomfortable for many reasons. 1) having a scheduled task at boot for ensuring the service is started (mentioned countless times) 2) installing windows_exporter using nssm.exe instead of sc.exe

For some reason, I haven't been able to reproduce the issue after patching when the service is created by nssm.

Another interesting test - I've installed windows_exporter on a test instance using both sc and nssm. With both services stopped I'm stressing the CPU to 100% using a powershell script and attempting to start/stop the services one by one. Results are: 1) sc service timeouts at 60 seconds and can't be started 2) nssm service starts for less than a second

It would be great if someone with more Windows-ing background could try to reproduce the issue using nssm. If it can't be reproduced using nssm (and I'm not insane), it would be even greater to know why and if sc could behave so.

Thanks.

[amccool]

I have a concern with using nssm. At least 2 organizations I have worked with block nssm, flagging it as malware or the sideeffects of malware.

re: sc.exe and 60 sec timeout. There is a setting for changing that timeout value. However this is system wide for all services, so yuck. ServicesPipeTimeout

if windows_exporter.exe is not actually starting under 60 seconds, or at least returning a running status to sc.exe, that will be the root cause.

[Andy-Techical]

Would there be any way to get this issue prioritised ? It's easy enough to reproduce (occurs when CPU is high on a Windows server post-restart once Windows patches have been installed)

[martohub]

@amccool, my concerns exactly. With CPU at 100%, windows_exporter.exe starts successfully after ~2-3 minutes when executed from shell, and timeouts if started by the sc service. The question here is why nssm starts the same executable for less than 1 second during the same conditions - privileges/priority? But again - yuck, whatever it is it'll still require touching registries. Edit: Tested this a while ago, the result is roughly the same when running from source and with executable:

@Andy-Techical, I don't believe that priority has been an issue here. No one has a clue how to fix this. You could use your patching software/pipeline to execute with delay "net start windows_exporter" on the machines upon reboot after patching - this has been working for me.

The only approach that I can think of is implementing a timer that throws exit code 1 to Windows if the main loop has not been started successfully in under 60 seconds. Unfortunately, I'm unsure if this will change anything and I'm lacking both golang experience and the nerves to pursue this.

If anyone has any new thoughts on how to approach this it'd be great to share with the rest of us.

[t0mcat1337]

@amccool, my concerns exactly. With CPU at 100%, windows_exporter.exe starts successfully after ~2-3 minutes when executed from shell, and timeouts if started by the sc service. The question here is why nssm starts the same executable for less than 1 second during the same conditions - privileges/priority? But again - yuck, whatever it is it'll still require touching registries. Edit: Tested this a while ago, the result is roughly the same when running from source and with executable:

@Andy-Techical, I don't believe that priority has been an issue here. No one has a clue how to fix this. You could use your patching software/pipeline to execute with delay "net start windows_exporter" on the machines upon reboot after patching - this has been working for me.

The only approach that I can think of is implementing a timer that throws exit code 1 to Windows if the main loop has not been started successfully in under 60 seconds. Unfortunately, I'm unsure if this will change anything and I'm lacking both golang experience and the nerves to pursue this.

If anyone has any new thoughts on how to approach this it'd be great to share with the rest of us.

Exactly the same behaviour I figuerd out as root cause in my post here: https://github.com/prometheus-community/windows_exporter/issues/551#issuecomment-1083148959

[jammiemil]

Ive been spending some time over the last few days looking into this in some detail and i thought id share what ive observed so far to see if it gives anyone some ideas

I will start by saying i am by no means a 'GO Developer' I am a hobbyist at best but i do a little bit of everything when it comes to diagnosing/troubleshooting issues like this as a consultant so i apologise if i have any of the nomenclature incorrect:

1. The 'Issue' Here can be reliably recreated on a device/VM with minimal system resources Available (Notably CPU) as the issue seems to be rooted in resource constraints when starting the executable. This is most obviously seen during a start-up after windows update due to the CPU spike that generally follows, but in my case I'm simulating this by limiting my VM to ~1/4 vcpu in hyper-v and Logging in before the service has a chance to start (here), the 'Issue' Being the Executable takes more than 30 seconds to initialise and report its status back to the Windows Service Subsystems
2. I confirmed that this happens in other GO Based services under similar constraints (Namely Grafana Agent + Telegraf) so this isn't completely a windows_exporter issue however in other GO implementations it seems that there are things you can sometimes do to make the initial load fast, ultimately however it would be good if GO handled this better (https://github.com/golang/go/issues/23479)
3. The workaround of Delaying the start of the service often helps as it delays the start for ~2mins (default was 120s on my test machine) and therefore skips the period of low resources, assuming this clears within 2 mins, however sometimes this isnt the case, and changing this delay system wide is often not an option
4. Moving the initialization of logging up to the init() of exporter.go allowed me to add extra logging to init() and main() however this wasn't being reached inside the 30 seconds under load so didnt yield much, Possibly something to consider doing regardless however so that logging can begin at the start of main() rather than part way through
5. Running a trace of the startup (set GODEBUG=inittrace=1) has yielded some interesting things, I couldnt work out a way to capture this when running as a service so ive been starting up using a batch file when the servers under load to again simulate the Resource constraints mentioned above. You can definately see that the load time of some of these dependencies are extended considerably under load, so if the aim was to 'slim down' the service statup they would probably be the places to start,

Heres a trace from a 'Constrained' Startup:

init internal/bytealg @0 ms, 0 ms clock, 0 bytes, 0 allocs
init runtime @0 ms, 0 ms clock, 0 bytes, 0 allocs
init errors @625 ms, 0 ms clock, 0 bytes, 0 allocs
init sync @625 ms, 0.50 ms clock, 16 bytes, 1 allocs
init io @626 ms, 0 ms clock, 144 bytes, 9 allocs
init math @626 ms, 0 ms clock, 0 bytes, 0 allocs
init strconv @626 ms, 0 ms clock, 32 bytes, 2 allocs
init unicode @626 ms, 0 ms clock, 23528 bytes, 25 allocs
init reflect @626 ms, 0 ms clock, 0 bytes, 0 allocs
init encoding/binary @626 ms, 0 ms clock, 16 bytes, 1 allocs
init encoding/base64 @626 ms, 0 ms clock, 1408 bytes, 4 allocs
init internal/oserror @626 ms, 0 ms clock, 80 bytes, 5 allocs
init internal/syscall/windows/sysdll @635 ms, 0 ms clock, 48 bytes, 1 allocs
init syscall @644 ms, 0.50 ms clock, 8912 bytes, 174 allocs
init internal/syscall/windows/registry @645 ms, 0 ms clock, 416 bytes, 10 allocs
init time @645 ms, 16 ms clock, 14792 bytes, 11 allocs
init path @661 ms, 0 ms clock, 16 bytes, 1 allocs
init io/fs @661 ms, 0 ms clock, 16 bytes, 1 allocs
init internal/syscall/windows @661 ms, 0 ms clock, 1616 bytes, 36 allocs
init internal/poll @661 ms, 381 ms clock, 344 bytes, 12 allocs
init os @1042 ms, 20 ms clock, 3120 bytes, 35 allocs
init fmt @1062 ms, 0 ms clock, 32 bytes, 2 allocs
init bytes @1063 ms, 0 ms clock, 48 bytes, 3 allocs
init encoding/json @1063 ms, 0 ms clock, 32 bytes, 2 allocs
init context @1063 ms, 0 ms clock, 128 bytes, 4 allocs
init crypto @1063 ms, 0 ms clock, 160 bytes, 1 allocs
init crypto/cipher @1063 ms, 0 ms clock, 16 bytes, 1 allocs
init crypto/aes @1063 ms, 0 ms clock, 16 bytes, 1 allocs
init math/rand @1063 ms, 0 ms clock, 5440 bytes, 3 allocs
init math/big @1063 ms, 0 ms clock, 32 bytes, 2 allocs
init crypto/elliptic/internal/fiat @1063 ms, 8.9 ms clock, 320 bytes, 6 allocs
init crypto/elliptic/internal/nistec @1072 ms, 0 ms clock, 712 bytes, 15 allocs
init crypto/rand @1072 ms, 0 ms clock, 48 bytes, 2 allocs
init crypto/sha512 @1072 ms, 0 ms clock, 0 bytes, 0 allocs
init encoding/asn1 @1072 ms, 0 ms clock, 224 bytes, 7 allocs
init vendor/golang.org/x/crypto/cryptobyte @1072 ms, 0 ms clock, 48 bytes, 2 allocs
init crypto/ecdsa @1072 ms, 0 ms clock, 48 bytes, 3 allocs
init crypto/ed25519/internal/edwards25519 @1072 ms, 0 ms clock, 496 bytes, 5 allocs
init crypto/rsa @1072 ms, 0 ms clock, 664 bytes, 18 allocs
init crypto/sha1 @1072 ms, 0 ms clock, 0 bytes, 0 allocs
init crypto/sha256 @1072 ms, 0 ms clock, 0 bytes, 0 allocs
init vendor/golang.org/x/sys/cpu @1072 ms, 0 ms clock, 1624 bytes, 7 allocs
init vendor/golang.org/x/crypto/chacha20poly1305 @1072 ms, 0 ms clock, 16 bytes, 1 allocs
init crypto/dsa @1072 ms, 0 ms clock, 16 bytes, 1 allocs
init encoding/hex @1072 ms, 0 ms clock, 16 bytes, 1 allocs
init crypto/x509/pkix @1072 ms, 0 ms clock, 624 bytes, 2 allocs
init vendor/golang.org/x/net/dns/dnsmessage @1072 ms, 0 ms clock, 1616 bytes, 27 allocs
init internal/intern @1072 ms, 0 ms clock, 336 bytes, 5 allocs
init net/netip @1072 ms, 0 ms clock, 48 bytes, 2 allocs
init net @1072 ms, 0 ms clock, 1568 bytes, 27 allocs
init crypto/md5 @1072 ms, 0 ms clock, 0 bytes, 0 allocs
init crypto/x509 @1072 ms, 0 ms clock, 5504 bytes, 251 allocs
init vendor/golang.org/x/crypto/curve25519 @1072 ms, 0 ms clock, 0 bytes, 0 allocs
init crypto/tls @1072 ms, 0 ms clock, 1888 bytes, 15 allocs
init log @1072 ms, 0 ms clock, 80 bytes, 1 allocs
init bufio @1072 ms, 0 ms clock, 176 bytes, 11 allocs
init mime @1072 ms, 0 ms clock, 1232 bytes, 4 allocs
init path/filepath @1073 ms, 0 ms clock, 16 bytes, 1 allocs
init mime/multipart @1073 ms, 0 ms clock, 192 bytes, 4 allocs
init compress/flate @1073 ms, 0 ms clock, 4240 bytes, 7 allocs
init hash/crc32 @1073 ms, 0 ms clock, 1024 bytes, 1 allocs
init compress/gzip @1073 ms, 0 ms clock, 32 bytes, 2 allocs
init io/ioutil @1073 ms, 0 ms clock, 0 bytes, 0 allocs
init vendor/golang.org/x/text/transform @1073 ms, 0 ms clock, 80 bytes, 5 allocs
init vendor/golang.org/x/text/unicode/bidi @1073 ms, 0 ms clock, 272 bytes, 2 allocs
init vendor/golang.org/x/text/secure/bidirule @1073 ms, 0 ms clock, 16 bytes, 1 allocs
init vendor/golang.org/x/text/unicode/norm @1073 ms, 0 ms clock, 0 bytes, 0 allocs
init vendor/golang.org/x/net/idna @1073 ms, 0 ms clock, 0 bytes, 0 allocs
init vendor/golang.org/x/net/http/httpguts @1073 ms, 0 ms clock, 688 bytes, 2 allocs
init vendor/golang.org/x/net/http2/hpack @1073 ms, 0 ms clock, 22232 bytes, 31 allocs
init net/http/internal @1073 ms, 0 ms clock, 16 bytes, 1 allocs
init vendor/golang.org/x/net/http/httpproxy @1073 ms, 0 ms clock, 336 bytes, 2 allocs
init net/http @1073 ms, 137 ms clock, 10856 bytes, 121 allocs
init golang.org/x/sys/windows @1210 ms, 0 ms clock, 21616 bytes, 453 allocs
init html @1210 ms, 0 ms clock, 224 bytes, 2 allocs
init regexp/syntax @1210 ms, 0 ms clock, 7232 bytes, 8 allocs
init regexp @1210 ms, 0 ms clock, 0 bytes, 0 allocs
init internal/profile @1210 ms, 1.0 ms clock, 98424 bytes, 758 allocs
init runtime/pprof @1211 ms, 0 ms clock, 32 bytes, 2 allocs
init net/http/pprof @1211 ms, 0 ms clock, 1328 bytes, 7 allocs
init github.com/go-ole/go-ole @1211 ms, 0 ms clock, 4304 bytes, 103 allocs
init github.com/StackExchange/wmi @1211 ms, 0 ms clock, 136 bytes, 4 allocs
init golang.org/x/sys/windows/registry @1211 ms, 0 ms clock, 496 bytes, 11 allocs
init github.com/sirupsen/logrus @1211 ms, 0 ms clock, 312 bytes, 5 allocs
init github.com/go-logfmt/logfmt @1214 ms, 0 ms clock, 64 bytes, 4 allocs
init github.com/go-kit/log @1214 ms, 0 ms clock, 13688 bytes, 109 allocs
init github.com/go-kit/log/level @1214 ms, 0 ms clock, 16 bytes, 1 allocs
init github.com/alecthomas/units @1214 ms, 0 ms clock, 832 bytes, 26 allocs
init internal/lazyregexp @1214 ms, 0 ms clock, 0 bytes, 0 allocs
init text/template/parse @1214 ms, 0 ms clock, 464 bytes, 2 allocs
init text/template @1214 ms, 0 ms clock, 80 bytes, 5 allocs
init go/token @1214 ms, 2.5 ms clock, 1776 bytes, 5 allocs
init go/doc @1217 ms, 0 ms clock, 2208 bytes, 18 allocs
init github.com/alecthomas/template/parse @1217 ms, 0 ms clock, 464 bytes, 2 allocs
init github.com/alecthomas/template @1217 ms, 0.27 ms clock, 4912 bytes, 12 allocs
init gopkg.in/alecthomas/kingpin%2ev2 @1217 ms, 0 ms clock, 7240 bytes, 96 allocs
init github.com/prometheus-community/windows_exporter/log @1217 ms, 0 ms clock, 416 bytes, 5 allocs
init google.golang.org/protobuf/internal/detrand @1217 ms, 0 ms clock, 4192 bytes, 28 allocs
init google.golang.org/protobuf/internal/errors @1217 ms, 0 ms clock, 16 bytes, 1 allocs
init google.golang.org/protobuf/encoding/protowire @1217 ms, 0 ms clock, 216 bytes, 10 allocs
init google.golang.org/protobuf/reflect/protoreflect @1217 ms, 0 ms clock, 0 bytes, 0 allocs
init google.golang.org/protobuf/internal/encoding/text @1217 ms, 0 ms clock, 3336 bytes, 34 allocs
init google.golang.org/protobuf/reflect/protoregistry @1217 ms, 0 ms clock, 104 bytes, 4 allocs
init google.golang.org/protobuf/proto @1217 ms, 1.0 ms clock, 352 bytes, 7 allocs
init google.golang.org/protobuf/internal/descfmt @1218 ms, 0 ms clock, 1152 bytes, 10 allocs
init google.golang.org/protobuf/internal/filedesc @1218 ms, 0 ms clock, 696 bytes, 13 allocs
init google.golang.org/protobuf/internal/encoding/tag @1218 ms, 0 ms clock, 0 bytes, 0 allocs
init google.golang.org/protobuf/internal/impl @1218 ms, 0 ms clock, 280 bytes, 7 allocs
init google.golang.org/protobuf/internal/filetype @1218 ms, 0 ms clock, 1328 bytes, 5 allocs
init google.golang.org/protobuf/types/descriptorpb @1218 ms, 0 ms clock, 43200 bytes, 57 allocs
init github.com/golang/protobuf/proto @1218 ms, 0 ms clock, 96 bytes, 6 allocs
init google.golang.org/protobuf/types/known/timestamppb @1218 ms, 0 ms clock, 1120 bytes, 6 allocs
init github.com/golang/protobuf/ptypes/timestamp @1218 ms, 0 ms clock, 544 bytes, 4 allocs
init github.com/prometheus/client_model/go @1218 ms, 0.99 ms clock, 118752 bytes, 207 allocs
init github.com/prometheus/common/model @1219 ms, 0 ms clock, 25176 bytes, 232 allocs
init expvar @1219 ms, 0 ms clock, 448 bytes, 13 allocs
init github.com/matttproud/golang_protobuf_extensions/pbutil @1219 ms, 0 ms clock, 16 bytes, 1 allocs
init github.com/prometheus/common/expfmt @1219 ms, 0 ms clock, 288 bytes, 4 allocs
init github.com/prometheus/client_golang/prometheus @1219 ms, 26 ms clock, 37184 bytes, 485 allocs
init github.com/leoluk/perflib_exporter/perflib @1245 ms, 8504 ms clock, 37288800 bytes, 50160 allocs
init github.com/Microsoft/hcsshim/internal/interop @9750 ms, 0 ms clock, 96 bytes, 2 allocs
init go.opencensus.io/internal @9750 ms, 0 ms clock, 432 bytes, 7 allocs
init go.opencensus.io/trace/tracestate @9750 ms, 11 ms clock, 520048 bytes, 2408 allocs
init go.opencensus.io/trace @9762 ms, 0 ms clock, 6128 bytes, 22 allocs
init github.com/Microsoft/hcsshim/internal/timeout @9762 ms, 0 ms clock, 3152 bytes, 24 allocs
init github.com/Microsoft/hcsshim/internal/vmcompute @9762 ms, 0 ms clock, 1296 bytes, 27 allocs
init github.com/gogo/protobuf/proto @9762 ms, 0 ms clock, 2576 bytes, 29 allocs
init github.com/gogo/protobuf/protoc-gen-gogo/descriptor @9762 ms, 0 ms clock, 12288 bytes, 34 allocs
init github.com/gogo/protobuf/gogoproto @9762 ms, 0 ms clock, 3808 bytes, 20 allocs
init github.com/containerd/cgroups/stats/v1 @9762 ms, 0 ms clock, 10992 bytes, 16 allocs
init github.com/Microsoft/hcsshim/internal/hcs/schema2 @9762 ms, 0 ms clock, 224 bytes, 2 allocs
init github.com/Microsoft/hcsshim/internal/queue @9762 ms, 0 ms clock, 16 bytes, 1 allocs
init github.com/Microsoft/hcsshim/internal/winapi @9762 ms, 0 ms clock, 1584 bytes, 33 allocs
init github.com/Microsoft/hcsshim/internal/jobobject @9762 ms, 0 ms clock, 32 bytes, 2 allocs
init github.com/Microsoft/go-winio @9762 ms, 0 ms clock, 2232 bytes, 54 allocs
init github.com/Microsoft/go-winio/vhd @9762 ms, 0 ms clock, 288 bytes, 6 allocs
init github.com/Microsoft/go-winio/pkg/security @9762 ms, 0 ms clock, 192 bytes, 4 allocs
init github.com/Microsoft/hcsshim/computestorage @9762 ms, 0 ms clock, 528 bytes, 11 allocs
init github.com/Microsoft/hcsshim/internal/hcs @9762 ms, 0 ms clock, 480 bytes, 13 allocs
init github.com/Microsoft/hcsshim/internal/hns @9762 ms, 0 ms clock, 96 bytes, 2 allocs
init github.com/Microsoft/hcsshim/internal/wclayer @9762 ms, 0 ms clock, 1376 bytes, 27 allocs
init github.com/Microsoft/hcsshim @9762 ms, 0 ms clock, 592 bytes, 6 allocs
init github.com/prometheus-community/windows_exporter/headers/sysinfoapi @9762 ms, 0 ms clock, 192 bytes, 4 allocs
init github.com/prometheus-community/windows_exporter/headers/netapi32 @9762 ms, 0 ms clock, 896 bytes, 5 allocs
init github.com/prometheus-community/windows_exporter/headers/psapi @9762 ms, 0 ms clock, 96 bytes, 2 allocs
init github.com/leoluk/perflib_exporter/collector @9762 ms, 0 ms clock, 1920 bytes, 14 allocs
init github.com/dimchansky/utfbom @9762 ms, 0 ms clock, 16 bytes, 1 allocs
init github.com/prometheus-community/windows_exporter/collector @9762 ms, 35909 ms clock, 1649008 bytes, 24245 allocs
init gopkg.in/yaml%2ev3 @45672 ms, 0 ms clock, 25128 bytes, 276 allocs
init database/sql/driver @45672 ms, 0 ms clock, 48 bytes, 3 allocs
init database/sql @45672 ms, 0 ms clock, 160 bytes, 8 allocs
init github.com/prometheus/client_golang/prometheus/promhttp @45672 ms, 0 ms clock, 304 bytes, 2 allocs
init github.com/prometheus/common/version @45672 ms, 0 ms clock, 0 bytes, 0 allocs
init golang.org/x/crypto/bcrypt @45672 ms, 0 ms clock, 384 bytes, 3 allocs
init html/template @45672 ms, 0 ms clock, 10296 bytes, 29 allocs
init golang.org/x/net/trace @45672 ms, 0 ms clock, 16864 bytes, 8 allocs
init github.com/mwitkow/go-conntrack @45672 ms, 80 ms clock, 4448 bytes, 121 allocs
init golang.org/x/text/transform @45752 ms, 0 ms clock, 80 bytes, 5 allocs
init golang.org/x/text/unicode/bidi @45752 ms, 0 ms clock, 272 bytes, 2 allocs
init golang.org/x/text/secure/bidirule @45752 ms, 0 ms clock, 16 bytes, 1 allocs
init golang.org/x/text/unicode/norm @45752 ms, 0 ms clock, 0 bytes, 0 allocs
init golang.org/x/net/idna @45752 ms, 0 ms clock, 0 bytes, 0 allocs
init golang.org/x/net/http/httpguts @45752 ms, 0 ms clock, 688 bytes, 2 allocs
init golang.org/x/net/http2/hpack @45752 ms, 0 ms clock, 21592 bytes, 30 allocs
init golang.org/x/net/http2 @45752 ms, 0 ms clock, 4400 bytes, 65 allocs
init golang.org/x/oauth2 @45752 ms, 0 ms clock, 96 bytes, 3 allocs
init gopkg.in/yaml%2ev2 @45752 ms, 0 ms clock, 26320 bytes, 263 allocs
init github.com/prometheus/common/config @45752 ms, 0 ms clock, 208 bytes, 2 allocs
init github.com/prometheus/exporter-toolkit/web @45752 ms, 0 ms clock, 1168 bytes, 11 allocs
init main @45752 ms, 35 ms clock, 28896 bytes, 277 allocs

and the equivelent when less constrained (VM was restricted during both but one was with additional load whilst the other was when the machine was 'quiet'):

init internal/bytealg @0 ms, 0 ms clock, 0 bytes, 0 allocs
init runtime @0 ms, 0 ms clock, 0 bytes, 0 allocs
init errors @58 ms, 0 ms clock, 0 bytes, 0 allocs
init sync @58 ms, 0 ms clock, 16 bytes, 1 allocs
init io @58 ms, 0 ms clock, 144 bytes, 9 allocs
init math @58 ms, 0 ms clock, 0 bytes, 0 allocs
init strconv @58 ms, 0 ms clock, 32 bytes, 2 allocs
init unicode @58 ms, 0 ms clock, 24360 bytes, 29 allocs
init reflect @58 ms, 0 ms clock, 0 bytes, 0 allocs
init encoding/binary @58 ms, 0 ms clock, 16 bytes, 1 allocs
init encoding/base64 @58 ms, 0 ms clock, 1408 bytes, 4 allocs
init internal/oserror @58 ms, 0 ms clock, 80 bytes, 5 allocs
init internal/syscall/windows/sysdll @58 ms, 0 ms clock, 48 bytes, 1 allocs
init syscall @58 ms, 0.50 ms clock, 8912 bytes, 174 allocs
init internal/syscall/windows/registry @59 ms, 0 ms clock, 416 bytes, 10 allocs
init time @59 ms, 0 ms clock, 14792 bytes, 11 allocs
init path @59 ms, 0 ms clock, 16 bytes, 1 allocs
init io/fs @59 ms, 0 ms clock, 16 bytes, 1 allocs
init internal/syscall/windows @59 ms, 0 ms clock, 1776 bytes, 37 allocs
init internal/poll @59 ms, 17 ms clock, 344 bytes, 12 allocs
init os @76 ms, 1.1 ms clock, 3120 bytes, 35 allocs
init fmt @78 ms, 0 ms clock, 32 bytes, 2 allocs
init bytes @78 ms, 0 ms clock, 48 bytes, 3 allocs
init encoding/json @78 ms, 0 ms clock, 32 bytes, 2 allocs
init context @78 ms, 0 ms clock, 128 bytes, 4 allocs
init crypto @78 ms, 0 ms clock, 160 bytes, 1 allocs
init crypto/cipher @78 ms, 0 ms clock, 16 bytes, 1 allocs
init crypto/aes @78 ms, 0 ms clock, 16 bytes, 1 allocs
init math/rand @78 ms, 0 ms clock, 5440 bytes, 3 allocs
init math/big @78 ms, 0 ms clock, 32 bytes, 2 allocs
init crypto/elliptic/internal/fiat @78 ms, 0.54 ms clock, 320 bytes, 6 allocs
init crypto/elliptic/internal/nistec @78 ms, 0 ms clock, 712 bytes, 15 allocs
init crypto/rand @78 ms, 0 ms clock, 48 bytes, 2 allocs
init crypto/sha512 @78 ms, 0 ms clock, 0 bytes, 0 allocs
init encoding/asn1 @78 ms, 0 ms clock, 224 bytes, 7 allocs
init vendor/golang.org/x/crypto/cryptobyte @78 ms, 0 ms clock, 48 bytes, 2 allocs
init crypto/ecdsa @78 ms, 0 ms clock, 48 bytes, 3 allocs
init crypto/ed25519/internal/edwards25519 @78 ms, 0 ms clock, 496 bytes, 5 allocs
init crypto/rsa @78 ms, 0 ms clock, 664 bytes, 18 allocs
init crypto/sha1 @78 ms, 0 ms clock, 0 bytes, 0 allocs
init crypto/sha256 @78 ms, 0 ms clock, 0 bytes, 0 allocs
init vendor/golang.org/x/sys/cpu @78 ms, 0 ms clock, 1624 bytes, 7 allocs
init vendor/golang.org/x/crypto/chacha20poly1305 @78 ms, 0 ms clock, 16 bytes, 1 allocs
init crypto/dsa @78 ms, 0 ms clock, 16 bytes, 1 allocs
init encoding/hex @78 ms, 0 ms clock, 16 bytes, 1 allocs
init crypto/x509/pkix @78 ms, 0 ms clock, 624 bytes, 2 allocs
init vendor/golang.org/x/net/dns/dnsmessage @78 ms, 0 ms clock, 1616 bytes, 27 allocs
init internal/intern @78 ms, 0 ms clock, 336 bytes, 5 allocs
init net/netip @78 ms, 0 ms clock, 48 bytes, 2 allocs
init net @78 ms, 0 ms clock, 1568 bytes, 27 allocs
init crypto/md5 @78 ms, 0 ms clock, 0 bytes, 0 allocs
init crypto/x509 @78 ms, 0 ms clock, 5504 bytes, 251 allocs
init vendor/golang.org/x/crypto/curve25519 @78 ms, 0 ms clock, 0 bytes, 0 allocs
init crypto/tls @78 ms, 0 ms clock, 1888 bytes, 15 allocs
init log @78 ms, 0 ms clock, 80 bytes, 1 allocs
init bufio @78 ms, 0 ms clock, 176 bytes, 11 allocs
init mime @78 ms, 0 ms clock, 1232 bytes, 4 allocs
init path/filepath @78 ms, 0 ms clock, 16 bytes, 1 allocs
init mime/multipart @78 ms, 0 ms clock, 192 bytes, 4 allocs
init compress/flate @78 ms, 0 ms clock, 4240 bytes, 7 allocs
init hash/crc32 @78 ms, 0 ms clock, 1024 bytes, 1 allocs
init compress/gzip @78 ms, 0 ms clock, 32 bytes, 2 allocs
init io/ioutil @78 ms, 0 ms clock, 0 bytes, 0 allocs
init vendor/golang.org/x/text/transform @78 ms, 0 ms clock, 80 bytes, 5 allocs
init vendor/golang.org/x/text/unicode/bidi @78 ms, 0 ms clock, 272 bytes, 2 allocs
init vendor/golang.org/x/text/secure/bidirule @78 ms, 0 ms clock, 16 bytes, 1 allocs
init vendor/golang.org/x/text/unicode/norm @78 ms, 0 ms clock, 0 bytes, 0 allocs
init vendor/golang.org/x/net/idna @78 ms, 0 ms clock, 0 bytes, 0 allocs
init vendor/golang.org/x/net/http/httpguts @78 ms, 0 ms clock, 688 bytes, 2 allocs
init vendor/golang.org/x/net/http2/hpack @78 ms, 0 ms clock, 21880 bytes, 30 allocs
init net/http/internal @78 ms, 0 ms clock, 16 bytes, 1 allocs
init vendor/golang.org/x/net/http/httpproxy @78 ms, 0 ms clock, 336 bytes, 2 allocs
init net/http @78 ms, 0 ms clock, 10856 bytes, 121 allocs
init golang.org/x/sys/windows @78 ms, 0 ms clock, 21616 bytes, 453 allocs
init html @78 ms, 0 ms clock, 224 bytes, 2 allocs
init regexp/syntax @78 ms, 0 ms clock, 6816 bytes, 7 allocs
init regexp @78 ms, 0 ms clock, 0 bytes, 0 allocs
init internal/profile @78 ms, 15 ms clock, 98424 bytes, 758 allocs
init runtime/pprof @94 ms, 0 ms clock, 32 bytes, 2 allocs
init net/http/pprof @94 ms, 0 ms clock, 1328 bytes, 7 allocs
init github.com/go-ole/go-ole @94 ms, 0 ms clock, 4304 bytes, 103 allocs
init github.com/StackExchange/wmi @94 ms, 0 ms clock, 136 bytes, 4 allocs
init golang.org/x/sys/windows/registry @94 ms, 0 ms clock, 496 bytes, 11 allocs
init github.com/sirupsen/logrus @94 ms, 0 ms clock, 312 bytes, 5 allocs
init github.com/go-logfmt/logfmt @94 ms, 0 ms clock, 64 bytes, 4 allocs
init github.com/go-kit/log @94 ms, 0 ms clock, 13688 bytes, 109 allocs
init github.com/go-kit/log/level @94 ms, 0 ms clock, 16 bytes, 1 allocs
init github.com/alecthomas/units @94 ms, 0 ms clock, 832 bytes, 26 allocs
init internal/lazyregexp @94 ms, 0 ms clock, 0 bytes, 0 allocs
init text/template/parse @94 ms, 0 ms clock, 464 bytes, 2 allocs
init text/template @94 ms, 0 ms clock, 80 bytes, 5 allocs
init go/token @94 ms, 0 ms clock, 1568 bytes, 4 allocs
init go/doc @94 ms, 0 ms clock, 2208 bytes, 18 allocs
init github.com/alecthomas/template/parse @94 ms, 0 ms clock, 464 bytes, 2 allocs
init github.com/alecthomas/template @94 ms, 0 ms clock, 4624 bytes, 11 allocs
init gopkg.in/alecthomas/kingpin%2ev2 @94 ms, 0 ms clock, 7240 bytes, 96 allocs
init github.com/prometheus-community/windows_exporter/log @94 ms, 0 ms clock, 416 bytes, 5 allocs
init google.golang.org/protobuf/internal/detrand @94 ms, 0 ms clock, 4192 bytes, 28 allocs
init google.golang.org/protobuf/internal/errors @94 ms, 0 ms clock, 16 bytes, 1 allocs
init google.golang.org/protobuf/encoding/protowire @94 ms, 0 ms clock, 216 bytes, 10 allocs
init google.golang.org/protobuf/reflect/protoreflect @94 ms, 0 ms clock, 0 bytes, 0 allocs
init google.golang.org/protobuf/internal/encoding/text @94 ms, 0 ms clock, 3336 bytes, 34 allocs
init google.golang.org/protobuf/reflect/protoregistry @94 ms, 0 ms clock, 104 bytes, 4 allocs
init google.golang.org/protobuf/proto @94 ms, 0 ms clock, 352 bytes, 7 allocs
init google.golang.org/protobuf/internal/descfmt @94 ms, 0 ms clock, 1152 bytes, 10 allocs
init google.golang.org/protobuf/internal/filedesc @94 ms, 0 ms clock, 696 bytes, 13 allocs
init google.golang.org/protobuf/internal/encoding/tag @94 ms, 0 ms clock, 0 bytes, 0 allocs
init google.golang.org/protobuf/internal/impl @94 ms, 0 ms clock, 280 bytes, 7 allocs
init google.golang.org/protobuf/internal/filetype @94 ms, 0 ms clock, 1168 bytes, 4 allocs
init google.golang.org/protobuf/types/descriptorpb @94 ms, 0 ms clock, 44352 bytes, 61 allocs
init github.com/golang/protobuf/proto @94 ms, 0 ms clock, 96 bytes, 6 allocs
init google.golang.org/protobuf/types/known/timestamppb @94 ms, 0 ms clock, 1120 bytes, 6 allocs
init github.com/golang/protobuf/ptypes/timestamp @94 ms, 0 ms clock, 544 bytes, 4 allocs
init github.com/prometheus/client_model/go @94 ms, 0 ms clock, 119040 bytes, 208 allocs
init github.com/prometheus/common/model @94 ms, 0 ms clock, 25176 bytes, 232 allocs
init expvar @94 ms, 0 ms clock, 448 bytes, 13 allocs
init github.com/matttproud/golang_protobuf_extensions/pbutil @94 ms, 0 ms clock, 16 bytes, 1 allocs
init github.com/prometheus/common/expfmt @94 ms, 0 ms clock, 288 bytes, 4 allocs
init github.com/prometheus/client_golang/prometheus @94 ms, 10 ms clock, 37712 bytes, 494 allocs
init github.com/leoluk/perflib_exporter/perflib @104 ms, 2195 ms clock, 37284576 bytes, 50136 allocs
init github.com/Microsoft/hcsshim/internal/interop @2300 ms, 0 ms clock, 96 bytes, 2 allocs
init go.opencensus.io/internal @2300 ms, 0 ms clock, 432 bytes, 7 allocs
init go.opencensus.io/trace/tracestate @2300 ms, 0 ms clock, 520048 bytes, 2408 allocs
init go.opencensus.io/trace @2300 ms, 0 ms clock, 6128 bytes, 22 allocs
init github.com/Microsoft/hcsshim/internal/timeout @2300 ms, 0 ms clock, 3152 bytes, 24 allocs
init github.com/Microsoft/hcsshim/internal/vmcompute @2300 ms, 0 ms clock, 1296 bytes, 27 allocs
init github.com/gogo/protobuf/proto @2300 ms, 0 ms clock, 2576 bytes, 29 allocs
init github.com/gogo/protobuf/protoc-gen-gogo/descriptor @2300 ms, 0 ms clock, 12576 bytes, 35 allocs
init github.com/gogo/protobuf/gogoproto @2300 ms, 0 ms clock, 3584 bytes, 18 allocs
init github.com/containerd/cgroups/stats/v1 @2300 ms, 0 ms clock, 10992 bytes, 16 allocs
init github.com/Microsoft/hcsshim/internal/hcs/schema2 @2300 ms, 0 ms clock, 224 bytes, 2 allocs
init github.com/Microsoft/hcsshim/internal/queue @2300 ms, 0 ms clock, 16 bytes, 1 allocs
init github.com/Microsoft/hcsshim/internal/winapi @2300 ms, 0 ms clock, 1584 bytes, 33 allocs
init github.com/Microsoft/hcsshim/internal/jobobject @2300 ms, 0 ms clock, 32 bytes, 2 allocs
init github.com/Microsoft/go-winio @2300 ms, 0 ms clock, 2232 bytes, 54 allocs
init github.com/Microsoft/go-winio/vhd @2300 ms, 0 ms clock, 288 bytes, 6 allocs
init github.com/Microsoft/go-winio/pkg/security @2300 ms, 0 ms clock, 192 bytes, 4 allocs
init github.com/Microsoft/hcsshim/computestorage @2300 ms, 0 ms clock, 528 bytes, 11 allocs
init github.com/Microsoft/hcsshim/internal/hcs @2300 ms, 0 ms clock, 480 bytes, 13 allocs
init github.com/Microsoft/hcsshim/internal/hns @2300 ms, 0 ms clock, 96 bytes, 2 allocs
init github.com/Microsoft/hcsshim/internal/wclayer @2300 ms, 0 ms clock, 1376 bytes, 27 allocs
init github.com/Microsoft/hcsshim @2300 ms, 0 ms clock, 592 bytes, 6 allocs
init github.com/prometheus-community/windows_exporter/headers/sysinfoapi @2300 ms, 0 ms clock, 192 bytes, 4 allocs
init github.com/prometheus-community/windows_exporter/headers/netapi32 @2300 ms, 0 ms clock, 896 bytes, 5 allocs
init github.com/prometheus-community/windows_exporter/headers/psapi @2300 ms, 0 ms clock, 96 bytes, 2 allocs
init github.com/leoluk/perflib_exporter/collector @2300 ms, 0 ms clock, 2088 bytes, 18 allocs
init github.com/dimchansky/utfbom @2316 ms, 0 ms clock, 16 bytes, 1 allocs
init github.com/prometheus-community/windows_exporter/collector @2316 ms, 2797 ms clock, 1645856 bytes, 24226 allocs
init gopkg.in/yaml%2ev3 @5114 ms, 0 ms clock, 25128 bytes, 276 allocs
init database/sql/driver @5114 ms, 0 ms clock, 48 bytes, 3 allocs
init database/sql @5114 ms, 0 ms clock, 160 bytes, 8 allocs
init github.com/prometheus/client_golang/prometheus/promhttp @5114 ms, 0 ms clock, 304 bytes, 2 allocs
init github.com/prometheus/common/version @5114 ms, 0 ms clock, 0 bytes, 0 allocs
init golang.org/x/crypto/bcrypt @5114 ms, 0 ms clock, 384 bytes, 3 allocs
init html/template @5114 ms, 0 ms clock, 10584 bytes, 30 allocs
init golang.org/x/net/trace @5114 ms, 0 ms clock, 16864 bytes, 8 allocs
init github.com/mwitkow/go-conntrack @5114 ms, 17 ms clock, 4448 bytes, 121 allocs
init golang.org/x/text/transform @5132 ms, 0 ms clock, 80 bytes, 5 allocs
init golang.org/x/text/unicode/bidi @5132 ms, 0 ms clock, 272 bytes, 2 allocs
init golang.org/x/text/secure/bidirule @5132 ms, 0 ms clock, 16 bytes, 1 allocs
init golang.org/x/text/unicode/norm @5132 ms, 0 ms clock, 0 bytes, 0 allocs
init golang.org/x/net/idna @5132 ms, 0 ms clock, 0 bytes, 0 allocs
init golang.org/x/net/http/httpguts @5132 ms, 0 ms clock, 688 bytes, 2 allocs
init golang.org/x/net/http2/hpack @5132 ms, 0 ms clock, 22088 bytes, 31 allocs
init golang.org/x/net/http2 @5132 ms, 0 ms clock, 4400 bytes, 65 allocs
init golang.org/x/oauth2 @5132 ms, 0 ms clock, 96 bytes, 3 allocs
init gopkg.in/yaml%2ev2 @5132 ms, 0 ms clock, 26736 bytes, 264 allocs
init github.com/prometheus/common/config @5132 ms, 0 ms clock, 208 bytes, 2 allocs
init github.com/prometheus/exporter-toolkit/web @5132 ms, 0 ms clock, 1168 bytes, 11 allocs
init main @5132 ms, 1.6 ms clock, 28976 bytes, 277 allocs

For completeness i also ran a trace with a full vcpu available which was again much faster:

init internal/bytealg @0 ms, 0 ms clock, 0 bytes, 0 allocs
init runtime @0 ms, 0 ms clock, 0 bytes, 0 allocs
init errors @12 ms, 0 ms clock, 0 bytes, 0 allocs
init sync @12 ms, 0 ms clock, 16 bytes, 1 allocs
init io @12 ms, 0 ms clock, 144 bytes, 9 allocs
init math @12 ms, 0 ms clock, 0 bytes, 0 allocs
init strconv @12 ms, 0 ms clock, 32 bytes, 2 allocs
init unicode @12 ms, 0 ms clock, 24360 bytes, 29 allocs
init reflect @12 ms, 0 ms clock, 0 bytes, 0 allocs
init encoding/binary @12 ms, 0 ms clock, 16 bytes, 1 allocs
init encoding/base64 @12 ms, 0 ms clock, 1408 bytes, 4 allocs
init internal/oserror @12 ms, 0 ms clock, 80 bytes, 5 allocs
init internal/syscall/windows/sysdll @12 ms, 0 ms clock, 48 bytes, 1 allocs
init syscall @14 ms, 0 ms clock, 8912 bytes, 174 allocs
init internal/syscall/windows/registry @14 ms, 0 ms clock, 416 bytes, 10 allocs
init time @14 ms, 0 ms clock, 14792 bytes, 11 allocs
init path @14 ms, 0 ms clock, 16 bytes, 1 allocs
init io/fs @14 ms, 0 ms clock, 16 bytes, 1 allocs
init internal/syscall/windows @14 ms, 0 ms clock, 1616 bytes, 36 allocs
init internal/poll @14 ms, 0 ms clock, 344 bytes, 12 allocs
init os @14 ms, 5.4 ms clock, 3120 bytes, 35 allocs
init fmt @20 ms, 0 ms clock, 32 bytes, 2 allocs
init bytes @20 ms, 0 ms clock, 48 bytes, 3 allocs
init encoding/json @20 ms, 0 ms clock, 32 bytes, 2 allocs
init context @20 ms, 0 ms clock, 128 bytes, 4 allocs
init crypto @20 ms, 0 ms clock, 160 bytes, 1 allocs
init crypto/cipher @20 ms, 0 ms clock, 16 bytes, 1 allocs
init crypto/aes @20 ms, 0 ms clock, 16 bytes, 1 allocs
init math/rand @20 ms, 0 ms clock, 5440 bytes, 3 allocs
init math/big @20 ms, 0 ms clock, 32 bytes, 2 allocs
init crypto/elliptic/internal/fiat @20 ms, 0 ms clock, 320 bytes, 6 allocs
init crypto/elliptic/internal/nistec @20 ms, 0 ms clock, 712 bytes, 15 allocs
init crypto/rand @20 ms, 0 ms clock, 48 bytes, 2 allocs
init crypto/sha512 @20 ms, 0 ms clock, 0 bytes, 0 allocs
init encoding/asn1 @20 ms, 0 ms clock, 224 bytes, 7 allocs
init vendor/golang.org/x/crypto/cryptobyte @20 ms, 0 ms clock, 48 bytes, 2 allocs
init crypto/ecdsa @20 ms, 0 ms clock, 48 bytes, 3 allocs
init crypto/ed25519/internal/edwards25519 @20 ms, 0 ms clock, 496 bytes, 5 allocs
init crypto/rsa @20 ms, 0 ms clock, 664 bytes, 18 allocs
init crypto/sha1 @20 ms, 0 ms clock, 0 bytes, 0 allocs
init crypto/sha256 @20 ms, 0 ms clock, 0 bytes, 0 allocs
init vendor/golang.org/x/sys/cpu @20 ms, 0 ms clock, 1624 bytes, 7 allocs
init vendor/golang.org/x/crypto/chacha20poly1305 @20 ms, 0 ms clock, 16 bytes, 1 allocs
init crypto/dsa @20 ms, 0 ms clock, 16 bytes, 1 allocs
init encoding/hex @20 ms, 0 ms clock, 16 bytes, 1 allocs
init crypto/x509/pkix @20 ms, 0 ms clock, 624 bytes, 2 allocs
init vendor/golang.org/x/net/dns/dnsmessage @20 ms, 0 ms clock, 1616 bytes, 27 allocs
init internal/intern @20 ms, 0 ms clock, 336 bytes, 5 allocs
init net/netip @20 ms, 0 ms clock, 48 bytes, 2 allocs
init net @20 ms, 0 ms clock, 1776 bytes, 28 allocs
init crypto/md5 @20 ms, 0 ms clock, 0 bytes, 0 allocs
init crypto/x509 @20 ms, 0 ms clock, 5504 bytes, 251 allocs
init vendor/golang.org/x/crypto/curve25519 @20 ms, 0 ms clock, 0 bytes, 0 allocs
init crypto/tls @20 ms, 0 ms clock, 1888 bytes, 15 allocs
init log @20 ms, 0 ms clock, 80 bytes, 1 allocs
init bufio @20 ms, 0 ms clock, 176 bytes, 11 allocs
init mime @20 ms, 0 ms clock, 1232 bytes, 4 allocs
init path/filepath @20 ms, 0 ms clock, 16 bytes, 1 allocs
init mime/multipart @20 ms, 0 ms clock, 192 bytes, 4 allocs
init compress/flate @20 ms, 0 ms clock, 4240 bytes, 7 allocs
init hash/crc32 @20 ms, 0 ms clock, 1024 bytes, 1 allocs
init compress/gzip @20 ms, 0 ms clock, 32 bytes, 2 allocs
init io/ioutil @20 ms, 0 ms clock, 0 bytes, 0 allocs
init vendor/golang.org/x/text/transform @20 ms, 0 ms clock, 80 bytes, 5 allocs
init vendor/golang.org/x/text/unicode/bidi @20 ms, 0 ms clock, 272 bytes, 2 allocs
init vendor/golang.org/x/text/secure/bidirule @20 ms, 0 ms clock, 16 bytes, 1 allocs
init vendor/golang.org/x/text/unicode/norm @20 ms, 0 ms clock, 0 bytes, 0 allocs
init vendor/golang.org/x/net/idna @20 ms, 0 ms clock, 0 bytes, 0 allocs
init vendor/golang.org/x/net/http/httpguts @20 ms, 0 ms clock, 848 bytes, 3 allocs
init vendor/golang.org/x/net/http2/hpack @20 ms, 0 ms clock, 21528 bytes, 29 allocs
init net/http/internal @20 ms, 0 ms clock, 16 bytes, 1 allocs
init vendor/golang.org/x/net/http/httpproxy @20 ms, 0 ms clock, 336 bytes, 2 allocs
init net/http @20 ms, 0 ms clock, 10856 bytes, 121 allocs
init golang.org/x/sys/windows @20 ms, 0 ms clock, 21616 bytes, 453 allocs
init html @20 ms, 0 ms clock, 224 bytes, 2 allocs
init regexp/syntax @20 ms, 0 ms clock, 7232 bytes, 8 allocs
init regexp @20 ms, 0 ms clock, 0 bytes, 0 allocs
init internal/profile @20 ms, 0 ms clock, 98424 bytes, 758 allocs
init runtime/pprof @20 ms, 0 ms clock, 32 bytes, 2 allocs
init net/http/pprof @20 ms, 0 ms clock, 1328 bytes, 7 allocs
init github.com/go-ole/go-ole @20 ms, 0 ms clock, 4304 bytes, 103 allocs
init github.com/StackExchange/wmi @20 ms, 0 ms clock, 136 bytes, 4 allocs
init golang.org/x/sys/windows/registry @20 ms, 0 ms clock, 496 bytes, 11 allocs
init github.com/sirupsen/logrus @20 ms, 0 ms clock, 312 bytes, 5 allocs
init github.com/go-logfmt/logfmt @20 ms, 0 ms clock, 64 bytes, 4 allocs
init github.com/go-kit/log @20 ms, 0 ms clock, 13688 bytes, 109 allocs
init github.com/go-kit/log/level @20 ms, 0 ms clock, 16 bytes, 1 allocs
init github.com/alecthomas/units @20 ms, 0 ms clock, 832 bytes, 26 allocs
init internal/lazyregexp @20 ms, 0 ms clock, 0 bytes, 0 allocs
init text/template/parse @20 ms, 0 ms clock, 464 bytes, 2 allocs
init text/template @20 ms, 0 ms clock, 80 bytes, 5 allocs
init go/token @20 ms, 0 ms clock, 1568 bytes, 4 allocs
init go/doc @20 ms, 0 ms clock, 2368 bytes, 19 allocs
init github.com/alecthomas/template/parse @20 ms, 0 ms clock, 464 bytes, 2 allocs
init github.com/alecthomas/template @20 ms, 0 ms clock, 4624 bytes, 11 allocs
init gopkg.in/alecthomas/kingpin%2ev2 @20 ms, 0 ms clock, 7240 bytes, 96 allocs
init github.com/prometheus-community/windows_exporter/log @20 ms, 0 ms clock, 416 bytes, 5 allocs
init google.golang.org/protobuf/internal/detrand @20 ms, 0 ms clock, 4192 bytes, 28 allocs
init google.golang.org/protobuf/internal/errors @20 ms, 0 ms clock, 16 bytes, 1 allocs
init google.golang.org/protobuf/encoding/protowire @20 ms, 0 ms clock, 216 bytes, 10 allocs
init google.golang.org/protobuf/reflect/protoreflect @20 ms, 0 ms clock, 0 bytes, 0 allocs
init google.golang.org/protobuf/internal/encoding/text @20 ms, 0 ms clock, 3336 bytes, 34 allocs
init google.golang.org/protobuf/reflect/protoregistry @20 ms, 0 ms clock, 104 bytes, 4 allocs
init google.golang.org/protobuf/proto @20 ms, 0 ms clock, 352 bytes, 7 allocs
init google.golang.org/protobuf/internal/descfmt @20 ms, 0 ms clock, 1152 bytes, 10 allocs
init google.golang.org/protobuf/internal/filedesc @20 ms, 0 ms clock, 696 bytes, 13 allocs
init google.golang.org/protobuf/internal/encoding/tag @20 ms, 0 ms clock, 0 bytes, 0 allocs
init google.golang.org/protobuf/internal/impl @20 ms, 0 ms clock, 280 bytes, 7 allocs
init google.golang.org/protobuf/internal/filetype @20 ms, 0 ms clock, 1168 bytes, 4 allocs
init google.golang.org/protobuf/types/descriptorpb @20 ms, 0 ms clock, 43952 bytes, 60 allocs
init github.com/golang/protobuf/proto @20 ms, 0 ms clock, 96 bytes, 6 allocs
init google.golang.org/protobuf/types/known/timestamppb @20 ms, 0 ms clock, 1120 bytes, 6 allocs
init github.com/golang/protobuf/ptypes/timestamp @20 ms, 0 ms clock, 544 bytes, 4 allocs
init github.com/prometheus/client_model/go @20 ms, 0 ms clock, 119328 bytes, 209 allocs
init github.com/prometheus/common/model @20 ms, 0 ms clock, 25176 bytes, 232 allocs
init expvar @20 ms, 0 ms clock, 448 bytes, 13 allocs
init github.com/matttproud/golang_protobuf_extensions/pbutil @20 ms, 0 ms clock, 16 bytes, 1 allocs
init github.com/prometheus/common/expfmt @20 ms, 0 ms clock, 288 bytes, 4 allocs
init github.com/prometheus/client_golang/prometheus @20 ms, 5.5 ms clock, 37600 bytes, 491 allocs
init github.com/leoluk/perflib_exporter/perflib @26 ms, 401 ms clock, 37286688 bytes, 50148 allocs
init github.com/Microsoft/hcsshim/internal/interop @427 ms, 0 ms clock, 96 bytes, 2 allocs
init go.opencensus.io/internal @427 ms, 0 ms clock, 432 bytes, 7 allocs
init go.opencensus.io/trace/tracestate @427 ms, 0 ms clock, 520048 bytes, 2408 allocs
init go.opencensus.io/trace @427 ms, 0 ms clock, 6128 bytes, 22 allocs
init github.com/Microsoft/hcsshim/internal/timeout @427 ms, 0 ms clock, 3152 bytes, 24 allocs
init github.com/Microsoft/hcsshim/internal/vmcompute @427 ms, 0 ms clock, 1296 bytes, 27 allocs
init github.com/gogo/protobuf/proto @427 ms, 0 ms clock, 2576 bytes, 29 allocs
init github.com/gogo/protobuf/protoc-gen-gogo/descriptor @427 ms, 0 ms clock, 12000 bytes, 33 allocs
init github.com/gogo/protobuf/gogoproto @427 ms, 0 ms clock, 3696 bytes, 19 allocs
init github.com/containerd/cgroups/stats/v1 @427 ms, 0 ms clock, 10416 bytes, 14 allocs
init github.com/Microsoft/hcsshim/internal/hcs/schema2 @427 ms, 0 ms clock, 224 bytes, 2 allocs
init github.com/Microsoft/hcsshim/internal/queue @427 ms, 0 ms clock, 16 bytes, 1 allocs
init github.com/Microsoft/hcsshim/internal/winapi @427 ms, 0 ms clock, 1584 bytes, 33 allocs
init github.com/Microsoft/hcsshim/internal/jobobject @427 ms, 0 ms clock, 32 bytes, 2 allocs
init github.com/Microsoft/go-winio @427 ms, 0 ms clock, 2232 bytes, 54 allocs
init github.com/Microsoft/go-winio/vhd @427 ms, 0 ms clock, 288 bytes, 6 allocs
init github.com/Microsoft/go-winio/pkg/security @427 ms, 0 ms clock, 192 bytes, 4 allocs
init github.com/Microsoft/hcsshim/computestorage @427 ms, 0 ms clock, 528 bytes, 11 allocs
init github.com/Microsoft/hcsshim/internal/hcs @427 ms, 0 ms clock, 480 bytes, 13 allocs
init github.com/Microsoft/hcsshim/internal/hns @427 ms, 0 ms clock, 96 bytes, 2 allocs
init github.com/Microsoft/hcsshim/internal/wclayer @427 ms, 0 ms clock, 1376 bytes, 27 allocs
init github.com/Microsoft/hcsshim @427 ms, 0 ms clock, 592 bytes, 6 allocs
init github.com/prometheus-community/windows_exporter/headers/sysinfoapi @427 ms, 0 ms clock, 192 bytes, 4 allocs
init github.com/prometheus-community/windows_exporter/headers/netapi32 @427 ms, 0 ms clock, 896 bytes, 5 allocs
init github.com/prometheus-community/windows_exporter/headers/psapi @427 ms, 0 ms clock, 96 bytes, 2 allocs
init github.com/leoluk/perflib_exporter/collector @427 ms, 0 ms clock, 1920 bytes, 14 allocs
init github.com/dimchansky/utfbom @427 ms, 0 ms clock, 16 bytes, 1 allocs
init github.com/prometheus-community/windows_exporter/collector @427 ms, 679 ms clock, 1650848 bytes, 24255 allocs
init gopkg.in/yaml%2ev3 @1107 ms, 0 ms clock, 25544 bytes, 277 allocs
init database/sql/driver @1107 ms, 0 ms clock, 48 bytes, 3 allocs
init database/sql @1107 ms, 0 ms clock, 160 bytes, 8 allocs
init github.com/prometheus/client_golang/prometheus/promhttp @1107 ms, 0 ms clock, 304 bytes, 2 allocs
init github.com/prometheus/common/version @1107 ms, 0 ms clock, 0 bytes, 0 allocs
init golang.org/x/crypto/bcrypt @1107 ms, 0 ms clock, 384 bytes, 3 allocs
init html/template @1107 ms, 0 ms clock, 10296 bytes, 29 allocs
init golang.org/x/net/trace @1107 ms, 0 ms clock, 16864 bytes, 8 allocs
init github.com/mwitkow/go-conntrack @1107 ms, 0.69 ms clock, 4448 bytes, 121 allocs
init golang.org/x/text/transform @1108 ms, 0 ms clock, 80 bytes, 5 allocs
init golang.org/x/text/unicode/bidi @1108 ms, 0 ms clock, 272 bytes, 2 allocs
init golang.org/x/text/secure/bidirule @1108 ms, 0 ms clock, 16 bytes, 1 allocs
init golang.org/x/text/unicode/norm @1108 ms, 0 ms clock, 0 bytes, 0 allocs
init golang.org/x/net/idna @1108 ms, 0 ms clock, 0 bytes, 0 allocs
init golang.org/x/net/http/httpguts @1108 ms, 0 ms clock, 688 bytes, 2 allocs
init golang.org/x/net/http2/hpack @1108 ms, 0 ms clock, 21464 bytes, 28 allocs
init golang.org/x/net/http2 @1108 ms, 0 ms clock, 4400 bytes, 65 allocs
init golang.org/x/oauth2 @1108 ms, 0 ms clock, 96 bytes, 3 allocs
init gopkg.in/yaml%2ev2 @1108 ms, 0 ms clock, 26736 bytes, 264 allocs
init github.com/prometheus/common/config @1108 ms, 0 ms clock, 208 bytes, 2 allocs
init github.com/prometheus/exporter-toolkit/web @1108 ms, 0 ms clock, 1168 bytes, 11 allocs
init main @1108 ms, 0.97 ms clock, 28736 bytes, 276 allocs

Some that jump out to me are:

init github.com/leoluk/perflib_exporter/perflib @104 ms, 2195 ms clock, 37284576 bytes, 50136 allocs becomes init github.com/leoluk/perflib_exporter/perflib @1245 ms, 8504 ms clock, 37288800 bytes, 50160 allocs

and

init github.com/prometheus-community/windows_exporter/collector @2316 ms, 2797 ms clock, 1645856 bytes, 24226 allocs becomes init github.com/prometheus-community/windows_exporter/collector @9762 ms, 35909 ms clock, 1649008 bytes, 24245 allocs

Slimming down the import of these modules would be the lowest hanging fruit, with the latter pushing the startup time out of the windows service timeout on its own under resource constraint. This diagram really helped me understand whats happening during initialization and why we never reach init/main when system is constrained:

The less we can do in the var/const/init of 'collector' (Or potentially one of the imports nested within) the better presumably in terms of load times, but that's where ive hit a bit of a natural stop for now.

If anyone has any suggestions on other things i could try to help provide more info or make tweaks/changes to try things out im more than happy to help so please let me know :)

[JDA88]

Thank you very much for your investigation, this confirms what I was suspecting at first, if all the initialization is done before reporting that the service is Started to Windows it's a recipe to disaster.

I’ll try to explain a little bit better my point; I developed quite a few native services in Windows over the past year and if you want it to be reliable at startup it should be done this way:

• Start the process
  • Declare variable, const, etc.
• Report back to Windows that the service is Starting (ASAP)
  • Idealy you should get to this point in under 1s in ANY scenario
  • It let windows know you are working on starting the service and that you are not hanging
• Minimal initialization
  • The bare minimal object and library initialization you need to start the main loop.
  • Anything that can be initialized into the main loop should not be done here
• Report back to windows the service Started state
  • Idealy you should get to this point in under 5s in ANY scenario
  • Start the main loop
  • Loop until you receive the "Stop" message from Windows
  • Then report the Stopping state and start killing the workers etc.
• Keep the main loop free of any “heavy code”
  • If possible, start sub-workers (threads) that initialise themselves and do the job
  • Use the main loop only to watch if the threads are doing fine

[jammiemil]

@JDA88 Exactly where my mind has been heading, Unfortunately I lack the GO Chops to really understand at what point we report back to windows that the service is started, Is it when we hit main() in main? Or is it done as part of the import of the package the 'manages' the service? ("golang.org/x/sys/windows/svc"?) but ultimately as you say the 'Path to main' needs to be kept as clear as possible so that unexpected behaviour doesnt creep in under load and we can report back to windows ASAP

[JDA88]

There Is a workaround for programs that can’t do It the correct way

You release 2 exe:

• Program.exe
• Program.Service.exe

Program.Service.exe does is the right way, reach the mail loop and call Program.exe in a sub thread. When it exit it kill the sub process. Sometime it's the only way to do it.

[jammiemil]

I've been fiddling around with this and I have a version of windows_exporter that does its service initialization as part of a separate package init and therefore responds to the windows service manager almost immediately. The only problem I have is that I've completely broken the signal channel so you cant 'stop' the service without going into task manager and killing the process.

There's probably all sorts of reasons why I shouldn't do it in the way that I have but ill rebase my fork early next week (its a mess right now) and share where I've gotten to to see if anyone can help get it over the line, or tell me what I've done wrong >.<