Asset Tracker application in NB-IoT mode

[amessner]

Hi everyone.
I'm using a Thingy:91 and the asset tracker application. I can compile and flash (using SES and a Segger J-Link) the application and the device connects to the nRF cloud.

But when I change the "network mode" from LTE-M + GPS to NB-IOT + GPS it stops working. I'm located in Canada where we do not have NB-IOT coverage, but the device should switch to fallback mode which is LTE-M. If I use the asset tracker NB-IOT binaries provided by nRF (thingy91_nbiot_dfu_2020-04-29_bc7ade8b.hex) I see exactly that: the device tries to connect, times out and falls back to LTE-M and then connects just fine.

What configuration settings do I have to change to switch the default asset tracker application from LTE-M to NB-IOT?

Below is the output of the link monitor of my test build with network mode set to NB-IOT:
%CESQ: 255,0,255,0
+CEREG: 2,"FFFE","FFFFFFFF",
[00:00:30.588,684] [0m<dbg> lte_lc.at_handler: +CEREG notification: +CEREG: 2,"FFFE","FFFFFFFF",9
[0m
[00:00:30.598,144] [1;31m<err> lte_lc: Could not get TAU, error: -22[0m
[00:00:30.604,736] [1;31m<err> lte_lc: Failed to parse PSM configuration, error: -22[0m
[00:00:30.612,792] [1;31m<err> lte_lc: Failed to parse notification (error -22): +CEREG: 2,"FFFE","FFFFFFFF",9
[0m
%CESQ: 255,0,255,0
%CESQ: 255,0,255,0
%CESQ: 255,0,255,0

Thanks

[Øyvind]

I was finally able to test asset_tracker application (NCS v1.3.0) regarding the fallback issue, and I did not have any issues. Do remember that the default time before it uses fallback is 10 minutes (600 sec). This can be overrun by adding CONFIG_LTE_NETWORK_TIMEOUT=30 (seconds) in prj.conf. See min below:

#
# Copyright (c) 2019 Nordic Semiconductor ASA
#
# SPDX-License-Identifier: LicenseRef-BSD-5-Clause-Nordic
#
# General config
CONFIG_NEWLIB_LIBC=y
CONFIG_NEWLIB_LIBC_FLOAT_PRINTF=y
CONFIG_ASSERT=y
CONFIG_REBOOT=y
CONFIG_LOG=y
CONFIG_LOG_IMMEDIATE=y

# Network
CONFIG_NETWORKING=y
CONFIG_NET_NATIVE=n
CONFIG_NET_SOCKETS=y
CONFIG_NET_SOCKETS_OFFLOAD=y

# LTE link control
CONFIG_POWER_OPTIMIZATION_ENABLE=n
CONFIG_LTE_LINK_CONTROL=y
CONFIG_LTE_NETWORK_MODE_LTE_M_GPS=n
CONFIG_LTE_AUTO_INIT_AND_CONNECT=n
CONFIG_LTE_LINK_CONTROL_LOG_LEVEL_DBG=y

CONFIG_LTE_NETWORK_MODE_NBIOT_GPS=y
CONFIG_LTE_LEGACY_PCO_MODE=n
CONFIG_LTE_PSM_REQ_RPTAU="00000110"
CONFIG_LTE_PSM_REQ_RAT="00000010"

#Fallback timer
CONFIG_LTE_NETWORK_TIMEOUT=30

# Modem info
CONFIG_MODEM_INFO=y

# BSD library
CONFIG_BSD_LIBRARY=y
CONFIG_BSD_LIBRARY_TRACE_ENABLED=n

# nRF Cloud
CONFIG_CLOUD_API=y
CONFIG_NRF_CLOUD=y
CONFIG_NRF_CLOUD_LOG_LEVEL_DBG=y
CONFIG_NRF_CLOUD_AGPS=y
CONFIG_NRF_CLOUD_CONNECTION_POLL_THREAD=y
CONFIG_NRF_CLOUD_NONBLOCKING_SEND=y
# Needed for the cloud codec
CONFIG_CJSON_LIB=y
# Shorter to prevent NAT timeouts
CONFIG_MQTT_KEEPALIVE=120
# Don't resubscribe to topics if broker remembers them
CONFIG_CLOUD_PERSISTENT_SESSIONS=y

# Sensors
CONFIG_ACCEL_USE_SIM=y
CONFIG_TEMP_USE_SIM=y
CONFIG_CLOUD_BUTTON=n

# GPS
CONFIG_NRF9160_GPS=y
# CONFIG_GPS_USE_SIM=y
CONFIG_NRF9160_GPS_LOG_LEVEL_DBG=y
CONFIG_GPS_USE_EXTERNAL=y
CONFIG_GPS_DEV_NAME="NRF9160_GPS"
CONFIG_GPS_CONTROL_PSM_ENABLE_ON_START=y

CONFIG_GPS_CONTROL_FIRST_FIX_CHECK_DELAY=10
CONFIG_GPS_CONTROL_FIX_CHECK_INTERVAL=30
CONFIG_GPS_CONTROL_FIX_TRY_TIME=360
CONFIG_GPS_CONTROL_PSM_DISABLE_ON_STOP=n

# Library for buttons and LEDs
CONFIG_DK_LIBRARY=y
CONFIG_DK_LIBRARY_INVERT_LEDS=n

# Console
CONFIG_CONSOLE_SUBSYS=y
CONFIG_CONSOLE_HANDLER=y
CONFIG_CONSOLE_GETCHAR=y

# Heap and stacks
CONFIG_HEAP_MEM_POOL_SIZE=16384
CONFIG_MAIN_STACK_SIZE=8192
CONFIG_SYSTEM_WORKQUEUE_STACK_SIZE=2048
CONFIG_HW_STACK_PROTECTION=y

# MCUBOOT
CONFIG_BOOTLOADER_MCUBOOT=y
CONFIG_IMG_MANAGER=y
CONFIG_MCUBOOT_IMG_MANAGER=y

# Flash
CONFIG_FLASH=y
CONFIG_IMG_ERASE_PROGRESSIVELY=y

# AWS FOTA
CONFIG_AWS_FOTA=y
CONFIG_FOTA_DOWNLOAD=y
CONFIG_AWS_FOTA_LOG_LEVEL_DBG=y
CONFIG_AWS_JOBS_LOG_LEVEL_DBG=y
CONFIG_DFU_TARGET=y

# Download client (needed by AWS FOTA)
CONFIG_DOWNLOAD_CLIENT=y
CONFIG_DOWNLOAD_CLIENT_STACK_SIZE=4096

# Fatal error
CONFIG_RESET_ON_FATAL_ERROR=n
CONFIG_WATCHDOG=y

I have not edited any else but network mode and network timeout. 

Below is the output from LTE Link Monitor:

2020-07-24T09:36:25.029Z INFO Application data folder: C:\Users\oysa\AppData\Roaming\nrfconnect\pc-nrfconnect-linkmonitor
2020-07-24T09:36:25.078Z DEBUG App pc-nrfconnect-linkmonitor v1.1.3 official
2020-07-24T09:36:25.079Z DEBUG App path: C:\Users\oysa\.nrfconnect-apps\node_modules\pc-nrfconnect-linkmonitor
2020-07-24T09:36:25.079Z DEBUG nRFConnect 3.4.1 is supported by the app (^3.2.0)
2020-07-24T09:36:25.079Z DEBUG nRFConnect path: C:\Users\oysa\AppData\Local\Programs\nrfconnect\resources\app.asar
2020-07-24T09:36:25.079Z DEBUG HomeDir: C:\Users\oysa
2020-07-24T09:36:25.079Z DEBUG TmpDir: C:\Users\oysa\AppData\Local\Temp
2020-07-24T09:36:25.086Z VERBOSE Could not fetch serial number for serial port at COM3
2020-07-24T09:36:26.633Z INFO Modem port is opened
2020-07-24T09:36:26.645Z DEBUG modem >> AT+CFUN?
2020-07-24T09:36:29.654Z DEBUG modem << *** Booting Zephyr OS build v2.3.0-rc1-ncs1  ***
2020-07-24T09:36:29.673Z DEBUG modem << [00:00:00.003,204] [0m<inf> mcuboot: Starting bootloader[0m
2020-07-24T09:36:29.677Z DEBUG modem << [00:00:00.008,911] [0m<inf> mcuboot: Primary image: magic=bad, swap_type=0x0, copy_done=0x2, image_ok=0x2[0m
2020-07-24T09:36:29.679Z DEBUG modem << [00:00:00.018,005] [0m<inf> mcuboot: Boot source: none[0m
2020-07-24T09:36:29.682Z DEBUG modem << [00:00:00.023,010] [0m<inf> mcuboot: Swap type: none[0m
2020-07-24T09:36:30.016Z DEBUG modem << [00:00:00.335,845] [0m<inf> mcuboot: Bootloader chainload address offset: 0x10000[0m
2020-07-24T09:36:30.024Z DEBUG modem << [00:00:00.342,987] [0m<inf> mcuboot: Jumping to the first image slot[0m
2020-07-24T09:36:30.031Z DEBUG modem << *** Booting Zephyr OS build v2.3.0-rc1-ncs1  ***
2020-07-24T09:36:30.032Z DEBUG modem << Flash regionsDomainPermissions
2020-07-24T09:36:30.044Z DEBUG modem << 00 02 0x00000 0x18000 Securerwxl
2020-07-24T09:36:30.048Z DEBUG modem << 03 31 0x18000 0x100000 Non-Securerwxl
2020-07-24T09:36:30.051Z DEBUG modem << Non-secure callable region 0 placed in flash region 2 with size 32.
2020-07-24T09:36:30.212Z DEBUG modem << SRAM regionDomainPermissions
2020-07-24T09:36:30.219Z DEBUG modem << 00 07 0x00000 0x10000 Securerwxl
2020-07-24T09:36:30.222Z DEBUG modem << 08 31 0x10000 0x40000 Non-Securerwxl
2020-07-24T09:36:30.224Z DEBUG modem << PeripheralDomainStatus
2020-07-24T09:36:30.227Z DEBUG modem << 00 NRF_P0               Non-SecureOK
2020-07-24T09:36:30.230Z DEBUG modem << 01 NRF_CLOCK            Non-SecureOK
2020-07-24T09:36:30.233Z DEBUG modem << 02 NRF_RTC0             Non-SecureOK
2020-07-24T09:36:30.243Z DEBUG modem << 03 NRF_RTC1             Non-SecureOK
2020-07-24T09:36:30.246Z DEBUG modem << 04 NRF_NVMC             Non-SecureOK
2020-07-24T09:36:30.249Z DEBUG modem << 05 NRF_UARTE1           Non-SecureOK
2020-07-24T09:36:30.252Z DEBUG modem << 06 NRF_UARTE2           SecureSKIP
2020-07-24T09:36:30.260Z DEBUG modem << 07 NRF_TWIM2            Non-SecureOK
2020-07-24T09:36:30.263Z DEBUG modem << 08 NRF_SPIM3            Non-SecureOK
2020-07-24T09:36:30.265Z DEBUG modem << 09 NRF_TIMER0           Non-SecureOK
2020-07-24T09:36:30.268Z DEBUG modem << 10 NRF_TIMER1           Non-SecureOK
2020-07-24T09:36:30.271Z DEBUG modem << 11 NRF_TIMER2           Non-SecureOK
2020-07-24T09:36:30.273Z DEBUG modem << 12 NRF_SAADC            Non-SecureOK
2020-07-24T09:36:30.281Z DEBUG modem << 13 NRF_PWM0             Non-SecureOK
2020-07-24T09:36:30.283Z DEBUG modem << 14 NRF_PWM1             Non-SecureOK
2020-07-24T09:36:30.287Z DEBUG modem << 15 NRF_PWM2             Non-SecureOK
2020-07-24T09:36:30.290Z DEBUG modem << 16 NRF_PWM3             Non-SecureOK
2020-07-24T09:36:30.292Z DEBUG modem << 17 NRF_WDT              Non-SecureOK
2020-07-24T09:36:30.293Z DEBUG modem << 18 NRF_IPC              Non-SecureOK
2020-07-24T09:36:30.299Z DEBUG modem << 19 NRF_VMC              Non-SecureOK
2020-07-24T09:36:30.301Z DEBUG modem << 20 NRF_FPU              Non-SecureOK
2020-07-24T09:36:30.302Z DEBUG modem << 21 NRF_EGU1             Non-SecureOK
2020-07-24T09:36:30.303Z DEBUG modem << 22 NRF_EGU2             Non-SecureOK
2020-07-24T09:36:30.312Z DEBUG modem << 23 NRF_DPPIC            Non-SecureOK
2020-07-24T09:36:30.316Z DEBUG modem << 24 NRF_GPIOTE1          Non-SecureOK
2020-07-24T09:36:30.322Z DEBUG modem << 25 NRF_REGULATORS       Non-SecureOK
2020-07-24T09:36:30.325Z DEBUG modem << SPM: NS image at 0x1c200
2020-07-24T09:36:30.326Z DEBUG modem << SPM: NS MSP at 0x20030ff8
2020-07-24T09:36:30.334Z DEBUG modem << SPM: NS reset vector at 0x25511
2020-07-24T09:36:30.336Z DEBUG modem << SPM: prepare to jump to Non-Secure image.
2020-07-24T09:36:30.529Z DEBUG modem << *** Booting Zephyr OS build v2.3.0-rc1-ncs1  ***
2020-07-24T09:36:30.541Z DEBUG modem << [00:00:00.203,521] [0m<dbg> nrf9160_gps.setup: MAGPIO set: AT%XMAGPIO=1,0,0,1,1,1574,1577[0m
2020-07-24T09:36:30.547Z DEBUG modem << [00:00:00.212,371] [0m<dbg> nrf9160_gps.setup: COEX0 set: AT%XCOEX0=1,1,1570,1580[0m
2020-07-24T09:36:30.559Z DEBUG modem << [00:00:00.220,062] [0m<inf> asset_tracker: Asset tracker started[0m
2020-07-24T09:36:30.566Z DEBUG modem << [00:00:00.226,287] [0m<inf> watchdog: Watchdog timeout installed. Timeout: 10000[0m
2020-07-24T09:36:30.569Z DEBUG modem << [00:00:00.233,856] [0m<inf> watchdog: Watchdog started[0m
2020-07-24T09:36:30.581Z DEBUG modem << [00:00:00.239,196] [0m<inf> watchdog: Watchdog feed enabled. Timeout: 5000[0m
2020-07-24T09:36:30.591Z DEBUG modem << [00:00:00.253,753] [0m<dbg> nrf_cloud_transport.nct_client_id_get: client_id = nrf-352656102628123[0m
2020-07-24T09:36:30.601Z DEBUG modem << [00:00:00.262,908] [0m<dbg> nrf_cloud_transport.nct_topics_populate: shadow_base_topic: $aws/things/nrf-352656102628123/shadow[0m
2020-07-24T09:36:30.619Z DEBUG modem << [00:00:00.274,475] [0m<dbg> nrf_cloud_transport.nct_topics_populate: accepted_topic: nrf-352656102628123/shadow/get/accepted[0m
2020-07-24T09:36:30.625Z DEBUG modem << [00:00:00.285,888] [0m<dbg> nrf_cloud_transport.nct_topics_populate: rejected_topic: $aws/things/nrf-352656102628123/shadow/get/rejected[0m
2020-07-24T09:36:30.645Z DEBUG modem << [00:00:00.298,309] [0m<dbg> nrf_cloud_transport.nct_topics_populate: update_delta_topic: $aws/things/nrf-352656102628123/shadow/update/delta[0m
2020-07-24T09:36:30.650Z DEBUG modem << [00:00:00.311,096] [0m<dbg> nrf_cloud_transport.nct_topics_populate: update_topic: $aws/things/nrf-352656102628123/shadow/update[0m
2020-07-24T09:36:30.662Z DEBUG modem << [00:00:00.322,845] [0m<dbg> nrf_cloud_transport.nct_topics_populate: shadow_get_topic: $aws/things/nrf-352656102628123/shadow/get[0m
2020-07-24T09:36:30.674Z DEBUG modem << [00:00:00.334,899] [0m<inf> asset_tracker: Connecting to LTE network.[0m
2020-07-24T09:36:30.677Z DEBUG modem << [00:00:00.341,522] [0m<inf> asset_tracker: This may take several minutes.[0m
2020-07-24T09:36:30.691Z DEBUG modem << [00:00:00.348,541] [0m<dbg> lte_lc.lte_lc_system_mode_set: Sending AT command to set system mode: AT%XSYSTEMMODE=0,1,1,0[0m
2020-07-24T09:36:30.711Z DEBUG modem << [00:00:00.368,377] [0m<dbg> lte_lc.lte_lc_system_mode_set: Sending AT command to set system mode: AT%XSYSTEMMODE=0,1,1,0[0m
2020-07-24T09:36:53.935Z DEBUG modem << +CEREG: 2,"9DD1","014A0303",9,0,0,"11100000","11100000"
2020-07-24T09:36:53.950Z DEBUG modem << [00:00:23.609,283] [0m<dbg> lte_lc.at_handler: +CEREG notification: +CEREG: 2,"9DD1","014A0303",9,0,0,"11100000","11100000"
2020-07-24T09:36:53.951Z DEBUG modem << [0m
2020-07-24T09:36:53.954Z DEBUG modem << [00:00:23.621,032] [0m<dbg> lte_lc.parse_psm_cfg: TAU: -1 sec, active time: -1 sec
2020-07-24T09:36:53.955Z DEBUG modem << [0m
2020-07-24T09:36:54.269Z DEBUG modem << +CSCON: 1
2020-07-24T09:36:54.273Z DEBUG modem << [00:00:23.941,467] [0m<dbg> lte_lc.at_handler: +CSCON notification[0m
2020-07-24T09:36:55.243Z DEBUG modem << +CEREG: 4,"9DD1","014A0303",9,0,15,"11100000","11100000"
2020-07-24T09:36:55.254Z DEBUG modem << [00:00:24.916,961] [0m<dbg> lte_lc.at_handler: +CEREG notification: +CEREG: 4,"9DD1","014A0303",9,0,15,"11100000","11100000"
2020-07-24T09:36:55.256Z DEBUG modem << [0m
2020-07-24T09:36:55.262Z DEBUG modem << [00:00:24.928,771] [0m<dbg> lte_lc.parse_psm_cfg: TAU: -1 sec, active time: -1 sec
2020-07-24T09:36:55.263Z DEBUG modem << [0m
2020-07-24T09:36:55.292Z DEBUG modem << +CSCON: 0
2020-07-24T09:36:55.297Z DEBUG modem << [00:00:24.965,637] [0m<dbg> lte_lc.at_handler: +CSCON notification[0m
2020-07-24T09:36:55.514Z DEBUG modem << +CEREG: 4,"FFFE","FFFFFFFF",9,0,15,"11100000","11100000"
2020-07-24T09:36:55.527Z DEBUG modem << [00:00:25.188,964] [0m<dbg> lte_lc.at_handler: +CEREG notification: +CEREG: 4,"FFFE","FFFFFFFF",9,0,15,"11100000","11100000"
2020-07-24T09:36:55.529Z DEBUG modem << [0m
2020-07-24T09:36:55.534Z DEBUG modem << [00:00:25.200,775] [0m<dbg> lte_lc.parse_psm_cfg: TAU: -1 sec, active time: -1 sec
2020-07-24T09:36:55.539Z DEBUG modem << [0m
2020-07-24T09:37:00.752Z DEBUG modem << [00:00:30.419,860] [0m<inf> lte_lc: Network connection attempt timed out[0m
2020-07-24T09:37:00.775Z DEBUG modem << +CEREG: 0,"FFFE","FFFFFFFF",9,0,15,"11100000","11100000"
2020-07-24T09:37:00.786Z DEBUG modem << [00:00:30.449,157] [0m<dbg> lte_lc.at_handler: +CEREG notification: +CEREG: 0,"FFFE","FFFFFFFF",9,0,15,"11100000","11100000"
2020-07-24T09:37:00.787Z DEBUG modem << [0m
2020-07-24T09:37:00.793Z DEBUG modem << [00:00:30.460,998] [0m<dbg> lte_lc.parse_psm_cfg: TAU: -1 sec, active time: -1 sec
2020-07-24T09:37:00.795Z DEBUG modem << [0m
2020-07-24T09:37:00.801Z DEBUG modem << [00:00:30.469,024] [0m<inf> lte_lc: Using fallback network mode[0m
2020-07-24T09:37:00.816Z DEBUG modem << [00:00:30.475,158] [0m<dbg> lte_lc.lte_lc_system_mode_set: Sending AT command to set system mode: AT%XSYSTEMMODE=1,0,1,0[0m
2020-07-24T09:37:08.497Z DEBUG modem << +CEREG: 2,"76C1","014ACE00",7,0,15,"11100000","11100000"
2020-07-24T09:37:08.507Z DEBUG modem << [00:00:38.171,691] [0m<dbg> lte_lc.at_handler: +CEREG notification: +CEREG: 2,"76C1","014ACE00",7,0,15,"11100000","11100000"
2020-07-24T09:37:08.509Z DEBUG modem << [0m
2020-07-24T09:37:08.516Z DEBUG modem << [00:00:38.183,502] [0m<dbg> lte_lc.parse_psm_cfg: TAU: -1 sec, active time: -1 sec
2020-07-24T09:37:08.518Z DEBUG modem << [0m
2020-07-24T09:37:08.540Z DEBUG modem << +CSCON: 1
2020-07-24T09:37:08.547Z DEBUG modem << [00:00:38.214,874] [0m<dbg> lte_lc.at_handler: +CSCON notification[0m
2020-07-24T09:37:09.428Z DEBUG modem << +CEREG: 1,"76C1","014ACE00",7,,,"11100000","00001111"
2020-07-24T09:37:09.438Z DEBUG modem >> AT+COPS=3,2
2020-07-24T09:37:09.441Z DEBUG modem << [00:00:39.102,844] [0m<dbg> lte_lc.at_handler: +CEREG notification: +CEREG: 1,"76C1","014ACE00",7,,,"11100000","00001111"
2020-07-24T09:37:09.442Z DEBUG modem << [0m
2020-07-24T09:37:09.447Z DEBUG modem << [00:00:39.114,410] [0m<dbg> lte_lc.parse_psm_cfg: TAU: 9000 sec, active time: -1 sec
2020-07-24T09:37:09.449Z DEBUG modem << [0m
2020-07-24T09:37:09.457Z DEBUG modem << [00:00:39.122,589] [0m<inf> asset_tracker: Connected to LTE network.[0m
2020-07-24T09:37:09.462Z DEBUG modem << [00:00:39.129,180] [0m<inf> asset_tracker: Connecting to cloud, attempt 1 of 8[0m
2020-07-24T09:37:09.473Z DEBUG modem << [00:00:39.136,627] [0m<inf> asset_tracker: Cloud connection request sent.[0m
2020-07-24T09:37:09.477Z DEBUG modem << [00:00:39.143,585] [0m<inf> asset_tracker: Connection response timeout is set to 30 seconds.[0m
2020-07-24T09:37:09.490Z DEBUG modem << [00:00:39.152,343] [0m<inf> asset_tracker: CLOUD_EVT_CONNECTING[0m
2020-07-24T09:37:09.495Z DEBUG modem << OK
2020-07-24T09:37:09.499Z DEBUG modem >> AT+COPS?
2020-07-24T09:37:09.510Z DEBUG modem << +COPS: 0,2,"24201",7
2020-07-24T09:37:09.512Z DEBUG modem << OK
2020-07-24T09:37:09.526Z DEBUG modem >> AT%XCBAND
2020-07-24T09:37:09.531Z DEBUG modem << %XCBAND: 20
2020-07-24T09:37:09.541Z DEBUG modem << OK
2020-07-24T09:37:09.546Z DEBUG modem >> AT+CGDCONT?
2020-07-24T09:37:09.558Z DEBUG modem << +CGDCONT: 0,"IPV4V6","telenor.iot","10.241.98.34 2A02:2121:0208:1741:0000:0036:57B8:C401",0,0
2020-07-24T09:37:09.561Z DEBUG modem << OK
2020-07-24T09:37:09.565Z DEBUG modem >> AT+CGACT?
2020-07-24T09:37:09.577Z DEBUG modem << +CGACT: 0,1
2020-07-24T09:37:09.580Z DEBUG modem << OK
2020-07-24T09:37:09.592Z DEBUG modem << [00:00:39.255,645] [0m<dbg> nrf_cloud_transport.nct_connect: IPv4 address: 52.21.78.210[0m
2020-07-24T09:37:09.599Z DEBUG modem << [00:00:39.263,854] [0m<dbg> nrf_cloud_transport.nct_mqtt_connect: mqtt_connect requesting persistent session[0m
2020-07-24T09:37:13.841Z DEBUG modem << [00:00:43.509,185] [0m<inf> nrf_cloud_transport: Using non-blocking socket[0m
2020-07-24T09:37:13.849Z DEBUG modem << [00:00:43.516,265] [0m<dbg> nrf_cloud.nrf_cloud_run: Cloud connection request sent.[0m
2020-07-24T09:37:14.113Z DEBUG modem << [00:00:43.777,740] [0m<dbg> aws_fota.aws_fota_mqtt_evt_handler: Previous session valid; skipping FOTA subscriptions[0m
2020-07-24T09:37:14.123Z DEBUG modem << [00:00:43.788,391] [0m<inf> aws_fota: Created notify_next_topic $aws/things/nrf-352656102628123/jobs/notify-next[0m
2020-07-24T09:37:14.138Z DEBUG modem << [00:00:43.798,797] [0m<inf> aws_fota: Created get_topic $aws/things/nrf-352656102628123/jobs/$next/get/#[0m
2020-07-24T09:37:14.141Z DEBUG modem << [00:00:43.808,441] [0m<inf> aws_fota: previously subscribed to notify-next topic[0m
2020-07-24T09:37:14.150Z DEBUG modem << [00:00:43.816,101] [0m<inf> aws_jobs: Publish topic: $aws/things/nrf-352656102628123/jobs/$next/get[0m
2020-07-24T09:37:14.160Z DEBUG modem << [00:00:43.825,317] [0m<inf> aws_jobs: Publish payload {"clientToken": ""}[0m
2020-07-24T09:37:14.167Z DEBUG modem << [00:00:43.833,343] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_CONNACK: result 0[0m
2020-07-24T09:37:14.176Z DEBUG modem << [00:00:43.842,315] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 2[0m
2020-07-24T09:37:14.183Z DEBUG modem << [00:00:43.849,975] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTED[0m
2020-07-24T09:37:14.191Z DEBUG modem << [00:00:43.858,428] [0m<inf> asset_tracker: CLOUD_EVT_CONNECTED[0m
2020-07-24T09:37:14.196Z DEBUG modem << [00:00:43.864,440] [0m<inf> asset_tracker: Persistent Sessions = 1[0m
2020-07-24T09:37:14.207Z DEBUG modem << [00:00:43.870,819] [0m<dbg> nrf_cloud_fsm.connection_handler: Previous session valid; skipping nct_cc_connect()[0m
2020-07-24T09:37:14.214Z DEBUG modem << [00:00:43.881,072] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 4[0m
2020-07-24T09:37:14.224Z DEBUG modem << [00:00:43.888,732] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 5678 opcode = 0 len = 0[0m
2020-07-24T09:37:14.231Z DEBUG modem << [00:00:43.899,230] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 5[0m
2020-07-24T09:37:14.322Z DEBUG modem << [00:00:43.986,633] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 60040 result = 0[0m
2020-07-24T09:37:14.357Z DEBUG modem << [00:00:44.020,416] [0m<dbg> aws_fota.on_publish_evt: Received topic: $aws/things/nrf-352656102628123/jobs/$next/get/accepted[0m
2020-07-24T09:37:14.363Z DEBUG modem << [00:00:44.031,768] [0m<inf> aws_fota: Checking for an available job[0m
2020-07-24T09:37:14.374Z DEBUG modem << [00:00:44.038,330] [0m<dbg> aws_fota.get_job_execution: Job doc: {"clientToken":"","timestamp":1595583434}[0m
2020-07-24T09:37:14.380Z DEBUG modem << [00:00:44.048,400] [0m<dbg> aws_fota.get_job_execution: Got only one field[0m
2020-07-24T09:37:14.390Z DEBUG modem << [00:00:44.055,450] [0m<inf> aws_fota: No queued jobs for this device[0m
2020-07-24T09:37:14.481Z DEBUG modem << [00:00:44.145,751] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 5678 result = 0[0m
2020-07-24T09:37:14.488Z DEBUG modem << [00:00:44.155,670] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 5[0m
2020-07-24T09:37:14.751Z DEBUG modem << [00:00:44.415,863] [0m<dbg> aws_fota.on_publish_evt: Received topic: nrf-352656102628123/shadow/get/accepted[0m
2020-07-24T09:37:14.764Z DEBUG modem << [00:00:44.425,842] [0m<dbg> aws_fota.on_publish_evt: received an unhandled MQTT publish event on topic: nrf-352656102628123/shadow/get/accepted[0m
2020-07-24T09:37:14.774Z DEBUG modem << [00:00:44.438,842] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBLISH: id = 0 len = 50[0m
2020-07-24T09:37:14.792Z DEBUG modem << [00:00:44.450,164] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 1 opcode = 1 len = 136[0m
2020-07-24T09:37:14.794Z DEBUG modem << [00:00:44.461,578] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 6[0m
2020-07-24T09:37:14.807Z DEBUG modem << [00:00:44.469,238] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_USER_ASSOCIATION_REQUEST[0m
2020-07-24T09:37:14.809Z DEBUG modem << [00:00:44.478,118] [0m<inf> asset_tracker: CLOUD_EVT_PAIR_REQUEST[0m
2020-07-24T09:37:14.816Z DEBUG modem << [00:00:44.484,375] [0m<inf> asset_tracker: Add device to cloud account.[0m
2020-07-24T09:37:14.824Z DEBUG modem << [00:00:44.491,180] [0m<inf> asset_tracker: Waiting for cloud association...[0m
2020-07-24T09:37:15.203Z DEBUG modem << [00:00:44.868,804] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 1 result = 0[0m
2020-07-24T09:38:08.022Z DEBUG modem << [00:01:37.687,591] [0m<dbg> aws_fota.on_publish_evt: Received topic: $aws/things/nrf-352656102628123/shadow/update/delta[0m
2020-07-24T09:38:08.036Z DEBUG modem << [00:01:37.698,638] [0m<dbg> aws_fota.on_publish_evt: received an unhandled MQTT publish event on topic: $aws/things/nrf-352656102628123/shadow/update/delta[0m
2020-07-24T09:38:08.045Z DEBUG modem << [00:01:37.712,677] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBLISH: id = 1 len = 502[0m
2020-07-24T09:38:08.061Z DEBUG modem << [00:01:37.729,919] [0m<dbg> nrf_cloud_transport.nct_dc_endpoint_set: nct_dc_endpoint_set[0m
2020-07-24T09:38:08.077Z DEBUG modem << [00:01:37.738,372] [0m<dbg> nrf_cloud_transport.nct_dc_endpoint_get: nct_dc_endpoint_get[0m
2020-07-24T09:38:08.082Z DEBUG modem << [00:01:37.748,016] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 7890 opcode = 1 len = 329[0m
2020-07-24T09:38:08.091Z DEBUG modem << [00:01:37.759,735] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 7[0m
2020-07-24T09:38:08.098Z DEBUG modem << [00:01:37.767,425] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_USER_ASSOCIATED[0m
2020-07-24T09:38:08.111Z DEBUG modem << [00:01:37.775,512] [0m<inf> asset_tracker: CLOUD_EVT_PAIR_DONE[0m
2020-07-24T09:38:08.113Z DEBUG modem << [00:01:37.781,524] [0m<inf> asset_tracker: Device associated with cloud.[0m
2020-07-24T09:38:08.124Z DEBUG modem << [00:01:37.788,421] [0m<inf> asset_tracker: Reconnecting for cloud policy to take effect.[0m
2020-07-24T09:38:08.126Z DEBUG modem << [00:01:37.796,691] [0m<inf> asset_tracker: Disconnecting from cloud...[0m
2020-07-24T09:38:08.134Z DEBUG modem << [00:01:37.803,405] [0m<dbg> nrf_cloud_transport.nct_disconnect: nct_disconnect[0m
2020-07-24T09:38:08.150Z DEBUG modem << [00:01:37.813,659] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_DISCONNECT: result = 0[0m
2020-07-24T09:38:08.154Z DEBUG modem << [00:01:37.823,089] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 1[0m
2020-07-24T09:38:08.162Z DEBUG modem << [00:01:37.830,749] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_DISCONNECTED[0m
2020-07-24T09:38:08.670Z DEBUG modem << [00:01:38.339,660] [0m<dbg> nrf_cloud.nrf_cloud_run: Expected disconnect event.[0m
2020-07-24T09:38:08.679Z DEBUG modem << [00:01:38.347,229] [0m<inf> asset_tracker: CLOUD_EVT_DISCONNECTED: 0[0m
2020-07-24T09:38:08.684Z DEBUG modem << [00:01:38.353,790] [0m<inf> asset_tracker: Attempting reconnect in 10 seconds...[0m
2020-07-24T09:38:18.692Z DEBUG modem << [00:01:48.361,450] [0m<inf> asset_tracker: Connecting to cloud, attempt 1 of 8[0m
2020-07-24T09:38:18.699Z DEBUG modem << [00:01:48.368,896] [0m<inf> asset_tracker: Cloud connection request sent.[0m
2020-07-24T09:38:18.706Z DEBUG modem << [00:01:48.375,854] [0m<inf> asset_tracker: Connection response timeout is set to 30 seconds.[0m
2020-07-24T09:38:18.713Z DEBUG modem << [00:01:48.384,521] [0m<inf> asset_tracker: CLOUD_EVT_CONNECTING[0m
2020-07-24T09:38:18.778Z DEBUG modem << [00:01:48.448,120] [0m<dbg> nrf_cloud_transport.nct_connect: IPv4 address: 54.88.128.192[0m
2020-07-24T09:38:22.711Z DEBUG modem << [00:01:52.381,866] [0m<inf> nrf_cloud_transport: Using non-blocking socket[0m
2020-07-24T09:38:22.719Z DEBUG modem << [00:01:52.388,946] [0m<dbg> nrf_cloud.nrf_cloud_run: Cloud connection request sent.[0m
2020-07-24T09:38:23.022Z DEBUG modem << [00:01:52.689,605] [0m<dbg> aws_fota.aws_fota_mqtt_evt_handler: Previous session valid; skipping FOTA subscriptions[0m
2020-07-24T09:38:23.034Z DEBUG modem << [00:01:52.700,256] [0m<inf> aws_fota: Created notify_next_topic $aws/things/nrf-352656102628123/jobs/notify-next[0m
2020-07-24T09:38:23.042Z DEBUG modem << [00:01:52.710,662] [0m<inf> aws_fota: Created get_topic $aws/things/nrf-352656102628123/jobs/$next/get/#[0m
2020-07-24T09:38:23.050Z DEBUG modem << [00:01:52.720,336] [0m<inf> aws_fota: previously subscribed to notify-next topic[0m
2020-07-24T09:38:23.060Z DEBUG modem << [00:01:52.727,966] [0m<inf> aws_jobs: Publish topic: $aws/things/nrf-352656102628123/jobs/$next/get[0m
2020-07-24T09:38:23.066Z DEBUG modem << [00:01:52.737,182] [0m<inf> aws_jobs: Publish payload {"clientToken": ""}[0m
2020-07-24T09:38:23.076Z DEBUG modem << [00:01:52.745,300] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_CONNACK: result 0[0m
2020-07-24T09:38:23.092Z DEBUG modem << [00:01:52.754,272] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 2[0m
2020-07-24T09:38:23.094Z DEBUG modem << [00:01:52.761,932] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_TRANSPORT_CONNECTED[0m
2020-07-24T09:38:23.099Z DEBUG modem << [00:01:52.770,355] [0m<inf> asset_tracker: CLOUD_EVT_CONNECTED[0m
2020-07-24T09:38:23.109Z DEBUG modem << [00:01:52.776,397] [0m<inf> asset_tracker: Persistent Sessions = 1[0m
2020-07-24T09:38:23.115Z DEBUG modem << [00:01:52.782,775] [0m<dbg> nrf_cloud_fsm.connection_handler: Previous session valid; skipping nct_cc_connect()[0m
2020-07-24T09:38:23.127Z DEBUG modem << [00:01:52.793,029] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 4[0m
2020-07-24T09:38:23.132Z DEBUG modem << [00:01:52.800,720] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 5678 opcode = 0 len = 0[0m
2020-07-24T09:38:23.143Z DEBUG modem << [00:01:52.811,096] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 5[0m
2020-07-24T09:38:23.278Z DEBUG modem << [00:01:52.946,563] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 24384 result = 0[0m
2020-07-24T09:38:23.290Z DEBUG modem << [00:01:52.956,939] [0m<dbg> aws_fota.on_publish_evt: Received topic: $aws/things/nrf-352656102628123/jobs/$next/get/accepted[0m
2020-07-24T09:38:23.296Z DEBUG modem << [00:01:52.968,292] [0m<inf> aws_fota: Checking for an available job[0m
2020-07-24T09:38:23.307Z DEBUG modem << [00:01:52.974,853] [0m<dbg> aws_fota.get_job_execution: Job doc: {"clientToken":"","timestamp":1595583503}[0m
2020-07-24T09:38:23.313Z DEBUG modem << [00:01:52.984,954] [0m<dbg> aws_fota.get_job_execution: Got only one field[0m
2020-07-24T09:38:23.324Z DEBUG modem << [00:01:52.992,004] [0m<inf> aws_fota: No queued jobs for this device[0m
2020-07-24T09:38:23.433Z DEBUG modem << [00:01:53.101,654] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 5678 result = 0[0m
2020-07-24T09:38:23.441Z DEBUG modem << [00:01:53.111,572] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 5[0m
2020-07-24T09:38:23.616Z DEBUG modem << [00:01:53.285,247] [0m<dbg> aws_fota.on_publish_evt: Received topic: nrf-352656102628123/shadow/get/accepted[0m
2020-07-24T09:38:23.629Z DEBUG modem << [00:01:53.295,227] [0m<dbg> aws_fota.on_publish_evt: received an unhandled MQTT publish event on topic: nrf-352656102628123/shadow/get/accepted[0m
2020-07-24T09:38:23.641Z DEBUG modem << [00:01:53.308,227] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBLISH: id = 0 len = 283[0m
2020-07-24T09:38:23.657Z DEBUG modem << [00:01:53.320,831] [0m<dbg> nrf_cloud_transport.nct_dc_endpoint_set: nct_dc_endpoint_set[0m
2020-07-24T09:38:23.660Z DEBUG modem << [00:01:53.329,284] [0m<dbg> nrf_cloud_transport.nct_dc_endpoint_get: nct_dc_endpoint_get[0m
2020-07-24T09:38:23.680Z DEBUG modem << [00:01:53.338,897] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 7890 opcode = 1 len = 329[0m
2020-07-24T09:38:23.681Z DEBUG modem << [00:01:53.350,555] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 7[0m
2020-07-24T09:38:23.688Z DEBUG modem << [00:01:53.358,245] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_USER_ASSOCIATED[0m
2020-07-24T09:38:23.694Z DEBUG modem << [00:01:53.366,333] [0m<inf> asset_tracker: CLOUD_EVT_PAIR_DONE[0m
2020-07-24T09:38:24.084Z DEBUG modem << [00:01:53.753,631] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 7890 result = 0[0m
2020-07-24T09:38:24.095Z DEBUG modem << [00:01:53.763,549] [0m<dbg> nrf_cloud_fsm.cc_tx_ack_handler: Previous session valid; skipping nct_dc_connect()[0m
2020-07-24T09:38:24.106Z DEBUG modem << [00:01:53.773,712] [0m<dbg> nrf_cloud.nfsm_set_current_state_and_notify: state: 9[0m
2020-07-24T09:38:24.110Z DEBUG modem << [00:01:53.781,402] [0m<dbg> nrf_cloud.api_event_handler: NRF_CLOUD_EVT_READY[0m
2020-07-24T09:38:24.116Z DEBUG modem << [00:01:53.788,604] [0m<inf> asset_tracker: CLOUD_EVT_READY[0m
2020-07-24T09:38:24.131Z DEBUG modem << [00:01:53.795,166] [0m<dbg> nrf9160_gps.init: GPS socket created, fd: 1232491587[0m
2020-07-24T09:38:24.140Z DEBUG modem << [00:01:53.809,906] [0m<inf> gps_control: GPS initialized[0m
2020-07-24T09:38:24.170Z DEBUG modem << [00:01:53.838,348] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 1 opcode = 1 len = 621[0m
2020-07-24T09:38:24.182Z DEBUG modem << [00:01:53.851,135] [0m<dbg> nrf_cloud_transport.nct_cc_send: mqtt_publish: id = 2 opcode = 1 len = 58[0m
2020-07-24T09:38:24.481Z DEBUG modem << [00:01:54.150,665] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 2 result = 0[0m
2020-07-24T09:38:24.491Z DEBUG modem << [00:01:54.160,583] [0m<dbg> nrf_cloud_transport.nct_mqtt_evt_handler: MQTT_EVT_PUBACK: id = 1 result = 0[0m
2020-07-24T09:38:32.180Z DEBUG modem << %CESQ: 50,2,23,3
2020-07-24T09:39:16.755Z DEBUG modem >> AT%XSYSTEMMODE?
2020-07-24T09:39:16.764Z DEBUG modem << %XSYSTEMMODE: 1,0,1,0
2020-07-24T09:39:16.766Z DEBUG modem << OK