We recently upgraded one of our clusters from 4.4.16 to 5.0.15. Prior to upgrading we saw about 50K "Refreshed cached collection" log messages per hour. Now we see about 50K per minute - an increase by 2 orders of magnitude.

Looking at the source code, it looks like the lookupCollection method in catalog{_}cache.cpp was refactored in 5.0, resulting in a regression where the "Refreshed cached collection" message is always logged at level 0, versus in 4.4 where it was only logged at level 0 on the very first call or when the version had changed.

From 4.4 (https://github.com/mongodb/mongo/blob/v4.4/src/mongo/s/catalog_cache.cpp#L756-L774):

const int logLevel =                (!existingRoutingInfo ||                 (existingRoutingInfo &&                  routingInfoAfterRefresh->getVersion() != existingRoutingInfo->getVersion()))                ? 0                : 1; 

From 5.0 (https://github.com/mongodb/mongo/blob/v5.0/src/mongo/s/catalog_cache.cpp#L667-L674):

// logLevel
isIncremental || newComparableVersion != previousVersion ? 0 : 1, 

So the 4.4 logic was to to log at level 0 if it's the very first call for the collection (!existingRoutingInfo) or if the version has changed.

In 5.0, the logic changed to log at level 0 if it's any call other than the very first call (isIncremental) or the version has changed. I believe this change in logic was unintentional, as it results in a huge amount of level 0 log spam. I think what was intended is:

 // logLevel
!isIncremental || newComparableVersion != previousVersion ? 0 : 1, 

Notice "isIncremental" was changed to "!isIncremental".