[BUG?] Deployment logs displayed outside of "Deploying application" if wrapped in $()


#1

In my deployment script, I have something like

provider: script
  script: $(now  --token $NOW_TOKEN -e TRAVIS_BUILD_WEB_URL -e TRAVIS_BUILD_NUMBER -e TRAVIS_BUILD_ID -e TRAVIS_REPO_SLUG -e TRAVIS_COMMIT_RANGE -e TRAVIS_COMMIT -e TRAVIS) && ... something else

The log of this call will be dumped outside and before the “Deploying application” in the log.
while the output of the commands that follows (&& … something) will be displayed correctly inside.

If I did not wrap the initial deploy script command inside $(), then everything is displayed correctly.


#2

UPDATE:

I think this is related to what I noticed in Deployment steps create log file, how to cat / echo log file in after_deploy step?

commands wrapped inside $() is executed in advance and out of order…


#3

Please include build log URL to indicate the problem. Thanks.


#4

@BanzaiMan
Here is one, https://travis-ci.com/ibcol/ibcol/builds/90853391
I think the deployment call

$(now  --token $NOW_TOKEN -e TRAVIS_BUILD_WEB_URL -e TRAVIS_BUILD_NUMBER -e TRAVIS_BUILD_ID -e TRAVIS_REPO_SLUG -e TRAVIS_COMMIT_RANGE -e TRAVIS_COMMIT -e TRAVIS) && ... something else

was triggered before the actual Deploying application steps (similar to what I experienced at Deployment steps create log file, how to cat / echo log file in after_deploy step? )


#5

Thanks for the information. I have seen in some cases the log parts are aggregated out of order. Here, for example, you see that there is a line that is unnumbered:

It does not mean that the deployment condition was evaluated before anything else, but that the parts are stored wrong.

I am sorry to say that I don’t know how this happens. Often, if you restart it, the resulting logs look fine.


#6

@BanzaiMan

  1. Initially, I came to the same conclusion that the log was just rendered out of order. But after experiencing what I saw in this other post (Deployment steps create log file, how to cat / echo log file in after_deploy step?) I am pretty sure the call inside $() was made in advance.

  2. I kept retrying similar calls by making adjustments to the travis.yml file over and over for 30 or so times, it is very much repeatable. We can go over the file if you want.


#7

Besides the certain log parts seemingly out of order, I don’t think there is much to see here.

  1. Note that $() is a bash construct to spawn a subshell, and uses its output to build up a command, so that needs to be executed first. To think, $() eats up all STDOUT from the command contained, so whatever you see from this construct is STDERR.

  2. The deployment provider that ran on the build you indicated has only one relevant provider, which has only one $(), and that is

    $(cat NOW_URL.log)
    
  3. Since the command in question is just cat, unless the file does not exist, there will be no output from $(cat NOW_URL.log); even then, it is of the form cat: NOW_URL.log: No such file or directory.


#8

In my deployment script, I had something like the following,

    now deploy..  > NOW_URL.log && cat NOW_URL.log && node somescript.js $(cat NOW_URL.log)
  1. NOW_URL.log is generated after I pipe the output of the now deploy command into NOW_URL.log.
  2. cat NOW_URL.log puts the content of NOW_URL.log out successfully and it was shown in the logs after the output of step 1, with actual content
  3. node somescript.js $(cat NOW_URL.log) received nothing as $(cat NOW_URL.log) triggered an error because the file wasn’t there; and there is a NOW_URL.log: No such file or directory error printed in the logs BEFORE the deployment script.

From all the points above, I started to suspect the subshell $(cat NOW_URL.log) was triggered BEFORE part one of the deployment command.

PS: Is this by design? If you chain a command with && the system see it as one command and hence the subshell script was called BEFORE the first block of that chained command?