dragonls opened a new issue, #16852: URL: https://github.com/apache/pulsar/issues/16852
**Describe the bug** While consumer subscribing on topic, it failed with `TimeOut` error.  The log above is using python client 2.7.4 to connect Pulsar. At the mean time, the broker shows the error log `java.lang.IllegalStateException: Recursion depth became negative: -1`  **To Reproduce** No clear way to reproduce yet. **Expected behavior** The consumer should subscribe successfully. **Desktop (please complete the following information):** - OS: Linux - Pulsar broker version: 2.8.3 - Pulsar client version: 2.7.4 **Additional context** I read the python and C++ code about the behavior of pulsar client, the client has already connected to the broker, but do not get the result of `newSubscribe` cmd, which results in the `TimeOut` error. It seems that broker get the `java.lang.IllegalStateException: Recursion depth became negative: -1` error while the logger print some log. Let's see the broker server log screenshot, it is caused by `org.apache.pulsar.broker.service.ServerCnx.lambda$handleSubscribe$16(ServerCnx.java:961)`, just code printing the log. https://github.com/apache/pulsar/blob/ee87c7d6c20186ae59298a9a9ec1fdb2b09954c7/pulsar-broker/src/main/java/org/apache/pulsar/broker/service/ServerCnx.java#L954-L968 The log4j2 config file `log4j2.yaml`: ```yaml Configuration: status: INFO monitorInterval: 30 name: pulsar packages: io.prometheus.client.log4j2 Properties: Property: - name: "pulsar.log.dir" value: "logs" - name: "pulsar.log.file" value: "pulsar.log" - name: "pulsar.log.appender" value: "RoutingAppender" - name: "pulsar.log.root.level" value: "info" - name: "pulsar.log.level" value: "info" - name: "pulsar.routing.appender.default" value: "Console" Appenders: # Console Console: name: Console target: SYSTEM_OUT PatternLayout: Pattern: "%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n" # Rolling file appender configuration RollingFile: name: RollingFile fileName: "${sys:pulsar.log.dir}/${sys:pulsar.log.file}" filePattern: "${sys:pulsar.log.dir}/${sys:pulsar.log.file}-%d{MM-dd-yyyy}-%i.log.gz" immediateFlush: false PatternLayout: Pattern: "%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n" Policies: TimeBasedTriggeringPolicy: interval: 1 modulate: true SizeBasedTriggeringPolicy: size: 1 GB # Delete file older than 30days DefaultRolloverStrategy: Delete: basePath: ${sys:pulsar.log.dir} maxDepth: 2 IfFileName: glob: "*/${sys:pulsar.log.file}*log.gz" IfLastModified: age: 30d Prometheus: name: Prometheus # Routing Routing: name: RoutingAppender Routes: pattern: "$${ctx:function}" Route: - Routing: name: InstanceRoutingAppender Routes: pattern: "$${ctx:instance}" Route: - RollingFile: name: "Rolling-${ctx:function}" fileName : "${sys:pulsar.log.dir}/functions/${ctx:function}/${ctx:functionname}-${ctx:instance}.log" filePattern : "${sys:pulsar.log.dir}/functions/${sys:pulsar.log.file}-${ctx:instance}-%d{MM-dd-yyyy}-%i.log.gz" PatternLayout: Pattern: "%d{ABSOLUTE} %level{length=5} [%thread] [instance: %X{instance}] %logger{1} - %msg%n" Policies: TimeBasedTriggeringPolicy: interval: 1 modulate: true SizeBasedTriggeringPolicy: size: "20MB" # Trigger every day at midnight that also scan # roll-over strategy that deletes older file CronTriggeringPolicy: schedule: "0 0 0 * * ?" # Delete file older than 30days DefaultRolloverStrategy: Delete: basePath: ${sys:pulsar.log.dir} maxDepth: 2 IfFileName: glob: "*/${sys:pulsar.log.file}*log.gz" IfLastModified: age: 30d - ref: "${sys:pulsar.routing.appender.default}" key: "${ctx:function}" - ref: "${sys:pulsar.routing.appender.default}" key: "${ctx:function}" Loggers: # Default root logger configuration Root: level: "${sys:pulsar.log.root.level}" additivity: true AppenderRef: - ref: "${sys:pulsar.log.appender}" - ref: Prometheus level: info Logger: - name: org.apache.bookkeeper.bookie.BookieShell level: info additivity: false AppenderRef: - ref: Console - name: verbose level: info additivity: false AppenderRef: - ref: Console ``` **Some other cases**  caused by `org.apache.pulsar.broker.service.ServerCnx.handleCloseConsumer(ServerCnx.java:1628)` https://github.com/apache/pulsar/blob/ee87c7d6c20186ae59298a9a9ec1fdb2b09954c7/pulsar-broker/src/main/java/org/apache/pulsar/broker/service/ServerCnx.java#L1625-L1638  caused by `org.apache.pulsar.broker.service.ServerCnx.lambda$handleProducer$25(ServerCnx.java:1201)` https://github.com/apache/pulsar/blob/ee87c7d6c20186ae59298a9a9ec1fdb2b09954c7/pulsar-broker/src/main/java/org/apache/pulsar/broker/service/ServerCnx.java#L1157-L1202 -- 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: [email protected] For queries about this service, please contact Infrastructure at: [email protected]
