Monday, June 18, 2018

Still chasing the agent initialization problem.

Bad scenario:

ddd@f25-turbo[smart-streaming] spice> DISPLAY=:1 RECORDER_TRACES='plugins:nvidia.*:main' spice-streaming-agent
[58 0.000137] main: Entering SPICE streaming agent spice-streaming-agent with 1 args
[59 0.000216] plugins: Loading plugins from /usr/local/lib/spice-streaming-agent/plugins/*.so
[60 0.000475] plugins: Plugin 1/1 is /usr/local/lib/spice-streaming-agent/plugins/libnvidia.so
[61 0.000485] plugins: Loading /usr/local/lib/spice-streaming-agent/plugins/libnvidia.so
[62 0.002293] plugins: Plugin init function is 0x7fa761ae7d15
[82 0.000137] nvidia: Streaming agent plugin recorded
[63 0.003932] main: Read header type 1
[64 0.003959] main: Reading capabilities len 0
[65 0.003969] main: Writing capabilities size 8
[66 0.004003] main: Wrote capabilities
[67 0.004020] main: Read header type 4
[69 0.004038] plugins: Plugin 0x15b7cc0 has rank 1
[70 0.004049] plugins: Plugin 0x15b7a80 has rank -1073741824
[76 0.004063] plugins: Plugin 0x15b7a80 offers codec type 3
[83 0.001802] nvidia: Create capture
[84 4.873679] nvidia: Capture frame
[85 4.873938] nvidia: Release frame
[86 4.873945] nvidia_sleep: Did sleep for 33333 us
[87 4.907396] nvidia: Check setting updates
[88 4.907423] nvidia: Start streaming
[89 4.941311] nvidia: Create capture session
[90 12.503917] nvidia_init: Releasing encoder
[91 12.504057] nvidia: Release encoder
[92 12.504063] nvidia: Release frame
[93 12.504068] nvidia_init: Recording initial settings
[94 12.504073] nvidia_init: Create encoder session
[95 27.213693] nvidia: Reset capture
[96 27.214002] nvidia: Release encoder
[97 27.214013] nvidia: Release frame
spice-streaming-agent[2251]: nvEncOpenEncodeSessionEx failed(2)

The case that works looks like this:

ddd@f25-turbo[smart-streaming] spice> DISPLAY=:1 RECORDER_TRACES='plugins:nvidia.*:main' spice-streaming-agent
[58 0.000132] main: Entering SPICE streaming agent spice-streaming-agent with 1 args
[59 0.000216] plugins: Loading plugins from /usr/local/lib/spice-streaming-agent/plugins/*.so
[60 0.000498] plugins: Plugin 1/1 is /usr/local/lib/spice-streaming-agent/plugins/libnvidia.so
[61 0.000517] plugins: Loading /usr/local/lib/spice-streaming-agent/plugins/libnvidia.so
[62 0.002612] plugins: Plugin init function is 0x7f428f4edd15
[82 0.000121] nvidia: Streaming agent plugin recorded
[63 0.005129] main: Read header type 1
[64 0.005146] main: Reading capabilities len 0
[65 0.005151] main: Writing capabilities size 8
[66 0.005165] main: Wrote capabilities
[67 0.005177] main: Read header type 4
[69 0.005196] plugins: Plugin 0x1383cc0 has rank 1
[70 0.005203] plugins: Plugin 0x1383a80 has rank -1073741824
[76 0.005216] plugins: Plugin 0x1383a80 offers codec type 3
[83 0.002631] nvidia: Create capture
[84 0.099553] nvidia: Capture frame
[85 0.099584] nvidia: Release frame
[86 0.099594] nvidia_sleep: Did sleep for 33333 us
[87 0.133018] nvidia: Check setting updates
[88 0.133056] nvidia: Start streaming
[89 0.167438] nvidia: Create capture session
[90 0.229145] nvidia_init: Releasing encoder
[91 0.229310] nvidia: Release encoder
[92 0.229428] nvidia: Release frame
[93 0.229519] nvidia_init: Recording initial settings
[94 0.229608] nvidia_init: Create encoder session
[95 2.945855] nvidia_init: Validate encoder GUID
[96 2.946447] nvidia_init: Initialize encode session
[97 2.955682] nvidia_init: Register texture
[98 2.955699] nvidia_init: Register parameters
[99 2.956270] nvidia_init: Create bitstream buffer
[100 2.963420] nvidia_init: Done
[101 2.963436] nvidia: Stream started
[102 2.963452] nvidia: Grab first frame
[103 2.963459] nvidia: FBC to GL grab frame
[104 4.175245] nvidia: Map frame for use by encoder
[105 4.175652] nvidia: Fill frame encoding information
[106 4.175671] nvidia: Encode the frame
[107 4.178207] nvidia: Get the bitstream
[108 4.184591] nvidia_frames: Capture 47621.87 bytes/s, total 199278, 0.24 loops/s, avg duration 291818.08 us,
[109 4.184614] nvidia_capture: Captured 199278 bytes after 4184.613000 ms, 1600 x 1200 pixels
[110 4.184797] nvidia: Capture frame
[111 4.184816] nvidia: Release frame
[112 4.184915] nvidia: Unlock bitstream
[113 4.185009] nvidia: Unmap input resource
[114 4.185387] nvidia_sleep: Did not sleep, behind by -4019127 us
[115 4.185412] nvidia: Check setting updates
[116 4.185522] nvidia: Grab another frame
[117 4.185622] nvidia: FBC to GL grab frame
[118 4.185914] nvidia: Map frame for use by encoder
[119 4.186174] nvidia: Fill frame encoding information
[120 4.186196] nvidia: Encode the frame
[121 4.186518] nvidia: Get the bitstream
[122 4.189471] nvidia_frames: Capture 29297.28 bytes/s, total 199421, 204.88 loops/s, avg duration 809055.52 us,
[123 4.189492] nvidia_capture: Captured 143 bytes after 4.879000 ms, 1600 x 1200 pixels
[124 4.189657] nvidia: Capture frame
[125 4.189674] nvidia: Release frame
[126 4.189765] nvidia: Unlock bitstream
[127 4.189913] nvidia: Unmap input resource
[128 4.190109] nvidia_sleep: Did sleep for 28611 us
[129 4.218919] nvidia: Check setting updates
[130 4.218944] nvidia: Grab another frame
[131 4.218949] nvidia: FBC to GL grab frame
[132 4.219102] nvidia: Map frame for use by encoder
[133 4.219386] nvidia: Fill frame encoding information
[134 4.219403] nvidia: Encode the frame
[135 4.219613] nvidia: Get the bitstream

So the problem does not occur on the first creation of the encode session, but on the next one. What seems to be missing is the GUID validation.