This bug should be used to fix the fact that s2i does not work with images that don't contain tar (layered build not working)

Got a few minutes to look into this, and I believe I have reproduced this with the current s2i code base.

The decision on whether to do a layered build is based on parsing the error string returned from the docker run container equivalent call.

This is the method that parses the message and what it looks for:

func isMissingRequirements(text string) bool {
	tar, _ := regexp.MatchString(`.*tar.*not found`, text)
	sh, _ := regexp.MatchString(`.*/bin/sh.*no such file or directory`, text)
	return tar || sh
}


So the message from DeShuai Ma's repro is slightly different, in that /bin/sh is missing, and so a match is not claimed.

That matcher pattern, based in git blame, has been in place since Feb 2015.
So the message from Docker (or the shell being used) must have changed slightly.

FYI in my repro, which used centos vs. rhel, /bin/sh was *NOT* missing, but "No" instead of "no" was used in "No such file or directory".

Don't know if we have alternatives to parsing the message string, but short term, went ahead and modified to algorithm to allow for the current message being generated.

I see the layered build get kicked off now, but it still fails.  Relevant logs:

I1001 18:08:19.739731 13673 layered.go:133] Building new image openshift/ruby-20-centos7-1443737299739724377 with scripts and sources already inside
I1001 18:08:19.760118 13673 layered.go:129] Step 0 : FROM openshift/ruby-20-centos7
I1001 18:08:19.760327 13673 layered.go:129]  ---> f7a89d36e935
I1001 18:08:19.760352 13673 layered.go:129] Step 1 : COPY scripts /tmp/scripts
I1001 18:08:19.762535 13673 cleanup.go:23] Removing temporary directory /tmp/sti837670925
I1001 18:08:19.762552 13673 fs.go:99] Removing directory '/tmp/sti837670925'
I1001 18:08:19.763691 13673 main.go:354] An error occurred: scripts: no such file or directory


I'll continue some on Friday.

Wonder if we can just test the return code from the tar invocation instead?

Perhaps ... I believe it was a 13 with my repo.  I was going to look at rhel as well as centos anyway.  I can see if there is some consistency there, along with some research into what different shells do.  First thing though of course is understanding why the layered build with my prototype fix ultimately failed.

On the error code, from errno.h, the rc of 13 I got from is EACCESS.  If we checked for that, and ENOENT (no such file), I would think we would have consistency at least across linux (and posix too most likely).  I think I'll do a combo of the error code and messages ... if any of them are true, assume missing tar and trigger layered build.

why not just any non-zero RC?

Well, maybe long term, but after getting familiar with the code path and pattern of logs, I now believe there are at least 2, maybe 3, problems.

The first error when I use an openshift/ruby-20-centos7 image that I build from the latest from grep https:///github.com/openshift/sti-ruby.  Turns out, it fails for me irregardless of whether I remove tar or not.  In either case, the error message contains "No such file or directory" with the capital N.  The change to the pattern matching / error code catches that, and at least goes down to layered path for me.

In the case where tar was still there, it complained about not finding the file "/usr/libexec/s2i/assemble" (perhaps the 3rd problem).

But as I mentioned originally in Comment 2 (https://bugzilla.redhat.com/show_bug.cgi?id=1261117#c2), the build was still ultimately failing when I went down the layered path.

It that case, I got the exact same error message as DeShuai Ma, and our 2nd problem:  
   An error occurred: scripts: no such file or directory

Circling back then and comparing his original logs with mine, his run did in fact detect the missing tar, and went down the layered path ... a snippet from his original logs:

I0908 17:09:44.348858 95934 sti.go:151] Image is missing basic requirements (sh or tar), layered build will be performed
I0908 17:09:44.501732 95934 layered.go:81] Writing custom Dockerfile to /tmp/sti616354485/upload

In both his case and mine, this error steps from this step in the Dockerfile:

         Step 1 : COPY scripts /tmp/scripts

By adding additional debug in the Dockerfile, there is not "scripts" dir in the current working directory.  Nor a src file.  In fact, I could not find a scripts dir anywhere when I added a "find / -name scripts" to the docker file (where I switched to ROOT beforehand).  Nor could I find under /tmp our sti working directory when I added RUN ls -la /tmp to the Dockerfile generated in layered.go.

The code obviously seems to assume it can find the previously downloaded scripts/source and copy into the new image, but can't.

When I remove my locally built ruby-20-centos7 (even the one I left as is with tar included) and docker pull docker.io/openshift/ruby-20-centos7, I can build locally.

I'll continue to investigate / learn the tar related paths (unexplored country for me), but pending further exchanges here getting to a conclusion, let's discuss next scrum.

your locally built ruby-20-centos7 is probably no good because you didn't pull or rebuild base-centos7 on which ruby-20-centos7 is based.  that is going to be the cause of a lot of your path issues.

