search

goharbor / harbor

An open source trusted cloud native registry project that stores, signs, and scans content.
https://goharbor.io
Apache License 2.0
24.03k stars 4.75k forks source link

[v1.10.0] Panic 500 when pushing image (using oidc authentication) #10913

Closed joeyjy closed 4 years ago

joeyjy commented 4 years ago

Hi Harbor team,

I have a production environment which has 5 harbor nodes, I always find some panic error in 2 of them, all the configuration files are same, my staff also report some 500 error when thay are pushing image, here's some panic logs which I found in core.log:

Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] the request url is  /service/token#033[0m
Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] Handler crashed with error interface conversion: interface {} is nil, not models.OIDCSetting#033[0m
Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] /usr/local/go/src/runtime/panic.go:522#033[0m
Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] /usr/local/go/src/runtime/iface.go:248#033[0m
Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] /harbor/src/common/utils/oidc/helper.go:243#033[0m
Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] /harbor/src/common/utils/oidc/secret.go:116#033[0m
Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] /harbor/src/common/utils/oidc/secret.go:131#033[0m
Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] /harbor/src/core/filter/security.go:242#033[0m
Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] /harbor/src/core/filter/security.go:135#033[0m
Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] /harbor/src/vendor/github.com/astaxie/beego/router.go:615#033[0m
Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] /harbor/src/vendor/github.com/astaxie/beego/router.go:701#033[0m
Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] /usr/local/go/src/net/http/server.go:2774#033[0m
Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] /usr/local/go/src/net/http/server.go:1878#033[0m
Mar  2 17:31:36 172.17.0.1 core[1051]: 2020/03/02 09:31:36 #033[1;35m[C] [panic.go:522] /usr/local/go/src/runtime/asm_amd64.s:1337#033[0m
wglambert commented 4 years ago

There was one other issue with that error error interface conversion: interface {} is nil https://github.com/goharbor/harbor/issues/7695 which was closed with https://github.com/goharbor/harbor/pull/7709

joeyjy commented 4 years ago

@wglambert thanks, I forgot to mention that my harbor version is 1.10.0, that issue doesn't meet my situation

ragarcia26 commented 4 years ago

We're seeing something similar on v1.10.0-6b84b62f, when pushing to charts to harbor we sometimes get this response 

