QA (public) » openQA Project (public)

observation¶

from the logs on osd (privatized)

[Fri Mar 10 04:36:03 2017] [31317:debug] Net::OpenID::Consumer: Cache MISS for https://www.opensuse.org/openid/user/JohnDoe
[Fri Mar 10 04:36:03 2017] [812:debug] POST "/api/v1/jobs/808252/status"
[Fri Mar 10 04:36:03 2017] [812:debug] Routing to controller "OpenQA::WebAPI::Controller::API::V1" and action "auth_operator"
[Fri Mar 10 04:36:03 2017] [812:debug] API key from client: *ZZZZZZZZZZZZZZ*
[Fri Mar 10 04:36:03 2017] [812:debug] Key is for user 'openqaworker2'
[Fri Mar 10 04:36:03 2017] [812:debug] API auth by user: openqaworker2, operator: 1
[Fri Mar 10 04:36:03 2017] [812:debug] Routing to controller "OpenQA::WebAPI::Controller::API::V1::Job" and action "update_status"
[Fri Mar 10 04:36:03 2017] [812:debug] 200 OK (0.032422s, 30.843/s)
[Fri Mar 10 04:36:04 2017] [31317:debug] Net::OpenID::Consumer: Cache MISS for https://www.opensuse.org/openid/user/JohnDoe
[Fri Mar 10 04:36:05 2017] [31317:debug] Net::OpenID::Consumer: semantic info (https://www.opensuse.org/openid/user/JohnDoe) =
[Fri Mar 10 04:36:05 2017] [31317:debug] Net::OpenID::Consumer: Server is https://www.opensuse.org/openid/provider
[Fri Mar 10 04:36:05 2017] [31317:debug] Net::OpenID::Consumer: verified_identity: assoc_handle: 1437001474530-35122
[Fri Mar 10 04:36:05 2017] [31317:debug] Net::OpenID::Consumer: handle_assoc: dumb mode: no_cache
[Fri Mar 10 04:36:05 2017] [31317:debug] Net::OpenID::Consumer: verified_identity: verifying using HTTP (dumb mode)
[Fri Mar 10 04:36:05 2017] [30073:debug] POST "/api/v1/jobs/807981/status"
[Fri Mar 10 04:36:05 2017] [30073:debug] Routing to controller "OpenQA::WebAPI::Controller::API::V1" and action "auth_operator"
[Fri Mar 10 04:36:05 2017] [30073:debug] API key from client: *YYYYYYYYYY*
[Fri Mar 10 04:36:05 2017] [30073:debug] Key is for user 'malbec'
[Fri Mar 10 04:36:05 2017] [30073:debug] API auth by user: malbec, operator: 1
[Fri Mar 10 04:36:05 2017] [30073:debug] Routing to controller "OpenQA::WebAPI::Controller::API::V1::Job" and action "update_status"
[Fri Mar 10 04:36:05 2017] [30073:debug] 200 OK (0.035889s, 27.864/s)
[Fri Mar 10 04:36:05 2017] [31317:debug] Net::OpenID::Consumer: verified identity! = https://www.opensuse.org/openid/user/JohnDoe
[Fri Mar 10 04:36:05 2017] [31317:debug] 302 Found (2.348143s, 0.426/s)
[Fri Mar 10 04:36:06 2017] [812:debug] POST "/api/v1/jobs/807564/status"
[Fri Mar 10 04:36:06 2017] [812:debug] Routing to controller "OpenQA::WebAPI::Controller::API::V1" and action "auth_operator"
[Fri Mar 10 04:36:06 2017] [812:debug] API key from client: *XXXXXXXX*
[Fri Mar 10 04:36:06 2017] [812:debug] Key is for user 'openqaw2'
[Fri Mar 10 04:36:06 2017] [812:debug] API auth by user: openqaw2, operator: 1
[Fri Mar 10 04:36:06 2017] [812:debug] Routing to controller "OpenQA::WebAPI::Controller::API::V1::Job" and action "update_status"
[Fri Mar 10 04:36:06 2017] [812:debug] 200 OK (0.023016s, 43.448/s)
[Fri Mar 10 04:36:06 2017] [31317:debug] GET "/response"
[Fri Mar 10 04:36:06 2017] [31317:debug] Routing to controller "OpenQA::WebAPI::Controller::Session" and action "response"
[Fri Mar 10 04:36:06 2017] [31317:error] Not an OpenID message at /usr/share/openqa/script/../lib/OpenQA/WebAPI/Auth/OpenID.pm line 116.

[Fri Mar 10 04:36:06 2017] [31317:debug] Template "exception.production.html.ep" not found
[Fri Mar 10 04:36:06 2017] [31317:debug] Rendering template "exception.html.ep"
[Fri Mar 10 04:36:06 2017] [31317:debug] Rendering template "layouts/error.html.ep"
[Fri Mar 10 04:36:06 2017] [31317:debug] 500 Internal Server Error (0.028803s, 34.719/s)

steps to reproduce¶

We could ask "JohnDoe" if it is reproducible but the error messages only shows up very seldomly and at least in this instance not more than once

probem¶

H1. related to external ID service not giving back proper result
H2. something internal to openQA

workaround¶

probably retrying the login works.