Delivery+Github integration fails with 'key already created'

Chef Automate
1

While trying to follow https://docs.chef.io/release/delivery/integrate_delivery_github.html
I ran into issues where the integration doesn’t quite complete (and there wasn’t much info in the UI, so I started digging into the logs).

I’m unsure as to why we try to post to github/user/keys more than once.
I deleted the key manually and tried again, but it’s getting called multiple times after initial creation.

What would be a good approach to debugging this integration?

root@delivery-server-test:~# delivery-ctl list-applications
OAuth Applications: 
 github

root@delivery-server-test:~# delivery-ctl tail | grep github
{function_clause,[{cowboy_req,reply,[200,[],ok,{http_req,#Port<0.5364>,ranch_tcp,close,<0.1482.0>,<<"GET">>,'HTTP/1.1',{{127,0,0,1},39125},<<"192.168.2.75">>,undefined,443,<<"/api/v0/github_auth_callback">>,undefined,<<"code=7e2b5472c14fe8164da5&state=tJIPe64NL3SiXQZHVg18SFqDD6yOyfQ2IST3L6Y5I5KH0yXA6S7n5QWTCnfDRTCjlv7U4GBAcyLU1EvaVEP0Ls8jhkSALzcfajjBctuqJnLdk2BZqeLZXlBt9zfxlOxc49ZsF1FMn0Ue2MqiXF19YkfZbyZtAR9sP13s">>,[{<<"code">>,<<"7e2b5472c14fe8164da5">>},{<<"state">>,<<"tJIPe64NL3SiXQZHVg18SFqDD6yOyfQ2IST3L6Y5I5KH0yXA6S7n5QWTCnfDRTCjlv7U4GBAcyLU1EvaVEP0Ls8jhkSALzcfajjBctuqJnLdk2BZqeLZXlBt9zfxlOxc49ZsF1FMn0Ue2MqiXF19YkfZbyZtAR9sP13s">>}],[],[{<<"host">>,<<"192.168.2.75:443">>},{<<"x-real-ip">>,<<"192.168.237.203">>},{<<"x-scheme">>,<<"https">>},{<<"x-forwarded-for">>,<<"192.168.237.203">>},{<<"x-forwarded-proto">>,<<"https">>},{<<"connection">>,<<"close">>},{<<"user-agent">>,<<"Mozilla/5.0 (X11; Linux x86_64; rv:47.0) Gecko/20100101 Firefox/47.0">>},{<<"accept">>,<<"text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8">>},{<<"accept-language">>,<<"en-US,en;q=0.5">>},{<<"accept-encoding">>,<<"gzip, deflate, br">>},{<<"referer">>,<<"https://github.com">>}],[{<<"if-modified-since">>,undefined},{<<"if-none-match">>,undefined},{<<"if-unmodified-since">>,undefined},{<<"if-match">>,undefined},{<<"accept">>,[{{<<"text">>,<<"html">>,[]},1000,[]},{{<<"application">>,<<"xhtml+xml">>,[]},1000,[]},{{<<"application">>,<<"xml">>,[]},900,[]},{{<<"*">>,<<"*">>,[]},800,[]}]},{<<"connection">>,[<<"close">>]}],undefined,[{media_type,{<<"application">>,<<"json">>,[]}},{charset,undefined}],waiting,<<>>,undefined,false,done,[],ok,undefined}],[{file,"src/cowboy_req.erl"},{line,815}]},{cowboy_rest,respond,3,[{file,"src/cowboy_rest.erl"},{line,993}]},{cowboy_rest,set_resp_body,2,[{file,"src/cowboy_rest.erl"},{line,869}]},{cowboy_protocol,execute,4,[{file,"src/cowboy_protocol.erl"},{line,435}]}]}
2016-06-19 21:24:42.904 [error] <0.1487.0> failed_http_req=https://api.github.com/user/keys; body={"message":"Validation Failed","errors":[{"resource":"PublicKey","code":"custom","field":"key","message":"key is already in use"}],"documentation_url":"https://developer.github.com/v3/users/keys/#create-a-public-key"}; reason=422
2016-06-19 21:24:42.907 [error] <0.1487.0> failed_call={github_repo:add_user_pub_key, [<<"test">>,<<"Delivery Builder (test)">>,<<"ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDAX6YF66vRkx7v1TrcL0AatRSUOXOZIpioScAYkhfOwesorKzxfXvvD0PA/K1kAjwc8Y7cqcNjd/IuTgfOi4Oydv0EsODcGNfV2FDOrDwZZkJQgJBNSLRH6DrQLhDDs4kvvUFeARmgiiSe2ieT42eQL8UcgU4hMWo9rtiXb8bf77LSiccmD1FSyWTxA0uQ9kiiPQm3dkVwkGOkJKM3ttnKtDr/jYSgELKHmCm7C/x4Cq2rdEKc/5xiVS0bKrfehshZVgdinnLCOHV1ocpEEXxGTt0nfsykGLF/Zln4rg4FpGPtbwxmswbnySgiJvaPsHt0KY44bwrJbfbsz7Ub10VR devops@codecan.novalocal\n">>]}; reason=unhandled_status; http_response_headers=[{"Server","GitHub.com"},{"Date","Sun, 19 Jun 2016 21:24:42 GMT"},{"Content-Type","application/json; charset=utf-8"},{"Content-Length","217"},{"Status","422 Unprocessable Entity"},{"X-RateLimit-Limit","5000"},{"X-RateLimit-Remaining","4997"},{"X-RateLimit-Reset","1466374956"},{"X-OAuth-Scopes","admin:repo_hook, repo, write:public_key"},{"X-Accepted-OAuth-Scopes","admin:public_key, write:public_key"},{"X-OAuth-Client-Id","d7757bc5b47345d25c97"},{"X-GitHub-Media-Type","github.v3"},{"Access-Control-Expose-Headers","ETag, Link, X-GitHub-OTP, X-RateLimit-Limit, X-RateLimit-Remaining, X-RateLimit-Reset, X-OAuth-Scopes, X-Accepted-OAuth-Scopes, X-Poll-Interval"},{"Access-Control-Allow-Origin","*"},{"Content-Security-Policy","default-src 'none'"},{"Strict-Transport-Security","max-age=31536000; includeSubdomains; preload"},{"X-Content-Type-Options","nosniff"},{"X-Frame-Options","deny"},{"X-XSS-Protection","1; mode=block"},{"X-GitHub-Request-Id","43C0F986:5523:1D248B3:57670D9A"}]; http_response_body={"message":"Validation Failed","errors":[{"resource":"PublicKey","code":"custom","field":"key","message":"key is already in use"}],"documentation_url":"https://developer.github.com/v3/users/keys/#create-a-public-key"}
2016-06-19 21:24:54.699 [error] <0.1492.0> failed_http_req=https://api.github.com/user/keys; body={"message":"Validation Failed","errors":[{"resource":"PublicKey","code":"custom","field":"key","message":"key is already in use"}],"documentation_url":"https://developer.github.com/v3/users/keys/#create-a-public-key"}; reason=422
2016-06-19 21:24:54.700 [error] <0.1492.0> failed_call={github_repo:add_user_pub_key, [<<"test">>,<<"Delivery Builder (test)">>,<<"ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDAX6YF66vRkx7v1TrcL0AatRSUOXOZIpioScAYkhfOwesorKzxfXvvD0PA/K1kAjwc8Y7cqcNjd/IuTgfOi4Oydv0EsODcGNfV2FDOrDwZZkJQgJBNSLRH6DrQLhDDs4kvvUFeARmgiiSe2ieT42eQL8UcgU4hMWo9rtiXb8bf77LSiccmD1FSyWTxA0uQ9kiiPQm3dkVwkGOkJKM3ttnKtDr/jYSgELKHmCm7C/x4Cq2rdEKc/5xiVS0bKrfehshZVgdinnLCOHV1ocpEEXxGTt0nfsykGLF/Zln4rg4FpGPtbwxmswbnySgiJvaPsHt0KY44bwrJbfbsz7Ub10VR devops@codecan.novalocal\n">>]}; reason=unhandled_status; http_response_headers=[{"Server","GitHub.com"},{"Date","Sun, 19 Jun 2016 21:24:54 GMT"},{"Content-Type","application/json; charset=utf-8"},{"Content-Length","217"},{"Status","422 Unprocessable Entity"},{"X-RateLimit-Limit","5000"},{"X-RateLimit-Remaining","4996"},{"X-RateLimit-Reset","1466374956"},{"X-OAuth-Scopes","admin:repo_hook, repo, write:public_key"},{"X-Accepted-OAuth-Scopes","admin:public_key, write:public_key"},{"X-OAuth-Client-Id","d7757bc5b47345d25c97"},{"X-GitHub-Media-Type","github.v3"},{"Access-Control-Expose-Headers","ETag, Link, X-GitHub-OTP, X-RateLimit-Limit, X-RateLimit-Remaining, X-RateLimit-Reset, X-OAuth-Scopes, X-Accepted-OAuth-Scopes, X-Poll-Interval"},{"Access-Control-Allow-Origin","*"},{"Content-Security-Policy","default-src 'none'"},{"Strict-Transport-Security","max-age=31536000; includeSubdomains; preload"},{"X-Content-Type-Options","nosniff"},{"X-Frame-Options","deny"},{"X-XSS-Protection","1; mode=block"},{"X-GitHub-Request-Id","43C0F986:EA5C:49EF386:57670DA6"}]; http_response_body={"message":"Validation Failed","errors":[{"resource":"PublicKey","code":"custom","field":"key","message":"key is already in use"}],"documentation_url":"https://developer.github.com/v3/users/keys/#create-a-public-key"}
{function_clause,[{cowboy_req,reply,[200,[],ok,{http_req,#Port<0.5364>,ranch_tcp,close,<0.1482.0>,<<"GET">>,'HTTP/1.1',{{127,0,0,1},39125},<<"192.168.2.75">>,undefined,443,<<"/api/v0/github_auth_callback">>,undefined,<<"code=7e2b5472c14fe8164da5&state=tJIPe64NL3SiXQZHVg18SFqDD6yOyfQ2IST3L6Y5I5KH0yXA6S7n5QWTCnfDRTCjlv7U4GBAcyLU1EvaVEP0Ls8jhkSALzcfajjBctuqJnLdk2BZqeLZXlBt9zfxlOxc49ZsF1FMn0Ue2MqiXF19YkfZbyZtAR9sP13s">>,[{<<"code">>,<<"7e2b5472c14fe8164da5">>},{<<"state">>,<<"tJIPe64NL3SiXQZHVg18SFqDD6yOyfQ2IST3L6Y5I5KH0yXA6S7n5QWTCnfDRTCjlv7U4GBAcyLU1EvaVEP0Ls8jhkSALzcfajjBctuqJnLdk2BZqeLZXlBt9zfxlOxc49ZsF1FMn0Ue2MqiXF19YkfZbyZtAR9sP13s">>}],[],[{<<"host">>,<<"192.168.2.75:443">>},{<<"x-real-ip">>,<<"192.168.237.203">>},{<<"x-scheme">>,<<"https">>},{<<"x-forwarded-for">>,<<"192.168.237.203">>},{<<"x-forwarded-proto">>,<<"https">>},{<<"connection">>,<<"close">>},{<<"user-agent">>,<<"Mozilla/5.0 (X11; Linux x86_64; rv:47.0) Gecko/20100101 Firefox/47.0">>},{<<"accept">>,<<"text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8">>},{<<"accept-language">>,<<"en-US,en;q=0.5">>},{<<"accept-encoding">>,<<"gzip, deflate, br">>},{<<"referer">>,<<"https://github.com">>}],[{<<"if-modified-since">>,undefined},{<<"if-none-match">>,undefined},{<<"if-unmodified-since">>,undefined},{<<"if-match">>,undefined},{<<"accept">>,[{{<<"text">>,<<"html">>,[]},1000,[]},{{<<"application">>,<<"xhtml+xml">>,[]},1000,[]},{{<<"application">>,<<"xml">>,[]},900,[]},{{<<"*">>,<<"*">>,[]},800,[]}]},{<<"connection">>,[<<"close">>]}],undefined,[{media_type,{<<"application">>,<<"json">>,[]}},{charset,undefined}],waiting,<<>>,undefined,false,done,[],ok,undefined}],[{file,"src/cowboy_req.erl"},{line,815}]},{cowboy_rest,respond,3,[{file,"src/cowboy_rest.erl"},{line,993}]},{cowboy_rest,set_resp_body,2,[{file,"src/cowboy_rest.erl"},{line,869}]},{cowboy_protocol,execute,4,[{file,"src/cowboy_protocol.erl"},{line,435}]}]}
Ranch listener http had connection process started with cowboy_protocol:start_link/4 at <0.1482.0> exit with reason: {function_clause,[{cowboy_req,reply,[200,[],ok,{http_req,#Port<0.5364>,ranch_tcp,close,<0.1482.0>,<<"GET">>,'HTTP/1.1',{{127,0,0,1},39125},<<"192.168.2.75">>,undefined,443,<<"/api/v0/github_auth_callback">>,undefined,<<"code=7e2b5472c14fe8164da5&state=tJIPe64NL3SiXQZHVg18SFqDD6yOyfQ2IST3L6Y5I5KH0yXA6S7n5QWTCnfDRTCjlv7U4GBAcyLU1EvaVEP0Ls8jhkSALzcfajjBctuqJnLdk2BZqeLZXlBt9zfxlOxc49ZsF1FMn0Ue2MqiXF19YkfZbyZtAR9sP13s">>,[{<<"code">>,<<"7e2b5472c14fe8164da5">>},{<<"state">>,<<"tJIPe64NL3SiXQZHVg18SFqDD6yOyfQ2IST3L6Y5I5KH0yXA6S7n5QWTCnfDRTCjlv7U4GBAcyLU1EvaVEP0Ls8jhkSALzcfajjBctuqJnLdk2BZqeLZXlBt9zfxlOxc49ZsF1FMn0Ue2MqiXF19YkfZbyZtAR9sP13s">>}],[],[{<<"host">>,<<"192.168.2.75:443">>},{<<"x-real-ip">>,<<"192.168.237.203">>},{<<"x-scheme">>,<<"https">>},{<<"x-forwarded-for">>,<<"192.168.237.203">>},{<<"x-forwarded-proto">>,<<"https">>},{<<"connection">>,<<"close">>},{<<"user-agent">>,<<"Mozilla/5.0 (X11; Linux x86_64; rv:47.0) Gecko/20100101 Firefox/47.0">>},{<<"accept">>,<<"text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8">>},{<<"accept-language">>,<<"en-US,en;q=0.5">>},{<<"accept-encoding">>,<<"gzip, deflate, br">>},{<<"referer">>,<<"https://github.com">>}],[{<<"if-modified-since">>,undefined},{<<"if-none-match">>,undefined},{<<"if-unmodified-since">>,undefined},{<<"if-match">>,undefined},{<<"accept">>,[{{<<"text">>,<<"html">>,[]},1000,[]},{{<<"application">>,<<"xhtml+xml">>,[]},1000,[]},{{<<"application">>,<<"xml">>,[]},900,[]},{{<<"*">>,<<"*">>,[]},800,[]}]},{<<"connection">>,[<<"close">>]}],undefined,[{media_type,{<<"application">>,<<"json">>,[]}},{charset,undefined}],waiting,<<>>,undefined,false,done,[],ok,undefined}],[{file,"src/cowboy_req.erl"},{line,815}]},{cowboy_rest,respond,3,[{file,"src/cowboy_rest.erl"},{line,993}]},{cowboy_rest,set_resp_body,2,[{file,"src/cowboy_rest.erl"},{line,869}]},{cowboy_protocol,execute,4,[{file,"src/cowboy_protocol.erl"},{line,435}]}]}
2

Should discussions like this go into https://feedback.chef.io/forums/289357-delivery-product-feedback or stay here?

3

Hello Hippiehacker,

This is a good place to have a discussion like this. Thank you for letting us know about your issues or doubts, we appreciate that.

The only thing I can see from the logs is that the OAuth you use is being in use already. Which I guess that is why you deleted the OAuth and created a new one, that is why you see two entries on the logs. (the two time you tried to configured) Let me ask you this questions;

  1. When you tried the second time, did you delete the OAuth Application in Delivery? (using the command: delivery-ctl delete-application github)
  2. When you ran the command delivery-ctl setup-github-token $DELIVERY_ENTERPRISE to generate a token. What happened when you followed the link?
  3. Is there any proxy between your environment and Github?

In order to debug this problem I would like you to try one more time with the logs opened without filter, just a simple delivery-ctl tail. Make sure to delete the Delivery Application and the Github OAuth completely. Post the logs on a gist and share it with us.

If this problem persist, I would be asking you to jump into a Zoom Meeting with me to troubleshoot this problem.

Salim Afiune