$ helm push --force metrics-aggregator-2.16.0-phil-test2.tgz harbor 
Pushing metrics-aggregator-2.16.0-phil-test2.tgz to harbor...
Done.
$ helm push --force metrics-aggregator-2.16.0-phil-test2.tgz harbor 
Pushing metrics-aggregator-2.16.0-phil-test2.tgz to harbor...
Error: 500: could not properly parse response JSON: 
<!DOCTYPE html>
<html>
<head>
    <meta http-equiv="Content-Type" content="text/html; charset=UTF-8" />
    <title>beego application error</title>
    <style>
        html, body, body * {padding: 0; margin: 0;}
        #header {background:#ffd; border-bottom:solid 2px #A31515; padding: 20px 10px;}
        #header h2{ }
        #footer {border-top:solid 1px #aaa; padding: 5px 10px; font-size: 12px; color:green;}
        #content {padding: 5px;}
        #content .stack b{ font-size: 13px; color: red;}
        #content .stack pre{padding-left: 10px;}
        table {}
        td.t {text-align: right; padding-right: 5px; color: #888;}
    </style>
    <script type="text/javascript">
    </script>
</head>
<body>
    <div id="header">
        <h2>Harbor:interface conversion: interface {} is nil, not models.OIDCSetting</h2>
    </div>
    <div id="content">
        <table>
            <tr>
                <td class="t">Request Method: </td><td>POST</td>
            </tr>
            <tr>
                <td class="t">Request URL: </td><td>/api/chartrepo/cloud/charts?force</td>
            </tr>
            <tr>
                <td class="t">RemoteAddr: </td><td>192.168.242.128</td>
            </tr>
        </table>
        <div class="stack">
            <b>Stack</b>
            <pre>/usr/local/go/src/runtime/panic.go:522
/usr/local/go/src/runtime/iface.go:248
/harbor/src/common/utils/oidc/helper.go:243
/harbor/src/common/utils/oidc/secret.go:116
/harbor/src/common/utils/oidc/secret.go:131
/harbor/src/core/filter/security.go:242
/harbor/src/core/filter/security.go:135
/harbor/src/vendor/github.com/astaxie/beego/router.go:615
/harbor/src/vendor/github.com/astaxie/beego/router.go:701
/usr/local/go/src/net/http/server.go:2774
/usr/local/go/src/net/http/server.go:1878
/usr/local/go/src/runtime/asm_amd64.s:1337
</pre>
        </div>
    </div>
    <div id="footer">
        <p>beego 1.9.0 (beego framework)</p>
        <p>golang version: go1.12.12</p>
    </div>
</body>
</html>

Error: plugin "push" exited with error
$ helm push --force metrics-aggregator-2.16.0-phil-test2.tgz harbor 
Pushing metrics-aggregator-2.16.0-phil-test2.tgz to harbor...
Done.
burdzwastaken commented 4 years ago

We are seeing the same issue in 1.10.2 with docker pull as well:

2020/04/10 19:56:52.025 [C] [panic.go:522]  the request url is  /service/token
2020/04/10 19:56:52.025 [C] [panic.go:522]  Handler crashed with error interface conversion: interface {} is nil, not models.OIDCSetting
2020/04/10 19:56:52.025 [C] [panic.go:522]  /usr/local/go/src/runtime/panic.go:522
2020/04/10 19:56:52.025 [C] [panic.go:522]  /usr/local/go/src/runtime/iface.go:248
2020/04/10 19:56:52.025 [C] [panic.go:522]  /harbor/src/common/utils/oidc/helper.go:243
2020/04/10 19:56:52.025 [C] [panic.go:522]  /harbor/src/common/utils/oidc/secret.go:116
2020/04/10 19:56:52.025 [C] [panic.go:522]  /harbor/src/common/utils/oidc/secret.go:131
2020/04/10 19:56:52.025 [C] [panic.go:522]  /harbor/src/core/filter/security.go:242
2020/04/10 19:56:52.025 [C] [panic.go:522]  /harbor/src/core/filter/security.go:135
2020/04/10 19:56:52.025 [C] [panic.go:522]  /harbor/src/vendor/github.com/astaxie/beego/router.go:644
2020/04/10 19:56:52.025 [C] [panic.go:522]  /harbor/src/vendor/github.com/astaxie/beego/router.go:730
2020/04/10 19:56:52.025 [C] [panic.go:522]  /usr/local/go/src/net/http/server.go:2774
2020/04/10 19:56:52.025 [C] [panic.go:522]  /usr/local/go/src/net/http/server.go:1878
2020/04/10 19:56:52.025 [C] [panic.go:522]  /usr/local/go/src/runtime/asm_amd64.s:1337
joeyjy commented 4 years ago

@wglambert @ragarcia26 @burdzwastaken
I can reproduce this panic problem. I have 6 nodes in my harbor cluster at this moment, everytime I run 'docker-compose down && docker-compose up -d' to recreate harbor, I need to use every node to login harbor, otherwise the panic error occurs (modify hosts file to point my harbor domain to specified node).

I looked into source code, found this file: https://github.com/goharbor/harbor/blob/master/src/common/utils/oidc/helper.go
line 42:

type providerHelper struct {
    sync.Mutex
    instance     atomic.Value
    setting      atomic.Value
    creationTime time.Time
}

wonder if it is the atomic value cause the problem? every node need to connect OIDC provider in order to init models.OIDCSetting？

ragarcia26 commented 4 years ago

That makes sense to me because it was after I loaded up a fresh deploy and the error seemed to have to gone away after some time

galicantensoft commented 4 years ago

I can reproduce this error with harbor version 1.10.2 ( helm chart installation ). After harbor-core pod restart docker authentication initially crash with error:

[panic.go:522] Handler crashed with error interface conversion: interface {} is nil, not models.OIDCSetting

After I login with my account from web its seems like initial configuration its loaded and everything works fine.

klinux commented 4 years ago

I had this issue too, I need to do login with oidc account from web to get Harbor login success. Harbor 2.0 had this same issue?

Harbor: v1.10.2-d0189bed Core Instances: 3

Thanks

joeyjy commented 4 years ago

@wglambert Will harbor team look into this issue? Recently, I also found similar errors suddenly occured when everything was ok with harbor service

Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] the request url is  /service/token#033[0m
Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] Handler crashed with error interface conversion: interface {} is nil, not models.OIDCSetting#033[0m
Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] /usr/local/go/src/runtime/panic.go:522#033[0m
Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] /usr/local/go/src/runtime/iface.go:248#033[0m
Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] /harbor/src/common/utils/oidc/helper.go:243#033[0m
Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] /harbor/src/common/utils/oidc/secret.go:116#033[0m
Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] /harbor/src/common/utils/oidc/secret.go:131#033[0m
Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] /harbor/src/core/filter/security.go:242#033[0m
Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] /harbor/src/core/filter/security.go:135#033[0m
Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] /harbor/src/vendor/github.com/astaxie/beego/router.go:615#033[0m
Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] /harbor/src/vendor/github.com/astaxie/beego/router.go:701#033[0m
Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] /usr/local/go/src/net/http/server.go:2774#033[0m
Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] /usr/local/go/src/net/http/server.go:1878#033[0m
Jul 14 15:37:56 172.18.0.1 core[1067]: 2020/07/14 07:37:56 #033[1;35m[C] [panic.go:522] /usr/local/go/src/runtime/asm_amd64.s:1337#033[0m
horjulf commented 4 years ago

