You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@pulsar.apache.org by GitBox <gi...@apache.org> on 2022/04/07 22:31:06 UTC

[GitHub] [pulsar] zbentley opened a new issue, #15078: [2.9.1] Python client returns UnknownError in some cases when it should return a specific error class

zbentley opened a new issue, #15078:
URL: https://github.com/apache/pulsar/issues/15078

   **Describe the bug**
   The Python client raises `_pulsar.UnknownError: Pulsar error: UnknownError` in cases when client logs indicate a specific exception code (for which there is already a specific error subclass) was recieved.
   
   
   **To Reproduce**
   0. Create a Client object with a Python logger that emits at INFO and above (e.g. `logging.getLogger()`).
   1. Create a persistent topic with a backlog policy that is very "short", e.g. 1mb.
   2. With a Python producer, send messages to the topic continually until the backlog quota is hit.
   3. Observe that the Python producer errors with an UnknownError rather than ProducerBlockedQuotaExceededException.
   4. Observe that the client logs show the arrival of a ProducerBlockedQuotaExceededException event.
   5. Attempt to re-create the producer on the quota-blocked topic.
   6. Observe that the same issue occurs: logs indicate ProducerBlockedQuotaExceededException, but an UnknownError is raised.
   
   **Expected behavior**
   Specific error classes (the exception classes distributed in the pulsar-client package) should be raised instead of UnknownError when the client can match an error event (visible in the logs) to an exception class: ProducerBlockedQuotaExceededException
   
   I suspect the issue is with the boost-python mapping code; I don't think class-type checks are matching correctly on C++ exception objects.
   
   **Example logs**:
   ```
   chariot.chariot.pulsar_client::75192::Dummy-8::WARNING 2022-04-07 18:06:35,902 [127.0.0.1:58048 -> 127.0.0.1:6650] Received error response from server: ProducerBlockedQuotaExceededException (Cannot create producer on topic with backlog quota exceeded) -- req_id: 0
   chariot.chariot.pulsar_client::75192::Dummy-8::ERROR 2022-04-07 18:06:35,902 [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-0, SynchronousChariotProducer-heartbeat-1-ZacBentleyMBP-75192] Failed to create producer: ProducerBlockedQuotaExceededException
   chariot.chariot.pulsar_client::75192::Dummy-8::ERROR 2022-04-07 18:06:35,902 Unable to create Producer for partition - 0 Error - ProducerBlockedQuotaExceededException
   ```
   
   **Example stacktrace which accompanies those logs:**
   ```
   Traceback (most recent call last):
     File "/Users/zac.bentley/Desktop/Projects/Klaviyo/chariot/.venv/lib/python3.7/site-packages/pulsar/__init__.py", line 603, in create_producer
       p._producer = self._client.create_producer(topic, conf)
   _pulsar.UnknownError: Pulsar error: UnknownError
   ```
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


[GitHub] [pulsar] BewareMyPower commented on issue #15078: [2.9.1] Python client returns UnknownError in some cases when it should return a specific error class

Posted by GitBox <gi...@apache.org>.
BewareMyPower commented on issue #15078:
URL: https://github.com/apache/pulsar/issues/15078#issuecomment-1094273716

   Oh, it looks like a bug for partitioned topics. Could you try with a non-partitioned topic?


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


[GitHub] [pulsar] BewareMyPower closed issue #15078: [2.9.1] With partitioned topics, the Python client returns UnknownError in some cases when it should return a specific error class

Posted by GitBox <gi...@apache.org>.
BewareMyPower closed issue #15078: [2.9.1] With partitioned topics, the Python client returns UnknownError in some cases when it should return a specific error class
URL: https://github.com/apache/pulsar/issues/15078


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


[GitHub] [pulsar] BewareMyPower commented on issue #15078: [2.9.1] Python client returns UnknownError in some cases when it should return a specific error class

Posted by GitBox <gi...@apache.org>.
BewareMyPower commented on issue #15078:
URL: https://github.com/apache/pulsar/issues/15078#issuecomment-1094294397

   Okay, I'll verify this issue tomorrow.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


[GitHub] [pulsar] BewareMyPower commented on issue #15078: [2.9.1] With partitioned topics, the Python client returns UnknownError in some cases when it should return a specific error class

