Skip to content

buildtime shows wrong value #15413

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

Closed
MrPeacockNLB opened this issue Nov 6, 2024 · 10 comments
Closed

buildtime shows wrong value #15413

MrPeacockNLB opened this issue Nov 6, 2024 · 10 comments
Assignees
Labels
observability Issues related to observability (metrics, dashboards, alerts, opentelemetry)

Comments

@MrPeacockNLB
Copy link
Contributor

MrPeacockNLB commented Nov 6, 2024

description

I just restarted my Workspace and wonder about the buildtime.

Image

As one could see the uptime is 13 minutes, but buildtime shows something else. Maybe the buildtime start does not get reset on restarting?

@coder-labeler coder-labeler bot added bug risk Prone to bugs observability Issues related to observability (metrics, dashboards, alerts, opentelemetry) labels Nov 6, 2024
@mafredri
Copy link
Member

mafredri commented Nov 6, 2024

This seems very peculiar, thanks for reporting. Could you also provide more information from the expanded timeline, what's taking up the most time?

Also, Is there any chance this workspace was updated? I believe updates still only issue a new start transition without doing stop in between. I'd be surprised if this was the case, but any chance we didn't take start->start transitions into account for this feature @dannykopping? (I'd also be surprised if a previous build affected timeline for the next one so I doubt this is the case.)

@BrunoQuaresma
Copy link
Collaborator

@MrPeacockNLB could you please share with us, here or in private, the JSON response for the /timings endpoint? You can find it in the network tab in the development console.

@MrPeacockNLB
Copy link
Contributor Author

I think I can share a sample which shows nicely what is going on here:

"agent_script_timings": [
        {
            "started_at": "2024-11-05T07:29:20.941125Z",
            "ended_at": "2024-11-05T07:29:22.644473Z",
            "exit_code": 0,
            "stage": "start",
            "status": "ok",
            "display_name": "XXX"
        },
        {
            "started_at": "2024-11-06T18:39:47.12748Z",
            "ended_at": "2024-11-06T18:39:48.806912Z",
            "exit_code": 0,
            "stage": "start",
            "status": "ok",
            "display_name": "XXX"
        },

It seems each coder script for each restart (in my case just two) gets send back as a response to the frontend. If you substract the timestamps then makes it sense to display 35h

@MrPeacockNLB
Copy link
Contributor Author

MrPeacockNLB commented Nov 7, 2024

to clarify what Uptime mean. As soon the agent startup script runs we write a timestamp file. In the metadata we show now-starttime. For my understanding Uptime should be provisioningtime + buildtime + runtime. So in any case buildtime must be lower than Uptime.

@MrPeacockNLB
Copy link
Contributor Author

I'e restarted again and now it shows the time between the last start/restart and is much lower.

@matifali matifali removed the bug risk Prone to bugs label Nov 7, 2024
@BrunoQuaresma
Copy link
Collaborator

@MrPeacockNLB, you helped us a lot. I think I know what the issue is now—thank you!

@BrunoQuaresma BrunoQuaresma self-assigned this Nov 7, 2024
@BrunoQuaresma
Copy link
Collaborator

@MrPeacockNLB I see the issue, but I can't reproduce that 🤔 does it happen with any workspace you create and restart?

@MrPeacockNLB
Copy link
Contributor Author

hmn... I've also problems in reproduce this failure. I tend to close this issue and open a new one if this occurrs again.

@BrunoQuaresma
Copy link
Collaborator

Let's leave it open for now but let me summarize the issue for posterity.

Issue:
Sometimes, the BE sends multiple timings for the same script when it should only return one since a script only runs once during the build.

Cause:
It is unclear what can cause the API to return multiple timings for the same script. I reviewed SQL queries and checked the tests for the endpoint and they all look good.

Workaround:
Make the FE more defensive and always use the last timing available instead of assuming the BE is always returning a single result.

@BrunoQuaresma
Copy link
Collaborator

@MrPeacockNLB I'm closing it for now.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
observability Issues related to observability (metrics, dashboards, alerts, opentelemetry)
Projects
None yet
Development

No branches or pull requests

4 participants