search

minio / mc

Simple | Fast tool to manage MinIO clusters :cloud:
https://min.io/download
GNU Affero General Public License v3.0
2.82k stars 541 forks source link

Latest release causes stdout issues - stdout hanging on multiple commands #3938

Closed denizsokullu closed 2 years ago

denizsokullu commented 2 years ago

NOTE

If this case is urgent, please subscribe to Subnet so that our 24/7 support team may help you faster.

Expected Behavior

The command should run and finish. Edit: I guess this is a mc issue, not minio.

Current Behavior

The command hangs in CI(linux environment)

#!/bin/bash -eo pipefail
wget https://dl.min.io/client/mc/release/linux-amd64/mc
chmod +x mc
./mc config host add minio $MINIO_ENDPOINT $MINIO_KEY $MINIO_SECRET
./mc mb minio/bucket1
./mc mb minio/bucket2

Output:

--2022-01-25 23:47:29--  https://dl.min.io/client/mc/release/linux-amd64/mc
Resolving dl.min.io (dl.min.io)... 178.128.69.202, 138.68.11.125
Connecting to dl.min.io (dl.min.io)|178.128.69.202|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 22315008 (21M) [application/octet-stream]
Saving to: ‘mc’

mc                  100%[===================>]  21.28M  15.2MB/s    in 1.4s    

2022-01-25 23:47:31 (15.2 MB/s) - ‘mc’ saved [22315008/22315008]

]11;?\mc: Configuration written to `/home/circleci/.mc/config.json`. Please update your access credentials.
mc: Successfully created `/home/circleci/.mc/share`.
mc: Initialized share uploads `/home/circleci/.mc/share/uploads.json` file.
mc: Initialized share downloads `/home/circleci/.mc/share/downloads.json` file.
Added `minio` successfully.
]11;?\Bucket created successfully `minio/bucket1`.
]11;?\

Possible Solution

Splitting the commands right after ./mc config ... fixes it.

Steps to Reproduce (for bugs)

  1. The commands below are ran in a linux based container on CircleCI(a CI provider) 
    #!/bin/bash -eo pipefail
wget https://dl.min.io/client/mc/release/linux-amd64/mc
chmod +x mc
./mc config host add minio $MINIO_ENDPOINT $MINIO_KEY $MINIO_SECRET
./mc mb minio/bucket1
./mc mb minio/bucket2
  2. It hangs after

Context

This is a pipeline that has been running fine for 2 years-ish. We haven't updated any of the base images or configuration. Minio released a new version yesterday and it exactly started happening after that release. I'm not saying the release is the cause but I don't have much else to point at.

One note. The symbols that can't be shown properly in the stdout did not happen on the release before the latest. It might be indicating a problem.

Regression

YES

Latest release

Your Environment

vadmeste commented 2 years ago

Minio released a new version yesterday and it exactly started happening after that release

I guess you need to look for logs there

denizsokullu commented 2 years ago

I don't see anything suspicious in https://github.com/minio/mc/releases/tag/RELEASE.2022-01-25T21-02-01Z except for a PR that updated the loading spinners for the tool. Any thoughts on how that could be affecting this? If you don't think this is minio/mc related you can close this issue.

SethTales commented 2 years ago

I am also experiencing this same problem

vadmeste commented 2 years ago

Can we articulate what is exactly the problem ?

denizsokullu commented 2 years ago

I've put together this Dockerfile and small script but I can't seem to recreate the issue on it. It's as close as I can get to the environment.(docker build .; docker run -i -t {the sha of the image})

Dockerfile

FROM circleci/php:7.3
COPY minio.sh minio.sh
CMD ./minio.sh

minio.sh

#!/bin/bash

sudo wget https://dl.min.io/server/minio/release/linux-amd64/minio
sudo chmod +x minio
sudo mkdir ./data
sudo chown -R circleci ./data
sudo chmod u+rxw ./data
./minio server ./data --address=:3000 &

sleep 2

sudo wget https://dl.min.io/client/mc/release/linux-amd64/mc
sudo chmod +x mc

