divinity666 / ruby-grafana-reporter

Reporting Service for Grafana
MIT License
66 stars 5 forks source link

grafana_sql_value and grafana_sql_table result in undefined method `id' for nil:NilClass #35

Closed kbmanseau closed 1 year ago

kbmanseau commented 1 year ago

Describe the issue I am evaluating the abilities of the ruby-reporter and when I was testing grafana_sql_value I ran into some issues. I have a dev environment so I am able to quickly test different grafana versions if needed but so far I was trying to match my prod deployment running grafana 7.2.2. I have also tested on 8.2.6m, 8.3.5 and latest. Whenever I try and use the sql calls I get undefined method 'id' for nil:NilClass

Attaching debug:

I, [2022-11-10T14:12:44.959074 #117406]  INFO -- : Report started at 2022-11-10 14:12:44 +0000
I, [2022-11-10T14:12:44.959133 #117406]  INFO -- : You are running ruby-grafana-reporter version 0.6.2.
D, [2022-11-10T14:12:45.228042 #117406] DEBUG -- : Document attributes: {"convert-backend"=>"pdf", "imagesdir"=>"./images", "var-template"=>"test"}
D, [2022-11-10T14:12:45.228424 #117406] DEBUG -- : Template ./templates/test.adoc contains 3 calls of grafana reporter functions.
D, [2022-11-10T14:12:45.311939 #117406] DEBUG -- : Processing SqlValueInlineMacro (instance: default, datasource: 1, sql: )
D, [2022-11-10T14:12:45.312099 #117406] DEBUG -- : Requesting [removed]/api/frontend/settings with '' and timeout '60'
D, [2022-11-10T14:12:45.345936 #117406] DEBUG -- : Received response #<Net::HTTPOK:0x000055e63c2aae40>
F, [2022-11-10T14:12:45.348503 #117406] FATAL -- : undefined method `id' for nil:NilClass
D, [2022-11-10T14:12:45.348989 #117406] DEBUG -- : Processing SqlValueInlineMacro (instance: default, datasource: 1, sql: select 1)
F, [2022-11-10T14:12:45.350099 #117406] FATAL -- : undefined method `id' for nil:NilClass
D, [2022-11-10T14:12:45.350389 #117406] DEBUG -- : Processing SqlValueInlineMacro (instance: default, datasource: 1, sql: select count(distinct prefix) from global_ip_rib;)
F, [2022-11-10T14:12:45.351419 #117406] FATAL -- : undefined method `id' for nil:NilClass
I, [2022-11-10T14:12:45.378211 #117406]  INFO -- : Report creation ended after 1 seconds with status 'finished'

Application call

Template file (if applicable)

Configuration file

grafana: default: host: [host] api_key: [api_key]

grafana-reporter:

Specifies how often the reporter shall check for newer versions [number of days].

You may set check-for-updates to 0 to disable

check-for-updates: 1 report-class: GrafanaReporter::Asciidoctor::Report templates-folder: ./templates reports-folder: ./reports report-retention: 24 webservice-port: 8815

you may want to configure the following webhook callbacks to get informed on certain events

callbacks:

all:

- <>

- ...

on_before_create:

- <>

- ...

on_after_cancel:

- <>

- ...

on_after_finish:

- <>

- ...

default-document-attributes: imagesdir: ./images

feel free to add here additional asciidoctor document attributes which are applied to all your templates



**Environment (please complete the following information):**
 - OS [e.g. Windows 10]: ubuntu 20.04
 - Grafana version [e.g. 6.3.4]: 7.2.2 (tested 8.3.5 and latest)
 - Environment [e.g. source, gem, docker or windows-exe]: gem
 - Ruby Version, if source or gem environment [e.g. 2.3.7]: 3.0.0
 - Reporter version [e.g. 0.3.0]: 0.6.2
divinity666 commented 1 year ago

Thanks for using the reporter.

Did you try creating and running the demo report from the wizard? You may recreate this, when you call ruby-grafana-reporter -w and follow the command line instructions to create a demo report.

Finally, you will receive a statement, which shows, how you may call the reporter with this template.

Does this work for you?

If this is not working, could you please provide (anonymized) results of the web url [removed]/api/frontend/settings? I would only need the part after datasources to investigate.

kbmanseau commented 1 year ago

Thank you for your response. We had some internal issue that took my focus away from this.

If I run the demo report again I see the following output in CLI

/home/ubuntu/.rbenv/versions/3.0.0/bin/ruby /home/ubuntu/.rbenv/versions/3.0.0/bin/ruby-grafana-reporter -t demo_report -o demo_report.pdf
I, [2022-11-23T20:44:38.974328 #155704]  INFO -- : Report started at 2022-11-23 20:44:38 +0000
I, [2022-11-23T20:44:38.974379 #155704]  INFO -- : You are running ruby-grafana-reporter version 0.6.2.
I, [2022-11-23T20:44:39.401796 #155704]  INFO -- : Reporter is running with NON-Admin privileges on grafana.
F, [2022-11-23T20:44:39.875299 #155704] FATAL -- : undefined method `id' for nil:NilClass
F, [2022-11-23T20:44:43.593375 #155704] FATAL -- : undefined method `id' for nil:NilClass
I, [2022-11-23T20:44:45.715919 #155704]  INFO -- : Report creation ended after 7 seconds with status 'finished'

In the report I can see the same error. Although in the pdf I seem to see the error contains part of the sql query in the error.

image

Datasource Setting from the API

"datasources": {
    "[datasource]": {
      "access": "proxy",
      "id": 1,
      "isDefault": false,
      "jsonData": {
        "keepCookies": null,
        "sslmode": "require",
        "timescaledb": true
      },
      "meta": {
        "id": "postgres",
        "type": "datasource",
        "name": "PostgreSQL",
        "info": {
          "author": {
            "name": "Grafana Labs",
            "url": "https://grafana.com"
          },
          "description": "Data source for PostgreSQL and compatible databases",
          "links": null,
          "logos": {
            "small": "public/app/plugins/datasource/postgres/img/postgresql_logo.svg",
            "large": "public/app/plugins/datasource/postgres/img/postgresql_logo.svg"
          },
          "build": {},
          "screenshots": null,
          "version": "",
          "updated": ""
        },
        "dependencies": {
          "grafanaDependency": "",
          "grafanaVersion": "*",
          "plugins": []
        },
        "includes": null,
        "category": "sql",
        "preload": false,
        "backend": true,
        "routes": null,
        "skipDataQuery": false,
        "autoEnabled": false,
        "annotations": true,
        "metrics": true,
        "alerting": true,
        "explore": false,
        "tables": false,
        "logs": false,
        "tracing": false,
        "queryOptions": {
          "minInterval": true
        },
        "streaming": false,
        "signature": "internal",
        "module": "app/plugins/datasource/postgres/module",
        "baseUrl": "public/app/plugins/datasource/postgres"
      },
      "module": "app/plugins/datasource/postgres/module",
      "name": "[datasource name]",
      "preload": false,
      "type": "postgres",
      "uid": "P9036489B7A1AC03C",
      "url": "/api/datasources/proxy/1"
    }
  }
divinity666 commented 1 year ago

Thanks for the feedback. At first glance, it looks like the brackets [ and ] in the SqlValueInlineMacro might lead to an issue here. Is it possible to formulate the SQL query without those brackets and try again?

If this was the issue, I would have to dig deeper into asciidoctor syntax, as this might limit our possibilities here.

kbmanseau commented 1 year ago

When I run a query without square brackets it just embeds "undefined method `id' for nil:NilClass" onto the pdf.

While troubleshooting an issue I was having with grafana_panel_image I found some interesting behavior. I was getting the same "FATAL -- : undefined method `[]' for nil:NilClass" issue". Here is the debug output

D, [2022-11-29T19:12:01.518785 #171648] DEBUG -- : Received request: GET /render?var-template=peer&var-group_name=removed&var-ASNs=All HTTP/1.1
D, [2022-11-29T19:12:01.518940 #171648] DEBUG -- : query_parameters: {"var-template"=>["peer"], "var-group_name"=>["removed"], "var-ASNs"=>["All"]}
I, [2022-11-29T19:12:01.521506 #171648]  INFO -- : 1 report(s) in progress: 0% (running 0 secs)
I, [2022-11-29T19:12:01.522422 #171648]  INFO -- : Report started at 2022-11-29 19:12:01 +0000
I, [2022-11-29T19:12:01.522529 #171648]  INFO -- : You are running ruby-grafana-reporter version 0.6.2.
D, [2022-11-29T19:12:01.522657 #171648] DEBUG -- : Document attributes: {"convert-backend"=>"pdf", "imagesdir"=>"./images", "var-template"=>"peer", "var-group_name"=>"removed", "var-ASNs"=>"All"}
D, [2022-11-29T19:12:01.522888 #171648] DEBUG -- : Template ./templates/peer.adoc contains 1 calls of grafana reporter functions.
D, [2022-11-29T19:12:01.575309 #171648] DEBUG -- : Processing PanelImageInlineMacro (instance: default, dashboard: BipxHhnVz, panel: 2)
D, [2022-11-29T19:12:01.575531 #171648] DEBUG -- : Requesting https://[removed]/api/frontend/settings with '' and timeout '60'
D, [2022-11-29T19:12:01.595582 #171648] DEBUG -- : Received request: GET /view_report?report_id=2280 HTTP/1.1
D, [2022-11-29T19:12:01.595647 #171648] DEBUG -- : query_parameters: {"report_id"=>["2280"]}
D, [2022-11-29T19:12:01.601005 #171648] DEBUG -- : Received response #<Net::HTTPOK:0x00007fe1007ae070>
D, [2022-11-29T19:12:01.601933 #171648] DEBUG -- : Requesting https://[removed]/api/dashboards/uid/BipxHhnVz with '' and timeout '60'
D, [2022-11-29T19:12:01.631913 #171648] DEBUG -- : Received response #<Net::HTTPOK:0x00007fe1007ee3a0>
D, [2022-11-29T19:12:01.648725 #171648] DEBUG -- : Requesting https://[removed]/api/health with '' and timeout '60'
D, [2022-11-29T19:12:01.667216 #171648] DEBUG -- : Received response #<Net::HTTPOK:0x00007fe1006874d0>
D, [2022-11-29T19:12:01.667638 #171648] DEBUG -- : Requesting https://[removed]/render/d-solo/BipxHhnVz?panelId=2&fullscreen=true&theme=light&timeout=240&var-group_name=removed&var-ASNs=%5B%22%24__all%22%5D&var-template=peer&var-asns=All&from=1664582400000&to=1667260799000 with '' and timeout '60'
I, [2022-11-29T19:12:06.522195 #171648]  INFO -- : 1 report(s) in progress: 100% (running 4 secs)
I, [2022-11-29T19:12:11.522590 #171648]  INFO -- : 1 report(s) in progress: 100% (running 10 secs)
I, [2022-11-29T19:12:16.523001 #171648]  INFO -- : 1 report(s) in progress: 100% (running 15 secs)
I, [2022-11-29T19:12:21.523413 #171648]  INFO -- : 1 report(s) in progress: 100% (running 20 secs)
I, [2022-11-29T19:12:26.523886 #171648]  INFO -- : 1 report(s) in progress: 100% (running 25 secs)
I, [2022-11-29T19:12:31.524312 #171648]  INFO -- : 1 report(s) in progress: 100% (running 30 secs)
I, [2022-11-29T19:12:36.524808 #171648]  INFO -- : 1 report(s) in progress: 100% (running 35 secs)
I, [2022-11-29T19:12:41.525227 #171648]  INFO -- : 1 report(s) in progress: 100% (running 40 secs)
I, [2022-11-29T19:12:46.525689 #171648]  INFO -- : 1 report(s) in progress: 100% (running 45 secs)
I, [2022-11-29T19:12:51.526116 #171648]  INFO -- : 1 report(s) in progress: 100% (running 50 secs)
I, [2022-11-29T19:12:56.526596 #171648]  INFO -- : 1 report(s) in progress: 100% (running 55 secs)
I, [2022-11-29T19:13:01.527022 #171648]  INFO -- : 1 report(s) in progress: 100% (running 60 secs)
I, [2022-11-29T19:13:06.527494 #171648]  INFO -- : 1 report(s) in progress: 100% (running 65 secs)
I, [2022-11-29T19:13:11.527950 #171648]  INFO -- : 1 report(s) in progress: 100% (running 70 secs)
I, [2022-11-29T19:13:16.528420 #171648]  INFO -- : 1 report(s) in progress: 100% (running 75 secs)
I, [2022-11-29T19:13:21.528960 #171648]  INFO -- : 1 report(s) in progress: 100% (running 80 secs)
I, [2022-11-29T19:13:26.529529 #171648]  INFO -- : 1 report(s) in progress: 100% (running 85 secs)
I, [2022-11-29T19:13:31.530038 #171648]  INFO -- : 1 report(s) in progress: 100% (running 90 secs)
I, [2022-11-29T19:13:36.530487 #171648]  INFO -- : 1 report(s) in progress: 100% (running 95 secs)
I, [2022-11-29T19:13:41.531176 #171648]  INFO -- : 1 report(s) in progress: 100% (running 100 secs)
I, [2022-11-29T19:13:46.531772 #171648]  INFO -- : 1 report(s) in progress: 100% (running 105 secs)
I, [2022-11-29T19:13:51.532225 #171648]  INFO -- : 1 report(s) in progress: 100% (running 110 secs)
I, [2022-11-29T19:13:56.532611 #171648]  INFO -- : 1 report(s) in progress: 100% (running 115 secs)
I, [2022-11-29T19:14:01.545347 #171648]  INFO -- : 1 report(s) in progress: 100% (running 120 secs)
F, [2022-11-29T19:14:01.826185 #171648] FATAL -- : undefined method `[]' for nil:NilClass
I, [2022-11-29T19:14:01.863312 #171648]  INFO -- : Report creation ended after 120 seconds with status 'finished'

We can see that "var-ASNs" is set properly based on the value I put in the GET request "ALL" but we can also see that the reporter appears to request a url that contains both "var-ASNs" and "var-asns" where the latter is set to ["$__all"] (decoded). After changing the dashboard variable from ASNs -> asns, everything works as expected.

I wonder if this is related to the grafana_sql_value issue as it is the same error? This is the output of just grafana_sql_value

I, [2022-11-29T19:21:49.757179 #172696]  INFO -- : Server listening on port 8815...
D, [2022-11-29T19:21:54.212709 #172696] DEBUG -- : Received request: GET /render?var-template=peer HTTP/1.1
D, [2022-11-29T19:21:54.212879 #172696] DEBUG -- : query_parameters: {"var-template"=>["peer"]}
I, [2022-11-29T19:21:54.215802 #172696]  INFO -- : Report started at 2022-11-29 19:21:54 +0000
I, [2022-11-29T19:21:54.218688 #172696]  INFO -- : You are running ruby-grafana-reporter version 0.6.2.
I, [2022-11-29T19:21:54.218935 #172696]  INFO -- : 1 report(s) in progress: 0% (running 0 secs)
D, [2022-11-29T19:21:54.310214 #172696] DEBUG -- : Received request: GET /view_report?report_id=2080 HTTP/1.1
D, [2022-11-29T19:21:54.310357 #172696] DEBUG -- : query_parameters: {"report_id"=>["2080"]}
D, [2022-11-29T19:21:54.442822 #172696] DEBUG -- : Document attributes: {"convert-backend"=>"pdf", "imagesdir"=>"./images", "var-template"=>"peer"}
D, [2022-11-29T19:21:54.443078 #172696] DEBUG -- : Template ./templates/peer.adoc contains 1 calls of grafana reporter functions.
D, [2022-11-29T19:21:54.530599 #172696] DEBUG -- : Processing SqlValueInlineMacro (instance: default, datasource: 1, sql: "select count(distinct asn_right) as count   from as_path_analysis a   where a.asn = [asn_num)
D, [2022-11-29T19:21:54.530778 #172696] DEBUG -- : Requesting https://[removed]/api/frontend/settings with '' and timeout '60'
D, [2022-11-29T19:21:54.559602 #172696] DEBUG -- : Received response #<Net::HTTPOK:0x0000563dec10ac68>
F, [2022-11-29T19:21:54.561996 #172696] FATAL -- : undefined method `id' for nil:NilClass
I, [2022-11-29T19:21:54.590194 #172696]  INFO -- : Report creation ended after 0 seconds with status 'finished'

In this case it fails before there is any in progress status.

Curious to know your thoughts

divinity666 commented 1 year ago

Hm, interesting. Looks like the variable names are case sensitive in the reporter, but maybe not for Grafana. I guess I have to investigate deeper there.

Just to understand: the grafana_panel_image is working now, right?

Regarding the manual query: It is a known bug in prometheus queries, that ] have to be escaped with \]. (refer https://github.com/divinity666/ruby-grafana-reporter/releases/tag/v0.5.1.

Please try the SQL query again with escaped closing square brackets

kbmanseau commented 1 year ago

Ah I see, the query with non escaped brackets was auto generated in the demo_report. However the issue is still present with a simple query: grafana_sql_value:1[sql="select count(distinct prefix) from global_ip_rib;"]

Should I be using "grafan_sql_value" in a different way?

divinity666 commented 1 year ago

Can you provide the logs for this easy example as well?

kbmanseau commented 1 year ago

Thanks again for continuing to look into this. I am also able to put some time into this myself if there is something I can help look into. As for the requested logs I have them below

dev-test.adoc:

grafana_sql_value:1[sql="select count(distinct prefix) from global_ip_rib;"]

include::grafana_panel_query_table:19[query="A",dashboard="BipxHhnVz",verbose_log="true"]

single run debug:

/home/ubuntu/.rbenv/versions/3.0.0/bin/ruby /home/ubuntu/.rbenv/versions/3.0.0/bin/ruby-grafana-reporter -t dev-test -o test.pdf -d DEBUG
I, [2023-01-04T19:59:56.549094 #54082]  INFO -- : Report started at 2023-01-04 19:59:56 +0000
I, [2023-01-04T19:59:56.549136 #54082]  INFO -- : You are running ruby-grafana-reporter version 0.6.2.
D, [2023-01-04T19:59:56.791909 #54082] DEBUG -- : Document attributes: {"convert-backend"=>"pdf", "imagesdir"=>"./images", "var-template"=>"dev-test"}
D, [2023-01-04T19:59:56.792136 #54082] DEBUG -- : Template ./templates/dev-test.adoc contains 2 calls of grafana reporter functions.
D, [2023-01-04T19:59:56.794364 #54082] DEBUG -- : Processing PanelQueryTableIncludeProcessor (instance: default, dashboard: BipxHhnVz, panel: 19, query: A)
D, [2023-01-04T19:59:56.794740 #54082] DEBUG -- : Requesting https://[grafana-host]/api/frontend/settings with '' and timeout '60'
D, [2023-01-04T19:59:56.824081 #54082] DEBUG -- : Received response #<Net::HTTPOK:0x000055604d0f5de0>
D, [2023-01-04T19:59:56.826456 #54082] DEBUG -- : Requesting https://[grafana-host]/api/dashboards/uid/BipxHhnVz with '' and timeout '60'
D, [2023-01-04T19:59:56.856087 #54082] DEBUG -- : Received response #<Net::HTTPOK:0x000055604d157900>
D, [2023-01-04T19:59:56.859225 #54082] DEBUG -- : Requesting https://[grafana-host]/api/health with '' and timeout '60'
D, [2023-01-04T19:59:56.874100 #54082] DEBUG -- : Received response #<Net::HTTPOK:0x000055604d1b8e58>
D, [2023-01-04T19:59:56.874784 #54082] DEBUG -- : Requesting https://[grafana-host]/api/tsdb/query with '{"from":"1665086396000","to":"1672862395000","queries":[{"rawSql":"select asn_number from asns where peer_group='telus'\n\n","datasourceId":2,"format":"table"}]}' and timeout '60'
D, [2023-01-04T19:59:56.903032 #54082] DEBUG -- : Received response #<Net::HTTPOK:0x000055604d1d4630>
D, [2023-01-04T19:59:56.903503 #54082] DEBUG -- : Raw result: {:header=>["asn_number"], :content=>[[852], [8013], [7861], [7445], [5765], [54719], [393217], [24914], [19190], [18214], [1691], [14663]]}
D, [2023-01-04T19:59:56.903828 #54082] DEBUG -- : Formatted result: | 852
| 8013
| 7861
| 7445
| 5765
| 54719
| 393217
| 24914
| 19190
| 18214
| 1691
| 14663
D, [2023-01-04T19:59:56.938454 #54082] DEBUG -- : Processing SqlValueInlineMacro (instance: default, datasource: 1, sql: select count(distinct prefix) from global_ip_rib;)
F, [2023-01-04T19:59:56.945444 #54082] FATAL -- : undefined method `id' for nil:NilClass
I, [2023-01-04T19:59:56.961543 #54082]  INFO -- : Report creation ended after 0 seconds with status 'finished'

The resulting pdf:

image
divinity666 commented 1 year ago

Good to see that one query was working as expected! By the way: to make it a table, you have to frame it like to:

|===
include::grafana_panel_query_table:19[query="A",dashboard="BipxHhnVz",verbose_log="true"]
|===

Now coming to the other query, which is not working: What makes me think is, that you specify there the datasource 1, whereas the other query runs on datasource 2.

Could it be, that you have to run the second query also on datasource 2, like so:

grafana_sql_value:2[sql="select count(distinct prefix) from global_ip_rib;"]

Does that work for you?

kbmanseau commented 1 year ago

That was my mistake, the query table is grabbing stuff from a different datasource. However, I don't think the issue is related to the specific datasource? The panel in grafana makes an sql query to datasource 2 and when I modify the template to make the same raw sql, it still results in the error. I seem to get this error anytime I try and use grafana_sql_value. I have even manually added a new datasource and tested it with the same results. I modified the template to:

grafana_sql_value:2[sql="select asn_number from asns where peer_group='telus'"]

|===
include::grafana_panel_query_table:19[query="A",dashboard="BipxHhnVz",verbose_log="true"]
|===

logs:

/home/ubuntu/.rbenv/versions/3.0.0/bin/ruby /home/ubuntu/.rbenv/versions/3.0.0/bin/ruby-grafana-reporter -t dev-test -o test.pdf -d DEBUG
I, [2023-01-05T14:38:35.880587 #55666]  INFO -- : Report started at 2023-01-05 14:38:35 +0000
I, [2023-01-05T14:38:35.880629 #55666]  INFO -- : You are running ruby-grafana-reporter version 0.6.2.
D, [2023-01-05T14:38:36.035628 #55666] DEBUG -- : Document attributes: {"convert-backend"=>"pdf", "imagesdir"=>"./images", "var-template"=>"dev-test"}
D, [2023-01-05T14:38:36.035839 #55666] DEBUG -- : Template ./templates/dev-test.adoc contains 2 calls of grafana reporter functions.
D, [2023-01-05T14:38:36.038092 #55666] DEBUG -- : Processing PanelQueryTableIncludeProcessor (instance: default, dashboard: BipxHhnVz, panel: 19, query: A)
D, [2023-01-05T14:38:36.038523 #55666] DEBUG -- : Requesting https://[grafana host]/api/frontend/settings with '' and timeout '60'
D, [2023-01-05T14:38:36.073780 #55666] DEBUG -- : Received response #<Net::HTTPOK:0x000055ba9d3af1d0>
D, [2023-01-05T14:38:36.075330 #55666] DEBUG -- : Requesting https://[grafana host]/api/dashboards/uid/BipxHhnVz with '' and timeout '60'
D, [2023-01-05T14:38:36.106083 #55666] DEBUG -- : Received response #<Net::HTTPOK:0x000055ba9d483868>
D, [2023-01-05T14:38:36.109697 #55666] DEBUG -- : Requesting https://[grafana host]/api/health with '' and timeout '60'
D, [2023-01-05T14:38:36.124545 #55666] DEBUG -- : Received response #<Net::HTTPOK:0x000055ba9df87ed0>
D, [2023-01-05T14:38:36.125180 #55666] DEBUG -- : Requesting https://[grafana host]/api/tsdb/query with '{"from":"1665153516000","to":"1672929515000","queries":[{"rawSql":"select asn_number from asns where peer_group='telus'\n\n","datasourceId":2,"format":"table"}]}' and timeout '60'
D, [2023-01-05T14:38:36.153903 #55666] DEBUG -- : Received response #<Net::HTTPOK:0x000055ba9d493c40>
D, [2023-01-05T14:38:36.154327 #55666] DEBUG -- : Raw result: {:header=>["asn_number"], :content=>[[852], [8013], [7861], [7445], [5765], [54719], [393217], [24914], [19190], [18214], [1691], [14663]]}
D, [2023-01-05T14:38:36.154593 #55666] DEBUG -- : Formatted result: | 852
| 8013
| 7861
| 7445
| 5765
| 54719
| 393217
| 24914
| 19190
| 18214
| 1691
| 14663
D, [2023-01-05T14:38:36.197143 #55666] DEBUG -- : Processing SqlValueInlineMacro (instance: default, datasource: 2, sql: select asn_number from asns where peer_group='telus')
F, [2023-01-05T14:38:36.197628 #55666] FATAL -- : undefined method `id' for nil:NilClass
I, [2023-01-05T14:38:36.248604 #55666]  INFO -- : Report creation ended after 1 seconds with status 'finished'

Resulting pdf:

image
divinity666 commented 1 year ago

I just released a new version, which should avoid the FATAL error - maybe in your case replaced it with a WARN message and still not functioning, but hopefully supports us in finding the root cause.

Anyway, I am happy to hear, that other queries seem to work as expected.

It would be great, if you could share the logs again when using the latest version.

kbmanseau commented 1 year ago

I have just updated and ran with the following template:

grafana_sql_value:2[sql="select asn_number from asns where peer_group='telus'"]

|===
include::grafana_panel_query_table:19[query="A",dashboard="BipxHhnVz",verbose_log="true"]
|===

which generated the following report image (Note the panel is just a grafana representation of the sql query)

with the following logs:

I, [2023-01-13T19:59:52.593731 #22894]  INFO -- : Server listening on port 8815...
D, [2023-01-13T20:00:33.444696 #22894] DEBUG -- : Received request: GET /render?var-template=dev-test&var-group_name=telus&var-asns=All HTTP/1.1
D, [2023-01-13T20:00:33.444921 #22894] DEBUG -- : query_parameters: {"var-template"=>["dev-test"], "var-group_name"=>["telus"], "var-asns"=>["All"]}
I, [2023-01-13T20:00:33.448806 #22894]  INFO -- : Report started at 2023-01-13 20:00:33 +0000
I, [2023-01-13T20:00:33.448973 #22894]  INFO -- : You are running ruby-grafana-reporter version 0.6.3.
I, [2023-01-13T20:00:33.451506 #22894]  INFO -- : 1 report(s) in progress: 0% (running 0 secs)
D, [2023-01-13T20:00:33.519531 #22894] DEBUG -- : Received request: GET /view_report?report_id=2080 HTTP/1.1
D, [2023-01-13T20:00:33.519674 #22894] DEBUG -- : query_parameters: {"report_id"=>["2080"]}
D, [2023-01-13T20:00:33.664773 #22894] DEBUG -- : Document attributes: {"convert-backend"=>"pdf", "imagesdir"=>"./images", "var-template"=>"dev-test", "var-group_name"=>"telus", "var-asns"=>"All"}
D, [2023-01-13T20:00:33.666413 #22894] DEBUG -- : Template ./templates/dev-test.adoc contains 2 calls of grafana reporter functions.
D, [2023-01-13T20:00:33.669184 #22894] DEBUG -- : Processing PanelQueryTableIncludeProcessor (instance: default, dashboard: BipxHhnVz, panel: 19, query: A)
D, [2023-01-13T20:00:33.670206 #22894] DEBUG -- : Requesting https://[grafana-host]/api/frontend/settings with '' and timeout '60'
D, [2023-01-13T20:00:33.707492 #22894] DEBUG -- : Received response #<Net::HTTPOK:0x00007f65d807bdc8>
D, [2023-01-13T20:00:33.709666 #22894] DEBUG -- : Requesting https://[grafana-host]/api/dashboards/uid/BipxHhnVz with '' and timeout '60'
D, [2023-01-13T20:00:33.742096 #22894] DEBUG -- : Received response #<Net::HTTPOK:0x00007f65d80d98d8>
D, [2023-01-13T20:00:33.746420 #22894] DEBUG -- : Requesting https://[grafana-host]/api/health with '' and timeout '60'
D, [2023-01-13T20:00:33.767810 #22894] DEBUG -- : Received response #<Net::HTTPOK:0x00007f65d814edb8>
D, [2023-01-13T20:00:33.769174 #22894] DEBUG -- : Requesting https://[grafana-host]/api/tsdb/query with '{"from":"1665864033000","to":"1673640032000","queries":[{"rawSql":"select asn_number from asns where peer_group='telus'\n\n","datasourceId":2,"format":"table"}]}' and timeout '60'
D, [2023-01-13T20:00:33.780226 #22894] DEBUG -- : Received request: GET /favicon.ico HTTP/1.1
D, [2023-01-13T20:00:33.780326 #22894] DEBUG -- : query_parameters: {"GET /favicon.ico HTTP/1.1"=>[]}
D, [2023-01-13T20:00:33.780467 #22894] DEBUG -- : GrafanaReporterError: Request 'GET /favicon.ico HTTP/1.1' calls an unknown path for this webservice.
D, [2023-01-13T20:00:33.840606 #22894] DEBUG -- : Received response #<Net::HTTPOK:0x00007f65d81711b0>
D, [2023-01-13T20:00:33.841342 #22894] DEBUG -- : Raw result: {:header=>["asn_number"], :content=>[[852], [8013], [7861], [7445], [5765], [54719], [393217], [24914], [19190], [18214], [1691], [14663]]}
D, [2023-01-13T20:00:33.842009 #22894] DEBUG -- : Formatted result: | 852
| 8013
| 7861
| 7445
| 5765
| 54719
| 393217
| 24914
| 19190
| 18214
| 1691
| 14663
D, [2023-01-13T20:00:34.038233 #22894] DEBUG -- : Processing SqlValueInlineMacro (instance: default, datasource: 2, sql: select asn_number from asns where peer_group='telus')
D, [2023-01-13T20:00:34.038716 #22894] DEBUG -- : Requesting https://[grafana-host]/api/tsdb/query with '{"from":"1673640033000","to":"1673640033000","queries":[{"rawSql":"select asn_number from asns where peer_group='telus'","datasourceId":2,"format":"table"}]}' and timeout '60'
D, [2023-01-13T20:00:34.065928 #22894] DEBUG -- : Received response #<Net::HTTPOK:0x0000556ff93c97b8>
I, [2023-01-13T20:00:34.160916 #22894]  INFO -- : Report creation ended after 1 seconds with status 'finished'
D, [2023-01-13T20:00:38.454647 #22894] DEBUG -- : Received request: GET /view_report?report_id=2080 HTTP/1.1
D, [2023-01-13T20:00:38.454809 #22894] DEBUG -- : query_parameters: {"report_id"=>["2080"]}
D, [2023-01-13T20:00:38.454930 #22894] DEBUG -- : Returning PDF report at ./reports/gf_pdf_20230113-22894-mecabq

I am not sure I understand the change but from the results it looks like it has resolved the issue as now I can see the "result in the first row of the first column" which is the expected behavior.

If this resolution was expected I think we can close this issue. Thanks for all the assitance

divinity666 commented 1 year ago

Well, the good thing is, that the issue is solved now, though I would have expected some WARN message in the log, which is not the case.

Anyway: let's close the issue for now.

Thanks for your support!