🐛 Bug Report: fetch:plain:file fails with stream is not readable #17072

punkle · 2023-03-24T09:16:49Z

📜 Description

When I created the following template step it fails with an error:

steps:
    - id: fetch-gitignore
      name: Fetch gitignore
      action: fetch:plain:file
      input:
        url: "https://github.com/AcmeInc/test123/blob/main/.gitignore"
        targetPath: '.gitignore'

👍 Expected behavior

i expect it to fetch the file and write it to the workspace directory at the targetPath

👎 Actual Behavior with Screenshots

It fails with the folling error:

2023-03-24T09:10:24.000Z Beginning step Fetch Repo
2023-03-24T09:10:24.000Z info: Fetching plain content from remote URL
2023-03-24T09:10:25.000Z InternalServerError: stream is not readable
    at readStream (/Users/brianfletcher/git-repos/backstage/node_modules/raw-body/index.js:185:17)
    at executor (/Users/brianfletcher/git-repos/backstage/node_modules/raw-body/index.js:120:5)
    at new Promise (<anonymous>)
    at getRawBody (/Users/brianfletcher/git-repos/backstage/node_modules/raw-body/index.js:119:10)
    at Object.buffer (webpack-internal:///../backend-common/src/reading/ReadUrlResponseFactory.ts:48:73)
    at fetchFile (webpack-internal:///../../plugins/scaffolder-backend/src/scaffolder/actions/builtin/fetch/helpers.ts:67:34)
    at async Object.handler (webpack-internal:///../../plugins/scaffolder-backend/src/scaffolder/actions/builtin/fetch/plainFile.ts:61:13)
    at async NunjucksWorkflowRunner.executeStep (webpack-internal:///../../plugins/scaffolder-backend/src/scaffolder/tasks/NunjucksWorkflowRunner.ts:196:13)
    at async NunjucksWorkflowRunner.execute (webpack-internal:///../../plugins/scaffolder-backend/src/scaffolder/tasks/NunjucksWorkflowRunner.ts:258:17)
    at async TaskWorker.runOneTask (webpack-internal:///../../plugins/scaffolder-backend/src/scaffolder/tasks/TaskWorker.ts:88:33)

👟 Reproduction steps

Create a template with the step shown above and run it.

📃 Provide the context for the Bug.

No response

🖥️ Your Environment

No response

👀 Have you spent some time to check if this bug has been raised before?

I checked and didn't find similar issue

🏢 Have you read the Code of Conduct?

I have read the Code of Conduct

Are you willing to submit PR?

Yes I am willing to submit a PR!

The text was updated successfully, but these errors were encountered:

punkle · 2023-03-24T09:17:10Z

Im happy to provide a PR, but I wouldnt know where to start with this.

punkle · 2023-03-24T15:23:24Z

@gavlyukovskiy are you finding it works for you?

gavlyukovskiy · 2023-03-24T16:25:45Z

@punkle It does work for me:

    - id: fetch-plain
      name: Fetch Plain
      action: fetch:plain:file
      input:
        url: https://github.com/gavlyukovskiy/spring-boot-data-source-decorator/blob/master/.gitignore
        targetPath: .gitignore

I can't access your repository, but for mine it works well.

gavlyukovskiy · 2023-03-24T16:52:00Z

@punkle well, I tried different combinations and it looks like it fails occasionally, especially first couple of seconds after starting with yarn dev, but not only.

I have tried adding more logging to GithubUrlReader after getting a response in readUrl, to see whether GH returns proper status code and response is readable:

this.logger.info(`Request ${ghUrl} -> ${response.status}, readable: ${response.body.readable}`)

but didn't find anything unusual:

[1] 2023-03-24T16:44:59.345Z backstage info Request https://raw.githubusercontent.com/gavlyukovskiy/spring-boot-data-source-decorator/master/.gitignore -> 200, readable: true 
[1] 2023-03-24T16:44:59.557Z backstage info Request https://raw.githubusercontent.com/gavlyukovskiy/spring-boot-data-source-decorator/master/.gitignore -> 200, readable: true

It's always 200 and readable true, even when Backstage task fails with

2023-03-24T16:44:59.000Z InternalServerError: stream is not readable
    at readStream (/Users/artur.h/dev/projects/backstage/node_modules/raw-body/index.js:185:17)
    at executor (/Users/artur.h/dev/projects/backstage/node_modules/raw-body/index.js:120:5)
    at new Promise (<anonymous>)
    at getRawBody (/Users/artur.h/dev/projects/backstage/node_modules/raw-body/index.js:119:10)
    at Object.buffer (webpack-internal:///../backend-common/src/reading/ReadUrlResponseFactory.ts:48:73)1
    at fetchFile (webpack-internal:///../../plugins/scaffolder-backend/src/scaffolder/actions/builtin/fetch/helpers.ts:67:34)1
    at async Object.handler (webpack-internal:///../../plugins/scaffolder-backend/src/scaffolder/actions/builtin/fetch/plainFile.ts:62:13)1
    at async NunjucksWorkflowRunner.executeStep (webpack-internal:///../../plugins/scaffolder-backend/src/scaffolder/tasks/NunjucksWorkflowRunner.ts:196:13)1
    at async NunjucksWorkflowRunner.execute (webpack-internal:///../../plugins/scaffolder-backend/src/scaffolder/tasks/NunjucksWorkflowRunner.ts:258:17)1
    at async TaskWorker.runOneTask (webpack-internal:///../../plugins/scaffolder-backend/src/scaffolder/tasks/TaskWorker.ts:88:33)

gavlyukovskiy · 2023-03-24T18:00:56Z

I've added more debug logs in various places and also close listener

    response.body.on("close", () => {
      getRootLogger().info("buffer close")
    })

and I think I know what is the problem:

[1] 2023-03-24T17:56:23.513Z backstage info Request https://raw.githubusercontent.com/gavlyukovskiy/spring-boot-data-source-decorator/master/.gitignore -> 200, readable: true 
[1] 2023-03-24T17:56:23.518Z backstage info fromNodeJSReadable readable: true 
[1] 2023-03-24T17:56:23.519Z backstage info fromReadable readable: true 
[1] 2023-03-24T17:56:23.526Z backstage info buffer close 
[1] 2023-03-24T17:56:23.527Z backstage info fromReadable.buffer readable: false

so body is closed before we could read it, but I have no idea what closes it, I didn't find any body.close() or body.destroy() calls. I'm not really node developer, but perhaps this helps somebody to investigate issue further 🤷

punkle · 2023-03-27T15:13:29Z

@gavlyukovskiy thanks for looking into it. Unfortunately I may not be able to help with identifying what might be causing that.

fabidick22 · 2023-04-19T15:56:59Z

Hi @gavlyukovskiy, I have the same problem, it seems to be related to private repository files. When I try to get the https://github.com/backstage/backstage/blob/master/mkdocs.yml file everything works fine, but when I try to get a repo from my organization (https://github.com/ORG/REPO/blob/main/mkdocs.yml) I get the same error.

2023-04-19T15:02:29.082Z Beginning step Get repo file
2023-04-19T15:02:29.091Z info: Fetching plain content from remote URL
2023-04-19T15:02:29.256Z InternalServerError: stream is not readable
    at readStream (/app/node_modules/raw-body/index.js:185:17)
    at executor (/app/node_modules/raw-body/index.js:120:5)

punkle · 2023-04-27T07:41:38Z

I wonder would someone in the @backstage/catalog-maintainers group be able to help us here. I believe the issue is being surfaced when accessing the buffer of the URL reader which I would expect would work in this case. Perhaps this task is not using the url reader correctly?

https://github.com/backstage/backstage/blob/master/plugins/scaffolder-backend/src/scaffolder/actions/builtin/fetch/helpers.ts#L79

eytanhanig · 2023-04-28T19:53:33Z

Ironically, it appears to work with the URL from the tests, https://github.com/backstage/community/tree/main/backstage-community-sessions/assets/Backstage%20Community%20Sessions.png.

Meanwhile, it fails for https://github.com/backstage/backstage/blob/master/plugins/scaffolder-backend/README.md.

punkle · 2023-05-02T10:05:33Z

@eytanhanig it is a little odd that it works some of the time. I am not sure yet what the pattern is.

benjdlambert · 2023-05-02T11:35:12Z

I wonder if this could be a node-fetch issue? Maybe moving over to using the built in fetch in node, and undici.stream something might be another debugging tool to see if we can work out what's going on here?

punkle · 2023-05-02T15:40:49Z

@benjdlambert can you elaborate a little? Which import would get us the fetch you are suggesting? At the moment the github url reader is using this: import fetch, { RequestInit, Response } from 'node-fetch';

What are you suggesting to try?

benjdlambert · 2023-05-03T07:51:21Z

I'm suggesting to use the new built in fetch with node, which is shipped as undici. You can see the docs for this https://undici.nodejs.org/#/?id=undicistreamurl-options-factory-promise and you can do undici.stream to basically give you a readable stream I think. It's not on the fetch like in node-fetch so you might have to change a few basic things to get it to work as it does today. Worth a try at least so we can see if it's anything to do with how we're using node-fetch or if it's something else.

require('undici').stream should be it

benjdlambert · 2023-05-03T07:51:51Z

I think you can even install that package as a seperate dependency too to backport it to older versions of node if you don't have it already.

benjdlambert · 2023-05-03T07:53:47Z

Sorry for the message spam, but there's also this docs here which might be of interest using the streams https://undici.nodejs.org/#/docs/api/Dispatcher?id=example-1-basic-get-stream-request

punkle · 2023-05-03T14:14:19Z

@benjdlambert something like this #17632

eytanhanig · 2023-05-18T18:14:02Z

Have there been any updates on this?

pcgqueiroz · 2023-07-14T08:56:50Z

Hey! I had the same issue and I have managed to fix the problem changing the order of calls in the fetchFile function.

    const res = await reader.readUrl(readUrl);
-   await fs.ensureDir(path.dirname(outputPath));
-   const buffer = await res.buffer();
+   const buffer = await res.buffer();
+   await fs.ensureDir(path.dirname(outputPath));    
    await fs.outputFile(outputPath, buffer.toString());

Please comment if this fix also works for you.

benjdlambert · 2023-07-17T08:50:32Z

Hmm that's an unexpected fix if that works 🤷 Looks like a race condition to me, I wondered if this was also perhaps related to the #18002 issue that was previously fixed recently?

pcgqueiroz · 2023-07-17T11:37:01Z

Hey @benjdlambert , I agree with you that it is an unexpected fix. It took me a while to discover it and, sincerely, I don´t know why this change fixes the problem.
The thing is that it worked for me and changing the order things are called do no harm for the code. I mean, no side effects apparently. I think it's worth a try.

benjdlambert · 2023-07-20T09:11:41Z

@eytanhanig @pcgqueiroz can you try the latest version of backstage 1.16 and see if you can reproduce it with this? And if you can, can we get a reproducible example that we can try with so we can dig into this further?

athifongoqa · 2023-08-24T20:19:01Z

Hey, has there been any progress/updates on this?

pedronastasi · 2023-09-26T18:27:32Z

I've got

{
  "version": "1.15.0"
}

and I'm facing the issue

benjdlambert · 2023-09-27T06:59:23Z

@pedronastasi can you update to the latest versions and see if the problem still persists? We made some changes in 1.16 but without reproduction case it's hard to see if we've fixed it or not.

alper98 · 2023-10-05T11:09:08Z

We're on 1.17.5, and have the same issue.

And can confirm that it works fine by fetching from public repositories, but when fetching from our org, it fails with stream is not readable

benjdlambert · 2023-10-09T11:33:41Z

Hey @alper98 would it be possible for you to create a reproduction repo or something with a basic create-app? This is hard to debug without a reliable reproduction case.

brunosantosnet · 2023-11-16T21:46:24Z

I've used fetch:plain:file several times without any problems. Now I have this problem

benjdlambert · 2023-11-17T13:21:44Z

@brunosantosnet is it possible that you can setup a minimal reproduction repository for this so we can dig in further? Also what change caused this to start breaking and failing? 🙏

brunosantosnet · 2023-11-17T22:56:45Z

@benjdlambert my scenario is the worst possible. There are repositories that using fetch:plain:file the error does not occur, I don't know why. When I use fetch:plain I only have problems in repositories with many objects :-(

benjdlambert · 2023-11-20T12:51:38Z

For people that have this issue, is it Node 20 or are we seeing it on Node 18 too?

benjdlambert · 2023-11-20T13:07:55Z

I think I have a fix, it's a similar fix to the other stream bug that we had. I managed to replicate this locally, but it doesn't happen every time, so I think that this works as I've not been able to reproduce it one using this fix.

#21417

benjdlambert · 2023-11-22T12:52:37Z

Can we verify that this is fixed by bumping to the latest -next release?

yarn backstage-cli versions:bump --release=next

pballandras · 2023-12-15T20:24:23Z

Can we verify that this is fixed by bumping to the latest -next release?

yarn backstage-cli versions:bump --release=next

@benjdlambert

Maybe you got your answer a while ago, but I was able to fix this issue by moving on to the 0.20.0-next.3 version of @backstage/backend-common. So it would look like this is fixed.

Cheers!

benjdlambert · 2023-12-18T10:31:41Z

Yep I think that this got released in the mainline release of 1.20 so should be fixed for everyone from that version 🤞

gavlyukovskiy · 2023-12-21T13:45:32Z

Hi @benjdlambert, unfortunately this is still the case on Backstage 1.20.3, but with gitlab url in format https://<url>/<group>/<repo>/blob/main/CODEOWNERS:

2023-12-21T13:34:06.384Z info: Fetching plain content from remote URL
2023-12-21T13:34:06.750Z InternalServerError: stream is not readable
    at readStream (/app/node_modules/@backstage/backend-common/node_modules/raw-body/index.js:185:17)
    at executor (/app/node_modules/@backstage/backend-common/node_modules/raw-body/index.js:120:5)
    at new Promise (<anonymous>)
    at Object.getRawBody [as default] (/app/node_modules/@backstage/backend-common/node_modules/raw-body/index.js:119:10)
    at Object.buffer (/app/node_modules/@backstage/backend-common/dist/index.cjs.js:1232:48)
    at Object.fetchFile (/app/node_modules/@backstage/plugin-scaffolder-node/dist/index.cjs.js:87:30)
    at async Object.handler (/app/node_modules/@backstage/plugin-scaffolder-backend/dist/cjs/router-68c854a3.cjs.js:724:7)
    at async NunjucksWorkflowRunner.executeStep (/app/node_modules/@backstage/plugin-scaffolder-backend/dist/cjs/router-68c854a3.cjs.js:7233:9)
    at async NunjucksWorkflowRunner.execute (/app/node_modules/@backstage/plugin-scaffolder-backend/dist/cjs/router-68c854a3.cjs.js:7306:9)
    at async TaskWorker.runOneTask (/app/node_modules/@backstage/plugin-scaffolder-backend/dist/cjs/router-68c854a3.cjs.js:7528:26)
    at async run (/app/node_modules/p-queue/dist/index.js:163:29)

but it's not consistent, approximately every second request fails.

benjdlambert · 2023-12-21T14:13:31Z

@gavlyukovskiy can you create a reproduction repo or something so that we can reproduce this easier? These things are hard to dig into otherwise.

gavlyukovskiy · 2023-12-21T15:53:07Z

@benjdlambert I've created a reproducer, though I cannot reproduce it with latest version v1.21.0 (or master), but I still can with v1.20.3:

git checkout v1.20.3

# add to remote templates: https://gitlab.com/agavlyukovskiy/backstage-17072/-/blob/main/template.yaml
yq eval '.spec.targets += "https://gitlab.com/agavlyukovskiy/backstage-17072/-/blob/main/template.yaml"' -i plugins/scaffolder-backend/sample-templates/remote-templates.yaml

yarn dev

then after using the template with url https://gitlab.com/agavlyukovskiy/backstage-17072/-/blob/main/CODEOWNERS (default) it returns InternalServerError: stream is not readable error.

We will upgrade our Backstage to the latest version tomorrow and I'll let you know if we still see that issue on our production instance.

gavlyukovskiy · 2023-12-21T16:06:34Z

@benjdlambert ah, I thought that your fix was in 1.20.3, but it only got into 1.21.0. Looks like it did fix the issue 👍

benjdlambert · 2023-12-22T08:59:03Z

Ah apologies - yeah looks like it did go out in 1.21.0, nice at least it's fixed! 🎉

punkle added the bug Something isn't working label Mar 24, 2023

Rugvip added help wanted Help/Contributions wanted from community members backend labels Mar 27, 2023

maciek-mckinsey mentioned this issue Jul 13, 2023

🐛 Bug Report: fetch helpers are not exported #18663

Closed

2 tasks

sblausten mentioned this issue Nov 10, 2023

🐛 Bug Report: publish:github:pull-request fails with HttpError: You have exceeded a secondary rate limit. #17188

Open

2 tasks

benjdlambert mentioned this issue Nov 20, 2023

Use Readable.from for streams #21417

Merged

benjdlambert closed this as completed in #21417 Nov 21, 2023

🐛 Bug Report: fetch:plain:file fails with stream is not readable #17072

🐛 Bug Report: fetch:plain:file fails with stream is not readable #17072

Comments

punkle commented Mar 24, 2023

📜 Description

👍 Expected behavior

👎 Actual Behavior with Screenshots

👟 Reproduction steps

📃 Provide the context for the Bug.

🖥️ Your Environment

👀 Have you spent some time to check if this bug has been raised before?

🏢 Have you read the Code of Conduct?

Are you willing to submit PR?

punkle commented Mar 24, 2023

punkle commented Mar 24, 2023 • edited

gavlyukovskiy commented Mar 24, 2023

gavlyukovskiy commented Mar 24, 2023

gavlyukovskiy commented Mar 24, 2023

punkle commented Mar 27, 2023

fabidick22 commented Apr 19, 2023

punkle commented Apr 27, 2023

eytanhanig commented Apr 28, 2023

punkle commented May 2, 2023

benjdlambert commented May 2, 2023

punkle commented May 2, 2023

benjdlambert commented May 3, 2023 • edited

benjdlambert commented May 3, 2023

benjdlambert commented May 3, 2023

punkle commented May 3, 2023

eytanhanig commented May 18, 2023

pcgqueiroz commented Jul 14, 2023

benjdlambert commented Jul 17, 2023

pcgqueiroz commented Jul 17, 2023

benjdlambert commented Jul 20, 2023

athifongoqa commented Aug 24, 2023

pedronastasi commented Sep 26, 2023

benjdlambert commented Sep 27, 2023

alper98 commented Oct 5, 2023 • edited

benjdlambert commented Oct 9, 2023

brunosantosnet commented Nov 16, 2023

benjdlambert commented Nov 17, 2023

brunosantosnet commented Nov 17, 2023

benjdlambert commented Nov 20, 2023

benjdlambert commented Nov 20, 2023

benjdlambert commented Nov 22, 2023

pballandras commented Dec 15, 2023

benjdlambert commented Dec 18, 2023

gavlyukovskiy commented Dec 21, 2023

benjdlambert commented Dec 21, 2023

gavlyukovskiy commented Dec 21, 2023 • edited

gavlyukovskiy commented Dec 21, 2023

benjdlambert commented Dec 22, 2023

punkle commented Mar 24, 2023 •

edited

benjdlambert commented May 3, 2023 •

edited

alper98 commented Oct 5, 2023 •

edited

gavlyukovskiy commented Dec 21, 2023 •

edited