./mc config host add minio http://127.0.0.1:3000 minioadmin minioadmin
./mc mb minio/test1
./mc mb minio/test2

There might be something that I don't know about the CI environment but here is the 'definition of the issue': Any 3 mc commands run one after another cause the last one to hang and never finish. I have done something to alleviate the issue and have no more time to investigate the reason behind it.

harshavardhana commented 2 years ago

./mc config host add minio http://127.0.0.1:3000 minioadmin minioadmin ./mc mb minio/test1 ./mc mb minio/test2

Can you add --debug for mc

denizsokullu commented 2 years ago 
#!/bin/bash -eo pipefail
./mc mb --debug minio/test1
./mc mb --debug minio/test2
./mc mb --debug minio/test3
]11;?\mc: <DEBUG> PUT /test1/ HTTP/1.1
Host: 127.0.0.1:3000
User-Agent: MinIO (linux; amd64) minio-go/v7.0.20 mc/RELEASE.2022-01-25T21-02-01Z
Content-Length: 0
Authorization: AWS4-HMAC-SHA256 Credential=minioadmin/20220126/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=**REDACTED**
X-Amz-Content-Sha256: UNSIGNED-PAYLOAD
X-Amz-Date: 20220126T194340Z
Accept-Encoding: gzip

mc: <DEBUG> HTTP/1.1 200 OK
Content-Length: 0
Accept-Ranges: bytes
Content-Security-Policy: block-all-mixed-content
Date: Wed, 26 Jan 2022 19:43:40 GMT
Location: /test1
Server: MinIO
Strict-Transport-Security: max-age=31536000; includeSubDomains
Vary: Origin
Vary: Accept-Encoding
X-Amz-Request-Id: 16CDE98A854E77B8
X-Content-Type-Options: nosniff
X-Xss-Protection: 1; mode=block

mc: <DEBUG> Response Time:  1.315734ms

Bucket created successfully `minio/test1`.
]11;?\mc: <DEBUG> PUT /test2/ HTTP/1.1
Host: 127.0.0.1:3000
User-Agent: MinIO (linux; amd64) minio-go/v7.0.20 mc/RELEASE.2022-01-25T21-02-01Z
Content-Length: 0
Authorization: AWS4-HMAC-SHA256 Credential=minioadmin/20220126/us-east-1/s3/aws4_request, SignedHeaders=host;x-amz-content-sha256;x-amz-date, Signature=**REDACTED**
X-Amz-Content-Sha256: UNSIGNED-PAYLOAD
X-Amz-Date: 20220126T194340Z
Accept-Encoding: gzip

mc: <DEBUG> HTTP/1.1 200 OK
Content-Length: 0
Accept-Ranges: bytes
Content-Security-Policy: block-all-mixed-content
Date: Wed, 26 Jan 2022 19:43:40 GMT
Location: /test2
Server: MinIO
Strict-Transport-Security: max-age=31536000; includeSubDomains
Vary: Origin
Vary: Accept-Encoding
X-Amz-Request-Id: 16CDE98A870299E0
X-Content-Type-Options: nosniff
X-Xss-Protection: 1; mode=block

mc: <DEBUG> Response Time:  1.255731ms

Bucket created successfully `minio/test2`.

The logs for the process above are still waiting on output. The process did not exit somehow.

denizsokullu commented 2 years ago
Screen Shot 2022-01-26 at 2 47 13 PM
harshavardhana commented 2 years ago

The logs for the process above are still waiting on output. The process did not exit somehow.

I suspect the mc has exited already @denizsokullu there is something else going on here.

LinAnt commented 2 years ago

We are also experiencing this.

Like in the original issue, we are also using CircleCi. The mc command we run is:

mc cp -r -q ./path-to-thing cool-bucket/

What is interesting is that I get more output if I exec into the container:

mc: <ERROR> Failed to copy `weathericons-regular-webfont.1341a15172cec8dae06e.svg`. Object name contains unsupported characters.
harshavardhana commented 2 years ago

Most probably its a TTY problem - when you don't have a tty

harshavardhana commented 2 years ago

NOTE: We use mc in GitHub actions do not see a problem there https://github.com/minio/minio/blob/master/docs/bucket/replication/setup_3site_replication.sh

