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

[Bug] HTTP lookup could return non-retryable error when connecting through proxy #343

Open
2 tasks done
BewareMyPower opened this issue Nov 13, 2023 · 0 comments
Open
2 tasks done

[Bug] HTTP lookup could return non-retryable error when connecting through proxy #343

BewareMyPower opened this issue Nov 13, 2023 · 0 comments

Comments

@BewareMyPower
Copy link
Contributor

Search before asking

  • I searched in the issues and found nothing similar.

Version

  • Pulsar: 3.1.0
  • Client: main (bb16f24)

Minimal reproduce step

Run the testMultiAddresses with a proxy.

export http_proxy=http://localhost:7890
./tests/pulsar-tests --gtest_filter='Look*Multi*'

What did you expect to see?

The test passed.

What did you see instead?

3-11-13 10:35:16.850 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:8080/lookup/v2/topic/persistent/public/default/topic
2023-11-13 10:35:16.863 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:8080/lookup/v2/topic/persistent/public/default/topic responseCode 200 curl res 0
2023-11-13 10:35:16.863 INFO  [0x16f0a3000] HTTPLookupService:336 | parseLookupData = { LookupDataResult [brokerUrl_ = pulsar://127.0.0.1:6650] [brokerUrlTls_ = ] [partitions = 0] [authoritative = 0] [redirect = 0] proxyThroughServiceUrl = 0] }
2023-11-13 10:35:16.863 INFO  [0x1ff929e00] LookupServiceTest:115 | getBroker [0] Ok, logical address: pulsar://127.0.0.1:6650, physical address: pulsar://127.0.0.1:6650
2023-11-13 10:35:16.863 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:9999/lookup/v2/topic/persistent/public/default/topic
2023-11-13 10:35:16.866 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:9999/lookup/v2/topic/persistent/public/default/topic responseCode 502 curl res 22
2023-11-13 10:35:16.866 ERROR [0x16f0a3000] HTTPLookupService:264 | Response failed for url http://localhost:9999/lookup/v2/topic/persistent/public/default/topic. Error Code 22
2023-11-13 10:35:16.866 INFO  [0x1ff929e00] LookupServiceTest:115 | getBroker [1] ConnectError, logical address: , physical address: 
2023-11-13 10:35:16.866 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:8080/lookup/v2/topic/persistent/public/default/topic
2023-11-13 10:35:16.871 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:8080/lookup/v2/topic/persistent/public/default/topic responseCode 200 curl res 0
2023-11-13 10:35:16.871 INFO  [0x16f0a3000] HTTPLookupService:336 | parseLookupData = { LookupDataResult [brokerUrl_ = pulsar://127.0.0.1:6650] [brokerUrlTls_ = ] [partitions = 0] [authoritative = 0] [redirect = 0] proxyThroughServiceUrl = 0] }
2023-11-13 10:35:16.872 INFO  [0x1ff929e00] LookupServiceTest:115 | getBroker [2] Ok, logical address: pulsar://127.0.0.1:6650, physical address: pulsar://127.0.0.1:6650
2023-11-13 10:35:16.872 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:9999/lookup/v2/topic/persistent/public/default/topic
2023-11-13 10:35:16.876 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:9999/lookup/v2/topic/persistent/public/default/topic responseCode 502 curl res 22
2023-11-13 10:35:16.876 ERROR [0x16f0a3000] HTTPLookupService:264 | Response failed for url http://localhost:9999/lookup/v2/topic/persistent/public/default/topic. Error Code 22
2023-11-13 10:35:16.876 INFO  [0x1ff929e00] LookupServiceTest:115 | getBroker [3] ConnectError, logical address: , physical address: 
2023-11-13 10:35:16.877 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:8080/lookup/v2/topic/persistent/public/default/topic
2023-11-13 10:35:16.880 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:8080/lookup/v2/topic/persistent/public/default/topic responseCode 200 curl res 0
2023-11-13 10:35:16.880 INFO  [0x16f0a3000] HTTPLookupService:336 | parseLookupData = { LookupDataResult [brokerUrl_ = pulsar://127.0.0.1:6650] [brokerUrlTls_ = ] [partitions = 0] [authoritative = 0] [redirect = 0] proxyThroughServiceUrl = 0] }
2023-11-13 10:35:16.880 INFO  [0x1ff929e00] LookupServiceTest:115 | getBroker [4] Ok, logical address: pulsar://127.0.0.1:6650, physical address: pulsar://127.0.0.1:6650
2023-11-13 10:35:16.880 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:9999/lookup/v2/topic/persistent/public/default/topic
2023-11-13 10:35:16.883 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:9999/lookup/v2/topic/persistent/public/default/topic responseCode 502 curl res 22
2023-11-13 10:35:16.883 ERROR [0x16f0a3000] HTTPLookupService:264 | Response failed for url http://localhost:9999/lookup/v2/topic/persistent/public/default/topic. Error Code 22
2023-11-13 10:35:16.883 INFO  [0x1ff929e00] LookupServiceTest:115 | getBroker [5] ConnectError, logical address: , physical address: 
/Users/xuyunze/github.com/bewaremypower/pulsar-client-cpp/tests/LookupServiceTest.cc:108: Failure
Expected equality of these values:
  std::count(results.cbegin(), results.cend(), ResultRetryable)
    Which is: 0
  numRequests / 2
    Which is: 3

2023-11-13 10:35:16.883 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:8080/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true
2023-11-13 10:35:16.886 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:8080/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true responseCode 200 curl res 0
2023-11-13 10:35:16.886 INFO  [0x16f0a3000] HTTPLookupService:301 | parsePartitionData = { LookupDataResult [brokerUrl_ = ] [brokerUrlTls_ = ] [partitions = 0] [authoritative = 0] [redirect = 0] proxyThroughServiceUrl = 0] }
2023-11-13 10:35:16.886 INFO  [0x1ff929e00] LookupServiceTest:124 | getPartitionMetadataAsync [0] Ok
2023-11-13 10:35:16.886 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:9999/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true
2023-11-13 10:35:16.893 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:9999/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true responseCode 502 curl res 22
2023-11-13 10:35:16.893 ERROR [0x16f0a3000] HTTPLookupService:264 | Response failed for url http://localhost:9999/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true. Error Code 22
2023-11-13 10:35:16.893 INFO  [0x1ff929e00] LookupServiceTest:124 | getPartitionMetadataAsync [1] ConnectError
2023-11-13 10:35:16.893 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:8080/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true
2023-11-13 10:35:16.896 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:8080/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true responseCode 200 curl res 0
2023-11-13 10:35:16.896 INFO  [0x16f0a3000] HTTPLookupService:301 | parsePartitionData = { LookupDataResult [brokerUrl_ = ] [brokerUrlTls_ = ] [partitions = 0] [authoritative = 0] [redirect = 0] proxyThroughServiceUrl = 0] }
2023-11-13 10:35:16.896 INFO  [0x1ff929e00] LookupServiceTest:124 | getPartitionMetadataAsync [2] Ok
2023-11-13 10:35:16.897 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:9999/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true
2023-11-13 10:35:16.899 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:9999/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true responseCode 502 curl res 22
2023-11-13 10:35:16.899 ERROR [0x16f0a3000] HTTPLookupService:264 | Response failed for url http://localhost:9999/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true. Error Code 22
2023-11-13 10:35:16.899 INFO  [0x1ff929e00] LookupServiceTest:124 | getPartitionMetadataAsync [3] ConnectError
2023-11-13 10:35:16.899 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:8080/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true
2023-11-13 10:35:16.903 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:8080/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true responseCode 200 curl res 0
2023-11-13 10:35:16.903 INFO  [0x16f0a3000] HTTPLookupService:301 | parsePartitionData = { LookupDataResult [brokerUrl_ = ] [brokerUrlTls_ = ] [partitions = 0] [authoritative = 0] [redirect = 0] proxyThroughServiceUrl = 0] }
2023-11-13 10:35:16.903 INFO  [0x1ff929e00] LookupServiceTest:124 | getPartitionMetadataAsync [4] Ok
2023-11-13 10:35:16.904 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:9999/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true
2023-11-13 10:35:16.907 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:9999/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true responseCode 502 curl res 22
2023-11-13 10:35:16.907 ERROR [0x16f0a3000] HTTPLookupService:264 | Response failed for url http://localhost:9999/admin/v2/persistent/public/default/topic/partitions?checkAllowAutoCreation=true. Error Code 22
2023-11-13 10:35:16.907 INFO  [0x1ff929e00] LookupServiceTest:124 | getPartitionMetadataAsync [5] ConnectError
/Users/xuyunze/github.com/bewaremypower/pulsar-client-cpp/tests/LookupServiceTest.cc:108: Failure
Expected equality of these values:
  std::count(results.cbegin(), results.cend(), ResultRetryable)
    Which is: 0
  numRequests / 2
    Which is: 3

2023-11-13 10:35:16.907 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:8080/admin/v2/namespaces/public/default/topics?mode=PERSISTENT
2023-11-13 10:35:16.917 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:8080/admin/v2/namespaces/public/default/topics?mode=PERSISTENT responseCode 200 curl res 0
2023-11-13 10:35:16.917 INFO  [0x1ff929e00] LookupServiceTest:136 | getTopicsOfNamespaceAsync [0] Ok
2023-11-13 10:35:16.917 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:9999/admin/v2/namespaces/public/default/topics?mode=PERSISTENT
2023-11-13 10:35:16.919 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:9999/admin/v2/namespaces/public/default/topics?mode=PERSISTENT responseCode 502 curl res 22
2023-11-13 10:35:16.919 ERROR [0x16f0a3000] HTTPLookupService:264 | Response failed for url http://localhost:9999/admin/v2/namespaces/public/default/topics?mode=PERSISTENT. Error Code 22
2023-11-13 10:35:16.919 INFO  [0x1ff929e00] LookupServiceTest:136 | getTopicsOfNamespaceAsync [1] ConnectError
2023-11-13 10:35:16.919 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:8080/admin/v2/namespaces/public/default/topics?mode=PERSISTENT
2023-11-13 10:35:16.928 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:8080/admin/v2/namespaces/public/default/topics?mode=PERSISTENT responseCode 200 curl res 0
2023-11-13 10:35:16.929 INFO  [0x1ff929e00] LookupServiceTest:136 | getTopicsOfNamespaceAsync [2] Ok
2023-11-13 10:35:16.929 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:9999/admin/v2/namespaces/public/default/topics?mode=PERSISTENT
2023-11-13 10:35:16.930 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:9999/admin/v2/namespaces/public/default/topics?mode=PERSISTENT responseCode 502 curl res 22
2023-11-13 10:35:16.931 ERROR [0x16f0a3000] HTTPLookupService:264 | Response failed for url http://localhost:9999/admin/v2/namespaces/public/default/topics?mode=PERSISTENT. Error Code 22
2023-11-13 10:35:16.931 INFO  [0x1ff929e00] LookupServiceTest:136 | getTopicsOfNamespaceAsync [3] ConnectError
2023-11-13 10:35:16.931 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:8080/admin/v2/namespaces/public/default/topics?mode=PERSISTENT
2023-11-13 10:35:16.936 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:8080/admin/v2/namespaces/public/default/topics?mode=PERSISTENT responseCode 200 curl res 0
2023-11-13 10:35:16.936 INFO  [0x1ff929e00] LookupServiceTest:136 | getTopicsOfNamespaceAsync [4] Ok
2023-11-13 10:35:16.936 INFO  [0x16f0a3000] HTTPLookupService:226 | Curl [1] Lookup Request sent for http://localhost:9999/admin/v2/namespaces/public/default/topics?mode=PERSISTENT
2023-11-13 10:35:16.938 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:9999/admin/v2/namespaces/public/default/topics?mode=PERSISTENT responseCode 502 curl res 22
2023-11-13 10:35:16.938 ERROR [0x16f0a3000] HTTPLookupService:264 | Response failed for url http://localhost:9999/admin/v2/namespaces/public/default/topics?mode=PERSISTENT. Error Code 22
2023-11-13 10:35:16.938 INFO  [0x1ff929e00] LookupServiceTest:136 | getTopicsOfNamespaceAsync [5] ConnectError
/Users/xuyunze/github.com/bewaremypower/pulsar-client-cpp/tests/LookupServiceTest.cc:108: Failure
Expected equality of these values:
  std::count(results.cbegin(), results.cend(), ResultRetryable)
    Which is: 0
  numRequests / 2
    Which is: 3

Anything else?

As you can see, the root cause is libcurl returns error code 22 when connecting through proxy.

2023-11-13 10:35:16.866 INFO  [0x16f0a3000] HTTPLookupService:242 | Response received for url http://localhost:9999/lookup/v2/topic/persistent/public/default/topic responseCode 502 curl res 22
2023-11-13 10:35:16.866 ERROR [0x16f0a3000] HTTPLookupService:264 | Response failed for url http://localhost:9999/lookup/v2/topic/persistent/public/default/topic. Error Code 22
2023-11-13 10:35:16.866 INFO  [0x1ff929e00] LookupServiceTest:115 | getBroker [1] ConnectError, logical address: , physical address:

The error code is 22

This is returned if CURLOPT_FAILONERROR is set TRUE and the HTTP server returns an error code that is >= 400.

See https://curl.se/libcurl/c/libcurl-errors.html

We should not treat it as non-retryable errors.

Are you willing to submit a PR?

  • I'm willing to submit a PR!
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@BewareMyPower