Error log full of ServerErrorHandler: Poco::Exception. Code: 1000, e.code() = 107, Net Exception: Socket is not connected #34218

simPod · 2022-02-01T10:35:34Z

I've got the error log full of errors like this

2022.02.01 10:29:55.659210 [ 341370 ] {} <Error> ServerErrorHandler: Poco::Exception. Code: 1000, e.code() = 107, Net Exception: Socket is not connected, Stack trace (when copying this message, always include the lines below):

0. Poco::Net::NetException::NetException(std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&, int) @ 0x16f242ec in /usr/bin/clickhouse
1. Poco::Net::SocketImpl::error(int, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&) @ 0x16f36164 in /usr/bin/clickhouse
2. Poco::Net::SocketImpl::peerAddress() @ 0x16f38856 in /usr/bin/clickhouse
3. DB::ReadBufferFromPocoSocket::ReadBufferFromPocoSocket(Poco::Net::Socket&, unsigned long) @ 0x129c87b1 in /usr/bin/clickhouse
4. DB::HTTPServerRequest::HTTPServerRequest(std::__1::shared_ptr<DB::Context const>, DB::HTTPServerResponse&, Poco::Net::HTTPServerSession&) @ 0x13ff7147 in /usr/bin/clickhouse
5. DB::HTTPServerConnection::run() @ 0x13ff5b03 in /usr/bin/clickhouse
6. Poco::Net::TCPServerConnection::start() @ 0x16f3d6af in /usr/bin/clickhouse
7. Poco::Net::TCPServerDispatcher::run() @ 0x16f3fb01 in /usr/bin/clickhouse
8. Poco::PooledThread::run() @ 0x1704e889 in /usr/bin/clickhouse
9. Poco::ThreadImpl::runnableEntry(void*) @ 0x1704bf80 in /usr/bin/clickhouse
10. start_thread @ 0x8ea7 in /usr/lib/x86_64-linux-gnu/libpthread-2.31.so
11. clone @ 0xfddef in /usr/lib/x86_64-linux-gnu/libc-2.31.so
 (version 21.12.3.32 (official build))

It's not really visible from the trace what kind of error this is. I have no idea where to look since I don't know what connection fails
Any idea what might it be? I have one MergeTree table and inserting into it over http interface. I've disabled clickhouse-keeper since I suspected that might have been the cause but it is not.

The text was updated successfully, but these errors were encountered:

SaltTan · 2022-02-06T16:48:57Z

Check what the thread was doing before and after the exception.
Look by the thread number [ 341370 ].

socketpair · 2022-06-07T08:12:27Z

So, what is the status ? I'm facing the same problem

simPod · 2022-06-07T08:18:56Z

We still don't really know, so far did not find anything that would help trace the source of the issue.

rchadin · 2023-02-09T13:04:11Z

We always have an error after inserting data, but not on every request

