Automatically renew JWT token after expiration time

[owenhaynes]

When pushing big layers timeout of the authentication happens. eg layers over 1GB insize

[flavio]

Can you provide more context? This should be an error of the registry, not of Portus.

[GrantStreetGroup]

Portus sets the length of time that the token is considered valid.
See https://docs.docker.com/registry/spec/auth/token/

Maybe the push is going past that point?

[mssola]

@GrantStreetGroup is right. The period of time in which the authentication token is valid spans for 5 minutes. @mad0house is the upload taking that long ?

[owenhaynes]

Yes push can take that long as some times we have people pushing over WiFi
which can get congested at times, some layers of the image can range from
1gb to 1.9gb and docker v1.8 takes ages to buffer and then the server takes
a while as well.

Not had any pulls timeout yet but I assume that can happen as well
On 28 Oct 2015 3:16 pm, "Miquel Sabaté Solà" notifications@github.com
wrote:

@GrantStreetGroup https://github.com/GrantStreetGroup is right. The
period of time in which the authentication token is valid spans for 5
minutes. @mad0house https://github.com/mad0house is the upload taking
that long ?

—
Reply to this email directly or view it on GitHub
#510 (comment).

[mssola]

@mad0house so, just for testing purposes, could you try to raise this timeout to something like 30 minutes and see whether that works for you ? You can do that by changing this line from 5.minutes to 30.minutes. Then, of course, restart services, etc.

[owenhaynes]

Will test it for you tomorrow morning(GMT), If this does work can we make it a configuration item?
On 28 Oct 2015 5:47 pm, "Miquel Sabaté Solà" notifications@github.com
wrote:

@mad0house https://github.com/mad0house so, just for testing purposes,
could you try to raise this timeout to something like 30 minutes and see
whether that works for you ? You can do that by changing this line
https://github.com/SUSE/Portus/blob/master/lib/portus/jwt_token.rb#L33
from 5.minutes to 30.minutes.

—
Reply to this email directly or view it on GitHub
#510 (comment).

[mssola]

@mad0house yes, sounds reasonable.

[owenhaynes]

change has been made will get back to you later on today to give it time to test.

[kidhasmoxy]

I have the same issue, testing now.

Here's what I get from the registry logs for layers ~ 1GB:

172.17.46.121 - - [29/Oct/2015:13:35:53 +0000] "GET /v2/_catalog HTTP/1.0" 200 20 "" "Ruby"
time="2015-10-29T13:37:41Z" level=error msg="token not to be used before 1446125032 or after 1446125337 - currently 1446125861"
time="2015-10-29T13:37:41Z" level=warning msg="error authorizing context: invalid token" http.request.host="registry.demosnc.com:5000" http.request.id=7a72895f-3a71-487e-af81-8f9af5a9907c http.request.method=PATCH http.request.remoteaddr=68.228.156.33 http.request.uri="/v2/release/geneva/blobs/uploads/5e4174b7-9f34-49ab-a6b6-3b0c8c96c28e?_state=RRNl2YXESRKrLWHT3e4RcMyYH5u0tiN50cBbztE_GLd7Ik5hbWUiOiJyZWxlYXNlL2dlbmV2YSIsIlVVSUQiOiI1ZTQxNzRiNy05ZjM0LTQ5YWItYTZiNi0zYjBjOGM5NmMyOGUiLCJPZmZzZXQiOjAsIlN0YXJ0ZWRBdCI6IjIwMTUtMTAtMjlUMTM6MjM6NTguMTc3MTg3NzIxWiJ9" http.request.useragent="docker/1.8.3 go/go1.4.2 git-commit/f4bf5c7 kernel/4.1.10-boot2docker os/linux arch/amd64" instance.id=34d12fcb-9cd8-4e0a-b706-564777af862f vars.name="release/geneva" vars.uuid=5e4174b7-9f34-49ab-a6b6-3b0c8c96c28e version=v2.1.1
172.17.46.121 - - [29/Oct/2015:13:37:41 +0000] "PATCH /v2/release/geneva/blobs/uploads/5e4174b7-9f34-49ab-a6b6-3b0c8c96c28e?_state=RRNl2YXESRKrLWHT3e4RcMyYH5u0tiN50cBbztE_GLd7Ik5hbWUiOiJyZWxlYXNlL2dlbmV2YSIsIlVVSUQiOiI1ZTQxNzRiNy05ZjM0LTQ5YWItYTZiNi0zYjBjOGM5NmMyOGUiLCJPZmZzZXQiOjAsIlN0YXJ0ZWRBdCI6IjIwMTUtMTAtMjlUMTM6MjM6NTguMTc3MTg3NzIxWiJ9 HTTP/1.0" 401 235 "" "docker/1.8.3 go/go1.4.2 git-commit/f4bf5c7 kernel/4.1.10-boot2docker os/linux arch/amd64"

[owenhaynes]

Not had any problems so far after the change.

[GrantStreetGroup]

This sounds like an bug with 'docker push' If a layer is taking longer then the token timeout to upload then the command should re-authorise and get a new token.

[mssola]

@GrantStreetGroup agreed.

I'm going to take a deeper look into this as soon as possible. For now, we can just provide a configurable option so we can work around this problem.

[kidhasmoxy]

Increasing the token delay worked, but it's more of a workaround on the Portus side for the fact that the docker client isn't retrying the token request when it finishes the upload as @GrantStreetGroup mentioned.

Either way, better to have a config option for it than to wait for a docker client update.

[mssola]

@kidhasmoxy yes, I totally agree. That's why in my PR, you can see the note on the configuration option saying that it will be deprecated in the future once this is fixed upstream ;)

[mssola]

I've changed the title so it's more obvious to tell what's this issue about when planning.

[dtitov]

@mssola, is it possible to set jwt_expiration_time as an env-variable? I tried to set PORTUS_JWT_EXPIRATION_TIME to the portus service in docker-compose.yml, but it doesn't seem to work...

[Vad1mo]

@dtitov it should be PORTUS_REGISTRY_JWT_EXPIRATION_TIME or even PORTUS_REGISTRY_JWT_EXPIRATION_TIME_VALUE

[dtitov]

@Vad1mo, oh, my bad. I'll try, thanks :)

[dtitov]

@Vad1mo, should it be "10" or "10.minutes"? Here I can see the ".minutes" postfix: mssola@6fdeaa5 But I don't see it in the real config file...

[Vad1mo]

just the number 10

[dtitov]

@Vad1mo, does not seem to work either :(

I've set up PORTUS_REGISTRY_JWT_EXPIRATION_TIME=150 for the portus service, but still uploading of my big layer (11GB) fails (it takes ~9 minutes to upload it with my connection). Other smaller layers are uploaded successfully, but for the big one it keeps retrying:

The push refers to a repository [my.repo.com/bla/bla]
7902fbd464d1: Pushing [===============>                                   ]  3.382GB/11.2GB
5bec4e745b28: Layer already exists 
dc453c5797ed: Layer already exists 
8accd2d03eae: Layer already exists 
34b08772d370: Layer already exists 
9f2f1271c125: Layer already exists 
f68f7e631f19: Layer already exists 
dd09f9dfc5ab: Layer already exists 
02c4ce60b578: Layer already exists 
92c827a08a45: Layer already exists 
a52029db6cb4: Layer already exists 
9bc559abaa46: Layer already exists 
f770dc887900: Layer already exists 
35cd2499f509: Layer already exists 
eb092ea31ec0: Layer already exists 
6f4ce6b88849: Layer already exists 
92914665e7f6: Layer already exists 
c98ef191df4b: Layer already exists 
9c7183e0ea88: Layer already exists 
ff986b10a018: Layer already exists 

Log:

registry_registry.1.u8p72ed85yyk@registry    | time="2018-03-16T14:05:41Z" level=info msg="token not to be used after 2018-03-16 13:58:35 +0000 UTC - currently 2018-03-16 14:05:41.632429994 +0000 UTC" 
registry_registry.1.u8p72ed85yyk@registry    | time="2018-03-16T14:05:41Z" level=warning msg="error authorizing context: invalid token" go.version=go1.7.6 http.request.host=docker.bioinfo.no http.request.id=316b01da-e4ca-47e7-be44-d8c56bfd2f41 http.request.method=PATCH http.request.remoteaddr=10.255.0.2 http.request.uri="/v2/bla/bla/blobs/uploads/21464a81-f29b-4fed-973f-16e5fa056052?_state=IK46z6x4pLKtBBkxqxCRVeMV1TTqLc5gz6NGN8ZCpKh7Ik5hbWUiOiJjb25nbG9tZXJhdGUvZ29zaGlmdGVyIiwiVVVJRCI6IjIxNDY0YTgxLWYyOWItNGZlZC05NzNmLTE2ZTVmYTA1NjA1MiIsIk9mZnNldCI6MCwiU3RhcnRlZEF0IjoiMjAxOC0wMy0xNlQxMzo1MjozNi4yNzA4MTY1ODVaIn0%3D" http.request.useragent="docker/17.09.1-ce go/go1.8.3 git-commit/19e2cf6 kernel/3.10.0-693.11.1.el7.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/17.09.1-ce \\(linux\\))" instance.id=2bbcfce9-45f1-4df8-a237-f55a73f8a865 vars.name="bla/bla" vars.uuid=21464a81-f29b-4fed-973f-16e5fa056052 version=v2.6.2 

Variable is properly set within the container:

ubuntu@portus:~$ docker exec -it dbcb849a1c5e bash
bash-4.3# echo $PORTUS_REGISTRY_JWT_EXPIRATION_TIME
150

My Portus version is: 2.3.0@6bf45381824ef4edf2dc572374e9b13080817a9a

[dtitov]

Well, it worked with PORTUS_REGISTRY_JWT_EXPIRATION_TIME_VALUE, but this VALUE postfix is not that obvious... Thanks anyway.

[mssola]

Well, it worked with PORTUS_REGISTRY_JWT_EXPIRATION_TIME_VALUE, but this VALUE postfix is not that obvious... Thanks anyway.

@dtitov it looks like I'm a bit late... I'm glad you found a solution meanwhile. As explained on this section of the documentation, this option is a workaround for this issue (Portus should be able to renew the token automatically). I know it's not ideal, but we have other issues with higher priority unfortunately...

The naming of these environment variables is explained at the beginning of this page, which is quite important (and it's also referenced in the containerized deployment of the documentation). The thing is that this option, as it is found in the config/config.yml file, is like this:

registry:
  jwt_expiration_time:
    value: 5

So, the environment variable has to start with the PORTUS prefix, and then it goes on with each specific part, so registry, then jwt_expiration_time and finally value. Hence, the environment variable has to be PORTUS_REGISTRY_JWT_EXPIRATION_TIME_VALUE: the value part is not really a postfix. Since this value ending is quite common in the configuration, I've also considered allowing administrators to avoid writing this last part, but I think adding more magic can be more confusing ...

As for the specific value, the documentation page says: This value is set in minutes, so a 10 should suffice. The 10.minutes syntax is deprecated in 2.3, since, again, we want to remove magic that might confuse people ...

Hope this clarifies things 👍

[dtitov]

Yes, it does. Thank you :)