We're noticing an issue an issue where actions that are done in quick succession only generate 1 event with the last state of the interface.

For example, issuing the following commands against a CCR-1009 using mikronode-ng
results in only 1 event returned reflecting the last state if the interface...
The exchange was verified with wireshark. 2 'done' sentences are received but only 1 event.

While this isn't a real production scenario there are cases where actions in quick succession are needed and the lack of discrete events is troublesome.

Happens on devices using version 6.34 and greater at least. Can't check any versions earlier than that right now.

Thoughts?

There are these things known as "tags", intended to make such cases more workable. The exact API word being ".tag=name" (where "name" can be an arbitrary string).

One of the commands would need to have a tag, so that the API client can monitor for events per tag. When each call includes its own unique tag, the API client can process the replies regardless of the order they come in.

In my API client, I require all async calls to include a unique tag (and fail if not), and only allow tag omission for synchronous ones (triggered with a separate method). This policy ensures you can never end up with a !done reply, and not know what to do about it.

This NodeJS client (and many other API clients in general BTW) don't seem to follow this policy though. Instead, it seems that they treat all API calls as synchronous - each new command creates a new event stream, and each !done reply closes the first opened event stream, but that's just not a correct implementation. This is a problem of the API client, which should be modified to enforce tags at some particular point (perhaps as an optional 3rd argument and/or a separate method where the tag is required), and call the appropriate callback based on the tag in the reply.

Well, this isn't really a tags issue. Even if I issue the command on 2 different tags, I still only get 1 event from /interface/listen.

Anyway, mikronode-ng serializes commands on the same channel(tag). The next command on the channel doesn't get sent until previous one gets a 'done'. If you want parallel commands, you use multiple channels.

What about ?

It should be equivalent to "/listen", but I don't know... certainly, neither is supposed to ever give off a !done reply, unless a "/cancel" for it is issued.

If tags are indeed used per channel, then it seems the real bug is that the second command is sent, despite the fact that, as you say, it shouldn't be... Since the "/listen" is never really finished on its own.

Maybe the API client is assuming that if it doesn't get any data within a timeout, the command was done anyway? "/listen" could have long stretches of not sending back any data you know, while in the meantime, other commands can potentially be started and be complete over the same connection.

Let me clarify...

The /interface/listen` is being done in a separate process whose sole job is to print the events. In the other process, the second command is sent only when the first command returns the 'done'. If I put a sleep of 200ms between the 2 commands, i get 2 events. It's almost as though whatever thread is sending the events only wakes up every 100ms and sends the current state of an object if a change was detected.

That confuses me more, as I don't think you mean "process" as in an actual OS "process"... I'm pretty sure it's not possible for two processes ("process" being the OS term...) to use the same TCP connection.

So when you say "process"...? You mean two independent JavaScript functions, which both run asynchronously?

Yeah, I think Node runs these two in two different threads ("thread" again being the OS term), and AFAIK, the "data" event on the socket occurs in its own thread.

Hmmm... err... this comment in the source might shed some light on the matter... The "hope" there doesn't sound like what's exactly happening. The router might send multiple sentences at once (i.e. inside one "data" event), with each sentence belonging to a different tag (i.e. channel), or the second sentence might be partially sent in one firing of the "data" event, with the rest in another "data" event altogether, and you can never be truly sure where you are when the "data" event is triggered, without specifically keeping track of ALL the boundaries in the client.

Instead, it appears the client merely checks if it's within a word, and resumes the last sentence if it is... But that's not enough. Only one sentence is created per emitted "data" event, when it should instead attempt to read multiple sentences if possible.

That confuses me more, as I don't think you mean "process" as in an actual OS "process"... I'm pretty sure it's not possible for two processes ("process" being the OS term...) to use the same TCP connection.

Yes, 2 different OS processes. The listener process opens it's own connection to the device and is keeping track of all interface events.

So when you say "process"...? You mean two independent JavaScript functions, which both run asynchronously?

Nope. See previous. Even if the listener is in the same process using it's own tag, the issue still occurs.

Yeah, I think Node runs these two in two different threads ("thread" again being the OS term), and AFAIK, the "data" event on the socket occurs in its own thread.

Node runs all user javascript code in a single thread. node itself does all it's work on separate threads.

Hmmm... err... this comment in the source might shed some light on the matter... The "hope" there doesn't sound like what's exactly happening. The router might send multiple sentences at once (i.e. inside one "data" event), with each sentence belonging to a different tag (i.e. channel), or the second sentence might be partially sent in one firing of the "data" event, with the rest in another "data" event altogether, and you can never be truly sure where you are when the "data" event is triggered, without specifically keeping track of ALL the boundaries in the client.

Instead, it appears the client merely checks if it's within a word, and resumes the last sentence if it is... But that's not enough. Only one sentence is created per emitted "data" event, when it should instead attempt to read multiple sentences if possible.

I should have removed that note when I re-wrote those bits. mikronode-ng does handle multiple events. It returns them as an array of events. Besides, I did verify with Wireshark that only 1 event is generated.

I've opened a support ticket with Mikrotik.

Aaaahhhh.... I see. So the issue is very different than what your first post made it out to be.

So... Let me get this straight... There are two processes, each having its own connection. One process is only listening continuously for modifications, the other process does two modifications in sequence, waiting for the first one to finish before doing the second. Thus you expect the listener process to receive two sentences - one for each modification - but instead you get one.... OK...

So if that's the case, apparently, "/listen" is made to loop over the list, scanning the item list for changes, and give sentences when a change is detected. Because the changes are so quick in succession, the next iteration of the "/listen" loop only arrives by the time the second modification is already done, and thus the first modification does not trigger its own sentence.

If MikroTik really wanted to fix that, they'd have to modify the modification commands ("set", etc.) to trigger listeners, instead of listeners having to monitor the list for changes... That's not exactly the most efficient thing, plus, for interfaces specifically, there are "interface flops" and cable issues, where an interface might rapidly change its state between "connected" and "disconnected". Do you really want tens of thousands of sentences in those events, or would you rather have a few dozen? I think the latter is sufficient. So modifying commands like "set" without also making things worse is tricky (though not impossible).

So... sure, it's a RouterOS issue, but for the "/interface" menu in particular, I wouldn't hold my breath for it being fixed, ever. Here's hoping this issue does not exist in other menus OR that they'd at least fix it there if it does.

GTJ, I hope that you don't mind if I add some findings/logs.

I have tried to work with some other part of MT functionality to see is this a problem only with /interfaces and
created similar script to work with firewall rules and results from this trial are introducing new questions from my side.
I am also using Mikrotik API Studio by Rodolfo Rughi to verify executed commands.

When there is no time wait between commands result is always "disabled":"false"
ACTION:
        sleep.sleep(1);
        console.log('I am here 1');
        actionChannel.write(['/ip/firewall/filter/set','=disabled=yes','=.id=*D']);

//      sleep.usleep(1000000); //Sleep disabled
        console.log('I am here 2');
        actionChannel.write(['/ip/firewall/filter/set','=disabled=no','=.id=*D']);

RESULT:
root@ub64:~# node test5-listen-mt.js
I am here 1
Interface change: [{".id":"*D",".nextid":"*FFFFFFFF","chain":"forward","action":"accept","log":"false","log-prefix":"","invalid":"true","dynamic":"false","disabled":"false","comment":"test"}]
Interface change: [{".id":"*D",".nextid":"*FFFFFFFF","chain":"forward","action":"accept","log":"false","log-prefix":"","invalid":"false","dynamic":"false","disabled":"false","comment":"test"}]
When I introduce small delay of 0,21 sec ( i have tried 0,5 sec also) 3 changes are registered although in MT log only 2 of them are shown.
ACTION:
        sleep.sleep(1);
        console.log('I am here 1');
        actionChannel.write(['/ip/firewall/filter/set','=disabled=yes','=.id=*D']);

        sleep.usleep(210000); //Sleep for 0,21 sec
        console.log('I am here 2');
        actionChannel.write(['/ip/firewall/filter/set','=disabled=no','=.id=*D']);

RESULT:
Interface change: [{".id":"*D",".nextid":"*FFFFFFFF","chain":"forward","action":"accept","log":"false","log-prefix":"","invalid":"true","dynamic":"false","disabled":"true","comment":"test"}]
Interface change: [{".id":"*D",".nextid":"*FFFFFFFF","chain":"forward","action":"accept","log":"false","log-prefix":"","invalid":"true","dynamic":"false","disabled":"false","comment":"test"}]
Interface change: [{".id":"*D",".nextid":"*FFFFFFFF","chain":"forward","action":"accept","log":"false","log-prefix":"","invalid":"false","dynamic":"false","disabled":"false","comment":"test"}]

When pause between commands is 1 second all seem OK.
ACTION:
        sleep.sleep(1);
        console.log('I am here 1');
        actionChannel.write(['/ip/firewall/filter/set','=disabled=yes','=.id=*D']);

        sleep.usleep(1000000); //Sleep for 1 sec
        console.log('I am here 2');
        actionChannel.write(['/ip/firewall/filter/set','=disabled=no','=.id=*D']);

RESULT:
Interface change: [{".id":"*D",".nextid":"*FFFFFFFF","chain":"forward","action":"accept","log":"false","log-prefix":"","invalid":"true","dynamic":"false","disabled":"true","comment":"test"}]
Interface change: [{".id":"*D",".nextid":"*FFFFFFFF","chain":"forward","action":"accept","log":"false","log-prefix":"","invalid":"false","dynamic":"false","disabled":"false","comment":"test"}]


LOG from MT router showing 2 commands executed in each iteration:

13:41:31 system,info,account user admin logged in from 192.168.0.200 via api
13:41:32 system,info filter rule changed by admin
13:41:32 system,info filter rule changed by admin
13:41:32 system,info,account user admin logged out from 192.168.0.200 via api
13:43:29 system,info,account user admin logged in from 192.168.0.200 via api
13:43:30 system,info filter rule changed by admin
13:43:30 system,info filter rule changed by admin
13:43:30 system,info,account user admin logged out from 192.168.0.200 via api
13:43:52 system,info,account user admin logged in from 192.168.0.200 via api
13:43:53 system,info filter rule changed by admin
13:43:53 system,info filter rule changed by admin
13:43:53 system,info,account user admin logged out from 192.168.0.200 via api
13:45:16 system,info,account user admin logged in from 192.168.0.200 via api
13:45:17 system,info filter rule changed by admin
13:45:18 system,info filter rule changed by admin
13:45:18 system,info,account user admin logged out from 192.168.0.200 via api
13:46:11 system,info,account user admin logged in from 192.168.0.200 via api
13:46:12 system,info filter rule changed by admin
13:46:13 system,info filter rule changed by admin
13:46:13 system,info,account user admin logged out from 192.168.0.200 via api

GTJ, I hope that you don't mind if I add some findings/logs.

Not at all, especially since you opened the issue in mikronode-ng. I referenced this thread in the support ticket I created so the more information the better.

Hmmm... Now that you've mentioned the logs... If you were to "/listen" to the logs (or ["/log/print","=follow-only="]), I'm pretty sure you'd get both new sentences (since they persist across the monitoring loop; it's not like the actual interface, where the item is modified by the time the monitor comes around).

It's not exactly a neat workaround, but if you really care about every "blip" in an interface's status, that would at least help with your original problem.
(AFAIK, if you also add "debug" logs, you should also get details on what exactly was changed, not just that it was...)

Hi boen_robot,

To be honest, I don't really need such precision because my planed application will deal with firewall rules only (for now) but it is inconsistency and erratic behavior which is bothering me.
What I expect is if I issue command a result will be shown in same way in all occasions. In this case it isn't.
Active monitoring of firewall rules state is essential in my case where two or more users can change rules in same time. Yes, I can create a check point in application to prevent users to
change rules in same time but this is not the point here.
I don't know is it the same with other API connector languages because I am new to API programming.
New tests are in the queue and we will know more after testing.
BTW, do you know is there a Wireshark packet decoder for API written by someone?

I don't know is it the same with other API connector languages because I am new to API programming.

It probably will be the same regardless of language, since this a problem of sentences not being received, not a problem of them being handled incorrectly (as I first thought with gtj's initial description...).

New tests are in the queue and we will know more after testing.

Here's one for you - I'm curious if the original issue is also a thing... That is, if you have a single connection, and use two channels (two ".tag" sets)  - one for the listen, and another one for the two modifications - do you still have the listen produce just once !re, or does it produce 2 ones in those particular circumstances?

BTW, do you know is there a Wireshark packet decoder for API written by someone?

I don't know of any, but last time I used Wireshark for the API (which was very long ago, and several Wireshark versions have been released since), it parsed API contents as IRC, with each API word being considered a line in the chat... Which isn't that hard to read anyway.

New tests are in the queue and we will know more after testing.

Here's one for you - I'm curious if the original issue is also a thing... That is, if you have a single connection, and use two channels (two ".tag" sets)  - one for the listen, and another one for the two modifications - do you still have the listen produce just once !re, or does it produce 2 ones in those particular circumstances?

Same result. Only 1 sentence is received regardless of whether the same connection or different connections are used.

BTW, do you know is there a Wireshark packet decoder for API written by someone?

I don't know of any, but last time I used Wireshark for the API (which was very long ago, and several Wireshark versions have been released since), it parsed API contents as IRC, with each API word being considered a line in the chat... Which isn't that hard to read anyway.

Tnx boen_robot,

Excellent advice to use IRC as a decoder for the packages. Now it is much easier to read.

Got feedback from MikroTik Support...

If interface state changed few times, message contains only 1 interface change.
It is done to protect router from extensive writes and keep it from out of
memory. We will consider adding some specific counter or similar, for most
important events (like interface change) and notify it by API call