search

grafana / pyroscope

Continuous Profiling Platform. Debug performance issues down to a single line of code
https://grafana.com/oss/pyroscope/
GNU Affero General Public License v3.0
10.13k stars 614 forks source link

Pyroscope UI fails on Node.js cpu profiles #3666

Open madaraszg-tulip opened 2 weeks ago

madaraszg-tulip commented 2 weeks ago

Describe the bug

I started collecting cpu profiles from some services written in Typescript, and when I want to look at them in the UI, it intermittently fails by turning the whole page black, and the following javascript error:

app.e9df57e….js:2 TypeError: i[e.getLabel(...)].push is not a function
    at app.e9df57e….js:69:66536
    at Vj.initLevels (app.e9df57e….js:69:66730)
    at Vj.getCollapsedMap (app.e9df57e….js:69:65990)
    at app.e9df57e….js:47:866
    at oc (app.e9df57e….js:2:1113477)
    at Al (app.e9df57e….js:2:1133422)
    at ll (app.e9df57e….js:2:1125815)
    at Yo (app.e9df57e….js:2:1067057)
    at app.e9df57e….js:2:1132254
    at vl (app.e9df57e….js:2:1132259)
app.e9df57e….js:2 Uncaught TypeError: i[e.getLabel(...)].push is not a function
    at app.e9df57e….js:69:66536
    at Vj.initLevels (app.e9df57e….js:69:66730)
    at Vj.getCollapsedMap (app.e9df57e….js:69:65990)
    at app.e9df57e….js:47:866
    at oc (app.e9df57e….js:2:1113477)
    at Al (app.e9df57e….js:2:1133422)
    at ll (app.e9df57e….js:2:1125815)
    at Yo (app.e9df57e….js:2:1067057)
    at app.e9df57e….js:2:1132254
    at vl (app.e9df57e….js:2:1132259)

Sometimes I can see the profiles, then I change the time window, and then UI fails again.

To Reproduce

Steps to reproduce the behavior:

  1. Start Pyroscope 1.9.1
  2. Collect cpu profiles from a Typescript service using Alloy pull mode (@pyroscope/nodejs v0.4.1)
  3. View cpu profiles for that service in the Pyroscope UI

Expected behavior

I would expect the UI not to fail

Environment

Additional Context

