Unable to connect to Cloud using Asset Tracker on nRF9160 DK

[AlbertSerica]

Hello, I am currently learning to use nRF9160 DK in Guangzhou, China. 

It is weird that my China Mobile cellphone SIM card can be used on this DK to connect to Cloud. However, iBasics SIM and China Telecom NBIOT SIM cannot connect to Cloud. 

While using iBasics, it's LED3 that keeps blinking. While using China Telecom, LED3 blinks first, then LED4 blinks, LED1 and LED4 blinks at last.

The following is from nRF Connect during the entire session for China Telecom

+CSCON: 1

 

 

[00:00:08.419,586]

[0m<inf> asset_tracker: RRC mode: Connected

[0m

 

 

+CEREG: 1,"765E","075D6450",9,,,"11100000","00111000"

 

 

[00:00:10.095,031]

[0m<inf> asset_tracker: Connected to LTE network.

[0m

 

 

[00:00:10.101,623]

[0m<inf> asset_tracker: Connecting to cloud, attempt 1 of 8

[0m

 

 

[00:00:10.109,039]

[0m<inf> asset_tracker: Cloud connection request sent.

[0m

 

 

[00:00:10.115,966]

[0m<inf> asset_tracker: Connection response timeout is set to 30 seconds.

[0m

 

 

[00:00:10.124,664]

[0m<inf> asset_tracker: Network registration status: Connected - home network

[0m

 

 

[00:00:10.133,544]

[0m<inf> asset_tracker: PSM parameter update: TAU: 86400, Active time: -1

[0m

 

[00:00:10.142,242]

[0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTING

[0m

 

 

[00:00:10.150,695]

[0m<inf> asset_tracker: CLOUD_EVT_CONNECTING

[0m

 

 

[00:00:20.343,505]

[0m<dbg> nrf_cloud_transport.nct_connect: IPv4 address: 54.166.31.114

[0m

 

 

[00:00:20.351,715]

[0m<dbg> nrf_cloud_transport.nct_mqtt_connect: MQTT clean session flag: 0

[0m

 

 

[00:00:25.044,555]

[1;33m<wrn> date_time: sntp_query, error: -116

[0m

 

 

[00:00:32.817,443]

[1;33m<wrn> date_time: sntp_query, error: -116

[0m

 

 

[00:00:38.944,549]

[1;33m<wrn> date_time: sntp_query, error: -116

[0m

 

[00:00:44.977,661]

[1;33m<wrn> date_time: sntp_query, error: -116

[0m

 

 

[00:00:51.057,739]

[1;33m<wrn> date_time: sntp_query, error: -116

[0m

 

 

[00:00:51.064,270]

[1;33m<wrn> date_time: Not getting time from any NTP server

[0m

 

 

[00:00:51.072,357]

[0m<inf> asset_tracker: DATE_TIME_OBTAINED_MODEM

[0m

 

 

+CSCON: 0

 

 

[00:01:16.166,137]

[0m<inf> asset_tracker: RRC mode: Idle

[0m

 

 

+CSCON: 1

 

 

[00:01:21.380,767]

[0m<inf> asset_tracker: RRC mode: Connected

[0m

 

 

+CSCON: 0

 

 

[00:01:43.162,567]

[0m<inf> asset_tracker: RRC mode: Idle

[0m

 

 

+CSCON: 1

 

 

[00:02:13.541,534]

[0m<inf> asset_tracker: RRC mode: Connected

[0m

 

 

+CSCON: 0

 

 

[00:02:35.173,370]

[0m<inf> asset_tracker: RRC mode: Idle

[0m

 

 

[00:03:00.723,693]

[0m<dbg> nrf_cloud_transport.nct_mqtt_connect: mqtt_connect failed -22

[0m

 

 

[00:03:00.732,025]

[0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTING

[0m

 

 

[00:03:00.740,509]

[0m<inf> asset_tracker: CLOUD_EVT_CONNECTING

[0m

 

 

[00:03:00.746,582]

[1;31m<err> asset_tracker: Failed to connect to cloud, error -7

[0m

 

 

[00:03:00.754,333]

[1;31m<err> asset_tracker: Ensure device has a valid private key

[0m

 

 

[00:03:00.762,145]

[1;31m<err> asset_tracker: Device will reboot in 300 seconds

[0m

 

 

[00:03:00.769,653]

[1;31m<err> asset_tracker: LTE link disconnect

[0m

 

 

+CSCON: 1

 

 

[00:03:01.222,259]

[0m<inf> asset_tracker: RRC mode: Connected

[0m

 

 

+CEREG: 0,"765E","075D6450",9,0,0,"11100000","11100000"

 

 

+CSCON: 0

 

 

[00:03:06.757,415]

[0m<inf> asset_tracker: RRC mode: Idle

[0m

 

 

[00:03:07.170,684]

[1;31m<err> asset_tracker: Shutdown modem

[0m

[Heidi]

Hi!

1. When using the Chine Mobile Cellphone SIM, is it connecting through LTE-M or NB-IoT? The +CEREG response field AcT will return 7 for LTE-M and 9 for NB-IoT.

2. You say LED1 and LED4 blinks at last, which isn't one of the defined application states (see Asset Tracker: User interface). Could you take a look at the documentation and tell me if the LED blinking pattern matches any of them?

3. From the iBasis log it doesn't look like it's done connecting to the network. Please wait at least 10 minutes as it can take a while for the device to connect to the network and to nRF Cloud. 

[00:00:00.343,688] [0m<inf> asset_tracker: Connecting to LTE network.[0m
[00:00:00.350,280] [0m<inf> asset_tracker: This may take several minutes.[0m
+CEREG: 2,"FFFE","FFFFFFFF",7,0,0,"11100000","11100000"
[00:00:58.980,285] [0m<inf> asset_tracker: LTE cell changed: Cell ID: -1, Tracking area: 65534[0m

4. As for the issues with China Telecom NB-IoT SIM, we're going to need a modem trace to investigate further (see Collecting a modem trace for the nRF9160 DK). 

[AlbertSerica]

Hello, 

China doesn't have LTE-M so only NB-IoT is used. CEREG returns 9.

Blinking in cross pattern (LED 1 and 4, LED 2 and 3): Communication error with the nRF Connect for Cloud.

The asset tracker connected to the Internet after a few minutes. 

2021-06-15T01:56:50.457Z DEBUG modem << [00:00:10.103,912] [0m<inf> asset_tracker: Connected to LTE network.[0m

The problem I encountered seems to be related to zzhc library, there is a page about zzhc but it's not clear about how to use it:

developer.nordicsemi.com/.../zzhc.html

[AlbertSerica]

Hello, I'm afraid it's not a nrf cloud certificate issue as I can use China Mobile NB-IoT card without any problem now. 

After confirming that I removed my devices from my account, downloaded the certificate again. Then made changes in proj.conf file, update the certificate on the dev kit, and start using China Telecom NB-IoT card. The log is as recorded: 

Fullscreen 2021-06-30T01_14_12.152Z-log.txt Download

2021-06-30T01:14:12.613Z INFO Application data folder: C:\Users\aaa\AppData\Roaming\nrfconnect\pc-nrfconnect-linkmonitor
2021-06-30T01:14:12.637Z DEBUG App pc-nrfconnect-linkmonitor v1.1.10 official
2021-06-30T01:14:12.637Z DEBUG App path: C:\Users\aaa\.nrfconnect-apps\node_modules\pc-nrfconnect-linkmonitor
2021-06-30T01:14:12.637Z DEBUG nRFConnect 3.7.0, required by the app is (^3.6.0)
2021-06-30T01:14:12.637Z DEBUG nRFConnect path: C:\Users\aaa\AppData\Local\Programs\nrfconnect\resources\app.asar
2021-06-30T01:14:12.638Z DEBUG HomeDir: C:\Users\aaa
2021-06-30T01:14:12.638Z DEBUG TmpDir: C:\Users\aaa\AppData\Local\Temp
2021-06-30T01:14:15.860Z INFO Modem port is opened
2021-06-30T01:14:17.754Z DEBUG modem << *** Booting Zephyr OS build v2.4.99-ncs2  ***
2021-06-30T01:14:17.768Z DEBUG modem << I: Starting bootloader
2021-06-30T01:14:17.769Z DEBUG modem << I: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
2021-06-30T01:14:17.771Z DEBUG modem << I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
2021-06-30T01:14:17.772Z DEBUG modem << I: Boot source: none
2021-06-30T01:14:17.774Z DEBUG modem << I: Swap type: none
2021-06-30T01:14:18.051Z DEBUG modem << I: Bootloader chainload address offset: 0x10000
2021-06-30T01:14:18.055Z DEBUG modem << I: Jumping to the first image slot
2021-06-30T01:14:18.060Z DEBUG modem << *** Booting Zephyr OS build v2.4.99-ncs2  ***
2021-06-30T01:14:18.062Z DEBUG modem << Flash regionsDomainPermissions
2021-06-30T01:14:18.065Z DEBUG modem << 00 02 0x00000 0x18000 Securerwxl
2021-06-30T01:14:18.068Z DEBUG modem << 03 31 0x18000 0x100000 Non-Securerwxl
2021-06-30T01:14:18.079Z DEBUG modem << Non-secure callable region 0 placed in flash region 2 with size 32.
2021-06-30T01:14:18.245Z DEBUG modem << SRAM regionDomainPermissions
2021-06-30T01:14:18.251Z DEBUG modem << 00 07 0x00000 0x10000 Securerwxl
2021-06-30T01:14:18.253Z DEBUG modem << 08 31 0x10000 0x40000 Non-Securerwxl
2021-06-30T01:14:18.256Z DEBUG modem << PeripheralDomainStatus
2021-06-30T01:14:18.261Z DEBUG modem << 00 NRF_P0               Non-SecureOK
2021-06-30T01:14:18.263Z DEBUG modem << 01 NRF_CLOCK            Non-SecureOK
2021-06-30T01:14:18.266Z DEBUG modem << 02 NRF_RTC0             Non-SecureOK
2021-06-30T01:14:18.268Z DEBUG modem << 03 NRF_RTC1             Non-SecureOK
2021-06-30T01:14:18.271Z DEBUG modem << 04 NRF_NVMC             Non-SecureOK
2021-06-30T01:14:18.277Z DEBUG modem << 05 NRF_UARTE1           Non-SecureOK
2021-06-30T01:14:18.280Z DEBUG modem << 06 NRF_UARTE2           SecureSKIP
2021-06-30T01:14:18.283Z DEBUG modem << 07 NRF_TWIM2            Non-SecureOK
2021-06-30T01:14:18.285Z DEBUG modem << 08 NRF_SPIM3            Non-SecureOK
2021-06-30T01:14:18.288Z DEBUG modem << 09 NRF_TIMER0           Non-SecureOK
2021-06-30T01:14:18.294Z DEBUG modem << 10 NRF_TIMER1           Non-SecureOK
2021-06-30T01:14:18.296Z DEBUG modem << 11 NRF_TIMER2           Non-SecureOK
2021-06-30T01:14:18.299Z DEBUG modem << 12 NRF_SAADC            Non-SecureOK
2021-06-30T01:14:18.302Z DEBUG modem << 13 NRF_PWM0             Non-SecureOK
2021-06-30T01:14:18.305Z DEBUG modem << 14 NRF_PWM1             Non-SecureOK
2021-06-30T01:14:18.311Z DEBUG modem << 15 NRF_PWM2             Non-SecureOK
2021-06-30T01:14:18.314Z DEBUG modem << 16 NRF_PWM3             Non-SecureOK
2021-06-30T01:14:18.315Z DEBUG modem << 17 NRF_WDT              Non-SecureOK
2021-06-30T01:14:18.319Z DEBUG modem << 18 NRF_IPC              Non-SecureOK
2021-06-30T01:14:18.322Z DEBUG modem << 19 NRF_VMC              Non-SecureOK
2021-06-30T01:14:18.327Z DEBUG modem << 20 NRF_FPU              Non-SecureOK
2021-06-30T01:14:18.329Z DEBUG modem << 21 NRF_EGU1             Non-SecureOK
2021-06-30T01:14:18.333Z DEBUG modem << 22 NRF_EGU2             Non-SecureOK
2021-06-30T01:14:18.335Z DEBUG modem << 23 NRF_DPPIC            Non-SecureOK
2021-06-30T01:14:18.339Z DEBUG modem << 24 NRF_REGULATORS       Non-SecureOK
2021-06-30T01:14:18.344Z DEBUG modem << 25 NRF_GPIOTE1          Non-SecureOK
2021-06-30T01:14:18.347Z DEBUG modem << SPM: NS image at 0x1c200
2021-06-30T01:14:18.349Z DEBUG modem << SPM: NS MSP at 0x200228e0
2021-06-30T01:14:18.351Z DEBUG modem << SPM: NS reset vector at 0x26dad
2021-06-30T01:14:18.354Z DEBUG modem << SPM: prepare to jump to Non-Secure image.
2021-06-30T01:14:18.563Z DEBUG modem << *** Booting Zephyr OS build v2.4.99-ncs2  ***
2021-06-30T01:15:18.187Z DEBUG modem << +CEREG: 2,"FFFE","FFFFFFFF",7,0,0,"11100000","11100000"
2021-06-30T01:24:18.646Z DEBUG modem << [00:10:00.280,944] [0m<inf> lte_lc: Network connection attempt timed out[0m
2021-06-30T01:24:18.657Z DEBUG modem << +CEREG: 0,"FFFE","FFFFFFFF",7,0,0,"11100000","11100000"
2021-06-30T01:24:18.670Z DEBUG modem << [00:10:00.303,771] [0m<inf> lte_lc: Using fallback network mode[0m
2021-06-30T01:24:26.933Z DEBUG modem << +CEREG: 2,"765E","075D6450",9,0,0,"11100000","11100000"
2021-06-30T01:24:27.582Z DEBUG modem << +CSCON: 1
2021-06-30T01:24:29.591Z DEBUG modem << +CEREG: 1,"765E","075D6450",9,,,"11100000","00111000"
2021-06-30T01:24:29.599Z DEBUG modem << [00:10:11.238,037] [0m<inf> asset_tracker: Asset tracker started[0m
2021-06-30T01:24:29.605Z DEBUG modem << [00:10:11.244,171] [0m<inf> watchdog: Watchdog timeout installed. Timeout: 60000[0m
2021-06-30T01:24:29.610Z DEBUG modem << [00:10:11.251,678] [0m<inf> watchdog: Watchdog started[0m
2021-06-30T01:24:29.618Z DEBUG modem << [00:10:11.256,988] [0m<inf> watchdog: Watchdog feed enabled. Timeout: 30000[0m
2021-06-30T01:24:29.631Z DEBUG modem << [00:10:11.268,981] [0m<dbg> nrf_cloud_transport.nct_settings_set: Settings key: p_sesh, size: 4[0m
2021-06-30T01:24:29.639Z DEBUG modem << [00:10:11.277,832] [0m<dbg> nrf_cloud_transport.nct_settings_set: Read setting val: 1[0m
2021-06-30T01:24:29.652Z DEBUG modem << [00:10:11.290,008] [0m<dbg> nrf_cloud_transport.nct_client_id_get: client_id = nrf-352656100109613[0m
2021-06-30T01:24:29.664Z DEBUG modem << [00:10:11.299,163] [0m<dbg> nrf_cloud_transport.nct_topics_populate: shadow_base_topic: $aws/things/nrf-352656100109613/shadow[0m
2021-06-30T01:24:29.675Z DEBUG modem << [00:10:11.310,760] [0m<dbg> nrf_cloud_transport.nct_topics_populate: accepted_topic: nrf-352656100109613/shadow/get/accepted[0m
2021-06-30T01:24:29.687Z DEBUG modem << [00:10:11.322,143] [0m<dbg> nrf_cloud_transport.nct_topics_populate: rejected_topic: $aws/things/nrf-352656100109613/shadow/get/rejected[0m
2021-06-30T01:24:29.701Z DEBUG modem << [00:10:11.334,594] [0m<dbg> nrf_cloud_transport.nct_topics_populate: update_delta_topic: $aws/things/nrf-352656100109613/shadow/update/delta[0m
2021-06-30T01:24:29.712Z DEBUG modem << [00:10:11.347,412] [0m<dbg> nrf_cloud_transport.nct_topics_populate: update_topic: $aws/things/nrf-352656100109613/shadow/update[0m
2021-06-30T01:24:29.724Z DEBUG modem << [00:10:11.359,161] [0m<dbg> nrf_cloud_transport.nct_topics_populate: shadow_get_topic: $aws/things/nrf-352656100109613/shadow/get[0m
2021-06-30T01:24:29.730Z DEBUG modem << [00:10:11.371,032] [0m<inf> asset_tracker: Connected to LTE network.[0m
2021-06-30T01:24:29.738Z DEBUG modem << [00:10:11.377,655] [0m<inf> asset_tracker: Connecting to cloud, attempt 1 of 8[0m
2021-06-30T01:24:29.745Z DEBUG modem << [00:10:11.385,009] [0m<inf> asset_tracker: Cloud connection request sent.[0m
2021-06-30T01:24:29.753Z DEBUG modem << [00:10:11.391,937] [0m<inf> asset_tracker: Connection response timeout is set to 30 seconds.[0m
2021-06-30T01:24:29.767Z DEBUG modem << [0[00:10:11.405,792] [0m<dbg> nrf_cloud_transport.nct_settings_set: Settings key: p_sesh, size: 4[0m
2021-06-30T01:24:29.776Z DEBUG modem << [00:10:11.414,642] [0m<dbg> nrf_cloud_transport.nct_settings_set: Read setting val: 1[0m
2021-06-30T01:24:29.785Z DEBUG modem << 0:10:11.400,848] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTING[0m
2021-06-30T01:24:29.791Z DEBUG modem << [00:10:11.432,128] [0m<inf> asset_tracker: CLOUD_EVT_CONNECTING[0m
2021-06-30T01:24:31.422Z DEBUG modem << [00:10:13.059,661] [0m<dbg> nrf_cloud_transport.nct_connect: IPv4 address: 52.200.176.113[0m
2021-06-30T01:24:31.430Z DEBUG modem << [00:10:13.068,023] [0m<dbg> nrf_cloud_transport.nct_mqtt_connect: MQTT clean session flag: 0[0m
2021-06-30T01:24:36.089Z DEBUG modem << [00:10:17.729,522] [1;33m<wrn> date_time: sntp_query, error: -116[0m
2021-06-30T01:24:41.569Z DEBUG modem << [00:10:23.209,503] [1;33m<wrn> date_time: sntp_query, error: -116[0m
2021-06-30T01:24:47.552Z DEBUG modem << [00:10:29.192,626] [1;33m<wrn> date_time: sntp_query, error: -116[0m
2021-06-30T01:24:53.585Z DEBUG modem << [00:10:35.225,677] [1;33m<wrn> date_time: sntp_query, error: -116[0m
2021-06-30T01:24:59.665Z DEBUG modem << [00:10:41.305,755] [1;33m<wrn> date_time: sntp_query, error: -116[0m
2021-06-30T01:24:59.673Z DEBUG modem << [00:10:41.312,286] [1;33m<wrn> date_time: Not getting time from any NTP server[0m
2021-06-30T01:24:59.683Z DEBUG modem << [00:10:41.320,343] [0m<inf> asset_tracker: DATE_TIME_OBTAINED_MODEM[0m
2021-06-30T01:25:27.369Z DEBUG modem << +CSCON: 0
2021-06-30T01:25:27.374Z DEBUG modem << [00:11:09.015,197] [0m<inf> asset_tracker: RRC mode: Idle[0m
2021-06-30T01:25:31.262Z DEBUG modem << +CSCON: 1
2021-06-30T01:25:31.268Z DEBUG modem << [00:11:12.908,752] [0m<inf> asset_tracker: RRC mode: Connected[0m
2021-06-30T01:25:53.383Z DEBUG modem << +CSCON: 0
2021-06-30T01:25:53.389Z DEBUG modem << [00:11:35.030,578] [0m<inf> asset_tracker: RRC mode: Idle[0m
2021-06-30T01:26:23.422Z DEBUG modem << +CSCON: 1
2021-06-30T01:26:23.429Z DEBUG modem << [00:12:05.069,519] [0m<inf> asset_tracker: RRC mode: Connected[0m
2021-06-30T01:26:45.408Z DEBUG modem << +CSCON: 0
2021-06-30T01:26:45.413Z DEBUG modem << [00:12:27.055,328] [0m<inf> asset_tracker: RRC mode: Idle[0m
2021-06-30T01:27:12.212Z DEBUG modem << [00:12:53.851,654] [0m<dbg> nrf_cloud_transport.nct_mqtt_connect: mqtt_connect failed -22[0m
2021-06-30T01:27:12.220Z DEBUG modem << [00:12:53.860,015] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTING[0m
2021-06-30T01:27:12.227Z DEBUG modem << [00:12:53.868,499] [0m<inf> asset_tracker: CLOUD_EVT_CONNECTING[0m
2021-06-30T01:27:12.235Z DEBUG modem << [00:12:53.874,603] [1;31m<err> asset_tracker: Failed to connect to cloud, error -7[0m
2021-06-30T01:27:12.242Z DEBUG modem << [00:12:53.882,354] [1;31m<err> asset_tracker: Ensure device has a valid private key[0m
2021-06-30T01:27:12.249Z DEBUG modem << [00:12:53.890,197] [1;31m<err> asset_tracker: Device will reboot in 300 seconds[0m
2021-06-30T01:27:12.256Z DEBUG modem << [00:12:53.897,674] [1;31m<err> asset_tracker: LTE link disconnect[0m
2021-06-30T01:27:12.702Z DEBUG modem << +CSCON: 1
2021-06-30T01:27:12.709Z DEBUG modem << [00:12:54.350,219] [0m<inf> asset_tracker: RRC mode: Connected[0m
2021-06-30T01:27:18.176Z DEBUG modem << +CEREG: 0,"765E","075D6450",9,0,0,"11100000","11100000"
2021-06-30T01:27:18.187Z DEBUG modem << [00:12:59.824,584] [0m<inf> asset_tracker: LTE cell changed: Cell ID: 123561040, Tracking area: 30302[0m
2021-06-30T01:27:18.246Z DEBUG modem << +CSCON: 0
2021-06-30T01:27:18.251Z DEBUG modem << [00:12:59.893,371] [0m<inf> asset_tracker: RRC mode: Idle[0m
2021-06-30T01:27:18.594Z DEBUG modem << %XSIM: 0
2021-06-30T01:27:18.741Z DEBUG modem << [00:13:00.383,331] [1;31m<err> asset_tracker: Shutdown modem[0m

[Heidi]

Hi, please attach the log when connecting with China Mobile NB-IoT card.

To investigate the issue further, we're going to need a modem trace from the China Telecom NB-IoT card.

[AlbertSerica]

Hello, Heidi. Thank you for your reply. The attachment is the log. I remove the device from my cloud, reinstall the hex file, and update modem firmware. Then I download and update the certificate from cloud. After that, I insert China Mobile NB card, turn on the dev kit and connect it back to my cloud.

Fullscreen 2021-06-30T08_05_24.885Z-log.txt Download

2021-06-30T08:05:25.295Z INFO Application data folder: C:\Users\aaa\AppData\Roaming\nrfconnect\pc-nrfconnect-linkmonitor
2021-06-30T08:05:25.340Z DEBUG App pc-nrfconnect-linkmonitor v1.1.10 official
2021-06-30T08:05:25.340Z DEBUG App path: C:\Users\aaa\.nrfconnect-apps\node_modules\pc-nrfconnect-linkmonitor
2021-06-30T08:05:25.340Z DEBUG nRFConnect 3.7.0, required by the app is (^3.6.0)
2021-06-30T08:05:25.340Z DEBUG nRFConnect path: C:\Users\aaa\AppData\Local\Programs\nrfconnect\resources\app.asar
2021-06-30T08:05:25.340Z DEBUG HomeDir: C:\Users\aaa
2021-06-30T08:05:25.340Z DEBUG TmpDir: C:\Users\aaa\AppData\Local\Temp
2021-06-30T08:05:27.501Z INFO Modem port is opened
2021-06-30T08:05:30.455Z DEBUG modem << *** Booting Zephyr OS build v2.4.99-ncs1  ***
2021-06-30T08:05:30.468Z DEBUG modem << I: Starting bootloader
2021-06-30T08:05:30.470Z DEBUG modem << I: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
2021-06-30T08:05:30.473Z DEBUG modem << I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
2021-06-30T08:05:30.474Z DEBUG modem << I: Boot source: none
2021-06-30T08:05:30.476Z DEBUG modem << I: Swap type: none
2021-06-30T08:05:30.749Z DEBUG modem << I: Bootloader chainload address offset: 0x10000
2021-06-30T08:05:30.753Z DEBUG modem << I: Jumping to the first image slot
2021-06-30T08:05:30.756Z DEBUG modem << *** Booting Zephyr OS build v2.4.99-ncs1  ***
2021-06-30T08:05:30.760Z DEBUG modem << Flash regionsDomainPermissions
2021-06-30T08:05:30.763Z DEBUG modem << 00 02 0x00000 0x18000 Securerwxl
2021-06-30T08:05:30.766Z DEBUG modem << 03 31 0x18000 0x100000 Non-Securerwxl
2021-06-30T08:05:30.772Z DEBUG modem << Non-secure callable region 0 placed in flash region 2 with size 32.
2021-06-30T08:05:30.943Z DEBUG modem << SRAM regionDomainPermissions
2021-06-30T08:05:30.948Z DEBUG modem << 00 07 0x00000 0x10000 Securerwxl
2021-06-30T08:05:30.951Z DEBUG modem << 08 31 0x10000 0x40000 Non-Securerwxl
2021-06-30T08:05:30.954Z DEBUG modem << PeripheralDomainStatus
2021-06-30T08:05:30.956Z DEBUG modem << 00 NRF_P0               Non-SecureOK
2021-06-30T08:05:30.961Z DEBUG modem << 01 NRF_CLOCK            Non-SecureOK
2021-06-30T08:05:30.965Z DEBUG modem << 02 NRF_RTC0             Non-SecureOK
2021-06-30T08:05:30.968Z DEBUG modem << 03 NRF_RTC1             Non-SecureOK
2021-06-30T08:05:30.969Z DEBUG modem << 04 NRF_NVMC             Non-SecureOK
2021-06-30T08:05:30.972Z DEBUG modem << 05 NRF_UARTE1           Non-SecureOK
2021-06-30T08:05:30.978Z DEBUG modem << 06 NRF_UARTE2           SecureSKIP
2021-06-30T08:05:30.980Z DEBUG modem << 07 NRF_TWIM2            Non-SecureOK
2021-06-30T08:05:30.984Z DEBUG modem << 08 NRF_SPIM3            Non-SecureOK
2021-06-30T08:05:30.986Z DEBUG modem << 09 NRF_TIMER0           Non-SecureOK
2021-06-30T08:05:30.989Z DEBUG modem << 10 NRF_TIMER1           Non-SecureOK
2021-06-30T08:05:30.995Z DEBUG modem << 11 NRF_TIMER2           Non-SecureOK
2021-06-30T08:05:30.997Z DEBUG modem << 12 NRF_SAADC            Non-SecureOK
2021-06-30T08:05:31.000Z DEBUG modem << 13 NRF_PWM0             Non-SecureOK
2021-06-30T08:05:31.004Z DEBUG modem << 14 NRF_PWM1             Non-SecureOK
2021-06-30T08:05:31.006Z DEBUG modem << 15 NRF_PWM2             Non-SecureOK
2021-06-30T08:05:31.011Z DEBUG modem << 16 NRF_PWM3             Non-SecureOK
2021-06-30T08:05:31.014Z DEBUG modem << 17 NRF_WDT              Non-SecureOK
2021-06-30T08:05:31.016Z DEBUG modem << 18 NRF_IPC              Non-SecureOK
2021-06-30T08:05:31.019Z DEBUG modem << 19 NRF_VMC              Non-SecureOK
2021-06-30T08:05:31.023Z DEBUG modem << 20 NRF_FPU              Non-SecureOK
2021-06-30T08:05:31.028Z DEBUG modem << 21 NRF_EGU1             Non-SecureOK
2021-06-30T08:05:31.032Z DEBUG modem << 22 NRF_EGU2             Non-SecureOK
2021-06-30T08:05:31.034Z DEBUG modem << 23 NRF_DPPIC            Non-SecureOK
2021-06-30T08:05:31.036Z DEBUG modem << 24 NRF_REGULATORS       Non-SecureOK
2021-06-30T08:05:31.039Z DEBUG modem << 25 NRF_GPIOTE1          Non-SecureOK
2021-06-30T08:05:31.044Z DEBUG modem << SPM: NS image at 0x1c200
2021-06-30T08:05:31.048Z DEBUG modem << SPM: NS MSP at 0x20025598
2021-06-30T08:05:31.049Z DEBUG modem << SPM: NS reset vector at 0x26805
2021-06-30T08:05:31.051Z DEBUG modem << SPM: prepare to jump to Non-Secure image.
2021-06-30T08:05:31.261Z DEBUG modem << *** Booting Zephyr OS build v2.4.99-ncs1  ***
2021-06-30T08:05:31.274Z DEBUG modem << [00:00:00.212,280] [0m<inf> asset_tracker: Asset tracker started[0m
2021-06-30T08:05:31.287Z DEBUG modem << [00:00:00.218,414] [0m<inf> watchdog: Watchdog timeout installed. Timeout: 60000[0m
2021-06-30T08:05:31.289Z DEBUG modem << [00:00:00.225,921] [0m<inf> watchdog: Watchdog started[0m
2021-06-30T08:05:31.296Z DEBUG modem << [00:00:00.231,231] [0m<inf> watchdog: Watchdog feed enabled. Timeout: 30000[0m
2021-06-30T08:05:31.311Z DEBUG modem << [00:00:00.245,605] [0m<dbg> nrf_cloud_transport.nct_client_id_get: client_id = nrf-352656100109613[0m
2021-06-30T08:05:31.322Z DEBUG modem << [00:00:00.254,699] [0m<dbg> nrf_cloud_transport.nct_topics_populate: shadow_base_topic: $aws/things/nrf-352656100109613/shadow[0m
2021-06-30T08:05:31.334Z DEBUG modem << [00:00:00.266,235] [0m<dbg> nrf_cloud_transport.nct_topics_populate: accepted_topic: nrf-352656100109613/shadow/get/accepted[0m
2021-06-30T08:05:31.346Z DEBUG modem << [00:00:00.277,648] [0m<dbg> nrf_cloud_transport.nct_topics_populate: rejected_topic: $aws/things/nrf-352656100109613/shadow/get/rejected[0m
2021-06-30T08:05:31.362Z DEBUG modem << [00:00:00.290,222] [0m<dbg> nrf_cloud_transport.nct_topics_populate: update_delta_topic: $aws/things/nrf-352656100109613/shadow/update/delta[0m
2021-06-30T08:05:31.370Z DEBUG modem << [00:00:00.303,070] [0m<dbg> nrf_cloud_transport.nct_topics_populate: update_topic: $aws/things/nrf-352656100109613/shadow/update[0m
2021-06-30T08:05:31.383Z DEBUG modem << [00:00:00.314,880] [0m<dbg> nrf_cloud_transport.nct_topics_populate: shadow_get_topic: $aws/things/nrf-352656100109613/shadow/get[0m
2021-06-30T08:05:31.389Z DEBUG modem << [00:00:00.326,751] [0m<inf> asset_tracker: Connecting to LTE network.[0m
2021-06-30T08:05:31.396Z DEBUG modem << [00:00:00.333,343] [0m<inf> asset_tracker: This may take several minutes.[0m
2021-06-30T08:05:36.241Z DEBUG modem << +CEREG: 2,"1D03","0D4DAA48",9,0,0,"11100000","11100000"
2021-06-30T08:05:36.253Z DEBUG modem << [00:00:05.185,180] [0m<inf> asset_tracker: LTE cell changed: Cell ID: 223193672, Tracking area: 7427[0m
2021-06-30T08:05:37.276Z DEBUG modem << +CSCON: 1
2021-06-30T08:05:37.282Z DEBUG modem << [00:00:06.219,970] [0m<inf> asset_tracker: RRC mode: Connected[0m
2021-06-30T08:05:37.833Z DEBUG modem << +CEREG: 1,"1D03","0D4DAA48",9,,,"11100000","11100000"
2021-06-30T08:05:37.840Z DEBUG modem << [00:00:06.778,106] [0m<inf> asset_tracker: Connected to LTE network.[0m
2021-06-30T08:05:37.848Z DEBUG modem << [00:00:06.784,698] [0m<inf> asset_tracker: Connecting to cloud, attempt 1 of 8[0m
2021-06-30T08:05:37.855Z DEBUG modem << [00:00:06.792,083] [0m<inf> asset_tracker: Cloud connection request sent.[0m
2021-06-30T08:05:37.863Z DEBUG modem << [00:00:06.799,011] [0m<inf> asset_tracker: Connection response timeout is set to 30 seconds.[0m
2021-06-30T08:05:37.872Z DEBUG modem << [00:00:06.807,739] [0m<inf> asset_tracker: Network registration status: Connected - home network[0m
2021-06-30T08:05:37.881Z DEBUG modem << [00:00:06.816,619] [0m<inf> asset_tracker: PSM parameter update: TAU: -1, Active time: -1[0m
2021-06-30T08:05:37.889Z DEBUG modem << [00:00:06.825,103] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTING[0m
2021-06-30T08:05:37.895Z DEBUG modem << [00:00:06.833,618] [0m<inf> asset_tracker: CLOUD_EVT_CONNECTING[0m
2021-06-30T08:05:38.281Z DEBUG modem << [00:00:07.217,712] [0m<dbg> nrf_cloud_transport.nct_connect: IPv4 address: 52.5.48.147[0m
2021-06-30T08:05:38.291Z DEBUG modem << [00:00:07.225,769] [0m<dbg> nrf_cloud_transport.nct_mqtt_connect: MQTT clean session flag: 1[0m
2021-06-30T08:05:38.571Z DEBUG modem << [00:00:07.508,850] [0m<inf> asset_tracker: DATE_TIME_OBTAINED_NTP[0m
2021-06-30T08:05:44.742Z DEBUG modem << [00:00:13.678,894] [0m<inf> nrf_cloud_transport: Using socket send timeout of 60 seconds[0m
2021-06-30T08:05:44.750Z DEBUG modem << [00:00:13.687,194] [0m<dbg> nrf_cloud.nrf_cloud_run: Cloud connection request sent.[0m
2021-06-30T08:05:45.330Z DEBUG modem << [00:00:14.264,709] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_DISCONNECT: result = -128[0m
2021-06-30T08:05:45.338Z DEBUG modem << [00:00:14.274,383] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 1[0m
2021-06-30T08:05:45.346Z DEBUG modem << [00:00:14.282,012] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_DISCONNECTED[0m
2021-06-30T08:05:45.353Z DEBUG modem << [00:00:14.290,710] [0m<inf> asset_tracker: CLOUD_EVT_DISCONNECTED: 1[0m
2021-06-30T08:05:45.363Z DEBUG modem << [00:00:14.297,302] [0m<inf> asset_tracker: Disconnected by the cloud.[0m
2021-06-30T08:05:45.368Z DEBUG modem << [00:00:14.303,985] [0m<inf> asset_tracker: This can occur during initial nRF Cloud provisioning.[0m
2021-06-30T08:05:45.380Z DEBUG modem << [00:00:14.312,927] [0m<inf> asset_tracker: Attempting reconnect in 10 seconds...[0m
2021-06-30T08:05:45.384Z DEBUG modem << [00:00:14.320,648] [0m<dbg> nrf_cloud.nrf_cloud_run: The cloud socket is already closed.[0m
2021-06-30T08:05:55.384Z DEBUG modem << [00:00:24.320,648] [0m<inf> asset_tracker: Connecting to cloud, attempt 2 of 8[0m
2021-06-30T08:05:55.394Z DEBUG modem << [00:00:24.328,033] [0m<inf> asset_tracker: Cloud connection request sent.[0m
2021-06-30T08:05:55.399Z DEBUG modem << [00:00:24.334,930] [0m<inf> asset_tracker: Connection response timeout is set to 30 seconds.[0m
2021-06-30T08:05:55.412Z DEBUG modem << [00:00:24.343,627] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTING[0m
2021-06-30T08:05:55.415Z DEBUG modem << [00:00:24.352,081] [0m<inf> asset_tracker: CLOUD_EVT_CONNECTING[0m
2021-06-30T08:05:55.423Z DEBUG modem << [00:00:24.358,703] [0m<dbg> nrf_cloud_transport.nct_connect: IPv4 address: 52.5.48.147[0m
2021-06-30T08:06:02.038Z DEBUG modem << [00:00:30.974,121] [0m<inf> nrf_cloud_transport: Using socket send timeout of 60 seconds[0m
2021-06-30T08:06:02.046Z DEBUG modem << [00:00:30.982,360] [0m<dbg> nrf_cloud.nrf_cloud_run: Cloud connection request sent.[0m
2021-06-30T08:06:02.617Z DEBUG modem << [00:00:31.552,215] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_CONNACK: result 0[0m
2021-06-30T08:06:02.625Z DEBUG modem << [00:00:31.561,187] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 2[0m
2021-06-30T08:06:02.633Z DEBUG modem << [00:00:31.568,908] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTED[0m
2021-06-30T08:06:02.639Z DEBUG modem << [00:00:31.577,423] [0m<inf> asset_tracker: CLOUD_EVT_CONNECTED[0m
2021-06-30T08:06:02.647Z DEBUG modem << [00:00:31.583,404] [0m<inf> asset_tracker: Persistent Sessions = 0[0m
2021-06-30T08:06:02.653Z DEBUG modem << [00:00:31.589,843] [0m<dbg> nrf_cloud_transport.nct_cc_connect: nct_cc_connect[0m
2021-06-30T08:06:02.663Z DEBUG modem << [00:00:31.598,175] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 3[0m
2021-06-30T08:06:03.431Z DEBUG modem << [00:00:32.365,234] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_SUBACK: id = 1234 result = 0[0m
2021-06-30T08:06:03.439Z DEBUG modem << [00:00:32.375,152] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 4[0m
2021-06-30T08:06:03.448Z DEBUG modem << [00:00:32.382,812] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 5678 opcode = 0 len = 0[0m
2021-06-30T08:06:03.456Z DEBUG modem << [00:00:32.393,249] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 5[0m
2021-06-30T08:06:06.230Z DEBUG modem << [00:00:35.164,245] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 5678 result = 0[0m
2021-06-30T08:06:06.237Z DEBUG modem << [00:00:35.174,163] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 5[0m
2021-06-30T08:06:06.344Z DEBUG modem << [00:00:35.278,350] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBLISH: id = 37220 len = 50[0m
2021-06-30T08:06:06.355Z DEBUG modem << [00:00:35.290,313] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 1 opcode = 1 len = 168[0m
2021-06-30T08:06:06.366Z DEBUG modem << [00:00:35.301,483] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 6[0m
2021-06-30T08:06:06.374Z DEBUG modem << [00:00:35.309,112] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_USER_ASSOCIATION_REQUEST[0m
2021-06-30T08:06:06.381Z DEBUG modem << [00:00:35.318,023] [0m<inf> asset_tracker: CLOUD_EVT_PAIR_REQUEST[0m
2021-06-30T08:06:06.387Z DEBUG modem << [00:00:35.324,371] [0m<inf> asset_tracker: Add device to cloud account.[0m
2021-06-30T08:06:06.396Z DEBUG modem << [00:00:35.331,146] [0m<inf> asset_tracker: Waiting for cloud association...[0m
2021-06-30T08:06:09.648Z DEBUG modem << [00:00:38.583,282] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 1 result = 0[0m
2021-06-30T08:06:22.419Z DEBUG modem << [00:00:51.354,064] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBLISH: id = 1 len = 503[0m
2021-06-30T08:06:22.435Z DEBUG modem << [00:00:51.371,215] [0m<dbg> nrf_cloud_transport.nct_dc_endpoint_set: nct_dc_endpoint_set[0m
2021-06-30T08:06:22.446Z DEBUG modem << [00:00:51.379,882] [0m<dbg> nrf_cloud_transport.nct_dc_endpoint_get: nct_dc_endpoint_get[0m
2021-06-30T08:06:22.456Z DEBUG modem << [00:00:51.390,350] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 7890 opcode = 1 len = 360[0m
2021-06-30T08:06:22.465Z DEBUG modem << [00:00:51.402,008] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 7[0m
2021-06-30T08:06:22.478Z DEBUG modem << [00:00:51.409,667] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_USER_ASSOCIATED[0m
2021-06-30T08:06:22.480Z DEBUG modem << [00:00:51.417,816] [0m<inf> asset_tracker: CLOUD_EVT_PAIR_DONE[0m
2021-06-30T08:06:22.486Z DEBUG modem << [00:00:51.423,797] [0m<inf> asset_tracker: Device associated with cloud.[0m
2021-06-30T08:06:22.497Z DEBUG modem << [00:00:51.430,755] [0m<inf> asset_tracker: Reconnecting for cloud policy to take effect.[0m
2021-06-30T08:06:22.502Z DEBUG modem << [00:00:51.439,117] [0m<inf> asset_tracker: Disconnecting from cloud...[0m
2021-06-30T08:06:22.515Z DEBUG modem << [00:00:51.445,800] [0m<dbg> nrf_cloud_transport.nct_disconnect: nct_disconnect[0m
2021-06-30T08:06:22.521Z DEBUG modem << [00:00:51.453,430] [0m[00:00:51.455,627] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_DISCONNECT: result = 0[0m
2021-06-30T08:06:22.531Z DEBUG modem << <inf> asset_tracker: CLOUD_EVT_FOTA_ERROR[0m
2021-06-30T08:06:22.533Z DEBUG modem << [00:00:51.469,055] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 1[0m
2021-06-30T08:06:22.548Z DEBUG modem << [00:00:51.476,684] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_DISCONNECTED[0m
2021-06-30T08:06:22.549Z DEBUG modem << [00:00:51.485,351] [0m<inf> asset_tracker: CLOUD_EVT_DISCONNECTED: 0[0m
2021-06-30T08:06:22.555Z DEBUG modem << [00:00:51.491,882] [0m<inf> asset_tracker: Attempting reconnect in 10 seconds...[0m
2021-06-30T08:06:22.564Z DEBUG modem << [00:00:51.499,633] [0m<dbg> nrf_cloud.nrf_cloud_run: The cloud socket is already closed.[0m
2021-06-30T08:06:32.562Z DEBUG modem << [00:01:01.499,511] [0m<inf> asset_tracker: Connecting to cloud, attempt 1 of 8[0m
2021-06-30T08:06:32.571Z DEBUG modem << [00:01:01.506,927] [0m<inf> asset_tracker: Cloud connection request sent.[0m
2021-06-30T08:06:32.582Z DEBUG modem << [00:01:01.513,824] [0m<inf> asset_tracker: Connection response timeout is set to 30 seconds.[0m
2021-06-30T08:06:32.587Z DEBUG modem << [00:01:01.522,521] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTING[0m
2021-06-30T08:06:32.598Z DEBUG modem << [00:01:01.530,975] [0m<inf> asset_tracker: CLOUD_EVT_CONNECTING[0m
2021-06-30T08:06:32.601Z DEBUG modem << [00:01:01.537,658] [0m<dbg> nrf_cloud_transport.nct_connect: IPv4 address: 52.5.48.147[0m
2021-06-30T08:06:39.146Z DEBUG modem << [00:01:08.082,702] [0m<inf> nrf_cloud_transport: Using socket send timeout of 60 seconds[0m
2021-06-30T08:06:39.154Z DEBUG modem << [00:01:08.090,911] [0m<dbg> nrf_cloud.nrf_cloud_run: Cloud connection request sent.[0m
2021-06-30T08:06:39.702Z DEBUG modem << [00:01:08.637,756] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_CONNACK: result 0[0m
2021-06-30T08:06:39.709Z DEBUG modem << [00:01:08.646,667] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 2[0m
2021-06-30T08:06:39.718Z DEBUG modem << [00:01:08.654,388] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTED[0m
2021-06-30T08:06:39.729Z DEBUG modem << [00:01:08.662,811] [0m<inf> asset_tracker: CLOUD_EVT_CONNECTED[0m
2021-06-30T08:06:39.731Z DEBUG modem << [00:01:08.668,884] [0m<inf> asset_tracker: Persistent Sessions = 0[0m
2021-06-30T08:06:39.738Z DEBUG modem << [00:01:08.675,323] [0m<dbg> nrf_cloud_transport.nct_cc_connect: nct_cc_connect[0m
2021-06-30T08:06:39.747Z DEBUG modem << [00:01:08.683,593] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 3[0m
2021-06-30T08:06:40.558Z DEBUG modem << [00:01:09.492,767] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_SUBACK: id = 1234 result = 0[0m
2021-06-30T08:06:40.566Z DEBUG modem << [00:01:09.502,685] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 4[0m
2021-06-30T08:06:40.579Z DEBUG modem << [00:01:09.510,345] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 5678 opcode = 0 len = 0[0m
2021-06-30T08:06:40.584Z DEBUG modem << [00:01:09.520,996] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 5[0m
2021-06-30T08:06:41.419Z DEBUG modem << [00:01:10.353,790] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 5678 result = 0[0m
2021-06-30T08:06:41.427Z DEBUG modem << [00:01:10.363,647] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 5[0m
2021-06-30T08:06:41.634Z DEBUG modem << [00:01:10.569,000] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBLISH: id = 37220 len = 283[0m
2021-06-30T08:06:41.645Z DEBUG modem << [00:01:10.582,061] [0m<dbg> nrf_cloud_transport.nct_dc_endpoint_set: nct_dc_endpoint_set[0m
2021-06-30T08:06:41.655Z DEBUG modem << [00:01:10.590,728] [0m<dbg> nrf_cloud_transport.nct_dc_endpoint_get: nct_dc_endpoint_get[0m
2021-06-30T08:06:41.666Z DEBUG modem << [00:01:10.601,135] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 7890 opcode = 1 len = 360[0m
2021-06-30T08:06:41.679Z DEBUG modem << [00:01:10.612,609] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 7[0m
2021-06-30T08:06:41.684Z DEBUG modem << [00:01:10.620,239] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_USER_ASSOCIATED[0m
2021-06-30T08:06:41.690Z DEBUG modem << [00:01:10.628,417] [0m<inf> asset_tracker: CLOUD_EVT_PAIR_DONE[0m
2021-06-30T08:06:41.698Z DEBUG modem << [00:01:10.634,490] [0m<inf> asset_tracker: CLOUD_EVT_FOTA_ERROR[0m
2021-06-30T08:06:45.283Z DEBUG modem << [00:01:14.217,834] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 7890 result = 0[0m
2021-06-30T08:06:45.290Z DEBUG modem << [00:01:14.227,722] [0m<dbg> nrf_cloud_transport.nct_dc_connect: nct_dc_connect[0m
2021-06-30T08:06:45.299Z DEBUG modem << [00:01:14.236,114] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 8[0m
2021-06-30T08:06:45.810Z DEBUG modem << [00:01:14.744,873] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_SUBACK: id = 8765 result = 0[0m
2021-06-30T08:06:45.819Z DEBUG modem << [00:01:14.754,821] [0m<dbg> nrf_cloud_transport.save_session_state: Setting session state: 1[0m
2021-06-30T08:06:45.834Z DEBUG modem << [00:01:14.763,977] [0m<dbg> nrf_cloud_fota.nrf_cloud_fota_subscribe: Subscribing to topic: prod/cf667ede-b660-46cf-a93b-f3f7074ada5e/nrf-352656100109613/jobs/rcv[0m
2021-06-30T08:06:45.846Z DEBUG modem << [00:01:14.779,479] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 9[0m
2021-06-30T08:06:45.850Z DEBUG modem << [00:01:14.787,139] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_READY[0m
2021-06-30T08:06:45.856Z DEBUG modem << [00:01:14.794,342] [0m<inf> asset_tracker: CLOUD_EVT_READY[0m
2021-06-30T08:06:45.866Z DEBUG modem << [00:01:14.801,300] [0m<dbg> nrf9160_gps.configure_antenna: MAGPIO set: AT%XMAGPIO=1,0,0,1,1,1565,1586[0m
2021-06-30T08:06:45.880Z DEBUG modem << [00:01:14.811,218] [0m<dbg> nrf9160_gps.configure_antenna: COEX0 set: AT%XCOEX0=1,1,1565,1586[0m
2021-06-30T08:06:45.883Z DEBUG modem << [00:01:14.819,885] [0m<dbg> nrf9160_gps.open_socket: GPS socket created, fd: 1232491587[0m
2021-06-30T08:06:45.888Z DEBUG modem << [00:01:14.828,063] [0m<inf> gps_control: GPS initialized[0m
2021-06-30T08:06:45.915Z DEBUG modem << %CESQ: 53,2,28,4
2021-06-30T08:06:45.967Z DEBUG modem << [00:01:14.903,045] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 1 opcode = 1 len = 631[0m
2021-06-30T08:06:45.979Z DEBUG modem << [00:01:14.915,252] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 2 opcode = 1 len = 58[0m
2021-06-30T08:06:46.565Z DEBUG modem << [00:01:15.500,854] [0m<dbg> nrf_cloud_fota.nrf_cloud_fota_mqtt_evt_handler: MQTT_EVT_SUBACK[0m
2021-06-30T08:06:46.577Z DEBUG modem << [00:01:15.509,307] [0m<dbg> nrf_cloud_fota.publish: Topic: prod/cf667ede-b660-46cf-a93b-f3f7074ada5e/nrf-352656100109613/jobs/req[0m
2021-06-30T08:06:46.583Z DEBUG modem << [00:01:15.521,240] [0m<dbg> nrf_cloud_fota.publish: Payload (4 bytes): [""][0m
2021-06-30T08:06:47.413Z DEBUG modem << [00:01:16.348,846] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 1 result = 0[0m
2021-06-30T08:06:47.445Z DEBUG modem << [00:01:16.379,974] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 2 result = 0[0m
2021-06-30T08:06:48.018Z DEBUG modem << [00:01:16.953,918] [0m<dbg> nrf_cloud_fota.nrf_cloud_fota_mqtt_evt_handler: MQTT_EVT_PUBACK: msg id 8767[0m
2021-06-30T08:07:14.290Z DEBUG modem << +CSCON: 0
2021-06-30T08:07:14.298Z DEBUG modem << [00:01:43.235,076] [0m<inf> asset_tracker: RRC mode: Idle[0m
2021-06-30T08:07:14.610Z DEBUG modem << %CESQ: 56,2,20,2
2021-06-30T08:07:15.134Z DEBUG modem << %CESQ: 55,2,31,4
2021-06-30T08:07:21.771Z DEBUG modem << +CSCON: 1
2021-06-30T08:07:21.778Z DEBUG modem << [00:01:50.715,637] [0m<inf> asset_tracker: RRC mode: Connected[0m
2021-06-30T08:07:28.670Z DEBUG modem << %CESQ: 50,2,30,4
2021-06-30T08:07:43.272Z DEBUG modem << %CESQ: 55,2,30,4
2021-06-30T08:07:44.290Z DEBUG modem << +CSCON: 0
2021-06-30T08:07:44.298Z DEBUG modem << [00:02:13.235,534] [0m<inf> asset_tracker: RRC mode: Idle[0m
2021-06-30T08:07:44.530Z DEBUG modem << %CESQ: 57,2,22,3
2021-06-30T08:07:45.855Z DEBUG modem << %CESQ: 55,2,30,4
2021-06-30T08:07:47.051Z DEBUG modem << +CSCON: 1
2021-06-30T08:07:47.058Z DEBUG modem << [00:02:15.995,971] [0m<inf> asset_tracker: RRC mode: Connected[0m

[Heidi]

Thank you for the log!

To investigate the issue further, please use the Trace Collector application in nRF Connect for Desktop to capture a modem trace from the nRF9160 DK when using the China Telecom card to connect (see Collecting a modem trace for the nRF9160 DK). 

Then provide me with the resulting .bin file and the corresponding log file from the application, as well as the modem FW version, NCS version and HW revision of the nRF9160 DK. 

[AlbertSerica]

trace-2021-07-05T07-01-26.414Z.bin

Fullscreen 2021-07-05T06_41_13.741Z-log.txt Download

2021-07-05T06:41:13.976Z INFO Application data folder: C:\Users\aaa\AppData\Roaming\nrfconnect\pc-nrfconnect-tracecollector
2021-07-05T06:41:14.038Z DEBUG App pc-nrfconnect-tracecollector v1.0.8 official
2021-07-05T06:41:14.038Z DEBUG App path: C:\Users\aaa\.nrfconnect-apps\node_modules\pc-nrfconnect-tracecollector
2021-07-05T06:41:14.038Z DEBUG nRFConnect 3.7.0, required by the app is (^3.0.0)
2021-07-05T06:41:14.038Z DEBUG nRFConnect path: C:\Users\aaa\AppData\Local\Programs\nrfconnect\resources\app.asar
2021-07-05T06:41:14.038Z DEBUG HomeDir: C:\Users\aaa
2021-07-05T06:41:14.038Z DEBUG TmpDir: C:\Users\aaa\AppData\Local\Temp
2021-07-05T06:41:18.712Z INFO Device opened
2021-07-05T06:41:23.578Z INFO Tracefile created: C:\Users\aaa\AppData\Roaming\nrfconnect\pc-nrfconnect-tracecollector\trace-2021-07-05T06-41-23.572Z.bin
2021-07-05T07:01:03.104Z INFO Device closed
2021-07-05T07:01:19.655Z INFO Device opened
2021-07-05T07:01:26.414Z INFO Tracefile created: C:\Users\aaa\AppData\Roaming\nrfconnect\pc-nrfconnect-tracecollector\trace-2021-07-05T07-01-26.414Z.bin
2021-07-05T07:35:43.113Z INFO Tracefile closed

Hello, please check the .bin and log in attachments. Modem FW is mfwnrf9160123 (mfw_nrf9160_1.3.0 does not work for unknow reason, log attached). NCS version 1.6.0; HW version 0.8.3 2019.1.

Fullscreen mfw_nrf9160_1.3.0 DNW 2021-07-05T06_36_56.451Z-log.txt Download

2021-07-05T06:36:56.828Z INFO Application data folder: C:\Users\aaa\AppData\Roaming\nrfconnect\pc-nrfconnect-linkmonitor
2021-07-05T06:36:56.875Z DEBUG App pc-nrfconnect-linkmonitor v1.1.10 official
2021-07-05T06:36:56.876Z DEBUG App path: C:\Users\aaa\.nrfconnect-apps\node_modules\pc-nrfconnect-linkmonitor
2021-07-05T06:36:56.876Z DEBUG nRFConnect 3.7.0, required by the app is (^3.6.0)
2021-07-05T06:36:56.876Z DEBUG nRFConnect path: C:\Users\aaa\AppData\Local\Programs\nrfconnect\resources\app.asar
2021-07-05T06:36:56.876Z DEBUG HomeDir: C:\Users\aaa
2021-07-05T06:36:56.876Z DEBUG TmpDir: C:\Users\aaa\AppData\Local\Temp
2021-07-05T06:36:58.291Z INFO Modem port is opened
2021-07-05T06:37:01.931Z DEBUG modem << *** Booting Zephyr OS build v2.6.0-rc1-ncs1  ***
2021-07-05T06:37:01.944Z DEBUG modem << I: Starting bootloader
2021-07-05T06:37:01.946Z DEBUG modem << I: Primary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
2021-07-05T06:37:01.948Z DEBUG modem << I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3
2021-07-05T06:37:01.950Z DEBUG modem << I: Boot source: none
2021-07-05T06:37:01.954Z DEBUG modem << I: Swap type: none
2021-07-05T06:37:02.272Z DEBUG modem << I: Bootloader chainload address offset: 0x10000
2021-07-05T06:37:02.276Z DEBUG modem << I: Jumping to the first image slot
2021-07-05T06:37:02.540Z DEBUG modem << *** Booting Zephyr OS build v2.6.0-rc1-ncs1  ***
2021-07-05T06:37:02.543Z DEBUG modem << Flash regionsDomainPermissions
2021-07-05T06:37:02.547Z DEBUG modem << 00 03 0x00000 0x20000 Securerwxl
2021-07-05T06:37:02.552Z DEBUG modem << 04 31 0x20000 0x100000 Non-Securerwxl
2021-07-05T06:37:02.556Z DEBUG modem << Non-secure callable region 0 placed in flash region 2 with size 32.
2021-07-05T06:37:02.606Z DEBUG modem << SRAM regionDomainPermissions
2021-07-05T06:37:02.612Z DEBUG modem << 00 07 0x00000 0x10000 Securerwxl
2021-07-05T06:37:02.614Z DEBUG modem << 08 31 0x10000 0x40000 Non-Securerwxl
2021-07-05T06:37:02.620Z DEBUG modem << PeripheralDomainStatus
2021-07-05T06:37:02.621Z DEBUG modem << 00 NRF_P0               Non-SecureOK
2021-07-05T06:37:02.623Z DEBUG modem << 01 NRF_CLOCK            Non-SecureOK
2021-07-05T06:37:02.625Z DEBUG modem << 02 NRF_RTC0             Non-SecureOK
2021-07-05T06:37:02.629Z DEBUG modem << 03 NRF_RTC1             Non-SecureOK
2021-07-05T06:37:02.636Z DEBUG modem << 04 NRF_NVMC             Non-SecureOK
2021-07-05T06:37:02.637Z DEBUG modem << 05 NRF_UARTE1           Non-SecureOK
2021-07-05T06:37:02.640Z DEBUG modem << 06 NRF_UARTE2           SecureSKIP
2021-07-05T06:37:02.642Z DEBUG modem << 07 NRF_TWIM2            Non-SecureOK
2021-07-05T06:37:02.645Z DEBUG modem << 08 NRF_SPIM3            Non-SecureOK
2021-07-05T06:37:02.652Z DEBUG modem << 09 NRF_TIMER0           Non-SecureOK
2021-07-05T06:37:02.654Z DEBUG modem << 10 NRF_TIMER1           Non-SecureOK
2021-07-05T06:37:02.656Z DEBUG modem << 11 NRF_TIMER2           Non-SecureOK
2021-07-05T06:37:02.659Z DEBUG modem << 12 NRF_SAADC            Non-SecureOK
2021-07-05T06:37:02.662Z DEBUG modem << 13 NRF_PWM0             Non-SecureOK
2021-07-05T06:37:02.669Z DEBUG modem << 14 NRF_PWM1             Non-SecureOK
2021-07-05T06:37:02.671Z DEBUG modem << 15 NRF_PWM2             Non-SecureOK
2021-07-05T06:37:02.673Z DEBUG modem << 16 NRF_PWM3             Non-SecureOK
2021-07-05T06:37:02.676Z DEBUG modem << 17 NRF_WDT              Non-SecureOK
2021-07-05T06:37:02.679Z DEBUG modem << 18 NRF_IPC              Non-SecureOK
2021-07-05T06:37:02.686Z DEBUG modem << 19 NRF_VMC              Non-SecureOK
2021-07-05T06:37:02.688Z DEBUG modem << 20 NRF_FPU              Non-SecureOK
2021-07-05T06:37:02.690Z DEBUG modem << 21 NRF_EGU1             Non-SecureOK
2021-07-05T06:37:02.693Z DEBUG modem << 22 NRF_EGU2             Non-SecureOK
2021-07-05T06:37:02.696Z DEBUG modem << 23 NRF_DPPIC            Non-SecureOK
2021-07-05T06:37:02.703Z DEBUG modem << 24 NRF_REGULATORS       Non-SecureOK
2021-07-05T06:37:02.704Z DEBUG modem << 25 NRF_PDM              Non-SecureOK
2021-07-05T06:37:02.707Z DEBUG modem << 26 NRF_I2S              Non-SecureOK
2021-07-05T06:37:02.710Z DEBUG modem << 27 NRF_GPIOTE1          Non-SecureOK
2021-07-05T06:37:02.712Z DEBUG modem << SPM: NS image at 0x20200
2021-07-05T06:37:02.715Z DEBUG modem << SPM: NS MSP at 0x200257a8
2021-07-05T06:37:02.720Z DEBUG modem << SPM: NS reset vector at 0x2a0cd
2021-07-05T06:37:02.722Z DEBUG modem << SPM: prepare to jump to Non-Secure image.

[Heidi]

Hi, the trace file you provided was empty. 

Did you make sure to enable CONFIG_NRF_MODEM_LIB_TRACE_ENABLED in your application?

You can also send AT%XMODEMTRACE=1,2 to the modem for good meaure, even though enabling the config should take care of that.

And then make sure that the file size of the trace increases in the Trace Collector application as the device is running.