Yep, that was it.  After a git fetch and rebuild of that image, it runs fine for me out of the box.  Unfortunately, it also now runs fine for me when I remove tar via the sti-ruby Dockerfile.

Unless I'm not sabotaging the image correctly (I'll get a sanity check from the team), I'm now wondering if test had a similar mismatch of images that gave the similar error message I saw that the scripts directory was missing.

I'll pick up on Monday.

OK, removing tar via Dockerfile proved unsuccessful (tried a variety of permutations and got a sanity check from Cesar), but a docker run / remove tar / docker commit has proven successful.

I can successfully build when tar is there, and fail in the same fashion as test with tar removed.  sti-base/sti-ruby are at latest levels.

In both test and my repro's, the lack of tar is detected, and it goes in the layered build path.  No changes to looking for error codes or different error messages needed.  It fails in the layered docker build, copying a "scripts" directory which does not exist.

Investigation so far, no directory called "scripts" anywhere in the image.  The scripts are still in the original /usr/libexec/s2i directory from the sti builder image.  

Will start iterating over getting the layered docker build to work, and will update the bug at that point.

Have a fix in hand.  Will be initiating the PR shortly after some clean up and regression test runs.

There was a bit of back and forth on whether a more strategic change of getting rid of the scripts dir was a desired solution.  While that still may occur,
the more immediate fix within the current structure of s2i has just merged upstream with 

https://github.com/openshift/source-to-image/pull/302

If QA can refresh their s2i executable to include a level that has this PR / commit and verify the fix, that would be great.

thanks

Will test again when this pr merge to origin repo

FYI - the PR has merged into source-to-image and the source-to-image godeps has been bumped with this change in origin.

It should be available for verification.

success with s2i command like this:
s2i build  https://github.com/openshift/ruby-hello-world docker.io/uptoknow/ruby-20-centos7:notar rails-test  --loglevel=2

failed with origin
root@ip-172-18-10-210 ~]# openshift version
openshift v1.1.1-277-gf45f63e
kubernetes v1.2.0-alpha.4-851-g4a65fa1
etcd 2.2.2

1. prepare a builder image without tar installed
  docker.io/uptoknow/ruby-20-centos7:notar
2. oc new-app uptoknow/ruby-20-centos7:notar~https://github.com/openshift/ruby-hello-world
3. check the log
I0129 02:55:09.681271       1 sti.go:173] The value of ALLOWED_UIDS is [1-]
I0129 02:55:09.686375       1 docker.go:224] Image uptoknow/ruby-20-centos7@sha256:d6f5718b85126954d98931e654483ee794ac357e0a98f4a680c1e848d78863a1 available locally
I0129 02:55:09.689502       1 sti.go:195] Creating a new S2I builder with build config: "Builder Name:\t\tRuby 2.0\nBuilder Image:\t\tuptoknow/ruby-20-centos7@sha256:d6f5718b85126954d98931e654483ee794ac357e0a98f4a680c1e848d78863a1\nSource:\t\t\tfile:///tmp/s2i-build411899154/upload/src\nOutput Image Tag:\t172.30.169.200:5000/haowang/ruby-hello-world:latest\nEnvironment:\t\tOPENSHIFT_BUILD_SOURCE=https://github.com/openshift/ruby-hello-world.git,BUILD_LOGLEVEL=2,OPENSHIFT_BUILD_NAME=ruby-hello-world-3,OPENSHIFT_BUILD_NAMESPACE=haowang\nIncremental Build:\tdisabled\nRemove Old Build:\tdisabled\nBuilder Pull Policy:\tif-not-present\nQuiet:\t\t\tdisabled\nLayered Build:\t\tdisabled\nWorkdir:\t\t/tmp/s2i-build411899154\nDocker NetworkMode:\tcontainer:fa9f03d8083322542bce240e94faa01d9119bf356e670ac6f632e6e3abfc7477\nDocker Endpoint:\tunix:///var/run/docker.sock\n"
I0129 02:55:09.692693       1 docker.go:224] Image uptoknow/ruby-20-centos7@sha256:d6f5718b85126954d98931e654483ee794ac357e0a98f4a680c1e848d78863a1 available locally
I0129 02:55:09.698751       1 sti.go:140] Preparing to build 172.30.169.200:5000/haowang/ruby-hello-world:latest
I0129 02:55:09.874805       1 source.go:189] Cloning source from https://github.com/openshift/ruby-hello-world.git
I0129 02:55:10.238949       1 docker.go:224] Image uptoknow/ruby-20-centos7@sha256:d6f5718b85126954d98931e654483ee794ac357e0a98f4a680c1e848d78863a1 available locally
I0129 02:55:10.238973       1 docker.go:344] Image contains io.openshift.s2i.scripts-url set to 'image:///usr/libexec/s2i'
I0129 02:55:10.238999       1 download.go:57] Using image internal scripts from: image:///usr/libexec/s2i/assemble
I0129 02:55:10.239007       1 download.go:57] Using image internal scripts from: image:///usr/libexec/s2i/run
I0129 02:55:10.242154       1 docker.go:224] Image uptoknow/ruby-20-centos7@sha256:d6f5718b85126954d98931e654483ee794ac357e0a98f4a680c1e848d78863a1 available locally
I0129 02:55:10.242169       1 docker.go:344] Image contains io.openshift.s2i.scripts-url set to 'image:///usr/libexec/s2i'
I0129 02:55:10.242183       1 download.go:57] Using image internal scripts from: image:///usr/libexec/s2i/save-artifacts
I0129 02:55:10.242190       1 sti.go:221] Using assemble from image:///usr/libexec/s2i
I0129 02:55:10.242197       1 sti.go:221] Using run from image:///usr/libexec/s2i
I0129 02:55:10.242201       1 sti.go:221] Using save-artifacts from image:///usr/libexec/s2i
I0129 02:55:10.242221       1 sti.go:148] Clean build will be performed
I0129 02:55:10.242230       1 sti.go:151] Performing source build from file:///tmp/s2i-build411899154/upload/src
I0129 02:55:10.242235       1 sti.go:164] Running "assemble" in "172.30.169.200:5000/haowang/ruby-hello-world:latest"
I0129 02:55:10.242246       1 sti.go:412] Using image name uptoknow/ruby-20-centos7@sha256:d6f5718b85126954d98931e654483ee794ac357e0a98f4a680c1e848d78863a1
I0129 02:55:10.242275       1 environment.go:52] Setting 'RACK_ENV' to 'production'
I0129 02:55:10.249842       1 docker.go:344] Image contains io.openshift.s2i.scripts-url set to 'image:///usr/libexec/s2i'
I0129 02:55:10.249858       1 docker.go:399] Base directory for STI scripts is '/usr/libexec/s2i'. Untarring destination is '/tmp'.
I0129 02:55:10.249868       1 docker.go:529] Creating container using config: {Hostname: Domainname: User: Memory:0 MemorySwap:0 CPUShares:0 CPUSet: AttachStdin:false AttachStdout:true AttachStderr:false PortSpecs:[] ExposedPorts:map[] Tty:false OpenStdin:true StdinOnce:true Env:[RACK_ENV=production OPENSHIFT_BUILD_NAME=ruby-hello-world-3 OPENSHIFT_BUILD_NAMESPACE=haowang OPENSHIFT_BUILD_SOURCE=https://github.com/openshift/ruby-hello-world.git BUILD_LOGLEVEL=2] Cmd:[/bin/sh -c tar -C /tmp -xf - && /usr/libexec/s2i/assemble] DNS:[] Image:uptoknow/ruby-20-centos7@sha256:d6f5718b85126954d98931e654483ee794ac357e0a98f4a680c1e848d78863a1 Volumes:map[] VolumeDriver: VolumesFrom: WorkingDir: MacAddress: Entrypoint:[] NetworkDisabled:false SecurityOpts:[] OnBuild:[] Mounts:[] Labels:map[]}
I0129 02:55:10.400450       1 docker.go:543] Attaching to container
I0129 02:55:10.401271       1 docker.go:549] Starting container
I0129 02:55:10.468159       1 docker.go:479] Waiting for container
E0129 02:55:10.531214       1 util.go:91] /bin/sh: tar: command not found
I0129 02:55:10.613822       1 docker.go:481] Container wait returns with 127 and <nil>
I0129 02:55:10.614104       1 docker.go:488] Container exited
I0129 02:55:16.841025       1 sti.go:172] Image is missing basic requirements (sh or tar), layered build will be performed
I0129 02:55:16.844521       1 layered.go:82] Writing custom Dockerfile to /tmp/s2i-build411899154/upload
I0129 02:55:16.844538       1 layered.go:101] Creating application source code image
I0129 02:55:16.846084       1 layered.go:135] Building new image uptoknow/ruby-20-centos7@sha256:d6f5718b85126954d98931e654483ee794ac357e0a98f4a680c1e848d78863a1-1454036116846072655 with scripts and sources already inside
I0129 02:55:16.847634       1 cleanup.go:23] Removing temporary directory /tmp/s2i-build411899154
I0129 02:55:16.847648       1 fs.go:117] Removing directory '/tmp/s2i-build411899154'
F0129 02:55:16.849302       1 builder.go:185] Error: build error: API error (500): Illegal tag name (sha256:d6f5718b85126954d98931e654483ee794ac357e0a98f4a680c1e848d78863a1-1454036116846072655): only [A-Za-z0-9_.-] are allowed ('.' and '-' are NOT allowed in the initial), minimum 1, maximum 128 in length

