Log interpretation – scheduling conflict

[Thomas Hermansson]

Hi All!

We are using the Multitech conduit gw and are having some problems with getting the packets out to our nodes. Sometimes it works fine and sometime it takes longer time. We are running all our nodes as Class C nodes and we are operating on the US marked (915Mhz). Below you will find a snippet of the lora-network-server.log and there are a few logs that confuse me.

1. Node has not checked in, or packet is already scheduled, cannot schedule packet.
We are running all nodes as Class C. Node should not have to check in – a transmission should be possible at all times.

2. 8:15:2:237|DEBUG| ED:03-43-4b-4b-50-33-38-20|PACKET-RX|GW:00:80:00:00:a0:00:03:89 Time_us:842151780
It says time_us: 842 seconds? What does that mean. what took 842 seconds? 🙂

3. 8:15:2:276|INFO| TransmitQueue find 879770 879930
What are the two numbers after TransmitQueue – are we having a queue of 897 000 packets that are waiting to be transmitted?

4. 8:15:2:276|INFO| TransmitQueue cannot increase duration
What does it mean? Or what is the implication of it?

5. 8:15:2:277|INFO| ED:18-43-4b-4b-39-32-5f-20|SCHED-TX|DEFER-TX 0600007b RX-WND:1 Scheduling conflict
It appears to me as we here try to send a packet at RX1 window. But why. All units are class C and a packet should be possible to transmit at all times. And what does Scheduling conflict indicate?

6. 8:15:2:277|WARNING| Unschedule frame
I guess this is just a print saying that we failed.

Any help that would point us in the correct direction of what might cause these problems are very much apprechiated.

Kind Regards
Thomas Hermansson
ÅF Technology – Sweden

=======all the logs above can be found in the following raw printout.=====
8:15:2:107|DEBUG| Node::ScheduleSendApplication Class: 2
8:15:2:107|DEBUG| Schedule Class C downlink packet
8:15:2:108|DEBUG| Node::ScheduleSendApplication Class: 2
8:15:2:108|WARNING| Node has not checked in, or packet is already scheduled, cannot schedule packet
8:15:2:118|DEBUG| Node::ScheduleSendApplication Class: 2
8:15:2:139|DEBUG| Schedule Class C downlink packet
8:15:2:151|DEBUG| Node::ScheduleSendApplication Class: 2
8:15:2:152|DEBUG| Schedule Class C downlink packet
8:15:2:184|DEBUG| Node::ScheduleSendApplication Class: 2
8:15:2:184|DEBUG| Schedule Class C downlink packet
8:15:2:233|INFO| GW:00:80:00:00:a0:00:03:89|FRAME-RX|Parsing 1 packets
8:15:2:234|DEBUG| GW:00:80:00:00:a0:00:03:89|FRAME-RX|DATA: 408400000680f903029cceb0b4e1f4a8a91ed860eb04bc
8:15:2:234|DEBUG| GW:00:80:00:00:a0:00:03:89|FRAME-RX|FREQ: 903.700000 MHz DR0 RSSI: -111 dB SNR: 25 cB
8:15:2:234|DEBUG| GW:00:80:00:00:a0:00:03:89|FRAME-RX|TYPE: Unconfirmed Up
8:15:2:235|DEBUG| GW:00:80:00:00:a0:00:03:89|PACKET-RX|ADDR: 06:00:00:84 FCnt:03f9
8:15:2:236|INFO| ED:03-43-4b-4b-50-33-38-20|CHECK-PKT|FCNT: 000003f9 LAST-FCNT: 000003f8 Duplicate: no
8:15:2:237|INFO| ED:03-43-4b-4b-50-33-38-20|CHECK-MIC|ADDR: 06:00:00:84 passed
8:15:2:237|INFO| ED:03-43-4b-4b-50-33-38-20|PER|0.000000%
8:15:2:237|DEBUG| ED:03-43-4b-4b-50-33-38-20|PACKET-RX|GW:00:80:00:00:a0:00:03:89 Time_us:842151780
8:15:2:238|DEBUG| ED:03-43-4b-4b-50-33-38-20|PACKET-RX|Downlink Packets Queued: 10
8:15:2:238|INFO| ED:03-43-4b-4b-50-33-38-20|FCTRL|ADR:1 ADRACK:0 ACK:0 CLASS:A OPTS:0
8:15:2:259|INFO| ED:03-43-4b-4b-50-33-38-20|SCHED-TX|Use RX1 TOA:92 ms
8:15:2:269|DEBUG| GW:00:80:00:00:a0:00:03:89|FRAME-RX|JSON: {“chan”:7,”codr”:”4/5″,”data”:”QIQAAAaA+QMCnM6wtOH0qKke2GDrBLw=”,”datr”:”SF10BW125″,”freq”:903.70000000000005,”lsnr”:2.5,”modu”:$
8:15:2:273|INFO| GW:00:80:00:00:a0:00:03:89|FRAME-TX|IP: 127.0.0.1:45855 CH: LC2 NODE: 06:00:00:7b FCNT: 000001e9 REPEAT: 0
8:15:2:276|INFO| ED:18-43-4b-4b-39-32-5f-20|SCHED-TX|Q-SIZE: 13 PKT-SIZE: 46 PKT-ROOM: 242
8:15:2:276|INFO| TransmitQueue find 879770 879930
8:15:2:276|INFO| TransmitQueue cannot increase duration
8:15:2:277|INFO| ED:18-43-4b-4b-39-32-5f-20|SCHED-TX|DEFER-TX 0600007b RX-WND:1 Scheduling conflict
8:15:2:277|WARNING| Unschedule frame
8:15:2:291|INFO| GW:00:80:00:00:a0:00:03:89|FRAME-TX|IP: 127.0.0.1:45855 CH: LC1 NODE: 06:00:01:6c FCNT: 0000019a REPEAT: 0
8:15:2:295|INFO| ED:18-43-4b-4b-3c-b2-40-20|SCHED-TX|Q-SIZE: 13 PKT-SIZE: 19 PKT-ROOM: 242
8:15:2:295|INFO| TransmitQueue find 879930 879941
8:15:2:296|INFO| TransmitQueue cannot increase duration
8:15:2:296|INFO| ED:18-43-4b-4b-3c-b2-40-20|SCHED-TX|DEFER-TX 0600016c RX-WND:2 Scheduling conflict
8:15:2:297|WARNING| Unschedule frame
8:15:2:324|INFO| GW:00:80:00:00:a0:00:03:89|FRAME-TX|IP: 127.0.0.1:45855 CH: LC5 NODE: 06:00:01:70 FCNT: 000003cb REPEAT: 0
8:15:2:328|INFO| ED:03-43-4b-4b-39-33-3d-20|SCHED-TX|Q-SIZE: 2 PKT-SIZE: 19 PKT-ROOM: 242
8:15:2:328|INFO| TransmitQueue find 879941 879986
8:15:2:348|INFO| TransmitQueue cannot increase duration
8:15:2:349|INFO| ED:03-43-4b-4b-39-33-3d-20|SCHED-TX|DEFER-TX 06000170 RX-WND:2 Scheduling conflict
8:15:2:349|WARNING| Unschedule frame
8:15:2:353|INFO| GW:00:80:00:00:a0:00:03:89|FRAME-TX|IP: 127.0.0.1:45855 CH: LC2 NODE: 06:00:01:82 FCNT: 000005ba REPEAT: 0
8:15:2:357|INFO| ED:18-43-4b-4b-3b-32-55-20|SCHED-TX|Q-SIZE: 17 PKT-SIZE: 19 PKT-ROOM: 242
8:15:2:358|INFO| TransmitQueue find 879986 880083

[Jason Reiss]

Thomas,

Thanks for the specific questions. I have a few questions about your setup.

How many nodes are registered?
Do they join via OTA or ABP?
Is most traffic meant to be downlink? Is any uplink?

1. The network server will need to know the node is available. After an OTA join the device should send an uplink to confirm it has received the Join Response. Or if the device has been registered the network does not know if it has been powered on until an uplink. It may be possible work around by incrementing the uplink counter to 1.
Also in a larger network it may be necessary for the device to send a periodic uplink so the network knows what gateways are available to reach the device.

2. The us time is from the internal clock of the gw card

3. The values are ms time from start of process used for scheduling downlink packets and avoid collisions.

4. Cannot increase duration mean a packet was scheduled but the payload cannot be added in the available downlink slot. The payload will wait in the queue until a downlink slot is found.

5. a.) A devices are Class A, when an uplink is received the Rx1 Slot can be used for downlink. Class C is additional behavior beyond Class A, it has Rx2 open always. Class A operation is the default behavior of all LoRaWAN end-devices. When the device is registered as Class C the downlinks are scheduled for Rx1 or after the close of Rx1, when an uplink is received.

b.) Scheduling conflict means two transmissions want to use the same time. Only one can be transmitted. Some guard time is added in scheduling, we will have this timing tightened in a coming release. It should reduce conflicts.

6. The payload has been unscheduled to be sent at a later time.

[Thomas Hermansson]

Hi!

The units join via OTA. Most traffic is uplink, but once a week there is significant traffic downlink.

We have several different installations. Nodes range from 30 items to 400 items (and up to 1000 units are planned).

The nodes report back (uplink) every 15 minutes sending a short status of aproximately 10 bytes.

Once a week aprox 300 bytes of data is transmitted to each unit. data is splitted into packages of size 50 bytes.

if something goes wrong with the 300 bytes of data (it is not all received) a new attempt is done at every 15 minutes when the node sends its status. We then resend the 300 bytes (as 6 packets).

We are using a STM lora chip and your gateway. The lora stack beeing used is obtained from STM.

1. “It may be possible work around by incrementing the uplink counter to 1” – how can this be done?

