apache / apache/pulsar-client-cpp

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

Open
#343 0 comments 0 reactions 0 assignees View on GitHub
Dominant language
C++
Stars
71
Forks
90
Avg merge
2h 33m
Merged PRs (30d)
3

Description

### Search before asking

- [X] I searched in the [issues](https://github.com/apache/pulsar-client-cpp/issues) and found nothing similar.

### Version

- Pulsar: 3.1.0
- Client: main (https://github.com/apache/pulsar-client-cpp/commit/bb16f24bb68699c15eddba3163cfbef0b1282ebf)

### Minimal reproduce step

Run the `testMultiAddresses` with a proxy.

```bash
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](https://curl.se/libcurl/c/CURLOPT_FAILONERROR.html) 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?

- [X] I'm willing to submit a PR!

Contributor guide

Open the contributing guide

Research direction

Start with tests/LookupServiceTest.cc, especially testMultiAddresses and the assertions around ResultRetryable. Reproduce the failure with the shown http_proxy setting and gtest filter, then trace the HTTP lookup response handling reported by HTTPLookupService. Done means proxy failures receive the expected retryable result while successful lookups continue to pass.

Written by the indexing model from the issue text.

Assessment

Tech stack
cpp
Domain
api, backend, testing
Issue type
Bug
Difficulty
3/5
Estimated time
1-2 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
42/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.