Re: INVALID_FETCH_SESSION_EPOCH after upgrade to 1.1.0
Also in this case will it fall back to a full request?
Hence no data is lost but it might increase latency?
Thanks
Mark
On Thu, 26 Jul 2018, 12:28 Mark Anderson, wrote:
> Ted,
>
> Below are examples of the DEBUG entries from FetchSession
>
> [2018-07-26 11:14:43,461] DEBUG Created a new error FetchContext for
> session id 1139872548: expected epoch 13719, but got epoch 13718.
> (kafka.server.FetchManager)
> [2018-07-26 11:24:35,339] DEBUG Created a new error FetchContext for
> session id 738221153: expected epoch 12679, but got epoch 12678.
> (kafka.server.FetchManager)
>
> [2018-07-26 11:24:36,967] DEBUG Created a new error FetchContext for
> session id 1696245254: expected epoch 34143, but got epoch 34142.
> (kafka.server.FetchManager)
>
> [2018-07-26 11:24:47,736] DEBUG Created a new error FetchContext for
> session id 2131207151: expected epoch 14185, but got epoch 14184.
> (kafka.server.FetchManager)
> [2018-07-26 11:24:51,414] DEBUG Created a new error FetchContext for
> session id 1213530731: expected epoch 77250, but got epoch 77249.
> (kafka.server.FetchManager)
>
> Is the fact that there are always out by one significant?
>
> Thanks,
> Mark
>
> On Wed, 13 Jun 2018 at 17:46 Ted Yu wrote:
>
>> You would need this (plus any appender you want the log to go to):
>>
>> log4j.logger.kafka.server=DEBUG
>>
>> FYI
>>
>> On Wed, Jun 13, 2018 at 9:15 AM, Ted Yu wrote:
>>
>>> In log4j.properties, can you make the following change (you can keep
>>> whatever follows the first comma in the rootLogger line):
>>>
>>> log4j.rootLogger=DEBUG
>>> log4j.logger.org.apache.kafka=DEBUG
>>>
>>> FetchSession.scala is in kafka.server package. You can just turn on
>>> DEBUG for this package.
>>>
>>> FYI
>>>
>>>
>>> On Wed, Jun 13, 2018 at 9:08 AM, Mark Anderson
>>> wrote:
>>>
Ted
I don't see any other INFO log messages so I assume that means it is the
DEBUG case I'm seeing?
I don't have DEBUG enabled at the moment.
Thanks
On Wed, 13 Jun 2018, 00:21 Ted Yu, wrote:
> Before Errors.INVALID_FETCH_SESSION_EPOCH is returned,
FetchSession.scala
> would log the reason for the response.
> There are 3 cases, 2 with info log and 1 with debug log.
> Here is one code snippet:
>
> if (session.epoch != reqMetadata.epoch()) {
>
> debug(s"Created a new error FetchContext for session id
${
> session.id}: expected " +
>
> s"epoch ${session.epoch}, but got epoch $
> {reqMetadata.epoch()}.")
>
> new
SessionErrorContext(Errors.INVALID_FETCH_SESSION_EPOCH,
> reqMetadata)
>
> Can you pastebin the log line preceding what you pasted ?
>
> Thanks
>
> On Tue, Jun 12, 2018 at 3:12 PM, Mark Anderson >>> >
> wrote:
>
> > We recently updated our Kafka brokers and clients to 1.1.0. Since
the
> > upgrade we periodically see INFO log entries such as
> >
> > INFO Jun 08 08:30:20.335 61161458 [KafkaRecordConsumer-0]
> > org.apache.kafka.clients.FetchSessionHandler [Consumer
> > clientId=consumer-1,
> > groupId=group_60_10] Node 3 was unable to process the fetch request
with
> > (sessionId=819759315, epoch=145991): INVALID_FETCH_SESSION_EPOCH.
> >
> > I see that this message comes from the changes introduced in
KIP-227:
> > Introduce Incremental FetchRequests To Increase Partition Stability
> > > 227%3A+Introduce+Incremental+FetchRequests+to+Increase+
> > Partition+Scalability>.
> > However, I cannot find any detailed information about why this
message
> > would appear or what parameters might have to be tuned after its
> > introduction.
> >
> > So far it doesn't seem to have an impact on consumer behaviour with
> respect
> > to receiving records but I would like to understand
> >
> >1. Why is the message being logged?
> >2. Do I need to do anything?
> >3. Can anything be done to stop it being logged?
> >
> > Thanks,
> > Mark
> >
>
>>>
>>>
>>
Re: INVALID_FETCH_SESSION_EPOCH after upgrade to 1.1.0
Ted,
Below are examples of the DEBUG entries from FetchSession
[2018-07-26 11:14:43,461] DEBUG Created a new error FetchContext for
session id 1139872548: expected epoch 13719, but got epoch 13718.
(kafka.server.FetchManager)
[2018-07-26 11:24:35,339] DEBUG Created a new error FetchContext for
session id 738221153: expected epoch 12679, but got epoch 12678.
(kafka.server.FetchManager)
[2018-07-26 11:24:36,967] DEBUG Created a new error FetchContext for
session id 1696245254: expected epoch 34143, but got epoch 34142.
(kafka.server.FetchManager)
[2018-07-26 11:24:47,736] DEBUG Created a new error FetchContext for
session id 2131207151: expected epoch 14185, but got epoch 14184.
(kafka.server.FetchManager)
[2018-07-26 11:24:51,414] DEBUG Created a new error FetchContext for
session id 1213530731: expected epoch 77250, but got epoch 77249.
(kafka.server.FetchManager)
Is the fact that there are always out by one significant?
Thanks,
Mark
On Wed, 13 Jun 2018 at 17:46 Ted Yu wrote:
> You would need this (plus any appender you want the log to go to):
>
> log4j.logger.kafka.server=DEBUG
>
> FYI
>
> On Wed, Jun 13, 2018 at 9:15 AM, Ted Yu wrote:
>
>> In log4j.properties, can you make the following change (you can keep
>> whatever follows the first comma in the rootLogger line):
>>
>> log4j.rootLogger=DEBUG
>> log4j.logger.org.apache.kafka=DEBUG
>>
>> FetchSession.scala is in kafka.server package. You can just turn on DEBUG
>> for this package.
>>
>> FYI
>>
>>
>> On Wed, Jun 13, 2018 at 9:08 AM, Mark Anderson
>> wrote:
>>
>>> Ted
>>>
>>> I don't see any other INFO log messages so I assume that means it is the
>>> DEBUG case I'm seeing?
>>>
>>> I don't have DEBUG enabled at the moment.
>>>
>>> Thanks
>>>
>>> On Wed, 13 Jun 2018, 00:21 Ted Yu, wrote:
>>>
>>> > Before Errors.INVALID_FETCH_SESSION_EPOCH is returned,
>>> FetchSession.scala
>>> > would log the reason for the response.
>>> > There are 3 cases, 2 with info log and 1 with debug log.
>>> > Here is one code snippet:
>>> >
>>> > if (session.epoch != reqMetadata.epoch()) {
>>> >
>>> > debug(s"Created a new error FetchContext for session id
>>> ${
>>> > session.id}: expected " +
>>> >
>>> > s"epoch ${session.epoch}, but got epoch $
>>> > {reqMetadata.epoch()}.")
>>> >
>>> > new
>>> SessionErrorContext(Errors.INVALID_FETCH_SESSION_EPOCH,
>>> > reqMetadata)
>>> >
>>> > Can you pastebin the log line preceding what you pasted ?
>>> >
>>> > Thanks
>>> >
>>> > On Tue, Jun 12, 2018 at 3:12 PM, Mark Anderson
>>> > wrote:
>>> >
>>> > > We recently updated our Kafka brokers and clients to 1.1.0. Since the
>>> > > upgrade we periodically see INFO log entries such as
>>> > >
>>> > > INFO Jun 08 08:30:20.335 61161458 [KafkaRecordConsumer-0]
>>> > > org.apache.kafka.clients.FetchSessionHandler [Consumer
>>> > > clientId=consumer-1,
>>> > > groupId=group_60_10] Node 3 was unable to process the fetch request
>>> with
>>> > > (sessionId=819759315, epoch=145991): INVALID_FETCH_SESSION_EPOCH.
>>> > >
>>> > > I see that this message comes from the changes introduced in KIP-227:
>>> > > Introduce Incremental FetchRequests To Increase Partition Stability
>>> > > >> > > 227%3A+Introduce+Incremental+FetchRequests+to+Increase+
>>> > > Partition+Scalability>.
>>> > > However, I cannot find any detailed information about why this
>>> message
>>> > > would appear or what parameters might have to be tuned after its
>>> > > introduction.
>>> > >
>>> > > So far it doesn't seem to have an impact on consumer behaviour with
>>> > respect
>>> > > to receiving records but I would like to understand
>>> > >
>>> > >1. Why is the message being logged?
>>> > >2. Do I need to do anything?
>>> > >3. Can anything be done to stop it being logged?
>>> > >
>>> > > Thanks,
>>> > > Mark
>>> > >
>>> >
>>>
>>
>>
>
Re: INVALID_FETCH_SESSION_EPOCH after upgrade to 1.1.0
In log4j.properties, can you make the following change (you can keep
whatever follows the first comma in the rootLogger line):
log4j.rootLogger=DEBUG
log4j.logger.org.apache.kafka=DEBUG
FetchSession.scala is in kafka.server package. You can just turn on DEBUG
for this package.
FYI
On Wed, Jun 13, 2018 at 9:08 AM, Mark Anderson
wrote:
> Ted
>
> I don't see any other INFO log messages so I assume that means it is the
> DEBUG case I'm seeing?
>
> I don't have DEBUG enabled at the moment.
>
> Thanks
>
> On Wed, 13 Jun 2018, 00:21 Ted Yu, wrote:
>
> > Before Errors.INVALID_FETCH_SESSION_EPOCH is returned,
> FetchSession.scala
> > would log the reason for the response.
> > There are 3 cases, 2 with info log and 1 with debug log.
> > Here is one code snippet:
> >
> > if (session.epoch != reqMetadata.epoch()) {
> >
> > debug(s"Created a new error FetchContext for session id ${
> > session.id}: expected " +
> >
> > s"epoch ${session.epoch}, but got epoch $
> > {reqMetadata.epoch()}.")
> >
> > new SessionErrorContext(Errors.
> INVALID_FETCH_SESSION_EPOCH,
> > reqMetadata)
> >
> > Can you pastebin the log line preceding what you pasted ?
> >
> > Thanks
> >
> > On Tue, Jun 12, 2018 at 3:12 PM, Mark Anderson
> > wrote:
> >
> > > We recently updated our Kafka brokers and clients to 1.1.0. Since the
> > > upgrade we periodically see INFO log entries such as
> > >
> > > INFO Jun 08 08:30:20.335 61161458 [KafkaRecordConsumer-0]
> > > org.apache.kafka.clients.FetchSessionHandler [Consumer
> > > clientId=consumer-1,
> > > groupId=group_60_10] Node 3 was unable to process the fetch request
> with
> > > (sessionId=819759315, epoch=145991): INVALID_FETCH_SESSION_EPOCH.
> > >
> > > I see that this message comes from the changes introduced in KIP-227:
> > > Introduce Incremental FetchRequests To Increase Partition Stability
> > > > > 227%3A+Introduce+Incremental+FetchRequests+to+Increase+
> > > Partition+Scalability>.
> > > However, I cannot find any detailed information about why this message
> > > would appear or what parameters might have to be tuned after its
> > > introduction.
> > >
> > > So far it doesn't seem to have an impact on consumer behaviour with
> > respect
> > > to receiving records but I would like to understand
> > >
> > >1. Why is the message being logged?
> > >2. Do I need to do anything?
> > >3. Can anything be done to stop it being logged?
> > >
> > > Thanks,
> > > Mark
> > >
> >
>
Re: INVALID_FETCH_SESSION_EPOCH after upgrade to 1.1.0
Ted
I don't see any other INFO log messages so I assume that means it is the
DEBUG case I'm seeing?
I don't have DEBUG enabled at the moment.
Thanks
On Wed, 13 Jun 2018, 00:21 Ted Yu, wrote:
> Before Errors.INVALID_FETCH_SESSION_EPOCH is returned, FetchSession.scala
> would log the reason for the response.
> There are 3 cases, 2 with info log and 1 with debug log.
> Here is one code snippet:
>
> if (session.epoch != reqMetadata.epoch()) {
>
> debug(s"Created a new error FetchContext for session id ${
> session.id}: expected " +
>
> s"epoch ${session.epoch}, but got epoch $
> {reqMetadata.epoch()}.")
>
> new SessionErrorContext(Errors.INVALID_FETCH_SESSION_EPOCH,
> reqMetadata)
>
> Can you pastebin the log line preceding what you pasted ?
>
> Thanks
>
> On Tue, Jun 12, 2018 at 3:12 PM, Mark Anderson
> wrote:
>
> > We recently updated our Kafka brokers and clients to 1.1.0. Since the
> > upgrade we periodically see INFO log entries such as
> >
> > INFO Jun 08 08:30:20.335 61161458 [KafkaRecordConsumer-0]
> > org.apache.kafka.clients.FetchSessionHandler [Consumer
> > clientId=consumer-1,
> > groupId=group_60_10] Node 3 was unable to process the fetch request with
> > (sessionId=819759315, epoch=145991): INVALID_FETCH_SESSION_EPOCH.
> >
> > I see that this message comes from the changes introduced in KIP-227:
> > Introduce Incremental FetchRequests To Increase Partition Stability
> > > 227%3A+Introduce+Incremental+FetchRequests+to+Increase+
> > Partition+Scalability>.
> > However, I cannot find any detailed information about why this message
> > would appear or what parameters might have to be tuned after its
> > introduction.
> >
> > So far it doesn't seem to have an impact on consumer behaviour with
> respect
> > to receiving records but I would like to understand
> >
> >1. Why is the message being logged?
> >2. Do I need to do anything?
> >3. Can anything be done to stop it being logged?
> >
> > Thanks,
> > Mark
> >
>
Re: INVALID_FETCH_SESSION_EPOCH after upgrade to 1.1.0
Before Errors.INVALID_FETCH_SESSION_EPOCH is returned, FetchSession.scala
would log the reason for the response.
There are 3 cases, 2 with info log and 1 with debug log.
Here is one code snippet:
if (session.epoch != reqMetadata.epoch()) {
debug(s"Created a new error FetchContext for session id ${
session.id}: expected " +
s"epoch ${session.epoch}, but got epoch $
{reqMetadata.epoch()}.")
new SessionErrorContext(Errors.INVALID_FETCH_SESSION_EPOCH,
reqMetadata)
Can you pastebin the log line preceding what you pasted ?
Thanks
On Tue, Jun 12, 2018 at 3:12 PM, Mark Anderson
wrote:
> We recently updated our Kafka brokers and clients to 1.1.0. Since the
> upgrade we periodically see INFO log entries such as
>
> INFO Jun 08 08:30:20.335 61161458 [KafkaRecordConsumer-0]
> org.apache.kafka.clients.FetchSessionHandler [Consumer
> clientId=consumer-1,
> groupId=group_60_10] Node 3 was unable to process the fetch request with
> (sessionId=819759315, epoch=145991): INVALID_FETCH_SESSION_EPOCH.
>
> I see that this message comes from the changes introduced in KIP-227:
> Introduce Incremental FetchRequests To Increase Partition Stability
> 227%3A+Introduce+Incremental+FetchRequests+to+Increase+
> Partition+Scalability>.
> However, I cannot find any detailed information about why this message
> would appear or what parameters might have to be tuned after its
> introduction.
>
> So far it doesn't seem to have an impact on consumer behaviour with respect
> to receiving records but I would like to understand
>
>1. Why is the message being logged?
>2. Do I need to do anything?
>3. Can anything be done to stop it being logged?
>
> Thanks,
> Mark
>
