grafana-image-renderer stops working after 2nd restart of Grafana service (Windows)

[AlexHeylin]

What happened:
Restart Grafana service, or computer. Grafana front end says grafana-image-renderer not installed. grafana-cli might agree, or might show it installed. grafana-image-renderer folder and files exist on disk without any apparent changes since before service was restarted.

What you expected to happen:
Once installed, grafana-image-renderer continues to show as installed and work after service / computer restarts.

How to reproduce it (as minimally and precisely as possible):
Install v8.x and grafana-image-renderer on Windows (I'm using MySQL, and Grafana was upgraded from at least v7, v6 before that - no idea if relevant).
loop to here
Restart Grafana service once to activate grafana-image-renderer.
Check front end and confirm grafana-image-renderer installed and working.
Restart Grafana service.
Check front end and observe that it says grafana-image-renderer is not installed.
Run grafana-cli.exe plugins ls and observe it may / may not show grafana-image-renderer as installed. Even if it's shown as installed, it doesn't work.
Run grafana-cli.exe remove grafana-image-renderer and observe from result that it was removed, even if grafana-cli.exe plugins ls said it wasn't installed.
Run grafana-cli.exe remove grafana-image-renderer and observe the file not found error because it tried to remove a file that wasn't there - observe how this is different to the run above.
Run grafana-cli.exe install grafana-image-renderer and observe success reported, and prompt to restart Grafana service to activate plugin.
Loop back to loop to here in this list. Repeat until you're convinced I'm not making this up.

Anything else we need to know?:
As I recall, following the upgrade of 7.x to 8.0.2 the plugins refused to run and I think I had to delete the plugins.json from the plugins root folder and let it rebuild before they would work. All other plugins work fine now - only grafana-image-renderer gives problems.

Environment:

• Grafana Image Renderer version: 3.0.1
• Grafana version: 8.0.1 - 8.0.5
• Data source type & version: MySQL 5.7 DB for Grafana data. Graph data sources include MySQL and InfluxDB
• OS Grafana is installed on: Windows Server 2012 R2
• User OS & Browser: Window 10 AMD64, Chrome 91.0.4472.124 (Official Build) (64-bit)
• Grafana plugins:
  grafana-clock-panel ←[33m@←[0m 1.1.3
  grafana-image-renderer ←[33m@←[0m 3.0.1
  grafana-piechart-panel ←[33m@←[0m 1.6.2
  grafana-polystat-panel ←[33m@←[0m 1.2.5
  grafana-worldmap-panel ←[33m@←[0m 0.3.3
• Others:
  briangann-datatable-panel ←[33m@←[0m 1.0.3
  briangann-gauge-panel ←[33m@←[0m 0.0.9
  farski-blendstat-panel ←[33m@←[0m 1.0.3
  jasonlashua-prtg-datasource ←[33m@←[0m 4.0.4
  michaeldmoore-annunciator-panel ←[33m@←[0m 1.1.0
  michaeldmoore-multistat-panel ←[33m@←[0m 1.7.2
  mtanda-heatmap-epoch-panel ←[33m@←[0m 0.1.8
  mxswat-separator-panel ←[33m@←[0m 1.0.1
  neocat-cal-heatmap-panel ←[33m@←[0m 0.0.4
  petrslavotinek-carpetplot-panel ←[33m@←[0m 0.1.2
  satellogic-3d-globe-panel ←[33m@←[0m 0.1.1
  savantly-heatmap-panel ←[33m@←[0m 0.2.1
  vonage-status-panel ←[33m@←[0m 1.0.11

[AlexHeylin]

After reproducing this to gather logs and screen grabs, I found this in the grafana.log (filtered to "render")

lvl=dbug msg="Loading plugin" logger=plugins path="C:\\Program Files\\GrafanaLabs\\grafana\\data\\plugins\\grafana-image-renderer\\plugin.json"
lvl=dbug msg="Getting signature state of plugin" logger=plugins plugin=grafana-image-renderer isBackend=true
lvl=dbug msg="Verifying contents of plugin manifest" logger=plugins plugin=grafana-image-renderer
lvl=warn msg="The following files were not included in the signature" logger=plugins plugin=grafana-image-renderer files=[chrome-win/debug.log]
lvl=dbug msg="Found plugin" logger=plugins id=grafana-image-renderer signature=modified hasRoot=false
lvl=dbug msg="Non-valid plugin Signature" logger=plugins pluginID=grafana-image-renderer pluginDir="C:\\Program Files\\GrafanaLabs\\grafana\\data\\plugins\\grafana-image-renderer" state=modified
lvl=dbug msg="Non-valid plugin Signature" logger=plugins pluginID=grafana-image-renderer pluginDir="C:\\Program Files\\GrafanaLabs\\grafana\\data\\plugins\\grafana-image-renderer" state=modified
lvl=dbug msg="Plugin has a modified signature" logger=plugins pluginID=grafana-image-renderer
lvl=dbug msg="Failed to validate plugin signature. Will skip loading" logger=plugins id=grafana-image-renderer signature=modified status=signatureModified
lvl=warn msg="Some plugin scanning errors were found" logger=plugins errors="plugin 'grafana-image-renderer' has a modified signature"
lvl=dbug msg="No image renderer found/installed. For image rendering support please install the grafana-image-renderer plugin. Read more at https://grafana.com/docs/grafana/latest/administration/image_rendering/" logger=rendering
	

So the plugin is getting disabled (though grafana-cli doesn't show it's disabled) because of the presence of data/plugins/grafana-image-renderer/chrome-win/debug.log

Which contains

[0709/131602.144:ERROR:dxva_video_decode_accelerator_win.cc(1397)] DXVAVDA fatal error: could not LoadLibrary: mf.dll: The specified module could not be found. (0x7E)
[0709/131602.147:ERROR:dxva_video_decode_accelerator_win.cc(1397)] DXVAVDA fatal error: could not LoadLibrary: mfplat.dll: The specified module could not be found. (0x7E)
[0709/131602.147:ERROR:dxva_video_decode_accelerator_win.cc(1397)] DXVAVDA fatal error: could not LoadLibrary: msmpeg2vdec.dll: The specified module could not be found. (0x7E)
[0709/131602.149:ERROR:dxva_video_decode_accelerator_win.cc(1405)] DXVAVDA fatal error: could not LoadLibrary: msvproc.dll: The specified module could not be found. (0x7E)
[0709/131604.440:ERROR:dxva_video_decode_accelerator_win.cc(1397)] DXVAVDA fatal error: could not LoadLibrary: mf.dll: The specified module could not be found. (0x7E)
[0709/131604.442:ERROR:dxva_video_decode_accelerator_win.cc(1397)] DXVAVDA fatal error: could not LoadLibrary: mfplat.dll: The specified module could not be found. (0x7E)
[0709/131604.442:ERROR:dxva_video_decode_accelerator_win.cc(1397)] DXVAVDA fatal error: could not LoadLibrary: msmpeg2vdec.dll: The specified module could not be found. (0x7E)
[0709/131604.444:ERROR:dxva_video_decode_accelerator_win.cc(1405)] DXVAVDA fatal error: could not LoadLibrary: msvproc.dll: The specified module could not be found. (0x7E)
[0709/131604.707:ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.
[0709/131604.712:ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.

Looking at microsoft/playwright#2901 suggest that this is because this build of Chromium is trying to load video renderer DLLs which don't exist on this OS (Windows Server 2012 R2). Those DLLs probably can't be added to some OS, particularly Server OS.

As this is an expected condition, and doesn't affect the plugin rendering for Grafana (on first run) it seems the cause of the problem is Chromium being called with settings that cause the debug.log to be generated which then breaks the signature for the plugin making it get ignored on all future Grafana service starts.

While it doesn't appear to be related to the "missing" video decoder DLLs, I've also seen this

[0709/133708.058:WARNING:ipc_message_attachment_set.cc(49)] MessageAttachmentSet destroyed with unconsumed attachments: 0/1

logged to the debug.log. I think any log entries which cause the debug.log to get generated will cause the plugin to break.

The most logical thing to do here would be to call Chromium with settings that prevent the debug.log being generated unless specifically enabled for debugging.

I did have custom.ini including

[log]
filters = rendering:debug

Which it looks like I added to try and debug this issue. Removing it still causes the debug.log to get generated - so the log level isn't being passed to Chromium.

An alternative approach, if it's possible, might be to set the signing to ignore /chrome-win/debug.log .

[AlexHeylin]

As per https://peter.sh/experiments/chromium-command-line-switches/ other options might be to pass one or more of

--disable-and-delete-previous-log | Disable cros action logging.
--disable-logging | Force logging to be disabled. Logging is enabled by default in debug builds. 
--log-file  | Overrides the default file name to use for general-purpose logging (does not affect which events are logged).
--log-level | Sets the minimum log level. Valid values are from 0 to 3: INFO = 0, WARNING = 1, LOG_ERROR = 2, LOG_FATAL = 3. 

It's worth noting that https://www.chromium.org/for-testers/enable-logging says the file will be called chrome_debug.log, but the file being created is debug.log so it's possible that while I can't find any config / code for this in this project there may be some which is already controlling the creation of this file.

[EdissonMG]

Hi,

@AlexHeylin I'm experiencing the same problem with the debug file in the chromium folder, so I would like to know if you did what you say in the last comment as a possible workaround and if it was solved.

have you solved this issue?

these are the errors that I get from debug.file (It works correctly for 1 or 2 days, then the debug.file is created, Grafana service is restarted and finally image render is broken)

ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.
ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.
WARNING:ipc_message_attachment_set.cc(49)] MessageAttachmentSet destroyed with unconsumed attachments: 0/1
ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.
ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.
WARNING:ipc_message_attachment_set.cc(49)] MessageAttachmentSet destroyed with unconsumed attachments: 0/1
ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.
ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.
ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.
ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.
ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.
ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.
WARNING:ipc_message_attachment_set.cc(49)] MessageAttachmentSet destroyed with unconsumed attachments: 0/1
ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.
ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.

As a possible workaround, I modified the custom init file of Grafana adding "rendering_args" = --disable-gpu or -disable-gpu without any successful

This is because I have read that it is an issue with the GPU but my VM does not have it

Thanks!

[AlexHeylin]

After upgrade to 8.0.6 data/plugins/grafana-image-renderer/chrome-win/debug.log contained only

[0719/132746.508:ERROR:command_buffer_proxy_impl.cc(122)] ContextResult::kTransientFailure: Failed to send GpuChannelMsg_CreateCommandBuffer.
[0719/132746.523:WARNING:ipc_message_attachment_set.cc(49)] MessageAttachmentSet destroyed with unconsumed attachments: 0/1

Note that the codec warnings are gone. This may also be because I installed the "Media Foundation" feature in Windows Server 2012 R2. The issue persists though.

Given there are multiple reasons Chromium may generate this file, I suggest the best way to resolve this is to have this file ignored for signing purposes, or tell Chromium to create it in a temp folder such as %TEMP% or c:\windows\temp. I don't know how that works - can someone who knows how that works comment on the practicality of this approach?

I will try passing switches to Chromium, and report back.

[EdissonMG]

HI @AlexHeylin,

I followed this thread and it works... but the plugin will be unsigned

https://community.grafana.com/t/image-rendering-plugin-installation-fails-with-grafana-8-on-windows-2019/48694

BR
Edisson Martinez

[AlexHeylin]

This issue isn't resolved, simply worked around. If the plugin doesn't shutdown cleanly for some reason the debug.log file remains in place and the plugin can't start until the debug.log file is removed manually and Grafana restarted. Restarting the Grafana service won't solve the problem because once the plugin can't load due to the debug.log , the plugin isn't running so can't remove the debug.log file to resolve the problem.