Or, “Understanding the Arnold log, part 23”

In this case, a client had very low (15%) CPU usage for a render. We got the Arnold log, and here’s the interesting part:

00:01:44  856MB   | OpenImageIO ImageCache statistics (0000000025850F20) ver 1.5.24
00:01:44  856MB   |   Images : 3 unique
00:01:44  856MB   |     ImageInputs : 299 created, 2 current, 3 peak
00:01:44  856MB   |     Total size of all images referenced : 192.4 MB
00:01:44  856MB   |     Read from disk : 12.0 GB
00:01:44  856MB   |     File I/O time : 45m 41.5s (48.1s average per thread)
00:01:44  856MB   |     File open time only : 0.0s
00:01:44  856MB   |   Tiles: 711523 created, 559 current, 640 peak
00:01:44  856MB   |     total tile requests : 249379431
00:01:44  856MB   |     micro-cache misses : 3353694 (1.34482%)
00:01:44  856MB   |     main cache misses : 711523 (0.285317%)
00:01:44  856MB   |     Peak cache memory : 10.0 MB
00:01:44  856MB   |   1 not tiled, 1 not MIP-mapped
00:01:44  856MB   | -----------------------------------------------------------------------------------
00:01:44  856MB   | performance warnings:
00:01:44  856MB   | Rendering utilization was only 15%. Your render may be bound by a single threaded process or I/O.
00:01:44  856MB   | -----------------------------------------------------------------------------------

• File I/O time seems a bit high for three textures and a render that took less than 2 minutes
• main cache* misses is pretty high. Normally you expect something less than 0.01%.

  0.285% means that texture tiles are loaded from disk (instead of from the in-memory texture cache) once out of every 350 texture lookups. That’s a little high.

  * The main cache is the cache of 64×64 texture tiles loaded from disk into the texture cache.

• Peak cache memory is 10.0 MB !!! That explains the main cache misses: the texture cache is really, really small.

Other clues to the too-small texture cache size:

• Read from disk is 12 GB but the total size of all images referenced is just 192.4 MB, and the peak cache memory was just 10.0 MB
  So the same texture data is constantly being unloaded from the cache and reloaded from disk.

The solution? Increase the size of the texture cache. The current default is 2048, which should be good in most cases.