Posted by GitBox <gi...@apache.org>.
BewareMyPower commented on issue #15078:
URL: https://github.com/apache/pulsar/issues/15078#issuecomment-1094705415

   I also reproduced this bug for a partitioned topic.
   
   ```
   2022-04-11 16:29:20.714 INFO  [0x70000f276000] ProducerImpl:189 | [persistent://public/default/my-topic-partition-0, ] Created producer on broker [127.0.0.1:64964 -> 127.0.0.1:6650] 
   2022-04-11 16:29:20.714 INFO  [0x70000f276000] ProducerImpl:662 | [persistent://public/default/my-topic-partition-0, standalone-0-7] Closing producer for topic persistent://public/default/my-topic-partition-0
   2022-04-11 16:29:20.714 INFO  [0x70000f276000] ProducerImpl:662 | [persistent://public/default/my-topic-partition-1, ] Closing producer for topic persistent://public/default/my-topic-partition-1
   2022-04-11 16:29:20.714 INFO  [0x70000f276000] ProducerImpl:662 | [persistent://public/default/my-topic-partition-2, ] Closing producer for topic persistent://public/default/my-topic-partition-2
   2022-04-11 16:29:20.714 ERROR [0x70000f276000] PartitionedProducerImpl:151 | Unable to create Producer for partition - 0 Error - ProducerBlockedQuotaExceededException
   2022-04-11 16:29:20.714 ERROR [0x11352f600] SampleProducer:35 | Error creating producer: UnknownError
   ```
   
   I will fix this issue soon.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


[GitHub] [pulsar] zbentley commented on issue #15078: [2.9.1] Python client returns UnknownError in some cases when it should return a specific error class

Posted by GitBox <gi...@apache.org>.
zbentley commented on issue #15078:
URL: https://github.com/apache/pulsar/issues/15078#issuecomment-1094282171

   A topic with a single partition returns the below output; unsure if that's the same as a nonpartitioned topic:
   ```
   2022-04-10 10:03:20.907 INFO  [0x10cec3600] ClientConnection:181 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-04-10 10:03:20.907 INFO  [0x10cec3600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-04-10 10:03:20.909 INFO  [0x700005637000] ClientConnection:367 | [127.0.0.1:54061 -> 127.0.0.1:6650] Connected to broker
   2022-04-10 10:03:20.910 INFO  [0x700005637000] HandlerBase:64 | [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-0, ] Getting connection from pool
   2022-04-10 10:03:20.911 WARN  [0x700005637000] ClientConnection:1052 | [127.0.0.1:54061 -> 127.0.0.1:6650] Received error response from server: ProducerBlockedQuotaExceededException (Cannot create producer on topic with backlog quota exceeded) -- req_id: 0
   2022-04-10 10:03:20.911 ERROR [0x700005637000] ProducerImpl:248 | [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-0, ] Failed to create producer: ProducerBlockedQuotaExceededException
   2022-04-10 10:03:20.911 INFO  [0x700005637000] ProducerImpl:621 | [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-0, ] Closing producer for topic persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-0
   2022-04-10 10:03:20.911 ERROR [0x700005637000] PartitionedProducerImpl:152 | Unable to create Producer for partition - 0 Error - ProducerBlockedQuotaExceededException
   2022-04-10 10:03:20.911 INFO  [0x700005637000] ProducerImpl:590 | Producer - [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-0, ] , [batching  = off]
   Traceback (most recent call last):
     File "scratch.py", line 5, in <module>
       producer = client.create_producer('persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat')
     File "/Users/zac.bentley/Desktop/Projects/Klaviyo/chariot/.venv/lib/python3.7/site-packages/pulsar/__init__.py", line 603, in create_producer
       p._producer = self._client.create_producer(topic, conf)
   _pulsar.UnknownError: Pulsar error: UnknownError
   2022-04-10 10:03:20.913 INFO  [0x10cec3600] ClientConnection:1535 | [127.0.0.1:54061 -> 127.0.0.1:6650] Connection closed
   ```


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


[GitHub] [pulsar] zbentley commented on issue #15078: [2.9.1] Python client returns UnknownError in some cases when it should return a specific error class

Posted by GitBox <gi...@apache.org>.
zbentley commented on issue #15078:
URL: https://github.com/apache/pulsar/issues/15078#issuecomment-1094274391

   I'm working on reproducing on non-partitioned now (focus is split, sorry, results will be here inside the hour). I'm on MacOS, broker 2.9.1 via homebrew, client 2.9.1 via pip, python 3.7.12.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


[GitHub] [pulsar] BewareMyPower commented on issue #15078: [2.9.1] Python client returns UnknownError in some cases when it should return a specific error class

Posted by GitBox <gi...@apache.org>.
BewareMyPower commented on issue #15078:
URL: https://github.com/apache/pulsar/issues/15078#issuecomment-1092559338

   It looks like it works well in my env (macOS, Python 3.9, latest code from master branch).
   
   ```
   2022-04-08 15:48:43.972 INFO  [0x1191ad600] ClientConnection:189 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-04-08 15:48:43.972 INFO  [0x1191ad600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-04-08 15:48:43.977 WARN  [0x70000bfd7000] ClientConnection:436 | [<none> -> pulsar://localhost:6650] Failed to establish connection: Connection refused
   2022-04-08 15:48:43.977 INFO  [0x70000bfd7000] ClientConnection:375 | [127.0.0.1:62856 -> 127.0.0.1:6650] Connected to broker
   2022-04-08 15:48:43.986 INFO  [0x70000bfd7000] HandlerBase:64 | [persistent://public/default/topic1, ] Getting connection from pool
   2022-04-08 15:48:44.132 INFO  [0x70000bfd7000] ProducerImpl:189 | [persistent://public/default/topic1, ] Created producer on broker [127.0.0.1:62856 -> 127.0.0.1:6650] 
   2022-04-08 15:48:44.132 ERROR [0x70000bfd7000] ProducerImpl:220 | [persistent://public/default/topic1, standalone-0-2] XYZ Failed to create producer: ProducerBlockedQuotaExceededException
   2022-04-08 15:48:44.133 INFO  [0x70000bfd7000] ProducerImpl:635 | Producer - [persistent://public/default/topic1, standalone-0-2] , [batching  = off]
   Traceback (most recent call last):
     File "/pulsar/pulsar-client-cpp/python/2.py", line 25, in <module>
       producer = client.create_producer('topic1')
     File "/pulsar/pulsar-client-cpp/python/pulsar/__init__.py", line 603, in create_producer
       p._producer = self._client.create_producer(topic, conf)
   _pulsar.ProducerBlockedQuotaExceededException: Pulsar error: ProducerBlockedQuotaExceededException
   2022-04-08 15:48:44.136 INFO  [0x1191ad600] ClientConnection:1560 | [127.0.0.1:62856 -> 127.0.0.1:6650] Connection closed
   2022-04-08 15:48:44.136 INFO  [0x1191ad600] ClientConnection:263 | [127.0.0.1:62856 -> 127.0.0.1:6650] Destroyed connection
   ```
   
   I modified the C++ code to make producer creation always fail.
   
   ```diff
   diff --git a/pulsar-client-cpp/lib/ProducerImpl.cc b/pulsar-client-cpp/lib/ProducerImpl.cc
   index a539889ac00..37bd979435d 100644
   --- a/pulsar-client-cpp/lib/ProducerImpl.cc
   +++ b/pulsar-client-cpp/lib/ProducerImpl.cc
   @@ -215,8 +215,13 @@ void ProducerImpl::handleCreateProducer(const ClientConnectionPtr& cnx, Result r
                startSendTimeoutTimer();
            }
    
   -        producerCreatedPromise_.setValue(shared_from_this());
   -
   +        // producerCreatedPromise_.setValue(shared_from_this());
   +        LOG_ERROR(getName() << "XYZ Failed to create producer: "
   +                            << ResultProducerBlockedQuotaExceededException);
   +        failPendingMessages(ResultProducerBlockedQuotaExceededException, true);
   +        producerCreatedPromise_.setFailed(ResultProducerBlockedQuotaExceededException);
   +        Lock lock(mutex_);
   +        state_ = Failed;
        } else {
            lock.unlock();
   ```
   
   The Python script is
   
   ```python
   import pulsar
   
   client = pulsar.Client(service_url='pulsar://localhost:6650')
   
   producer = client.create_producer('topic1')
   producer.send("hello".encode())
   
   client.close()
   ```


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


[GitHub] [pulsar] BewareMyPower commented on issue #15078: [2.9.1] Python client returns UnknownError in some cases when it should return a specific error class

Posted by GitBox <gi...@apache.org>.
BewareMyPower commented on issue #15078:
URL: https://github.com/apache/pulsar/issues/15078#issuecomment-1094274252

   If you can still reproduce this bug on a non-partitioned topic, could you give your OS version? I'll try to reproduce the bug on Ubuntu 18.04 and the Python client 2.9.1 installed by `pip3 install` on workdays.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


[GitHub] [pulsar] zbentley commented on issue #15078: [2.9.1] Python client returns UnknownError in some cases when it should return a specific error class

Posted by GitBox <gi...@apache.org>.
zbentley commented on issue #15078:
URL: https://github.com/apache/pulsar/issues/15078#issuecomment-1094339400

   When I create a truly non-partitioned topic, the behavior is correct (I get a `ResultProducerBlockedQuotaExceededException` on the client). So this bug only happens for partitioned topics. I'll update the title accordingly.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