Can replicate too, any new scheduled core pod will fail with a request to /v2/*.

2020/07/20 22:37:56.875 [D] [server.go:2774]  |  <ip>| 401 |   6.774748ms|   match| GET      /v2/   r:/v2/*
2020/07/20 22:37:57.778 [C] [panic.go:522]  the request url is  /service/token
2020/07/20 22:37:57.778 [C] [panic.go:522]  Handler crashed with error interface conversion: interface {} is nil, not models.OIDCSetting
2020/07/20 22:37:57.778 [C] [panic.go:522]  /usr/local/go/src/runtime/panic.go:522
2020/07/20 22:37:57.778 [C] [panic.go:522]  /usr/local/go/src/runtime/iface.go:248
2020/07/20 22:37:57.778 [C] [panic.go:522]  /harbor/src/common/utils/oidc/helper.go:243
2020/07/20 22:37:57.778 [C] [panic.go:522]  /harbor/src/common/utils/oidc/secret.go:116
2020/07/20 22:37:57.778 [C] [panic.go:522]  /harbor/src/common/utils/oidc/secret.go:131
2020/07/20 22:37:57.778 [C] [panic.go:522]  /harbor/src/core/filter/security.go:242
2020/07/20 22:37:57.778 [C] [panic.go:522]  /harbor/src/core/filter/security.go:135
2020/07/20 22:37:57.778 [C] [panic.go:522]  /harbor/src/vendor/github.com/astaxie/beego/router.go:644
2020/07/20 22:37:57.778 [C] [panic.go:522]  /harbor/src/vendor/github.com/astaxie/beego/router.go:730
2020/07/20 22:37:57.778 [C] [panic.go:522]  /usr/local/go/src/net/http/server.go:2774
2020/07/20 22:37:57.778 [C] [panic.go:522]  /usr/local/go/src/net/http/server.go:1878
2020/07/20 22:37:57.778 [C] [panic.go:522]  /usr/local/go/src/runtime/asm_amd64.s:1337
2020/07/20 22:37:57.778 [server.go:3010]  [HTTP] http: superfluous response.WriteHeader call from github.com/astaxie/beego/context.(*Response).WriteHeader (context.go:230)
thoro commented 4 years ago

Same, v2.1.0:

2020/09/21 08:38:52.203  [HTTP] http: panic serving 10.253.45.1:52494: interface conversion: interface {} is nil, not models.OIDCSetting
goroutine 251 [running]:
net/http.(*conn).serve.func1(0xc001080640)
    /usr/local/go/src/net/http/server.go:1800 +0x139
panic(0x1d80c40, 0xc001588870)
    /usr/local/go/src/runtime/panic.go:975 +0x3e3
github.com/goharbor/harbor/src/common/utils/oidc.UserInfoFromToken(0x250eb40, 0xc001588570, 0xc00047a1c0, 0x1e2bc00, 0xc00047a1c0, 0x0)
    /harbor/src/common/utils/oidc/helper.go:244 +0x693
github.com/goharbor/harbor/src/common/utils/oidc.(*defaultManager).VerifySecret(0x369bff0, 0x250eb40, 0xc001588570, 0xc00171e230, 0x22, 0xc00171e253, 0x20, 0xc00109e8c0, 0xc0018a4e98, 0x1a8e6f0)
    /harbor/src/common/utils/oidc/secret.go:116 +0x5b5
github.com/goharbor/harbor/src/common/utils/oidc.VerifySecret(...)
    /harbor/src/common/utils/oidc/secret.go:131
github.com/goharbor/harbor/src/server/middleware/security.(*oidcCli).Generate(0x36d0140, 0xc001898100, 0x0, 0x0)
    /harbor/src/server/middleware/security/oidc_cli.go:58 +0x1b6
github.com/goharbor/harbor/src/server/middleware/security.Middleware.func1.1(0x24f7c40, 0xc00221c230, 0xc000a13800)
    /harbor/src/server/middleware/security/security.go:58 +0x172
net/http.HandlerFunc.ServeHTTP(0xc001d67060, 0x24f7c40, 0xc00221c230, 0xc000a13800)
    /usr/local/go/src/net/http/server.go:2041 +0x44
github.com/goharbor/harbor/src/server/middleware/artifactinfo.Middleware.func1.1(0x24f7c40, 0xc00221c230, 0xc000a13800)
    /harbor/src/server/middleware/artifactinfo/artifact_info.go:55 +0x8ea
net/http.HandlerFunc.ServeHTTP(0xc001d67080, 0x24f7c40, 0xc00221c230, 0xc000a13800)
    /usr/local/go/src/net/http/server.go:2041 +0x44
github.com/goharbor/harbor/src/server/middleware/transaction.Middleware.func1.1(0x250eb40, 0xc0015b0e10, 0x0, 0xc001226500)
    /harbor/src/server/middleware/transaction/transaction.go:62 +0x19d
github.com/goharbor/harbor/src/lib/orm.WithTransaction.func1(0x250eb40, 0xc0015b0e10, 0x0, 0x0)
    /harbor/src/lib/orm/orm.go:73 +0x176
github.com/goharbor/harbor/src/server/middleware/transaction.Middleware.func1(0x24f7c80, 0xc001226520, 0xc00221e500, 0x24c4e20, 0xc001d67080)
    /harbor/src/server/middleware/transaction/transaction.go:71 +0xfe
github.com/goharbor/harbor/src/server/middleware.New.func1.1(0x24f7c80, 0xc001226520, 0xc00221e500)
    /harbor/src/server/middleware/middleware.go:57 +0x105
net/http.HandlerFunc.ServeHTTP(0xc0005c8940, 0x24f7c80, 0xc001226520, 0xc00221e500)
    /usr/local/go/src/net/http/server.go:2041 +0x44
github.com/goharbor/harbor/src/server/middleware/notification.Middleware.func1(0x2507540, 0xc00177e000, 0xc00221e400, 0x24c4e20, 0xc0005c8940)
    /harbor/src/server/middleware/notification/notification.go:31 +0x225
github.com/goharbor/harbor/src/server/middleware.New.func1.1(0x2507540, 0xc00177e000, 0xc00221e400)
    /harbor/src/server/middleware/middleware.go:57 +0x105
net/http.HandlerFunc.ServeHTTP(0xc0005c8980, 0x2507540, 0xc00177e000, 0xc00221e400)
    /usr/local/go/src/net/http/server.go:2041 +0x44
github.com/goharbor/harbor/src/server/middleware/orm.MiddlewareWithConfig.func1(0x2507540, 0xc00177e000, 0xc00221e300, 0x24c4e20, 0xc0005c8980)
    /harbor/src/server/middleware/orm/orm.go:53 +0x18b
github.com/goharbor/harbor/src/server/middleware.New.func1.1(0x2507540, 0xc00177e000, 0xc00221e300)
    /harbor/src/server/middleware/middleware.go:57 +0x105
net/http.HandlerFunc.ServeHTTP(0xc0005c89c0, 0x2507540, 0xc00177e000, 0xc00221e300)
    /usr/local/go/src/net/http/server.go:2041 +0x44
github.com/goharbor/harbor/src/server/middleware.New.func1.1(0x2507540, 0xc00177e000, 0xc00221e300)
    /harbor/src/server/middleware/middleware.go:52 +0xcc
net/http.HandlerFunc.ServeHTTP(0xc0005c8a00, 0x2507540, 0xc00177e000, 0xc00221e300)
    /usr/local/go/src/net/http/server.go:2041 +0x44
github.com/goharbor/harbor/src/server/middleware/session.Middleware.func1.1(0x2507540, 0xc00177e000, 0xc00221e300)
    /harbor/src/server/middleware/session/session.go:34 +0x99
net/http.HandlerFunc.ServeHTTP(0xc001d670a0, 0x2507540, 0xc00177e000, 0xc00221e300)
    /usr/local/go/src/net/http/server.go:2041 +0x44
github.com/goharbor/harbor/src/server/middleware/log.Middleware.func1(0x2507540, 0xc00177e000, 0xc00221e200, 0x24c4e20, 0xc001d670a0)
    /harbor/src/server/middleware/log/log.go:33 +0x422
github.com/goharbor/harbor/src/server/middleware.New.func1.1(0x2507540, 0xc00177e000, 0xc00221e200)
    /harbor/src/server/middleware/middleware.go:57 +0x105
net/http.HandlerFunc.ServeHTTP(0xc0005c8a40, 0x2507540, 0xc00177e000, 0xc00221e200)
    /usr/local/go/src/net/http/server.go:2041 +0x44
github.com/goharbor/harbor/src/server/middleware/requestid.Middleware.func1(0x2507540, 0xc00177e000, 0xc00221e200, 0x24c4e20, 0xc0005c8a40)
    /harbor/src/server/middleware/requestid/requestid.go:37 +0x1ad
github.com/goharbor/harbor/src/server/middleware.New.func1.1(0x2507540, 0xc00177e000, 0xc00221e200)
    /harbor/src/server/middleware/middleware.go:57 +0x105
net/http.HandlerFunc.ServeHTTP(0xc0005c8a80, 0x2507540, 0xc00177e000, 0xc00221e200)
    /usr/local/go/src/net/http/server.go:2041 +0x44
net/http.serverHandler.ServeHTTP(0xc0002cc1c0, 0x2507540, 0xc00177e000, 0xc00221e200)
    /usr/local/go/src/net/http/server.go:2836 +0xa3
net/http.(*conn).serve(0xc001080640, 0x250ea80, 0xc00123c4c0)
    /usr/local/go/src/net/http/server.go:1924 +0x86c
created by net/http.(*Server).Serve
    /usr/local/go/src/net/http/server.go:2962 +0x35c

Refreshing the UI or logging in again solves the issue on the newly scheduled pod

horjulf commented 4 years ago

@steven-zou can we get some labels on this issue for visibility as this is reproducible in all versions since at least 1.10 and affects service availability (autoscaling, HA, etc) for instances using OIDC auth. 🙏

muzimuzi42 commented 3 years ago

this change has been merged to master since October. Any idea when it'll be packaged in a release ??

horjulf commented 3 years ago

@wy65701436 can this be included in v2.1.3 ? 🙏

muzimuzi42 commented 3 years ago

looks like this is finally included in the v2.2.1 release, thanks !