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

Strange error message when trying to use plugin-git #147

Closed
bjodah opened this issue May 22, 2024 · 18 comments
Closed

Strange error message when trying to use plugin-git #147

bjodah opened this issue May 22, 2024 · 18 comments

Comments

@bjodah
Copy link

bjodah commented May 22, 2024

I'm trying to do a full checkout in my .woodpecker.yaml, so I added this block (verbatim from the documentation):

clone:
  - name: git
    image: woodpeckerci/plugin-git
    settings:
      partial: false
      depth: 50

However, instead of getting a normal log for this step (called "git"), I get:

Oh no, we got some errors!
Error response from daemon: open /var/lib/docker/overlay2/93a90a69b5e1b59b33054616556fb6d2f5015dff02adba21d83aab890c27ad76/.tmp-committed1531029885: no such file or directory

any idea how I could troubleshoot this?

@qwerty287
Copy link
Contributor

Do you get this with other containers/steps too?

@bjodah
Copy link
Author

bjodah commented May 22, 2024

No, without the clone:-block everything works fine.
I even converted from an older .drone.yml file, and forgot to update the - clone block, so I ran with this block:

clone:
  default:
    image: plugins/git
    recursive: true
    submodule_override:
      finitediff/external/newton_interval: git://github.com/bjodah/newton_interval.git

this did actually run, and gave me a proper log:

+ git init
Initialized empty Git repository in /woodpecker/src/github.com/bjodah/finitediff/.git/
+ git remote add origin https://github.com/bjodah/finitediff.git
+ git fetch --no-tags origin +refs/heads/update-ci:
From https://github.com/bjodah/finitediff
 * branch            update-ci  -> FETCH_HEAD
 * [new branch]      update-ci  -> origin/update-ci
