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.

Sign up for GitHub

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

Jump to bottom

OCPBUGS-14612: Improve logging for IPI deployments #3725

Merged
merged 1 commit into from Jun 9, 2023
Merged

OCPBUGS-14612: Improve logging for IPI deployments #3725

merged 1 commit into from Jun 9, 2023

Conversation

andreaskaris
Copy link
Contributor

@andreaskaris andreaskaris commented Jun 6, 2023 •
edited

- What I did

Improve logging format of KNI haproxy logs to display tcplogs + frondend IP and frontend port.

The current logging format is not very verbose:

<134>Jun  2 22:54:02 haproxy[11]: Connect from ::1:42424 to ::1:9445 (main/TCP)
<134>Jun  2 22:54:04 haproxy[11]: Connect from ::1:42436 to ::1:9445 (main/TCP)
<134>Jun  2 22:54:04 haproxy[11]: Connect from ::1:42446 to ::1:9445 (main/TCP)

It lacks critical information for troubleshooting, such as load-balancing destination and timestamps.
https://www.haproxy.com/blog/introduction-to-haproxy-logging recommends the following for tcp mode:

When in TCP mode, which is set by adding mode tcp, you should also add [option tcplog](https://www.haproxy.com/documentation/hapee/1-8r1/onepage/#option%20tcplog).

Because option tcplog actually loses information about the frontend IP and port that are being hit, I modified the logging format slightly to be:

log-format "%ci:%cp -> %fi:%fp [%t] %ft %b/%s %Tw/%Tc/%Tt %B %ts %ac/%fc/%bc/%sc/%rc %sq/%bq"

- How to verify it

Check the kni haproxy logs which will be more verbose now:

[akaris@workstation kubernetes (debug-apiserver-scc)]$ oc logs -n openshift-kni-infra                                haproxy-master-2 --tail=10
Defaulted container "haproxy" out of: haproxy, haproxy-monitor, verify-api-int-resolvable (init)
<134>Jun  6 13:09:44 haproxy[16]: ::ffff:192.168.111.1:37732 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:43.179] main masters/master-2 1/0/883 134324 -- 65/65/64/45/0 0/0
<134>Jun  6 13:09:49 haproxy[16]: ::1:38180 -> ::1:9445 [06/Jun/2023:13:09:49.279] main masters/master-0 1/0/3 3317 -- 65/65/64/16/0 0/0
<134>Jun  6 13:09:51 haproxy[16]: ::ffff:192.168.111.1:37734 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:50.478] main masters/master-2 1/0/1341 14630 -- 66/66/65/45/0 0/0
<134>Jun  6 13:09:51 haproxy[16]: ::ffff:192.168.111.1:37736 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:51.149] main masters/master-1 1/0/672 109397 -- 65/65/64/3/0 0/0
<134>Jun  6 13:09:55 haproxy[16]: ::1:40502 -> ::1:9445 [06/Jun/2023:13:09:55.301] main masters/master-0 1/0/3 3317 -- 65/65/64/16/0 0/0
<134>Jun  6 13:09:56 haproxy[16]: ::ffff:192.168.111.23:52916 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:56.595] main masters/master-2 1/0/3 2848 -- 66/66/65/45/0 0/0
<134>Jun  6 13:09:56 haproxy[16]: ::ffff:192.168.111.23:52924 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:56.595] main masters/master-1 1/0/3 2856 -- 65/65/64/3/0 0/0
<134>Jun  6 13:09:59 haproxy[16]: ::ffff:192.168.111.1:37738 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:58.001] main masters/master-0 1/0/1030 14630 -- 66/66/65/16/0 0/0
<134>Jun  6 13:09:59 haproxy[16]: ::ffff:192.168.111.1:37740 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:58.518] main masters/master-2 1/0/518 4493 -- 65/65/64/45/0 0/0
<134>Jun  6 13:10:01 haproxy[16]: ::1:40510 -> ::1:9445 [06/Jun/2023:13:10:01.319] main masters/master-1 1/0/4 3317 -- 65/65/64/3/0 0/0

- Description for the changelog

