AWS_FOTA: ERROR: mqtt_connect -22

[icampbell]

Hello, I've been having problems getting the AWS_FOTA sample working on a nrf9160 DK.

At first, the device got stuck as it was downloading the firmware update, at 2%. I was able to fix this by setting CONFIG_DFU_TARGET_MCUBOOT_SAVE_PROGRESS=n. After that, the download got stuck at around 11%, though that number changed a bit each time I ran it. While I was trying to fix that, the device stopped being able to connect to AWS at all, even though I didn't change anything. The device waits for a long time after the "client_id:" line, and then seems to time out and print "ERROR: mqtt_connect -22". The timeout/error seems to come from mqtt_connect -> mqtt_client_tls_connect -> connect (line 87 in mqtt_transport_socket_tls.c). I am able to connect to AWS IoT from a python client on my computer using the same credentials and MQTT broker, so I don't think it's a problem with the AWS server.

Here are the changes I made to prj.conf:
CONFIG_DFU_TARGET_MCUBOOT_SAVE_PROGRESS=n
CONFIG_CLOUD_CERT_SEC_TAG=5
CONFIG_APP_VERSION="v1"
CONFIG_MQTT_BROKER_HOSTNAME="ahykgwaormc93-ats.iot.us-west-2.amazonaws.com"
CONFIG_USE_CLOUD_CLIENT_ID=y
CONFIG_CLOUD_CLIENT_ID="nrf9160dk"
CONFIG_USE_NRF_CLOUD=n

Besides that and the credentials (ran once with CONFIG_PROVISION_CERTIFICATES), I didn't make any changes to the AWS_FOTA sample.

I tried both the master branch and the v1.2.0 branch. I also stuff like turning CONFIG_DFU_TARGET_MCUBOOT_SAVE_PROGRESS on again, and re-flashing the credentials with CONFIG_PROVISION_CERTIFICATES again.

[Øyvind]

Hello, 

From nrfxlib\bsdlib\include\nrf_errno.h

#define NRF_EINVAL          22  /**< Invalid argument */

I've had no issues with the AWS FOTA sample (tested yesterday). Can you please provide the output from i.e. LTE Link Monitor? 

Kind regards,
Øyvind

[icampbell]

OK, here's the output

[icampbell]

I am using iBasis, and I seem to have enough data. I also tried a test application that sends and receives on a UDP socket, which also works.

I tried the more restrictive policy, but that didn't fix the problem, still an error with mqtt_connect -22.

About the default configuration - I wasn't aware that this example even worked with nrf cloud until just now.  Reverting the repository doesn't work (the broker is set to your_aws_mqtt_broker_hostname.amazonaws.com by default, which causes "getaddrinfo failed -11"), and when I set CONFIG_USE_NRF_CLOUD=y, I get the same problem as before (mqtt_connect -22)

Here is the output of the AT Client.

[Øyvind]

icampbell said:

I am using iBasis, and I seem to have enough data

 Yes, should be enough. 

 

icampbell said:

About the default configuration - I wasn't aware that this example even worked with nrf cloud until just now

 No, this should not work with nRF Cloud from what I am told. It is designed to work nRF Cloud in the beginning, but some changes were introduced to nRF Cloud which made it not work with nRF Cloud. nRF Cloud is based on AWS, and will, therefore, have a similar address. 

 

icampbell said:

Here is the output of the AT Client.

 Can you please click on Open Log File, then save and send a full log file?

From the information you give, there seems to be a mismatch between your prj.conf and the AWS MQTT settings. Are you using SES when building and programming? What I am fearing, is that the settings you add in prj.conf are overwritten by kconfig. E.g. your client-id does not match in the latest output:

[icampbell]

Here's the log from AT client:

