too many calls to DrupalCacheInterface::set() ?

Are there corresponding database calls too? The entire countries array should be bulk loaded in a singular hit and then passed out from the cached version as required.

I can not replicate any excessive overheads here. Of the 455 DB calls, only 4 were related to the countries load, 3 bulk loads and 1 singular load from a node displaying a countries field.

And when you load the page for the second time, there are none :)

Every fieldable entity gets cached, and we bulk load countries in a single hit to avoid multiple individual database calls per country as that is much worse. So that's the 250 calls for the first load and none afterwards.

Regards single c/f all. This is a very non-scientific test based off 1 page load:

0.4ms for a single db call to get id / title (and no field loading)
8.4ms for the complete 253 country & field loads

20 times slower, but you get 250 times as much data (ie countries and fields), or 0.03 ms per country

I flushed the cache on this site while on a typical development site, nothing too special, a couple of sliders, few blocks, etc on a panel page. There were over 2000 db calls, and ~1/4 were due to node and file [the entity behind both files & images] entity field cache sets. Second load, there were 374 db calls [menu / path modules accounts for much of these], but only 3 cache sets calls.

So this is just how Drupal works if you want fieldable entities.

Actually, I may have a look at the option widgets to see if these can be optimized. This is what is causing the high load on a single hit.

I think the implementation is good. Loading ~250 at once should not be an issue.

@johnv Have you found the problem? Can reproduce. Everything works as expected.

@John

Nodes, users, files (images included), terms, vocabs, countries, and ..... are entities. Every single one will trigger a cache set if it is loaded for the first time.

load_xxx()
load_fields()
-- foreach field, load field
cache_set()

Then if cached, there should be no cache sets, just

load_xxx()
load_cached_fields()

Or

load_xxx_multiple()
load_cached_fields_multiple()

If you see 253 cache sets on every page (each time you visit "node/add/content-with-country-field") then there is an issue with the caching on your system, ie: the cache is not being used.

OK, as promised, here are the results.

Currently, the existing code takes 60ms for the first time (full entity load), and this drops to 9 - 10ms for additional calls.

The widget options list can easily be done via direct DB calls:

function countries_allowed_values($field) {
  $query = db_select('countries_country', 'c');
  $query->distinct();
  $query->fields('c', array('iso2', 'name'));
  $query->orderBy('c.name', 'ASC');
  if (!empty($field['#filters'])) {
    countries_filter_query_alter($query, $field['#filters'], 'c');
  }
  $countries = $query->execute()->fetchAllKeyed(0, 1);

  // Allow other modules to update this list.
  countries_invoke_additional_countries_alter($countries);

  return $countries;
}

Execution time: 2.5 to 3.5 ms

Bypassing the countries module

  $s = microtime_float();
  include_once DRUPAL_ROOT . '/includes/locale.inc';
  $list = country_get_list();
  $e = microtime_float();
  dpm("Executed full load in " . (($e - $s) * 1000) . ' ms');

First time that I ran this, I got an execution time: 160-170ms. But that appeared to be a one off.

Generally, times were around 60-80ms, a few in the 90-120ms range, for the first load, then dropped significantly.

Overview:

Direct DB: x1
First load: x20
Additional loads: x3

No Countries Module
First load: x20 to x23
Additional loads: x2.5

No significant difference between the including the countries module with a full entity load and the iso file that only contains the iso2 code and name! That was totally unexpected! Having the data in the database is faster than reading it off the disk.

I tried to by bypass multiple calls to $countries = entity_load_multiple_by_name('country'); using a local static variable, but there were no noticeable differences.

OK, and looking at loading individual countries rather than mass loading:

function microtime_float() {
  list($usec, $sec) = explode(" ", microtime());
  return ((float)$usec + (float)$sec);
}

  $s = microtime_float();
  for($i = 1; $i <= 250; $i++) {
    entity_load_single('country', $i);
  }
  $e = microtime_float();
  dpm("Executed full load in " . (($e - $s) * 1000 / 250) . ' ms');

This gave a load time of 3.5ms per country, again about 1/20th of the load time of the full countries array.

What to make of all this?

If we display only 1 or 2 countries, then by passing the bulk load is good. After maybe 15 or so, we start seeing additional overhead.

In terms of the widget, well a one off load looks ok to me too. Higher, but uses the tested code.

lol, I knew that there was something fishy. The results were too good!

OK, after removing the countries module country alter hook, the core times dropped by a seventh and additional loads were half that of the direct db call.

Overview:

Direct DB: x1
Full entity load (first time): x20
Additional loads: x3

No Countries Module involvement.
First load: x3
Additional loads: x0.5

Testing appears to show no issues here. If caching is 100% disabled, then yes, there would be a cache set for every field for every entity on every load. This is a global issue related to the specific developmental tools enabled (ie. Drupal core with no caching caches fields on entities).

Follow-up caching issues in: #1397762: Entity cache integration

Can you replicate this on a clean installation? I definitively could not replicate this myself on either a clean installation or a complex one (with 150 modules enabled, yes 150).

You can see if there is a difference between countries_load_multiple() and entity_load_multiple_by_name('country'), both do the same thing and I'm not sure why the second was chosen.

Anyways, this is not related to this module and there is something corrupt with yours for repeatedly resetting the cache, as you said, this also effects other fields. Try disabling all devel modules using the admin menu, then slowly disabling other modules one by one until you find the module responsible. It may not be something directly related to the entity or caching system.

Thanks for the feedback. Nothing has changed here to assist the issue, I'm guessing there were other updates other than just Drupal core and this one, and the issue was fixed here. (Nothing from core that I have tracked would have contributed to this issue either)

But great news. I guess you would be seeing a better performance from your site!