Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve log tracing by sending 'X-VMWARE-VCLOUD-CLIENT-REQUEST-ID' header #656

Merged
merged 13 commits into from
Apr 26, 2024

Conversation

Didainius
Copy link
Collaborator

@Didainius Didainius commented Mar 22, 2024

This PR improves log traceability using VCD built-in functionality.

About the functionality itself

Whenever an HTTP client sends header X-Vmware-Vcloud-Client-Request-Id with a request, the response will have header X-Vmware-Vcloud-Request-Id that has a prefix (up to 128 chars) of what was sent to X-Vmware-Vcloud-Client-Request-Id and additionally a suffix of hypen and UUIDv4.

More about this in VCD docs: https://vdc-download.vmware.com/vmwb-repository/dcr-public/6ac8164c-8844-4188-ac1b-cd59721c06b8/7d36e490-310e-4485-91cc-c3abb23b0d32/GUID-0EAF1523-CA02-41FC-A7F3-B103108F5E4A.html

This is very useful for troubleshooting logs (especially when a lot of things are going in parallel like in the case of Terraform provider). It makes it easy to always find response to a particular request by simply searching of the part being sent.

X-Vmware-Vcloud-Client-Request-Id: [1-2024-04-13-01-58-25-733-]
X-Vmware-Vcloud-Request-Id: [1-2024-04-13-01-58-25-733--1a4df440-bf75-4317-b6a1-f0df2c9602a7]

Features in this PR

This PR adds infrastructure to send X-Vmware-Vcloud-Client-Request-Id header and also a function VcloudRequestIdBuilderFunc that can create X-Vmware-Vcloud-Client-Request-Id headers in such format {sequence-number}-{date-time-hyphen-separated}-. The sequence number is an uint64 that can support values up to 1844674407370955161518446744073709551615. The advantage of a sequence number is that it can help to understand order of requests going (and provide some sort of stats of total API requests made in the life of a program).

Longer example:

2024/03/22 13:46:56 --------------------------------------------------------------------------------
2024/03/22 13:46:56 Request caller: govcd.(*VCDClient).GetAdminOrgByName-->govcd.(*VCDClient).GetAdminOrgByName-->govcd.(*Client).executeRequest-->govcd.executeRequestWithApiVersion-->govcd.executeRequestCustomErr-->govcd.(*Client).NewRequestWithApiVersion-->govcd.executeRequestCustomErr-->govcd.(*Client).newRequest
2024/03/22 13:46:56 GET https://HOST/api/admin/org/087a027e-f3c0-4fc8-8184-d1cc691ec254
2024/03/22 13:46:56 --------------------------------------------------------------------------------
2024/03/22 13:46:56 Req header:
2024/03/22 13:46:56 	X-Vmware-Vcloud-Token-Type: [Bearer]
2024/03/22 13:46:56 	Authorization: [********]
2024/03/22 13:46:56 	User-Agent: [terraform-provider-vcd/test (darwin/arm64; isProvider:true)]
2024/03/22 13:46:56 	X-Vmware-Vcloud-Client-Request-Id: [1-2024-04-13-01-58-25-733-]  <---- Request being sent. Sequence number 1 followed by UUID
.......
################################################################################
2024/03/22 13:46:57 Response caller vcd.resourceVcdNsxtIpSetCreate-->vcd.resourceVcdNsxtIpSetRead-->vcd.(*VCDClient).GetAdminOrgFromResource-->vcd.(*VCDClient).GetAdminOrg-->govcd.(*VCDClient).GetAdminOrgByName-->govcd.(*VCDClient).GetAdminOrgByName-->govcd.(*Client).executeRequest-->govcd.decodeBody
2024/03/22 13:46:57 Response status 200 OK
2024/03/22 13:46:57 ################################################################################
2024/03/22 13:46:57 Response header:
2024/03/22 13:46:57 	X-Vmware-Vcloud-Request-Id: [1-2024-04-13-01-58-25-733--1a4df440-bf75-4317-b6a1-f0df2c9602a7] <---- Response that is prefixed by all the data that was sent in request X-Vmware-Vcloud-Client-Request-Id
2024/03/22 13:46:57 	Cache-Control: [no-store, must-revalidate]
2024/03/22 13:46:57 	Date: [Fri, 22 Mar 2024 11:46:57 GMT]
2024/03/22 13:46:57 	X-Vmware-Vcloud-Ceip-Id: [463fac1b-382b-4117-a7ca-ebd5c20a1595]
2024/03/22 13:46:57 	Content-Type: [application/vnd.vmware.admin.organization+xml;version=37.0]
2024/03/22 13:46:57 	X-Vmware-Vcloud-Request-Execution-Time: [432]
2024/03/22 13:46:57 	Vary: [Accept-Encoding]
2024/03/22 13:46:57 Response text: [72504]
<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<AdminOrg xmlns="http://www.vmware.com/vcloud/v1.5" xmlns:vmext="http://www.vmware.com/vcloud/extension/v1.5" xmlns:ovf="http://schemas.dmtf.org/ovf/envelope/1" xmlns:vssd="http://schemas.dmtf.org/wbem/wscim/1/cim-schema/2/CIM_VirtualSystemSettingData" xmlns:common="http://schemas.dmtf.org/wbem/wscim/1/common" xmlns:rasd="http://schemas.dmtf.org/wbem/wscim/1/cim-schema/2/CIM_ResourceAllocationSettingData" xmlns:vmw="http://www.vmware.com/schema/ovf" xmlns:ovfenv="http://schemas.dmtf.org/ovf/environment/1" xmlns:ns9="http://www.vmware.com/vcloud/versions" name="dserplis" id="urn:vcloud:org:087a027e-f3c0-4fc8-8184-d1cc691ec254" href="https://HOST/api/admin/org/087a027e-f3c0-4fc8-8184-d1cc691ec254" type="application/vnd.vmware.admin.organization+xml">
    <Link rel="down" href="https://HOST/api/query?type=adminOrgVdc&amp;filter=org%3D%3D087a027e-f3c0-4fc8-8184-d1cc691ec254" type="application/vnd.vmware.vcloud.query.records+xml"/>
   ....

A few inaccuracies are also fixed (both have comments inline):

  • There was duplicate call to setHttpUserAgent in request manipulation functions
  • There was a missing logging for response function

Signed-off-by: Dainius Serplis <dserplis@vmware.com>
@Didainius Didainius changed the title WIP - Improve log tracing by optionally sending 'X-VMWARE-VCLOUD-CLIENT-REQUEST-ID' header Improve log tracing by optionally sending 'X-VMWARE-VCLOUD-CLIENT-REQUEST-ID' header Mar 22, 2024
Signed-off-by: Dainius Serplis <dserplis@vmware.com>
Signed-off-by: Dainius Serplis <dserplis@vmware.com>
Signed-off-by: Dainius Serplis <dserplis@vmware.com>
@Didainius Didainius force-pushed the request-id branch 3 times, most recently from 14cfb86 to f3383e8 Compare March 28, 2024 06:25
Signed-off-by: Dainius Serplis <dserplis@vmware.com>
Signed-off-by: Dainius Serplis <dserplis@vmware.com>
Signed-off-by: Dainius Serplis <dserplis@vmware.com>
Signed-off-by: Dainius Serplis <dserplis@vmware.com>
Signed-off-by: Dainius Serplis <dserplis@vmware.com>
@Didainius Didainius marked this pull request as ready for review April 9, 2024 12:12
@Didainius Didainius changed the title Improve log tracing by optionally sending 'X-VMWARE-VCLOUD-CLIENT-REQUEST-ID' header Improve log tracing by sending 'X-VMWARE-VCLOUD-CLIENT-REQUEST-ID' header Apr 9, 2024
Copy link
Contributor

@dataclouder dataclouder left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Some minor issues in comments

Signed-off-by: Dainius Serplis <dserplis@vmware.com>
Signed-off-by: Dainius Serplis <dserplis@vmware.com>
Signed-off-by: Dainius Serplis <dserplis@vmware.com>
Copy link
Collaborator

@lvirbalas lvirbalas left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is great!

@Didainius Didainius merged commit 1b9648b into vmware:main Apr 26, 2024
2 checks passed
@Didainius Didainius deleted the request-id branch April 26, 2024 06:08
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

5 participants