kick によるイメージのレンダリングの実行中、進捗メッセージ、警告、エラーがレンダー ログとしてコンソールまたはファイルに出力されます。進捗状況の割合を示すだけでなく、これらの詳細な統計情報を使用してシーンの最適化とデバッグを行うことができます。
Arnold のログは、レンダーのデバッグ、最適化、およびベンチマークに役立つ詳細な統計情報を提供します。エラーが発生した場合には、まず最初に確認する必要があります。また、サポートに相談する際に、最初に送信する情報でもあります。
レンダリングで問題が発生したら、まず最初に行うべきことは、ログ ファイルで「ERROR」という単語を検索することです。ほとんどの場合、そのエラー メッセージに問題の原因が見つかります。
詳細レベルは、kick とプラグインでは異なります。
| kick | プラグイン |
|---|---|
| 0 - 出力なし 1 - 進行状況 2 3 4 5 - 詳細 6 - デバッグ |
エラー 警告 + 情報 デバッグ |
ログの最も一般的な出力例を以下に示します。ログの最初の列 00:00:00 は、[hh:mm:ss](http://hhmmss) 形式の経過時間を示します。2 番目の列 773 MB は、その段階でのメモリの使用量を示します。
このセクションには、使用されている Arnold のバージョンと、そのビルドの詳細が示されます。また、レンダーに使用されたマシンのハードウェア仕様とオペレーティング システムも示されます。
00:00:00 773MB | log started Tue Jul 21 15:26:25 2015
00:00:00 773MB | Arnold 4.2.7.4 windows icc-14.0.2 oiio-1.5.15 rlm-11.2.2 2015/06/15 09:39:31
00:00:00 773MB | host application: MtoA 1.2.3.1 03a85380bec8 (Master) MtoA-1.2.3.1 Maya 2016
00:00:00 773MB | running on PC, pid=12188
00:00:00 773MB | 1 x Intel(R) Xeon(R) CPU E5-1650 v2 @ 3.50GHz (6 cores, 12 logical) with 32712MB
00:00:00 773MB | Windows 7 Professional Service Pack 1 (version 6.1, build 7601) レンダー セッション全体に対して 1 つの初期化プロセスがあり(最初のレンダーでのみ)、以降のすべてのレンダーには更新されたプロセスがあります。
00:00:00 773MB | [mtoa.session] Initializing at frame 1.000000
00:00:00 773MB | [mtoa] Exporting Arnold options 'defaultArnoldRenderOptions'
00:00:00 773MB | [mtoa.extensions] aiOptions Using translator <built-in>, provided by <built-in>(<built-in>).
00:00:00 773MB | [mtoa.session] defaultArnoldRenderOptions | Exporting plug defaultArnoldRenderOptions.message for type aiOptions このセクションには、すべてのシェーダまたはプロシージャルの読み込み結果が示されます。
kick によるレンダリングの場合は、プラグインと ass の場所は示されません。
00:00:00 773MB | loading plugins from . ...
00:00:00 773MB | no plugins loaded
00:00:00 773MB | [ass] loading project/scenes/simplescene.ass ...
00:00:00 773MB | [ass] read 11386 bytes, 11 nodes in 0:00.00 プラグインを読み込む際、詳細レベルが十分高ければ、シェーダがリストされます。
00:00:00 773MB | loading plugin: C:/solidangle/mtoadeploy/2016/shaders/mtoa_shaders.dll ...
00:00:00 773MB | mtoa_shaders.dll: MayaMultiplyDivide uses Arnold 4.2.7.4
00:00:00 773MB | mtoa_shaders.dll: MayaClamp uses Arnold 4.2.7.4
00:00:00 773MB | mtoa_shaders.dll: MayaGammaCorrect uses Arnold 4.2.7.4
00:00:00 773MB | mtoa_shaders.dll: MayaCondition uses Arnold 4.2.7.4
....
00:00:00 774MB | mtoa_shaders.dll: volume_sample_float uses Arnold 4.2.7.4
00:00:00 774MB | mtoa_shaders.dll: volume_sample_rgb uses Arnold 4.2.7.4
00:00:00 774MB | mtoa_shaders.dll: driver_mplay uses Arnold 4.2.7.4
00:00:00 774MB | loaded 90 plugins from 1 lib(s) in 0:00.00 ライセンスが使用可能な場合、ログには次のように示されます。
00:00:00 810MB | [rlm] checkout of "arnold 20150615" in progress ...
00:00:00 810MB | [rlm] checkout of "arnold 20150615" from server PC in 0:00.01
00:00:00 810MB | [rlm] expiration date: 31-dec-2015 (164 days left) ただし、RLM サーバが実行されていない場合は、警告が表示されます。
00:00:00 810MB WARNING | [rlm] could not connect to license server on 5053@localhost 00:00:00 56MB |
00:00:00 63MB | [color_manager_syncolor] Using syncolor_color_manager Version 2018.0.80
00:00:00 63MB | with the native catolog directory from /path/to/synColor
00:00:00 63MB | and the optional custom catalog directory from /other/path/to/Shared/ SYNCOLOR 環境変数を使用した場合は、kick が ass カラー管理パスをオーバーライドするため、次のように出力されます。
00:00:00 63MB | [color_manager_syncolor] Using syncolor_color_manager Version 2018.0.80
00:00:00 63MB | from the preference file /path/to/synColorConfig.xml
00:00:00 63MB | and the optional custom catalog directory from /other/path/to/Shared/ ここにはシーン内のライトとオブジェクトの数(およびそのタイプ)がリストされます。
00:00:00 818MB | there are 1 light and 2 objects:
00:00:00 818MB | 1 persp_camera
00:00:00 818MB | 1 distant_light
00:00:00 818MB | 1 utility
00:00:00 818MB | 1 lambert
00:00:00 818MB | 1 driver_exr
00:00:00 818MB | 1 gaussian_filter
00:00:00 818MB | 1 polymesh
00:00:00 818MB | 1 list_aggregate
00:00:00 818MB | 1 MayaShadingEngine
00:00:00 818MB | 1 renderview_display
00:00:00 818MB | 1 color_manager_syncolor このセクションには、出力の解像度とサンプル数についての詳細が示されます。
00:00:00 818MB | rendering image at 640 x 480, 3 AA samples
00:00:00 818MB | AA sample clamp <disabled>
00:00:00 818MB | diffuse samples 3 / depth 1
00:00:00 818MB | specular samples 3 / depth 2
00:00:00 818MB | transmission samples 1 / depth 2
00:00:00 818MB | volume indirect <disabled by depth>
00:00:00 818MB | total depth 10
00:00:00 818MB | bssrdf <disabled>
00:00:00 818MB | transparency depth 10 / fast opacity off レンダリングが開始される前にノードが初期化されます。この統計情報により、シーン内のオブジェクトやライトに関する情報が提供され、何かが間違って設定されている場合には警告が表示されます。ただし、詳細な情報はレンダー中に示されることがあるため、即座に初期化されないデータがあったり、最初のレイがオブジェクトにヒットするまで計算が実行されない場合があります。
00:00:00 818MB | initializing 11 nodes ...
00:00:00 818MB | creating root object list ...
00:00:00 818MB | scene bounds: (-0.995465517 -1.01209259 -0.995465755) -> (1.00453472 0.98790741 1.00453484)
00:00:00 818MB | node initialization done in 0:00.00 (single-threaded)
00:00:00 818MB | updating 12 nodes ...
00:00:00 818MB | directionalLightShape1: distant_light using 1 sample
00:00:00 818MB | node update done in 0:00.00 (single-threaded)
このセクションにはシーンで使用されているドライバと AOV が示されます。また、それらが間違って設定されている場合は警告が示されます。
00:00:00 818MB | [aov] parsing output statement: "RGBA RGBA defaultArnoldFilter@gaussian_filter defaultArnoldDisplayDriver@renderview_display"
00:00:00 818MB | [aov] parsing output statement: "RGBA RGBA defaultArnoldFilter@gaussian_filter defaultArnoldDriver@driver_exr.RGBA"
00:00:00 818MB | [aov] registered driver: "defaultArnoldDisplayDriver@renderview_display" (renderview_display)
00:00:00 818MB | [aov] * "RGBA" of type RGBA filtered by "defaultArnoldFilter@gaussian_filter" (gaussian_filter)
00:00:00 818MB | [aov] registered driver: "defaultArnoldDriver@driver_exr.RGBA" (driver_exr)
00:00:00 818MB | [aov] * "RGBA" of type RGBA filtered by "defaultArnoldFilter@gaussian_filter" (gaussian_filter)
00:00:00 818MB | [aov] done preparing 1 AOV for 2 outputs to 2 drivers (0 deep AOVs) レンダリングが始まると、使用されているバケットの数とサイズがログに示されます。 重点サンプリングに使用されるテーブルを生成する必要がある場合(ここではスカイドームを例にしています)、平均エネルギー値を示してこれらが実行されます。5% ごとの増分で示される進行の割合とともにピクセルあたりの平均レイが示されています。この値を確認すれば、サンプリング設定が高すぎるかどうかが一目でわかります。
00:00:00 825MB | starting 12 bucket workers of size 64x64 ...
00:00:00 835MB | 0% done - 9 rays/pixel
00:00:00 835MB | [accel] bvh4 done - 0:00.00 - 400 prims, 1 key
00:00:00 836MB | 5% done - 9 rays/pixel
00:00:00 836MB | 10% done - 9 rays/pixel
00:00:00 836MB | 15% done - 9 rays/pixel
00:00:00 837MB | 20% done - 9 rays/pixel
00:00:00 837MB | 25% done - 9 rays/pixel
00:00:00 837MB | 30% done - 9 rays/pixel
00:00:00 837MB | 35% done - 10 rays/pixel
00:00:00 837MB | 40% done - 10 rays/pixel
00:00:00 838MB | 45% done - 12 rays/pixel
00:00:00 838MB | 50% done - 12 rays/pixel
00:00:00 838MB | 55% done - 13 rays/pixel
00:00:00 838MB | 60% done - 13 rays/pixel
00:00:00 838MB | 65% done - 13 rays/pixel
00:00:00 838MB | 70% done - 13 rays/pixel
00:00:00 838MB | 75% done - 13 rays/pixel
00:00:00 838MB | 80% done - 13 rays/pixel
00:00:00 838MB | 85% done - 13 rays/pixel
00:00:00 838MB | 90% done - 13 rays/pixel
00:00:00 838MB | 95% done - 13 rays/pixel
00:00:00 838MB | 100% done - 13 rays/pixel
00:00:00 824MB | bucket workers done in 0:00.38 レンダーが完了すると、選択した出力ドライバを使用してファイル(または画面)に書き込まれます。ログには相対パスが表示されます。
00:00:00 824MB | [driver_exr] writing file `C:/Users/Documents/example.exr'
00:00:00 821MB | render done 次の時間は、プラグインと .ass ファイルの読み込みにかかる時間を示します。
00:00:00 821MB | scene creation time:
00:00:00 821MB | plugin loading 0:00.07
00:00:00 821MB | system/unaccounted 0:00.12
00:00:00 821MB | total 0:00.12 ( 1.05% machine utilization) 次の時間は、さまざまなタスクの実行にかかる時間を示します。通常、ノードの初期化とジオメトリの統計情報を確認して効率性低下の原因が明らかにならなければ、ピクセルのレンダリングにほとんどの時間が費やされます。マシンの稼働率が低い場合、同じマシン上の他のプロセスによってレンダーの速度が低下していることがあります。しかし、ノードの初期化、プロシージャル、またはメッシュの処理などの単一スレッド タスクの実行に多くの時間が費やされていることもあります。また、テクスチャやボリュームなどで(低速な)ファイル アクセスが頻発することもあります。テクスチャの統計情報を見ると、問題が明確になる場合があります。
00:00:00 821MB | render time:
00:00:00 821MB | node init 0:00.00
00:00:00 821MB | sanity checks 0:00.00
00:00:00 821MB | bucket rendering 0:00.38
00:00:00 821MB | mesh processing 0:00.00
00:00:00 821MB | accel. building 0:00.00
00:00:00 821MB | pixel rendering 0:00.38 (multi-threaded render, this value may not be reliable)
00:00:00 821MB | system/unaccounted 0:00.17
00:00:00 821MB | total 0:00.55 (69.23% machine utilization) このセクションには、起動時に使用されるメモリと、さまざまなタイプのデータのピーク メモリが示されます。プラグインを使用している場合、起動時のメモリにはホスト アプリケーションが使用しているメモリ量が示されます。kick からレンダーしている場合は、起動時のメモリが少ないため、通常は大きなシーンをレンダーできることを意味します。メモリが大量に使用されている場合、この統計情報を確認することにより、メモリの削減に最も役立つデータを特定できます。
00:00:00 821MB | memory consumed in MB:
00:00:00 821MB | at startup 807.25
00:00:00 821MB | plugins 2.52
00:00:00 821MB | AOV samples 11.67
00:00:00 821MB | output buffers 5.32
00:00:00 821MB | node overhead 0.00
00:00:00 821MB | message passing 0.02
00:00:00 821MB | memory pools 13.54
00:00:00 821MB | geometry 0.01
00:00:00 821MB | polymesh 0.01
00:00:00 821MB | accel. structs 0.02
00:00:00 821MB | strings 0.30
00:00:00 821MB | texture cache 0.00
00:00:00 821MB | unaccounted 1.64
00:00:00 821MB | total peak 842.29 これらは、タイプ単位、ピクセル単位、AA サンプル単位のレイの数です。レンダー時間が長い場合、これらの数値を使用して、レンダーに時間のかかるサンプル タイプや、時間の削減に最も役立つサンプル タイプを特定できます。
00:00:00 821MB | ray counts: (/pixel , /sample) (% total) (avg. hits) (max hits)
00:00:00 821MB | camera 2318256 ( 8.71, 1.00) ( 64.57%) ( 0.11) ( 1)
00:00:00 821MB | shadow 228076 ( 0.86, 0.10) ( 6.35%) ( 0.00) ( 0)
00:00:00 821MB | diffuse 1043914 ( 3.92, 0.45) ( 29.08%) ( 0.00) ( 0)
00:00:00 821MB | total 3590246 ( 13.48, 1.55) (100.00%) ( 0.07) ( 1)
00:00:00 821MB | max depth 1 さまざまなコンテキストでのシェーダ呼び出しの数が表示されます。これは、高速化に最も役立つシェーダ呼び出しを特定するのに便利です。
00:00:00 821MB | shader calls: (/pixel , /sample) (% total)
00:00:00 821MB | primary 523006 ( 1.96, 0.23) (100.00%)
00:00:00 821MB | total 523006 ( 1.96, 0.23) (100.00%) これらのシェーダの状態を使用して、レンダリング時間を改善できます。たとえば、transparent_shadow が数多く表示される場合は、通常、ライト サンプルが非常に高い、または、透明なオブジェクトが多いことを示します。あるいは、自動バンプが非常に高い場合は、そのメリットをあまり受けていないメッシュで、自動バンプを無効にすることができます。
これらの統計情報から、シーン内のジオメトリの量が分かります。メモリ使用量の多い場合、またはシーンのセットアップに時間がかかる場合、これらの情報を使用すると、これらに最も影響を与えるオブジェクト、さらに簡略化したり、サブディビジョンの反復を減らしたりすることでメリットが得られる可能性のあるオブジェクトを見つけることができます。
00:00:00 821MB | geometry: (% hit ) (instances) ( init mem, final mem)
00:00:00 821MB | lists 1 (100.0%) ( 0) ( 0.00, 0.00)
00:00:00 821MB | polymeshes 1 (100.0%) ( 0) ( 0.02, 0.01)
00:00:00 821MB | -----------------------------------------------------------------------------------------
00:00:00 821MB | geometric elements: ( min) ( avg.) ( max)
00:00:00 821MB | objects (top level) 1 ( 1) ( 1.0) ( 1)
00:00:00 821MB | polygons 400 ( 400) ( 400.0) ( 400)
00:00:00 821MB | -----------------------------------------------------------------------------------------
00:00:00 821MB | triangle tessellation: ( min) ( avg.) ( max) (/ element) (% total)
00:00:00 821MB | polymeshes 760 ( 760) ( 760.0) ( 760) ( 1.90) (100.00%)
00:00:00 821MB | unique triangles: 760
00:00:00 821MB | memory use (in MB) 0.01
00:00:00 821MB | vertices 0.00
00:00:00 821MB | vertex indices 0.00
00:00:00 821MB | packed normals 0.00
00:00:00 821MB | normal indices 0.00
00:00:00 821MB | uv coords 0.00
00:00:00 821MB | uv coords idxs 0.00
00:00:00 821MB | uniform indices 0.00
00:00:00 821MB | userdata 0.00
00:00:00 821MB | largest polymeshes by triangle count:
00:00:00 821MB | 760 tris -- pSphereShape1 イメージ テクスチャの詳細な統計情報です。これらの統計情報から、メモリを最も使用するテクスチャ、タイル化されていないテクスチャ、および .tx ファイルに変換することでメリットが得られる可能性のあるテクスチャが分かります。良好なパフォーマンスを得るためには、メイン キャッシュ ミスの割合を非常に少なくする必要があります。割合が高い場合、レンダー時間が大幅に長くなる可能性があります。メイン キャッシュ ミスが極端に高い場合は、.tx ファイルのみを使用したり、テクスチャの数を減らしたり、テクスチャ設定を微調整したりすることが役に立ちます。
00:00:00 841MB | OpenImageIO Texture statistics
00:00:00 841MB | Queries/batches :
00:00:00 841MB | texture : 261503 queries in 261503 batches
00:00:00 841MB | texture 3d : 0 queries in 0 batches
00:00:00 841MB | shadow : 0 queries in 0 batches
00:00:00 841MB | environment : 0 queries in 0 batches
00:00:00 841MB | Interpolations :
00:00:00 841MB | closest : 0
00:00:00 841MB | bilinear : 398256
00:00:00 841MB | bicubic : 701789
00:00:00 841MB | Average anisotropic probes : 2.8
00:00:00 841MB | Max anisotropy in the wild : 671
00:00:00 841MB |
00:00:00 841MB | OpenImageIO ImageCache statistics (000000003D574040) ver 1.5.15
00:00:00 841MB | Images : 1 unique
00:00:00 841MB | ImageInputs : 1 created, 1 current, 1 peak
00:00:00 841MB | Total size of all images referenced : 1.7 MB
00:00:00 841MB | Read from disk : 1.7 MB
00:00:00 841MB | File I/O time : 0.2s (0.0s average per thread)
00:00:00 841MB | File open time only : 0.0s
00:00:00 841MB | Tiles: 25 created, 24 current, 24 peak
00:00:00 841MB | total tile requests : 1454328
00:00:00 841MB | micro-cache misses : 35383 (2.43294%)
00:00:00 841MB | main cache misses : 25 (0.00171901%)
00:00:00 841MB | Peak cache memory : 2.3 MB
00:00:00 841MB | Image file statistics:
00:00:00 841MB | opens tiles MB read I/O time res File
00:00:00 841MB | 1 1 12 1.7 0.2s 768x 768x3.u8 C:/Users/Documents/example.tif UNTILED UNMIPPED MIP-COUNT [12,7,3,2,1,0,0,0,0,0]
00:00:00 841MB |
00:00:00 841MB | Tot: 1 12 1.7 0.2s
00:00:00 841MB | 1 not tiled, 1 not MIP-mapped Arnold が終了すると、リソース、メモリ/スレッドがすべて解放された後で、シャットダウンが実行されます。
00:00:00 841MB | releasing resources
00:00:00 831MB | unloading 27 plugins
00:00:00 829MB | unloading plugins done
00:00:00 828MB | Arnold shutdown Kick の情報の詳細については、こちらを参照してください。