@openshift-ci openshift-ci bot requested review from bfournie and rvanderp3 June 6, 2023 11:30
@andreaskaris
Improve logging for KNI haproxy
cce43aa 
Improve logging format of KNI haproxy logs to display tcplogs plus
additional frondend IP and frontend port.

Signed-off-by: Andreas Karis <ak.karis@gmail.com>
@andreaskaris andreaskaris changed the title DNM: Test: Improve logging for IPI deployments Improve logging for IPI deployments Jun 6, 2023
@andreaskaris andreaskaris changed the title Improve logging for IPI deployments OCPBUGS-14612: Improve logging for IPI deployments Jun 6, 2023
@openshift-ci-robot openshift-ci-robot added the jira/valid-reference Indicates that this PR references a valid Jira ticket of any type. label Jun 6, 2023
@openshift-ci-robot
Copy link
Contributor

@andreaskaris: This pull request references Jira Issue OCPBUGS-14612, which is valid. The bug has been moved to the POST state.

3 validation(s) were run on this bug
  • bug is open, matching expected state (open)
  • bug target version (4.14.0) matches configured target version for branch (4.14.0)
  • bug is in the state New, which is one of the valid states (NEW, ASSIGNED, POST)

Requesting review from QA contact:
/cc @sergiordlr

The bug has been updated to refer to the pull request using the external bug tracker.

In response to this:

- What I did

Improve logging format of KNI haproxy logs to display tcplogs + frondend IP and frontend port.

The current logging format is not very verbose:

<134>Jun  2 22:54:02 haproxy[11]: Connect from ::1:42424 to ::1:9445 (main/TCP)
<134>Jun  2 22:54:04 haproxy[11]: Connect from ::1:42436 to ::1:9445 (main/TCP)
<134>Jun  2 22:54:04 haproxy[11]: Connect from ::1:42446 to ::1:9445 (main/TCP)

It lacks critical information for troubleshooting, such as load-balancing destination and timestamps.
https://www.haproxy.com/blog/introduction-to-haproxy-logging recommends the following for tcp mode:

When in TCP mode, which is set by adding mode tcp, you should also add [option tcplog](https://www.haproxy.com/documentation/hapee/1-8r1/onepage/#option%20tcplog).

Because option tcplog actually loses information about the frontend IP and port that are being hit, I modified the logging format slightly to be:

log-format "%ci:%cp -> %fi:%fp [%t] %ft %b/%s %Tw/%Tc/%Tt %B %ts %ac/%fc/%bc/%sc/%rc %sq/%bq"

- How to verify it

Check the kni haproxy logs which will be more verbose now:

[akaris@workstation kubernetes (debug-apiserver-scc)]$ oc logs -n openshift-kni-infra                                haproxy-master-2 --tail=10
Defaulted container "haproxy" out of: haproxy, haproxy-monitor, verify-api-int-resolvable (init)
<134>Jun  6 13:09:44 haproxy[16]: ::ffff:192.168.111.1:37732 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:43.179] main masters/master-2 1/0/883 134324 -- 65/65/64/45/0 0/0
<134>Jun  6 13:09:49 haproxy[16]: ::1:38180 -> ::1:9445 [06/Jun/2023:13:09:49.279] main masters/master-0 1/0/3 3317 -- 65/65/64/16/0 0/0
<134>Jun  6 13:09:51 haproxy[16]: ::ffff:192.168.111.1:37734 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:50.478] main masters/master-2 1/0/1341 14630 -- 66/66/65/45/0 0/0
<134>Jun  6 13:09:51 haproxy[16]: ::ffff:192.168.111.1:37736 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:51.149] main masters/master-1 1/0/672 109397 -- 65/65/64/3/0 0/0
<134>Jun  6 13:09:55 haproxy[16]: ::1:40502 -> ::1:9445 [06/Jun/2023:13:09:55.301] main masters/master-0 1/0/3 3317 -- 65/65/64/16/0 0/0
<134>Jun  6 13:09:56 haproxy[16]: ::ffff:192.168.111.23:52916 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:56.595] main masters/master-2 1/0/3 2848 -- 66/66/65/45/0 0/0
<134>Jun  6 13:09:56 haproxy[16]: ::ffff:192.168.111.23:52924 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:56.595] main masters/master-1 1/0/3 2856 -- 65/65/64/3/0 0/0
<134>Jun  6 13:09:59 haproxy[16]: ::ffff:192.168.111.1:37738 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:58.001] main masters/master-0 1/0/1030 14630 -- 66/66/65/16/0 0/0
<134>Jun  6 13:09:59 haproxy[16]: ::ffff:192.168.111.1:37740 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:58.518] main masters/master-2 1/0/518 4493 -- 65/65/64/45/0 0/0
<134>Jun  6 13:10:01 haproxy[16]: ::1:40510 -> ::1:9445 [06/Jun/2023:13:10:01.319] main masters/master-1 1/0/4 3317 -- 65/65/64/3/0 0/0

- Description for the changelog

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

@openshift-ci-robot openshift-ci-robot added the jira/valid-bug Indicates that a referenced Jira bug is valid for the branch this PR is targeting. label Jun 6, 2023
@openshift-ci openshift-ci bot requested a review from sergiordlr June 6, 2023 13:21
@cybertron
Copy link
Member

/lgtm

Big +1 from me. This looks like a nice improvement.

/assign @yuqi-zhang
per the bot's recommendation.

/retest-required
because this doesn't affect any of the failing jobs and the openstack job that does use it passed.

@openshift-ci openshift-ci bot added the lgtm Indicates that a PR is ready to be merged. label Jun 6, 2023
@cgwalters
Copy link
Member

/approve

@openshift-ci
Copy link
Contributor

openshift-ci bot commented Jun 6, 2023

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: andreaskaris, cgwalters, cybertron

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

@openshift-ci openshift-ci bot added the approved Indicates a PR has been approved by an approver from all required OWNERS files. label Jun 6, 2023
@openshift-ci-robot
Copy link
Contributor

/retest-required

Remaining retests: 0 against base HEAD dadba5b and 2 for PR HEAD cce43aa in total

@andreaskaris
Copy link
Contributor Author

/retest ci/prow/e2e-aws-ovn-upgrade

@openshift-ci
Copy link
Contributor

openshift-ci bot commented Jun 7, 2023

@andreaskaris: The /retest command does not accept any targets.
The following commands are available to trigger required jobs:

  • /test 4.12-upgrade-from-stable-4.11-images
  • /test cluster-bootimages
  • /test e2e-aws-ovn
  • /test e2e-aws-ovn-upgrade
  • /test e2e-gcp-op
  • /test e2e-hypershift
  • /test images
  • /test okd-scos-images
  • /test unit
  • /test verify

The following commands are available to trigger optional jobs:

  • /test 4.12-upgrade-from-stable-4.11-e2e-aws-ovn-upgrade
  • /test bootstrap-unit
  • /test e2e-alibabacloud-ovn
  • /test e2e-aws-disruptive
  • /test e2e-aws-ovn-fips
  • /test e2e-aws-ovn-fips-op
  • /test e2e-aws-ovn-workers-rhel8
  • /test e2e-aws-proxy
  • /test e2e-aws-serial
  • /test e2e-aws-single-node
  • /test e2e-aws-upgrade-single-node
  • /test e2e-aws-workers-rhel8
  • /test e2e-azure
  • /test e2e-azure-ovn-upgrade
  • /test e2e-azure-upgrade
  • /test e2e-gcp-op-single-node
  • /test e2e-gcp-ovn-rt-upgrade
  • /test e2e-gcp-rt
  • /test e2e-gcp-rt-op
  • /test e2e-gcp-single-node
  • /test e2e-gcp-upgrade
  • /test e2e-metal-assisted
  • /test e2e-metal-ipi
  • /test e2e-metal-ipi-ovn-dualstack
  • /test e2e-metal-ipi-ovn-ipv6
  • /test e2e-openstack
  • /test e2e-openstack-externallb
  • /test e2e-openstack-parallel
  • /test e2e-ovirt
  • /test e2e-ovirt-upgrade
  • /test e2e-ovn-step-registry
  • /test e2e-vsphere
  • /test e2e-vsphere-upgrade
  • /test e2e-vsphere-upi
  • /test e2e-vsphere-upi-zones
  • /test e2e-vsphere-zones
  • /test okd-e2e-aws
  • /test okd-e2e-gcp-op
  • /test okd-e2e-upgrade
  • /test okd-e2e-vsphere
  • /test okd-images
  • /test okd-scos-e2e-aws-ovn
  • /test okd-scos-e2e-gcp-op
  • /test okd-scos-e2e-gcp-ovn-upgrade
  • /test okd-scos-e2e-vsphere

Use /test all to run the following jobs that were automatically triggered:

  • pull-ci-openshift-machine-config-operator-master-bootstrap-unit
  • pull-ci-openshift-machine-config-operator-master-e2e-aws-ovn
  • pull-ci-openshift-machine-config-operator-master-e2e-aws-ovn-upgrade
  • pull-ci-openshift-machine-config-operator-master-e2e-gcp-op
  • pull-ci-openshift-machine-config-operator-master-e2e-hypershift
  • pull-ci-openshift-machine-config-operator-master-e2e-openstack
  • pull-ci-openshift-machine-config-operator-master-images
  • pull-ci-openshift-machine-config-operator-master-okd-images
  • pull-ci-openshift-machine-config-operator-master-okd-scos-e2e-aws-ovn
  • pull-ci-openshift-machine-config-operator-master-okd-scos-images
  • pull-ci-openshift-machine-config-operator-master-unit
  • pull-ci-openshift-machine-config-operator-master-verify

In response to this:

/retest ci/prow/e2e-aws-ovn-upgrade

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

@andreaskaris
Copy link
Contributor Author

/test e2e-aws-ovn-upgrade

@andreaskaris
Copy link
Contributor Author

/test e2e-hypershift

@andreaskaris
Copy link
Contributor Author

/retest

@openshift-ci-robot
Copy link
Contributor

/retest-required

Remaining retests: 0 against base HEAD dadba5b and 2 for PR HEAD cce43aa in total

@andreaskaris
Copy link
Contributor Author

/retest

@yuqi-zhang
Copy link
Contributor

The Hypershift test seems to be broken currently, I have raised it with the Hypershift team.

@openshift-ci-robot
Copy link
Contributor

/retest-required

Remaining retests: 0 against base HEAD 5c99674 and 1 for PR HEAD cce43aa in total

@andreaskaris
Copy link
Contributor Author

/retest

@openshift-ci-robot
Copy link
Contributor

/retest-required

Remaining retests: 0 against base HEAD c1a6a34 and 0 for PR HEAD cce43aa in total

@openshift-ci
Copy link
Contributor

openshift-ci bot commented Jun 9, 2023

@andreaskaris: The following tests failed, say /retest to rerun all failed tests or /retest-required to rerun all mandatory failed tests:

Test name Commit Details Required Rerun command
ci/prow/e2e-alibabacloud-ovn cce43aa link false /test e2e-alibabacloud-ovn
ci/prow/okd-scos-e2e-gcp-ovn-upgrade cce43aa link false /test okd-scos-e2e-gcp-ovn-upgrade
ci/prow/okd-scos-e2e-aws-ovn cce43aa link false /test okd-scos-e2e-aws-ovn

Full PR test history. Your PR dashboard.

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository. I understand the commands that are listed here.

@openshift-merge-robot openshift-merge-robot merged commit d19cd58 into openshift:master Jun 9, 2023
13 of 16 checks passed
@openshift-ci-robot
Copy link
Contributor

@andreaskaris: Jira Issue OCPBUGS-14612: All pull requests linked via external trackers have merged:

Jira Issue OCPBUGS-14612 has been moved to the MODIFIED state.

In response to this:

- What I did

Improve logging format of KNI haproxy logs to display tcplogs + frondend IP and frontend port.

The current logging format is not very verbose:

<134>Jun  2 22:54:02 haproxy[11]: Connect from ::1:42424 to ::1:9445 (main/TCP)
<134>Jun  2 22:54:04 haproxy[11]: Connect from ::1:42436 to ::1:9445 (main/TCP)
<134>Jun  2 22:54:04 haproxy[11]: Connect from ::1:42446 to ::1:9445 (main/TCP)

It lacks critical information for troubleshooting, such as load-balancing destination and timestamps.
https://www.haproxy.com/blog/introduction-to-haproxy-logging recommends the following for tcp mode:

When in TCP mode, which is set by adding mode tcp, you should also add [option tcplog](https://www.haproxy.com/documentation/hapee/1-8r1/onepage/#option%20tcplog).

Because option tcplog actually loses information about the frontend IP and port that are being hit, I modified the logging format slightly to be:

log-format "%ci:%cp -> %fi:%fp [%t] %ft %b/%s %Tw/%Tc/%Tt %B %ts %ac/%fc/%bc/%sc/%rc %sq/%bq"

- How to verify it

Check the kni haproxy logs which will be more verbose now:

[akaris@workstation kubernetes (debug-apiserver-scc)]$ oc logs -n openshift-kni-infra                                haproxy-master-2 --tail=10
Defaulted container "haproxy" out of: haproxy, haproxy-monitor, verify-api-int-resolvable (init)
<134>Jun  6 13:09:44 haproxy[16]: ::ffff:192.168.111.1:37732 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:43.179] main masters/master-2 1/0/883 134324 -- 65/65/64/45/0 0/0
<134>Jun  6 13:09:49 haproxy[16]: ::1:38180 -> ::1:9445 [06/Jun/2023:13:09:49.279] main masters/master-0 1/0/3 3317 -- 65/65/64/16/0 0/0
<134>Jun  6 13:09:51 haproxy[16]: ::ffff:192.168.111.1:37734 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:50.478] main masters/master-2 1/0/1341 14630 -- 66/66/65/45/0 0/0
<134>Jun  6 13:09:51 haproxy[16]: ::ffff:192.168.111.1:37736 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:51.149] main masters/master-1 1/0/672 109397 -- 65/65/64/3/0 0/0
<134>Jun  6 13:09:55 haproxy[16]: ::1:40502 -> ::1:9445 [06/Jun/2023:13:09:55.301] main masters/master-0 1/0/3 3317 -- 65/65/64/16/0 0/0
<134>Jun  6 13:09:56 haproxy[16]: ::ffff:192.168.111.23:52916 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:56.595] main masters/master-2 1/0/3 2848 -- 66/66/65/45/0 0/0
<134>Jun  6 13:09:56 haproxy[16]: ::ffff:192.168.111.23:52924 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:56.595] main masters/master-1 1/0/3 2856 -- 65/65/64/3/0 0/0
<134>Jun  6 13:09:59 haproxy[16]: ::ffff:192.168.111.1:37738 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:58.001] main masters/master-0 1/0/1030 14630 -- 66/66/65/16/0 0/0
<134>Jun  6 13:09:59 haproxy[16]: ::ffff:192.168.111.1:37740 -> ::ffff:192.168.111.22:9445 [06/Jun/2023:13:09:58.518] main masters/master-2 1/0/518 4493 -- 65/65/64/45/0 0/0
<134>Jun  6 13:10:01 haproxy[16]: ::1:40510 -> ::1:9445 [06/Jun/2023:13:10:01.319] main masters/master-1 1/0/4 3317 -- 65/65/64/3/0 0/0

- Description for the changelog

Instructions for interacting with me using PR comments are available here. If you have questions or suggestions related to my behavior, please file an issue against the kubernetes/test-infra repository.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@bfournie bfournie Awaiting requested review from bfournie

@rvanderp3 rvanderp3 Awaiting requested review from rvanderp3

@sergiordlr sergiordlr Awaiting requested review from sergiordlr

Assignees

@cybertron cybertron

@yuqi-zhang yuqi-zhang

Labels
approved Indicates a PR has been approved by an approver from all required OWNERS files. jira/valid-bug Indicates that a referenced Jira bug is valid for the branch this PR is targeting. jira/valid-reference Indicates that this PR references a valid Jira ticket of any type. lgtm Indicates that a PR is ready to be merged.
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.

None yet
6 participants
@andreaskaris @openshift-ci-robot @cybertron @cgwalters @yuqi-zhang @openshift-merge-robot