2023.02.09 12:38:42.963375 [ 2911 ] {4518af60-d369-4055-9fe6-01df404347c5} <Debug> executeQuery: (from *:*, user: user) INSERT INTO table FORMAT JSONEachRow  (stage: Complete)
2023.02.09 12:38:42.965766 [ 2911 ] {4518af60-d369-4055-9fe6-01df404347c5} <Debug> table (169a6716-5a5c-4f61-b061-975e76f02280) (Replicated OutputStream): Wrote block with ID '2023_9391140777711110759_17375060344880984532', 8 rows
2023.02.09 12:38:42.976916 [ 2911 ] {4518af60-d369-4055-9fe6-01df404347c5} <Information> executeQuery: Read 8 rows, 4.66 KiB in 0.013634 sec., 586.7683731846853 rows/sec., 341.95 KiB/sec.
2023.02.09 12:38:42.977102 [ 2911 ] {4518af60-d369-4055-9fe6-01df404347c5} <Debug> DynamicQueryHandler: Done processing query
2023.02.09 12:38:42.977129 [ 2911 ] {4518af60-d369-4055-9fe6-01df404347c5} <Debug> MemoryTracker: Peak memory usage (for query): 4.15 MiB.
2023.02.09 12:38:43.165323 [ 2911 ] {} <Error> ServerErrorHandler: Poco::Exception. Code: 1000, e.code() = 107, Net Exception: Socket is not connected, Stack trace (when copying this message, always include the lines below):
0. Poco::Net::SocketImpl::error(int, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> const&) @ 0x1753718b in /usr/bin/clickhouse
1. Poco::Net::SocketImpl::peerAddress() @ 0x175399d6 in /usr/bin/clickhouse
2. DB::HTTPServerRequest::HTTPServerRequest(std::__1::shared_ptr<DB::IHTTPContext>, DB::HTTPServerResponse&, Poco::Net::HTTPServerSession&) @ 0x14695eb8 in /usr/bin/clickhouse
3. DB::HTTPServerConnection::run() @ 0x1469486f in /usr/bin/clickhouse
4. Poco::Net::TCPServerConnection::start() @ 0x1753e2f4 in /usr/bin/clickhouse
5. Poco::Net::TCPServerDispatcher::run() @ 0x1753fc9b in /usr/bin/clickhouse
6. Poco::PooledThread::run() @ 0x176cf0a7 in /usr/bin/clickhouse
7. Poco::ThreadImpl::runnableEntry(void*) @ 0x176ccadd in /usr/bin/clickhouse
8. ? @ 0x7fd40a7ec609 in ?
9. __clone @ 0x7fd40a711133 in ?
 (version 23.1.3.5 (official build))

makorne · 2023-05-30T05:28:34Z

We always have an error after inserting data, but not on every request

We have too.


2023.05.30 05:10:50.029653 [ 897638 ] {} <Error> ServerErrorHandler: Poco::Exception. Code: 1000, e.code() = 107, Net Exception: Socket is not connected, Stack trace (when copying this message, always include the lines below):

0. Poco::Net::SocketImpl::error(int, String const&) @ 0x17c5594b in /usr/bin/clickhouse
1. Poco::Net::SocketImpl::peerAddress() @ 0x17c58196 in /usr/bin/clickhouse
2. DB::HTTPServerRequest::HTTPServerRequest(std::shared_ptr<DB::IHTTPContext>, DB::HTTPServerResponse&, Poco::Net::HTTPServerSession&) @ 0x14cf3e40 in /usr/bin/clickhouse
3. DB::HTTPServerConnection::run() @ 0x14cf27ef in /usr/bin/clickhouse
4. Poco::Net::TCPServerConnection::start() @ 0x17c5cab4 in /usr/bin/clickhouse
5. Poco::Net::TCPServerDispatcher::run() @ 0x17c5dcdb in /usr/bin/clickhouse
6. Poco::PooledThread::run() @ 0x17ddb087 in /usr/bin/clickhouse
7. Poco::ThreadImpl::runnableEntry(void*) @ 0x17dd8abd in /usr/bin/clickhouse
8. start_thread @ 0x7ea7 in /usr/lib/x86_64-linux-gnu/libpthread-2.31.so
9. clone @ 0xfca2f in /usr/lib/x86_64-linux-gnu/libc-2.31.so
 (version 23.4.2.11 (official build))
2023.05.30 05:10:50.090230 [ 903914 ] {} <Error> ServerErrorHandler: Poco::Exception. Code: 1000, e.code() = 107, Net Exception: Socket is not connected, Stack trace (when copying this message, always include the lines below):

