Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

error data input for date(CAST(value AS DATETIME)) causing high TiFlash sys CPU #5097

Closed
dbsid opened this issue Jun 9, 2022 · 5 comments · Fixed by #5477
Closed

error data input for date(CAST(value AS DATETIME)) causing high TiFlash sys CPU #5097

dbsid opened this issue Jun 9, 2022 · 5 comments · Fixed by #5477

Comments

@dbsid
Copy link

dbsid commented Jun 9, 2022

Bug Report

Please answer these questions before submitting your issue. Thanks!

1. Minimal reproduce step (Required)

run a query include date(CAST(rv_EndDateTime.value AS DATETIME)), and make wrong input for the cast function. TiFlash need to do exception handle and capture the unwind(stack) information, which explain the high sys cpu.

with date(CAST(rv_EndDateTime.value AS DATETIME)), the query takes over 10 minutes, and causing TiFlash high sys CPU.
without date(CAST(rv_EndDateTime.value AS DATETIME)), the query take around 300 ms.

SELECT
  id,
  module_id,
  rel_namespace,
  owned_by,
  created_by,
  updated_by,
  deleted_by,
  created_at,
  updated_at,
  deleted_at
FROM
  (
    SELECT
      crd.id,
      crd.module_id,
      crd.rel_namespace,
      crd.owned_by,
      crd.created_by,
      crd.updated_by,
      crd.deleted_by,
      crd.created_at,
      crd.updated_at,
      crd.deleted_at,
      row_number() over (PARTITION by id) AS pp_rn
    FROM
      compose_record AS crd
      LEFT JOIN compose_record_value AS rv_ActivityDate ON (
        rv_ActivityDate.record_id = crd.id
        AND rv_ActivityDate.name = 'ActivityDate'
        AND rv_ActivityDate.deleted_at IS NULL
      )
      LEFT JOIN compose_record_value AS rv_EndDateTime ON (
        rv_EndDateTime.record_id = crd.id
        AND rv_EndDateTime.name = 'EndDateTime'
        AND rv_EndDateTime.deleted_at IS NULL
      )
      LEFT JOIN compose_record_value AS rv_Type ON (
        rv_Type.record_id = crd.id
        AND rv_Type.name = 'Type'
        AND rv_Type.deleted_at IS NULL
      )
    WHERE
      crd.module_id = 287514257044686682
      AND crd.rel_namespace = 287514254259603290
      AND crd.deleted_at IS NULL
      AND (
        (
          date(CAST(rv_ActivityDate.value AS DATETIME)) <= '2022-07-10T16:00:00.000Z'
          AND '2022-05-29T16:00:00.000Z' <= date(CAST(rv_EndDateTime.value AS DATETIME))
        )
        AND (rv_Type.value IS NULL)
      )
    ORDER BY
      id ASC
  ) AS base
WHERE
  pp_rn = 1
LIMIT
  501;

2. What did you expect to see? (Required)

no high cpu

3. What did you see instead (Required)

high TiFlash sys CPU

image

origin_img_v2_28c59784-5f72-4a54-b55b-49761f35a89g

origin_img_v2_0d0daa81-3a5f-4ef5-8a27-e72ca8533a3g

origin_img_v2_5afbd5d3-4ea4-45de-87fc-ecf296c8c96g

4. What is your TiFlash version? (Required)

v6.1

@dbsid dbsid added the type/bug The issue is confirmed as a bug. label Jun 9, 2022
@zanmato1984
Copy link
Contributor

We should avoid using exception to pass error during function evaluation. We'd rather use return value to do that.

@fuzhe1989
Copy link
Contributor

@zanmato1984 before achieving this, how about not print stacktrace for normal exceptions (only let BaseDaemon print stacetrace)? Such information is almost useless for debuging if we print enough logs at the throw points.

@windtalker
Copy link
Contributor

@zanmato1984 before achieving this, how about not print stacktrace for normal exceptions (only let BaseDaemon print stacetrace)? Such information is almost useless for debuging if we print enough logs at the throw points.

But here we don't print the stacktrace, it is the stack unwind that causes the hight sys cpu usage.

@fuzhe1989
Copy link
Contributor

@windtalker Yes that's what I meant, not print here also means not to unwind.

@fuzhe1989
Copy link
Contributor

@windtalker FYI, stacktrace unwind is disabled by default in my previous team (only enabled for fatal errors).

ti-chi-bot pushed a commit that referenced this issue Aug 11, 2022
xzhangxian1008 added a commit to xzhangxian1008/tiflash that referenced this issue Nov 16, 2022
ti-chi-bot pushed a commit that referenced this issue Nov 17, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
4 participants