ERR Copying droplet into the container failed: stream-in: nstar: error streaming in: exit status 2. Output: tar: file time stamp in the future

[krismarc]

Dear community,

One of our customers is trying to deploy package which files are dated newer than the current time. I came to this repository because I found some lines which potentially are doing droplet (tar) archive extraction. https://github.com/cloudfoundry/guardian/blob/af39e7c43e9540444420b07183cb388ad981ebac/rundmc/nstar.go#L39

..the question is, why the warning from tar's utility is considered as an error and results in failure.

   2021-10-07T15:59:34.26+0200 [API/11] OUT Creating droplet for app with guid ed06bffd-68d0-4ff4-b813-010edd9ecf2f
   2021-10-07T16:00:13.05+0200 [STG/0] OUT Uploaded droplet (850.5M)
   2021-10-07T16:00:13.18+0200 [STG/0] OUT Uploading complete
   2021-10-07T16:00:13.48+0200 [STG/0] OUT Cell 8c44d9f5-e9c8-4e9d-9f30-c54f71074f2d stopping instance 9abed58a-d3a6-4ec1-9e23-f3f606401285
   2021-10-07T16:00:13.48+0200 [STG/0] OUT Cell 8c44d9f5-e9c8-4e9d-9f30-c54f71074f2d destroying container for instance 9abed58a-d3a6-4ec1-9e23-f3f606401285
   2021-10-07T16:00:14.56+0200 [CELL/0] OUT Cell 00f764af-3ea4-46a1-8464-17baee4c86ca creating container for instance 1c0f5eb9-abd2-42f3-58e6-ed1b
   2021-10-07T16:00:15.12+0200 [CELL/0] OUT Cell 00f764af-3ea4-46a1-8464-17baee4c86ca successfully created container for instance 1c0f5eb9-abd2-42f3-58e6-ed1b
   2021-10-07T16:00:15.13+0200 [STG/0] OUT Cell 8c44d9f5-e9c8-4e9d-9f30-c54f71074f2d successfully destroyed container for instance 9abed58a-d3a6-4ec1-9e23-f3f606401285
   2021-10-07T16:00:15.20+0200 [CELL/0] OUT Downloading droplet...
   2021-10-07T16:00:47.48+0200 [CELL/0] ERR Copying droplet into the container failed: stream-in: nstar: error streaming in: exit status 2. Output: tar: ./app/wlp/usr/servers/defaultServer/apps/boxx-ear-21.1.606.ear/com.company.a37.dta-rest-21.1.606.war/META-INF/MANIFEST.MF: time stamp 2021-10-07 15:47:16 is 6391.567685301 s in the future
   2021-10-07T16:00:47.48+0200 [CELL/0] ERR tar: ./app/wlp/usr/servers/defaultServer/apps/boxx-ear-21.1.606.ear/com.company.a37.dta-rest-21.1.606.war/WEB-INF/lib/aggs-matrix-stats-client-7.10.2.jar: time stamp 2021-10-07 15:39:40 is 5935.567329099 s in the future
   2021-10-07T16:00:47.48+0200 [CELL/0] ERR tar: ./app/wlp/usr/servers/defaultServer/apps/boxx-ear-21.1.606.ear/com.company.a37.dta-rest-21.1.606.war/WEB-INF/lib/api-0.5.0.jar: time stamp 2021-10-07 15:39:36 is 5931.567088468 s in the future
   2021-10-07T16:00:47.48+0200 [CELL/0] ERR tar: ./app/wlp/usr/servers/defaultServer/apps/boxx-ear-21.1.606.ear/com.company.a37.dta-rest-21.1.606.war/WEB-INF/lib/bcprov-jdk15on-1.61.jar: time stamp 2021-10-07 15:42:50 is 6125.560460296 s in the future
   2021-10-07T16:00:52.82+0200 [CELL/0] OUT Cell 00f764af-3ea4-46a1-8464-17baee4c86ca stopping instance 1c0f5eb9-abd2-42f3-58e6-ed1b
   2021-10-07T16:00:52.82+0200 [CELL/0] OUT Cell 00f764af-3ea4-46a1-8464-17baee4c86ca destroying container for instance 1c0f5eb9-abd2-42f3-58e6-ed1b
   2021-10-07T16:00:52.94+0200 [CELL/0] OUT Cell d6055c8b-56d5-4df7-98fa-14b192c3e465 creating container for instance afafaf63-7545-4bb8-7ca4-090a
   2021-10-07T16:00:53.00+0200 [API/7] OUT Process has crashed with type: "web"

