Access prereleases? Proget 6.0.9

janne.aho_4082

We have upgraded ProGet to 6.0.8 and we still have issues with LDAP/AD request ain't cached which in turn makes npm/nuget packages to take 100 times longer than using 5.3.x. We tried to rollback to 5.3.44 but due of a type cast error we had to upgrade back to the 6 series.

There is a new fix for this which is part of the 6.0.9 release, https://inedo.myjetbrains.com/youtrack/issue/PG-2096

We really would need to be able to test this and verify that it do fix our problem and to cut down build times if it works and do not cause other issue.

Had been nice if there was a way to get access to prereleases in the InedoHub...

stevedennis

Hi @janne-aho_4082 ,

No problem, and great you can try this so quickly; PG-2096 is available in 6.0.9-rc.3, and you can install this via the Inedo Hub; https://docs.inedo.com/docs/desktophub-overview#prerelease-product-versions

Cheers,
Steve

janne.aho_4082

Thanks, we got hold of the release candidate (6.0.9-rc.3), but I don't think the PG-2096 solved the issue, we get a high number of requests towards the LDAP/AD server and we still get sometimes errors like this:

System.DirectoryServices.Protocols.LdapException: The LDAP server is unavailable.
at System.DirectoryServices.Protocols.LdapConnection.Connect()
at System.DirectoryServices.Protocols.LdapConnection.BindHelper(NetworkCredential newCredential, Boolean needSetCredential)
at Inedo.Extensions.UserDirectories.DirectoryServicesLdapClient.Bind(NetworkCredential credentials)
at Inedo.Extensions.UserDirectories.ADUserDirectory.Search(String dn, String filter, LdapClientSearchScope scope, String userName, SecureString password)
at Inedo.Extensions.UserDirectories.ADUserDirectory.TryGetPrincipal(PrincipalSearchType searchType, String principalName)
at Inedo.Extensions.UserDirectories.ADUserDirectory.ActiveDirectoryUser.IsMemberOfGroup(String groupName)
at System.Linq.Enumerable.WhereArrayIterator`1.MoveNext()
at System.Linq.Buffer`1..ctor(IEnumerable`1 source)
at System.Linq.OrderedEnumerable`1.<GetEnumerator>d__1.MoveNext()
at System.Linq.Buffer`1..ctor(IEnumerable`1 source)
at System.Linq.Enumerable.ToArray[TSource](IEnumerable`1 source)
at System.Collections.Concurrent.ConcurrentDictionary`2.GetOrAdd(TKey key, Func`2 valueFactory)
at Inedo.ProGet.Web.Security.TaskChecker.CanPerformTask(IUserDirectoryUser user, ProGetSecuredTask task, Nullable`1 feedId)
at Inedo.ProGet.WebApplication.Security.WebApiContext.isAuthorizedForTask(ProGetSecuredTask task, Nullable`1 feedId)
at Inedo.ProGet.WebApplication.Security.WebApiContext.IsAuthorizedForTask(ProGetSecuredTask task, Nullable`1 feedId)
at Inedo.ProGet.WebApplication.FeedEndpoints.Npm.NpmFeedHandlerBase.ValidateTasks(WebApiContext apiContext, Int32 feedId, ProGetSecuredTask[] tasks)
at Inedo.ProGet.WebApplication.FeedEndpoints.Npm.NpmPackageMetadataHandler.<TryProcessRequestAsync>d__0.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Inedo.ProGet.WebApplication.FeedEndpoints.Npm.NpmHandler.<ProcessRequestAsync>d__3.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at Inedo.ProGet.WebApplication.FeedEndpoints.FeedEndpointHandler.FeedRequestHandler.<ProcessRequestAsync>d__8.MoveNext()

not as many as before, but still enough to fault a build once in a while. Also the download time of packages has become worse on our test environment after the upgrade.

Yes we do have a private ticket on this.

rhessinger

Hi @janne-aho_4082,

Thanks for providing us with the stack trace. It looks like we may have found the issue. Would you be able to install the InedoCore 1.31.1-RC.10 pre-release extension and see if that fixes your issue?

Thanks,
Rich

janne.aho_4082

Great that you found something, we will try out the InedoCore RC on our test instance and evaluate it. Just a short follow up question, then 1.31.1-RC.10 does it work with 6.0.9-rc.3 only or can this be run on the 6.0.8 too?

stevedennis

Hi @janne-aho_4082 ,

That version will work on 6.0.8 as well! Please let us know, we're eager to get this improved.

Since there's a lot going on, I want to share a summary...

In some maintenance release of v5, we updated Active Directory libraries. Apparently a side effect for your domain was that querying the "memberOf" property of a LDAP user object is really slow. Who knows why.... it makes no sense. But that's LDAP. Anyways, I guess it must not have been noticed from the front-end? Hard to say.

In v6, we redid API authentication. However, we didn't use the LDAP User Cache. We fixed this mostly in 6.0.8, and hopefully fully in 6.0.9-rc.3. That seems like it helped some, but it must be still slow querying the "memberOf" property.

We figured out a way to cache the "memberOf" property, and then applied that to InedoCore-1.13.1-rc.10. So hopefully with the user object cached and memberOf property cached, this should be much faster.

Cheers,
Steve

janne.aho_4082

Hi @stevedennis,

I'm a bit novice on the LDAP part in ProGet, more used to how Atlassian has it in some of it's products where you as administrator have to setup the LDAP query more or less, a bit more try and error there.

We have now tested a bit (just a couple of runs on npm install) on 6.0.8+1.13.1-rc.10:

Takes more than 100s to install 1153 packages when using always-auth=true in npm

When using npm with always-auth=false then we start suddenly get 404's which we didn't get with the InedoCore 1.13.0.

npm http fetch GET 200 https://internalserver.example.net/npm/private-npm/minipass/-/minipass-3.1.1.tgz 4831ms
npm http fetch GET 200 https://internalserver.example.net/npm/private-npm/terser-webpack-plugin/-/terser-webpack-plugin-2.3.5.tgz 5249ms
npm http fetch GET 404 https://internalserver.example.net/npm/private-npm/del 3152ms
npm http fetch GET 404 https://internalserver.example.net/npm/private-npm/rimraf 2469ms
npm http fetch GET 200 https://internalserver.example.net/npm/private-npm/y18n/-/y18n-4.0.0.tgz 3248ms
npm http fetch GET 200 https://internalserver.example.net/npm/private-npm/@npmcli/installed-package-contents/-/installed-package-contents-1.0.5.tgz 2941ms
npm http fetch GET 200 https://internalserver.example.net/npm/private-npm/read-package-tree/-/read-package-tree-5.3.1.tgz 2951ms

As you can see we still have quite high times on packages that can be downloaded.

A workaround that would work is to set allow anonymous to all feeds, but we wouldn't like that, sadly when you set allow anonymous on a specific feed then it takes long time to fetch packages, seems like it then makes it makes some LDAP logic first (it's our guess).

Forgot to say, we haven't seen any of the LDAP errors that we used to get quite many of with 6.0.8+1.13.0.

stevedennis

Thanks for the update, @janne-aho_4082

1153 packages yields about 2000 quests to ProGet, and I'm guessing you have a connector to npmjs.org, that will probably yield another 1000-2000 requests outbound (e.g. "what is latest version of del for example). It's possible that some of those proxied requests are timing out, and that's why you're seeing 404s. Hard to say.

Can you try using 6.0.9.rc.3 +1.13.1-rc.10? This will have both the LDAP User caching (it wasn't fully implemented in 6.0.8) plus the "memberOf" property caching.

The next step, if you enabled CEIP, we can track down your sessions and find what's taking so long.

janne.aho_4082

We do tend to configure with always-auth=true for npm, it's just while testing to see if there are any differences that I have tested always-auth=false, but with 1.13.1-rc.10 I noticed the 404 for the first time.

Are there any differences between ProGet 6.0.9-rc.3 and 6.0.9-rc.4 that could affect LDAP?

Regarding CEIP, I have to take that with people higher up in the hierarchy before I can turn it on, some policy that prevents me to take that decision.

atripp

@janne-aho_4082 I'm not really sure what always-auth does, but my guess is that it first tries a request with no authorization, receives a 401, then spends the authorization header My guess is that it's unrelated; that initial 401 should be really quick if anonymous access isn't enabled.

rc.4 seems to only have PG-2094 and PG-2098... both unrelated to LDAP, but prety minor. And you'll now have a "copy" button on the console :)

janne.aho_4082

@atripp if you have always-auth=true for npm then it will do an authentication each request it makes to the repository, if always-auth=false then it will only do the authentication from time to time (not sure how often or how it decides it's time to authenticate again).
Thanks for the heads up on the change, we will test with the rc.3 for now.

@stevedennis we turned on CEIP on the test instance and run a npm install against the npm feed that just a cache of npm org.
The license number is: CQAB8SJN-XXXX-XXXXXX-XXXXXX-46VCSHTF (ProGet Trial)
Start time: 10.13 CET
Result: added 1406 packages from 1153 contributors in 150.089s

janne.aho_4082

It seems that the 6.0.9.rc.3+1.13.1-rc.10 combination fixed the 404 issue when using the always-auth=false. Sorry no CEIP on that one as I hadn't restarted ProGet service and IIS when I run that test.

atripp

@janne-aho_4082 great, thanks!

Do you know what the old times were? I really don't know if 2-3 minutes for installing 1400 packages is unreasonable... that doesn't sound so bad to me , but I don't know.

If it's easy to try the older version , we can try to compare CEIP data on both.

Oh and the easiest way to find your CEIP data is from the server/machine name... but it's probably best to submit to the EDO-8231 ticket since it's perhaps sensitive data.

janne.aho_4082

If we pull the packages directly from npm org it takes around 40s to install and that was kind of the time it took on 5.3.11 before the upgrade too (when the packages are cached).

After the upgrade (first to 6.0.6, then 6.0.8), the time it took was just less of 600s (for prod: test should have been around 300s) for the same packages.

I'll see to that the machine name will be posted in the private ticket.

atripp

@janne-aho_4082 thanks!

The timing might be okay then.

npmjs.org will most certainly be faster. Not just because they have a massive server farm compared to you, but their content is static and unauthenticated.

ProGet content isn't static -- and also needs to proxy most requests to the connectors, because they are "what is latest version of this package". Turning on metadata caching in the connector will help, but I still would expect slower response time.

janne.aho_4082

@atripp Will look into the metadata caching and see if it helps us.

The machine name has been posted in EDO-8231

Update: the caching has been enabled all the time for the npm and nuget repositories.

janne.aho_4082

We did upgrade production environment, sadly the npm install is still as slow as before, 600s. It's similar to the test environment but twice as much memory.

What would be your recommended vCPU and Memory for a instant that gets a good amount of package requests and also has maybe around 10 new packages pushed (all from nuget to docker images) per hour.

Dan_Woolf

Hi @janne-aho_4082,

It looks like @rhessinger replied to your other ticket, EDO-8231, with another potential fix. We will update this forums post with the result of that test.

Thanks,
Dan

janne.aho_4082

We installed InedoCore 1.13.1-rc.11 on our test environment

npm install: added 1406 packages from 1153 contributors in 215.136s

npm install --no-audit: added 1406 packages from 1153 contributors in 110.997s
(this we not tested before)

Comparing with yesterday, it seems 1.13.1-rc.11 is slower.

janne.aho_4082

Something we noticed while testing on our test environment was that after running a "Clear Cache" in "Task/Permission", the time to fetch packages went up.

If we didn't run tests for a longer time, we started to see better times the first time we run the test, just running like 20 sec later it was back on long responses.

The two test were run approximately 11:00 CET:
Running test 25 mins after previous test:
added 1406 packages from 1153 contributors in 60.835s

Running next test 20-30 sec later:
added 1406 packages from 1153 contributors in 210.565s

We did update the InedoCore to 1.13.1-rc.11 to our production instance, this far running the same test runs seems to do it between 41s to 65s without seeing the same slowdown that we saw in the test environment.
added 1408 packages from 1153 contributors in 65.477s
added 1408 packages from 1153 contributors in 42.449s
added 1408 packages from 1153 contributors in 40.736s
added 1408 packages from 1153 contributors in 52.648s
No, there is no CEIP data from the production instance.

If there are anything you want us to test in the test environment, let us know.

rhessinger

Hi @janne-aho_4082,

Thank you for providing the extra details. When you click the Clear Cache option in the tasks, that clears the permissions cache, which will mean that calls to AD will need to be made again for the impersonated user and their AD groups. There is a timeout that can also be set in the Advanced Settings on how long to cache users. The default is 60 minutes, but you may want to make sure that the value was not changed. The cache is also cleared anytime permissions/restrictions were added or removed.

As for your testing environment, is your test environment in the cloud? If so, is it in the same region as your active directory server? This can sometimes cause the performance of AD to degrade. Also, you mentioned about 20-30 seconds later in the test environment, it seems to lose the cache. What is your application pool's setting for recycling and Idle time-out? If those are too quick, that will also cause the permissions cache to reset as well.

How long did it take previously in production to run these tests?

Thanks,
Rich

janne.aho_4082

@rhessinger thanks for your explanation of the user cache.

Till yesterday our test environment had been the faster one, even if it had half the amount of ram compared to the production environment. So decided to setup the permissions for the LDAP users in the same way. The first test after that took around 60s to run, directly after that we decided to clear the cache and after that the test environment was back on 200s per run.

On the test environment the recycle time for the app pool is 1740m and idle-timeout is 10m, I assume that is default. I don't see anything about reset of the pool or crashes in the eventlog. So it don't explain why having a pause or 30 mins makes the time better than run twice after each other. Any recommended values for these configs?

Yes, the AD is in a different network which causes extra latency, but there is no difference between test and production in this regard. They are both setup in the same way when accessing their AD's.

Regarding the time to run in production the same "test" before the upgrade, I can see the last build before upgrade it took 59s to install the same packages.

atripp

Hi @janne-aho_4082 ,

Looking at your CEIP sessions, there's a lot of factors going on.

The biggest issue is that your LDAP response is incredibly slow. We can see that a basic a query to [1] find a user is taking 500-900ms, and a query to [2] find user groups is taking upwards of 7500ms. This is compounded by thousands of incoming requests, thousands of outgoing requests, relatively slow download times, and minimum hardware requirements. This all yields different/unpredictable performance, which is why you're seeing varying results so much.

All told, it looks like ~70% of the time is going to LDAP queries (each request does the find user query), ~18% is going to outbound connections, and ~8% is going to the database (most to the "get package metadata" procedure).

There's a few "overload" points, where the OS is spending more time managing multiple things than it is doing those things, and increasing CPUs ought to help.

So, at this point, I would recommend:

switch to a "Feed API Key" instead of a username:password key or "Personal API Key"
enabling metadata query caching on the connector

This should yield a significant performance improvement overall. We can consider new ways of caching things in v4 of this directory provider.... but if you have this kind of latency on your LDAP queries, it's best to just use Feed API keys...

Alana

janne.aho_4082

@atripp thanks for your reply.

I guess most of the LDAP requests are for the authentication, would it be possible to cache the authentication request and LDAP response for a short time, think that could also improve things. But sure, the test environment is limited compared to the production environment, tend to be a question about money.

About the keys, we had some keys of which a number were of old type that version 6 don't allow you to create anymore, we decided to remove all api keys that hadn't been in use for a long while, most api keys seemed to not been used at all, so we ended up with deleting all of them. Turned out that a couple of the keys were in frequent use (in production), I'm not sure if it's something we have configured on our side or there are issues in logging of successful use of the api keys?

As there been a will of having a centralized way of administrating access and also quite many places to change if switching from account credentials to api keys wouldn't happen over night. But we may have to look into that path incase we notice issues in production.

atripp

Hi @janne-aho_4082 ,

would it be possible to cache the authentication request and LDAP response for a short time

That definitely seems possible, but that's the sort of thing we'd want to implement in the "v4" of this directory provider (not as a patch in a maintenance release). I meant to link to that last time, but here it is: https://docs.inedo.com/docs/installation-security-ldap-active-directory#ldap-ad-user-directories-versions --- but v4 is a little whiles out.

switching from account credentials to api keys wouldn't happen over night

We definitely recommend this path going forward, in particular from a security standpoint. Generally a smaller attack surface in case the API key gets leaked (compared to LDAP credentials).

janne.aho_4082

Then we have something to look forward to, could be that we by then switched to API Keys, but the decision ain't mine.

Thanks for the help and for all the RC that we got to test.