Skip to content

ci: Print go test stats #6855

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

Merged
merged 12 commits into from
Apr 3, 2023
Merged

ci: Print go test stats #6855

merged 12 commits into from
Apr 3, 2023

Conversation

mafredri
Copy link
Member

Fixes #6676

@mafredri mafredri self-assigned this Mar 28, 2023
@mafredri
Copy link
Member Author

Example output:

{
  "packages": [
    {
      "name": "agent",
      "time": 21.092
    },
    {
      "name": "agent/reaper",
      "time": 0,
      "skip": true
    },
    {
      "name": "agent/usershell",
      "time": 0,
      "skip": true
    },
    {
      "name": "buildinfo",
      "time": 0.004
    },
    {
      "name": "cli",
      "time": 66.449,
      "fail": true,
      "num_failed": 2
    }
    // ...
  ],
  "tests": [
    {
      "package": "cli",
      "name": "TestTemplatePush",
      "time": 4.96,
      "fail": true,
      "output": "=== RUN   TestTemplatePush\n=== PAUSE TestTemplatePush\n=== CONT  TestTemplatePush\n--- FAIL: TestTemplatePush (4.96s)\n"
    },
    {
      "package": "cli",
      "name": "TestTemplatePush/NewParameter",
      "time": 6.35
    },
    {
      "package": "cli",
      "name": "TestTemplatePush/OK",
      "time": 2.66
    },
    {
      "package": "cli",
      "name": "TestTemplatePush/UseWorkingDir",
      "time": 4.95,
      "fail": true,
      "output": "=== RUN   TestTemplatePush/UseWorkingDir\n    t.go:81: 2023-03-28 19:31:04.042 [DEBUG]\t(metrics_cache)\t\u003cgithub.com\\coder\\coder\\coderd\\metricscache\\metricscache.go:272\u003e\t(*Cache).run\tdeployment stats metrics refreshed\t{\"took\": \"0s\", \"interval\": \"5m0s\"}\n    t.go:81: 2023-03-28 19:31:04.047 [DEBUG]\t(metrics_cache)\t\u003cgithub.com\\coder\\coder\\coderd\\metricscache\\metricscache.go:272\u003e\t(*Cache).run\ttemplate daus metrics refreshed\t{\"took\": \"4.8161ms\", \"interval\": \"1h0m0s\"}\n    t.go:81: 2023-03-28 19:31:04.047 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\provisionerd.go:200\u003e\t(*Server).connect\tconnected\n    t.go:81: 2023-03-28 19:31:04.358 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tPOST\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/users/first\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"7.704ms\", \"status_code\": 201, \"latency_ms\": 7, \"request_id\": \"20b7e7fb-c73f-4aa6-9acd-01809ce809c9\"}\n    t.go:81: 2023-03-28 19:31:04.409 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tPOST\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/users/login\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"32.6858ms\", \"status_code\": 201, \"latency_ms\": 32, \"request_id\": \"c2b386ba-fc01-4a85-a04a-efe779917d67\"}\n    t.go:81: 2023-03-28 19:31:04.428 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tPOST\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/files\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"4.2347ms\", \"status_code\": 201, \"latency_ms\": 4, \"request_id\": \"7db0f5ed-3b2f-4b2d-86d5-ce1fb40ad366\"}\n    t.go:81: 2023-03-28 19:31:04.435 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tPOST\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/organizations/66859f14-9a30-4a02-aeba-4f4f5a583231/templateversions\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"6.2105ms\", \"status_code\": 201, \"latency_ms\": 6, \"request_id\": \"9f781bbc-75f7-4ecb-92bb-2b533673291f\"}\n    templatepush_test.go:164: waiting for template version job c8bb50c6-7700-4535-ac0f-71376f688414\n    t.go:81: 2023-03-28 19:31:04.513 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"4.632ms\", \"status_code\": 200, \"latency_ms\": 4, \"request_id\": \"52ca505d-1edc-4929-9a94-d5cd0e6f36c6\"}\n    t.go:81: 2023-03-28 19:31:04.556 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"2.4654ms\", \"status_code\": 200, \"latency_ms\": 2, \"request_id\": \"e9ed00de-fc56-48f1-9edf-d55f4b5dede2\"}\n    t.go:81: 2023-03-28 19:31:04.608 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"8.0762ms\", \"status_code\": 200, \"latency_ms\": 8, \"request_id\": \"fa73eb53-bbf7-4767-b735-6464f4071330\"}\n    t.go:81: 2023-03-28 19:31:04.648 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"2.6979ms\", \"status_code\": 200, \"latency_ms\": 2, \"request_id\": \"f0aeaf6c-39ae-4cb9-a83f-e9c75353fc4f\"}\n    t.go:81: 2023-03-28 19:31:04.698 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"3.7678ms\", \"status_code\": 200, \"latency_ms\": 3, \"request_id\": \"44a96def-d6cd-4595-8b69-6a6f0c2cd5fb\"}\n    t.go:81: 2023-03-28 19:31:04.752 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"6.9289ms\", \"status_code\": 200, \"latency_ms\": 6, \"request_id\": \"73562e59-5006-404b-bf09-173d15a719d9\"}\n    t.go:81: 2023-03-28 19:31:04.802 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"2.5612ms\", \"status_code\": 200, \"latency_ms\": 2, \"request_id\": \"f5c3df1c-9d5b-474d-80b9-ff45dfceed0b\"}\n    t.go:81: 2023-03-28 19:31:04.851 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"4.0167ms\", \"status_code\": 200, \"latency_ms\": 4, \"request_id\": \"8280dbd3-0d43-413d-a546-57ea161e9390\"}\n    t.go:81: 2023-03-28 19:31:04.909 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"564µs\", \"status_code\": 200, \"latency_ms\": 0, \"request_id\": \"716304c0-52a0-4740-96fa-956c5d7cd999\"}\n    t.go:81: 2023-03-28 19:31:04.954 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"1.0357ms\", \"status_code\": 200, \"latency_ms\": 1, \"request_id\": \"e2087944-d4eb-43c8-bcdf-b645c1eb0989\"}\n    t.go:81: 2023-03-28 19:31:04.995 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"0s\", \"status_code\": 200, \"latency_ms\": 0, \"request_id\": \"6b14aab3-b9d9-4ba2-a36c-a4b13b094e23\"}\n    t.go:81: 2023-03-28 19:31:05.048 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"2.136ms\", \"status_code\": 200, \"latency_ms\": 2, \"request_id\": \"89217a3f-6140-45df-930a-752c6fe3be66\"}\n    t.go:81: 2023-03-28 19:31:05.102 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"0s\", \"status_code\": 200, \"latency_ms\": 0, \"request_id\": \"b1902e28-bc06-45ea-b973-efcc7f16ca00\"}\n    t.go:81: 2023-03-28 19:31:05.151 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"4.7633ms\", \"status_code\": 200, \"latency_ms\": 4, \"request_id\": \"96e5e476-4867-4177-b7f2-4636f1b162a5\"}\n    t.go:81: 2023-03-28 19:31:05.244 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"1.4896ms\", \"status_code\": 200, \"latency_ms\": 1, \"request_id\": \"2fcc1e1d-95d5-486c-b504-a54099c37598\"}\n    t.go:81: 2023-03-28 19:31:05.248 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:105\u003e\t(*Server).AcquireJob\tlocked job from database\t{\"id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\"}\n    t.go:81: 2023-03-28 19:31:05.262 [INFO]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\provisionerd.go:378\u003e\t(*Server).acquireJob\tacquired job\t{\"initiator_username\": \"testuser\", \"provisioner\": \"echo\", \"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\"}\n    t.go:81: 2023-03-28 19:31:05.262 [INFO]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:395\u003e\t(*Runner).do\tunpacking template source archive\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"size_bytes\": 3072}\n    t.go:81: 2023-03-28 19:31:05.262 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:442\u003e\t(*Runner).do\textracted file\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"size_bytes\": 2, \"path\": \"C:\\\\Users\\\\RUNNER~1\\\\AppData\\\\Local\\\\Temp\\\\TestTemplatePushUseWorkingDir2657825464\\\\002\\\\0.parse.protobuf\", \"mode\": \"-rw-r--r--\"}\n    t.go:81: 2023-03-28 19:31:05.262 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:442\u003e\t(*Runner).do\textracted file\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"size_bytes\": 2, \"path\": \"C:\\\\Users\\\\RUNNER~1\\\\AppData\\\\Local\\\\Temp\\\\TestTemplatePushUseWorkingDir2657825464\\\\002\\\\0.provision.apply.protobuf\", \"mode\": \"-rw-r--r--\"}\n    t.go:81: 2023-03-28 19:31:05.262 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:442\u003e\t(*Runner).do\textracted file\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"size_bytes\": 2, \"path\": \"C:\\\\Users\\\\RUNNER~1\\\\AppData\\\\Local\\\\Temp\\\\TestTemplatePushUseWorkingDir2657825464\\\\002\\\\0.provision.plan.protobuf\", \"mode\": \"-rw-r--r--\"}\n    t.go:81: 2023-03-28 19:31:05.262 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:451\u003e\t(*Runner).do\tacquired job is template import\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"user_variable_values\": null}\n    t.go:81: 2023-03-28 19:31:05.262 [INFO]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:680\u003e\t(*Runner).runTemplateImportParse\tparse complete\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"parameter_schemas\": null, \"template_variables\": null}\n    t.go:81: 2023-03-28 19:31:05.265 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:450\u003e\t(*Server).UpdateJob\tUpdateJob starting\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\"}\n    t.go:81: 2023-03-28 19:31:05.266 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"4.0752ms\", \"status_code\": 200, \"latency_ms\": 4, \"request_id\": \"f1ac3c6d-3771-4169-9ec1-fa0107968540\"}\n    t.go:81: 2023-03-28 19:31:05.266 [INFO]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:782\u003e\t(*Runner).runTemplateImportProvisionWithRichParameters\tparse dry-run provision successful\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"resource_count\": 0, \"resources\": null, \"state_length\": 0}\n    t.go:81: 2023-03-28 19:31:05.267 [INFO]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:782\u003e\t(*Runner).runTemplateImportProvisionWithRichParameters\tparse dry-run provision successful\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"resource_count\": 0, \"resources\": null, \"state_length\": 0}\n    t.go:81: 2023-03-28 19:31:05.267 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:365\u003e\t(*Runner).doCleanFinish.func2\tcleaned up work directory\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\"}\n    t.go:81: 2023-03-28 19:31:05.267 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:450\u003e\t(*Server).UpdateJob\tUpdateJob starting\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\"}\n    t.go:81: 2023-03-28 19:31:05.267 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:487\u003e\t(*Server).UpdateJob\tjob log\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"stage\": \"Setting up\", \"output\": \"\"}\n    t.go:81: 2023-03-28 19:31:05.267 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:487\u003e\t(*Server).UpdateJob\tjob log\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"stage\": \"No README.md provided\", \"output\": \"\"}\n    t.go:81: 2023-03-28 19:31:05.267 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:487\u003e\t(*Server).UpdateJob\tjob log\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"stage\": \"Parsing template parameters\", \"output\": \"\"}\n    t.go:81: 2023-03-28 19:31:05.267 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:487\u003e\t(*Server).UpdateJob\tjob log\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"stage\": \"Detecting persistent resources\", \"output\": \"\"}\n    t.go:81: 2023-03-28 19:31:05.267 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:487\u003e\t(*Server).UpdateJob\tjob log\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"stage\": \"Detecting ephemeral resources\", \"output\": \"\"}\n    t.go:81: 2023-03-28 19:31:05.267 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:487\u003e\t(*Server).UpdateJob\tjob log\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\", \"stage\": \"Cleaning Up\", \"output\": \"\"}\n    t.go:81: 2023-03-28 19:31:05.267 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:501\u003e\t(*Server).UpdateJob\tinserted job logs\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\"}\n    t.go:81: 2023-03-28 19:31:05.267 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:513\u003e\t(*Server).UpdateJob\tpublished job logs\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\"}\n    t.go:81: 2023-03-28 19:31:05.267 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:226\u003e\t(*Runner).Run\tsending CompletedJob\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\"}\n    t.go:81: 2023-03-28 19:31:05.267 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:830\u003e\t(*Server).CompleteJob\tCompleteJob starting\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\"}\n    t.go:81: 2023-03-28 19:31:05.270 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:940\u003e\t(*Server).CompleteJob\tmarked import job as completed\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\"}\n    t.go:81: 2023-03-28 19:31:05.270 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:1185\u003e\t(*Server).CompleteJob\tCompleteJob done\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\"}\n    t.go:81: 2023-03-28 19:31:05.270 [INFO]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:231\u003e\t(*Runner).Run\tsent CompletedJob\t{\"job_id\": \"dc4f2786-5756-41ce-baae-aeb5263840ec\"}\n    t.go:81: 2023-03-28 19:31:05.302 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"2.6015ms\", \"status_code\": 200, \"latency_ms\": 2, \"request_id\": \"60f9a2e3-1a7e-4a0d-bf41-3325c3ab4837\"}\n    templatepush_test.go:164: got template version job c8bb50c6-7700-4535-ac0f-71376f688414\n    t.go:81: 2023-03-28 19:31:05.681 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tPOST\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/organizations/66859f14-9a30-4a02-aeba-4f4f5a583231/templates\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"4.2726ms\", \"status_code\": 201, \"latency_ms\": 4, \"request_id\": \"5d725573-944d-475b-8cd2-4bf6a3233dbb\"}\n    clitest.go:67: invoking command: coder --global-config C:\\Users\\RUNNER~1\\AppData\\Local\\Temp\\TestTemplatePushUseWorkingDir2657825464\\004 templates push --test.provisioner echo\n    t.go:81: 2023-03-28 19:31:06.000 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/buildinfo\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"0s\", \"status_code\": 200, \"latency_ms\": 0, \"request_id\": \"90f5328b-bb4d-425c-abda-7a73ba7cf7c2\"}\n    t.go:81: 2023-03-28 19:31:06.000 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/entitlements\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"0s\", \"status_code\": 404, \"latency_ms\": 0, \"request_id\": \"a4638ea2-c4d6-4922-86f3-d7a38c1c3f3b\"}\n    t.go:81: 2023-03-28 19:31:06.001 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/users/me/organizations\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"606µs\", \"status_code\": 200, \"latency_ms\": 0, \"request_id\": \"a9e3b0c9-497a-4293-8788-5c3f079ff5f8\"}\n    t.go:81: 2023-03-28 19:31:06.009 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/organizations/66859f14-9a30-4a02-aeba-4f4f5a583231/templates/003\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"4.2373ms\", \"status_code\": 200, \"latency_ms\": 4, \"request_id\": \"f57d7d21-0d7e-46cc-a814-c8ce6ea1fd23\"}\n    templatepush_test.go:201: 2023-03-28 19:31:06.009: cmd: matched \"Upload\" = \"\u003e Upload\"\n    templatepush_test.go:202: 2023-03-28 19:31:06.009: cmd: stdin: \"yes\\r\\n\"\n    t.go:81: 2023-03-28 19:31:06.012 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tPOST\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/files\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"2.7995ms\", \"status_code\": 201, \"latency_ms\": 2, \"request_id\": \"9adc414b-b8c4-4706-9f4a-92f03609aa91\"}\n    t.go:81: 2023-03-28 19:31:06.020 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tPOST\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/organizations/66859f14-9a30-4a02-aeba-4f4f5a583231/templateversions\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"7.0953ms\", \"status_code\": 201, \"latency_ms\": 7, \"request_id\": \"b6273a31-452d-4aef-8de3-ff298a74b318\"}\n    ptytest.go:121: 2023-03-28 19:31:06.024: cmd: \"\u003e Upload \\\".\\\"? (yes/no) ⧗  Queued \"\n    t.go:81: 2023-03-28 19:31:06.035 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/7402a6a5-716e-4299-b041-922a1253f235\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"14.9136ms\", \"status_code\": 200, \"latency_ms\": 14, \"request_id\": \"e9a88948-d71b-4701-a308-fbaf037819f4\"}\n    t.go:81: 2023-03-28 19:31:06.678 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:105\u003e\t(*Server).AcquireJob\tlocked job from database\t{\"id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.681 [INFO]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\provisionerd.go:378\u003e\t(*Server).acquireJob\tacquired job\t{\"initiator_username\": \"testuser\", \"provisioner\": \"echo\", \"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.683 [INFO]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:395\u003e\t(*Runner).do\tunpacking template source archive\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"size_bytes\": 3584}\n    t.go:81: 2023-03-28 19:31:06.798 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:442\u003e\t(*Runner).do\textracted file\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"size_bytes\": 2, \"path\": \"C:\\\\Users\\\\RUNNER~1\\\\AppData\\\\Local\\\\Temp\\\\TestTemplatePushUseWorkingDir2657825464\\\\002\\\\0.parse.protobuf\", \"mode\": \"-rw-rw-rw-\"}\n    t.go:81: 2023-03-28 19:31:06.798 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:442\u003e\t(*Runner).do\textracted file\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"size_bytes\": 2, \"path\": \"C:\\\\Users\\\\RUNNER~1\\\\AppData\\\\Local\\\\Temp\\\\TestTemplatePushUseWorkingDir2657825464\\\\002\\\\0.provision.apply.protobuf\", \"mode\": \"-rw-rw-rw-\"}\n    t.go:81: 2023-03-28 19:31:06.798 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:442\u003e\t(*Runner).do\textracted file\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"size_bytes\": 2, \"path\": \"C:\\\\Users\\\\RUNNER~1\\\\AppData\\\\Local\\\\Temp\\\\TestTemplatePushUseWorkingDir2657825464\\\\002\\\\0.provision.plan.protobuf\", \"mode\": \"-rw-rw-rw-\"}\n    t.go:81: 2023-03-28 19:31:06.798 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:442\u003e\t(*Runner).do\textracted file\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"size_bytes\": 0, \"path\": \"C:\\\\Users\\\\RUNNER~1\\\\AppData\\\\Local\\\\Temp\\\\TestTemplatePushUseWorkingDir2657825464\\\\002\\\\158663528.tf\", \"mode\": \"-rw-rw-rw-\"}\n    t.go:81: 2023-03-28 19:31:06.799 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:451\u003e\t(*Runner).do\tacquired job is template import\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"user_variable_values\": null}\n    t.go:81: 2023-03-28 19:31:06.752 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:450\u003e\t(*Server).UpdateJob\tUpdateJob starting\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.819 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:487\u003e\t(*Server).UpdateJob\tjob log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"Setting up\", \"output\": \"\"}\n    t.go:81: 2023-03-28 19:31:06.823 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:501\u003e\t(*Server).UpdateJob\tinserted job logs\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.823 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:385\u003e\t(*API).followProvisionerJobLogs.func1\tsubscribe buffered log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"Setting up\"}\n    t.go:81: 2023-03-28 19:31:06.823 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:513\u003e\t(*Server).UpdateJob\tpublished job logs\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.823 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:172\u003e\t(*API).provisionerJobLogs\tsubscribe encoding log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"request_id\": \"2a7bb063-5fab-427b-ae2b-a6b5f33e0da2\", \"stage\": \"Setting up\"}\n    t.go:81: 2023-03-28 19:31:06.823 [INFO]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:680\u003e\t(*Runner).runTemplateImportParse\tparse complete\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"parameter_schemas\": null, \"template_variables\": null}\n    t.go:81: 2023-03-28 19:31:06.823 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:450\u003e\t(*Server).UpdateJob\tUpdateJob starting\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    ptytest.go:121: 2023-03-28 19:31:06.833: cmd: \"\\r✔ Queued [662ms]\"\n    t.go:81: 2023-03-28 19:31:06.834 [INFO]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:782\u003e\t(*Runner).runTemplateImportProvisionWithRichParameters\tparse dry-run provision successful\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"resource_count\": 0, \"resources\": null, \"state_length\": 0}\n    ptytest.go:121: 2023-03-28 19:31:06.835: cmd: \"⧗  Setting up \"\n    t.go:81: 2023-03-28 19:31:06.835 [INFO]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:782\u003e\t(*Runner).runTemplateImportProvisionWithRichParameters\tparse dry-run provision successful\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"resource_count\": 0, \"resources\": null, \"state_length\": 0}\n    t.go:81: 2023-03-28 19:31:06.835 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:365\u003e\t(*Runner).doCleanFinish.func2\tcleaned up work directory\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.835 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:450\u003e\t(*Server).UpdateJob\tUpdateJob starting\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.837 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:487\u003e\t(*Server).UpdateJob\tjob log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"No README.md provided\", \"output\": \"\"}\n    t.go:81: 2023-03-28 19:31:06.839 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:487\u003e\t(*Server).UpdateJob\tjob log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"Parsing template parameters\", \"output\": \"\"}\n    t.go:81: 2023-03-28 19:31:06.839 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:487\u003e\t(*Server).UpdateJob\tjob log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"Detecting persistent resources\", \"output\": \"\"}\n    t.go:81: 2023-03-28 19:31:06.839 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:487\u003e\t(*Server).UpdateJob\tjob log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"Detecting ephemeral resources\", \"output\": \"\"}\n    t.go:81: 2023-03-28 19:31:06.839 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:487\u003e\t(*Server).UpdateJob\tjob log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"Cleaning Up\", \"output\": \"\"}\n    t.go:81: 2023-03-28 19:31:06.839 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:501\u003e\t(*Server).UpdateJob\tinserted job logs\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.840 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:385\u003e\t(*API).followProvisionerJobLogs.func1\tsubscribe buffered log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"Setting up\"}\n    t.go:81: 2023-03-28 19:31:06.845 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:385\u003e\t(*API).followProvisionerJobLogs.func1\tsubscribe buffered log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"No README.md provided\"}\n    t.go:81: 2023-03-28 19:31:06.845 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:385\u003e\t(*API).followProvisionerJobLogs.func1\tsubscribe buffered log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"Parsing template parameters\"}\n    t.go:81: 2023-03-28 19:31:06.845 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:385\u003e\t(*API).followProvisionerJobLogs.func1\tsubscribe buffered log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"Detecting persistent resources\"}\n    t.go:81: 2023-03-28 19:31:06.845 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:385\u003e\t(*API).followProvisionerJobLogs.func1\tsubscribe buffered log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"Detecting ephemeral resources\"}\n    t.go:81: 2023-03-28 19:31:06.845 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:385\u003e\t(*API).followProvisionerJobLogs.func1\tsubscribe buffered log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"Cleaning Up\"}\n    t.go:81: 2023-03-28 19:31:06.845 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:513\u003e\t(*Server).UpdateJob\tpublished job logs\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.840 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:172\u003e\t(*API).provisionerJobLogs\tsubscribe encoding log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"request_id\": \"2a7bb063-5fab-427b-ae2b-a6b5f33e0da2\", \"stage\": \"Setting up\"}\n    t.go:81: 2023-03-28 19:31:06.847 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:172\u003e\t(*API).provisionerJobLogs\tsubscribe encoding log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"request_id\": \"2a7bb063-5fab-427b-ae2b-a6b5f33e0da2\", \"stage\": \"No README.md provided\"}\n    t.go:81: 2023-03-28 19:31:06.847 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:172\u003e\t(*API).provisionerJobLogs\tsubscribe encoding log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"request_id\": \"2a7bb063-5fab-427b-ae2b-a6b5f33e0da2\", \"stage\": \"Parsing template parameters\"}\n    t.go:81: 2023-03-28 19:31:06.847 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:172\u003e\t(*API).provisionerJobLogs\tsubscribe encoding log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"request_id\": \"2a7bb063-5fab-427b-ae2b-a6b5f33e0da2\", \"stage\": \"Detecting persistent resources\"}\n    t.go:81: 2023-03-28 19:31:06.848 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:172\u003e\t(*API).provisionerJobLogs\tsubscribe encoding log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"request_id\": \"2a7bb063-5fab-427b-ae2b-a6b5f33e0da2\", \"stage\": \"Detecting ephemeral resources\"}\n    t.go:81: 2023-03-28 19:31:06.848 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:172\u003e\t(*API).provisionerJobLogs\tsubscribe encoding log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"request_id\": \"2a7bb063-5fab-427b-ae2b-a6b5f33e0da2\", \"stage\": \"Cleaning Up\"}\n    t.go:81: 2023-03-28 19:31:06.848 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:226\u003e\t(*Runner).Run\tsending CompletedJob\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    ptytest.go:121: 2023-03-28 19:31:06.848: cmd: \"  \"\n    ptytest.go:121: 2023-03-28 19:31:06.848: cmd: \"✔ Setting up [140ms]\"\n    ptytest.go:121: 2023-03-28 19:31:06.848: cmd: \"⧗  Parsing template parameters \"\n    ptytest.go:121: 2023-03-28 19:31:06.848: cmd: \"\\r✔ Parsing template parameters [11ms]\"\n    ptytest.go:121: 2023-03-28 19:31:06.848: cmd: \"⧗  Detecting persistent resources \"\n    ptytest.go:121: 2023-03-28 19:31:06.848: cmd: \"\\r✔ Detecting persistent resources [0ms]\"\n    ptytest.go:121: 2023-03-28 19:31:06.848: cmd: \"⧗  Detecting ephemeral resources \"\n    ptytest.go:121: 2023-03-28 19:31:06.848: cmd: \"\\r✔ Detecting ephemeral resources [1ms]\"\n    ptytest.go:121: 2023-03-28 19:31:06.848: cmd: \"⧗  Cleaning Up \"\n    t.go:81: 2023-03-28 19:31:06.848 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:830\u003e\t(*Server).CompleteJob\tCompleteJob starting\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.849 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:940\u003e\t(*Server).CompleteJob\tmarked import job as completed\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.855 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:385\u003e\t(*API).followProvisionerJobLogs.func1\tsubscribe buffered log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"stage\": \"Cleaning Up\"}\n    t.go:81: 2023-03-28 19:31:06.855 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:446\u003e\t(*API).followProvisionerJobLogs.func2\tgot End of Logs\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.872 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:172\u003e\t(*API).provisionerJobLogs\tsubscribe encoding log\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\", \"request_id\": \"2a7bb063-5fab-427b-ae2b-a6b5f33e0da2\", \"stage\": \"Cleaning Up\"}\n    t.go:81: 2023-03-28 19:31:06.872 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerjobs.go:165\u003e\t(*API).provisionerJobLogs\treached the end of published logs\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    ptytest.go:121: 2023-03-28 19:31:06.876: cmd: \"  \"\n    t.go:81: 2023-03-28 19:31:06.877 [DEBUG]\t(provisionerd-boring_pare6)\t\u003cgithub.com\\coder\\coder\\coderd\\provisionerdserver\\provisionerdserver.go:1185\u003e\t(*Server).CompleteJob\tCompleteJob done\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.879 [INFO]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\runner\\runner.go:231\u003e\t(*Runner).Run\tsent CompletedJob\t{\"job_id\": \"13824d47-78ce-47cd-a03a-82d57d4f2fc9\"}\n    t.go:81: 2023-03-28 19:31:06.877 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/7402a6a5-716e-4299-b041-922a1253f235/logs\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"530.1022ms\", \"status_code\": 101, \"latency_ms\": 530, \"request_id\": \"2a7bb063-5fab-427b-ae2b-a6b5f33e0da2\"}\n    t.go:81: 2023-03-28 19:31:07.194 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/7402a6a5-716e-4299-b041-922a1253f235\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"3.6521ms\", \"status_code\": 200, \"latency_ms\": 3, \"request_id\": \"7c219d98-cba6-46d3-a81d-06bd48ac3c67\"}\n    ptytest.go:121: 2023-03-28 19:31:07.195: cmd: \"✔ Cleaning Up [14ms]\"\n    t.go:81: 2023-03-28 19:31:07.200 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/7402a6a5-716e-4299-b041-922a1253f235\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"4.6788ms\", \"status_code\": 200, \"latency_ms\": 4, \"request_id\": \"63318ed7-8b83-428e-af41-954a562cd642\"}\n    t.go:81: 2023-03-28 19:31:07.204 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/7402a6a5-716e-4299-b041-922a1253f235/schema\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"2.5769ms\", \"status_code\": 200, \"latency_ms\": 2, \"request_id\": \"895e5821-0d9b-45f2-affe-4294def8f7a9\"}\n    t.go:81: 2023-03-28 19:31:07.207 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/7402a6a5-716e-4299-b041-922a1253f235/parameters\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"2.4779ms\", \"status_code\": 200, \"latency_ms\": 2, \"request_id\": \"81ff9324-ac2c-48ce-ac85-709537ed0330\"}\n    t.go:81: 2023-03-28 19:31:07.214 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/c8bb50c6-7700-4535-ac0f-71376f688414\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"4.3726ms\", \"status_code\": 200, \"latency_ms\": 4, \"request_id\": \"79690867-bbc7-4bb3-895d-08d6eee586c9\"}\n    t.go:81: 2023-03-28 19:31:07.215 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/parameters/import_job/dc4f2786-5756-41ce-baae-aeb5263840ec\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"1.3179ms\", \"status_code\": 200, \"latency_ms\": 1, \"request_id\": \"77847fc1-c54c-40cc-bc6e-c49b8b1b5002\"}\n    t.go:81: 2023-03-28 19:31:07.227 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templateversions/7402a6a5-716e-4299-b041-922a1253f235/resources\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"3.5113ms\", \"status_code\": 200, \"latency_ms\": 3, \"request_id\": \"fe4dfa9d-9f54-4d48-bf54-26d60477a35c\"}\n    t.go:81: 2023-03-28 19:31:07.230 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tPATCH\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templates/ba7b832d-4403-4484-a764-b686f089d388/versions\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"1.5296ms\", \"status_code\": 200, \"latency_ms\": 1, \"request_id\": \"1c770d5c-3849-4677-846b-7dee0b24f82d\"}\n    ptytest.go:121: 2023-03-28 19:31:07.230: cmd: \"┌──────────┐\"\n    ptytest.go:121: 2023-03-28 19:31:07.230: cmd: \"│ Template │\"\n    ptytest.go:121: 2023-03-28 19:31:07.230: cmd: \"│ Preview  │\"\n    ptytest.go:121: 2023-03-28 19:31:07.230: cmd: \"├──────────┤\"\n    ptytest.go:121: 2023-03-28 19:31:07.230: cmd: \"│ RESOURCE │\"\n    ptytest.go:121: 2023-03-28 19:31:07.230: cmd: \"├──────────┤\"\n    ptytest.go:121: 2023-03-28 19:31:07.230: cmd: \"└──────────┘\"\n    ptytest.go:121: 2023-03-28 19:31:07.230: cmd: \"Updated version at Mar 28 19:31:07!\"\n    t.go:81: 2023-03-28 19:31:07.548 [DEBUG]\t\u003cgithub.com\\coder\\coder\\coderd\\httpmw\\logger.go:63\u003e\tLogger.func1.1.1\tGET\t{\"host\": \"localhost:51147\", \"path\": \"/api/v2/templates/ba7b832d-4403-4484-a764-b686f089d388/versions\", \"proto\": \"HTTP/1.1\", \"remote_addr\": \"127.0.0.1\", \"took\": \"3.9478ms\", \"status_code\": 200, \"latency_ms\": 3, \"request_id\": \"c55f569a-29bb-4217-b457-8564e793c669\"}\n    ptytest.go:83: 2023-03-28 19:31:07.548: cmd: closing tpty: close\n    ptytest.go:74: 2023-03-28 19:31:07.548: cmd: closing pty\n    ptytest.go:110: 2023-03-28 19:31:07.550: cmd: copy done: \u003cnil\u003e\n    ptytest.go:111: 2023-03-28 19:31:07.550: cmd: closing out\n    ptytest.go:113: 2023-03-28 19:31:07.550: cmd: closed out: \u003cnil\u003e\n    ptytest.go:76: 2023-03-28 19:31:07.550: cmd: closed pty: \u003cnil\u003e\n    ptytest.go:74: 2023-03-28 19:31:07.550: cmd: closing logw\n    ptytest.go:76: 2023-03-28 19:31:07.550: cmd: closed logw: \u003cnil\u003e\n    ptytest.go:74: 2023-03-28 19:31:07.550: cmd: closing logr\n    ptytest.go:76: 2023-03-28 19:31:07.550: cmd: closed logr: \u003cnil\u003e\n    ptytest.go:102: 2023-03-28 19:31:07.550: cmd: closed tpty\n    t.go:81: 2023-03-28 19:31:07.550 [DEBUG]\t(provisionerd)\t\u003cgithub.com\\coder\\coder\\provisionerd\\provisionerd.go:553\u003e\t(*Server).closeWithError\tclosing server with error\t{\"error\": null}\n    testing.go:1206: TempDir RemoveAll cleanup: remove C:\\Users\\RUNNER~1\\AppData\\Local\\Temp\\TestTemplatePushUseWorkingDir2657825464\\003: The process cannot access the file because it is being used by another process.\n    stuntest.go:63: STUN server shutdown\n--- FAIL: TestTemplatePush/UseWorkingDir (4.95s)\n"
    },
    {
      "package": "cli",
      "name": "TestTemplateVersions",
      "time": 0
    },
    {
      "package": "cli",
      "name": "TestTemplateVersions/ListVersions",
      "time": 0.86
    },
    {
      "package": "cli",
      "name": "TestTokens",
      "time": 0.42
    }
    // ...
  ]
}