I suspect something is up with CircleCI here - @LinAnt can you confirm if your issue is seen with GitHub Actions as well?

LinAnt commented 2 years ago

I fired up the exact same commit workflow using https://dl.min.io/client/mc/release/linux-amd64/archive/mc.RELEASE.2022-01-07T06-01-38Z and it succeeds without issue, so I still suspect there is something funky in the new mc release.

I don't run gh actions anywhere :S

harshavardhana commented 2 years ago

I don't see how is this an mc problem still unless we get more details here. Since they run fine in GitHub actions I don't see where there is a problem.

I tried the Docker container locally no problems were found either. Tried in k8s no problems were found either.

Beyond this, we will have to chase down what the heck CircleCI does with its TTY - this is not going to take time.

giardltd commented 2 years ago

We are having the exact same issue on a docker image fired up through a concourse pipeline. this had been working for months.

giardltd commented 2 years ago

We have rolled back to previous RELEASE.2022-01-07T06-01-38Z problem fixed. lol

harshavardhana commented 2 years ago

One note. The symbols that can't be shown properly in the stdout did not happen on the release before the latest. It might be indicating a problem.

This might be something to think about let me check who is controlling the TTY at this point.

harshavardhana commented 2 years ago

@giardltd @LinAnt would it be possible to run a strace -f -o /tmp/mc.out on the mc command and share the result here?

harshavardhana commented 2 years ago

This is because of the lipgloss dependency added recently 

#!/bin/bash -eo pipefail
docker build . -t mc-debug
docker run -it mc-debug

Sending build context to Docker daemon  64.51kB
Step 1/3 : FROM circleci/php:7.3
7.3: Pulling from circleci/php

68f74026: Pulling fs layer 
c1c4d556: Pulling fs layer 
b6beb07a: Pulling fs layer 
148cff9a: Pulling fs layer 
1cd4227b: Pulling fs layer 
d2802f6d: Pulling fs layer 
ea503d22: Pulling fs layer 
62248d4b: Pulling fs layer 
4a5e69b5: Pulling fs layer 
87a948ff: Pulling fs layer 
9b468d0e: Pulling fs layer 
408b0377: Pulling fs layer 
0a1f6be9: Pulling fs layer 
803fc5b0: Pulling fs layer 
ddd4bc0c: Pulling fs layer 
3db7e723: Pulling fs layer 
7efdf0d1: Pulling fs layer 
e22d2f45: Pulling fs layer 
7931260d: Pulling fs layer 
18228f7d: Pulling fs layer 
aff543e0: Pulling fs layer 
071d8578: Pulling fs layer 
dee07bbd: Pulling fs layer 
70b872d0: Pulling fs layer 
a1f6be9: Extracting  31.75MB/131MBkBB
a1f6be9: Extracting  66.29MB/131MB
a1f6be9: Extracting  82.44MB/131MB
a1f6be9: Extracting  101.9MB/131MB
a1f6be9: Extracting  116.4MB/131MB
dd4bc0c: Pull complete .74MB/1.74MB
db7e723: Extracting  17.83MB/61.18MB
db7e723: Extracting  36.77MB/61.18MB
db7e723: Extracting  53.48MB/61.18MB
7931260d: Extracting  5.377kB/5.377kB
dee07bbd: Extracting   1.18MB/16.83MB
Digest: sha256:1a1d719f343f250605a0bb37d78d6aa487e328d87e6b3c852f8662f2ac461beb
Status: Downloaded newer image for circleci/php:7.3
 ---> 68e5c76e3bf9
Step 2/3 : COPY minio.sh minio.sh
 ---> 33ad3154f8ee
Step 3/3 : CMD ./minio.sh
 ---> Running in c17cc7ae8741
Removing intermediate container c17cc7ae8741
 ---> 19f340645a2c
