Harbor: docker login failed, unauthorized: authentication required

[steveal]

• harbor version: v1.8.1-16b59c41
• docker-compose version: 1.18.0, build 8dd22a9
• docker engine version:
  root@harbor21[/harbor]#docker version
  Client:
  Version: 17.12.0-ce
  API version: 1.35
  Go version: go1.9.2
  Git commit: c97c6d6
  Built: Wed Dec 27 20:10:14 2017
  OS/Arch: linux/amd64

Server:
Engine:
Version: 17.12.0-ce
API version: 1.35 (minimum version 1.12)
Go version: go1.9.2
Git commit: c97c6d6
Built: Wed Dec 27 20:12:46 2017
OS/Arch: linux/amd64
Experimental: false

Deployed clair and chartmuseum where harbor

root@harbor21[/harbor]#docker-compose ps
      Name                     Command               State             Ports          
--------------------------------------------------------------------------------------
chartmuseum         /docker-entrypoint.sh            Up      9999/tcp                 
clair               /docker-entrypoint.sh            Up      6060/tcp, 6061/tcp       
harbor-core         /harbor/start.sh                 Up                               
harbor-db           /entrypoint.sh postgres          Up      5432/tcp                 
harbor-jobservice   /harbor/start.sh                 Up                               
harbor-log          /bin/sh -c /usr/local/bin/ ...   Up      127.0.0.1:1514->10514/tcp
harbor-portal       nginx -g daemon off;             Up      80/tcp                   
nginx               nginx -g daemon off;             Up      0.0.0.0:80->80/tcp       
redis               docker-entrypoint.sh redis ...   Up      6379/tcp                 
registry            /entrypoint.sh /etc/regist ...   Up      5000/tcp                 
registryctl         /harbor/start.sh                 Up                               

Problem
docker login failed.
harbor container has been up for 6 weeks, but yesterday some client failed to login suddenly ,some times it's ok, but some time it's fail
I try to following measure, and not' work

1. restart habor
2. chang user password
3. add new administrator user
4. just use admin user
   BUT today it's work well.

[email protected][/root]# docker login -u admin_zcm -p abc@123A 10.45.80.1
Login Succeeded
[email protected][/root]# docker login -u admin_zcm -p abc@123A 10.45.80.1
Login Succeeded
[email protected][/root]# docker login -u admin_zcm -p abc@123A 10.45.80.1
Login Succeeded
[email protected][/root]# docker login -u admin_zcm -p abc@123A 10.45.80.1
Login Succeeded
[email protected][/root]# docker login -u admin_zcm -p abc@123A 10.45.80.1
Login Succeeded
[email protected][/root]# docker login -u admin_zcm -p abc@123A 10.45.80.1
Error response from daemon: Get http://10.45.80.1/v2/: unauthorized: authentication required
[email protected][/root]# docker login -u admin_zcm -p abc@123A 10.45.80.1
Error response from daemon: Get http://10.45.80.1/v2/: unauthorized: authentication required
[email protected][/root]# docker login -u admin_zcm -p abc@123A 10.45.80.1
Error response from daemon: Get http://10.45.80.1/v2/: unauthorized: authentication required
[email protected][/root]# docker login -u admin_zcm -p abc@123A 10.45.80.1
Error response from daemon: Get http://10.45.80.1/v2/: unauthorized: authentication required
[email protected][/root]# docker login -u admin_zcm -p abc@123A 10.45.80.1
Error response from daemon: Get http://10.45.80.1/v2/: unauthorized: authentication required
[email protected][/root]# docker login -u admin_zcm -p abc@123A 10.45.80.1
Error response from daemon: Get http://10.45.80.1/v2/: unauthorized: authentication required
[email protected][/root]# docker login -u admin_zcm -p abc@123A 10.45.80.1
Error response from daemon: Get http://10.45.80.1/v2/: unauthorized: authentication required
[email protected][/root]# docker login -u admin_zcm -p abc@123A 10.45.80.1
Error response from daemon: Get http://10.45.80.1/v2/: unauthorized: authentication required

proxy.log

login failed

193 Oct 15 09:57:52 172.18.0.1 proxy[1801]: 10.45.80.22 - "GET /v2/ HTTP/1.1" 401 87 "-" "docker/17.12.0-ce go/go1.9.2 git-commit/c97c6d6 kernel/3.10.0-514.6.2.el7.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/17.12.0-ce \x5C(linux\x5C))" 0.004 0.003 .
194 Oct 15 09:57:52 172.18.0.1 proxy[1801]: 10.45.80.22 - "GET /service/token?account=admin_zcm&client_id=docker&offline_token=true&service=harbor-registry HTTP/1.1" 401 0 "-" "docker/17.12.0-ce go/go1.9.2 git-commit/c97c6d6 kernel/3.10.0-514.6.2.el7.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/17.12.0-ce \x5C(linux\x5C))" 0.003 0.002 .

login success
213 Oct 15 09:57:56 172.18.0.1 proxy[1801]: 10.45.80.22 - "GET /v2/ HTTP/1.1" 401 87 "-" "docker/17.12.0-ce go/go1.9.2 git-commit/c97c6d6 kernel/3.10.0-514.6.2.el7.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/17.12.0-ce \x5C(linux\x5C))" 0.004 0.004 .
214 Oct 15 09:57:56 172.18.0.1 proxy[1801]: 10.45.80.22 - "GET /service/token?account=admin_zcm&client_id=docker&offline_token=true&service=harbor-registry HTTP/1.1" 200 896 "-" "docker/17.12.0-ce go/go1.9.2 git-commit/c97c6d6 kernel/3.10.0-514.6.2.el7.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/17.12.0-ce \x5C(linux\x5C))" 0.037 0.037 .
215 Oct 15 09:57:56 172.18.0.1 proxy[1801]: 10.45.80.22 - "GET /v2/ HTTP/1.1" 200 2 "-" "docker/17.12.0-ce go/go1.9.2 git-commit/c97c6d6 kernel/3.10.0-514.6.2.el7.x86_64 os/linux arch/amd64 UpstreamClient(Docker-Client/17.12.0-ce \x5C(linux\x5C))" 0.004 0.004 .

tcpdump login client log