@mafredri mafredri marked this pull request as ready for review March 28, 2023 19:49
@mafredri mafredri requested a review from mtojek March 28, 2023 19:49
Copy link
Member

@mtojek mtojek left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I left one comment regarding reviewing this PR, but feel free to ignore it if it slows you down 👍

@mtojek mtojek self-requested a review March 29, 2023 13:52
Copy link
Member

@mtojek mtojek left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's much easier to review looking at provided samples :)

@@ -302,7 +302,14 @@ jobs:
echo "cover=false" >> $GITHUB_OUTPUT
fi

gotestsum --junitfile="gotests.xml" --packages="./..." -- -parallel=8 -timeout=7m -short -failfast $COVERAGE_FLAGS
gotestsum --junitfile="gotests.xml" --jsonfile="gotests.json" --packages="./..." -- -parallel=8 -timeout=7m -short -failfast $COVERAGE_FLAGS
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should we run it with PostgreSQL too?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We do, see Makefile.

@mafredri mafredri requested a review from mtojek April 3, 2023 10:40
@mafredri mafredri enabled auto-merge (squash) April 3, 2023 11:06
@mafredri mafredri merged commit d9d44c1 into main Apr 3, 2023
@mafredri mafredri deleted the mafredri/ci-stats branch April 3, 2023 11:07
@github-actions github-actions bot locked and limited conversation to collaborators Apr 3, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Generate statistics from CI runs
2 participants