4. “Cannot increase duration mean a packet was scheduled but the payload cannot be added in the available downlink slot. The payload will wait in the queue until a downlink slot is found.”
This is very interesting, but would need some more explanation. We just noticed that the limitation of payload is different between Europe and US.
11 – 242 bytes US
51 – 242 bytes EU
Does this mean that we have a packet of 50 bytes that we try to send to a unit that transmits on a very low datarate so that the data does not fit in the 400ms window?
Or what do you mean with a downlink slot? What is regulating the downlink slots? Will many uplink data packages make it harder to find a downlink slot?
Please elaborate more as I think I might miss some vital part here. 🙂

5 b.) “Scheduling conflict means two transmissions want to use the same time. Only one can be transmitted. Some guard time is added in scheduling, we will have this timing tightened in a coming release. It should reduce conflicts.”
If our serverprogram sends lots of packets (6 packets of 50 bytes) for each node instantly to the mqtt server. Will the network server not just transmit them one by one in the same order as we transmitted them to mqtt?

I am very greatful for your help.

Thanks
Thomas Hermansson
ÅF Technology
Sweden.

[Jason Reiss]

1. Looks like current release does not allow update of uplink or downlink counter through commands. Only way currently is for device to send at least two uplinks after joining.

4. US uses 500k channels for downlinks. DR8-DR12 in the LW spec.
Each uplink will schedule two rx slots for possible downlinks. If a downlink does not use the slot another may use it.

5 b.) The packets will be queued for each node immediately, then they will be transmitted by cycling through the node list and transmitting a packet to each one. So i would not expect 6 to the first, then 6 to the second, but 1 to the first, 1 to the second,…

[Thomas Hermansson]

But can you give me one example that would generate a “Scheduling conflict”. Is this just a printout saying that the network-server does a bad scheduling? 🙂 Or is this due to us generating to much traffic, to large data packets?

Would it be possible to request a default lora-network-server.conf file for the 915 band? Just to make sure we have not messed up somethign there?

[Thomas Hermansson]

Are these printout added in the lora-network-server v 1.0.42? We have no logs with this print from earlier versions. I´m thinking of the Scheduling conflict and the cannot increase duration.

5. Does “Scheduling conflict” only mean anything to us – or is it only a debug for the developers of the lora network server. I am having problems to understand what you mean by “Two transmissions want to use the same time..”. According to your comment above the network server will not get this problems due to that we feed the gw with lots of packets to transmit to the nodes….as they will be handled one by one you say.

Kind Regards
Thomas

[Jason Reiss]

The scheduling conflict occurred after an uplink was received.

8:15:2:233|INFO| GW:00:80:00:00:a0:00:03:89|FRAME-RX|Parsing 1 packets
8:15:2:234|DEBUG| GW:00:80:00:00:a0:00:03:89|FRAME-RX|DATA: 408400000680f903029cceb0b4e1f4a8a91ed860eb04bc
8:15:2:234|DEBUG| GW:00:80:00:00:a0:00:03:89|FRAME-RX|FREQ: 903.700000 MHz DR0 RSSI: -111 dB SNR: 25 cB
8:15:2:234|DEBUG| GW:00:80:00:00:a0:00:03:89|FRAME-RX|TYPE: Unconfirmed Up
8:15:2:235|DEBUG| GW:00:80:00:00:a0:00:03:89|PACKET-RX|ADDR: 06:00:00:84 FCnt:03f9

Without uplink traffic the class C packets would have been scheduled without conflict.

[Thomas Hermansson]

Hi Jason!

There must be a bug in Lora Network Server related to the scheduling conflicts when having nodes in Class C.

1. We can repeat this error in two ways. Our first setup – we only have one or two nodes online and connected. If we send packets (size 40 bytes) rapidly to the mosquito server the scheduling conflicts occur – we then know that there is no uplink traffic in the area that is stealing bandwith.
Problem dissapears if we instead send the packets with aprox 1-2s delay to mosquitto.

2. Second setup. We have aprox 30 units. We pretend that all nodes are Class A – I.e we remove all nordes with lora-query so the joined list is blank. Then we wait for them to join. And we do NOT change them to Class C. Then we start sending packet to the Mosqito server and according to the Lora Spec, no packets should be sent until a node reports in. So far so good. Everything works as expected. BUT when changing the nodes to class C with lora-query (we change all 30 nodes instantly with a script). Then the scheduling conflicts occur directly. And NO PACKETS is transmitted at all.

This must be a but in the lora network server! We are happy to provide you assistance to get this solved.

Kind Regards
Thomas

[Jason Reiss]

Do you request ACK from the end-device for class C downlinks?

The current implementation will transmit a Confirmed downlink once and wait for uplink.
The packet will stay queued until ACK is received as with class A but there is no timeout implemented in the current release that will replay the downlink.

We are testing a new release with major improvements to downlink scheduling with retry max settings and ACK retry timeouts.

[Thomas Hermansson]

Thanks for your reply!

Hmm I see from our implementation that we did not set the “ack” to either false or true. So I guess it depends on how the mosquito server defaults. Do you know?

We are happy to beta-test your improved lora-network-server to see if it solves our problem.

Kind Regards
Thomas

[Jason Reiss]

Please open a case at support.multitech.com to discuss early access.

[Author]

Posts