Automatic builds fail due to expecting to build one binary

jwallden · March 30, 2020, 6:33pm

Hello,

Was just hooking up the automatic builds from the git repo to build Nebula for all platforms and all the builds fail with the below logs. It builds fine locally so I was a bit surprised that all the auto builds fail. Can someone help me out here?

/Joakim

Running repo phase...
Cloning into 'nebula'...
[30/Mar/2020:18:14:42 +0000] "CONNECT github.com:443 HTTP/1.1" 200 15386 "-" "git/2.17.1"
Running pull phase...
snapd is not logged in, snap install commands will use sudo
go 1.14.1 from Michael Hudson-Doyle (mwhudson) installed
Pulling nebula 
[30/Mar/2020:18:15:07 +0000] "CONNECT api.snapcraft.io:443 HTTP/1.0" 200 14094 "-" "-"
Cloning into '/build/nebula/parts/nebula/src'...
Note: checking out '13941aa7232765efc671c6d0d6e1a8c0d4704603'.

You are in 'detached HEAD' state. You can look around, make experimental
changes and commit them, and you can discard any commits you make in this
state without impacting any branches by performing another checkout.

If you want to create a new branch to retain commits you create, you may
do so (now or later) by using -b with the checkout command again. Example:

  git checkout -b <new-branch-name>

[30/Mar/2020:18:15:10 +0000] "CONNECT github.com:443 HTTP/1.1" 200 345486 "-" "git/2.17.1"
[30/Mar/2020:18:15:11 +0000] "CONNECT proxy.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:11 +0000] "CONNECT proxy.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:11 +0000] "CONNECT proxy.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:11 +0000] "CONNECT proxy.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:11 +0000] "CONNECT proxy.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:11 +0000] "CONNECT proxy.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:11 +0000] "CONNECT proxy.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:11 +0000] "CONNECT proxy.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:11 +0000] "CONNECT proxy.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:23 +0000] "CONNECT sum.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:23 +0000] "CONNECT sum.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:23 +0000] "CONNECT sum.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:23 +0000] "CONNECT sum.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:23 +0000] "CONNECT sum.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:23 +0000] "CONNECT sum.golang.org:443 HTTP/1.1" 200 7440 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:27 +0000] "CONNECT proxy.golang.org:443 HTTP/1.1" 200 21472828 "-" "Go-http-client/1.1"
[30/Mar/2020:18:15:27 +0000] "CONNECT sum.golang.org:443 HTTP/1.1" 200 187759 "-" "Go-http-client/1.1"
go mod download
Running build phase...
Skipping pull nebula (already ran)
Building nebula 
go build -o /build/nebula/parts/nebula/install/bin ./...
Sorry, an error occurred in Snapcraft:
Expected one binary to be built, found: {'nebula', 'nebula-cert', 'nebula-service'}
Traceback (most recent call last):
  File "/snap/snapcraft/4232/bin/snapcraft", line 11, in <module>
    load_entry_point('snapcraft==3.9.1', 'console_scripts', 'snapcraft')()
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/click/core.py", line 829, in __call__
    return self.main(*args, **kwargs)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/click/core.py", line 782, in main
    rv = self.invoke(ctx)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/click/core.py", line 1236, in invoke
    return Command.invoke(self, ctx)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/click/core.py", line 1066, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/click/core.py", line 610, in invoke
    return callback(*args, **kwargs)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/click/decorators.py", line 21, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/cli/_runner.py", line 112, in run
    snap_command.invoke(ctx)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/cli/_command.py", line 88, in invoke
    return super().invoke(ctx)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/click/core.py", line 1066, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/click/core.py", line 610, in invoke
    return callback(*args, **kwargs)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/cli/lifecycle.py", line 288, in snap
    _execute(steps.PRIME, parts=[], pack_project=True, output=output, **kwargs)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/cli/lifecycle.py", line 79, in _execute
    lifecycle.execute(step, project_config, parts)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/internal/lifecycle/_runner.py", line 131, in execute
    executor.run(step, part_names)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/internal/lifecycle/_runner.py", line 185, in run
    self._handle_step(part_names, part, step, current_step, cli_config)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/internal/lifecycle/_runner.py", line 199, in _handle_step
    getattr(self, "_run_{}".format(current_step.name))(part)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/internal/lifecycle/_runner.py", line 252, in _run_build
    self._run_step(step=steps.BUILD, part=part, progress="Building")
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/internal/lifecycle/_runner.py", line 318, in _run_step
    getattr(part, step.name)()
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/internal/pluginhandler/__init__.py", line 579, in build
    self._do_build()
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/internal/pluginhandler/__init__.py", line 600, in _do_build
    self._do_runner_step(steps.BUILD)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/internal/pluginhandler/__init__.py", line 246, in _do_runner_step
    return getattr(self._runner, "{}".format(step.name))()
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/internal/pluginhandler/_runner.py", line 80, in build
    "override-build", self._override_build_scriptlet, self._builddir
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/internal/pluginhandler/_runner.py", line 140, in _run_scriptlet
    scriptlet_name, function_call.strip()
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/internal/pluginhandler/_runner.py", line 196, in _handle_builtin_function
    function(**function_args)
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/plugins/go.py", line 291, in build
    self._build()
  File "/snap/snapcraft/4232/lib/python3.6/site-packages/snapcraft/plugins/go.py", line 266, in _build
    raise RuntimeError(f"Expected one binary to be built, found: {new_files!r}")
RuntimeError: Expected one binary to be built, found: {'nebula', 'nebula-cert', 'nebula-service'}
You can find the traceback in file '/tmp/tmpwiorwi4v/trace.txt'.
Build failed
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/lpbuildd/target/build_snap.py", line 266, in run
    self.build()
  File "/usr/lib/python2.7/dist-packages/lpbuildd/target/build_snap.py", line 255, in build
    env=env)
  File "/usr/lib/python2.7/dist-packages/lpbuildd/target/build_snap.py", line 102, in run_build_command
    return self.backend.run(args, env=full_env, **kwargs)
  File "/usr/lib/python2.7/dist-packages/lpbuildd/target/lxd.py", line 536, in run
    subprocess.check_call(cmd, **kwargs)
  File "/usr/lib/python2.7/subprocess.py", line 541, in check_call
    raise CalledProcessError(retcode, cmd)
CalledProcessError: Command '['lxc', 'exec', 'lp-bionic-s390x', '--env', 'LANG=C.UTF-8', '--env', 'SHELL=/bin/sh', '--env', 'SNAPCRAFT_BUILD_INFO=1', '--env', 'SNAPCRAFT_IMAGE_INFO={"build-request-id": "lp-55433682", "build-request-timestamp": "2020-03-30T18:12:53Z", "build_url": "https://launchpad.net/~build.snapcraft.io/+snap/c3646feaaf9de11406cf35f5e8f9d66c/+build/886973"}', '--env', 'SNAPCRAFT_BUILD_ENVIRONMENT=host', '--env', 'http_proxy=http://10.10.10.1:8222/', '--env', 'https_proxy=http://10.10.10.1:8222/', '--env', 'GIT_PROXY_COMMAND=/usr/local/bin/snap-git-proxy', '--', '/bin/sh', '-c', 'cd /build/nebula && linux64 snapcraft']' returned non-zero exit status 1

cjp256 · March 31, 2020, 9:50pm

@sergiusens - perhaps we should remove that check?

sergiusens · March 31, 2020, 10:36pm

Yeah, we could, as this will eventually fail later when trying to use the command. But then again, what is the point of building “nothing” with the go plugin?

I wonder if building locally is done with the deb of snapcraft (deprecated), considering that @jwallden mentions it works locally

ec0 · March 31, 2020, 10:58pm

I’m seeing this also on a snap I am working on. Essentially, if you build a Golang project which generates more than one binary, or zero binaries, then there is an error.

I think that checking for zero binaries is sensible, but I can imagine there are many projects which compile multiple binaries, so perhaps the check fail on"< 1" binaries rather than “!=1” binaries.

snapcraft, version 3.11+git15.ge5aec728
Building mattermost-server 
go build -o /root/parts/mattermost-server/install/bin ./...
Expected one binary to be built, found: {'test_get_bundle_path_plugin', 'test_call_log_api_plugin', 'platform', 'checker', 'layer_generators', 'manual.test_load_configuration_defaults_plugin', 'test_update_user_active_plugin', 'mattermost', 'test_get_profile_image_plugin', 'test_search_teams_plugin', 'test_bots_plugin', 'interface_generator', 'test_send_mail_plugin', 'test_get_direct_channel_plugin', 'test_get_channels_for_team_for_user_plugin', 'test_update_user_status_plugin', 'test_member_channels_plugin', 'test_set_profile_image_plugin', 'test_search_posts_in_team_plugin', 'manual.test_load_configuration_plugin', 'test_search_channels_plugin', 'config_generator', 'test_members_plugin'}

The code seems to have changed at this point: https://github.com/snapcore/snapcraft/blame/d976a8988ce833b4b0a3f1ed66fa744cdb6c7d3f/snapcraft/plugins/v1/go.py#L265

I have tested this on both the LXD builder, and Multipass builder. Same behavior.

cjp256 · April 1, 2020, 1:32pm

I put up a PR that should fix this:

Once it builds (an hour or so?), it should be available for testing with:
snap refresh snapcraft --channel edge/pr-3007

jwallden · April 1, 2020, 6:16pm

I’m using the Snapcraft snap, not the deb.

ec0 · April 2, 2020, 8:07pm

Hey @cjp256 - thanks so much for getting a fix in place for this so quickly! I’ve just installed the pr-3007 version and rebuilt the snap where I was seeing this issue, and it built perfectly, including all binaries. I feel this issue can be considered fixed with PR-3007 merged.

jwallden · April 15, 2020, 11:21am

Thank you!
Any idea when this can hit the build servers?

cjp256 · April 15, 2020, 6:07pm

It’s available in the edge channel. The next push to stable is a bit delayed at the moment, but I expect the stable channel to get an update around the end of the month. @sergiusens? If it’s an issue, I can backport this fix.