Skip to content

Unnecessary exception is logged #854

Description

@ameshkov

Source:
http://4pda.ru/forum/index.php?s=&showtopic=601691&view=findpost&p=54271571

Connection is blocked and closed by us.

Then SSL manager tries to write notifying packet to the closed connection and we get this record in the log:

13:13:32.514 [pool-3-thread-11] DEBUG com.adguard.filter.proxy.a - TCP id=100031 Server has accepted new tcp connection. Connection info=com.geargames.aow /192.168.100.5:34150 /54.243.140.205:443 10248
13:13:32.515 [Thread-4391] DEBUG com.adguard.commons.b.s - TCP id=100031 address=/192.168.100.5:34150 Read 225 bytes from socket channel
13:13:32.517 [pool-3-thread-11] DEBUG com.adguard.filter.proxy.a - TCP id=100031 Accepting incoming SSL connection
13:13:32.518 [pool-3-thread-11] DEBUG com.adguard.filter.proxy.ssl.g - TCP id=100031 Extracted host name connect.tapjoy.com from a ClientHello
13:13:32.519 [pool-3-thread-11] DEBUG com.adguard.filter.proxy.a - TCP id=100031 Checking request with HttpRequestFilter
13:13:32.519 [pool-3-thread-11] DEBUG com.adguard.filter.a.f - TCP id=100031 Start filtering http request. With response = false
13:13:32.519 [pool-3-thread-11] DEBUG com.adguard.filter.a.f - TCP id=100031 Filtering http request
13:13:32.520 [pool-3-thread-11] DEBUG com.adguard.filter.a.f - TCP id=100031 Black list rule found: ||tapjoy.com^$empty
13:13:32.521 [pool-3-thread-11] DEBUG com.adguard.filter.a.f - TCP id=100031 Finished filtering http request. Rule found: ||tapjoy.com^$empty
13:13:32.522 [pool-3-thread-11] DEBUG com.adguard.commons.b.r - TCP id=100031 Write 7 bytes to socket channel
13:13:32.523 [Thread-4391] DEBUG com.adguard.commons.b.s - TCP id=100031 address=/192.168.100.5:34150 Closing TCP connection
13:13:32.526 [pool-3-thread-11] ERROR com.adguard.filter.proxy.a - TCP id=100031 Error while processing connection. Connection info: com.geargames.aow /192.168.100.5:34150 /54.243.140.205:443 10248


java.net.SocketException: Socket closed
    at libcore.io.Posix.sendtoBytes(Native Method) ~[na:0.0]
    at libcore.io.Posix.sendto(Posix.java:198) ~[na:0.0]
    at libcore.io.BlockGuardOs.sendto(BlockGuardOs.java:270) ~[na:0.0]
    at libcore.io.IoBridge.sendto(IoBridge.java:536) ~[na:0.0]
    at java.nio.SocketChannelImpl.writeImpl(SocketChannelImpl.java:403) ~[na:0.0]
    at java.nio.SocketChannelImpl.write(SocketChannelImpl.java:361) ~[na:0.0]
    at com.adguard.commons.b.r.write(Unknown Source) ~[na:0.0]
    at com.adguard.commons.b.r.write(Unknown Source) ~[na:0.0]
    at org.apache.commons.io.output.ProxyOutputStream.write(Unknown Source) ~[na:0.0]
    at com.adguard.filter.proxy.ssl.g.a(Unknown Source) ~[na:0.0]
    at com.adguard.filter.proxy.a.a(Unknown Source) ~[na:0.0]
    at com.adguard.android.filtering.filter.i.a(Unknown Source) ~[na:0.0]
    at com.adguard.filter.proxy.a.a(Unknown Source) ~[na:0.0]
    at com.adguard.android.filtering.filter.i.a(Unknown Source) ~[na:0.0]
    at com.adguard.filter.proxy.n.a(Unknown Source) ~[na:0.0]
    at com.adguard.filter.proxy.n$2.run(Unknown Source) ~[na:0.0]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112) ~[na:0.0]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587) ~[na:0.0]
    at java.lang.Thread.run(Thread.java:818) ~[na:0.0]
13:13:32.527 [pool-3-thread-11] DEBUG com.adguard.filter.proxy.l - TCP id=100031 Closing TcpConnectionContext
13:13:32.528 [pool-3-thread-11] DEBUG com.adguard.filter.proxy.l - TCP id=100031 TcpConnectionContext has been closed
13:46:44.169 [pool-3-thread-6] DEBUG com.adguard.filter.proxy.a - TCP id=100031 Server has accepted new tcp connection. Connection info=net.wargaming.wot.blitz /192.168.100.5:33820 /52.44.253.73:443 10287
13:46:44.170 [Thread-4829] DEBUG com.adguard.commons.b.s - TCP id=100031 address=/192.168.100.5:33820 Read 194 bytes from socket channel
13:46:44.171 [pool-3-thread-6] DEBUG com.adguard.filter.proxy.a - TCP id=100031 Accepting incoming SSL connection
13:46:44.172 [pool-3-thread-6] DEBUG com.adguard.filter.proxy.ssl.g - TCP id=100031 Found host name adcolony.com in cache
13:46:44.173 [pool-3-thread-6] DEBUG com.adguard.filter.proxy.a - TCP id=100031 Checking request with HttpRequestFilter
13:46:44.175 [pool-3-thread-6] DEBUG com.adguard.filter.a.f - TCP id=100031 Start filtering http request. With response = false
13:46:44.176 [pool-3-thread-6] DEBUG com.adguard.filter.a.f - TCP id=100031 Filtering http request
13:46:44.177 [pool-3-thread-6] DEBUG com.adguard.filter.a.f - TCP id=100031 Black list rule found: ||adcolony.com^$empty
13:46:44.177 [pool-3-thread-6] DEBUG com.adguard.filter.a.f - TCP id=100031 Finished filtering http request. Rule found: ||adcolony.com^$empty
13:46:44.179 [pool-3-thread-6] DEBUG com.adguard.commons.b.r - TCP id=100031 Write 7 bytes to socket channel
13:46:44.183 [Thread-4829] DEBUG com.adguard.commons.b.s - TCP id=100031 address=/192.168.100.5:33820 Closing TCP connection
13:46:44.182 [pool-3-thread-6] DEBUG com.adguard.android.FilteringLog - TCP id=100031 CONNECT ads=1 http://adcolony.com/ net.wargaming.wot.blitz 0 0
13:46:44.186 [pool-3-thread-6] DEBUG com.adguard.filter.proxy.l - TCP id=100031 Closing TcpConnectionContext
13:46:44.186 [pool-3-thread-6] DEBUG com.adguard.filter.proxy.l - TCP id=100031 TcpConnectionContext has been closed

We shouldn't log it as error.

Metadata

Metadata

Assignees

Labels

Type

No type

Projects

No projects

Milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions