SQL errors in service.log

iklema commented 3 weeks ago

Hello,

Since I upgraded rundeck exporter to v2.7.0 I'm experiencing following errors in rundeck service.log:

2024-06-07T19:51:43,319] ERROR spi.SqlExceptionHelper - 0.707000 cannot be parse as time. time must have "99:99:99" format
[2024-06-07T19:51:43,319] WARN  spi.SqlExceptionHelper - SQL Error: 0, SQLState: null
[2024-06-07T19:51:43,319] ERROR spi.SqlExceptionHelper - 0.707000 cannot be parse as time. time must have "99:99:99" format
[2024-06-07T19:51:43,319] WARN  spi.SqlExceptionHelper - SQL Error: 0, SQLState: null
[2024-06-07T19:51:43,319] ERROR spi.SqlExceptionHelper - 0.707000 cannot be parse as time. time must have "99:99:99" format
[2024-06-07T19:51:58,343] WARN  spi.SqlExceptionHelper - SQL Error: 0, SQLState: null
[2024-06-07T19:51:58,343] WARN  spi.SqlExceptionHelper - SQL Error: 0, SQLState: null
[2024-06-07T19:51:58,343] ERROR spi.SqlExceptionHelper - 0.707000 cannot be parse as time. time must have "99:99:99" format
[2024-06-07T19:51:58,343] ERROR spi.SqlExceptionHelper - 0.707000 cannot be parse as time. time must have "99:99:99" format
[2024-06-07T19:51:58,344] WARN  spi.SqlExceptionHelper - SQL Error: 0, SQLState: null
[2024-06-07T19:51:58,344] WARN  spi.SqlExceptionHelper - SQL Error: 0, SQLState: null
[2024-06-07T19:51:58,344] ERROR spi.SqlExceptionHelper - 0.707000 cannot be parse as time. time must have "99:99:99" format
[2024-06-07T19:51:58,344] ERROR spi.SqlExceptionHelper - 0.707000 cannot be parse as time. time must have "99:99:99" format

I did some tests and see that following exporter option is causing the issue:

--rundeck.projects.executions

Could you have a look if you see the same behaviour? Thank you!

igor

phsmith commented 3 weeks ago

Hi @iklema,

It seems to be a problem with Rundeck itself, since the exporter simply collects metrics. By enabling the --rundeck.projects.executions the Rundeck API that retrieves the data might cause you to see these errors in the logs.

I got this error in the Rundeck v4.8.0 logs:

 ERROR spi.SqlExceptionHelper - Data conversion error converting "INTERVAL DAY TO SECOND to TIME" [22018-210]

There's a open issue about this: https://github.com/rundeck/rundeck/issues/8381

iklema commented 3 weeks ago

Hello @phsmith ,

Thank you very much! I'll check with rundeck support directly.

jgarces-pd commented 3 weeks ago

hi @phsmith, Could you please confirm to us the resulting endpoint when you use --rundeck.projects.executions?

We would like to perform some tests against this endpoint to determine if there is any issue on that.

phsmith commented 3 weeks ago

Of course @jgarces-pd. Here are the endpoints that are called when taht param is passed:

/api/34/project/<project_name>/executions?recentFilter=5n&max=20
/api/34/project/<project_name>/executions/running?max=20
/api/34/project/<project_name>/executions/metrics?recentFilter=1d

jgarces-pd commented 3 weeks ago

@phsmith I have tested all three endpoints, and all works fine:

/api/34/project/<project_name>/executions?recentFilter=5n&max=20

{
  "paging": {
    "count": 1,
    "total": 1,
    "offset": 0,
    "max": 20
  },
  "executions": [
    {
      "id": 776772,
      "href": "https://localhost:4440/api/47/execution/776772",
      "permalink": "https://localhost:4440/project/projectName/execution/show/776772",
      "status": "running",
      "project": "projectName",
      "executionType": "scheduled",
      "user": "jgarces",
      "date-started": {
        "unixtime": 1718135070200,
        "date": "2024-06-11T19:44:30Z"
      },
      "job": {
        "id": "9a01189a-359e-4d00-b88d-3b013406bea2",
        "averageDuration": 11184,
        "name": "Kerberos Test (Script)",
        "group": "",
        "project": "projectName",
        "description": "",
        "href": "https://localhost:4440/api/47/job/9a01189a-359e-4d00-b88d-3b013406bea2",
        "permalink": "https://localhost:4440/project/projectName/job/show/9a01189a-359e-4d00-b88d-3b013406bea2"
      },
      "description": "Plugin[script-inline, nodeStep: true]",
      "argstring": null,
      "serverUUID": "0ce696cd-80a1-422f-9631-2c86d68fca5d"
    }
  ]
}

/api/34/project/<project_name>/executions/running?max=20

{
  "paging": {
    "count": 10,
    "total": 10,
    "offset": 0,
    "max": 20
  },
  "executions": [
    {
      "id": 776770,
      "href": "https://localhost:4440/api/47/execution/776770",
      "permalink": "https://localhost:4440/project/projectName/execution/show/776770",
      "status": "succeeded",
      "project": "projectName",
      "executionType": "scheduled",
      "user": "jgarces",
      "date-started": {
        "unixtime": 1718135040684,
        "date": "2024-06-11T19:44:00Z"
      },
      "date-ended": {
        "unixtime": 1718135051968,
        "date": "2024-06-11T19:44:11Z"
      },
      "job": {
        "id": "aeefa01d-0b28-43a2-ac38-25c4d11185c4",
        "averageDuration": 11719,
        "name": "Kerberos Test (Command)",
        "group": "",
        "project": "projectName",
        "description": "",
        "href": "https://localhost:4440/api/47/job/aeefa01d-0b28-43a2-ac38-25c4d11185c4",
        "permalink": "https://localhost:4440/project/projectName/job/show/aeefa01d-0b28-43a2-ac38-25c4d11185c4"
      },
      "description": "Plugin[exec-command, nodeStep: true] [... 2 steps]",
      "argstring": null,
      "serverUUID": "0ce696cd-80a1-422f-9631-2c86d68fca5d",
      "successfulNodes": [
        "remote.rundeck.local"
      ]
    },
    {
      "id": 776767,
      "href": "https://localhost:4440/api/47/execution/776767",
      "permalink": "https://localhost:4440/project/projectName/execution/show/776767",
      "status": "succeeded",
      "project": "projectName",
      "executionType": "scheduled",
      "user": "jgarces",
      "date-started": {
        "unixtime": 1718135010132,
        "date": "2024-06-11T19:43:30Z"
      },
      "date-ended": {
        "unixtime": 1718135021256,
        "date": "2024-06-11T19:43:41Z"
      },
      "job": {
        "id": "9a01189a-359e-4d00-b88d-3b013406bea2",
        "averageDuration": 11184,
        "name": "Kerberos Test (Script)",
        "group": "",
        "project": "projectName",
        "description": "",
        "href": "https://localhost:4440/api/47/job/9a01189a-359e-4d00-b88d-3b013406bea2",
        "permalink": "https://localhost:4440/project/projectName/job/show/9a01189a-359e-4d00-b88d-3b013406bea2"
      },
      "description": "Plugin[script-inline, nodeStep: true]",
      "argstring": null,
      "serverUUID": "0ce696cd-80a1-422f-9631-2c86d68fca5d",
      "successfulNodes": [
        "remote.rundeck.local"
      ]
    },
    {
      "id": 776765,
      "href": "https://localhost:4440/api/47/execution/776765",
      "permalink": "https://localhost:4440/project/projectName/execution/show/776765",
      "status": "succeeded",
      "project": "projectName",
      "executionType": "scheduled",
      "user": "jgarces",
      "date-started": {
        "unixtime": 1718134980239,
        "date": "2024-06-11T19:43:00Z"
      },
      "date-ended": {
        "unixtime": 1718134991590,
        "date": "2024-06-11T19:43:11Z"
      },
      "job": {
        "id": "aeefa01d-0b28-43a2-ac38-25c4d11185c4",
        "averageDuration": 11719,
        "name": "Kerberos Test (Command)",
        "group": "",
        "project": "projectName",
        "description": "",
        "href": "https://localhost:4440/api/47/job/aeefa01d-0b28-43a2-ac38-25c4d11185c4",
        "permalink": "https://localhost:4440/project/projectName/job/show/aeefa01d-0b28-43a2-ac38-25c4d11185c4"
      },
      "description": "Plugin[exec-command, nodeStep: true] [... 2 steps]",
      "argstring": null,
      "serverUUID": "0ce696cd-80a1-422f-9631-2c86d68fca5d",
      "successfulNodes": [
        "remote.rundeck.local"
      ]
    },
    {
      "id": 776762,
      "href": "https://localhost:4440/api/47/execution/776762",
      "permalink": "https://localhost:4440/project/projectName/execution/show/776762",
      "status": "succeeded",
      "project": "projectName",
      "executionType": "scheduled",
      "user": "jgarces",
      "date-started": {
        "unixtime": 1718134950148,
        "date": "2024-06-11T19:42:30Z"
      },
      "date-ended": {
        "unixtime": 1718134963003,
        "date": "2024-06-11T19:42:43Z"
      },
      "job": {
        "id": "9a01189a-359e-4d00-b88d-3b013406bea2",
        "averageDuration": 11184,
        "name": "Kerberos Test (Script)",
        "group": "",
        "project": "projectName",
        "description": "",
        "href": "https://localhost:4440/api/47/job/9a01189a-359e-4d00-b88d-3b013406bea2",
        "permalink": "https://localhost:4440/project/projectName/job/show/9a01189a-359e-4d00-b88d-3b013406bea2"
      },
      "description": "Plugin[script-inline, nodeStep: true]",
      "argstring": null,
      "serverUUID": "0ce696cd-80a1-422f-9631-2c86d68fca5d",
      "successfulNodes": [
        "remote.rundeck.local"
      ]
    },
    {
      "id": 776760,
      "href": "https://localhost:4440/api/47/execution/776760",
      "permalink": "https://localhost:4440/project/projectName/execution/show/776760",
      "status": "succeeded",
      "project": "projectName",
      "executionType": "scheduled",
      "user": "jgarces",
      "date-started": {
        "unixtime": 1718134920455,
        "date": "2024-06-11T19:42:00Z"
      },
      "date-ended": {
        "unixtime": 1718134932426,
        "date": "2024-06-11T19:42:12Z"
      },
      "job": {
        "id": "aeefa01d-0b28-43a2-ac38-25c4d11185c4",
        "averageDuration": 11719,
        "name": "Kerberos Test (Command)",
        "group": "",
        "project": "projectName",
        "description": "",
        "href": "https://localhost:4440/api/47/job/aeefa01d-0b28-43a2-ac38-25c4d11185c4",
        "permalink": "https://localhost:4440/project/projectName/job/show/aeefa01d-0b28-43a2-ac38-25c4d11185c4"
      },
      "description": "Plugin[exec-command, nodeStep: true] [... 2 steps]",
      "argstring": null,
      "serverUUID": "0ce696cd-80a1-422f-9631-2c86d68fca5d",
      "successfulNodes": [
        "remote.rundeck.local"
      ]
    },
    {
      "id": 776757,
      "href": "https://localhost:4440/api/47/execution/776757",
      "permalink": "https://localhost:4440/project/projectName/execution/show/776757",
      "status": "succeeded",
      "project": "projectName",
      "executionType": "scheduled",
      "user": "jgarces",
      "date-started": {
        "unixtime": 1718134890128,
        "date": "2024-06-11T19:41:30Z"
      },
      "date-ended": {
        "unixtime": 1718134900821,
        "date": "2024-06-11T19:41:40Z"
      },
      "job": {
        "id": "9a01189a-359e-4d00-b88d-3b013406bea2",
        "averageDuration": 11184,
        "name": "Kerberos Test (Script)",
        "group": "",
        "project": "projectName",
        "description": "",
        "href": "https://localhost:4440/api/47/job/9a01189a-359e-4d00-b88d-3b013406bea2",
        "permalink": "https://localhost:4440/project/projectName/job/show/9a01189a-359e-4d00-b88d-3b013406bea2"
      },
      "description": "Plugin[script-inline, nodeStep: true]",
      "argstring": null,
      "serverUUID": "0ce696cd-80a1-422f-9631-2c86d68fca5d",
      "successfulNodes": [
        "remote.rundeck.local"
      ]
    },
    {
      "id": 776754,
      "href": "https://localhost:4440/api/47/execution/776754",
      "permalink": "https://localhost:4440/project/projectName/execution/show/776754",
      "status": "succeeded",
      "project": "projectName",
      "executionType": "scheduled",
      "user": "jgarces",
      "date-started": {
        "unixtime": 1718134860250,
        "date": "2024-06-11T19:41:00Z"
      },
      "date-ended": {
        "unixtime": 1718134872186,
        "date": "2024-06-11T19:41:12Z"
      },
      "job": {
        "id": "aeefa01d-0b28-43a2-ac38-25c4d11185c4",
        "averageDuration": 11719,
        "name": "Kerberos Test (Command)",
        "group": "",
        "project": "projectName",
        "description": "",
        "href": "https://localhost:4440/api/47/job/aeefa01d-0b28-43a2-ac38-25c4d11185c4",
        "permalink": "https://localhost:4440/project/projectName/job/show/aeefa01d-0b28-43a2-ac38-25c4d11185c4"
      },
      "description": "Plugin[exec-command, nodeStep: true] [... 2 steps]",
      "argstring": null,
      "serverUUID": "0ce696cd-80a1-422f-9631-2c86d68fca5d",
      "successfulNodes": [
        "remote.rundeck.local"
      ]
    },
    {
      "id": 776752,
      "href": "https://localhost:4440/api/47/execution/776752",
      "permalink": "https://localhost:4440/project/projectName/execution/show/776752",
      "status": "succeeded",
      "project": "projectName",
      "executionType": "scheduled",
      "user": "jgarces",
      "date-started": {
        "unixtime": 1718134830261,
        "date": "2024-06-11T19:40:30Z"
      },
      "date-ended": {
        "unixtime": 1718134841601,
        "date": "2024-06-11T19:40:41Z"
      },
      "job": {
        "id": "9a01189a-359e-4d00-b88d-3b013406bea2",
        "averageDuration": 11184,
        "name": "Kerberos Test (Script)",
        "group": "",
        "project": "projectName",
        "description": "",
        "href": "https://localhost:4440/api/47/job/9a01189a-359e-4d00-b88d-3b013406bea2",
        "permalink": "https://localhost:4440/project/projectName/job/show/9a01189a-359e-4d00-b88d-3b013406bea2"
      },
      "description": "Plugin[script-inline, nodeStep: true]",
      "argstring": null,
      "serverUUID": "0ce696cd-80a1-422f-9631-2c86d68fca5d",
      "successfulNodes": [
        "remote.rundeck.local"
      ]
    },
    {
      "id": 776749,
      "href": "https://localhost:4440/api/47/execution/776749",
      "permalink": "https://localhost:4440/project/projectName/execution/show/776749",
      "status": "succeeded",
      "project": "projectName",
      "executionType": "scheduled",
      "user": "jgarces",
      "date-started": {
        "unixtime": 1718134800504,
        "date": "2024-06-11T19:40:00Z"
      },
      "date-ended": {
        "unixtime": 1718134812013,
        "date": "2024-06-11T19:40:12Z"
      },
      "job": {
        "id": "aeefa01d-0b28-43a2-ac38-25c4d11185c4",
        "averageDuration": 11719,
        "name": "Kerberos Test (Command)",
        "group": "",
        "project": "projectName",
        "description": "",
        "href": "https://localhost:4440/api/47/job/aeefa01d-0b28-43a2-ac38-25c4d11185c4",
        "permalink": "https://localhost:4440/project/projectName/job/show/aeefa01d-0b28-43a2-ac38-25c4d11185c4"
      },
      "description": "Plugin[exec-command, nodeStep: true] [... 2 steps]",
      "argstring": null,
      "serverUUID": "0ce696cd-80a1-422f-9631-2c86d68fca5d",
      "successfulNodes": [
        "remote.rundeck.local"
      ]
    },
    {
      "id": 776747,
      "href": "https://localhost:4440/api/47/execution/776747",
      "permalink": "https://localhost:4440/project/projectName/execution/show/776747",
      "status": "succeeded",
      "project": "projectName",
      "executionType": "scheduled",
      "user": "jgarces",
      "date-started": {
        "unixtime": 1718134770223,
        "date": "2024-06-11T19:39:30Z"
      },
      "date-ended": {
        "unixtime": 1718134781232,
        "date": "2024-06-11T19:39:41Z"
      },
      "job": {
        "id": "9a01189a-359e-4d00-b88d-3b013406bea2",
        "averageDuration": 11184,
        "name": "Kerberos Test (Script)",
        "group": "",
        "project": "projectName",
        "description": "",
        "href": "https://localhost:4440/api/47/job/9a01189a-359e-4d00-b88d-3b013406bea2",
        "permalink": "https://localhost:4440/project/projectName/job/show/9a01189a-359e-4d00-b88d-3b013406bea2"
      },
      "description": "Plugin[script-inline, nodeStep: true]",
      "argstring": null,
      "serverUUID": "0ce696cd-80a1-422f-9631-2c86d68fca5d",
      "successfulNodes": [
        "remote.rundeck.local"
      ]
    }
  ]
}

/api/34/project/<project_name>/executions/metrics?recentFilter=1d

{
  "total": 387,
  "duration": {
    "average": "12s",
    "max": "10m",
    "min": "0s"
  }
}

phsmith commented 2 weeks ago

Great! So, yes, as I said, the errors in the Rundeck logs seem to be something else in the software itself, not something related to the exporter since it only retrieves data from Rundeck API enpoints.

jgarces-pd commented 2 weeks ago

@phsmith there are no SQL errors reported on the logs:

phsmith commented 2 weeks ago

Actually, there is one in the 4th line from bottom to top in the screenshot.

jgarces-pd commented 2 weeks ago

@phsmith you're right!, I will report this to our development team.

I have isolated the issue, and it seems that the endpoint: /api/34/project/<project_name>/executions/metrics?recentFilter=1d Is affected by this issue; the other two don't report any of these errors.

We will investigate if there are other endpoints affected by this. RUN-2580

phsmith / rundeck_exporter

SQL errors in service.log #94