Skip to content
New issue

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

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

Already on GitHub? Sign in to your account

Log flooded by done: cannot close log stream entries #2036

Closed
5 tasks done
xoxys opened this issue Jul 25, 2023 · 10 comments · Fixed by #2637
Closed
5 tasks done

Log flooded by done: cannot close log stream entries #2036

xoxys opened this issue Jul 25, 2023 · 10 comments · Fixed by #2637
Labels
bug Something isn't working
Milestone

Comments

@xoxys
Copy link
Member

xoxys commented Jul 25, 2023

Component

server

Describe the bug

After a short period of time, I have already many of these entries in the log:

{"level":"error","repo_id":"4","pipeline_id":"73","workflow_id":"172","error":"stream: not found","time":"2023-07-25T21:31:12Z","message":"done: cannot close log stream for step 519"}
{"level":"error","repo_id":"4","pipeline_id":"73","workflow_id":"172","error":"stream: not found","time":"2023-07-25T21:31:12Z","message":"done: cannot close log stream for step 520"}

This one also occurs pretty often:

{"level":"warn","error":"sql: no rows in result set","time":"2023-07-25T21:29:56Z"}

System Info

{"source":"https://github.com/woodpecker-ci/woodpecker","version":"next-1c116daf"}

Additional context

No response

Validations

  • Read the Contributing Guidelines.
  • Read the docs.
  • Check that there isn't already an issue that reports the same bug to avoid creating a duplicate.
  • Checked that the bug isn't fixed in the next version already [https://woodpecker-ci.org/faq#which-version-of-woodpecker-should-i-use]
  • Check that this is a concrete bug. For Q&A join our Discord Chat Server or the Matrix room.
@xoxys xoxys added the bug Something isn't working label Jul 25, 2023
@6543 6543 added this to the 1.0.0 milestone Jul 26, 2023
@6543
Copy link
Member

6543 commented Jul 26, 2023

The second error is a generic error the datastorge (db module) return, when an requested item was not found.

So to fix that we need more infobwhat the originated request was

@6543
Copy link
Member

6543 commented Jul 26, 2023

The first err got added by #1802 and jas just droped in tje past.

As it happens frequently, there is eiter an issue with either stream opening or it got closed before.

in any case we should dig into it.

Affected part: pubsub mod for live log streaming over eventstream

@xoxys
Copy link
Member Author

xoxys commented Jul 26, 2023

The second one occurs every time a repo page is accessed that does not yet have a pipeline:

image

Refreshing this page multiple time will create the sql: no rows in result set log every time.

@6543
Copy link
Member

6543 commented Jul 26, 2023

Ah then its a easy fix ... will do so once i have a keboard on hand again

@6543
Copy link
Member

6543 commented Jul 26, 2023

I think we do have something like that:

if errors.Is(err, types.RecordNotExist) {
(404 err handling) missing on a endpoint queryed by this view

@6543
Copy link
Member

6543 commented Jul 27, 2023

-> #2042

@6543
Copy link
Member

6543 commented Jul 27, 2023

also the generic error will get less generic -> #2041

@6543
Copy link
Member

6543 commented Jul 27, 2023

ok the first error is created here:

if err := s.logger.Close(c, step.ID); err != nil {
logger.Error().Err(err).Msgf("done: cannot close log stream for step %d", step.ID)
}

but the question is why!

@6543
Copy link
Member

6543 commented Jul 28, 2023

moved to bugfix version as it's non blocking :)

mzampetakis pushed a commit to mzampetakis/woodpecker that referenced this issue Jul 31, 2023
@6543 6543 modified the milestones: 1.0.1, 1.0.2 Aug 7, 2023
@qwerty287 qwerty287 modified the milestones: 1.0.2, v1.0.3, 1.0.3 Aug 8, 2023
@6543 6543 modified the milestones: 1.0.2, 1.0.3 Aug 16, 2023
@catdevnull
Copy link
Contributor

this also happens to me and the last few characters or things in the log for a pipeline disappear even though it shows itself as successful/errored

@qwerty287 qwerty287 removed this from the 1.0.3 milestone Oct 15, 2023
@qwerty287 qwerty287 added this to the 1.0.4 milestone Oct 15, 2023
qwerty287 added a commit that referenced this issue Oct 24, 2023
Previously, *all* log streams of the pipeline were closed everytime when
a workflow is done, if you have multiple workflows, streams will be
closed multiple times.

Closes #2036
qwerty287 added a commit to qwerty287/woodpecker that referenced this issue Oct 24, 2023
Previously, *all* log streams of the pipeline were closed everytime when
a workflow is done, if you have multiple workflows, streams will be
closed multiple times.

Closes woodpecker-ci#2036
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants