open-degu / USER_COMMUNITY

Deguの使い方に関する疑問を投稿、回答するためのIssueを提供しています。
4 stars 2 forks source link

Degu Data Post Fail #28

Closed suyouxin closed 4 years ago

suyouxin commented 4 years ago

Overview

Degu stops posting data to gateway after running for a while.

Setup

The Degu unit is setup to post sensor data to gateway every minute. Degu python code:

if __name__ == '__main__':
    path = 'thing/' + zcoap.eui64() + '/shadow/update'
    reported = {'state':{'reported':{}}}

    addr = zcoap.gw_addr()
    port = 5683
    cli = zcoap.client((addr, port))

    pin = Pin(('GPIO_1', 7), Pin.OUT)
    led1 = Signal(pin, invert=True)
    led1.off()
    bus = I2C(1)
    bmp = BMP280(i2c=bus)

    while True:
        light = round(light_sensor(), 2)
        reported['state']['reported']['light'] = light
        reported['state']['reported']['temp'] = float(bmp.values[0])
        reported['state']['reported']['pres'] = float(bmp.values[1])
        reported['state']['reported']['moisture'] = moisture_sensor()
        print(ujson.dumps(reported))
        cli.request_post(path, ujson.dumps(reported))

        received = cli.request_get(path)

        if received:
            led1.on()

        time.sleep(60)

    cli.close()

Issue

It worked fine for a while until an error occurred then it stopped posting data.

The log extract is below. The json debug message is printed out by the python script every minute and we can see the error message when it stopped posting to the gateway. See the attached file for the full log. degu.log

[2019-11-06 13:36:41] {"state": {"reported": {"moisture": 1036, "temp": 21.64, "pres": 1007.49, "light": 2.03}}}
[2019-11-06 13:36:41] -MAC-----: Sent IPv6 UDP msg, len:189, chksum:25de, to:0xa000, sec:yes, prio:normal
[2019-11-06 13:36:41] -MAC-----:        src:[fd41:8b08:c493:0:6116:bd8-MAC-----: Received IPv6 UDP msg, len:60, chksum:c436, from:0xa000, sec:yes, prio:normal, rss:-62.0
[2019-11-06 13:36:43] -MAC-----:        src:[fd41:8b08'2.04'
[2019-11-06 13:36:43] -MAC-----: Sent IPv6 UDP msg, len:100, chksu-MAC-----: Received IPv6 UDP msg, len:346, chksum:9f4e, from:0xa000, sec:yes, prio:normal, rss:-61.625
[2019-11-06 13:36:45] -MAC-----:        src:[fd41:8-MAC-----: Received IPv6 UDP msg, len:90, chksum:731f, from:924139b02c3e9d13, sec:no, prio:net, rss:-60.0
[2019-11-06 13:37:02] -MAC-----:        src:[fe8-MLE-----: Send Child Update Request to parent (fe80:0:0:0:9041:39b0:2c3e:9d13)
[2019-11-06 13:37:27] -MAC-----: Sent IPv6 UDP msg, len:98, chksum:0f78, to:924139b02c3e9d-MAC-----: Received IPv6 UDP msg, len:-MAC-----: Received IPv6 UDP msg, len:90, chksum:afce, from:924139b02c3e9d13, sec:no, prio:net, rss:-63.0
[2019-11-06 13:37:31] -MAC-----:        src:[fe82310
[2019-11-06 13:37:45] 1039
[2019-11-06 13:37:45] {"state": {"reported": {"moisture": 1039, "temp": 21.57, "pres": 1007.53, "light": 2.03}}}
[2019-11-06 13:37:45] -MAC-----: Sent IPv6 UDP msg, len:189, chksum:cd16, to:0xa000, sec:yes, prio:normal
[2019-11-06 13:37:45] -MAC-----:        src:[fd41:8b08:c493:0:6116:bd8-MAC-----: Received IPv6 UDP msg, len:60, chksum:6773, from:0xa000, sec:yes, prio:normal, rss:-67.0
[2019-11-06 13:37:47] -MAC-----:        src:[fd41:8b08'2.04'
[2019-11-06 13:37:47] -MAC-----: Sent IPv6 UDP msg, len:100, chksum:23b6, to:0xa000, sec:yes, prio:nor-MAC-----: Received IPv6 UDP msg, len:346, chksum:3075, from:0xa000, sec:yes, prio:normal, rss:-65.625
[2019-11-06 13:37:49] -MAC-----:        src:[fd41:8-MAC-----: Received IPv6 UDP msg, len:90, chksum:0a5d, from:924139b02c3e9d13, sec:no, prio:net, rss:-68.0
[2019-11-06 13:38:02] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:bf74, from:924139b02c3e9d13, sec:no, prio:net, rss:-64.0
[2019-11-06 13:38:40] -MAC-----:        src:[fe82311
[2019-11-06 13:38:49] 1036
[2019-11-06 13:38:49] {"state": {"reported": {"moisture": 1036, "temp": 21.57, "pres": 1007.47, "light": 2.03}}}
[2019-11-06 13:38:49] -MAC-----: Sent IPv6 UDP msg, len:189, chksum:657f, to:0xa000, sec:yes, prio:normal
[2019-11-06 13:38:49] -MAC-----:        src:[fd41:8b08:c493:0:6116:bd8-MAC-----: Received IPv6 UDP msg, len:60, chksum:00db, from:0xa000, sec:yes, prio:normal, rss:-68.0
[2019-11-06 13:38:50] -MAC-----:        src:[fd41:8b08'2.04'
[2019-11-06 13:38:50] -MAC-----: Sent IPv6 UDP msg, len:100, chksum:bd1d, to:0xa000, sec:ye-MAC-----: Dropping (reassembly queue) IPv6 UDP msg, len:346, chksum:d5f4, sec:yes, error:ReassemblyTimeout, prio:normal, rss:--MAC-----: Received IPv6 UDP msg, len:90, chksum:e94b, from:924139b02c3e9d13, sec:no, prio0
[2019-11-06 13:39:14] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:b52f, from:924139b02c3e9d13, sec:no, prio:net, rss:-57.0
[2019-11-06 13:39:50] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:6337, from:924139b02c3e9d13, sec:no, prio:net, rss:-62.0
[2019-11-06 13:40:13] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:55d5, from:924139b02c3e9d13, sec:no, prio:net, rss:-70.0
[2019-11-06 13:40:53] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:a88d, from:924139b02c3e9d13, sec:no, prio:net, rss:-68.0
[2019-11-06 13:41:21] -MAC-----:        src:[fe8-MLE-----: Send Child Update Request to parent (fe80:0:0:0:9041:39b0:2c3e:9d13)
[2019-11-06 13:41:23] -MAC-----: Sent IPv6 UDP msg, len:98, chksum:aaa4, to:924139b02c-MAC-----: Received IPv6 UDP msg, len:-MAC-----: Received IPv6 UDP msg, len:90, chksum:36af, from:924139b02c3e9d13, sec:no, prio:net, rss:-62.0
[2019-11-06 13:41:56] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:f2cc, from:924139b02c3e9d13, sec:no, prio:net, rss:-62.0
[2019-11-06 13:42:29] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:ca08, from:924139b02c3e9d13, sec:no, prio:net, rss:-63.0
[2019-11-06 13:42:54] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:7995, from:924139b02c3e9d13, sec:no, prio:net, rss:-67.0
[2019-11-06 13:43:26] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:eaa9, from:924139b02c3e9d13, sec:no, prio:net, rss:-59.0
[2019-11-06 13:43:55] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:a0fb, from:924139b02c3e9d13, sec:no, prio:net, rss:-62.0
[2019-11-06 13:44:36] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:5322, from:924139b02c3e9d13, sec:no, prio:net, rss:-66.0
[2019-11-06 13:45:10] -MAC-----:        src:[fe8-MLE-----: Send Child Update Request to parent (fe80:0:0:0:9041:39b0:2c3e:9d13)
[2019-11-06 13:45:18] -MAC-----: Sent IPv6 UDP msg, len:98, chksum:9589, to:924139b02c3e-MAC-----: Received IPv6 UD-MAC-----: Received IPv6 UDP msg, len:90, chksum:c2dc, from:924139b02c3e9d13, sec:no, prio:net, rss:-66.0
[2019-11-06 13:45:30] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:d086, from:924139b02c3e9d13, sec:no, prio:net, rss:-63.0
[2019-11-06 13:46:42] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:df27, from:924139b02c3e9d13, sec:no, prio:net, rss:-64.0
[2019-11-06 13:47:17] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:13cb, from:924139b02c3e9d13, sec:no, prio:net, rss:-63.0
[2019-11-06 13:47:50] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:6927, from:924139b02c3e9d13, sec:no, prio:net, rss:-61.0
[2019-11-06 13:48:20] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:2289, from:924139b02c3e9d13, sec:no, prio:net, rss:-60.0
[2019-11-06 13:48:43] -MAC-----:        src:[fe8-MLE-----: Send Child Update Request to parent (fe80:0:0:0:9041:39b0:2c3e:9d13)
[2019-11-06 13:49:14] -MAC-----: Sent IPv6 UDP msg, len:98, chksum:2280, to:924139b02c3e9d13, sec:no, prio:net
[2019-11-06 13:49:14] -MAC-----:        src:[fe80:0:0:0:90cc:fd90-MAC-----: Received IPv-MAC-----: Received IPv6 UDP msg, len:90, chksum:5d7f, from:924139b02c3e9d13, sec:no, prio:net, rss:-63.0
[2019-11-06 13:49:24] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:aff3, from:924139b02c3e9d13, sec:no, prio:net, rss:-72.0
[2019-11-06 13:49:58] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:7b56, from:924139b02c3e9d13, sec:no, prio:net, rss:-66.0
[2019-11-06 13:50:15] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:4c16, from:924139b02c3e9d13, sec:no, prio:net, rss:-66.0
[2019-11-06 13:50:52] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:64f8, from:924139b02c3e9d13, sec:no, prio:net, rss:-67.0
[2019-11-06 13:51:20] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:e9ce, from:924139b02c3e9d13, sec:no, prio:net, rss:-64.0
[2019-11-06 13:51:55] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:6a7c, from:924139b02c3e9d13, sec:no, prio:net, rss:-66.0
[2019-11-06 13:52:27] -MAC-----:        src:[fe8-MAC-----: Received IPv6 UDP msg, len:90, chksum:5b16, from:924139b02c3e9d13, sec:no, prio:net, rss:-64.0
[2019-11-06 13:53:02] -MAC-----:        src:[fe8-MLE-----: Send Child Update Request to parent (fe80:0:0:0:9041:39b0:2c3e:9d13)
naomitodori commented 4 years ago

Thank you for raising a issue.

I am trying to reproduce the issue. Which version of Degu firmware are you using?

suyouxin commented 4 years ago

@naomitodori The Degu firmware version is v0.9.5. Then I tried the latest master branch (bca668941a3033b137fe7840f13e2816c27b374f) for more debug message.

BTW: Would be appreciate if you can let me know how to get stable debug message output. I tried to enable log process thread and increase log buffer size:

CONFIG_LOG_PROCESS_THREAD=y
CONFIG_LOG_BUFFER_SIZE=4096

However, it always seems to be dropping a lot of messages and the log itself contains empty messages.

[26:22:49.227,233] <err> adc_nrfx_saadc: Unsupported power state 0
[26:22:49.230,438] <err> adc_nrfx_saadc: Unsupported power state 0
[26:22:49.262,420] <err> adc_nrfx_saadc: Unsupported power state 0
[26:22:49.497,619] <err> adc_nrfx_saadc: Unsupported power state 0
[26:22:49.501,464] <err> adc_nrfx_saadc: Unsupported power state 0
[26:22:49.764,556] <inf> net_openthread: 0i
[26:22:49.764,587] <inf> net_openthread: 
[26:22:49.764,923] <err> adc_nrfx_saadc: Unsupported power state 0
[26:22:49.798,645] <inf> net_openthread: ��
--- 38 messages dropped ---
[26:22:49.798,736] <inf> net_openthread:

Does the logging system work fine for you? Would you have better approach to get logs?

takumiando commented 4 years ago

I think that Degu may miss to get CoAP response from GW and it is still waiting. This bug is known, and we will fix it and apply in the future release.

Does the logging system work fine for you? Would you have better approach to get logs?

Sorry, we have not found the good way and approach yet... We should understand more details of the system and design of Zephyr RTOS.

yoshidam-at commented 4 years ago

This issue fixed on v1.0.0-rc1. Please check and close it.

How to update from v0.9.x to v1.0.0-rc1, see Degu v0.9.xからv1.0.0-rc1移行ガイド.