login success
10:16:58.153895 ARP, Request who-has 10.45.80.1 tell 10.45.80.194, length 46
10:16:59.936364 IP 10.45.80.22.35212 > 10.45.80.1.https: Flags [S], seq 573995873, win 29200, options [mss 1460,sackOK,TS val 258670711 ecr 0,nop,wscale 7], length 0
10:16:59.936544 IP 10.45.80.1.https > 10.45.80.22.35212: Flags [R.], seq 0, ack 573995874, win 0, length 0
10:16:59.936740 IP 10.45.80.22.60718 > 10.45.80.1.http: Flags [S], seq 174453011, win 29200, options [mss 1460,sackOK,TS val 258670711 ecr 0,nop,wscale 7], length 0
10:16:59.936976 IP 10.45.80.1.http > 10.45.80.22.60718: Flags [S.], seq 2498638510, ack 174453012, win 28960, options [mss 1460,sackOK,TS val 265983619 ecr 258670711,nop,wscale 7], length 0
10:16:59.937005 IP 10.45.80.22.60718 > 10.45.80.1.http: Flags [.], ack 1, win 229, options [nop,nop,TS val 258670712 ecr 265983619], length 0
10:16:59.937751 IP 10.45.80.22.60718 > 10.45.80.1.http: Flags [P.], seq 1:247, ack 1, win 229, options [nop,nop,TS val 258670712 ecr 265983619], length 246: HTTP: GET /v2/ HTTP/1.1
10:16:59.937939 IP 10.45.80.1.http > 10.45.80.22.60718: Flags [.], ack 247, win 235, options [nop,nop,TS val 265983620 ecr 258670712], length 0
10:16:59.941488 IP 10.45.80.1.http > 10.45.80.22.60718: Flags [P.], seq 1:463, ack 247, win 235, options [nop,nop,TS val 265983623 ecr 258670712], length 462: HTTP: HTTP/1.1 401 Unauthorized
10:16:59.941512 IP 10.45.80.22.60718 > 10.45.80.1.http: Flags [.], ack 463, win 237, options [nop,nop,TS val 258670716 ecr 265983623], length 0
10:16:59.941576 IP 10.45.80.1.http > 10.45.80.22.60718: Flags [F.], seq 463, ack 247, win 235, options [nop,nop,TS val 265983623 ecr 258670712], length 0
10:16:59.942033 IP 10.45.80.22.60718 > 10.45.80.1.http: Flags [F.], seq 247, ack 464, win 237, options [nop,nop,TS val 258670717 ecr 265983623], length 0
10:16:59.942214 IP 10.45.80.1.http > 10.45.80.22.60718: Flags [.], ack 248, win 235, options [nop,nop,TS val 265983624 ecr 258670717], length 0
10:16:59.981311 IP 10.45.80.22.60722 > 10.45.80.1.http: Flags [S], seq 480775236, win 29200, options [mss 1460,sackOK,TS val 258670756 ecr 0,nop,wscale 7], length 0
10:16:59.981506 IP 10.45.80.1.http > 10.45.80.22.60722: Flags [S.], seq 3886844134, ack 480775237, win 28960, options [mss 1460,sackOK,TS val 265983663 ecr 258670756,nop,wscale 7], length 0
10:16:59.981528 IP 10.45.80.22.60722 > 10.45.80.1.http: Flags [.], ack 1, win 229, options [nop,nop,TS val 258670756 ecr 265983663], length 0
10:16:59.981805 IP 10.45.80.22.60722 > 10.45.80.1.http: Flags [P.], seq 1:1298, ack 1, win 229, options [nop,nop,TS val 258670757 ecr 265983663], length 1297: HTTP: GET /v2/ HTTP/1.1
10:16:59.982020 IP 10.45.80.1.http > 10.45.80.22.60722: Flags [.], ack 1298, win 249, options [nop,nop,TS val 265983664 ecr 258670757], length 0
10:16:59.987707 IP 10.45.80.1.http > 10.45.80.22.60722: Flags [P.], seq 1:274, ack 1298, win 249, options [nop,nop,TS val 265983669 ecr 258670757], length 273: HTTP: HTTP/1.1 200 OK
10:16:59.987746 IP 10.45.80.22.60722 > 10.45.80.1.http: Flags [.], ack 274, win 237, options [nop,nop,TS val 258670762 ecr 265983669], length 0
10:16:59.987784 IP 10.45.80.1.http > 10.45.80.22.60722: Flags [F.], seq 274, ack 1298, win 249, options [nop,nop,TS val 265983669 ecr 258670757], length 0
10:16:59.988197 IP 10.45.80.22.60722 > 10.45.80.1.http: Flags [F.], seq 1298, ack 275, win 237, options [nop,nop,TS val 258670763 ecr 265983669], length 0
10:16:59.988349 IP 10.45.80.1.http > 10.45.80.22.60722: Flags [.], ack 1299, win 249, options [nop,nop,TS val 265983670 ecr 258670763], length 0



login failed
10:17:44.942123 IP 10.45.80.22.35660 > 10.45.80.1.https: Flags [S], seq 27536580, win 29200, options [mss 1460,sackOK,TS val 258715717 ecr 0,nop,wscale 7], length 0
10:17:44.942334 IP 10.45.80.1.https > 10.45.80.22.35660: Flags [R.], seq 0, ack 27536581, win 0, length 0
10:17:44.942946 IP 10.45.80.22.32934 > 10.45.80.1.http: Flags [S], seq 3442661736, win 29200, options [mss 1460,sackOK,TS val 258715718 ecr 0,nop,wscale 7], length 0
10:17:44.943145 IP 10.45.80.1.http > 10.45.80.22.32934: Flags [S.], seq 998141796, ack 3442661737, win 28960, options [mss 1460,sackOK,TS val 266028625 ecr 258715718,nop,wscale 7], length 0
10:17:44.943172 IP 10.45.80.22.32934 > 10.45.80.1.http: Flags [.], ack 1, win 229, options [nop,nop,TS val 258715718 ecr 266028625], length 0
10:17:44.943592 IP 10.45.80.22.32934 > 10.45.80.1.http: Flags [P.], seq 1:247, ack 1, win 229, options [nop,nop,TS val 258715718 ecr 266028625], length 246: HTTP: GET /v2/ HTTP/1.1
10:17:44.943831 IP 10.45.80.1.http > 10.45.80.22.32934: Flags [.], ack 247, win 235, options [nop,nop,TS val 266028625 ecr 258715718], length 0
10:17:44.949898 IP 10.45.80.1.http > 10.45.80.22.32934: Flags [P.], seq 1:463, ack 247, win 235, options [nop,nop,TS val 266028632 ecr 258715718], length 462: HTTP: HTTP/1.1 401 Unauthorized
10:17:44.949953 IP 10.45.80.22.32934 > 10.45.80.1.http: Flags [.], ack 463, win 237, options [nop,nop,TS val 258715725 ecr 266028632], length 0
10:17:44.949997 IP 10.45.80.1.http > 10.45.80.22.32934: Flags [F.], seq 463, ack 247, win 235, options [nop,nop,TS val 266028632 ecr 258715718], length 0
10:17:44.950202 IP 10.45.80.22.32934 > 10.45.80.1.http: Flags [F.], seq 247, ack 464, win 237, options [nop,nop,TS val 258715725 ecr 266028632], length 0
10:17:44.950377 IP 10.45.80.1.http > 10.45.80.22.32934: Flags [.], ack 248, win 235, options [nop,nop,TS val 266028632 ecr 258715725], length 0