+ git reset --hard -q 6425c435fa2af019743e96932a734e2bef6b9d09
+ git submodule update --init --recursive
Submodule 'finitediff/external/newton_interval' (git://github.com/bjodah/newton_interval) registered for path 'finitediff/external/newton_interval'
Cloning into '/woodpecker/src/github.com/bjodah/finitediff/finitediff/external/newton_interval'...
fatal: unable to look up github.com (port 9418) (Try again)
fatal: clone of 'git://github.com/bjodah/newton_interval' into submodule path '/woodpecker/src/github.com/bjodah/finitediff/finitediff/external/newton_interval' failed
Failed to clone 'finitediff/external/newton_interval'. Retry scheduled
Cloning into '/woodpecker/src/github.com/bjodah/finitediff/finitediff/external/newton_interval'...
fatal: unable to look up github.com (port 9418) (Try again)
fatal: clone of 'git://github.com/bjodah/newton_interval' into submodule path '/woodpecker/src/github.com/bjodah/finitediff/finitediff/external/newton_interval' failed
Failed to clone 'finitediff/external/newton_interval' a second time, aborting
time="2024-05-22T10:49:20Z" level=fatal msg="exit status 1"

there you see that it cannot resolve "github.com", this is because it is lacking the environment variables http_proxy and https_proxy. (those are set in my docker-compose.yml file so that they are defined for for both the woodpecker-server and woodpecker-agent containers).

(never mind the submodule_override bit, it's even using the git:// protocol no longer supported by github)

EDIT2:

Actually, dropping the submodule_override allows me to successfully clone using this block:

clone:
  default:
    image: plugins/git
    recursive: true

but that's using Drone's plugin, no? So I better change to woodpecker's for future compatibility guarantees?

@qwerty287
Copy link
Contributor

but that's using Drone's plugin, no?

Yes, that's the drone one.
Would probably be better to use ours, yes, but there shouldn't be something breaking, at least I'm not aware of.

What happens if you just use

clone:
  - name: git
    image: woodpeckerci/plugin-git

?

@bjodah
Copy link
Author

bjodah commented May 23, 2024

Then I get this:
bild

If I instead use:

clone:
  - name: git
    image: plugins/git

I get:
bild

@qwerty287
Copy link
Contributor

That's really weird.

Can you check the logs of woodpecker, docker etc.? Is there an error?

@bjodah
Copy link
Author

bjodah commented May 23, 2024

Sure, this is after I push a commit which uses woodpeckerci/plugin-git.

For the server:

$ docker logs woodpeckerci-woodpecker-server-1 2>&1 | tail -n 5
{"level":"error","repo_id":"12","pipeline_id":"537","workflow_id":"412","error":"sql: no rows in result set","time":"2024-05-23T13:43:47Z","message":"queue.Done: cannot ack workflow"}
{"level":"error","repo_id":"12","pipeline_id":"537","workflow_id":"412","error":"stream: not found","time":"2024-05-23T13:43:48Z","message":"done: cannot close log stream for step 1462"}
{"level":"error","repo_id":"12","pipeline_id":"537","workflow_id":"412","error":"stream: not found","time":"2024-05-23T13:43:48Z","message":"done: cannot close log stream for step 1463"}
{"level":"error","repo_id":"12","pipeline_id":"537","workflow_id":"412","error":"stream: not found","time":"2024-05-23T13:43:48Z","message":"done: cannot close log stream for step 1464"}
{"level":"error","repo_id":"12","pipeline_id":"537","workflow_id":"412","error":"stream: not found","time":"2024-05-23T13:43:48Z","message":"done: cannot close log stream for step 1465"}

For the agent:

$ docker logs woodpeckerci-woodpecker-agent-1 2>&1 | tail -n 2
{"level":"error","error":"rpc error: code = Unknown desc = step finished with exit code 1, Error response from daemon: open /var/lib/docker/overlay2/93a90a69b5e1b59b33054616556fb6d2f5015dff02adba21d83aab890c27ad76/.tmp-committed2378443676: no such file or directory","time":"2024-05-23T13:43:47Z","message":"grpc error: wait(): code: Unknown"}
{"level":"warn","repo":"bjodah/finitediff","pipeline":"44","id":"412","error":"rpc error: code = Unknown desc = step finished with exit code 1, Error response from daemon: open /var/lib/docker/overlay2/93a90a69b5e1b59b33054616556fb6d2f5015dff02adba21d83aab890c27ad76/.tmp-committed2378443676: no such file or directory","time":"2024-05-23T13:43:47Z","message":"cancel signal received"}

For docker:

$ tail -n 11 /var/log/docker.log
2024/05/23 15:41:17 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
time="2024-05-23T15:43:47.406756898+02:00" level=error msg="Handler for POST /v1.43/containers/create returned error: open /var/lib/docker/overlay2/93a90a69b5e1b59b33054616556fb6d2f5015dff02adba21d83aab890c27ad76/.tmp-committed2378443676: no such file or directory"
2024/05/23 15:43:53 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/23 15:44:07 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/23 15:45:06 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/23 15:45:11 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/23 15:45:39 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/23 15:45:43 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/23 15:48:18 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/23 15:48:56 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/23 15:49:02 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)

If i then push a commit reverting back to using plugins/git, I see some more rows in docker.log:

time="2024-05-23T15:55:20.700112733+02:00" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
time="2024-05-23T15:55:20.700181877+02:00" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
time="2024-05-23T15:55:20.700199463+02:00" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
time="2024-05-23T15:55:20.700344158+02:00" level=info msg="loading plugin \"io.containerd.ttrpc.v1.pause\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
2024/05/23 15:55:21 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
time="2024-05-23T15:55:22.231370045+02:00" level=info msg="ignoring event" container=3f468545edad3f8177caa714f6ddff90284ee1ca33dd5094195d28addb2c271e module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
time="2024-05-23T15:55:22.231423745+02:00" level=info msg="shim disconnected" id=3f468545edad3f8177caa714f6ddff90284ee1ca33dd5094195d28addb2c271e namespace=moby
time="2024-05-23T15:55:22.231474662+02:00" level=warning msg="cleaning up after shim disconnected" id=3f468545edad3f8177caa714f6ddff90284ee1ca33dd5094195d28addb2c271e namespace=moby
time="2024-05-23T15:55:22.231488268+02:00" level=info msg="cleaning up dead shim" namespace=moby
time="2024-05-23T15:55:23.119780234+02:00" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
time="2024-05-23T15:55:23.119843536+02:00" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
time="2024-05-23T15:55:23.119858677+02:00" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
time="2024-05-23T15:55:23.119965634+02:00" level=info msg="loading plugin \"io.containerd.ttrpc.v1.pause\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
2024/05/23 15:55:23 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
time="2024-05-23T15:55:43.165395909+02:00" level=info msg="shim disconnected" id=f46c7da5c2851862acef4e55ce3b52f3d02e41b3d24260dc916543856d7ed96f namespace=moby
time="2024-05-23T15:55:43.165485964+02:00" level=warning msg="cleaning up after shim disconnected" id=f46c7da5c2851862acef4e55ce3b52f3d02e41b3d24260dc916543856d7ed96f namespace=moby
time="2024-05-23T15:55:43.165502632+02:00" level=info msg="cleaning up dead shim" namespace=moby
time="2024-05-23T15:55:43.165680562+02:00" level=info msg="ignoring event" container=f46c7da5c2851862acef4e55ce3b52f3d02e41b3d24260dc916543856d7ed96f module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
time="2024-05-23T15:55:44.317421539+02:00" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
time="2024-05-23T15:55:44.317531624+02:00" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
time="2024-05-23T15:55:44.317554833+02:00" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
time="2024-05-23T15:55:44.317673705+02:00" level=info msg="loading plugin \"io.containerd.ttrpc.v1.pause\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
2024/05/23 15:55:44 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
time="2024-05-23T15:55:53.854077568+02:00" level=info msg="shim disconnected" id=39ab2d18734d4a499b0691860cfb1ff339397e2098a920508586ec8c006eed7d namespace=moby
time="2024-05-23T15:55:53.854186027+02:00" level=warning msg="cleaning up after shim disconnected" id=39ab2d18734d4a499b0691860cfb1ff339397e2098a920508586ec8c006eed7d namespace=moby
time="2024-05-23T15:55:53.854206034+02:00" level=info msg="cleaning up dead shim" namespace=moby
time="2024-05-23T15:55:53.854513430+02:00" level=info msg="ignoring event" container=39ab2d18734d4a499b0691860cfb1ff339397e2098a920508586ec8c006eed7d module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
time="2024-05-23T15:55:54.750811689+02:00" level=info msg="loading plugin \"io.containerd.event.v1.publisher\"..." runtime=io.containerd.runc.v2 type=io.containerd.event.v1
time="2024-05-23T15:55:54.750870626+02:00" level=info msg="loading plugin \"io.containerd.internal.v1.shutdown\"..." runtime=io.containerd.runc.v2 type=io.containerd.internal.v1
time="2024-05-23T15:55:54.750885839+02:00" level=info msg="loading plugin \"io.containerd.ttrpc.v1.task\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
time="2024-05-23T15:55:54.751358905+02:00" level=info msg="loading plugin \"io.containerd.ttrpc.v1.pause\"..." runtime=io.containerd.runc.v2 type=io.containerd.ttrpc.v1
2024/05/23 15:55:55 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/23 15:56:12 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/23 15:56:48 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/23 15:57:30 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/23 15:58:16 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
2024/05/23 15:58:19 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)
time="2024-05-23T15:58:41.719141087+02:00" level=info msg="ignoring event" container=eac08ef96de0c73a21267b6f8ffd359a1a401f3a18105c51b1d5ef26168a2896 module=libcontainerd namespace=moby topic=/tasks/delete type="*events.TaskDelete"
time="2024-05-23T15:58:41.719284670+02:00" level=info msg="shim disconnected" id=eac08ef96de0c73a21267b6f8ffd359a1a401f3a18105c51b1d5ef26168a2896 namespace=moby
time="2024-05-23T15:58:41.719346847+02:00" level=warning msg="cleaning up after shim disconnected" id=eac08ef96de0c73a21267b6f8ffd359a1a401f3a18105c51b1d5ef26168a2896 namespace=moby
time="2024-05-23T15:58:41.719359668+02:00" level=info msg="cleaning up dead shim" namespace=moby
2024/05/23 15:58:46 http: superfluous response.WriteHeader call from go.opentelemetry.io/contrib/instrumentation/net/http/otelhttp.(*respWriterWrapper).WriteHeader (wrap.go:98)

