Provide LogSource Operator

[ilanprager]

Per discussion with Streams architecture team, in order to support immediate consumption of Streams log messages for alerting purposes, we'd like to have an operator that can be used to streams the Streams log messages. The operator would subscribe to JMX and expose the messages as structured tuples, making the following available per message:

• Job ID
• PE ID
• Operator ID
• Event timestamp
• Message code
• Message text
• Parameter map (optional)

It's assumed that in most cases, the functionality exists today in the JMX interfaces and is being leveraged is most toolkits, but actually building this source and using it will help determine if there are any gaps in the message subscription mechanism and/or leverage of the appropriate logging by common toolkits.

[ddebrunner]

There is an abstract operator that creates tuples from JMX notifications in the control plane: AbstractNotificationSource [1].

it might provide a path to follow, and it uses NotificationTupleSubmitter [2] which is a generic JMX class to submit a tuple from an JMX notification.

Source to both classes is available (click on their name in the javadoc as well as in the samples jar) and both are part of the api, so may be safely used by primitive operator implementations.

In this case NotificationTupleSubmitter could probably be used as is.

[1] https://www.ibm.com/support/knowledgecenter/en/SSCRJU_4.2.0/com.ibm.streams.spl-java-operators.doc/samples/com/ibm/streams/operator/control/patterns/AbstractNotificationSource.html [2] https://www.ibm.com/support/knowledgecenter/en/SSCRJU_4.2.0/com.ibm.streams.spl-java-operators.doc/samples/com/ibm/streams/operator/control/patterns/NotificationTupleSubmitter.html

[ilanprager]

Thanks @ddebrunner - could you provide specific information (e.g. Object names, method(s) for obtaining the realtime logs)?

[jingdongsun]

Here is Java Doc for JMX related to notification: https://www.ibm.com/support/knowledgecenter/SSCRJU_4.2.0/com.ibm.streams.jmxapi.doc/api/com/ibm/streams/management/Notifications.html Please check "LOG_ERROR" and "LOG_WARNING". In same time, I will talk with Janet (she is off today, and will be back tomorrow) when she back about any details we need to pay attention. Thanks.

[ddebrunner]

@jingdongsun Any idea which MBean raises those notifications?

[ddebrunner]

DomainMXBean raises those notifications - though it's not clear what are the contents of the notification, it says there is no user data ...

https://www.ibm.com/support/knowledgecenter/SSCRJU_4.2.0/com.ibm.streams.jmxapi.doc/api/com/ibm/streams/management/domain/DomainMXBean.html

[jingdongsun]

