Seeed Wio 3G fails to connect cellular network on Mbed OS 5.13.3 onward

[toyowata]

Description

Seeed Wio 3G fails to connect cellular network on Mbed OS 5.13.3 onward (5.13.2 worked fine). Greentea test (features-cellular-tests-socket-udp) results are below:

[Mbed OS 5.13.2]

mbedgt: test suite report:
| target         | platform_name | test suite                         | result | elapsed_time (sec) | copy_method |
|----------------|---------------|------------------------------------|--------|--------------------|-------------|
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | OK     | 62.38              | default     |
mbedgt: test suite results: 1 OK
mbedgt: test case report:
| target         | platform_name | test suite                         | test case                     | passed | failed | result | elapsed_time (sec) |
|----------------|---------------|------------------------------------|-------------------------------|--------|--------|--------|--------------------|
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP gethostbyname             | 1      | 0      | OK     | 0.21               |
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP network stack             | 1      | 0      | OK     | 23.27              |
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP socket send/receive       | 1      | 0      | OK     | 0.38               |
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP socket send/receive async | 1      | 0      | OK     | 0.39               |
mbedgt: test case results: 4 OK

[Mbed OS 5.13.3]

mbedgt: test suite report:
| target         | platform_name | test suite                         | result  | elapsed_time (sec) | copy_method |
|----------------|---------------|------------------------------------|---------|--------------------|-------------|
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | TIMEOUT | 639.33             | default     |
mbedgt: test suite results: 1 TIMEOUT
mbedgt: test case report:
| target         | platform_name | test suite                         | test case                     | passed | failed | result  | elapsed_time (sec) |
|----------------|---------------|------------------------------------|-------------------------------|--------|--------|---------|--------------------|
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP gethostbyname             | 0      | 0      | SKIPPED | 0.0                |
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP network stack             | 0      | 0      | ERROR   | 0.0                |
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP socket send/receive       | 0      | 0      | SKIPPED | 0.0                |
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP socket send/receive async | 0      | 0      | SKIPPED | 0.0                |
mbedgt: test case results: 3 SKIPPED / 1 ERROR

Full log output is below:
wio_3g_mbed-os-5.13.2.txt
wio_3g_mbed-os-5.13.3.txt

My configuration is:

        "WIO_3G": {
            "target.device_has_remove"          : ["SERIAL_FC"],
            "platform.stdio-buffered-serial"    : true,
            "nsapi.default-cellular-sim-pin"    : "\"0000\"",
            "nsapi.default-cellular-plmn"       : 0,
            "nsapi.default-cellular-apn"        : "\"soracom.io\"",
            "nsapi.default-cellular-username"   : "\"sora\"",
            "nsapi.default-cellular-password"   : "\"sora\""
        }

Also, I ran mbed-os-example-cellular with trace log:

mbed-os-cellular-example-5_13_2.txt
mbed-os-cellular-example-5_13_3.txt

Note that the target HAL code is not changed between 5.13.2 and 5.13.3.

Issue request type

[ ] Question
[ ] Enhancement
[x] Bug

cc @armmbed/team-seeed

[0xc0170]

cc @ARMmbed/mbed-os-wan

[ciarmcom]

Internal Jira reference: https://jira.arm.com/browse/MBOCUSTRIA-1848

[toyowata]

I confirmed that the Seeed Wio LTE-M1/NB1(BG96) has same issue on Mbed OS 5.13.3 onward.

[AriParkkila]

@toyowata I don't see any changes to WIO_3G or UG96 in Mbed OS 5.13, but there is one change to cellular-state-machine, can you revert #a1ffecca to see if it that has any impact?

[toyowata]

@AriParkkila Thanks.

The features-cellular-tests-socket-udp test passed by reverting the a1ffecc commit.