whereas I see no new output in the logs of the agent and server containers.

EDIT: the opentelemetry is probably just noise, looks like it has been addressed here:

@qwerty287
Copy link
Contributor

If you run it completely without a custom clone block it is working?

@bjodah
Copy link
Author

bjodah commented May 23, 2024

Yes, then it's working fine.

@qwerty287
Copy link
Contributor

Can you try to change the image to docker.io/woodpeckerci/plugin-git:2.4.0? That's the internal default value.

To get exactly the same clone step as the default one:

- name: clone
  image: docker.io/woodpeckerci/plugin-git:2.4.0
  settings:
    depth: 0
    tags: true # only if event = tag

What happens if you try to manually exec the plugin from the docker cli?

@bjodah
Copy link
Author

bjodah commented May 23, 2024

Manually executing docker reproduces the error:

# ./my-command.sh 
docker: Error response from daemon: open /var/lib/docker/overlay2/93a90a69b5e1b59b33054616556fb6d2f5015dff02adba21d83aab890c27ad76/.tmp-committed3083405079: no such file or directory.
See 'docker run --help'.
# cat my-command.sh 
#!/bin/sh
docker run --rm \
  -e CI_REPO_REMOTE=https://github.com/bjodah/finitediff.git \
  -e CI_WORKSPACE=/go/src/github.com/bjodah/finitediff \
  -e CI_BUILD_EVENT=push \
  -e CI_COMMIT_SHA=a342cdb59ee6b8a2ac96c0ea4f0539d34c4fd086 \
  -e CI_COMMIT_REF=refs/heads/master \
  woodpeckerci/plugin-git

The host is a dedicated Alpine VM:

# docker --version
Docker version 25.0.5, build d260a54c81efcc3f00fe67dee78c94b16c2f8692
# cat /etc/os-release 
NAME="Alpine Linux"
ID=alpine
VERSION_ID=3.19.1
PRETTY_NAME="Alpine Linux v3.19"
HOME_URL="https://alpinelinux.org/"
BUG_REPORT_URL="https://gitlab.alpinelinux.org/alpine/aports/-/issues"

Docker CLI looks functional at first glance:

# docker run --rm hello-world

Hello from Docker!
This message shows that your installation appears to be working correctly.
...

@bjodah
Copy link
Author

bjodah commented May 23, 2024

Using this for clone: actually works:

clone:
 - name: clone
   image: docker.io/woodpeckerci/plugin-git:2.4.0
   settings:
     depth: 0
     tags: true # only if event = tag

@bjodah
Copy link
Author

bjodah commented May 23, 2024

# docker info
Client:
 Version:    25.0.5
 Context:    default
 Debug Mode: false
 Plugins:
  buildx: Docker Buildx (Docker Inc.)
    Version:  v0.12.0
    Path:     /usr/libexec/docker/cli-plugins/docker-buildx
  compose: Docker Compose (Docker Inc.)
    Version:  v2.23.3
    Path:     /usr/libexec/docker/cli-plugins/docker-compose

Server:
 Containers: 5
  Running: 4
  Paused: 0
  Stopped: 1
 Images: 15
 Server Version: 25.0.3
 Storage Driver: overlay2
  Backing Filesystem: extfs
  Supports d_type: true
  Using metacopy: false
  Native Overlay Diff: true
  userxattr: false
 Logging Driver: json-file
 Cgroup Driver: cgroupfs
 Cgroup Version: 2
 Plugins:
  Volume: local
  Network: bridge host ipvlan macvlan null overlay
  Log: awslogs fluentd gcplogs gelf journald json-file local splunk syslog
 Swarm: inactive
 Runtimes: io.containerd.runc.v2 runc
 Default Runtime: runc
 Init Binary: docker-init
 containerd version: 4e1fe7492b9df85914c389d1f15a3ceedbb280ac
 runc version: 51d5e94601ceffbbd85688df1c928ecccbfa4685
 init version: 
 Security Options:
  seccomp
   Profile: builtin
  cgroupns
 Kernel Version: 6.6.21-0-virt
 Operating System: Alpine Linux v3.19
 OSType: linux
 Architecture: x86_64
 CPUs: 3
 Total Memory: 11.7GiB
 Name: REDACTED
 ID: 182295c6-9dd4-4eee-8f5f-86256ee46cf8
 Docker Root Dir: /var/lib/docker
 Debug Mode: false
 HTTP Proxy: http://REDACTED
 HTTPS Proxy: http://REDACTED
 No Proxy: localhost,REDACTED
 Experimental: false
 Insecure Registries:
  127.0.0.0/8
 Live Restore Enabled: false

@qwerty287
Copy link
Contributor

Manually executing docker reproduces the error:

So this seems to be a docker problem tbh. Can you try executing without the env vars?

Using this for clone: actually works:

So this can be used for a workaround.

@bjodah
Copy link
Author

bjodah commented May 23, 2024

Can you elaborate on "without the env vars"?

@bjodah
Copy link
Author

bjodah commented May 23, 2024

Ah, I think I see your point:

# ./my-command2.sh 
docker: Error response from daemon: open /var/lib/docker/overlay2/93a90a69b5e1b59b33054616556fb6d2f5015dff02adba21d83aab890c27ad76/.tmp-committed3365361133: no such file or directory.
See 'docker run --help'.
# cat ./my-command2.sh 
#!/bin/sh
docker run --rm \
  woodpeckerci/plugin-git

@bjodah
Copy link
Author

bjodah commented May 23, 2024

Using a full URL does the trick on the command line as well:

# docker run --rm docker.io/woodpeckerci/plugin-git:2.4.0
no commit information: using head checkout
+ git init
hint: Using 'master' as the name for the initial branch. This default branch name
hint: is subject to change. To configure the initial branch name to use in all
hint: of your new repositories, which will suppress this warning, call:
hint: 
hint:   git config --global init.defaultBranch <name>
hint: 
hint: Names commonly chosen instead of 'master' are 'main', 'trunk' and
hint: 'development'. The just-created branch can be renamed via this command:
hint: 
hint:   git branch -m <name>
Initialized empty Git repository in /.git/
+ git config --global --replace-all safe.directory 
+ git remote add origin 
+ git fetch --no-tags --depth=1 --filter=tree:0 origin +refs/heads/master:
fatal: no path specified; see 'git help pull' for valid url syntax
exit status 128

@qwerty287
Copy link
Contributor

Yes, so it seems to be not a problem with our plugin.

Maybe you can ask docker developers or use the full URL as workaround if that's fine for you?

@bjodah
Copy link
Author

bjodah commented May 23, 2024

Yes, that's fine. Thank you for your help in debugging this.

@bjodah bjodah closed this as completed May 23, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants