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/07/07 05:59:31 UTC
[GitHub] [pulsar] michaeljmarshall commented on issue #15401: Standalone broker on MacOS often fail to start after workstation sleep or reboot
michaeljmarshall commented on issue #15401:
URL: https://github.com/apache/pulsar/issues/15401#issuecomment-1177120312
I didn't realize you could start pulsar that way, thanks for sharing!
Your issue helped me solve a question I have been wondering about for a while (thank you!).
I think I found the likely root cause of your issue, but you will need to confirm. If I am correct, here is the TLDR: Pulsar discovers its IP address for things like `advertisedAddress` using a lookup of the hostname, and if your machine's hostname is not defined in the `/ect/hosts` file, then (based on my troubleshooting) the JVM will perform a DNS lookup on the address and issues can arise when the resulting IP does not route to the right Pulsar process.
Based on your logs, I noticed that some of your stack traces indicate trying to connect to `192.168.1.2:4181`:
```
2022-06-02T13:29:02,974-0400 [client-scheduler-OrderedScheduler-28-0] ERROR org.apache.bookkeeper.clients.impl.internal.RootRangeClientImplWithRetries - Reason for the failure
io.grpc.StatusRuntimeException: UNAVAILABLE: io exception
at io.grpc.Status.asRuntimeException(Status.java:535) ~[io.grpc-grpc-api-1.45.1.jar:1.45.1]
at io.grpc.stub.ClientCalls$UnaryStreamToFuture.onClose(ClientCalls.java:533) ~[io.grpc-grpc-stub-1.45.1.jar:1.45.1]
at io.grpc.internal.ClientCallImpl.closeObserver(ClientCallImpl.java:562) ~[io.grpc-grpc-core-1.45.1.jar:1.45.1]
at io.grpc.internal.ClientCallImpl.access$300(ClientCallImpl.java:70) ~[io.grpc-grpc-core-1.45.1.jar:1.45.1]
at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInternal(ClientCallImpl.java:743) ~[io.grpc-grpc-core-1.45.1.jar:1.45.1]
at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:722) ~[io.grpc-grpc-core-1.45.1.jar:1.45.1]
at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:37) ~[io.grpc-grpc-core-1.45.1.jar:1.45.1]
at io.grpc.internal.SerializingExecutor.run(SerializingExecutor.java:133) ~[io.grpc-grpc-core-1.45.1.jar:1.45.1]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
at java.lang.Thread.run(Thread.java:833) [?:?]
Caused by: io.grpc.netty.shaded.io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /192.168.1.2:4181
Caused by: java.net.ConnectException: Connection refused
at sun.nio.ch.Net.pollConnect(Native Method) ~[?:?]
at sun.nio.ch.Net.pollConnectNow(Net.java:672) ~[?:?]
at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:946) ~[?:?]
at io.grpc.netty.shaded.io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:330) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:334) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:710) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
... 1 more
```
Port 4181 is a bookkeeper port, and for some reason the client is trying to connect to a non-local host, but we already know that the bookkeeper should be running on localhost. I see the same behavior on my host machine:
```
Caused by: io.grpc.netty.shaded.io.netty.channel.AbstractChannel$AnnotatedConnectException: Connection refused: /23.202.231.169:4181
Caused by: java.net.ConnectException: Connection refused
at sun.nio.ch.Net.pollConnect(Native Method) ~[?:?]
at sun.nio.ch.Net.pollConnectNow(Net.java:672) ~[?:?]
at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:946) ~[?:?]
at io.grpc.netty.shaded.io.netty.channel.socket.nio.NioSocketChannel.doFinishConnect(NioSocketChannel.java:330) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.channel.nio.AbstractNioChannel$AbstractNioUnsafe.finishConnect(AbstractNioChannel.java:334) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:710) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:658) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:584) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:496) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
at io.grpc.netty.shaded.io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[io.grpc-grpc-netty-shaded-1.45.1.jar:1.45.1]
... 1 more
```
Interestingly, in my case, Pulsar fails when I am off my work VPN, but it works when I am on the VPN. I've see the same behavior when running Pulsar Standalone, which makes sense since the brew installation is Pulsar Standalone. The nuance comes here: https://github.com/apache/pulsar/blob/76646cfd9496820a6a6dbee225067045235838c0/pulsar-broker-common/src/main/java/org/apache/pulsar/broker/ServiceConfigurationUtils.java#L43-L51. If Pulsar does not have its `advertisedAddress` configured, it performs this lookup, and that lookup relies on a reverse lookup of your hostname, as described here https://stackoverflow.com/a/18488982. After updating my `/etc/hosts` file to map my hostname to map my hostname to `127.0.0.1`, standalone now works and I've confirmed that 2.10.1 works after putting my Mac to sleep and waking it up again. (I only just realized tonight that Standalone was not previously working because my hostname was not correctly resolving to `127.0.0.1`.)
I also noticed that running `nslookup` on my host name resulted in `23.202.231.169` before updating my `/etc/hosts` file and when off the VPN.
Let me know if this helps.
--
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