Successfully built 19f340645a2c
Successfully tagged mc-debug:latest
^@^@--2022-01-28 05:07:16--  https://dl.min.io/server/minio/release/linux-amd64/minio
Resolving dl.min.io (dl.min.io)... 178.128.69.202, 138.68.11.125
Connecting to dl.min.io (dl.min.io)|178.128.69.202|:443... connected.
HTTP request sent, awaiting response... 
200 OK
Length: 108453888 (103M) [application/octet-stream]
Saving to: ‘minio’

minio                 8%[>                   ]   9.12M  22.3MB/s               
minio                36%[======>             ]  37.34M  46.0MB/s               
minio                76%[==============>     ]  78.93M  55.3MB/s               
minio               100%[===================>] 103.43M  57.5MB/s    in 1.8s    

2022-01-28 05:07:18 (57.5 MB/s) - ‘minio’ saved [108453888/108453888]

WARNING: Detected default credentials 'minioadmin:minioadmin', we recommend that you change these values with 'MINIO_ROOT_USER' and 'MINIO_ROOT_PASSWORD' environment variables
API: http://172.17.0.2:3000  http://127.0.0.1:3000 
RootUser: minioadmin 
RootPass: minioadmin 

Console: http://172.17.0.2:37185 http://127.0.0.1:37185 
RootUser: minioadmin 
RootPass: minioadmin 

Command-line: https://docs.min.io/docs/minio-client-quickstart-guide
   $ mc alias set myminio http://172.17.0.2:3000 minioadmin minioadmin

Documentation: https://docs.min.io

WARNING: Console endpoint is listening on a dynamic port (37185), please use --console-address ":PORT" to choose a static port.

--2022-01-28 05:07:20--  https://dl.min.io/client/mc/release/linux-amd64/mc
Resolving dl.min.io (dl.min.io)... 178.128.69.202, 138.68.11.125
Connecting to dl.min.io (dl.min.io)|178.128.69.202|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: 22315008 (21M) [application/octet-stream]
Saving to: ‘mc’

mc                   42%[=======>            ]   9.10M  22.4MB/s               
mc                  100%[===================>]  21.28M  37.2MB/s    in 0.6s    

2022-01-28 05:07:21 (37.2 MB/s) - ‘mc’ saved [22315008/22315008]

]11;?\mc: Configuration written to `/home/circleci/.mc/config.json`. Please update your access credentials.
mc: Successfully created `/home/circleci/.mc/share`.
mc: Initialized share uploads `/home/circleci/.mc/share/uploads.json` file.
mc: Initialized share downloads `/home/circleci/.mc/share/downloads.json` file.
Added `minio` successfully.
]11;?\Bucket created successfully `minio/test1`.
]11;?\
SIGABRT: abort
PC=0x47f1d9 m=0 sigcode=0

goroutine 1 [syscall, locked to thread]:
syscall.Syscall(0x0, 0x1, 0xc00019f867, 0x1)
    syscall/asm_linux_amd64.s:20 +0x5 fp=0xc00019f710 sp=0xc00019f708 pc=0x47f1c5
syscall.read(0xc0000aa060, {0xc00019f867, 0xc00019f870, 0x4f1a94})
    syscall/zsyscall_linux_amd64.go:687 +0x4d fp=0xc00019f768 sp=0xc00019f710 pc=0x47ca8d
syscall.Read(...)
    syscall/syscall_unix.go:189
internal/poll.ignoringEINTRIO(...)
    internal/poll/fd_unix.go:582
internal/poll.(*FD).Read(0xc0000aa060, {0xc00019f867, 0x1, 0x1})
    internal/poll/fd_unix.go:163 +0x285 fp=0xc00019f7e8 sp=0xc00019f768 pc=0x49f545
os.(*File).read(...)
    os/file_posix.go:32
os.(*File).Read(0xc0000a8008, {0xc00019f867, 0x4ebaaa, 0x190ccc0})
    os/file.go:119 +0x5e fp=0xc00019f840 sp=0xc00019f7e8 pc=0x4a871e
github.com/muesli/termenv.readNextByte(0x4ebe74)
    github.com/muesli/termenv@v0.9.0/termenv_unix.go:88 +0x2b fp=0xc00019f878 sp=0xc00019f840 pc=0x897e4b
