wakatime / jetbrains-wakatime

IntelliJ IDEA, PyCharm, RubyMine, PhpStorm, AppCode, AndroidStudio, Goland, Rider, & WebStorm plugin for quantifying your coding.
https://wakatime.com/intellij-idea
BSD 3-Clause "New" or "Revised" License
1.15k stars 168 forks source link

Cant send data to wakatime api server #234

Closed counter2015 closed 2 years ago

counter2015 commented 2 years ago

My wakatime dashboard time cant be collected for serval days, here is the log. How to fix this?

Environment: IDEA 2022.2.3 wakatime plugins 14.1.1

wakatime.log

{"caller":"pkg/api/heartbeat.go:27","func":"api.(*Client)","level":"debug","message":"sending 1 heartbeat(s) to api at https://api.wakatime.com/api/v1/users/current/heartbeats.bulk","now":"2022-10-18T11:16:01+08:00","version":"v1.55.2"}
{"caller":"pkg/api/heartbeat.go:52","func":"api.(*Client)","level":"debug","message":"heartbeats: [{\"branch\":\"master\",\"category\":\"coding\",\"cursorpos\":null,\"dependencies\":[\"akka.actor.typed.ActorRef\",\"akka.cluster.sharding.typed.scaladsl\",\"akka.util.Timeout\",\"com.google.protobuf.struct.Value\",\"com.mesoor.platform.cqrs.projection\",\"com.mesoor.platform.cqrs.EntityLocator\",\"com.mesoor.platform.models.v2\",\"com.mesoor.platform.spec.json_patch.JsonPatchSpec\",\"com.mesoor.platform.transmitter.cqrs.extension.ProtoTracing\",\"com.mesoor.platform.models.DomainErrors\",\"com.mesoor.platform.transmitter.layers.ConfigLayer\",\"com.mesoor.platform.transmitter.proto.v2\",\"com.mesoor.platform.transmitter.services.grpc.PoolServiceV2\",\"com.mesoor.platform.utils.ProtoStructCodec\",\"com.mesoor.platform.utils.Tracing.RichSingleResponseRequestBuilder\",\"com.mesoor.platform.utils\",\"io.circe.Json\",\"io.circe.syntax.EncoderOps\",\"io.opentelemetry.api.OpenTelemetry\",\"io.opentelemetry.context.propagation.TextMapPropagator\",\"zio.telemetry.opentelemetry.Tracing\",\"zio.telemetry.opentelemetry.TracingSyntax\",\"zio\",\"scala.concurrent.duration.DurationInt\"],\"entity\":\"/Users/counter/dev/transmitter/core/src/main/scala/com/mesoor/platform/transmitter/services/http/routes/v2/TransmitterService.scala\",\"type\":\"file\",\"is_write\":null,\"language\":\"Scala\",\"lineno\":null,\"lines\":633,\"project\":\"transmitter\",\"time\":1666062935.558,\"user_agent\":\"wakatime/v1.55.2 (darwin-21.6.0-x86_64) go1.19.1 idea/2022.2.3 idea-wakatime/14.1.1\"}]","now":"2022-10-18T11:16:01+08:00","version":"v1.55.2"}
{"caller":"pkg/backoff/backoff.go:54","func":"backoff.WithBackoff","level":"debug","message":"incrementing backoff due to error","now":"2022-10-18T11:17:01+08:00","version":"v1.55.2"}
{"caller":"pkg/offline/offline.go:65","func":"offline.WithQueue","level":"debug","message":"pushing 1 heartbeat(s) to queue due to error","now":"2022-10-18T11:17:01+08:00","version":"v1.55.2"}
{"caller":"cmd/run.go:270","func":"cmd.runCmd","level":"error","message":"failed to run command: sending heartbeat(s) later due to api error: failed making request to \"https://api.wakatime.com/api/v1/users/current/heartbeats.bulk\": Post \"https://api.wakatime.com/api/v1/users/current/heartbeats.bulk\": proxyconnect tcp: tls: first record does not look like a TLS handshake","now":"2022-10-18T11:17:01+08:00","version":"v1.55.2"}
{"caller":"pkg/api/diagnostic.go:28","func":"api.(*Client)","level":"debug","message":"sending diagnostic data to api at https://api.wakatime.com/api/v1/plugins/errors","now":"2022-10-18T11:17:01+08:00","version":"v1.55.2"}
{"caller":"cmd/run.go:276","func":"cmd.runCmd","level":"warning","message":"failed to send diagnostics: failed to send diagnostics to the API: failed making request to \"https://api.wakatime.com/api/v1/plugins/errors\": Post \"https://api.wakatime.com/api/v1/plugins/errors\": proxyconnect tcp: tls: first record does not look like a TLS handshake","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"cmd/run.go:105","func":"cmd.Run","level":"debug","message":"command: heartbeat","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"cmd/heartbeat/heartbeat.go:91","func":"heartbeat.SendHeartbeats","level":"debug","message":"params: api params: (api key: '<hidden>ca6e', api url: 'https://api.wakatime.com/api/v1', backoff at: '2022-10-18T11:17:01+08:00', backoff retries: 5, hostname: 'counters-MacBook-Pro.local', key patterns: '[]', plugin: 'idea/2022.2.3 idea-wakatime/14.1.1', proxy url: 'https://127.0.0.1:1087', timeout: 2m0s, disable ssl verify: false, ssl cert filepath: ''), heartbeat params: (category: 'coding', cursor position: '', entity: '/Users/counter/dev/transmitter/core/src/main/scala/com/mesoor/platform/transmitter/services/http/routes/v2/TransmitterService.scala', entity type: 'file', num extra heartbeats: 0, is unsaved entity: false, is write: true, language: '', line number: '', lines in file: '634', time: 1666062979.32400, filter params: (exclude: '[]', exclude unknown project: false, include: '[]', include only with project file: false), project params: (alternate: 'transmitter', branch alternate: '', disable submodule: '[]', map patterns: '[]', override: ''), sanitize params: (hide branch names: '[]', hide project folder: false, hide file names: '[]', hide project names: '[]', project path override: '')), offline params: (disabled: false, print max: 10, queue file: '', num sync max: 1000), status bar params: (hide categories: false)","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/heartbeat/format.go:18","func":"heartbeat.WithFormatting","level":"debug","message":"execute heartbeat filepath formatting","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/heartbeat/entity_modify.go:15","func":"heartbeat.WithEntityModifer","level":"debug","message":"execute heartbeat entity modifier","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/filter/filter.go:26","func":"filter.WithFiltering","level":"debug","message":"execute heartbeat filtering","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/remote/remote.go:49","func":"remote.WithDetection","level":"debug","message":"execute remote file detection","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/apikey/apikey.go:31","func":"apikey.WithReplacing","level":"debug","message":"execute api key replacing","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/filestats/filestats.go:23","func":"filestats.WithDetection","level":"debug","message":"execute filestats detection","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/language/language.go:19","func":"language.WithDetection","level":"debug","message":"execute language detection","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/deps/deps.go:38","func":"deps.WithDetection","level":"debug","message":"execute dependency detection","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:126","func":"project.WithDetection","level":"debug","message":"execute project detection for: /Users/counter/dev/transmitter/core/src/main/scala/com/mesoor/platform/transmitter/services/http/routes/v2/TransmitterService.scala","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:213","func":"project.Detect","level":"debug","message":"execute project-file-detector","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:213","func":"project.Detect","level":"debug","message":"execute project-map-detector","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:254","func":"project.DetectWithRevControl","level":"debug","message":"execute git-detector","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/project/filter.go:23","func":"project.WithFiltering","level":"debug","message":"execute project filtering","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/heartbeat/sanitize.go:30","func":"heartbeat.WithSanitization","level":"debug","message":"execute heartbeat sanitization","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/remote/remote.go:113","func":"remote.WithCleanup","level":"debug","message":"execute remote cleanup","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/offline/offline.go:55","func":"offline.WithQueue","level":"debug","message":"execute offline queue with file /Users/counter/.wakatime.bdb","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/backoff/backoff.go:41","func":"backoff.WithBackoff","level":"debug","message":"execute heartbeat backoff algorithm","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/backoff/backoff.go:97","func":"backoff.shouldBackoff","level":"debug","message":"exponential backoff tried 5 times since Oct 18 11:17:01, will retry at Oct 18 11:25:01","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"pkg/offline/offline.go:65","func":"offline.WithQueue","level":"debug","message":"pushing 1 heartbeat(s) to queue due to error","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}
{"caller":"cmd/run.go:270","func":"cmd.runCmd","level":"error","message":"failed to run command: sending heartbeat(s) later because currently rate limited: won't send heartbeat due to backoff","now":"2022-10-18T11:18:01+08:00","version":"v1.55.2"}

idea.log

2022-10-18 11:16:17,559 [1187384]   FINE - WakaTime - visibleAreaChanged event
2022-10-18 11:16:17,576 [1187401]   FINE - WakaTime - visibleAreaChanged event
2022-10-18 11:16:17,592 [1187417]   FINE - WakaTime - visibleAreaChanged event
2022-10-18 11:16:18,042 [1187867]   FINE - WakaTime - visibleAreaChanged event
2022-10-18 11:16:18,059 [1187884]   FINE - WakaTime - visibleAreaChanged event
2022-10-18 11:16:18,076 [1187901]   FINE - WakaTime - visibleAreaChanged event
2022-10-18 11:16:18,092 [1187917]   FINE - WakaTime - visibleAreaChanged event
2022-10-18 11:16:18,126 [1187951]   FINE - WakaTime - visibleAreaChanged event
2022-10-18 11:16:18,142 [1187967]   FINE - WakaTime - visibleAreaChanged event
2022-10-18 11:16:19,324 [1189149]   FINE - WakaTime - beforeDocumentSaving event
2022-10-18 11:16:19,325 [1189150]   FINE - WakaTime - documentChangedNonBulk event
2022-10-18 11:18:01,694 [1291519]   FINE - WakaTime - Command finished with return value: 102
2022-10-18 11:18:01,694 [1291519]   INFO - WakaTime - built-in proxy will be used: https://127.0.0.1:1087
2022-10-18 11:18:01,695 [1291520]   FINE - WakaTime - Executing CLI: [/Users/counter/.wakatime/wakatime-cli-darwin-amd64, --entity, /Users/counter/dev/transmitter/core/src/main/scala/com/mesoor/platform/transmitter/services/http/routes/v2/TransmitterService.scala, --time, 1666062979.3240, --key, XXXXXXXX-XXXX-XXXX-XXXX-XXXXXXXXca6e, --lines-in-file, 634, --alternate-project, transmitter, --alternate-language, Scala, --plugin, idea/2022.2.3 idea-wakatime/14.1.1, --write, --proxy, https://127.0.0.1:1087]
2022-10-18 11:18:01,806 [1291631]   FINE - WakaTime - Command finished with return value: 112
2022-10-18 11:20:09,268 [1419093]   INFO - #c.i.c.ComponentStoreImpl - Saving appApplicationCodeStyleSettingsMigration took 20 ms
alanhamlett commented 2 years ago

The error message:

proxyconnect tcp: tls: first record does not look like a TLS handshake

Do you have a proxy defined in your IDE or your ~/.wakatime.cfg file?

counter2015 commented 2 years ago

yes, I use IDE behind proxy, and I found another rate limited message in log after restart IDE.

{"caller":"cmd/run.go:75","func":"cmd.Run","level":"debug","message":"command: version","now":"2022-10-18T13:51:49+08:00","version":"v1.55.2"}
{"caller":"cmd/run.go:93","func":"cmd.Run","level":"debug","message":"command: today","now":"2022-10-18T13:51:56+08:00","version":"v1.55.2"}
{"caller":"cmd/today/today.go:30","func":"today.Run","level":"debug","message":"successfully fetched today for status bar","now":"2022-10-18T13:51:57+08:00","version":"v1.55.2"}
{"caller":"cmd/run.go:105","func":"cmd.Run","level":"debug","message":"command: heartbeat","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"cmd/heartbeat/heartbeat.go:91","func":"heartbeat.SendHeartbeats","level":"debug","message":"params: api params: (api key: '<hidden>ca6e', api url: 'https://api.wakatime.com/api/v1', backoff at: '2022-10-18T13:47:34+08:00', backoff retries: 5, hostname: 'counters-MacBook-Pro.local', key patterns: '[]', plugin: 'idea/2022.2.3 idea-wakatime/14.1.1', proxy url: 'https://127.0.0.1:1087', timeout: 2m0s, disable ssl verify: false, ssl cert filepath: ''), heartbeat params: (category: 'coding', cursor position: '', entity: '/Users/counter/dev/transmitter/schema-registry/src/main/scala/com/mesoor/platform/schema_registry/routes/v2/dev_tool/Check.scala', entity type: 'file', num extra heartbeats: 3, is unsaved entity: false, is write: false, language: '', line number: '', lines in file: '68', time: 1666072316.96700, filter params: (exclude: '[]', exclude unknown project: false, include: '[]', include only with project file: false), project params: (alternate: 'transmitter', branch alternate: '', disable submodule: '[]', map patterns: '[]', override: ''), sanitize params: (hide branch names: '[]', hide project folder: false, hide file names: '[]', hide project names: '[]', project path override: '')), offline params: (disabled: false, print max: 10, queue file: '', num sync max: 1000), status bar params: (hide categories: false)","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"cmd/heartbeat/heartbeat.go:179","func":"heartbeat.buildHeartbeats","level":"debug","message":"include 3 extra heartbeat(s) from stdin","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/heartbeat/format.go:18","func":"heartbeat.WithFormatting","level":"debug","message":"execute heartbeat filepath formatting","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/heartbeat/entity_modify.go:15","func":"heartbeat.WithEntityModifer","level":"debug","message":"execute heartbeat entity modifier","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/filter/filter.go:26","func":"filter.WithFiltering","level":"debug","message":"execute heartbeat filtering","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/remote/remote.go:49","func":"remote.WithDetection","level":"debug","message":"execute remote file detection","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/apikey/apikey.go:31","func":"apikey.WithReplacing","level":"debug","message":"execute api key replacing","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/filestats/filestats.go:23","func":"filestats.WithDetection","level":"debug","message":"execute filestats detection","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/language/language.go:19","func":"language.WithDetection","level":"debug","message":"execute language detection","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/deps/deps.go:38","func":"deps.WithDetection","level":"debug","message":"execute dependency detection","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:126","func":"project.WithDetection","level":"debug","message":"execute project detection for: /Users/counter/dev/transmitter/schema-registry/src/main/scala/com/mesoor/platform/schema_registry/routes/v2/dev_tool/Check.scala","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:213","func":"project.Detect","level":"debug","message":"execute project-file-detector","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:213","func":"project.Detect","level":"debug","message":"execute project-map-detector","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:254","func":"project.DetectWithRevControl","level":"debug","message":"execute git-detector","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:126","func":"project.WithDetection","level":"debug","message":"execute project detection for: /Users/counter/dev/transmitter/core/src/main/scala/com/mesoor/platform/transmitter/services/external/SchemaService.scala","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:213","func":"project.Detect","level":"debug","message":"execute project-file-detector","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:213","func":"project.Detect","level":"debug","message":"execute project-map-detector","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:254","func":"project.DetectWithRevControl","level":"debug","message":"execute git-detector","now":"2022-10-18T13:52:19+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:126","func":"project.WithDetection","level":"debug","message":"execute project detection for: /Users/counter/dev/transmitter/kubernetes/kustomize/overlays/dev/kustomization.yaml","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:213","func":"project.Detect","level":"debug","message":"execute project-file-detector","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:213","func":"project.Detect","level":"debug","message":"execute project-map-detector","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:254","func":"project.DetectWithRevControl","level":"debug","message":"execute git-detector","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:126","func":"project.WithDetection","level":"debug","message":"execute project detection for: /Users/counter/dev/transmitter/core/src/main/scala/com/mesoor/platform/transmitter/services/http/routes/v2/TransmitterService.scala","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:213","func":"project.Detect","level":"debug","message":"execute project-file-detector","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:213","func":"project.Detect","level":"debug","message":"execute project-map-detector","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/project/project.go:254","func":"project.DetectWithRevControl","level":"debug","message":"execute git-detector","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/project/filter.go:23","func":"project.WithFiltering","level":"debug","message":"execute project filtering","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/heartbeat/sanitize.go:30","func":"heartbeat.WithSanitization","level":"debug","message":"execute heartbeat sanitization","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/remote/remote.go:113","func":"remote.WithCleanup","level":"debug","message":"execute remote cleanup","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/offline/offline.go:55","func":"offline.WithQueue","level":"debug","message":"execute offline queue with file /Users/counter/.wakatime.bdb","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/backoff/backoff.go:41","func":"backoff.WithBackoff","level":"debug","message":"execute heartbeat backoff algorithm","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/backoff/backoff.go:97","func":"backoff.shouldBackoff","level":"debug","message":"exponential backoff tried 5 times since Oct 18 13:47:34, will retry at Oct 18 13:55:34","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"pkg/offline/offline.go:65","func":"offline.WithQueue","level":"debug","message":"pushing 4 heartbeat(s) to queue due to error","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
{"caller":"cmd/run.go:270","func":"cmd.runCmd","level":"error","message":"failed to run command: sending heartbeat(s) later because currently rate limited: won't send heartbeat due to backoff","now":"2022-10-18T13:52:20+08:00","version":"v1.55.2"}
alanhamlett commented 2 years ago

Is your local proxy a HTTP proxy not HTTPS proxy? Try exluding *.wakatime.com from your IDE proxy.

If you need WakaTime to use a proxy, then set it as HTTP in your ~/.wakatime.cfg file:

[settings]
proxy = http://127.0.0.1:1087
counter2015 commented 2 years ago

Thanks!. After exluding *.wakatime.com from IDE proxy. it works

{"caller":"pkg/offline/offline.go:146","func":"offline.Sync","level":"debug","message":"no queued heartbeats ready for sending","now":"2022-10-19T10:34:40+08:00","version":"v1.55.2"}
{"caller":"cmd/offlinesync/offlinesync.go:48","func":"offlinesync.Run","level":"debug","message":"successfully synced offline activity","now":"2022-10-19T10:34:40+08:00","version":"v1.55.2"}