0. Poco::Net::SocketImpl::error(int, String const&) @ 0x17c5594b in /usr/bin/clickhouse
1. Poco::Net::SocketImpl::peerAddress() @ 0x17c58196 in /usr/bin/clickhouse
2. DB::HTTPServerRequest::HTTPServerRequest(std::shared_ptr<DB::IHTTPContext>, DB::HTTPServerResponse&, Poco::Net::HTTPServerSession&) @ 0x14cf3e40 in /usr/bin/clickhouse
3. DB::HTTPServerConnection::run() @ 0x14cf27ef in /usr/bin/clickhouse
4. Poco::Net::TCPServerConnection::start() @ 0x17c5cab4 in /usr/bin/clickhouse
5. Poco::Net::TCPServerDispatcher::run() @ 0x17c5dcdb in /usr/bin/clickhouse
6. Poco::PooledThread::run() @ 0x17ddb087 in /usr/bin/clickhouse
7. Poco::ThreadImpl::runnableEntry(void*) @ 0x17dd8abd in /usr/bin/clickhouse
8. start_thread @ 0x7ea7 in /usr/lib/x86_64-linux-gnu/libpthread-2.31.so
9. clone @ 0xfca2f in /usr/lib/x86_64-linux-gnu/libc-2.31.so
 (version 23.4.2.11 (official build))
2023.05.30 05:10:50.114752 [ 903914 ] {} <Error> ServerErrorHandler: Poco::Exception. Code: 1000, e.code() = 107, Net Exception: Socket is not connected, Stack trace (when copying this message, always include the lines below):

0. Poco::Net::SocketImpl::error(int, String const&) @ 0x17c5594b in /usr/bin/clickhouse
1. Poco::Net::SocketImpl::peerAddress() @ 0x17c58196 in /usr/bin/clickhouse
2. DB::HTTPServerRequest::HTTPServerRequest(std::shared_ptr<DB::IHTTPContext>, DB::HTTPServerResponse&, Poco::Net::HTTPServerSession&) @ 0x14cf3e40 in /usr/bin/clickhouse
3. DB::HTTPServerConnection::run() @ 0x14cf27ef in /usr/bin/clickhouse
4. Poco::Net::TCPServerConnection::start() @ 0x17c5cab4 in /usr/bin/clickhouse
5. Poco::Net::TCPServerDispatcher::run() @ 0x17c5dcdb in /usr/bin/clickhouse
6. Poco::PooledThread::run() @ 0x17ddb087 in /usr/bin/clickhouse
7. Poco::ThreadImpl::runnableEntry(void*) @ 0x17dd8abd in /usr/bin/clickhouse
8. start_thread @ 0x7ea7 in /usr/lib/x86_64-linux-gnu/libpthread-2.31.so
9. clone @ 0xfca2f in /usr/lib/x86_64-linux-gnu/libc-2.31.so
 (version 23.4.2.11 (official build))

How to solve this?

brunis · 2024-04-17T07:48:28Z

Also seeing the same after upgrading to 24.4.0:
sentry-self-hosted-clickhouse-1 | 2024.04.17 07:44:04.613891 [ 251 ] {} ServerErrorHandler: Poco::Exception. Code: 1000, e.code() = 107, e.displayText() = Net Exception: Socket is not connected, St ack trace (when copying this message, always include the lines below):
sentry-self-hosted-clickhouse-1 |
sentry-self-hosted-clickhouse-1 | 0. Poco::Net::SocketImpl::error(int, std::__1::basic_string<char, std::__1::char_traits, std::__1::allocator > const&) @ 0x13c4ee8e in /usr/bin/clickhouse
sentry-self-hosted-clickhouse-1 | 1. Poco::Net::SocketImpl::peerAddress() @ 0x13c510d6 in /usr/bin/clickhouse
sentry-self-hosted-clickhouse-1 | 2. DB::ReadBufferFromPocoSocket::ReadBufferFromPocoSocket(Poco::Net::Socket&, unsigned long) @ 0x101540cd in /usr/bin/clickhouse
sentry-self-hosted-clickhouse-1 | 3. DB::HTTPServerRequest::HTTPServerRequest(std::__1::shared_ptr<DB::Context const>, DB::HTTPServerResponse&, Poco::Net::HTTPServerSession&) @ 0x110e6fd5 in /usr/bin/click house
sentry-self-hosted-clickhouse-1 | 4. DB::HTTPServerConnection::run() @ 0x110e5d6e in /usr/bin/clickhouse
sentry-self-hosted-clickhouse-1 | 5. Poco::Net::TCPServerConnection::start() @ 0x13c5614f in /usr/bin/clickhouse
sentry-self-hosted-clickhouse-1 | 6. Poco::Net::TCPServerDispatcher::run() @ 0x13c57bda in /usr/bin/clickhouse
sentry-self-hosted-clickhouse-1 | 7. Poco::PooledThread::run() @ 0x13d89e59 in /usr/bin/clickhouse
sentry-self-hosted-clickhouse-1 | 8. Poco::ThreadImpl::runnableEntry(void*) @ 0x13d860ea in /usr/bin/clickhouse
sentry-self-hosted-clickhouse-1 | 9. start_thread @ 0x9609 in /usr/lib/x86_64-linux-gnu/libpthread-2.31.so
sentry-self-hosted-clickhouse-1 | 10. clone @ 0x122293 in /usr/lib/x86_64-linux-gnu/libc-2.31.so
sentry-self-hosted-clickhouse-1 | (version 21.8.13.1.altinitystable (altinity build))