github.com/muesli/termenv.readNextResponse(0x119f580)
    github.com/muesli/termenv@v0.9.0/termenv_unix.go:104 +0x25 fp=0xc00019f8e0 sp=0xc00019f878 pc=0x897ec5
github.com/muesli/termenv.termStatusReport(0x6)
    github.com/muesli/termenv@v0.9.0/termenv_unix.go:200 +0x209 fp=0xc00019f9f8 sp=0xc00019f8e0 pc=0x898329
github.com/muesli/termenv.backgroundColor()
    github.com/muesli/termenv@v0.9.0/termenv_unix.go:65 +0x25 fp=0xc00019fa48 sp=0xc00019f9f8 pc=0x897d25
github.com/muesli/termenv.BackgroundColor()
    github.com/muesli/termenv@v0.9.0/termenv.go:50 +0x5e fp=0xc00019fa68 sp=0xc00019fa48 pc=0x897a9e
github.com/muesli/termenv.HasDarkBackground()
    github.com/muesli/termenv@v0.9.0/termenv.go:55 +0x19 fp=0xc00019fa90 sp=0xc00019fa68 pc=0x897af9
github.com/charmbracelet/lipgloss.init()
    github.com/charmbracelet/lipgloss@v0.4.0/color.go:19 +0x17 fp=0xc00019faa0 sp=0xc00019fa90 pc=0xce28f7
runtime.doInit(0x18917c0)
    runtime/proc.go:6498 +0x123 fp=0xc00019fbd8 sp=0xc00019faa0 pc=0x445483
runtime.doInit(0x188da20)
    runtime/proc.go:6475 +0x71 fp=0xc00019fd10 sp=0xc00019fbd8 pc=0x4453d1
runtime.doInit(0x18a0c60)
    runtime/proc.go:6475 +0x71 fp=0xc00019fe48 sp=0xc00019fd10 pc=0x4453d1
runtime.doInit(0x1889f00)
    runtime/proc.go:6475 +0x71 fp=0xc00019ff80 sp=0xc00019fe48 pc=0x4453d1
runtime.main()
    runtime/proc.go:238 +0x1e6 fp=0xc00019ffe0 sp=0xc00019ff80 pc=0x438146
runtime.goexit()
    runtime/asm_amd64.s:1581 +0x1 fp=0xc00019ffe8 sp=0xc00019ffe0 pc=0x468f2

Here is the main code where it holds a lock on TTY and never relinquishes

github.com/muesli/termenv.readNextByte(0x4ebe74)
    github.com/muesli/termenv@v0.9.0/termenv_unix.go:88 +0x2b fp=0xc00019f878 sp=0xc00019f840 pc=0x897e4b
harshavardhana commented 2 years ago

@muesli would you be able to provide some guidance here?

harshavardhana commented 2 years ago

The odd characters is the correct indication there is a problem

]11;?\mc: Configuration written to `/home/circleci/.mc/config.json`. Please update your access credentials.
mc: Successfully created `/home/circleci/.mc/share`.
mc: Initialized share uploads `/home/circleci/.mc/share/uploads.json` file.
mc: Initialized share downloads `/home/circleci/.mc/share/downloads.json` file.
Added `minio` successfully.
+ ./mc mb minio/test1
]11;?\Bucket created successfully `minio/test1`.
+ ./mc mb minio/test2
]11;?\
harshavardhana commented 2 years ago

The issue arises from

Perhaps the odd characters are

Looks like the assumption here that CI/CD terminals support these control characters is perhaps not right or maybe it is just that these CI/CDs might not implement all these correctly.

Iincompletely written virtual terminals such as CI/CD terminals have this problem.

For example, GitHub actions do not but CircleCI and perhaps also Concourse CI has this issue.

A workaround here is to set TERM=screen instead of default xterm and this seems to work and it won't hang anymore. 

#!/bin/bash

export TERM=screen

sudo wget https://dl.min.io/server/minio/release/linux-amd64/minio
sudo chmod +x minio
sudo mkdir ./data
sudo chown -R circleci ./data
sudo chmod u+rxw ./data
./minio server ./data --address=:3000 &

sleep 2

