Hi Oleg, I had to modify the logging code a bit to work with the v4.3 branch and I've also changed the loggers to use our slf4j logging, but on friday we've finally deployed the code to one of our server and waited for the spinning to appear again. This is what I see a lot in the logs:
2014-09-14 19:40:17,630 DEBUG [I/O dispatcher 31] NHttpServerConnection:144 - produceOutput : http-incoming-22190: Produce output 2014-09-14 19:40:17,630 DEBUG [I/O dispatcher 183] NHttpServerConnection:144 - produceOutput : http-incoming-13597: Produce output 2014-09-14 19:40:17,630 DEBUG [I/O dispatcher 31] NHttpServerConnection:112 - close : http-incoming-22190: Close connection 2014-09-14 19:40:17,630 DEBUG [I/O dispatcher 183] NHttpServerConnection:112 - close : http-incoming-13597: Close connection 2014-09-14 19:40:17,630 DEBUG [I/O dispatcher 31] NHttpServerConnection:144 - produceOutput : http-incoming-22190: Produce output 2014-09-14 19:40:17,630 DEBUG [I/O dispatcher 183] NHttpServerConnection:144 - produceOutput : http-incoming-13597: Produce output 2014-09-14 19:40:17,630 DEBUG [I/O dispatcher 31] NHttpServerConnection:112 - close : http-incoming-22190: Close connection 2014-09-14 19:40:17,630 DEBUG [I/O dispatcher 183] NHttpServerConnection:112 - close : http-incoming-13597: Close connection 2014-09-14 19:40:17,630 DEBUG [I/O dispatcher 31] NHttpServerConnection:144 - produceOutput : http-incoming-22190: Produce output 2014-09-14 19:40:17,630 DEBUG [I/O dispatcher 183] NHttpServerConnection:144 - produceOutput : http-incoming-13597: Produce output 2014-09-14 19:40:17,631 DEBUG [I/O dispatcher 31] NHttpServerConnection:112 - close : http-incoming-22190: Close connection 2014-09-14 19:40:17,631 DEBUG [I/O dispatcher 183] NHttpServerConnection:112 - close : http-incoming-13597: Close connection I'm not exactly sure what the problem is here, but it looks wrong to me. I hope someone here is able to explain what might be happening there. Would you want me to share the modified logging code so you could integrate it into your repo again? Tobias 2014-09-10 14:58 GMT+02:00 Oleg Kalnichevski <[email protected]>: > On Wed, 2014-09-10 at 13:59 +0200, Tobias Bieniek wrote: >> Hi guys, >> >> we are running httpcore-nio on several production servers as an API >> frontend. Lately we upgraded httpcore from v4.2 to v4.3.2 and since >> then we are experiencing a much higher CPU load (constantly around >> 40%) and memory usage. >> >> We have activated JMX on the servers, had a look with VisualVM and >> noticed that the Sampler shows SessionOutputBufferImpl.flush() to >> consume over 90% of the CPU time. So far we haven't been able to track >> why it is spending so much time flushing when the HTTP request load is >> actually rather low. >> >> The memory graph in VisualVM shows that a lot of memory is allocated >> in what we suspect to be an endless loop somewhere, which would also >> explain the high CPU load. >> >> As I said above we haven't been successful in debugging this problem >> and we would be very thankful for any ideas on how we could solve >> this. >> >> Tobias Bieniek >> > > Hi Tobias > > If any of the sessions is 'spinning' it should be fairly easy to find > out by using I/O session logging. > > Can you add those (or similar) classes to your test project [1] and > reproduce the problem with I/O session logging turned on? > > Oleg > > [1] > http://svn.apache.org/repos/asf/httpcomponents/contrib/httpcore/trunk/src/main/java/org/apache/http/contrib/logging/ > > > > --------------------------------------------------------------------- > To unsubscribe, e-mail: [email protected] > For additional commands, e-mail: [email protected] > --------------------------------------------------------------------- To unsubscribe, e-mail: [email protected] For additional commands, e-mail: [email protected]