mbedgt: test suite report:
| target         | platform_name | test suite                         | result | elapsed_time (sec) | copy_method |
|----------------|---------------|------------------------------------|--------|--------------------|-------------|
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | OK     | 61.14              | default     |
mbedgt: test suite results: 1 OK
mbedgt: test case report:
| target         | platform_name | test suite                         | test case                     | passed | failed | result | elapsed_time (sec) |
|----------------|---------------|------------------------------------|-------------------------------|--------|--------|--------|--------------------|
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP gethostbyname             | 1      | 0      | OK     | 0.16               |
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP network stack             | 1      | 0      | OK     | 22.22              |
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP socket send/receive       | 1      | 0      | OK     | 0.39               |
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP socket send/receive async | 1      | 0      | OK     | 0.4                |
mbedgt: test case results: 4 OK

I also confirmed that changing TIMEOUT_POWER_ON value to be (3*1000) works fine for the Seeed Wio 3G.

mbed-os/features/cellular/framework/device/CellularStateMachine.cpp

Line 28 in 31114ba

#define TIMEOUT_POWER_ON (1*1000)

I think this should be done by calling CellularStateMachine::set_timeout function, but I have two concerns below:

1. How to call this function?
   I am not sure how to call this function from application code or target code. e.g. how to get CellularStateMachine instance. Do you have any example code?

2. Single timeout value for variety states
   The CellularStateMachine::set_timeout can only pass single parameter, but each timeout values should have different range of timeout.

mbed-os/features/cellular/framework/device/CellularStateMachine.cpp

Lines 760 to 767 in 31114ba

	void CellularStateMachine::set_timeout(int timeout)
	{
	_state_timeout_power_on = timeout;
	_state_timeout_sim_pin = timeout;
	_state_timeout_registration = timeout;
	_state_timeout_network = timeout;
	_state_timeout_connect = timeout;
	}

mbed-os/features/cellular/framework/device/CellularStateMachine.cpp

Lines 27 to 37 in 31114ba

	// timeout to wait for AT responses
	#define TIMEOUT_POWER_ON (1*1000)
	#define TIMEOUT_SIM_PIN (1*1000)
	#define TIMEOUT_NETWORK (10*1000)
	/** CellularStateMachine does connecting up to packet service attach, and
	* after that it's up to CellularContext::connect() to connect to PDN.
	* If CellularContext or an application does not set timeout (via `CellularDevice::set_timeout`)
	* then TIMEOUT_CONNECT is used also for connecting to PDN and also for socket operations.
	*/
	#define TIMEOUT_CONNECT (60*1000)
	#define TIMEOUT_REGISTRATION (180*1000)

[AriParkkila]

@toyowata UG96 seems to be missing QUECTEL_UG96::soft_power_on, where (according to UG96_Hardware_Design_V1.0) it should have 3.5s delay after reset. But that doesn't explain BG96 failures.

[AriParkkila]

@toyowata Can you check if PR #11618 fixes?

[toyowata]

@AriParkkila Thanks for the patch. Test result is below:

(mbed-venv) 18:36:36 mbed-os $ mbed test -m wio_3g -t gcc_arm -n features-cellular-TESTS-socket-udp --run -v
[mbed] Working path "/Users/toywat01/test/seeed/wio_3g_test/ug95_test/mbed-os" (program)
[mbed] Exec "mbedgt --test-spec ./BUILD/tests/WIO_3G/GCC_ARM/test_spec.json -n features-cellular-TESTS-socket-udp -V" in "/Users/toywat01/test/seeed/wio_3g_test/ug95_test/mbed-os"
mbedgt: greentea test automation tool ver. 1.7.2
mbedgt: test specification file './BUILD/tests/WIO_3G/GCC_ARM/test_spec.json' (specified with --test-spec option)
mbedgt: using './BUILD/tests/WIO_3G/GCC_ARM/test_spec.json' from current directory!
mbedgt: detecting connected mbed-enabled devices...
mbedgt: detected 1 device
	| platform_name | platform_name_unique | serial_port            | mount_point      | target_id                                        |
	|---------------|----------------------|------------------------|------------------|--------------------------------------------------|
	| WIO_3G        | WIO_3G[0]            | /dev/tty.usbmodem14202 | /Volumes/DAPLINK | 901400001fe2140000000000000000000000000097969902 |
mbedgt: processing target 'WIO_3G' toolchain 'GCC_ARM' compatible platforms... (note: switch set to --parallel 1)
	| platform_name | platform_name_unique | serial_port                 | mount_point      | target_id                                        |
	|---------------|----------------------|-----------------------------|------------------|--------------------------------------------------|
	| WIO_3G        | WIO_3G[0]            | /dev/tty.usbmodem14202:9600 | /Volumes/DAPLINK | 901400001fe2140000000000000000000000000097969902 |
mbedgt: test case filter (specified with -n option)
	features-cellular-tests-socket-udp
	test filtered in 'features-cellular-tests-socket-udp'
mbedgt: running 1 test for platform 'WIO_3G' and toolchain 'GCC_ARM'
	use 1 instance of execution threads for testing
mbedgt: checking for 'host_tests' directory above image directory structure
	'host_tests' directory not found: two directory levels above image path checked
mbedgt: selecting test case observer...
	calling mbedhtrun: mbedhtrun -m WIO_3G -p /dev/tty.usbmodem14202:9600 -f "BUILD/tests/WIO_3G/GCC_ARM/features/cellular/TESTS/socket/udp/udp.bin" -d /Volumes/DAPLINK -c default -t 901400001fe2140000000000000000000000000097969902 -r default -C 4 --sync 5 -P 60
mbedgt: mbed-host-test-runner: started
[1570095405.67][HTST][INF] host test executor ver. 0.0.9
[1570095405.67][HTST][INF] copy image onto target...
[1570095405.67][COPY][INF] Waiting up to 60 sec for '901400001fe2140000000000000000000000000097969902' mount point (current is '/Volumes/DAPLINK')...
[1570095438.69][HTST][INF] starting host test process...
[1570095438.70][CONN][INF] starting connection process...
[1570095438.70][CONN][INF] notify event queue about extra 60 sec timeout for serial port pooling
[1570095438.70][CONN][INF] initializing serial port listener...
[1570095438.70][PLGN][INF] Waiting up to 60 sec for '901400001fe2140000000000000000000000000097969902' serial port (current is '/dev/tty.usbmodem14202')...
[1570095438.70][HTST][INF] setting timeout to: 60 sec
[1570095439.05][SERI][INF] serial(port=/dev/tty.usbmodem14202, baudrate=9600, read_timeout=0.01, write_timeout=5)
[1570095439.06][SERI][INF] reset device using 'default' plugin...
[1570095439.46][SERI][INF] waiting 1.00 sec after reset
[1570095440.46][SERI][INF] wait for it...
[1570095440.46][SERI][TXD] mbedmbedmbedmbedmbedmbedmbedmbedmbedmbed
[1570095440.46][CONN][INF] sending up to 5 __sync packets (specified with --sync=5)
[1570095440.46][CONN][INF] sending preamble 'ac2362bd-d717-4dab-8941-15939d3d4fd6'
[1570095440.46][SERI][TXD] {{__sync;ac2362bd-d717-4dab-8941-15939d3d4fd6}}
[1570095440.59][CONN][RXD] mbedmbedmbedmbedmbedmbedmbedmbed
[1570095440.65][CONN][INF] found SYNC in stream: {{__sync;ac2362bd-d717-4dab-8941-15939d3d4fd6}} it is #0 sent, queued...
[1570095440.65][HTST][INF] sync KV found, uuid=ac2362bd-d717-4dab-8941-15939d3d4fd6, timestamp=1570095440.646258
[1570095440.67][CONN][INF] found KV pair in stream: {{__version;1.3.0}}, queued...
[1570095440.67][HTST][INF] DUT greentea-client version: 1.3.0
[1570095440.69][CONN][INF] found KV pair in stream: {{__timeout;600}}, queued...
[1570095440.69][HTST][INF] setting timeout to: 600 sec
[1570095440.72][CONN][INF] found KV pair in stream: {{__host_test_name;default_auto}}, queued...
[1570095440.72][HTST][INF] host test class: '<class 'mbed_os_tools.test.host_tests.default_auto.DefaultAuto'>'
[1570095440.72][HTST][INF] host test setup() call...
[1570095440.72][HTST][INF] CALLBACKs updated
[1570095440.72][HTST][INF] host test detected: default_auto
[1570095440.75][CONN][RXD] >>> Running 4 test cases...
[1570095440.80][CONN][INF] found KV pair in stream: {{__testcase_name;UDP network stack}}, queued...
[1570095440.83][CONN][INF] found KV pair in stream: {{__testcase_name;UDP gethostbyname}}, queued...
[1570095440.89][CONN][INF] found KV pair in stream: {{__testcase_name;UDP socket send/receive}}, queued...
[1570095440.93][CONN][INF] found KV pair in stream: {{__testcase_name;UDP socket send/receive async}}, queued...
[1570095440.94][CONN][RXD]
[1570095440.98][CONN][RXD] >>> Running case #1: 'UDP network stack'...
[1570095441.03][CONN][INF] found KV pair in stream: {{__testcase_start;UDP network stack}}, queued...
[1570095518.84][CONN][INF] found KV pair in stream: {{__testcase_finish;UDP network stack;1;0}}, queued...
[1570095518.89][CONN][RXD] >>> 'UDP network stack': 1 passed, 0 failed
[1570095518.89][CONN][RXD]
[1570095518.93][CONN][RXD] >>> Running case #2: 'UDP gethostbyname'...
[1570095518.98][CONN][INF] found KV pair in stream: {{__testcase_start;UDP gethostbyname}}, queued...
[1570095519.13][CONN][INF] found KV pair in stream: {{__testcase_finish;UDP gethostbyname;1;0}}, queued...
[1570095519.17][CONN][RXD] >>> 'UDP gethostbyname': 1 passed, 0 failed
[1570095519.17][CONN][RXD]
[1570095519.23][CONN][RXD] >>> Running case #3: 'UDP socket send/receive'...
[1570095519.28][CONN][INF] found KV pair in stream: {{__testcase_start;UDP socket send/receive}}, queued...
[1570095519.68][CONN][INF] found KV pair in stream: {{__testcase_finish;UDP socket send/receive;1;0}}, queued...
[1570095519.74][CONN][RXD] >>> 'UDP socket send/receive': 1 passed, 0 failed
[1570095519.74][CONN][RXD]
[1570095519.79][CONN][RXD] >>> Running case #4: 'UDP socket send/receive async'...
[1570095519.85][CONN][INF] found KV pair in stream: {{__testcase_start;UDP socket send/receive async}}, queued...
[1570095520.24][CONN][INF] found KV pair in stream: {{__testcase_finish;UDP socket send/receive async;1;0}}, queued...
[1570095520.29][CONN][RXD] >>> 'UDP socket send/receive async': 1 passed, 0 failed
[1570095520.29][CONN][RXD]
[1570095520.33][CONN][RXD] >>> Test cases: 4 passed, 0 failed
[1570095520.36][CONN][INF] found KV pair in stream: {{__testcase_summary;4;0}}, queued...
[1570095520.37][CONN][INF] found KV pair in stream: {{end;success}}, queued...
[1570095520.37][HTST][INF] __notify_complete(True)
[1570095520.37][HTST][INF] __exit_event_queue received
[1570095520.37][HTST][INF] test suite run finished after 79.68 sec...
[1570095520.38][CONN][INF] received special event '__host_test_finished' value='True', finishing
[1570095520.43][HTST][INF] CONN exited with code: 0
[1570095520.43][HTST][INF] No events in queue
[1570095520.43][HTST][INF] stopped consuming events
[1570095520.43][HTST][INF] host test result() call skipped, received: True
[1570095520.43][HTST][WRN] missing __exit event from DUT
[1570095520.43][HTST][INF] calling blocking teardown()
[1570095520.43][HTST][INF] teardown() finished
[1570095520.43][HTST][INF] {{result;success}}
mbedgt: checking for GCOV data...
mbedgt: mbed-host-test-runner: stopped and returned 'OK'
mbedgt: test on hardware with target id: 901400001fe2140000000000000000000000000097969902
mbedgt: test suite 'features-cellular-tests-socket-udp' .............................................. OK in 115.41 sec
	test case: 'UDP gethostbyname' ............................................................... OK in 0.15 sec
	test case: 'UDP network stack' ............................................................... OK in 77.81 sec
	test case: 'UDP socket send/receive' ......................................................... OK in 0.40 sec
	test case: 'UDP socket send/receive async' ................................................... OK in 0.39 sec
mbedgt: test case summary: 4 passes, 0 failures
mbedgt: all tests finished!
mbedgt: shuffle seed: 0.5786339786
mbedgt: test suite report:
| target         | platform_name | test suite                         | result | elapsed_time (sec) | copy_method |
|----------------|---------------|------------------------------------|--------|--------------------|-------------|
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | OK     | 115.41             | default     |
mbedgt: test suite results: 1 OK
mbedgt: test case report:
| target         | platform_name | test suite                         | test case                     | passed | failed | result | elapsed_time (sec) |
|----------------|---------------|------------------------------------|-------------------------------|--------|--------|--------|--------------------|
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP gethostbyname             | 1      | 0      | OK     | 0.15               |
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP network stack             | 1      | 0      | OK     | 77.81              |
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP socket send/receive       | 1      | 0      | OK     | 0.4                |
| WIO_3G-GCC_ARM | WIO_3G        | features-cellular-tests-socket-udp | UDP socket send/receive async | 1      | 0      | OK     | 0.39               |
mbedgt: test case results: 4 OK
mbedgt: completed in 116.22 sec
(mbed-venv) 18:38:40 mbed-os $ mbedls
| platform_name | platform_name_unique | mount_point      | serial_port            | target_id                                        | daplink_version |
|---------------|----------------------|------------------|------------------------|--------------------------------------------------|-----------------|
| WIO_3G        | WIO_3G[0]            | /Volumes/DAPLINK | /dev/tty.usbmodem14202 | 901400001fe2140000000000000000000000000097969902 | 0253            |
(mbed-venv) 18:39:12 mbed-os $ mbed ls
[mbed] Working path "/Users/toywat01/test/seeed/wio_3g_test/ug95_test/mbed-os" (program)
mbed-os (#73145fd55136)
(mbed-venv) 18:39:19 mbed-os $ 

[toyowata]

@AriParkkila I also confirmed that the patch fixed Seeed Wio BG96 issue as well. Thanks a lot.

mbedgt: test on hardware with target id: 901500001ee2efee00000000000000000000000097969902
mbedgt: test suite 'features-cellular-tests-socket-udp' .............................................. OK in 87.31 sec
	test case: 'UDP gethostbyname' ............................................................... OK in 0.97 sec
	test case: 'UDP network stack' ............................................................... OK in 52.44 sec
	test case: 'UDP socket send/receive' ......................................................... OK in 0.49 sec
	test case: 'UDP socket send/receive async' ................................................... OK in 0.48 sec
mbedgt: test case summary: 4 passes, 0 failures
mbedgt: all tests finished!
mbedgt: shuffle seed: 0.9535131944
mbedgt: test suite report:
| target           | platform_name | test suite                         | result | elapsed_time (sec) | copy_method |
|------------------|---------------|------------------------------------|--------|--------------------|-------------|
| WIO_BG96-GCC_ARM | WIO_BG96      | features-cellular-tests-socket-udp | OK     | 87.31              | default     |
mbedgt: test suite results: 1 OK
mbedgt: test case report:
| target           | platform_name | test suite                         | test case                     | passed | failed | result | elapsed_time (sec) |
|------------------|---------------|------------------------------------|-------------------------------|--------|--------|--------|--------------------|
| WIO_BG96-GCC_ARM | WIO_BG96      | features-cellular-tests-socket-udp | UDP gethostbyname             | 1      | 0      | OK     | 0.97               |
| WIO_BG96-GCC_ARM | WIO_BG96      | features-cellular-tests-socket-udp | UDP network stack             | 1      | 0      | OK     | 52.44              |
| WIO_BG96-GCC_ARM | WIO_BG96      | features-cellular-tests-socket-udp | UDP socket send/receive       | 1      | 0      | OK     | 0.49               |
| WIO_BG96-GCC_ARM | WIO_BG96      | features-cellular-tests-socket-udp | UDP socket send/receive async | 1      | 0      | OK     | 0.48               |
mbedgt: test case results: 4 OK
mbedgt: completed in 88.58 sec