sudo wget https://dl.min.io/client/mc/release/linux-amd64/mc
sudo chmod +x mc

./mc config host add minio http://127.0.0.1:3000 minioadmin minioadmin
./mc mb minio/test1
./mc mb minio/test2

@LinAnt @denizsokullu @giardltd

muesli commented 2 years ago

(co-)Author of lipgloss and termenv here.

The situation

What's happening here is that termenv first checks whether stdout is attached to a terminal, and if it is, it tries to query the current background color setting via OSC. CircleCI never responds to that query and we're stuck waiting for an uncancelable read.

The workaround

Setting TERM to screen prevents this from happening, as terminal multiplexers can't correctly respond to OSC queries. termenv anticipates that and skips the queries altogether.

Open questions

Why does CircleCI claim stdout is attached to a terminal when it isn't? If anyone knows why CircleCI behaves the way it does, I'd love to hear about it.

How to fix/improve this

The quick-fix would be adding CircleCI as an exception for OSC queries in termenv (a bit like screen). We should also revert to "lazily" querying the terminal on init. In other words: if we never access the terminal's color settings, there's no need to query them. Ideally we also introduce a cancel-able reader, so we can abort the query after a (rather short) timeout.

I'm fairly confident we can get a quick fix out for this today. I'll ping you and provide a PR to bump the dependencies as soon as we're ready.

muesli commented 2 years ago

I've pushed a simple fix that checks for the presence of a CI environment variable: it assumes that these CI systems don't (fully) conform with terminal control sequences / OSC and skips the terminal queries. It's not the nicest of fixes, but apparently necessary. As I've laid out in my previous comment, there are other fixes we'll follow up with and that prevent this from happening, even without the presence of an environment variable.

I'd appreciate it if some of you could test this fix in their environments, as I obviously can't possibly replicate all your setups & use cases locally :heart:

Apologies for the issues this caused and thank you for the detailed reports!

LinAnt commented 2 years ago

Got other issues on the table today, but I will give it a spin on Monday morning :)

harshavardhana commented 2 years ago

You have to set CI=1 to ignore the TTY presented by CircleCI and Concourse CI for now. 


#!/bin/bash

set -x

export CI=1 # to make sure terminal doesn't hang
sudo wget https://dl.min.io/server/minio/release/linux-amd64/minio
sudo chmod +x minio
sudo mkdir ./data
sudo chown -R circleci ./data
sudo chmod u+rxw ./data
./minio server ./data --address=:3000 &

sleep 2

sudo wget https://dl.min.io/client/mc/release/linux-amd64/mc
sudo chmod +x mc

./mc config host add minio http://127.0.0.1:3000 minioadmin minioadmin
./mc mb minio/test1
./mc mb minio/test2

This works, alternatively, you can also do export TERM=screen

@muesli perhaps you should have a specific timeout on the fd by having an external context and then close the fd when the context times out is an easier solution. A side effect of this is - it shall potentially add further delays on command startups.

Whoever has a paid account with CircleCI please bring this to their attention as many other tools might get affected by this if anyone tries to do OSC querying on the os.Stdout

Closing this out as fully resolved so that this answer stays in as the final resolution on this for now.

harshavardhana commented 2 years ago

To update why CirclCI won't work automatically is because CI environment variable is only available as part of the shell that is running the command however if you run your jobs as part of docker container the shell environment doesn't pass on the CI environment variable into the container.

This leads to similar behavior as seen in the issue https://github.com/harshavardhana/mc-debug/pull/1/files - here is how one can reproduce it every time without setting CI=1 manually inside your shell scripts before invoking mc

// cc @muesli

So a comprehensive fix is still needed for the termenv library - but this workaround works for now and I think everyone can update their scripts locally as a workaround.

harshavardhana commented 2 years ago

The latest mc release has this comprehensively fixed - no more CI=true needed - https://app.circleci.com/pipelines/github/harshavardhana/mc-debug/10/workflows/d0eefcf9-f745-4a4b-a6d4-e413aaf177f2/jobs/11

Thanks a lot for quick turn-around @muesli

harshavardhana commented 2 years ago

Looks like there is another remnant of this problem #3955