[steveal]

core.log found a lot login failed
````
md5-69b23bd1e37bbfb23fa078358e0580e1

//filter https://github.com/goharbor/harbor/blob/v1.8.1/src/core/filter/security.go#L369
// standalone
user, err := auth.Login(models.AuthModel{
Principal: username,
Password: password,
})
if err != nil {
log.Errorf("failed to authenticate %s: %v", username, err)
return false
}

// src\coreauthauthenticator.go
//func Login(m models.AuthModel) (*models.User, error) {
...
...
if lock.IsLocked(m.Principal) {
log.Debugf("%s is locked due to login failure, login failed", m.Principal)
return nil, nil
}
user, err := authenticator.Authenticate(m)
if err != nil {
if _, ok = err.(ErrAuth); ok {
log.Debugf("Login failed, locking %s, and sleep for %v", m.Principal, frozenTime)
lock.Lock(m.Principal)
time.Sleep(frozenTime)
}
return nil, err
}
...
...
```

[Hokwang]

This helped!!

[chris-mccoy]

Good day all. I just wanted comment on this bug to report I was seeing this as well--here were my symptoms. After setting up the helm chart with what I thought were correct values, I was seeing this message when trying to log in:

# echo -n mypassword | docker login -u myuser --password-stdin harbor.example.com
Error response from daemon: Get https://harbor.example.com/v2/: unauthorized: authentication required

The output from the core container wasn't very helpful:

2020-03-04T20:01:14Z [DEBUG] [/core/middlewares/url/handler.go:40]: in url handler, path: /v2/
2020/03/04 20:01:14.504 [D] [server.go:2774]  |  192.168.1.168| 401 |    4.17917ms|   match| GET      /v2/   r:/v2/*
2020-03-04T20:01:14Z [DEBUG] [/core/filter/security.go:459]: can not get user information from session
2020-03-04T20:01:14Z [DEBUG] [/core/filter/security.go:514]: user information is nil
2020-03-04T20:01:14Z [DEBUG] [/core/filter/security.go:528]: using local database project manager
2020-03-04T20:01:14Z [DEBUG] [/core/filter/security.go:530]: creating local database security context...
2020-03-04T20:01:14Z [DEBUG] [/core/service/token/token.go:42]: URL for token request: /service/token?account=myuser&client_id=docker&offline_token=true&service=harbor-registry
2020-03-04T20:01:14Z [DEBUG] [/core/service/token/creator.go:204]: scopes: []
2020-03-04T20:01:17Z [DEBUG] [/core/filter/security.go:232]: OIDC CLI modifier only handles request by docker CLI or helm CLI
2020-03-04T20:01:17Z [DEBUG] [/core/filter/security.go:459]: can not get user information from session
2020-03-04T20:01:17Z [DEBUG] [/core/filter/security.go:514]: user information is nil
2020-03-04T20:01:17Z [DEBUG] [/core/filter/security.go:528]: using local database project manager
2020-03-04T20:01:17Z [DEBUG] [/core/filter/security.go:530]: creating local database security context...

Using curl to walk through the login process, and fetching the value from /service/token?account=myuser&client_id=docker&offline_token=true&service=harbor-registry, yielded no useful output. Just an HTTP 401 pointing to the wrong www-authenticate: Bearer ... URL.

Turns out I had used an externalURL value with an incorrect scheme. Changed: externalURL: "http://harbor.example.com" to externalURL: "https://harbor.example.com" which fixed it. Hopefully you spend less time troubleshooting this than I did. :wink: