Packer: PACKER_TMP_DIR override host directory with user root

[sudhir05]

This issue has been raised and closed without proper justification
The issue here is i am able to override PACKER_TMP_DIR (/tmp/branch_name/build_number) but docker daemon is creating the directory with user root. Therefore, user which is running the packer in our case jenkins not able to use this directory for any stage files uploading.

see the logs below:
==> docker: Creating a temporary directory for sharing data...
==> docker: Pulling Docker image: centos:7
==> docker: Starting docker container...
docker: Run command: docker run -v /tmp/branch_number/build_number:/packer-files -d -i -t --entrypoint=/bin/sh -- centos:7

Build 'docker' errored: Error uploading script: Failed to open temp file for writing: open /tmp/branch_number/build_number/upload420280486: permission denied

[SwampDragons]

You were right -- I misread the original issue. I've found the problem and made a PR to fix it; once tests pass I will be able to link you a binary that solves the problem for you to test.

[SwampDragons]

https://circleci.com/gh/hashicorp/packer/7695#artifacts/containers/0

[sudhir05]

@SwampDragons , how to test this.

[SwampDragons]

The link I shared contains archived binaries for each of the major OS architectures; download the one that is relevant to you, unzip it, and use it instead of the packer you have installed by calling it directly.

[rickerc]

Testing the linked binary and I still see the issue. export PACKER_TMP_DIR=/home/$user/packer_config/tmp and start off the run

initially see /home/$user/packer_config/tmp/tmp created and owned by $user

at some point during the run however that changes (presumably because of a delete and then a recreate) and then I see /home/$user/packer_config/tmp/tmp owned by root. Which of course blows up my provisioning

I have 4 provisioners in a row:

shell (inline)
ansible
ansible
shell (inline)

and it's getting changed before that last shell (which then won't work b/c the tmp script can't be written due to the PACKER_TMP_DIR now being owned by root and not by $user)

[rickerc]

Testing was with linux_amd64 (on Ubuntu 19.04)

[SwampDragons]

@rickerc I can't reproduce this; can you please share a minimal template + ansible scripts that reproduce the issue?

[apolloclark]

I noticed this issue happens when I run a multiple parallelized instances of Packer build, and they each pull a remote Docker image. It works fine when I'm using locally cached Docker images.

Test case:
https://github.com/apolloclark/packer-cloudsploit

after installing Gradle, run:

gradle test --parallel --rerun-tasks

When the local user does not have the required base Docker images, Packer will have Docker pull down the base Docker images, and then Packer will throw the permissions error.

Build 'docker' errored: Error uploading script: Failed to open temp file for writing: open ~/.packer.d/tmp/upload720136788: permission denied

[bmurphey]

I have been having a lot of issues with this (indirectly via Spinnaker's rosco service). It fails intermittently, whether there are multiple pipelines running or not. It only started happening after upgrading Spinnaker from 1.14.1 to 1.16.1, which upgrades Packer from version 1.3.1 to version 1.4.2. Using the shell provisioner and a Docker builder, it fails after reaching a 5 minute timeout like so:

2019-09-26T15:21:48Z: ==> app-base: Provisioning with shell script: /tmp/packer-shell734323009
2019-09-26T15:26:49Z: ==> app-base: Killing the container: d01843adcd8997ae2dfecadd9ed13ec6536dca450a2d10e0dac9c5e172166e97
2019-09-26T15:26:52Z: Build 'app-base' errored: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload695674763: permission denied

Please let me know what I can do to help debug this.

[bmurphey]

It's still too early to tell, but I may have re-set the correct behavior on the failing shell provisioner(s) by setting the remote_folder parameter on those provisioners to /tmp: https://www.packer.io/docs/provisioners/shell.html#remote_folder.

[bmurphey]

That did not fix it. Now I'm trying to run with the PACKER_LOG=1 envar to try and get more information.

[bmurphey]

@SwampDragons I have been able to reproduce this almost at will. In Spinnaker I do this by starting a pipeline that uses the docker builder, and then starting another one. Both of these pull down Docker images from either Docker Hub or ECR. Here are the debug logs for a successful run using a shell provisioner:

2019/09/28 15:37:35 [INFO] (telemetry) Starting provisioner shell
2019/09/28 15:37:35 packer: 2019/09/28 15:37:35 shutting down the SSH proxy
2019/09/28 15:37:35 Error asking for input: no available tty
2019-09-28T15:37:35Z: ==> www-master: Provisioning with shell script: /opt/rosco/config/packer/docker_ruby_app_build.sh
2019/09/28 15:37:35 packer: 2019/09/28 15:37:35 Opening /opt/rosco/config/packer/docker_ruby_app_build.sh for reading
2019/09/28 15:37:35 packer: 2019/09/28 15:37:35 [INFO] 6197 bytes written for 'uploadData'
2019/09/28 15:37:35 [INFO] 6197 bytes written for 'uploadData'
2019/09/28 15:37:35 packer: 2019/09/28 15:37:35 Copying to /tmp/script_2619.sh on container adc96f693b67addc17b35bdf104ea551c4f33bdc6ae40b7a62d5dd178d23a54e.
2019/09/28 15:37:35 packer: 2019/09/28 15:37:35 Copied 6197 bytes for /tmp/script_2619.sh
2019/09/28 15:37:36 packer: 2019/09/28 15:37:36 Executing docker exec -i adc96f693b67addc17b35bdf104ea551c4f33bdc6ae40b7a62d5dd178d23a54e /bin/sh -c (chmod 0755 /tmp/script_2619.sh):
2019/09/28 15:37:37 packer: 2019/09/28 15:37:37 [INFO] RPC endpoint: Communicator ended with: 0
2019/09/28 15:37:37 [INFO] RPC client: Communicator ended with: 0
2019/09/28 15:37:37 [INFO] RPC endpoint: Communicator ended with: 0

And here are the shell provisioner logs for the failed build:

2019/09/28 15:57:04 [INFO] (telemetry) Starting provisioner shell
2019/09/28 15:57:04 Error asking for input: no available tty
2019-09-28T15:57:04Z: ==> app-master: Provisioning with shell script: /tmp/packer-shell413775073
2019/09/28 15:57:04 packer: 2019/09/28 15:57:04 Opening /tmp/packer-shell413775073 for reading
2019/09/28 15:57:04 packer: 2019/09/28 15:57:04 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:04 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:04 packer: 2019/09/28 15:57:04 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload130292118: permission denied
2019/09/28 15:57:06 packer: 2019/09/28 15:57:06 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:06 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:06 packer: 2019/09/28 15:57:06 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload128006653: permission denied
2019/09/28 15:57:08 packer: 2019/09/28 15:57:08 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:08 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:08 packer: 2019/09/28 15:57:08 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload089902392: permission denied
2019/09/28 15:57:10 packer: 2019/09/28 15:57:10 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:10 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:10 packer: 2019/09/28 15:57:10 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload585455927: permission denied
2019/09/28 15:57:12 packer: 2019/09/28 15:57:12 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:12 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:12 packer: 2019/09/28 15:57:12 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload644702506: permission denied
2019/09/28 15:57:14 packer: 2019/09/28 15:57:14 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:14 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:14 packer: 2019/09/28 15:57:14 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload938495105: permission denied
2019/09/28 15:57:16 packer: 2019/09/28 15:57:16 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:16 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:16 packer: 2019/09/28 15:57:16 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload627556332: permission denied
2019/09/28 15:57:18 packer: 2019/09/28 15:57:18 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:18 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:18 packer: 2019/09/28 15:57:18 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload926399067: permission denied
2019/09/28 15:57:20 packer: 2019/09/28 15:57:20 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:20 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:20 packer: 2019/09/28 15:57:20 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload902554110: permission denied
2019/09/28 15:57:22 packer: 2019/09/28 15:57:22 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:22 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:22 packer: 2019/09/28 15:57:22 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload002786629: permission denied
2019/09/28 15:57:24 packer: 2019/09/28 15:57:24 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:24 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:24 packer: 2019/09/28 15:57:24 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload071395296: permission denied
2019/09/28 15:57:26 packer: 2019/09/28 15:57:26 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:26 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:26 packer: 2019/09/28 15:57:26 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload192899519: permission denied
2019/09/28 15:57:28 packer: 2019/09/28 15:57:28 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:28 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:28 packer: 2019/09/28 15:57:28 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload294687250: permission denied
2019/09/28 15:57:30 packer: 2019/09/28 15:57:30 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:30 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:30 packer: 2019/09/28 15:57:30 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload187270729: permission denied
2019/09/28 15:57:32 packer: 2019/09/28 15:57:32 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:32 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:32 packer: 2019/09/28 15:57:32 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload817151764: permission denied
2019/09/28 15:57:34 packer: 2019/09/28 15:57:34 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:34 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:34 packer: 2019/09/28 15:57:34 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload864407907: permission denied
2019/09/28 15:57:36 packer: 2019/09/28 15:57:36 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:36 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:36 packer: 2019/09/28 15:57:36 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload030275430: permission denied
2019/09/28 15:57:38 packer: 2019/09/28 15:57:38 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:38 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:38 packer: 2019/09/28 15:57:38 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload746774925: permission denied
2019/09/28 15:57:40 packer: 2019/09/28 15:57:40 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:40 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:40 packer: 2019/09/28 15:57:40 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload420468616: permission denied
2019/09/28 15:57:42 packer: 2019/09/28 15:57:42 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:42 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:42 packer: 2019/09/28 15:57:42 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload731166535: permission denied
2019/09/28 15:57:44 packer: 2019/09/28 15:57:44 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:44 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:44 packer: 2019/09/28 15:57:44 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload791278586: permission denied
2019/09/28 15:57:46 packer: 2019/09/28 15:57:46 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:46 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:46 packer: 2019/09/28 15:57:46 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload949874449: permission denied
2019/09/28 15:57:48 packer: 2019/09/28 15:57:48 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:48 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:48 packer: 2019/09/28 15:57:48 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload484819260: permission denied
2019/09/28 15:57:50 packer: 2019/09/28 15:57:50 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:50 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:50 packer: 2019/09/28 15:57:50 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload711042923: permission denied
2019/09/28 15:57:52 packer: 2019/09/28 15:57:52 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:52 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:52 packer: 2019/09/28 15:57:52 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload316954574: permission denied
2019/09/28 15:57:54 packer: 2019/09/28 15:57:54 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:54 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:54 packer: 2019/09/28 15:57:54 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload223420117: permission denied
2019/09/28 15:57:56 packer: 2019/09/28 15:57:56 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:56 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:56 packer: 2019/09/28 15:57:56 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload259429424: permission denied
2019/09/28 15:57:58 packer: 2019/09/28 15:57:58 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:58 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:57:58 packer: 2019/09/28 15:57:58 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload548047311: permission denied
2019/09/28 15:58:00 packer: 2019/09/28 15:58:00 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:58:00 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:58:00 packer: 2019/09/28 15:58:00 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload669511906: permission denied
2019/09/28 15:58:02 packer: 2019/09/28 15:58:02 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:58:02 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:58:02 packer: 2019/09/28 15:58:02 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload859978457: permission denied
2019/09/28 15:58:04 packer: 2019/09/28 15:58:04 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:58:04 [INFO] 79 bytes written for 'uploadData'
2019/09/28 15:58:04 packer: 2019/09/28 15:58:04 Retryable error: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload184827492: permission denied
2019/09/28 15:58:04 [INFO] (telemetry) ending shell
2019/09/28 15:58:04 packer: 2019/09/28 15:58:04 Error asking for input: no available tty
2019/09/28 15:58:04 packer: 2019/09/28 15:58:04 Error asking for input: no available tty
2019-09-28T15:58:04Z: ==> app-master: Killing the container: 6cda447182e4bf22a28402a3d6be2736d916cbffc88d618c6a30b17a5dc372da
2019-09-28T15:58:06Z: Build 'app-master' errored: Error uploading script: Failed to open temp file for writing: open /home/spinnaker/.packer.d/tmp/upload184827492: permission denied

[SwampDragons]

Okay, I'll try to reproduce using multiple concurrent build runs and report back. It probably won't happen until after I get the 1.4.4 release out though.

[bmurphey]

Sounds great, thanks! Please let me know if you need any more information. In the meantime I am going to step through Packer versions from 1.3.1 onward and see if I can isolate when this behavior began.

[bmurphey]

From my testing it appears the issue was introduced in 1.3.4 and present in every version since then, including 1.4.3.

[nqb]

@SwampDragons, I got this issue too when running parallel builds that need to pull remote Docker images and using shell and ansible provisionners. Let me know if I can help solving this issue.

[SwampDragons]

Thanks. @nqb. I'll try to get to this before the next release, but sure if you want to take a dive into it I'd appreciate the assist. It sounds to me like there's a race condition where concurrent build runs are stomping on each other's use of the temp dir.

Right now I'm wondering if the mkdirall command sometimes fails because the directory is getting created in between when we check whether it exists and when we actually create it, here: https://github.com/hashicorp/packer/blob/master/builder/docker/step_temp_dir.go#L41

But like I said it may be a little while before I can look at this so if you have time I'd appreciate it.

[SwampDragons]

One solution may be to make the tempdir not "tmp" but some unique name like tmp-$buildUUID and make sure the builds use it appropriately.

[SwampDragons]

I think #8015 may be the same as this issue.

[SwampDragons]

~Can you confirm that this is still a problem since the v1.4.3 release?~ oops I see that you did already.

[SwampDragons]

I've managed to reproduce! 🎉

[SwampDragons]

I've got a build for y'all to test: https://circleci.com/gh/hashicorp/packer/15648#artifacts/containers/0

[nqb]

@SwampDragons, tested and it works.

Now, when I'm running parallel Docker builds, I got several temp directories. If one builder fail, other can continue because temp directory are still here.

[bmurphey]

Confirmed it works for me as well, thank you!

[nqb]

Despite milestone 1.5, this bug should be fix in 1.4.5 according to CHANGELOG.

[SwampDragons]

Good catch -- I forgot to change the milestone after we decided to do a final patch release. This should be live n v1.4.5.

[hashibot[bot]]

I'm going to lock this issue because it has been closed for _30 days_ ⏳. This helps our maintainers find and focus on the active issues.

If you have found a problem that seems similar to this, please open a new issue and complete the issue template so we can capture all the details necessary to investigate further.