2020-03-26T14:07:31.789Z INFO Application data folder: /home/icampbell/.config/nrfconnect/pc-nrfconnect-linkmonitor
2020-03-26T14:07:31.861Z DEBUG App pc-nrfconnect-linkmonitor v1.1.1 official
2020-03-26T14:07:31.861Z DEBUG App path: /home/icampbell/.nrfconnect-apps/node_modules/pc-nrfconnect-linkmonitor
2020-03-26T14:07:31.862Z DEBUG nRFConnect 3.3.0 is supported by the app (^3.2.0)
2020-03-26T14:07:31.862Z DEBUG nRFConnect path: /tmp/.mount_nrfconDssE2Z/resources/app.asar
2020-03-26T14:07:31.862Z DEBUG HomeDir: /home/icampbell
2020-03-26T14:07:31.862Z DEBUG TmpDir: /tmp
2020-03-26T14:07:31.924Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS0
2020-03-26T14:07:31.924Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS1
2020-03-26T14:07:31.924Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS10
2020-03-26T14:07:31.924Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS11
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS12
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS13
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS14
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS15
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS16
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS17
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS18
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS19
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS2
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS20
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS21
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS22
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS23
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS24
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS25
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS26
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS27
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS28
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS29
2020-03-26T14:07:31.925Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS3
2020-03-26T14:07:31.926Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS30
2020-03-26T14:07:31.926Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS31
2020-03-26T14:07:31.926Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS4
2020-03-26T14:07:31.926Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS5
2020-03-26T14:07:31.926Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS6
2020-03-26T14:07:31.926Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS7
2020-03-26T14:07:31.926Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS8
2020-03-26T14:07:31.926Z VERBOSE Could not fetch serial number for serial port at /dev/ttyS9
2020-03-26T14:07:33.791Z INFO Modem port is opened
2020-03-26T14:07:33.797Z DEBUG modem <<  Zephyr OS build v2.1.99-ncs1-4-gc025ef3dd566  ***\x0D\x0A
2020-03-26T14:07:33.800Z DEBUG modem << Flash region\x09\x09Domain\x09\x09Permissions\x0D\x0A
2020-03-26T14:07:33.834Z DEBUG modem >> AT+CFUN?\x0D\x0A
2020-03-26T14:07:33.846Z DEBUG modem << 00 0x00000 0x08000 \x09Secure\x09\x09rw+CFUN: 0\x0D\x0A
2020-03-26T14:07:33.848Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:41.826Z DEBUG modem << *** Booting Zephyr OS build v2.1.99-ncs1-4-gc025ef3dd566  ***\x0D\x0A
2020-03-26T14:07:41.828Z DEBUG modem << Flash region\x09\x09Domain\x09\x09Permissions\x0D\x0A
2020-03-26T14:07:41.833Z DEBUG modem << 00 0x00000 0x08000 \x09Secure\x09\x09rwxl\x0D\x0A
2020-03-26T14:07:41.835Z DEBUG modem << 01 0x08000 0x10000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.838Z DEBUG modem << 02 0x10000 0x18000 \x09Non-Secure\x09rwxl\x0D
2020-03-26T14:07:41.841Z DEBUG modem << 03 0x18000 0x20000 \x09Non-Secure\x09rwxl\x0D
2020-03-26T14:07:41.844Z DEBUG modem << 04 0x20000 0x28000 \x09Non-Secure\x09rwxl\x0D
2020-03-26T14:07:41.847Z DEBUG modem << 05 0x28000 0x30000 \x09Non-Secure\x09rwxl\x0D
2020-03-26T14:07:41.853Z DEBUG modem << 06 0x30000 0x38000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.856Z DEBUG modem << 07 0x38000 0x40000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.859Z DEBUG modem << 08 0x40000 0x48000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.862Z DEBUG modem << 09 0x48000 0x50000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.866Z DEBUG modem << 10 0x50000 0x58000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.870Z DEBUG modem << 11 0x58000 0x60000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.873Z DEBUG modem << 12 0x60000 0x68000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.882Z DEBUG modem << 13 0x68000 0x70000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.883Z DEBUG modem << 14 0x70000 0x78000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.885Z DEBUG modem << 15 0x78000 0x80000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.886Z DEBUG modem << 16 0x80000 0x88000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.888Z DEBUG modem << 17 0x88000 0x90000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.891Z DEBUG modem << 18 0x90000 0x98000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.896Z DEBUG modem << 19 0x98000 0xa0000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.897Z DEBUG modem << 20 0xa0000 0xa8000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.903Z DEBUG modem << 21 0xa8000 0xb0000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.904Z DEBUG modem << 22 0xb0000 0xb8000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.906Z DEBUG modem << 23 0xb8000 0xc0000 \x09Non-Secure\x09rwxl\x0D
2020-03-26T14:07:41.912Z DEBUG modem << 24 0xc0000 0xc8000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.913Z DEBUG modem << 25 0xc8000 0xd0000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.916Z DEBUG modem << 26 0xd0000 0xd8000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.922Z DEBUG modem << 27 0xd8000 0xe0000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.924Z DEBUG modem << 28 0xe0000 0xe8000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.927Z DEBUG modem << 29 0xe8000 0xf0000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.929Z DEBUG modem << 30 0xf0000 0xf8000 \x09Non-Secure\x09rwxl\x0D
2020-03-26T14:07:41.936Z DEBUG modem << 31 0xf8000 0x100000 \x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:41.941Z DEBUG modem << Non-secure callable region 0 placed in flash region 0 with size 32.\x0D\x0A\x0D\x0A
2020-03-26T14:07:42.111Z DEBUG modem << SRAM region\x09\x09Domain\x09\x09Permissions\x0D
2020-03-26T14:07:42.114Z DEBUG modem << 00 0x00000 0x02000\x09Secure\x09\x09rwxl\x0D
2020-03-26T14:07:42.117Z DEBUG modem << 01 0x02000 0x04000\x09Secure\x09\x09rwxl\x0D\x0A
2020-03-26T14:07:42.120Z DEBUG modem << 02 0x04000 0x06000\x09Secure\x09\x09rwxl\x0D
2020-03-26T14:07:42.122Z DEBUG modem << 03 0x06000 0x08000\x09Secure\x09\x09rwxl\x0D
2020-03-26T14:07:42.131Z DEBUG modem << 04 0x08000 0x0a000\x09Secure\x09\x09rwxl\x0D\x0A
2020-03-26T14:07:42.133Z DEBUG modem << 05 0x0a000 0x0c000\x09Secure\x09\x09rwxl\x0D\x0A
2020-03-26T14:07:42.136Z DEBUG modem << 06 0x0c000 0x0e000\x09Secure\x09\x09rwxl\x0D\x0A
2020-03-26T14:07:42.138Z DEBUG modem << 07 0x0e000 0x10000\x09Secure\x09\x09rwxl\x0D\x0A
2020-03-26T14:07:42.141Z DEBUG modem << 08 0x10000 0x12000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.147Z DEBUG modem << 09 0x12000 0x14000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.149Z DEBUG modem << 10 0x14000 0x16000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.151Z DEBUG modem << 11 0x16000 0x18000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.153Z DEBUG modem << 12 0x18000 0x1a000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.155Z DEBUG modem << 13 0x1a000 0x1c000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.157Z DEBUG modem << 14 0x1c000 0x1e000\x09Non-Secure\x09rwxl\x0D
2020-03-26T14:07:42.164Z DEBUG modem << 15 0x1e000 0x20000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.166Z DEBUG modem << 16 0x20000 0x22000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.168Z DEBUG modem << 17 0x22000 0x24000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.170Z DEBUG modem << 18 0x24000 0x26000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.172Z DEBUG modem << 19 0x26000 0x28000\x09Non-Secure\x09rwxl\x0D
2020-03-26T14:07:42.179Z DEBUG modem << 20 0x28000 0x2a000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.181Z DEBUG modem << 21 0x2a000 0x2c000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.182Z DEBUG modem << 22 0x2c000 0x2e000\x09Non-Secure\x09rwxl\x0D
2020-03-26T14:07:42.185Z DEBUG modem << 23 0x2e000 0x30000\x09Non-Secure\x09rwxl\x0D
2020-03-26T14:07:42.188Z DEBUG modem << 24 0x30000 0x32000\x09Non-Secure\x09rwxl\x0D
2020-03-26T14:07:42.195Z DEBUG modem << 25 0x32000 0x34000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.197Z DEBUG modem << 26 0x34000 0x36000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.199Z DEBUG modem << 27 0x36000 0x38000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.201Z DEBUG modem << 28 0x38000 0x3a000\x09Non-Secure\x09rwxl\x0D
2020-03-26T14:07:42.204Z DEBUG modem << 29 0x3a000 0x3c000\x09Non-Secure\x09rwxl\x0D
2020-03-26T14:07:42.212Z DEBUG modem << 30 0x3c000 0x3e000\x09Non-Secure\x09rwxl\x0D\x0A
2020-03-26T14:07:42.213Z DEBUG modem << 31 0x3e000 0x40000\x09Non-Secure\x09rwxl\x0D\x0A\x0D\x0A
2020-03-26T14:07:42.215Z DEBUG modem << Peripheral\x09\x09Domain\x09\x09Status\x0D\x0A
2020-03-26T14:07:42.217Z DEBUG modem << 00 NRF_P0               Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.220Z DEBUG modem << 01 NRF_CLOCK            Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.224Z DEBUG modem << 02 NRF_RTC0             Non-Secure\x09OK\x0D
2020-03-26T14:07:42.230Z DEBUG modem << 03 NRF_RTC1             Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.232Z DEBUG modem << 04 NRF_NVMC             Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.234Z DEBUG modem << 05 NRF_UARTE1           Non-Secure\x09OK\x0D
2020-03-26T14:07:42.237Z DEBUG modem << 06 NRF_UARTE2           Secure\x09\x09SKIP\x0D
2020-03-26T14:07:42.246Z DEBUG modem << 07 NRF_TWIM2            Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.247Z DEBUG modem << 08 NRF_SPIM3            Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.249Z DEBUG modem << 09 NRF_TIMER0           Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.251Z DEBUG modem << 10 NRF_TIMER1           Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.254Z DEBUG modem << 11 NRF_TIMER2           Non-Secure\x09OK\x0D
2020-03-26T14:07:42.262Z DEBUG modem << 12 NRF_SAADC            Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.263Z DEBUG modem << 13 NRF_PWM0             Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.265Z DEBUG modem << 14 NRF_PWM1             Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.268Z DEBUG modem << 15 NRF_PWM2             Non-Secure\x09OK\x0D
2020-03-26T14:07:42.272Z DEBUG modem << 16 NRF_PWM3             Non-Secure\x09OK\x0D
2020-03-26T14:07:42.279Z DEBUG modem << 17 NRF_WDT              Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.281Z DEBUG modem << 18 NRF_IPC              Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.283Z DEBUG modem << 19 NRF_VMC              Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.285Z DEBUG modem << 20 NRF_FPU              Non-Secure\x09OK\x0D
2020-03-26T14:07:42.297Z DEBUG modem << 21 NRF_EGU1             Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.298Z DEBUG modem << 22 NRF_EGU2             Non-Secure\x09OK\x0D
2020-03-26T14:07:42.300Z DEBUG modem << 23 NRF_DPPIC            Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.302Z DEBUG modem << 24 NRF_GPIOTE1          Non-Secure\x09OK\x0D\x0A
2020-03-26T14:07:42.303Z DEBUG modem << 25 NRF_REGULATORS       Non-Secure\x09OK\x0D\x0A\x0D\x0A
2020-03-26T14:07:42.305Z DEBUG modem << SPM: NS image at 0xc000\x0D
2020-03-26T14:07:42.313Z DEBUG modem << SPM: NS MSP at 0x20026fb8\x0D\x0A
2020-03-26T14:07:42.315Z DEBUG modem << SPM: NS reset vector at 0xd1d9\x0D\x0A
2020-03-26T14:07:42.317Z DEBUG modem << SPM: prepare to jump to Non-Secure image.\x0D\x0A
2020-03-26T14:07:42.510Z DEBUG modem << *** Booting Zephyr OS build v2.1.99-ncs1-4-gc025ef3dd566  ***\x0D
2020-03-26T14:07:42.513Z DEBUG modem << The AT host sample started\x0D\x0A
2020-03-26T14:07:45.516Z DEBUG modem >> AT+CFUN=1\x0D\x0A
2020-03-26T14:07:45.559Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.058Z DEBUG modem >> AT+CFUN?\x0D\x0A
2020-03-26T14:07:48.062Z DEBUG modem << +CFUN: 1\x0D
2020-03-26T14:07:48.068Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.069Z DEBUG modem >> AT+CGSN=1\x0D\x0A
2020-03-26T14:07:48.076Z DEBUG modem << +CGSN: "352656100382004"\x0D\x0A
2020-03-26T14:07:48.077Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.081Z DEBUG modem >> AT+CGMI\x0D\x0A
2020-03-26T14:07:48.091Z DEBUG modem << Nordic Semiconductor ASA\x0D\x0A
2020-03-26T14:07:48.093Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.097Z DEBUG modem >> AT+CGMM\x0D\x0A
2020-03-26T14:07:48.102Z DEBUG modem << nRF9160-SICA\x0D\x0A
2020-03-26T14:07:48.108Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.111Z DEBUG modem >> AT+CGMR\x0D\x0A
2020-03-26T14:07:48.115Z DEBUG modem << mfw_nrf9160_1.1.0\x0D
2020-03-26T14:07:48.117Z DEBUG modem << \x0A
2020-03-26T14:07:48.120Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.122Z INFO Nordic Semiconductor ASA nRF9160-SICA [mfw_nrf9160_1.1.0] SerNr: 352656100382004
2020-03-26T14:07:48.127Z DEBUG modem >> AT+CEMODE?\x0D\x0A
2020-03-26T14:07:48.132Z DEBUG modem << +CEMODE: 2\x0D
2020-03-26T14:07:48.134Z DEBUG modem << \x0A
2020-03-26T14:07:48.136Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.147Z DEBUG modem >> AT%XCBAND=?\x0D\x0A
2020-03-26T14:07:48.158Z DEBUG modem << %XCBAND: (1,2,3,4,5,8,12,13,14,17,18,19,20,25,26,28,66)\x0D\x0A
2020-03-26T14:07:48.160Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.167Z DEBUG modem >> AT+CMEE?\x0D\x0A
2020-03-26T14:07:48.176Z DEBUG modem << +CMEE: 0\x0D\x0A
2020-03-26T14:07:48.177Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.179Z DEBUG modem >> AT+CMEE=1\x0D\x0A
2020-03-26T14:07:48.185Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.192Z DEBUG modem >> AT+CNEC?\x0D\x0A
2020-03-26T14:07:48.197Z DEBUG modem << +CNEC: 0\x0D\x0A
2020-03-26T14:07:48.199Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.201Z DEBUG modem >> AT+CNEC=24\x0D\x0A
2020-03-26T14:07:48.209Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.211Z DEBUG modem >> AT+CGEREP?\x0D\x0A
2020-03-26T14:07:48.216Z DEBUG modem << +CGEREP: 0,0\x0D
2020-03-26T14:07:48.217Z DEBUG modem << \x0A
2020-03-26T14:07:48.218Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.225Z DEBUG modem >> AT+CGDCONT?\x0D\x0A
2020-03-26T14:07:48.231Z DEBUG modem << +CGDCONT: 0,"IP","","",0,0\x0D
2020-03-26T14:07:48.232Z DEBUG modem << \x0A
2020-03-26T14:07:48.233Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.245Z DEBUG modem >> AT+CGACT?\x0D\x0A
2020-03-26T14:07:48.247Z DEBUG modem << +CNEC_ESM: 50,0\x0D\x0A
2020-03-26T14:07:48.252Z DEBUG modem << +CGACT: 0,1\x0D\x0A
2020-03-26T14:07:48.253Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.269Z DEBUG modem >> AT+CGEREP=1\x0D\x0A
2020-03-26T14:07:48.272Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.276Z DEBUG modem >> AT+CIND=1,1,1\x0D\x0A
2020-03-26T14:07:48.281Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.283Z DEBUG modem >> AT+CEREG=2\x0D\x0A
2020-03-26T14:07:48.292Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.295Z DEBUG modem >> AT+CEREG?\x0D\x0A
2020-03-26T14:07:48.302Z DEBUG modem << +CEREG: 2,5,"4E0C","02F1EE08",7\x0D
2020-03-26T14:07:48.308Z DEBUG modem << \x0A
2020-03-26T14:07:48.310Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.319Z DEBUG modem >> AT+COPS=3,2\x0D\x0A
2020-03-26T14:07:48.327Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.331Z DEBUG modem >> AT+COPS?\x0D\x0A
2020-03-26T14:07:48.341Z DEBUG modem << +COPS: 0,2,"310410",7\x0D
2020-03-26T14:07:48.344Z DEBUG modem << \x0A
2020-03-26T14:07:48.347Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.359Z DEBUG modem >> AT%XCBAND\x0D\x0A
2020-03-26T14:07:48.364Z DEBUG modem << %XCBAND: 2\x0D
2020-03-26T14:07:48.365Z DEBUG modem << \x0A
2020-03-26T14:07:48.367Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.379Z DEBUG modem >> AT+CGDCONT?\x0D\x0A
2020-03-26T14:07:48.392Z DEBUG modem << +CGDCONT: 0,"IP","data641003","10.49.40.232",0,0\x0D\x0A
2020-03-26T14:07:48.393Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.400Z DEBUG modem >> AT+CGACT?\x0D\x0A
2020-03-26T14:07:48.410Z DEBUG modem << +CGACT: 0,1\x0D\x0A
2020-03-26T14:07:48.411Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.417Z DEBUG modem >> AT%CESQ=1\x0D\x0A
2020-03-26T14:07:48.425Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.428Z DEBUG modem >> AT+CESQ\x0D\x0A
2020-03-26T14:07:48.435Z DEBUG modem << +CESQ: 99,99,255,255,17,33\x0D
2020-03-26T14:07:48.443Z DEBUG modem << \x0A
2020-03-26T14:07:48.444Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.459Z DEBUG modem >> AT%XSIM=1\x0D\x0A
2020-03-26T14:07:48.463Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.466Z DEBUG modem >> AT%XSIM?\x0D\x0A
2020-03-26T14:07:48.475Z DEBUG modem << %XSIM: 1\x0D\x0A
2020-03-26T14:07:48.477Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.484Z DEBUG modem >> AT+CPIN?\x0D\x0A
2020-03-26T14:07:48.492Z DEBUG modem << +CPIN: READY\x0D\x0A
2020-03-26T14:07:48.494Z DEBUG modem << OK\x0D\x0A
2020-03-26T14:07:48.502Z DEBUG modem >> AT+CPINR="SIM PIN"\x0D\x0A
2020-03-26T14:07:50.273Z DEBUG modem << +CPINR: "SIM PIN",3\x0D\x0A
2020-03-26T14:07:50.300Z DEBUG modem << OK\x0D\x0A

