No thread name in AccessLogValve printed

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
4 messages Options
Reply | Threaded
Open this post in threaded view
|

No thread name in AccessLogValve printed

Michael Osipov
Folks,

I have seen recently entried like this on our access logs:
> 2020-10-19T20:00:05.591 [null] xyz - "-" 400 - 0
> 2020-10-19T20:00:05.591 [null] abc- "-" 400 - 0
> 2020-10-19T20:00:05.592 [null] abc - "-" 400 - 0
> 2020-10-19T20:00:05.593 [null] abc - "-" 400 - 0
> 2020-10-19T20:00:05.616 [null] abc - "-" 400 - 0

with pattern:
> %{yyyy-MM-dd'T'HH:mm:ss.SSS}t [%I] %h %u "%r" %s %b %D

While I am quite certain that these ary "security" scans at work
I wonder why RequestInfo#getWorkerThreadName() is null.
Is the request rejected because it is malformed because before it is
handled to a worker? I am not sure whether "info != null &&
info.getgetWorkerThreadName() != null" would be the right change here.

Does someone know better?

Michael

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: No thread name in AccessLogValve printed

markt
On 20/10/2020 10:10, Michael Osipov wrote:

> Folks,
>
> I have seen recently entried like this on our access logs:
>> 2020-10-19T20:00:05.591 [null] xyz - "-" 400 - 0
>> 2020-10-19T20:00:05.591 [null] abc- "-" 400 - 0
>> 2020-10-19T20:00:05.592 [null] abc - "-" 400 - 0
>> 2020-10-19T20:00:05.593 [null] abc - "-" 400 - 0
>> 2020-10-19T20:00:05.616 [null] abc - "-" 400 - 0
>
> with pattern:
>> %{yyyy-MM-dd'T'HH:mm:ss.SSS}t [%I] %h %u "%r" %s %b %D
>
> While I am quite certain that these ary "security" scans at work
> I wonder why RequestInfo#getWorkerThreadName() is null.
> Is the request rejected because it is malformed because before it is
> handled to a worker?

Have you tried looking at the source code? Callers of
RequestInfo.setWorkerThreadName() are likely to be enlightening.

> I am not sure whether "info != null &&
> info.getgetWorkerThreadName() != null" would be the right change here.

That would address the symptom. There may be a better fix that addresses
(or at least gets closer) to the cause.

Mark

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: No thread name in AccessLogValve printed

Michael Osipov
Am 2020-10-20 um 11:44 schrieb Mark Thomas:

> On 20/10/2020 10:10, Michael Osipov wrote:
>> Folks,
>>
>> I have seen recently entried like this on our access logs:
>>> 2020-10-19T20:00:05.591 [null] xyz - "-" 400 - 0
>>> 2020-10-19T20:00:05.591 [null] abc- "-" 400 - 0
>>> 2020-10-19T20:00:05.592 [null] abc - "-" 400 - 0
>>> 2020-10-19T20:00:05.593 [null] abc - "-" 400 - 0
>>> 2020-10-19T20:00:05.616 [null] abc - "-" 400 - 0
>>
>> with pattern:
>>> %{yyyy-MM-dd'T'HH:mm:ss.SSS}t [%I] %h %u "%r" %s %b %D
>>
>> While I am quite certain that these ary "security" scans at work
>> I wonder why RequestInfo#getWorkerThreadName() is null.
>> Is the request rejected because it is malformed because before it is
>> handled to a worker?
>
> Have you tried looking at the source code? Callers of
> RequestInfo.setWorkerThreadName() are likely to be enlightening.

Yes, I did. It happens before the thread local is used. It happens in
org.apache.coyote.http11.Http11Processor.prepareRequest() before a
servlet is invoked. So the worker name has to be null here.

>> I am not sure whether "info != null &&
>> info.getgetWorkerThreadName() != null" would be the right change here.
>
> That would address the symptom. There may be a better fix that addresses
> (or at least gets closer) to the cause.

Given the information above I am inclined to say that Thread#getName()
would make sense here. Writing '-' does not make sense becuase every
request is processed in some thread, isn't it?

Michael

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]

Reply | Threaded
Open this post in threaded view
|

Re: No thread name in AccessLogValve printed

markt
On 20/10/2020 11:39, Michael Osipov wrote:

> Am 2020-10-20 um 11:44 schrieb Mark Thomas:
>> On 20/10/2020 10:10, Michael Osipov wrote:
>>> Folks,
>>>
>>> I have seen recently entried like this on our access logs:
>>>> 2020-10-19T20:00:05.591 [null] xyz - "-" 400 - 0
>>>> 2020-10-19T20:00:05.591 [null] abc- "-" 400 - 0
>>>> 2020-10-19T20:00:05.592 [null] abc - "-" 400 - 0
>>>> 2020-10-19T20:00:05.593 [null] abc - "-" 400 - 0
>>>> 2020-10-19T20:00:05.616 [null] abc - "-" 400 - 0
>>>
>>> with pattern:
>>>> %{yyyy-MM-dd'T'HH:mm:ss.SSS}t [%I] %h %u "%r" %s %b %D
>>>
>>> While I am quite certain that these ary "security" scans at work
>>> I wonder why RequestInfo#getWorkerThreadName() is null.
>>> Is the request rejected because it is malformed because before it is
>>> handled to a worker?
>>
>> Have you tried looking at the source code? Callers of
>> RequestInfo.setWorkerThreadName() are likely to be enlightening.
>
> Yes, I did. It happens before the thread local is used.

Strictly, RequestInfo isn't a ThreadLocal. There is plumbing in place to
ensure there is a one-to-one mapping between Http11Processor, Request,
Response and RequestInfo (and other objects as well) and that that group
of objects is only accessed by one thread at a time.

> It happens in
> org.apache.coyote.http11.Http11Processor.prepareRequest() before a
> servlet is invoked. So the worker name has to be null here.

Processing is transferred to a worker thread as soon as the socket as
accepted / as soon as the Poller identifies there is data to process so
there is no need for the worker name to be null here.

>>> I am not sure whether "info != null &&
>>> info.getgetWorkerThreadName() != null" would be the right change here.
>>
>> That would address the symptom. There may be a better fix that addresses
>> (or at least gets closer) to the cause.
>
> Given the information above I am inclined to say that Thread#getName()
> would make sense here.

That would give the correct value but is more of an "address the
symptom" approach that an "address the root cause" approach.

I'd suggest looking at moving the RequestInfo.setWorkerThreadName()
calls to an earlier point in the processing chain so it was set when the
AccessLogValve tries to use it.

> Writing '-' does not make sense because every
> request is processed in some thread, isn't it?

Agreed. Although it is worth keeping in mind async requests and any
request where non-blocking IO is used may be processed by more than one
thread during the duration of the request. In those cases the thread
recorded is (I think) going to be the last container thread that handled
the request.

Mark

---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]