alexey-milovidov · 2024-05-21T05:03:39Z

(version 21.8.13.1.altinitystable (altinity build))

This is a mistake. We don't support alternative, third-party builds.
I strongly do not recommend "altinity" builds.

Read https://clickhouse.com/docs/knowledgebase/difference_between_official_builds_and_3rd_party

Tristan971 · 2024-05-21T05:06:20Z

@alexey-milovidov other reports in the issue are for the official build though. We also experience it on official builds. Don’t close because 1 commenter uses a third-party version…

csvan · 2024-06-12T18:35:52Z

Confirming the same problem on vanilla Sentry 24.5.1

mbovingfred · 2024-06-20T08:42:51Z

Anyone has a solution to this ? I'm facing the same issue on vanilla Sentry 24.5.1

den-crane · 2024-06-20T15:56:08Z

@mbovingfred @csvan Do you experience related issues at a client side? Or is it only about spoiled logs?

Tristan971 · 2024-06-20T23:00:00Z

Do you experience related issues at a client side?

None

Or is it only about spoiled logs?

Yes exactly

csvan · 2024-06-21T08:25:53Z

Same as above ^

mbovingfred · 2024-06-21T08:32:44Z

I get the error when i check clickhouse container logs

csvan · 2024-06-21T16:14:36Z

FYI error persists on Sentry 24.6.0

clickhouse-1                                    | 2024.06.21 16:13:47.456878 [ 61550 ] {} <Error> ServerErrorHandler: Poco::Exception. Code: 1000, e.code() = 107, Net Exception: Socket is not connected, Stack trace (when copying this message, always include the lines below):
clickhouse-1                                    |
clickhouse-1                                    | 0. Poco::Net::SocketImpl::error(int, String const&) @ 0x0000000015b3dbf2 in /usr/bin/clickhouse
clickhouse-1                                    | 1. Poco::Net::SocketImpl::peerAddress() @ 0x0000000015b40376 in /usr/bin/clickhouse
clickhouse-1                                    | 2. DB::HTTPServerRequest::HTTPServerRequest(std::shared_ptr<DB::IHTTPContext>, DB::HTTPServerResponse&, Poco::Net::HTTPServerSession&) @ 0x0000000013154417 in /usr/bin/clickhouse
clickhouse-1                                    | 3. DB::HTTPServerConnection::run() @ 0x0000000013152ba4 in /usr/bin/clickhouse
clickhouse-1                                    | 4. Poco::Net::TCPServerConnection::start() @ 0x0000000015b42834 in /usr/bin/clickhouse
clickhouse-1                                    | 5. Poco::Net::TCPServerDispatcher::run() @ 0x0000000015b43a31 in /usr/bin/clickhouse
clickhouse-1                                    | 6. Poco::PooledThread::run() @ 0x0000000015c7a667 in /usr/bin/clickhouse
clickhouse-1                                    | 7. Poco::ThreadImpl::runnableEntry(void*) @ 0x0000000015c7893c in /usr/bin/clickhouse
clickhouse-1                                    | 8. ? @ 0x00007f4cc6a4f609 in ?
clickhouse-1                                    | 9. ? @ 0x00007f4cc6974353 in ?
clickhouse-1                                    |  (version 23.8.11.29.altinitystable (altinity build))

alexey-milovidov · 2024-06-30T17:17:56Z

The error is reported when a user immediately disconnects with TCP RST after connecting.
The fact that this error is reported is normal. It may indicate problems with your infrastructure, but usually does not require any actions.

Tristan971 · 2024-06-30T17:19:53Z

Yes, no one really minds that it’s happening. The problem is that it makes logs entirely unusable.

It indicates problems with ClickHouse loudly polluting the logs for what any other system uses a debug-level « connection reset by peer » log line.

It is in fact completely inappropriate to throw error-level logs with stacktraces in the logs for it…

Closing this issue is very wrong.

csvan · 2024-07-01T15:44:28Z

Yes kindly do not close this, at the very least the log level should be downgraded

coelho · 2024-07-21T13:33:10Z

We are experiencing this log spam as well in a production environment.

The error is reported when a user immediately disconnects with TCP RST after connecting. The fact that this error is reported is normal. It may indicate problems with your infrastructure, but usually does not require any actions.

It is reasonable to believe there will be a degree of unreliability over a network, especially under high load. In our case, we do not observe any negative effect correlated with this debug message (besides spamming our logs).

abrahamibo · 2024-08-01T09:17:52Z

Yes, no one really minds that it’s happening. The problem is that it makes logs entirely unusable.

It indicates problems with ClickHouse loudly polluting the logs for what any other system uses a debug-level « connection reset by peer » log line.

It is in fact completely inappropriate to throw error-level logs with stacktraces in the logs for it…

Closing this issue is very wrong.

So what exactly do we need to do?

Tristan971 · 2024-08-01T11:26:51Z

So what exactly do we need to do?

Moving this error to TRACE level (or whatever is the lowest developer-intended log level) seems appropriate to me.

If a client sends a TCP RST, which is a very appropriate way for an HTTP client to terminate a non-H2-multiplexed HTTP connection, it should not appear at the standard log level, especially not with an entire stacktrace.

You could argue that it’s already a debug-level log but the CH team has repeatedly indicated that users are expected to run it at debug log level rather than information level, so it is de-facto what would be considered « info » level in other software.

alexey-milovidov · 2024-08-01T16:48:30Z

We run all our servers with the Trace level by default.

Tristan971 · 2024-08-01T16:54:05Z

We run all our servers with the Trace level by default.

That's great, then you can move this to trace, still see it yourself, and anyone else who doesn't do so won't see it anymore...? Win-win

alexey-milovidov · 2024-08-01T16:57:27Z

Yes, this makes sense.

Tristan971 · 2024-08-01T17:01:13Z

While I'm happy to make this change, it seems that there's already a PR related to it here #67177

Any preference between my proposal (move it to TRACE) and that PR (keeping it at DEBUG, but ratelimiting it)?

alexey-milovidov · 2024-08-01T17:02:22Z

Rate-limiting is better.

vdimir · 2024-08-02T08:51:26Z

keeping it at DEBUG

Currently it's <Error>. So, for me either Debug or Trace with rate limiting seems alright

simPod added the usability label Feb 1, 2022

doom369 mentioned this issue Jul 26, 2022

Server log filled with errors Blynk-Technologies/clickhouse4j#95

Closed

makorne mentioned this issue May 30, 2023

Client dropped the connection ClickHouse/clickhouse-rs#64

Open

brunis mentioned this issue May 13, 2024

Release 24.5.0 getsentry/self-hosted#2964

Closed

17 tasks

den-crane mentioned this issue May 15, 2024

Net Exception: Socket is not connected logs error logs with every insert #63598

Closed

alexey-milovidov closed this as completed May 21, 2024

alexey-milovidov added the alternative build label May 21, 2024

alexey-milovidov reopened this May 21, 2024

alexey-milovidov removed the alternative build label May 21, 2024