Hmm ... not sure that origin level has the godeps bump with the fix.

If the fix is in play, one of these two messages from layered.go:CreateDockerfile should have shown up:

	if scriptsIncluded {
		glog.V(2).Infof("The scripts are included in %q directory", path.Join(config.WorkingDir, api.UploadScripts))
		buffer.WriteString(fmt.Sprintf("COPY scripts %s\n", locations[0]))
	} else {
		// if an err on reading or opening dir, can't copy it
		glog.V(2).Infof("Could not gather scripts from the directory %q", path.Join(config.WorkingDir, api.UploadScripts))
	}

Neither are there; however, "Writing custom Dockerfile ..." from that same method is there.

I'm in the midst of a origin rebuild, but have pulled uptoknow/ruby-20-centos7:notar down.  Once my rebuild is done, I'll try the oc new-app above, and see what is the same/different.

Yep, even https://github.com/openshift/origin/releases/tag/v1.1.1.1 does not have the fix.  I examined the associated source.

That said, I ran with latest origin / latest images, confirmed the prints I highlighted above do in fact occur as would be expected in a no tar case, but the same error message from builder.go is occurring:

I0129 15:56:46.278327       1 layered.go:89] Could not gather scripts from the directory "/tmp/s2i-build956018727/upload/scripts"
I0129 15:56:46.278411       1 layered.go:109] Writing custom Dockerfile to /tmp/s2i-build956018727/upload
I0129 15:56:46.278418       1 layered.go:130] Creating application source code image
I0129 15:56:46.279621       1 layered.go:164] Building new image uptoknow/ruby-20-centos7@sha256:d6f5718b85126954d98931e654483ee794ac357e0a98f4a680c1e848d78863a1-1454083006279609812 with scripts and sources already inside
I0129 15:56:46.279633       1 docker.go:717] Building container using config: %+v{uptoknow/ruby-20-centos7@sha256:d6f5718b85126954d98931e654483ee794ac357e0a98f4a680c1e848d78863a1-1454083006279609812  true false false true true 0 0 0 0 0  0xc2083c8328 0xc2083c8338 false  {   } {map[]}  []}
I0129 15:56:46.280642       1 cleanup.go:23] Removing temporary directory /tmp/s2i-build956018727
I0129 15:56:46.280683       1 fs.go:156] Removing directory '/tmp/s2i-build956018727'
F0129 15:56:46.282111       1 builder.go:185] Error: build error: API error (500): Illegal tag name (sha256:d6f5718b85126954d98931e654483ee794ac357e0a98f4a680c1e848d78863a1-1454083006279609812): only [A-Za-z0-9_.-] are allowed ('.' and '-' are NOT allowed in the initial), minimum 1, maximum 128 in length

that d6f57 image id is present in the image stream.

Perhaps an s2i vs. docker item ... in any event, I'm investigating.

The builder image name is supplied as a command line option when running s2i, and the tag ref is supplied.  When running with new-app, it is set from the new-app generated s.build.Spec.Strategy.SourceStrategy.From.Name at https://github.com/openshift/origin/blob/master/pkg/build/builder/sti.go#L162, where the new-app code seeds it with the hexadecimal image id vs. the tag name (through several layers ultimately landing at dockerimagelookup.go).

When the layered code creates a new name for the dynamically created builder image at https://github.com/openshift/source-to-image/blob/master/pkg/build/strategies/layered/layered.go#L137, simply appending the timestamp to the tag supplied in the s21 invocation is OK, but the docker API does not like the -timestamp appended to the hex image id.

Initial thought, not inclined to change the use if the hex image id, so layered.go should inspect the builder image name, and if it contains a hex image id, inspect the associated image stream and got the associated tag, then append the timestamp, etc.

I'll start down that path, but alternative suggestions/analysis welcome.

Have PR https://github.com/openshift/source-to-image/pull/404 opened to address the diff between `oc new-app` and `s2i` and their entry into the layered path.

Went with a simpler solution than outlined #Comment 18.

Update:  the s2i PR has merged, and we are waiting on a origin PR that will bump the s2i Godeps:  https://github.com/openshift/origin/pull/6940

OK, running with origin built from upstream, where that origin contains commit 3a820fefa45945c4b0063bac9ca7009c8fd6beb3, i have verified the fix.

Note, I had to run the openshift server with --latest-images=true given the builder images on docker.io are not updated yet.

Please either verify by building upstream and running, or waiting for that commit to show up in a origin puddle/release.

verified with devenv-rhel7_3313 using --latest-images=true when start openshift