I am using the alloy configuration provided by the helm chart (slightly modified for godeltaprof profiles). The relevant generated pyroscope.scrape config looks like this:

  pyroscope.scrape "pyroscope_scrape_cpu" {
    clustering {
      enabled = true
    }

    targets    = concat(discovery.relabel.kubernetes_pods_cpu_default_name.output, discovery.relabel.kubernetes_pods_cpu_custom_name.output)
    forward_to = [pyroscope.write.pyroscope_write.receiver]

    profiling_config {
      profile.memory {
        enabled = false
      }

      profile.process_cpu {
        enabled = true
      }

      profile.goroutine {
        enabled = false
      }

      profile.block {
        enabled = false
      }

      profile.mutex {
        enabled = false
      }

      profile.fgprof {
        enabled = false
      }

      profile.godeltaprof_memory {
        enabled = false
      }

      profile.godeltaprof_mutex {
        enabled = false
      }

      profile.godeltaprof_block {
        enabled = false
      }
    }

The logs of Alloy are clean, and so is the debug page for this component.

Logs from query-frontend:

2024-11-06 11:08:56.410 
ts=2024-11-06T10:08:56.410226154Z caller=http.go:252 level=debug traceID=721726c758ece00d783453e5b01a366f method=GET uri="/?query=process_cpu%3Awall%3Ananoseconds%3Awall%3Ananoseconds%7Bservice_name%3D%22default%2Fpartitionmanager%22%7D&from=now-30m" status=200 duration=71.628µs msg="http request processed"
2024-11-06 11:08:56.738 
ts=2024-11-06T10:08:56.737899631Z caller=http.go:252 level=debug traceID=bbf206d37c6a96d6170bf891ed70607f method=GET uri=/assets/app.e9df57e4b72c8bbf2d0a.js status=200 duration=96.982676ms msg="http request processed"
2024-11-06 11:08:56.809 
ts=2024-11-06T10:08:56.809823116Z caller=http.go:252 level=debug traceID=d8ec8fa7a51ce1c206f84621e15f4fc8 method=GET uri=/assets/app.9775dae14dc1e26e3bad.css status=200 duration=3.074209ms msg="http request processed"
2024-11-06 11:08:58.093 
ts=2024-11-06T10:08:58.09364733Z caller=interceptor.go:66 level=info msg="request parameters" route=/querier.v1.QuerierService/LabelNames tenant=anonymous traceID=5b2357b3cde998db3d827d46ec981166 duration=2.672889ms
2024-11-06 11:08:58.093 
ts=2024-11-06T10:08:58.093916697Z caller=http.go:252 level=debug traceID=5b2357b3cde998db3d827d46ec981166 orgID=anonymous method=POST uri=/frontendpb.FrontendForQuerier/QueryResult status=200 duration=467.284µs request_body_size=128B msg="http request processed"
2024-11-06 11:08:58.094 
ts=2024-11-06T10:08:58.094256497Z caller=http.go:252 level=debug traceID=5b2357b3cde998db3d827d46ec981166 method=POST uri=/querier.v1.QuerierService/LabelNames status=200 duration=3.37899ms request_body_size=43B msg="http request processed"
2024-11-06 11:08:58.115 
ts=2024-11-06T10:08:58.115733744Z caller=interceptor.go:66 level=info msg="request parameters" route=/querier.v1.QuerierService/Series tenant=anonymous traceID=1ebf4e89f71ec18033413810e44da84e duration=7.257271ms
2024-11-06 11:08:58.116 
ts=2024-11-06T10:08:58.116425209Z caller=http.go:252 level=debug traceID=1ebf4e89f71ec18033413810e44da84e method=POST uri=/querier.v1.QuerierService/Series status=200 duration=8.050411ms request_body_size=144B msg="http request processed"
2024-11-06 11:08:58.116 
ts=2024-11-06T10:08:58.116621689Z caller=http.go:252 level=debug traceID=1ebf4e89f71ec18033413810e44da84e orgID=anonymous method=POST uri=/frontendpb.FrontendForQuerier/QueryResult status=200 duration=1.158236ms request_body_size=1.2KiB msg="http request processed"
2024-11-06 11:08:58.130 
ts=2024-11-06T10:08:58.130813984Z caller=http.go:252 level=debug traceID=d072f3a5165d335a9432132e16a6bffd method=GET uri=/assets/favicon.ico status=200 duration=576.124µs msg="http request processed"
2024-11-06 11:08:58.361 
ts=2024-11-06T10:08:58.361479282Z caller=interceptor.go:66 level=info msg="request parameters" route=/querier.v1.QuerierService/LabelNames tenant=anonymous traceID=457be43dec61c0a7edd5d0711b4764cf duration=3.77622ms
2024-11-06 11:08:58.361 
ts=2024-11-06T10:08:58.361682315Z caller=http.go:252 level=debug traceID=457be43dec61c0a7edd5d0711b4764cf method=POST uri=/querier.v1.QuerierService/LabelNames status=200 duration=4.08725ms request_body_size=170B msg="http request processed"
2024-11-06 11:08:58.361 
ts=2024-11-06T10:08:58.361807344Z caller=http.go:252 level=debug traceID=457be43dec61c0a7edd5d0711b4764cf orgID=anonymous method=POST uri=/frontendpb.FrontendForQuerier/QueryResult status=200 duration=553.524µs request_body_size=299B msg="http request processed"
2024-11-06 11:08:58.380 
ts=2024-11-06T10:08:58.380260798Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/frontendpb.FrontendForQuerier/QueryResult status=200 duration=442.238µs request_body_size=4.7KiB msg="http request processed"
2024-11-06 11:08:58.381 
ts=2024-11-06T10:08:58.381591537Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/frontendpb.FrontendForQuerier/QueryResult status=200 duration=451.881µs request_body_size=6.7KiB msg="http request processed"
2024-11-06 11:08:58.383 
ts=2024-11-06T10:08:58.383308442Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/frontendpb.FrontendForQuerier/QueryResult status=200 duration=1.403814ms request_body_size=2.2KiB msg="http request processed"
2024-11-06 11:08:58.383 
ts=2024-11-06T10:08:58.383525664Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 method=GET uri="/pyroscope/render?query=process_cpu%3Awall%3Ananoseconds%3Awall%3Ananoseconds%7Bservice_name%3D%22default%2Fpartitionmanager%22%7D&from=now-30m&until=now&aggregation=sum&format=json" status=200 duration=20.947786ms msg="http request processed"
2024-11-06 11:09:00.201 
ts=2024-11-06T10:09:00.201646355Z caller=frontend_scheduler_worker.go:360 level=debug component=frontend msg="stream context finished" err="context canceled"
2024-11-06 11:09:00.485 
ts=2024-11-06T10:09:00.485202263Z caller=frontend_scheduler_worker.go:360 level=debug component=frontend msg="stream context finished" err="context canceled"

Logs from query-scheduler:

2024-11-06 11:08:56.429 
ts=2024-11-06T10:08:56.428915327Z caller=http.go:252 level=debug traceID=62be386e18d4c19d method=POST uri=/schedulerpb.SchedulerForQuerier/QuerierLoop status=200 duration=20.129472685s request_body_size=49B msg="http request processed"
2024-11-06 11:08:59.687 
ts=2024-11-06T10:08:59.687682735Z caller=http.go:252 level=debug traceID=50b47a19e9ca1e5e method=POST uri=/schedulerpb.SchedulerForQuerier/QuerierLoop status=200 duration=21.277098465s request_body_size=54B msg="http request processed"
2024-11-06 11:09:00.202 
ts=2024-11-06T10:09:00.202066821Z caller=http.go:252 level=debug traceID=24745defda4fe88d method=POST uri=/schedulerpb.SchedulerForFrontend/FrontendLoop status=200 duration=24.835525511s request_body_size=1.7KiB msg="http request processed"
2024-11-06 11:09:00.485 
ts=2024-11-06T10:09:00.48557242Z caller=http.go:252 level=debug traceID=3b82f2bda76b81f1 method=POST uri=/schedulerpb.SchedulerForFrontend/FrontendLoop status=200 duration=23.980555638s request_body_size=1.4KiB msg="http request processed"
2024-11-06 11:09:00.661 
ts=2024-11-06T10:09:00.660602105Z caller=http.go:252 level=debug traceID=4eefbbdab020b90a method=POST uri=/schedulerpb.SchedulerForQuerier/QuerierLoop status=200 duration=21.811866677s request_body_size=59B msg="http request processed"

Logs from querier:

2024-11-06 11:08:56.427 
ts=2024-11-06T10:08:56.42788724Z caller=scheduler_processor.go:152 level=debug component=querier-worker msg="waiting for inflight queries to complete"
2024-11-06 11:08:56.428 
ts=2024-11-06T10:08:56.427914677Z caller=scheduler_processor.go:163 level=debug component=querier-worker msg="refreshing scheduler connection"
2024-11-06 11:08:58.109 
ts=2024-11-06T10:08:58.109358714Z caller=spanlogger.go:109 component=querier user=anonymous traceID=1ebf4e89f71ec18033413810e44da84e level=debug msg=storeQueries queryStoreAfter=4h0m0s ingester=true ingester.start=2024-11-06T09:38:57.949Z ingester.end=2024-11-06T10:08:57.949Z store-gateway=false store-gateway.start=1970-01-01T00:00:00Z store-gateway.end=1970-01-01T00:00:00Z
2024-11-06 11:08:58.358 
ts=2024-11-06T10:08:58.358537889Z caller=spanlogger.go:109 component=querier user=anonymous traceID=457be43dec61c0a7edd5d0711b4764cf level=debug msg=storeQueries queryStoreAfter=4h0m0s ingester=true ingester.start=2024-11-06T09:38:58.274Z ingester.end=2024-11-06T10:08:58.274Z store-gateway=false store-gateway.start=1970-01-01T00:00:00Z store-gateway.end=1970-01-01T00:00:00Z
2024-11-06 11:08:58.364 
ts=2024-11-06T10:08:58.364001644Z caller=spanlogger.go:109 component=querier user=anonymous traceID=2f7cc680bdc25d316756327c98eab837 level=info start="2024-11-06 09:38:58.362 +0000 UTC" end="2024-11-06 09:59:59.999 +0000 UTC" selector="{service_name=\"default/partitionmanager\"}" profile_id=process_cpu:wall:nanoseconds:wall:nanoseconds
2024-11-06 11:08:58.364 
ts=2024-11-06T10:08:58.364723392Z caller=spanlogger.go:109 component=querier user=anonymous traceID=2f7cc680bdc25d316756327c98eab837 level=info start="2024-11-06 10:00:00 +0000 UTC" end="2024-11-06 10:08:58.362 +0000 UTC" selector="{service_name=\"default/partitionmanager\"}" profile_id=process_cpu:wall:nanoseconds:wall:nanoseconds
2024-11-06 11:08:58.369 
ts=2024-11-06T10:08:58.369057574Z caller=spanlogger.go:109 component=querier user=anonymous traceID=2f7cc680bdc25d316756327c98eab837 level=debug msg="block plan created" deduplicate=true smallest_compaction_level=0 planned_blocks_ingesters=4 planned_blocks_store_gateways=0 plan="{\"10.19.240.90:4040\":{\"ulids\":[\"01JC0ENBC6N1DEW7R1NEKPFZG8\",\"01JC0B7FR73PVM094P5EH1GNAQ\"],\"deduplication\":true,\"InstanceTypes\":\"AQ==\"},\"10.19.244.52:4040\":{\"ulids\":[\"01JC0ENBC60WFDBHCW38GXS5Y2\",\"01JC0B7FR54TYWSY71SXFPA82D\"],\"deduplication\":true,\"InstanceTypes\":\"AQ==\"}}"
2024-11-06 11:08:58.369 
ts=2024-11-06T10:08:58.369359808Z caller=spanlogger.go:109 component=querier user=anonymous traceID=2f7cc680bdc25d316756327c98eab837 level=debug msg="block plan created" deduplicate=true smallest_compaction_level=0 planned_blocks_ingesters=2 planned_blocks_store_gateways=0 plan="{\"10.19.243.160:4040\":{\"ulids\":[\"01JC0ENBC71V2ST6JQZVVE9ZG3\"],\"deduplication\":true,\"InstanceTypes\":\"AQ==\"},\"10.19.244.52:4040\":{\"ulids\":[\"01JC0ENBC60WFDBHCW38GXS5Y2\"],\"deduplication\":true,\"InstanceTypes\":\"AQ==\"}}"
2024-11-06 11:08:58.369 
ts=2024-11-06T10:08:58.369439436Z caller=spanlogger.go:109 component=querier user=anonymous traceID=2f7cc680bdc25d316756327c98eab837 level=debug msg=storeQueries queryStoreAfter=0s ingester=true ingester.start=2024-11-06T10:00:00Z ingester.end=2024-11-06T10:08:58.362Z store-gateway=true store-gateway.start=2024-11-06T10:00:00Z store-gateway.end=2024-11-06T10:08:58.362Z
2024-11-06 11:08:58.370 
ts=2024-11-06T10:08:58.370517629Z caller=spanlogger.go:109 component=querier user=anonymous traceID=2f7cc680bdc25d316756327c98eab837 level=debug msg="block plan created" deduplicate=true smallest_compaction_level=0 planned_blocks_ingesters=2 planned_blocks_store_gateways=0 plan="{\"10.19.240.90:4040\":{\"ulids\":[\"01JC0B7FR73PVM094P5EH1GNAQ\"],\"deduplication\":true,\"InstanceTypes\":\"AQ==\"},\"10.19.243.160:4040\":{\"ulids\":[\"01JC0B7FR51VKDFW45BWD0VE17\"],\"deduplication\":true,\"InstanceTypes\":\"AQ==\"}}"
2024-11-06 11:08:58.372 
ts=2024-11-06T10:08:58.370573706Z caller=spanlogger.go:109 component=querier user=anonymous traceID=2f7cc680bdc25d316756327c98eab837 level=debug msg=storeQueries queryStoreAfter=0s ingester=true ingester.start=2024-11-06T09:38:58.362Z ingester.end=2024-11-06T09:59:59.999Z store-gateway=true store-gateway.start=2024-11-06T09:38:58.362Z store-gateway.end=2024-11-06T09:59:59.999Z
2024-11-06 11:08:59.686 
ts=2024-11-06T10:08:59.68652516Z caller=scheduler_processor.go:152 level=debug component=querier-worker msg="waiting for inflight queries to complete"
2024-11-06 11:08:59.686 
ts=2024-11-06T10:08:59.686561215Z caller=scheduler_processor.go:163 level=debug component=querier-worker msg="refreshing scheduler connection"
2024-11-06 11:09:00.660 
ts=2024-11-06T10:09:00.66012828Z caller=scheduler_processor.go:152 level=debug component=querier-worker msg="waiting for inflight queries to complete"
2024-11-06 11:09:00.661 
ts=2024-11-06T10:09:00.66016141Z caller=scheduler_processor.go:163 level=debug component=querier-worker msg="refreshing scheduler connection"

Logs from ingester:

2024-11-06 11:08:58.092 
ts=2024-11-06T10:08:58.092512Z caller=http.go:252 level=debug traceID=5b2357b3cde998db3d827d46ec981166 orgID=anonymous method=POST uri=/ingester.v1.IngesterService/LabelNames status=200 duration=182.356µs request_body_size=26B msg="http request processed"
2024-11-06 11:08:58.112 
ts=2024-11-06T10:08:58.112281844Z caller=http.go:252 level=debug traceID=1ebf4e89f71ec18033413810e44da84e orgID=anonymous method=POST uri=/ingester.v1.IngesterService/Series status=200 duration=1.888725ms request_body_size=81B msg="http request processed"
2024-11-06 11:08:58.114 
ts=2024-11-06T10:08:58.114389921Z caller=http.go:252 level=debug traceID=1ebf4e89f71ec18033413810e44da84e orgID=anonymous method=POST uri=/ingester.v1.IngesterService/Series status=200 duration=1.847554ms request_body_size=81B msg="http request processed"
2024-11-06 11:08:58.359 
ts=2024-11-06T10:08:58.359583518Z caller=http.go:252 level=debug traceID=457be43dec61c0a7edd5d0711b4764cf orgID=anonymous method=POST uri=/ingester.v1.IngesterService/LabelNames status=200 duration=388.815µs request_body_size=123B msg="http request processed"
2024-11-06 11:08:58.360 
ts=2024-11-06T10:08:58.36040138Z caller=http.go:252 level=debug traceID=457be43dec61c0a7edd5d0711b4764cf orgID=anonymous method=POST uri=/ingester.v1.IngesterService/LabelNames status=200 duration=318.988µs request_body_size=123B msg="http request processed"
2024-11-06 11:08:58.367 
ts=2024-11-06T10:08:58.367290213Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/ingester.v1.IngesterService/BlockMetadata status=200 duration=78.983µs request_body_size=14B msg="http request processed"
2024-11-06 11:08:58.367 
ts=2024-11-06T10:08:58.367536563Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/ingester.v1.IngesterService/BlockMetadata status=200 duration=298.687µs request_body_size=14B msg="http request processed"
2024-11-06 11:08:58.367 
ts=2024-11-06T10:08:58.36774544Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/ingester.v1.IngesterService/BlockMetadata status=200 duration=274.465µs request_body_size=14B msg="http request processed"
2024-11-06 11:08:58.368 
ts=2024-11-06T10:08:58.368107131Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/ingester.v1.IngesterService/BlockMetadata status=200 duration=70.187µs request_body_size=14B msg="http request processed"
2024-11-06 11:08:58.368 
ts=2024-11-06T10:08:58.367853423Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/ingester.v1.IngesterService/BlockMetadata status=200 duration=184.04µs request_body_size=14B msg="http request processed"
2024-11-06 11:08:58.368 
ts=2024-11-06T10:08:58.368490647Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/ingester.v1.IngesterService/BlockMetadata status=200 duration=187.753µs request_body_size=14B msg="http request processed"
2024-11-06 11:08:58.373 
ts=2024-11-06T10:08:58.373743801Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/ingester.v1.IngesterService/MergeProfilesStacktraces status=200 duration=2.767859ms request_body_size=269B msg="http request processed"
2024-11-06 11:08:58.377 
ts=2024-11-06T10:08:58.37779722Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/ingester.v1.IngesterService/MergeProfilesStacktraces status=200 duration=7.860761ms request_body_size=269B msg="http request processed"
2024-11-06 11:08:58.378 
ts=2024-11-06T10:08:58.378412951Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/ingester.v1.IngesterService/MergeProfilesLabels status=200 duration=2.964812ms request_body_size=438B msg="http request processed"
2024-11-06 11:08:58.379 
ts=2024-11-06T10:08:58.379551572Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/ingester.v1.IngesterService/MergeProfilesLabels status=200 duration=6.697281ms request_body_size=438B msg="http request processed"
2024-11-06 11:08:58.380 
ts=2024-11-06T10:08:58.379936521Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/ingester.v1.IngesterService/MergeProfilesStacktraces status=200 duration=4.270521ms request_body_size=350B msg="http request processed"
2024-11-06 11:08:58.380 
ts=2024-11-06T10:08:58.380555771Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/ingester.v1.IngesterService/MergeProfilesStacktraces status=200 duration=5.305908ms request_body_size=350B msg="http request processed"
2024-11-06 11:09:01.431 
ts=2024-11-06T10:09:01.431654433Z caller=log.go:245 level=debug msg="Stream connection from=10.19.252.102:58266"
2024-11-06 11:09:02.393 
ts=2024-11-06T10:09:02.393059141Z caller=log.go:245 level=debug msg="Stream connection from=10.19.246.247:41636"

Logs from store-gateway:

2024-11-06 11:08:58.365 
ts=2024-11-06T10:08:58.365743263Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/storegateway.v1.StoreGatewayService/BlockMetadata status=200 duration=201.71µs request_body_size=14B msg="http request processed"
2024-11-06 11:08:58.365 
ts=2024-11-06T10:08:58.365881346Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/storegateway.v1.StoreGatewayService/BlockMetadata status=200 duration=346.685µs request_body_size=14B msg="http request processed"
2024-11-06 11:08:58.366 
ts=2024-11-06T10:08:58.366049374Z caller=http.go:252 level=debug traceID=2f7cc680bdc25d316756327c98eab837 orgID=anonymous method=POST uri=/storegateway.v1.StoreGatewayService/BlockMetadata status=200 duration=643.714µs request_body_size=14B msg="http request processed"