alexey-milovidov closed this as completed Jun 30, 2024

alexey-milovidov reopened this Jul 1, 2024

otbutz mentioned this issue Jul 15, 2024

Clickhouse Net Exception: Socket is not connected getsentry/self-hosted#3199

Closed

vdimir mentioned this issue Jul 26, 2024

Do not spam logs with messages related to connection reset by peer #67177

Merged

19 tasks

alexey-milovidov added the help wanted label Aug 1, 2024

alexey-milovidov assigned Tristan971 Aug 1, 2024

alexey-milovidov assigned vdimir and unassigned Tristan971 Aug 1, 2024

alexey-milovidov closed this as completed in #67177 Aug 8, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Error log full of ServerErrorHandler: Poco::Exception. Code: 1000, e.code() = 107, Net Exception: Socket is not connected #34218

Error log full of ServerErrorHandler: Poco::Exception. Code: 1000, e.code() = 107, Net Exception: Socket is not connected #34218

simPod commented Feb 1, 2022

SaltTan commented Feb 6, 2022

socketpair commented Jun 7, 2022 •

edited

Loading

simPod commented Jun 7, 2022

rchadin commented Feb 9, 2023

makorne commented May 30, 2023

brunis commented Apr 17, 2024 •

edited

Loading

alexey-milovidov commented May 21, 2024

Tristan971 commented May 21, 2024

csvan commented Jun 12, 2024

mbovingfred commented Jun 20, 2024

den-crane commented Jun 20, 2024

Tristan971 commented Jun 20, 2024

csvan commented Jun 21, 2024

mbovingfred commented Jun 21, 2024

csvan commented Jun 21, 2024

alexey-milovidov commented Jun 30, 2024

Tristan971 commented Jun 30, 2024 •

edited

Loading

csvan commented Jul 1, 2024

coelho commented Jul 21, 2024

abrahamibo commented Aug 1, 2024

Tristan971 commented Aug 1, 2024 •

edited

Loading

alexey-milovidov commented Aug 1, 2024

Tristan971 commented Aug 1, 2024

alexey-milovidov commented Aug 1, 2024

Tristan971 commented Aug 1, 2024

alexey-milovidov commented Aug 1, 2024

vdimir commented Aug 2, 2024

Error log full of ServerErrorHandler: Poco::Exception. Code: 1000, e.code() = 107, Net Exception: Socket is not connected #34218

Error log full of ServerErrorHandler: Poco::Exception. Code: 1000, e.code() = 107, Net Exception: Socket is not connected #34218

Comments

simPod commented Feb 1, 2022

SaltTan commented Feb 6, 2022

socketpair commented Jun 7, 2022 • edited Loading

simPod commented Jun 7, 2022

rchadin commented Feb 9, 2023

makorne commented May 30, 2023

brunis commented Apr 17, 2024 • edited Loading

alexey-milovidov commented May 21, 2024

Tristan971 commented May 21, 2024

csvan commented Jun 12, 2024

mbovingfred commented Jun 20, 2024

den-crane commented Jun 20, 2024

Tristan971 commented Jun 20, 2024

csvan commented Jun 21, 2024

mbovingfred commented Jun 21, 2024

csvan commented Jun 21, 2024

alexey-milovidov commented Jun 30, 2024

Tristan971 commented Jun 30, 2024 • edited Loading

csvan commented Jul 1, 2024

coelho commented Jul 21, 2024

abrahamibo commented Aug 1, 2024

Tristan971 commented Aug 1, 2024 • edited Loading

alexey-milovidov commented Aug 1, 2024

Tristan971 commented Aug 1, 2024

alexey-milovidov commented Aug 1, 2024

Tristan971 commented Aug 1, 2024

alexey-milovidov commented Aug 1, 2024

vdimir commented Aug 2, 2024

socketpair commented Jun 7, 2022 •

edited

Loading

brunis commented Apr 17, 2024 •

edited

Loading

Tristan971 commented Jun 30, 2024 •

edited

Loading

Tristan971 commented Aug 1, 2024 •

edited

Loading