Øyvind said:

there seems to be a mismatch between your prj.conf and the AWS MQTT settings

No, the output there is from when I ran it with CONFIG_USE_NRF_CLOUD=y, which changes the client id, so it's expected behavior. Running with the config I posted earlier to connect to my AWS account, it still produces the same output as in my original post, where the client-id outputs as "nrf9160dk" as expected. I am using west build / west flash, but changes made to prj.conf are definitely taking effect.

[Øyvind]

I think we need to have a look at the modem connection. Can you please provide a modem trace?

Thanks!
-Øyvind

[icampbell]

trace-2020-03-26T14-58-36.611Z.bin

Here you go. I rebooted the device just after I started the trace, and ended the trace just after it printed "mqtt_connect -22".

[Øyvind]

Thank you! I will look into the modem trace and the log output to see if there is anything causing this issue. 

Will get back to you asap.

Kind regards,

Øyvind

[Øyvind]

Hello again, 

I'm sorry, so far I've got nothing from the modem trace or log. Can you please try updating the modem FW to mfw 1.1.1? If this does not fix the issue, can you please provide your project?

Thanks!

Kind regards,
Øyvind

[icampbell]

Hello,

I updated the modem firmware to 1.1.1, but I still have the same problem.

I sent you a PM with a link to my project. To use it you would have to uncomment CONFIG_PROVISION_CERTIFICATES=y.

[Øyvind]

Hello, 

I was not able to build your project, but am working on a solution. However, I found that your CLOUD_CLIENT_PRIVATE_KEY in certificates.h had an extra space after \n". This can cause issues with certificates. 
Please remove and let me know how it goes!

Kind regards,
Øyvind

[icampbell]

I removed the extra spaces, but unfortunately it still says "ERROR: mqtt_connect -22".

The project should build. I'm on the "master" branch of the sdk, if that helps (I have also tried v1.2.0, rebased off of the v1.2.0 aws_fota sample, but it had the same problem).