Similar operation can be simulated by using tar in regular linux machine: Creation of the file dated in the future:

user@host:/tmp/test_dir # touch -a -m -t 203801181205.09 tgs.txt

user@host:/tmp/test_dir # ls -l tgs.txt
-rw-rw---- 1 wlpmp wlp 0 Jan 18 2038 tgs.txt

Making a tar:

user@host:/tmp/test_dir # tar -zcvf file.tar.gz tgs.txt
tgs.txt

Tar extraction:

user@host:/tmp/test_dir # tar -ztvf file.tar.gz
-rw-rw---- wlpmp/wlp 0 2038-01-18 12:05 tgs.txt
user@host:/tmp/test_dir # tar -xvf file.tar.gz
tgs.txt
tar: tgs.txt: time stamp 2038-01-18 12:05:09 is 514075567.645626074 s in the future

..as you can see, the file is extracted successfully just with a warning message.

I am not sure if this part of code should care if files are dated like that? Or it's just wrongly handled exception/warning?

Best regards, K.M.

[cf-gitbot]

We have created an issue in Pivotal Tracker to manage this:

https://www.pivotaltracker.com/story/show/179853304

The labels on this github issue will be updated when the story is started.

[krismarc]

Hi there,

after another attempts to troubleshoot this. We have found out this was most likely caused by exceed disk quota size. As I understand, the previous error was just a captured stream of tar extraction and we were unlucky to get those warnings instead of exact error. I am not sure if there's any space for improvements from this part of code perspective.

2021-10-07T18:12:06.44+0200 [CELL/0] ERR Copying droplet into the container failed: stream-in: nstar: error streaming in: exit status 2. Output: tar: ./app/.liberty/dev/api/third-party/com.ibm.websphere.appserver.thirdparty.eclipselink_1.0.53.jar: Wrote only 1024 of 10240 bytes
   2021-10-07T18:12:06.44+0200 [CELL/0] ERR tar: ./app/.liberty/dev/api/third-party/com.ibm.websphere.appserver.thirdparty.jaxrs_1.0.53.jar: Cannot open: Disk quota exceeded
   2021-10-07T18:12:06.44+0200 [CELL/0] ERR tar: ./app/.liberty/dev/api/third-party/com.ibm.websphere.appserver.thirdparty.jpa_1.3.53.jar: Cannot open: Disk quota exceeded
   2021-10-07T18:12:06.44+0200 [CELL/0] ERR tar: ./app/.liberty/dev/api/third-party/com.ibm.websphere.appserver.thirdparty.jsf-2.2_1.0.53.jar: Cannot open: Disk quota exceeded
   2021-10-07T18:12:06.44+0200 [CELL/0] ERR tar: ./app/.liberty/dev/api/third-party/com.ibm.websphere.appserver.thirdparty.jsf-2.3_1.0.53.jar: Cannot open: Disk quota exceeded
   2021-10-07T18:12:06.44+0200 [CELL/0] ERR tar: ./app/.liberty/dev/api/third-party/com.ibm.websphere.appserver.thirdparty.mail-1.6_1.6.53.jar: Cannot open: Disk quota exceeded

Best regards, K.M.

[mnitchev]

Hello,

It is expected for the push to fail if you exceed the quota. Can you verify that you are indeed exceeding it? If this is the case you should close this issue, as it is not a bug in garden. If it isn't the case, could you please provide us with the dontpanic report, so we can have a closer look.

[krismarc]

Hi,

yes, in our case it was indeed exceeded quota. However, the error returned wasn't clearly telling that (in compare to the other one). As I understand there's no hook available which would allow to return the right message as it simply prints out console messages from the container.

Best regards, K.M.

[mnitchev]

Hello, Considering it's an exceeded quota I'll go ahead and close this issue. Feel free to open another issue if you feel there is anything that can be improved with the error messages.