contiki-ng / cooja

This is a fork of the Cooja network simulator from contiki-os/contiki
Other
30 stars 49 forks source link

Log output missing #136

Open atiselsts opened 2 years ago

atiselsts commented 2 years ago

We're using a modified version of Contiki-NG (based on 4.6) along with unmodified version of Cooja, commit 7a7fd5e471b3333c97d09c24224a865be4a4f4f4 from June 2021.

There are some big problems with the log output in Cooja. The amount seems to depend on the exact system used to run the simulation. On my PC, most of the nodes show expected logging output in "Mote output" window, except the gateway node, which has most of the logs missing. My colleague on his PC sees empty output from all nodes. It's not a fault of the C code I think, as the actual correct log output for some reason appears in the output of the Cooja console window! The logs do reach Cooja, but they are not reaching the Mote output plugin for some reason.

This bug is a strange one. I've been looking into this for a while, but I feel that I'm not expert enough in how Cooja works, perhaps you guys can help me.

Same thing happens when running without GUI. This is output in COOJA.log, when running a simulation with just the gateway node:

 INFO [main] (ScriptRunner.java:430) - Test script deactivated
 INFO [main] (LogScriptEngine.java:265) - Script timeout in 3600000 ms
 INFO [main] (ScriptRunner.java:387) - Test script activated
 INFO [Thread-2] (Simulation.java:253) - Simulation main loop started, system time: 1654171999186
(... some lines skipped ...)
[INFO: RPL       ] [INFO: Main      ] Tentative link-local IPv6 address: fe80::201:1:1:1[INFO: Main      ] [INFO: Main      ] - Routing: RPL Lite
[INFO: Main      ] - Net: sicslowpan
[INFO: Main      ] - MAC: TSCH
[INFO: Main      ] - 802.15.4 PANID: 0xff4e
[INFO: Main      ] - 802.15.4 TSCH default hopping sequence length: 128
[INFO: Main      ] Node ID: 1
(...further output skipped...)

This is output in COOJA.testlog:

Random seed: 123456
Starting COOJA logger
382000 1 Starting Gateway 
382000 1 }
382000 1 initializing
382000 1 Starting Contiki-NG-5.2.22.0601
382000 1 ...
382000 1  Node_Info will be here
382000 1 scanning on channel
382000 1 IPv6 addresses:
382000 1 created a new RPL DAG
392000 1 scanning over
392000 1 }
20051000 1 ...Sending multicast DIO
20724008 1 .........
26486120 1 ...
52489620 1 ......
60382000 1 nbr: end of list
60382000 1 No routing links
77176000 1 ...Sending multicast DIO
77578008 1 .........
78493120 1 ...
120382000 1 ...nbr: end of list
120382000 1 No routing links
130500120 1 ...
180382000 1 nbr: end of list
180382000 1 No routing links
208510620 1 ......
227370000 1 Sending multicast DIO
227835008 1 .........
pjonsson commented 2 years ago

If you get all output to the console it might be something with the printf interception. It could also be some truncation of something and then missing error checks in Cooja so it just continues despite things going wrong. Do both of you use the docker container, or are you running on 64-bit systems?

The Cooja platform in current HEAD on develop in contiki-ng is updated to use dbg-io. Cooja itself has a number of 64-bit fixes and is updated to use log4j 2.x.

The output issues shouldn't be triggered by the algorithms you are looking at in your modified Contiki-NG 4.6, can you replicate the problems on the develop branch with some other simulation?