REST GridCacheCommandHandler writes ERROR in log in case of bad user input

classic Classic list List threaded Threaded
13 messages Options
Reply | Threaded
Open this post in threaded view
|

REST GridCacheCommandHandler writes ERROR in log in case of bad user input

Ilya Kasnacheev
Hello!

It seems that we have subj behavior since the earliest days if Apache
Ignite.

If you send a REST command with error in it (such as missing "keys" for
getAll), you will get a nice
[2018-10-30 22:22:14,021][ERROR][rest-#61061][GridCacheCommandHandler]
Failed to execute cache command: GridRestCacheRequest
error in your logs.

Which is probably an overkill since ERROR usually means unexpected and
severe errors in application code as opposed to user input validation
errors.

This made worse by the fact that you can have some automatic REST client do
a lot of incorrect requests, spam your logs with thousands of such ERRORs.
The error is returned to client but it is also tee'd to log.

What we could do:
- Move log level from ERROR to WARN or even INFO.
- Handle REST user input validation errors differently from Ignite internal
errors by introducing new exception class, logging it as INFO or maybe just
returning to user.
- Third funny option?

WDYT?

Regards,
--
Ilya Kasnacheev
Reply | Threaded
Open this post in threaded view
|

Re: REST GridCacheCommandHandler writes ERROR in log in case of bad user input

Denis Magda-2
Hello Ilya,

It's fine to use ERROR level if an operation can't be completed due to
missing parameters. That's, in fact, an exception/error. What needs to be
changed is texts of messages so that everyone understands what exactly
happened and how to address a failure.

--
Denis


On Fri, Dec 14, 2018 at 5:45 AM Ilya Kasnacheev <[hidden email]>
wrote:

> Hello!
>
> It seems that we have subj behavior since the earliest days if Apache
> Ignite.
>
> If you send a REST command with error in it (such as missing "keys" for
> getAll), you will get a nice
> [2018-10-30 22:22:14,021][ERROR][rest-#61061][GridCacheCommandHandler]
> Failed to execute cache command: GridRestCacheRequest
> error in your logs.
>
> Which is probably an overkill since ERROR usually means unexpected and
> severe errors in application code as opposed to user input validation
> errors.
>
> This made worse by the fact that you can have some automatic REST client do
> a lot of incorrect requests, spam your logs with thousands of such ERRORs.
> The error is returned to client but it is also tee'd to log.
>
> What we could do:
> - Move log level from ERROR to WARN or even INFO.
> - Handle REST user input validation errors differently from Ignite internal
> errors by introducing new exception class, logging it as INFO or maybe just
> returning to user.
> - Third funny option?
>
> WDYT?
>
> Regards,
> --
> Ilya Kasnacheev
>
Reply | Threaded
Open this post in threaded view
|

Re: REST GridCacheCommandHandler writes ERROR in log in case of bad user input

Ilya Kasnacheev
Hello!

Thank you for the opinion!

The following messages (Exception and its message) are fairly descriptive.

Regards,
--
Ilya Kasnacheev


пт, 14 дек. 2018 г. в 21:35, Denis Magda <[hidden email]>:

> Hello Ilya,
>
> It's fine to use ERROR level if an operation can't be completed due to
> missing parameters. That's, in fact, an exception/error. What needs to be
> changed is texts of messages so that everyone understands what exactly
> happened and how to address a failure.
>
> --
> Denis
>
>
> On Fri, Dec 14, 2018 at 5:45 AM Ilya Kasnacheev <[hidden email]
> >
> wrote:
>
> > Hello!
> >
> > It seems that we have subj behavior since the earliest days if Apache
> > Ignite.
> >
> > If you send a REST command with error in it (such as missing "keys" for
> > getAll), you will get a nice
> > [2018-10-30 22:22:14,021][ERROR][rest-#61061][GridCacheCommandHandler]
> > Failed to execute cache command: GridRestCacheRequest
> > error in your logs.
> >
> > Which is probably an overkill since ERROR usually means unexpected and
> > severe errors in application code as opposed to user input validation
> > errors.
> >
> > This made worse by the fact that you can have some automatic REST client
> do
> > a lot of incorrect requests, spam your logs with thousands of such
> ERRORs.
> > The error is returned to client but it is also tee'd to log.
> >
> > What we could do:
> > - Move log level from ERROR to WARN or even INFO.
> > - Handle REST user input validation errors differently from Ignite
> internal
> > errors by introducing new exception class, logging it as INFO or maybe
> just
> > returning to user.
> > - Third funny option?
> >
> > WDYT?
> >
> > Regards,
> > --
> > Ilya Kasnacheev
> >
>
Reply | Threaded
Open this post in threaded view
|

Re: REST GridCacheCommandHandler writes ERROR in log in case of bad user input

Sergey Kozlov
In reply to this post by Denis Magda-2
Denis

I can't agree with you.

Apache Ignite is the compute platform. It means that an exception on a
server node looks like an alarm that something went wrong or even broken.
I think if we can catch the mistake from user request and return the
correct response (e.g. with error code) is good enough and does not require
throw the exception on nodes.
From the that standpoint the WARNING or even DEBUG is most suitable level
to report such issues. Same approach may be used more widely for instance
for wrong sql syntax.





On Fri, Dec 14, 2018 at 9:35 PM Denis Magda <[hidden email]> wrote:

> Hello Ilya,
>
> It's fine to use ERROR level if an operation can't be completed due to
> missing parameters. That's, in fact, an exception/error. What needs to be
> changed is texts of messages so that everyone understands what exactly
> happened and how to address a failure.
>
> --
> Denis
>
>
> On Fri, Dec 14, 2018 at 5:45 AM Ilya Kasnacheev <[hidden email]
> >
> wrote:
>
> > Hello!
> >
> > It seems that we have subj behavior since the earliest days if Apache
> > Ignite.
> >
> > If you send a REST command with error in it (such as missing "keys" for
> > getAll), you will get a nice
> > [2018-10-30 22:22:14,021][ERROR][rest-#61061][GridCacheCommandHandler]
> > Failed to execute cache command: GridRestCacheRequest
> > error in your logs.
> >
> > Which is probably an overkill since ERROR usually means unexpected and
> > severe errors in application code as opposed to user input validation
> > errors.
> >
> > This made worse by the fact that you can have some automatic REST client
> do
> > a lot of incorrect requests, spam your logs with thousands of such
> ERRORs.
> > The error is returned to client but it is also tee'd to log.
> >
> > What we could do:
> > - Move log level from ERROR to WARN or even INFO.
> > - Handle REST user input validation errors differently from Ignite
> internal
> > errors by introducing new exception class, logging it as INFO or maybe
> just
> > returning to user.
> > - Third funny option?
> >
> > WDYT?
> >
> > Regards,
> > --
> > Ilya Kasnacheev
> >
>


--
Sergey Kozlov
GridGain Systems
www.gridgain.com
Reply | Threaded
Open this post in threaded view
|

RE: REST GridCacheCommandHandler writes ERROR in log in case of baduser input

Stanislav Lukyanov
+1.

ERROR and even WARNING messages are often treated as incidents in the production systems.
Ignite produces a lot of these messages though.

I’d suggest the following as a rule of thumb:
- ERROR – we’re sure there is an issue with a node/cluster that needs attention; cluster stability and/or data integrity are in danger
- WARNING – we’re not sure, but something might be wrong – cluster stability and/or data integrity could be in danger; we can’t verify if that’s an error or not, so user attention is needed
- INFO – anything that we’d like to have in the logs which doesn’t indicate an unrecoverable problem (or possibility of it)
- DEBUG – anything that we’d like to have in the logs but which would produce too much logging; can be enabled on testing environments for selected packages though
- TRACE – anything that we’d like to have for deep debugging which probably wouldn’t help anyone but Ignite developers; can produce enormous amount of logs

WDYT?

Stan

From: Sergey Kozlov
Sent: 20 декабря 2018 г. 15:53
To: [hidden email]
Subject: Re: REST GridCacheCommandHandler writes ERROR in log in case of baduser input

Denis

I can't agree with you.

Apache Ignite is the compute platform. It means that an exception on a
server node looks like an alarm that something went wrong or even broken.
I think if we can catch the mistake from user request and return the
correct response (e.g. with error code) is good enough and does not require
throw the exception on nodes.
From the that standpoint the WARNING or even DEBUG is most suitable level
to report such issues. Same approach may be used more widely for instance
for wrong sql syntax.





On Fri, Dec 14, 2018 at 9:35 PM Denis Magda <[hidden email]> wrote:

> Hello Ilya,
>
> It's fine to use ERROR level if an operation can't be completed due to
> missing parameters. That's, in fact, an exception/error. What needs to be
> changed is texts of messages so that everyone understands what exactly
> happened and how to address a failure.
>
> --
> Denis
>
>
> On Fri, Dec 14, 2018 at 5:45 AM Ilya Kasnacheev <[hidden email]
> >
> wrote:
>
> > Hello!
> >
> > It seems that we have subj behavior since the earliest days if Apache
> > Ignite.
> >
> > If you send a REST command with error in it (such as missing "keys" for
> > getAll), you will get a nice
> > [2018-10-30 22:22:14,021][ERROR][rest-#61061][GridCacheCommandHandler]
> > Failed to execute cache command: GridRestCacheRequest
> > error in your logs.
> >
> > Which is probably an overkill since ERROR usually means unexpected and
> > severe errors in application code as opposed to user input validation
> > errors.
> >
> > This made worse by the fact that you can have some automatic REST client
> do
> > a lot of incorrect requests, spam your logs with thousands of such
> ERRORs.
> > The error is returned to client but it is also tee'd to log.
> >
> > What we could do:
> > - Move log level from ERROR to WARN or even INFO.
> > - Handle REST user input validation errors differently from Ignite
> internal
> > errors by introducing new exception class, logging it as INFO or maybe
> just
> > returning to user.
> > - Third funny option?
> >
> > WDYT?
> >
> > Regards,
> > --
> > Ilya Kasnacheev
> >
>


--
Sergey Kozlov
GridGain Systems
www.gridgain.com

Reply | Threaded
Open this post in threaded view
|

Re: REST GridCacheCommandHandler writes ERROR in log in case of baduser input

Ilya Kasnacheev
Hello!

Where should user-specified SQL errors and REST call parameter errors fall
in this scheme?

Regards,
--
Ilya Kasnacheev


чт, 20 дек. 2018 г. в 16:12, Stanislav Lukyanov <[hidden email]>:

> +1.
>
> ERROR and even WARNING messages are often treated as incidents in the
> production systems.
> Ignite produces a lot of these messages though.
>
> I’d suggest the following as a rule of thumb:
> - ERROR – we’re sure there is an issue with a node/cluster that needs
> attention; cluster stability and/or data integrity are in danger
> - WARNING – we’re not sure, but something might be wrong – cluster
> stability and/or data integrity could be in danger; we can’t verify if
> that’s an error or not, so user attention is needed
> - INFO – anything that we’d like to have in the logs which doesn’t
> indicate an unrecoverable problem (or possibility of it)
> - DEBUG – anything that we’d like to have in the logs but which would
> produce too much logging; can be enabled on testing environments for
> selected packages though
> - TRACE – anything that we’d like to have for deep debugging which
> probably wouldn’t help anyone but Ignite developers; can produce enormous
> amount of logs
>
> WDYT?
>
> Stan
>
> From: Sergey Kozlov
> Sent: 20 декабря 2018 г. 15:53
> To: [hidden email]
> Subject: Re: REST GridCacheCommandHandler writes ERROR in log in case of
> baduser input
>
> Denis
>
> I can't agree with you.
>
> Apache Ignite is the compute platform. It means that an exception on a
> server node looks like an alarm that something went wrong or even broken.
> I think if we can catch the mistake from user request and return the
> correct response (e.g. with error code) is good enough and does not require
> throw the exception on nodes.
> From the that standpoint the WARNING or even DEBUG is most suitable level
> to report such issues. Same approach may be used more widely for instance
> for wrong sql syntax.
>
>
>
>
>
> On Fri, Dec 14, 2018 at 9:35 PM Denis Magda <[hidden email]> wrote:
>
> > Hello Ilya,
> >
> > It's fine to use ERROR level if an operation can't be completed due to
> > missing parameters. That's, in fact, an exception/error. What needs to be
> > changed is texts of messages so that everyone understands what exactly
> > happened and how to address a failure.
> >
> > --
> > Denis
> >
> >
> > On Fri, Dec 14, 2018 at 5:45 AM Ilya Kasnacheev <
> [hidden email]
> > >
> > wrote:
> >
> > > Hello!
> > >
> > > It seems that we have subj behavior since the earliest days if Apache
> > > Ignite.
> > >
> > > If you send a REST command with error in it (such as missing "keys" for
> > > getAll), you will get a nice
> > > [2018-10-30 22:22:14,021][ERROR][rest-#61061][GridCacheCommandHandler]
> > > Failed to execute cache command: GridRestCacheRequest
> > > error in your logs.
> > >
> > > Which is probably an overkill since ERROR usually means unexpected and
> > > severe errors in application code as opposed to user input validation
> > > errors.
> > >
> > > This made worse by the fact that you can have some automatic REST
> client
> > do
> > > a lot of incorrect requests, spam your logs with thousands of such
> > ERRORs.
> > > The error is returned to client but it is also tee'd to log.
> > >
> > > What we could do:
> > > - Move log level from ERROR to WARN or even INFO.
> > > - Handle REST user input validation errors differently from Ignite
> > internal
> > > errors by introducing new exception class, logging it as INFO or maybe
> > just
> > > returning to user.
> > > - Third funny option?
> > >
> > > WDYT?
> > >
> > > Regards,
> > > --
> > > Ilya Kasnacheev
> > >
> >
>
>
> --
> Sergey Kozlov
> GridGain Systems
> www.gridgain.com
>
>
Reply | Threaded
Open this post in threaded view
|

RE: REST GridCacheCommandHandler writes ERROR in log in case ofbaduser input

Stanislav Lukyanov
I think that the error detected in the server’s SQL engine is INFO or even DEBUG – for the server it is just a normal workflow.

At the same time the error needs to be propagated to the client – and shown to the user as an exception, error code in the response, etc.

Stan

From: Ilya Kasnacheev
Sent: 20 декабря 2018 г. 16:31
To: [hidden email]
Subject: Re: REST GridCacheCommandHandler writes ERROR in log in case ofbaduser input

Hello!

Where should user-specified SQL errors and REST call parameter errors fall
in this scheme?

Regards,
--
Ilya Kasnacheev


чт, 20 дек. 2018 г. в 16:12, Stanislav Lukyanov <[hidden email]>:

> +1.
>
> ERROR and even WARNING messages are often treated as incidents in the
> production systems.
> Ignite produces a lot of these messages though.
>
> I’d suggest the following as a rule of thumb:
> - ERROR – we’re sure there is an issue with a node/cluster that needs
> attention; cluster stability and/or data integrity are in danger
> - WARNING – we’re not sure, but something might be wrong – cluster
> stability and/or data integrity could be in danger; we can’t verify if
> that’s an error or not, so user attention is needed
> - INFO – anything that we’d like to have in the logs which doesn’t
> indicate an unrecoverable problem (or possibility of it)
> - DEBUG – anything that we’d like to have in the logs but which would
> produce too much logging; can be enabled on testing environments for
> selected packages though
> - TRACE – anything that we’d like to have for deep debugging which
> probably wouldn’t help anyone but Ignite developers; can produce enormous
> amount of logs
>
> WDYT?
>
> Stan
>
> From: Sergey Kozlov
> Sent: 20 декабря 2018 г. 15:53
> To: [hidden email]
> Subject: Re: REST GridCacheCommandHandler writes ERROR in log in case of
> baduser input
>
> Denis
>
> I can't agree with you.
>
> Apache Ignite is the compute platform. It means that an exception on a
> server node looks like an alarm that something went wrong or even broken.
> I think if we can catch the mistake from user request and return the
> correct response (e.g. with error code) is good enough and does not require
> throw the exception on nodes.
> From the that standpoint the WARNING or even DEBUG is most suitable level
> to report such issues. Same approach may be used more widely for instance
> for wrong sql syntax.
>
>
>
>
>
> On Fri, Dec 14, 2018 at 9:35 PM Denis Magda <[hidden email]> wrote:
>
> > Hello Ilya,
> >
> > It's fine to use ERROR level if an operation can't be completed due to
> > missing parameters. That's, in fact, an exception/error. What needs to be
> > changed is texts of messages so that everyone understands what exactly
> > happened and how to address a failure.
> >
> > --
> > Denis
> >
> >
> > On Fri, Dec 14, 2018 at 5:45 AM Ilya Kasnacheev <
> [hidden email]
> > >
> > wrote:
> >
> > > Hello!
> > >
> > > It seems that we have subj behavior since the earliest days if Apache
> > > Ignite.
> > >
> > > If you send a REST command with error in it (such as missing "keys" for
> > > getAll), you will get a nice
> > > [2018-10-30 22:22:14,021][ERROR][rest-#61061][GridCacheCommandHandler]
> > > Failed to execute cache command: GridRestCacheRequest
> > > error in your logs.
> > >
> > > Which is probably an overkill since ERROR usually means unexpected and
> > > severe errors in application code as opposed to user input validation
> > > errors.
> > >
> > > This made worse by the fact that you can have some automatic REST
> client
> > do
> > > a lot of incorrect requests, spam your logs with thousands of such
> > ERRORs.
> > > The error is returned to client but it is also tee'd to log.
> > >
> > > What we could do:
> > > - Move log level from ERROR to WARN or even INFO.
> > > - Handle REST user input validation errors differently from Ignite
> > internal
> > > errors by introducing new exception class, logging it as INFO or maybe
> > just
> > > returning to user.
> > > - Third funny option?
> > >
> > > WDYT?
> > >
> > > Regards,
> > > --
> > > Ilya Kasnacheev
> > >
> >
>
>
> --
> Sergey Kozlov
> GridGain Systems
> www.gridgain.com
>
>

Reply | Threaded
Open this post in threaded view
|

Re: REST GridCacheCommandHandler writes ERROR in log in case ofbaduser input

Ilya Kasnacheev
Hello!

We often rely on server nodes' logs since there is always possibility that
client will swallow our error, especially when we discover internal errors.

We could try and isolate cases when we are sure that there is error on user
side, change log level for such errors.

Regards,
--
Ilya Kasnacheev


чт, 20 дек. 2018 г. в 17:20, Stanislav Lukyanov <[hidden email]>:

> I think that the error detected in the server’s SQL engine is INFO or even
> DEBUG – for the server it is just a normal workflow.
>
> At the same time the error needs to be propagated to the client – and
> shown to the user as an exception, error code in the response, etc.
>
> Stan
>
> From: Ilya Kasnacheev
> Sent: 20 декабря 2018 г. 16:31
> To: [hidden email]
> Subject: Re: REST GridCacheCommandHandler writes ERROR in log in case
> ofbaduser input
>
> Hello!
>
> Where should user-specified SQL errors and REST call parameter errors fall
> in this scheme?
>
> Regards,
> --
> Ilya Kasnacheev
>
>
> чт, 20 дек. 2018 г. в 16:12, Stanislav Lukyanov <[hidden email]>:
>
> > +1.
> >
> > ERROR and even WARNING messages are often treated as incidents in the
> > production systems.
> > Ignite produces a lot of these messages though.
> >
> > I’d suggest the following as a rule of thumb:
> > - ERROR – we’re sure there is an issue with a node/cluster that needs
> > attention; cluster stability and/or data integrity are in danger
> > - WARNING – we’re not sure, but something might be wrong – cluster
> > stability and/or data integrity could be in danger; we can’t verify if
> > that’s an error or not, so user attention is needed
> > - INFO – anything that we’d like to have in the logs which doesn’t
> > indicate an unrecoverable problem (or possibility of it)
> > - DEBUG – anything that we’d like to have in the logs but which would
> > produce too much logging; can be enabled on testing environments for
> > selected packages though
> > - TRACE – anything that we’d like to have for deep debugging which
> > probably wouldn’t help anyone but Ignite developers; can produce enormous
> > amount of logs
> >
> > WDYT?
> >
> > Stan
> >
> > From: Sergey Kozlov
> > Sent: 20 декабря 2018 г. 15:53
> > To: [hidden email]
> > Subject: Re: REST GridCacheCommandHandler writes ERROR in log in case of
> > baduser input
> >
> > Denis
> >
> > I can't agree with you.
> >
> > Apache Ignite is the compute platform. It means that an exception on a
> > server node looks like an alarm that something went wrong or even broken.
> > I think if we can catch the mistake from user request and return the
> > correct response (e.g. with error code) is good enough and does not
> require
> > throw the exception on nodes.
> > From the that standpoint the WARNING or even DEBUG is most suitable level
> > to report such issues. Same approach may be used more widely for instance
> > for wrong sql syntax.
> >
> >
> >
> >
> >
> > On Fri, Dec 14, 2018 at 9:35 PM Denis Magda <[hidden email]> wrote:
> >
> > > Hello Ilya,
> > >
> > > It's fine to use ERROR level if an operation can't be completed due to
> > > missing parameters. That's, in fact, an exception/error. What needs to
> be
> > > changed is texts of messages so that everyone understands what exactly
> > > happened and how to address a failure.
> > >
> > > --
> > > Denis
> > >
> > >
> > > On Fri, Dec 14, 2018 at 5:45 AM Ilya Kasnacheev <
> > [hidden email]
> > > >
> > > wrote:
> > >
> > > > Hello!
> > > >
> > > > It seems that we have subj behavior since the earliest days if Apache
> > > > Ignite.
> > > >
> > > > If you send a REST command with error in it (such as missing "keys"
> for
> > > > getAll), you will get a nice
> > > > [2018-10-30
> 22:22:14,021][ERROR][rest-#61061][GridCacheCommandHandler]
> > > > Failed to execute cache command: GridRestCacheRequest
> > > > error in your logs.
> > > >
> > > > Which is probably an overkill since ERROR usually means unexpected
> and
> > > > severe errors in application code as opposed to user input validation
> > > > errors.
> > > >
> > > > This made worse by the fact that you can have some automatic REST
> > client
> > > do
> > > > a lot of incorrect requests, spam your logs with thousands of such
> > > ERRORs.
> > > > The error is returned to client but it is also tee'd to log.
> > > >
> > > > What we could do:
> > > > - Move log level from ERROR to WARN or even INFO.
> > > > - Handle REST user input validation errors differently from Ignite
> > > internal
> > > > errors by introducing new exception class, logging it as INFO or
> maybe
> > > just
> > > > returning to user.
> > > > - Third funny option?
> > > >
> > > > WDYT?
> > > >
> > > > Regards,
> > > > --
> > > > Ilya Kasnacheev
> > > >
> > >
> >
> >
> > --
> > Sergey Kozlov
> > GridGain Systems
> > www.gridgain.com
> >
> >
>
>
Reply | Threaded
Open this post in threaded view
|

RE: REST GridCacheCommandHandler writes ERROR in log in caseofbaduser input

Stanislav Lukyanov
In reply to this post by Stanislav Lukyanov
More food for thought - here are JCL guidelines that look close to what I’ve suggested:
http://commons.apache.org/proper/commons-logging/guide.html#JCL_Best_Practices

Big thanks to Oleg Ignatenko for the pointer.

Thanks,
Stan

From: Stanislav Lukyanov
Sent: 20 декабря 2018 г. 17:20
To: [hidden email]
Subject: RE: REST GridCacheCommandHandler writes ERROR in log in caseofbaduser input

I think that the error detected in the server’s SQL engine is INFO or even DEBUG – for the server it is just a normal workflow.

At the same time the error needs to be propagated to the client – and shown to the user as an exception, error code in the response, etc.

Stan

From: Ilya Kasnacheev
Sent: 20 декабря 2018 г. 16:31
To: [hidden email]
Subject: Re: REST GridCacheCommandHandler writes ERROR in log in case ofbaduser input

Hello!

Where should user-specified SQL errors and REST call parameter errors fall
in this scheme?

Regards,
--
Ilya Kasnacheev


чт, 20 дек. 2018 г. в 16:12, Stanislav Lukyanov <[hidden email]>:

> +1.
>
> ERROR and even WARNING messages are often treated as incidents in the
> production systems.
> Ignite produces a lot of these messages though.
>
> I’d suggest the following as a rule of thumb:
> - ERROR – we’re sure there is an issue with a node/cluster that needs
> attention; cluster stability and/or data integrity are in danger
> - WARNING – we’re not sure, but something might be wrong – cluster
> stability and/or data integrity could be in danger; we can’t verify if
> that’s an error or not, so user attention is needed
> - INFO – anything that we’d like to have in the logs which doesn’t
> indicate an unrecoverable problem (or possibility of it)
> - DEBUG – anything that we’d like to have in the logs but which would
> produce too much logging; can be enabled on testing environments for
> selected packages though
> - TRACE – anything that we’d like to have for deep debugging which
> probably wouldn’t help anyone but Ignite developers; can produce enormous
> amount of logs
>
> WDYT?
>
> Stan
>
> From: Sergey Kozlov
> Sent: 20 декабря 2018 г. 15:53
> To: [hidden email]
> Subject: Re: REST GridCacheCommandHandler writes ERROR in log in case of
> baduser input
>
> Denis
>
> I can't agree with you.
>
> Apache Ignite is the compute platform. It means that an exception on a
> server node looks like an alarm that something went wrong or even broken.
> I think if we can catch the mistake from user request and return the
> correct response (e.g. with error code) is good enough and does not require
> throw the exception on nodes.
> From the that standpoint the WARNING or even DEBUG is most suitable level
> to report such issues. Same approach may be used more widely for instance
> for wrong sql syntax.
>
>
>
>
>
> On Fri, Dec 14, 2018 at 9:35 PM Denis Magda <[hidden email]> wrote:
>
> > Hello Ilya,
> >
> > It's fine to use ERROR level if an operation can't be completed due to
> > missing parameters. That's, in fact, an exception/error. What needs to be
> > changed is texts of messages so that everyone understands what exactly
> > happened and how to address a failure.
> >
> > --
> > Denis
> >
> >
> > On Fri, Dec 14, 2018 at 5:45 AM Ilya Kasnacheev <
> [hidden email]
> > >
> > wrote:
> >
> > > Hello!
> > >
> > > It seems that we have subj behavior since the earliest days if Apache
> > > Ignite.
> > >
> > > If you send a REST command with error in it (such as missing "keys" for
> > > getAll), you will get a nice
> > > [2018-10-30 22:22:14,021][ERROR][rest-#61061][GridCacheCommandHandler]
> > > Failed to execute cache command: GridRestCacheRequest
> > > error in your logs.
> > >
> > > Which is probably an overkill since ERROR usually means unexpected and
> > > severe errors in application code as opposed to user input validation
> > > errors.
> > >
> > > This made worse by the fact that you can have some automatic REST
> client
> > do
> > > a lot of incorrect requests, spam your logs with thousands of such
> > ERRORs.
> > > The error is returned to client but it is also tee'd to log.
> > >
> > > What we could do:
> > > - Move log level from ERROR to WARN or even INFO.
> > > - Handle REST user input validation errors differently from Ignite
> > internal
> > > errors by introducing new exception class, logging it as INFO or maybe
> > just
> > > returning to user.
> > > - Third funny option?
> > >
> > > WDYT?
> > >
> > > Regards,
> > > --
> > > Ilya Kasnacheev
> > >
> >
>
>
> --
> Sergey Kozlov
> GridGain Systems
> www.gridgain.com
>
>


Reply | Threaded
Open this post in threaded view
|

RE: REST GridCacheCommandHandler writes ERROR in log in caseofbaduser input

Stanislav Lukyanov
In reply to this post by Ilya Kasnacheev
I agree that the status quo is that all info is at least visible in the Ignite server logs,
so I’d avoid making current ERROR/WARN messages DEBUG for now.

INFO is safe though – we’ll be able to debug things same as now, but monitoring
systems won’t complain about our unnecessarily red log.

Stan

From: Ilya Kasnacheev
Sent: 20 декабря 2018 г. 17:25
To: [hidden email]
Subject: Re: REST GridCacheCommandHandler writes ERROR in log in caseofbaduser input

Hello!

We often rely on server nodes' logs since there is always possibility that
client will swallow our error, especially when we discover internal errors.

We could try and isolate cases when we are sure that there is error on user
side, change log level for such errors.

Regards,
--
Ilya Kasnacheev


чт, 20 дек. 2018 г. в 17:20, Stanislav Lukyanov <[hidden email]>:

> I think that the error detected in the server’s SQL engine is INFO or even
> DEBUG – for the server it is just a normal workflow.
>
> At the same time the error needs to be propagated to the client – and
> shown to the user as an exception, error code in the response, etc.
>
> Stan
>
> From: Ilya Kasnacheev
> Sent: 20 декабря 2018 г. 16:31
> To: [hidden email]
> Subject: Re: REST GridCacheCommandHandler writes ERROR in log in case
> ofbaduser input
>
> Hello!
>
> Where should user-specified SQL errors and REST call parameter errors fall
> in this scheme?
>
> Regards,
> --
> Ilya Kasnacheev
>
>
> чт, 20 дек. 2018 г. в 16:12, Stanislav Lukyanov <[hidden email]>:
>
> > +1.
> >
> > ERROR and even WARNING messages are often treated as incidents in the
> > production systems.
> > Ignite produces a lot of these messages though.
> >
> > I’d suggest the following as a rule of thumb:
> > - ERROR – we’re sure there is an issue with a node/cluster that needs
> > attention; cluster stability and/or data integrity are in danger
> > - WARNING – we’re not sure, but something might be wrong – cluster
> > stability and/or data integrity could be in danger; we can’t verify if
> > that’s an error or not, so user attention is needed
> > - INFO – anything that we’d like to have in the logs which doesn’t
> > indicate an unrecoverable problem (or possibility of it)
> > - DEBUG – anything that we’d like to have in the logs but which would
> > produce too much logging; can be enabled on testing environments for
> > selected packages though
> > - TRACE – anything that we’d like to have for deep debugging which
> > probably wouldn’t help anyone but Ignite developers; can produce enormous
> > amount of logs
> >
> > WDYT?
> >
> > Stan
> >
> > From: Sergey Kozlov
> > Sent: 20 декабря 2018 г. 15:53
> > To: [hidden email]
> > Subject: Re: REST GridCacheCommandHandler writes ERROR in log in case of
> > baduser input
> >
> > Denis
> >
> > I can't agree with you.
> >
> > Apache Ignite is the compute platform. It means that an exception on a
> > server node looks like an alarm that something went wrong or even broken.
> > I think if we can catch the mistake from user request and return the
> > correct response (e.g. with error code) is good enough and does not
> require
> > throw the exception on nodes.
> > From the that standpoint the WARNING or even DEBUG is most suitable level
> > to report such issues. Same approach may be used more widely for instance
> > for wrong sql syntax.
> >
> >
> >
> >
> >
> > On Fri, Dec 14, 2018 at 9:35 PM Denis Magda <[hidden email]> wrote:
> >
> > > Hello Ilya,
> > >
> > > It's fine to use ERROR level if an operation can't be completed due to
> > > missing parameters. That's, in fact, an exception/error. What needs to
> be
> > > changed is texts of messages so that everyone understands what exactly
> > > happened and how to address a failure.
> > >
> > > --
> > > Denis
> > >
> > >
> > > On Fri, Dec 14, 2018 at 5:45 AM Ilya Kasnacheev <
> > [hidden email]
> > > >
> > > wrote:
> > >
> > > > Hello!
> > > >
> > > > It seems that we have subj behavior since the earliest days if Apache
> > > > Ignite.
> > > >
> > > > If you send a REST command with error in it (such as missing "keys"
> for
> > > > getAll), you will get a nice
> > > > [2018-10-30
> 22:22:14,021][ERROR][rest-#61061][GridCacheCommandHandler]
> > > > Failed to execute cache command: GridRestCacheRequest
> > > > error in your logs.
> > > >
> > > > Which is probably an overkill since ERROR usually means unexpected
> and
> > > > severe errors in application code as opposed to user input validation
> > > > errors.
> > > >
> > > > This made worse by the fact that you can have some automatic REST
> > client
> > > do
> > > > a lot of incorrect requests, spam your logs with thousands of such
> > > ERRORs.
> > > > The error is returned to client but it is also tee'd to log.
> > > >
> > > > What we could do:
> > > > - Move log level from ERROR to WARN or even INFO.
> > > > - Handle REST user input validation errors differently from Ignite
> > > internal
> > > > errors by introducing new exception class, logging it as INFO or
> maybe
> > > just
> > > > returning to user.
> > > > - Third funny option?
> > > >
> > > > WDYT?
> > > >
> > > > Regards,
> > > > --
> > > > Ilya Kasnacheev
> > > >
> > >
> >
> >
> > --
> > Sergey Kozlov
> > GridGain Systems
> > www.gridgain.com
> >
> >
>
>

Reply | Threaded
Open this post in threaded view
|

RE: REST GridCacheCommandHandler writes ERROR in log in caseofbaduser input

Gerus
I think that this case is serious gap in Ignite maintainability
1. This is business as usual case and client application can create an
incorrect API call. User error should be returned back to user via the same
API
2. Exception in the Ignite log file should cause an alert for application
operations. Most common case for monitoring setup is to parse log file in
realtime and create an incident in case if ERROR or Exception is detected.
The only way for admin is to mute the false alert, and
3. Current approach is adding a lot of noise into the application logs and
significantly increasing logfile size. Taking in account log rotation as a
good practice, we may have less useful information to maintain Ignite



--
Sent from: http://apache-ignite-developers.2346864.n4.nabble.com/
Reply | Threaded
Open this post in threaded view
|

Re: REST GridCacheCommandHandler writes ERROR in log in caseofbaduser input

Ilya Kasnacheev
Hello!

1. Unfortunately, it's complicated:
- With JDBC, we don't really offer complete reasoning for a problem,
*especially* if it is Ignite internal problem or expectations mismatch,
which is frequent case.
- With ODBC, we don't have ways to offer full Java stack trace to client,
neither expectations that client will display them anywhere.
- With HTTP client will usually disconnect as soon it sees 500 status code,
and will swallow error messages even if we had them.
- With other platforms' clients I assume we will lose error messages almost
always.

In short this will mean that error messages will be unrecovered when people
come with their issues but they have default logging.

2. Malfunctioning client is usually a case for alert. Most of Ignite
installations are single-purpose, and if there are errors in log there must
be problems with this sole purpose.

3. It's hard to remove noise but keep useful information. Maybe we could
throttle such messages?

We could try and create an IEP about those logging concerns.

Regards,
--
Ilya Kasnacheev


сб, 29 дек. 2018 г. в 13:34, Gerus <[hidden email]>:

> I think that this case is serious gap in Ignite maintainability
> 1. This is business as usual case and client application can create an
> incorrect API call. User error should be returned back to user via the same
> API
> 2. Exception in the Ignite log file should cause an alert for application
> operations. Most common case for monitoring setup is to parse log file in
> realtime and create an incident in case if ERROR or Exception is detected.
> The only way for admin is to mute the false alert, and
> 3. Current approach is adding a lot of noise into the application logs and
> significantly increasing logfile size. Taking in account log rotation as a
> good practice, we may have less useful information to maintain Ignite
>
>
>
> --
> Sent from: http://apache-ignite-developers.2346864.n4.nabble.com/
>
Reply | Threaded
Open this post in threaded view
|

Re: REST GridCacheCommandHandler writes ERROR in log in caseofbaduser input

Ilya Kasnacheev
Hello!

I have found one more relevant case:

[17:03:16,141][SEVERE][jdbc-request-handler-worker-#78][JdbcRequestHandler]
Failed to execute SQL query [reqId=0, req=JdbcQueryExecuteRequest
[schemaName=PUBLIC, pageSize=1024, maxRows=0, sqlQry=merge INTO
city2(id,name,name1) VALUES(2,'1','1'),(1,'1','1'), args=[],
stmtType=UPDATE_STMT_TYPE, autoCommit=true]]
class org.apache.ignite.internal.processors.query.IgniteSQLException:
Cannot serialize transaction due to write conflict (transaction is marked
for rollback)
        at
org.apache.ignite.internal.processors.cache.GridCacheMapEntry.serializationError(GridCacheMapEntry.java:6759)
        at
org.apache.ignite.internal.processors.cache.GridCacheMapEntry.mvccSet(GridCacheMapEntry.java:1117)

MVCC update conflicts are entirely normal, and will never be a case of
concern of DevOps since they are recoverable (just retry the statement or
batch).

There's no reason for such SEVERE log level. This one should only merit an
INFO.

Regards,
--
Ilya Kasnacheev


пт, 11 янв. 2019 г. в 19:26, Ilya Kasnacheev <[hidden email]>:

> Hello!
>
> 1. Unfortunately, it's complicated:
> - With JDBC, we don't really offer complete reasoning for a problem,
> *especially* if it is Ignite internal problem or expectations mismatch,
> which is frequent case.
> - With ODBC, we don't have ways to offer full Java stack trace to client,
> neither expectations that client will display them anywhere.
> - With HTTP client will usually disconnect as soon it sees 500 status
> code, and will swallow error messages even if we had them.
> - With other platforms' clients I assume we will lose error messages
> almost always.
>
> In short this will mean that error messages will be unrecovered when
> people come with their issues but they have default logging.
>
> 2. Malfunctioning client is usually a case for alert. Most of Ignite
> installations are single-purpose, and if there are errors in log there must
> be problems with this sole purpose.
>
> 3. It's hard to remove noise but keep useful information. Maybe we could
> throttle such messages?
>
> We could try and create an IEP about those logging concerns.
>
> Regards,
> --
> Ilya Kasnacheev
>
>
> сб, 29 дек. 2018 г. в 13:34, Gerus <[hidden email]>:
>
>> I think that this case is serious gap in Ignite maintainability
>> 1. This is business as usual case and client application can create an
>> incorrect API call. User error should be returned back to user via the
>> same
>> API
>> 2. Exception in the Ignite log file should cause an alert for application
>> operations. Most common case for monitoring setup is to parse log file in
>> realtime and create an incident in case if ERROR or Exception is detected.
>> The only way for admin is to mute the false alert, and
>> 3. Current approach is adding a lot of noise into the application logs and
>> significantly increasing logfile size. Taking in account log rotation as a
>> good practice, we may have less useful information to maintain Ignite
>>
>>
>>
>> --
>> Sent from: http://apache-ignite-developers.2346864.n4.nabble.com/
>>
>