[GitHub] [pulsar] zbentley commented on issue #15078: [2.9.1] Python client returns UnknownError in some cases when it should return a specific error class

Posted by GitBox <gi...@apache.org>.
zbentley commented on issue #15078:
URL: https://github.com/apache/pulsar/issues/15078#issuecomment-1094272476

   I can reproduce with that exact snippet, substituting only my topic name. 
   
   The topic is:
   - Persistent
   - Partitioned
   - Has two subscriptions, both behind
   - Does not have any consumers active
   - Uses BytesSchema
   - Is the only topic in its namespace
   - Does not have compaction or dedup enabled.
   
   When I run the above snippet with my topic name and a backlog that's over quota I get:
   
   ```
   2022-04-10 09:07:03.039 INFO  [0x105619600] ClientConnection:181 | [<none> -> pulsar://localhost:6650] Create ClientConnection, timeout=10000
   2022-04-10 09:07:03.039 INFO  [0x105619600] ConnectionPool:96 | Created connection for pulsar://localhost:6650
   2022-04-10 09:07:03.041 INFO  [0x70000451e000] ClientConnection:367 | [127.0.0.1:52487 -> 127.0.0.1:6650] Connected to broker
   2022-04-10 09:07:03.043 INFO  [0x70000451e000] HandlerBase:64 | [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-0, ] Getting connection from pool
   2022-04-10 09:07:03.043 INFO  [0x70000451e000] HandlerBase:64 | [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-1, ] Getting connection from pool
   2022-04-10 09:07:03.043 INFO  [0x70000451e000] HandlerBase:64 | [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-2, ] Getting connection from pool
   2022-04-10 09:07:03.043 INFO  [0x70000451e000] HandlerBase:64 | [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-3, ] Getting connection from pool
   2022-04-10 09:07:03.045 WARN  [0x70000451e000] ClientConnection:1052 | [127.0.0.1:52487 -> 127.0.0.1:6650] Received error response from server: ProducerBlockedQuotaExceededException (Cannot create producer on topic with backlog quota exceeded) -- req_id: 0
   2022-04-10 09:07:03.045 ERROR [0x70000451e000] ProducerImpl:248 | [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-0, ] Failed to create producer: ProducerBlockedQuotaExceededException
   2022-04-10 09:07:03.045 INFO  [0x70000451e000] ProducerImpl:621 | [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-0, ] Closing producer for topic persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-0
   2022-04-10 09:07:03.045 INFO  [0x70000451e000] ProducerImpl:621 | [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-1, ] Closing producer for topic persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-1
   2022-04-10 09:07:03.045 INFO  [0x70000451e000] ProducerImpl:621 | [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-2, ] Closing producer for topic persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-2
   2022-04-10 09:07:03.045 INFO  [0x70000451e000] ProducerImpl:621 | [persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-3, ] Closing producer for topic persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat-partition-3
   2022-04-10 09:07:03.045 ERROR [0x70000451e000] PartitionedProducerImpl:152 | Unable to create Producer for partition - 0 Error - ProducerBlockedQuotaExceededException
   Traceback (most recent call last):
     File "scratch.py", line 8, in <module>
   2022-04-10 09:07:03.045 WARN  [0x70000451e000] ClientConnection:1052 | [127.0.0.1:52487 -> 127.0.0.1:6650] Received error response from server: ProducerBlockedQuotaExceededException (Cannot create producer on topic with backlog quota exceeded) -- req_id: 1
       producer = client.create_producer('persistent://chariot1/chariot_namespace_heartbeat/chariot_topic_heartbeat')
     File "/Users/zac.bentley/Desktop/Projects/Klaviyo/chariot/.venv/lib/python3.7/site-packages/pulsar/__init__.py", line 603, in create_producer
   2022-04-10 09:07:03.045 WARN  [0x70000451e000] ClientConnection:1052 | [127.0.0.1:52487 -> 127.0.0.1:6650] Received error response from server: ProducerBlockedQuotaExceededException (Cannot create producer on topic with backlog quota exceeded) -- req_id: 2
       p._producer = self._client.create_producer(topic, conf)
   _pulsar.UnknownError: Pulsar error: UnknownError
   2022-04-10 09:07:03.046 WARN  [0x70000451e000] ClientConnection:1052 | [127.0.0.1:52487 -> 127.0.0.1:6650] Received error response from server: ProducerBlockedQuotaExceededException (Cannot create producer on topic with backlog quota exceeded) -- req_id: 3
   ```


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: commits-unsubscribe@pulsar.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org