I think we have message with the notification. Janet not here, so I did not have chance to talk with her about this details. But, I checked the way Console using it, it as below: case Notifications.LOG_ERROR: manager.addLogErrorMessage(notification.getMessage()); break; case Notifications.LOG_WARNING: manager.addLogWarningMessage(notification.getMessage()); notification is a Notification type object, and manager is their (Console's) ListenerManager.

[jingdongsun]

notification.getMessage() return a string

[jingdongsun]

notification.getMessage() returns String

[ilanprager]

@markheger @jingdongsun I'm able to run the MetricsSource and see instance added notifications, but when I try adding the following:

filter.enableType(Notifications.LOG_ERROR);
filter.enableType(Notifications.LOG_NOTIFICATION);
filter.enableType(Notifications.LOG_WARNING);

and then logging:

appTrc(Trace.error,"Got an error here!");

I don't see any notifications show up.

What do I need to do to log messages in a way that they'll show up in notifications?

[ddebrunner]

appTrc is a trace message, you need a log message.

Use appLog.

[ilanprager]

@ddebrunner I now am logging the following and see the message appearing in the PE logs, but I don't see any log notifications:

appLog(Log.error,"Wow I got an error");

Here's what I see in the PE log:

[2017-08-02T17:41:10.376+0300] [127.0.0.1] [domain=StreamsDomain,instance=StreamsInstance,host=localhost,#splapplog,J[20],P[22],MyTestFunctor] Wow I got an error
[2017-08-02T17:41:15.389+0300] [127.0.0.1] [domain=StreamsDomain,instance=StreamsInstance,host=localhost,#splapplog,J[20],P[22],MyTestFunctor] Wow I got an error
[2017-08-02T17:41:20.402+0300] [127.0.0.1] [domain=StreamsDomain,instance=StreamsInstance,host=localhost,#splapplog,J[20],P[22],MyTestFunctor] Wow I got an error

If you have an example where this is working, that would be great - thanks!

[markheger]

@ilanprager : I observed the same as you, that there are no notifications for logs on the DomainMXBean. In the debug traces, the following errors are shown:

02 Aug 2017 16:50:56.658 [27891] DEBUG M[ClientNotifForwarder.init:?:-1] - Failed to register a listener to the mbean server: the client will not do clean when an MBean is unregistered 02 Aug 2017 16:50:56.658 [27891] DEBUG M[?:?:0] - java.lang.ClassCastException: [Ljava.lang.Integer; incompatible with java.lang.Integer 02 Aug 2017 16:50:56.659 [27891] DEBUG M[?:?:0] - javax.management.remote.generic.ClientIntermediary$GenericClientNotifForwarder.addListenerForMBeanRemovedNotif(ClientIntermediary.java:902) 02 Aug 2017 16:50:56.659 [27891] DEBUG M[?:?:0] - com.sun.jmx.remote.opt.internal.ClientNotifForwarder.init(ClientNotifForwarder.java:639) 02 Aug 2017 16:50:56.659 [27891] DEBUG M[?:?:0] - com.sun.jmx.remote.opt.internal.ClientNotifForwarder.addNotificationListener(ClientNotifForwarder.java:91) 02 Aug 2017 16:50:56.659 [27891] DEBUG M[?:?:0] - javax.management.remote.generic.ClientIntermediary.addNotificationListener(ClientIntermediary.java:586) 02 Aug 2017 16:50:56.659 [27891] DEBUG M[?:?:0] - javax.management.remote.generic.GenericConnector$RemoteMBeanServerConnection.addNotificationListener(GenericConnector.java:540) 02 Aug 2017 16:50:56.659 [27891] DEBUG M[?:?:0] - com.ibm.streamsx.monitoring.jobs.internal.DomainHandler.(DomainHandler.java:84) 02 Aug 2017 16:50:56.659 [27891] DEBUG M[?:?:0] - com.ibm.streamsx.monitoring.jobs.JobStatusSource.scanDomain(JobStatusSource.java:594) 02 Aug 2017 16:50:56.660 [27891] DEBUG M[?:?:0] - com.ibm.streamsx.monitoring.jobs.JobStatusSource.initialize(JobStatusSource.java:413) 02 Aug 2017 16:50:56.660 [27891] DEBUG M[?:?:0] - com.ibm.streams.operator.internal.runtime.api.OperatorAdapter.initialize(OperatorAdapter.java:736) 02 Aug 2017 16:50:56.660 [27891] DEBUG M[?:?:0] - com.ibm.streams.operator.internal.jni.JNIBridge.(JNIBridge.java:274)

This belongs to the following line in the DomainHandler class: _operatorConfiguration.get_mbeanServerConnection().addNotificationListener(_objName, this, filter, null);

@jingdongsun Have you any idea, why this error is on debug level only and if this might be related to the problem that notification on domain level are missing.

[jingdongsun]

I will need to ask Janet

[weberjanet]

Using jconsole, I can see notifications for job-related errors being written to the Streams product log. @markheger could you show the call you are making to register the listener? @jingdongsun could you comment on what goes in the PE log verses the Streams product log for job-related errors? The LOG_ERROR notification is for errors written to the Streams product log.

[jingdongsun]

from application, if using appLog, like Ilan tried, log message should write to streams product log, and trigger notification. But, as we have that "1 second" limitation (please check my slack channel thread), the log message may lost if another one came just before and quickly.

[jingdongsun]

I mean, if many (error/warn) log messages generated within a seconds, we will write them to streams product log, but will not do notification to all of them -- notification just happens once a second

[ilanprager]

@jingdongsun I used a Beacon to trigger logging at a period of 0.2 for a few minutes (verified that the log was being called many times) but still not getting any notifications. I'm again able to verify that I do get notifications when I add / remove an instance so I know the log statement I added to DomainHandler is valid. I think a working program demonstrating the logging actually working would be most helpful as a starting point. thanks

[weberjanet]

@ilanprager when you say 'the log' was being called many times, to which log are you referring?

[ddebrunner]

@weberjanet I think @ilanprager means:

appLog(Log.error,"Wow I got an error");

(a few comments up)

[weberjanet]

I see what is happening now. JMX is not getting notified when application messages are being written to the log, only when CDIS messages are being written. I will talk to Jingdong and Steve about this. It will require a code change to make it work the way you want.

[weberjanet]

@ilanprager @markheger @ddebrunner Code has been added so JMX now notifies on application errors and warnings as well as on Streams detected errors/warnings. It was decided to add two new notification types for these: LOG_APPLICATION_WARNING (com.ibm.streams.management.log.application.warning) and LOG_APPLICATION_ERROR (com.ibm.streams.management.log.application.error). This way existing behavior remains unchanged and it is possible to distinguish between application and streams detected log messages. One thing to note, as shown in the screenshot: SPL runtime is treated as part of the application so there can be CDIS messages logged as application warnings/errors. These changes will be part of the next SaS refresh with the REST API start/stop view additions.

[weberjanet]

@ddebrunner The issue discussed was not receiving JMX notifications for errors/warnings being added to the Streams product log as expected. If the code was able to watch for the existing notification types, why would it not be able to watch for the newly added notification types? I included the values of the new types in my previous comment so they can be used if needed.

[markheger]

released with 1.4.0