LTE-M always connected

[DavidKaplan]

Shalom!

 I have using the nRF9160 examples created an application for a future proposed custom board that when there is external power should always stay connected to our TCP server in LTE-M mode.

Like in the UDP example main.c file, I call modem_init(), configure_low_power() & then modem_connect().

After LTE-M network connection, I connect to our TCP server successfully but then I get a RRC change to Idle notification and then no TCP server requests are received.

We have another project using a different modem that connects to the LTE-M network that is always accessible in external power mode.

I tried changing the the proj.conf file fields and also lte_lc_psm_req(false);

The same board will need to use the LTE-M's power saving modes when only a battery is connected.

How can I have the nFR9160 always connected without going to idle?

What am I doing wrong?

This is the first time I have had to address the PSM & RPTAU & RAT directly.

Thanks

[DavidKaplan]

Shalom!

 This morning I wanted to duplicate the problem and create a debug log. I may have added late afternoon a code segment that when a send() returns an error, I understand that there is a problem and close the socket.

In the debug below you can see that after the modem registers and connects to the cellular network, I issue a series of AT commands primarily to get information for our GetStatus() command and then try to connect to our TCP server. After connection I  restarted my TCP Server and then try to reconenct.

I added to the debug [?!?] explanations. Previously when I tried in my Nordic code to close the current TCP server connection and then connect to another server I got the errno 116 always and immediately. Yesterday after I stopped the TCP server and restarted it I got a 1116 also the first reconnection try.

Thanks David

Fullscreen AMI_debug_17Jun2021a.txt Download

66-17 6:25 17/06/2021 03:25:46 |  Serial Direct Port:COM14 Reconnected!
6-17 6:25 17/06/2021 03:25:48 |  0ooting Zephyr OS build v2.4.99-ncs2  ***

6-17 6:25 17/06/2021 03:25:48 |  I: Starting bootloader

6-17 6:25 17/06/2021 03:25:48 |  I: Primary image: magic=good, swap_type=0x4, copy_done=0x1, image_ok=0x1

6-17 6:25 17/06/2021 03:25:48 |  I: Secondary image: magic=unset, swap_type=0x1, copy_done=0x3, image_ok=0x3

6-17 6:25 17/06/2021 03:25:48 |  I: Boot source: none

6-17 6:25 17/06/2021 03:25:48 |  I: Swap type: none

6-17 6:25 17/06/2021 03:25:48 |  I: Bootloader chainload address offset: 0x10000

6-17 6:25 17/06/2021 03:25:48 |  I: Jumping to the first image slot
*** Booting Zephyr OS build v2.4.99-ncs2  ***

6-17 6:25 17/06/2021 03:25:48 |  Flash regions		Domain		Permissions

6-17 6:25 17/06/2021 03:25:48 |  00 02 0x00000 0x18000 	Secure		rwxl

6-17 6:25 17/06/2021 03:25:48 |  03 31 0x18000 0x100000 	Non-Secure	rwxl

6-17 6:25 17/06/2021 03:25:48 |  

6-17 6:25 17/06/2021 03:25:48 |  Non-secure callable region 0 placed in flash region 2 with size 32.

6-17 6:25 17/06/2021 03:25:48 |  

6-17 6:25 17/06/2021 03:25:49 |  SRAM region		Domain		Permissions

6-17 6:25 17/06/2021 03:25:49 |  00 07 0x00000 0x10000 	Secure		rwxl

6-17 6:25 17/06/2021 03:25:49 |  08 31 0x10000 0x40000 	Non-Secure	rwxl

6-17 6:25 17/06/2021 03:25:49 |  

6-17 6:25 17/06/2021 03:25:49 |  Peripheral		Domain		Status

6-17 6:25 17/06/2021 03:25:49 |  00 NRF_P0               Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  01 NRF_CLOCK            Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  02 NRF_RTC0             Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  03 NRF_RTC1             Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  04 NRF_NVMC             Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  05 NRF_UARTE1           Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  06 NRF_UARTE2           Secure		SKIP

6-17 6:25 17/06/2021 03:25:49 |  07 NRF_TWIM2            Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  08 NRF_SPIM3            Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  09 NRF_TIMER0           Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  10 NRF_TIMER1           Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  11 NRF_TIMER2           Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  12 NRF_SAADC            Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  13 NRF_PWM0             Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  14 NRF_PWM1             Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  15 NRF_PWM2             Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  16 NRF_PWM3             Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  17 NRF_WDT              Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  18 NRF_IPC              Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  19 NRF_VMC              Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  20 NRF_FPU              Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  21 NRF_EGU1             Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  22 NRF_EGU2             Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  23 NRF_DPPIC            Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  24 NRF_REGULATORS       Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  25 NRF_GPIOTE1          Non-Secure	OK

6-17 6:25 17/06/2021 03:25:49 |  

6-17 6:25 17/06/2021 03:25:49 |  SPM: NS image at 0x1c200

6-17 6:25 17/06/2021 03:25:49 |  SPM: NS MSP at 0x2002e1e8

6-17 6:25 17/06/2021 03:25:49 |  SPM: NS reset vector at 0x308a9

6-17 6:25 17/06/2021 03:25:49 |  SPM: prepare to jump to Non-Secure image.

6-17 6:25 17/06/2021 03:25:49 |  E: Device id 00 00 00 does not match config c2 28 17

6-17 6:25 17/06/2021 03:25:49 |  *** Booting Zephyr OS build v2.4.99-ncs2  ***
//-----------------------------------------------------------------------------
[?!?] start of our main function
//-----------------------------------------------------------------------------
6-17 6:25 17/06/2021 03:25:49 |  01/01/2004 00:00:00[ami_main.c:2383] AMI Axion nRF9160DK Startup

6-17 6:25 17/06/2021 03:25:49 |  01/01/2004 00:00:00[ami_main.c:2421] ModemInit

//-----------------------------------------------------------------------------
[?!?] Our custom board will have an external I2C EEPROM, so I have started preparing the underlying code
//-----------------------------------------------------------------------------
6-17 6:25 17/06/2021 03:25:49 |  01/01/2004 00:00:00[ami_ee2rom.c:  40] Unable to get EEPROM device

6-17 6:25 17/06/2021 03:25:49 |  01/01/2004 00:00:00[ami_uart_boot.c: 126] Event: UART_RX_BUF_REQUEST

6-17 6:25 17/06/2021 03:25:49 |  01/01/2004 00:00:00[ami_sched.c: 358] new Watchdog alert

//-----------------------------------------------------------------------------
[?!?] Our custom board will have an external I2C temperature sensor, so I have started preparing the underlying code
//-----------------------------------------------------------------------------
6-17 6:25 17/06/2021 03:25:49 |  01/01/2004 00:00:00[ami_si7050.c:  52] Could not get SI7050 device

6-17 6:25 17/06/2021 03:25:49 |  01/01/2004 00:00:00[ami_modem.c: 780] AMI Nordic VER:1.0 03-Jun-2021

6-17 6:25 17/06/2021 03:25:49 |  01/01/2004 00:00:00[ami_sched.c: 317] ResetPIN

//-----------------------------------------------------------------------------
[?!?] Our custom board will have an external acceler sensor, so I have started preparing the underlying code
//-----------------------------------------------------------------------------
6-17 6:25 17/06/2021 03:25:49 |  01/01/2004 00:00:00[ami_lsm6dsl.c:1895] Could not get LSM6DSL device

6-17 6:25 17/06/2021 03:25:49 |  01/01/2004 00:00:00[ami_sched.c: 352] new ver changed alert

6-17 6:25 17/06/2021 03:25:49 |  01/01/2004 00:00:00[ami_main.c: 916] Axion Spectral Master Ver:38.39 6.16 16-Jun-2021 DeviceID:122 W:1 Serial:0 HW:0.0 BV:0.0 RV:0.0 AD:0

6-17 6:25 17/06/2021 03:25:49 |  01/01/2004 00:00:00[ami_main.c: 934] Boot XMODEM:0.0 0.0 EXT_FLASH:0.0 0.0

6-17 6:25 17/06/2021 03:25:49 |  01/01/2004 00:00:00[ami_main.c: 939] FDeviceID:0 AMI_Rst:0

//-----------------------------------------------------------------------------
[?!?] After modem int and start connection
//-----------------------------------------------------------------------------
6-17 6:25 17/06/2021 03:25:51 |  01/01/2004 00:00:00[ami_main.c: 364] LTE cellchange CellID:1385987 TrackingArea:7631

6-17 6:25 17/06/2021 03:25:51 |  01/01/2004 00:00:00[ami_main.c: 359] RRC mode:Connected

6-17 6:25 17/06/2021 03:25:52 |  01/01/2004 00:00:00[ami_main.c: 337] NetworkRegStatus:ConnectedHome

6-17 6:25 17/06/2021 03:25:52 |  01/01/2004 00:00:00[ami_main.c: 343] PSMupdate TAU:-1 ActiveTime:60

6-17 6:25 17/06/2021 03:25:57 |  01/01/2004 00:00:05[ami_modem.c: 919] ModemReady2Use

//-----------------------------------------------------------------------------
[?!?] The code detects that the modem has successfully connected to the cellular network, so I get more information for our GetStaus() command.
//-----------------------------------------------------------------------------
6-17 6:25 17/06/2021 03:25:57 |  01/01/2004 00:00:05[ami_modem.c:1419] +CPIN: READY


6-17 6:25 17/06/2021 03:25:57 |  01/01/2004 00:00:05[ami_modem.c:1054] AT+CPIN?


6-17 6:25 17/06/2021 03:25:57 |  01/01/2004 00:00:05[ami_modem.c:1419] %SHORTSWVER: nrf9160_1.3.0


6-17 6:25 17/06/2021 03:25:57 |  01/01/2004 00:00:05[ami_modem.c:1054] ATSHORTSWVER


6-17 6:25 17/06/2021 03:25:57 |  01/01/2004 00:00:05[ami_modem.c:1419] 352656106111514


6-17 6:25 17/06/2021 03:25:57 |  01/01/2004 00:00:05[ami_modem.c:1054] AT+CGSN


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:05[ami_modem.c:1419] 425030027739234


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:05[ami_modem.c:1054] AT+CIMI


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:05[ami_modem.c:1419] %XICCID: 8997250200077392340F


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:05[ami_modem.c:1559] RECORD DeviceID:122 IMEI:352656106111514
 SIM_ID:8997250200077392340F

6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:05[ami_modem.c:1054] AT3ICCID


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:05[ami_modem.c:1054] AT+CNUM


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:05[ami_modem.c:1054] AT+CNMI=3,2,0,1


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:05[ami_modem.c:1419] +COPS: 0,2,"42503",7


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:05[ami_modem.c:1054] AT+COPS?


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:06[ami_modem.c:1419] +CEREG: 5,1,"1DCF","00152603",7,,,"00011110","11100000"


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:06[ami_modem.c:1054] AT+CEREG?


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:06[ami_modem.c:1054] AT+COPS=3,0


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:06[ami_modem.c:1419] +COPS: 0,0,"Pelephone",7


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:06[ami_modem.c:1054] AT+COPS?


6-17 6:25 17/06/2021 03:25:58 |  01/01/2004 00:00:06[ami_modem.c:1054] AT+COPS=3,2


6-17 6:25 17/06/2021 03:25:59 |  01/01/2004 00:00:06[ami_modem.c:1419] +COPS: 0,2,"42503",7


6-17 6:25 17/06/2021 03:25:59 |  01/01/2004 00:00:06[ami_modem.c:1054] AT+COPS?


6-17 6:25 17/06/2021 03:25:59 |  01/01/2004 00:00:06[ami_modem.c:1419] %XVBAT: 5093


6-17 6:25 17/06/2021 03:25:59 |  01/01/2004 00:00:06[ami_modem.c:1054] AT3VBAT


6-17 6:25 17/06/2021 03:25:59 |  01/01/2004 00:00:06[ami_modem.c:1419] +CESQ: 99,99,255,255,10,26


6-17 6:25 17/06/2021 03:25:59 |  01/01/2004 00:00:06[ami_modem.c:1054] AT+CESQ

//-----------------------------------------------------------------------------
[?!?] I start the connect_to_cloud() function to connect to our server
//-----------------------------------------------------------------------------
6-17 6:25 17/06/2021 03:25:59 |  01/01/2004 00:00:06[ami_socket.c: 342] SocketFD:1

6-17 6:25 17/06/2021 03:25:59 |  01/01/2004 00:00:06[ami_socket.c: 286] SocketTimeout:30s

6-17 6:25 17/06/2021 03:25:59 |  01/01/2004 00:00:06[ami_socket.c: 359] Connected:192.117.10.xxx:8808
//-----------------------------------------------------------------------------
[?!?] Connection success
//-----------------------------------------------------------------------------
6-17 6:25 17/06/2021 03:25:59 |  01/01/2004 00:00:06[ami_modem.c: 991] CONNECT AppServer ONLINE
//-----------------------------------------------------------------------------
[?!?] start of send and recv
//-----------------------------------------------------------------------------
6-17 6:26 17/06/2021 03:26:12 |  01/01/2004 00:00:20[ami_local_pc.c:8020] formatFakeSetClkReply

6-17 6:26 17/06/2021 03:26:12 |  01/01/2004 00:00:20[ami_local_pc.c:5224] msg MODEM op:84 'T' len:16 ID:122

6-17 6:26 17/06/2021 03:26:12 |  01/01/2004 00:00:20[ami_local_pc.c:5224] msg MODEM op:84 'T' len:16 ID:122

6-17 6:26 17/06/2021 03:26:13 |  01/01/2004 00:00:21[ami_local_pc.c:5224] msg MODEM op:84 'T' len:16 ID:122

6-17 6:26 17/06/2021 03:26:13 |  17/06/2021 06:26:30[ami_log.c:1076] LogAquire

6-17 6:26 17/06/2021 03:26:13 |  17/06/2021 06:26:30[ami_local_pc.c:5224] msg MODEM op:84 'T' len:16 ID:122

6-17 6:26 17/06/2021 03:26:14 |  17/06/2021 06:26:30[ami_local_pc.c:5224] msg MODEM op:84 'T' len:16 ID:122

6-17 6:26 17/06/2021 03:26:14 |  17/06/2021 06:26:31[ami_local_pc.c:8128] formatAlert

6-17 6:26 17/06/2021 03:26:14 |  17/06/2021 06:26:31[ami_local_pc.c:5224] msg MODEM op:65 'A' len:20 ID:122

6-17 6:26 17/06/2021 03:26:14 |  17/06/2021 06:26:31[ami_local_pc.c:5224] msg MODEM op:115 's' len:15 ID:122

6-17 6:26 17/06/2021 03:26:14 |  17/06/2021 06:26:31[ami_local_pc.c: 813] Ver Aqua:38.39 6.16 HW:0.0 LastUpdate:16-Jun-2021

6-17 6:26 17/06/2021 03:26:15 |  17/06/2021 06:26:31[ami_local_pc.c:5224] msg MODEM op:99 'c' len:17 ID:122

6-17 6:26 17/06/2021 03:26:19 |  17/06/2021 06:26:36[ami_local_pc.c:5224] msg MODEM op:99 'c' len:17 ID:122

//-----------------------------------------------------------------------------
[?!?] I stopped my TCP server here and restarted it.
 The ami_socket_SendBinaryData() detected that the send failed and closes socket.
//-----------------------------------------------------------------------------
6-17 6:26 17/06/2021 03:26:19 |  17/06/2021 06:26:36[ami_socket.c: 226] TX Fail:128

6-17 6:26 17/06/2021 03:26:19 |  17/06/2021 06:26:36[ami_modem.c: 996] TCP|UDP Disconnected

6-17 6:26 17/06/2021 03:26:36 |  17/06/2021 06:26:52[ami_main.c: 359] RRC mode:Idle

6-17 6:26 17/06/2021 03:26:52 |  17/06/2021 06:27:09[ami_log.c:1078] AquireOnly

//-----------------------------------------------------------------------------
[?!?] Before every reconnection I want to get the battery's value. It may be that I need this before connecting to the cellular network,
    but after just thge modem_init() most AT commands do not work.
    Also before reconnection I want the signal strength for the GetStatus()
//-----------------------------------------------------------------------------
6-17 6:26 17/06/2021 03:26:52 |  17/06/2021 06:27:09[ami_modem.c:1419] %XVBAT: 5085


6-17 6:26 17/06/2021 03:26:52 |  17/06/2021 06:27:09[ami_modem.c:1054] AT3VBAT


6-17 6:26 17/06/2021 03:26:52 |  17/06/2021 06:27:09[ami_modem.c:1419] +CESQ: 99,99,255,255,16,26


6-17 6:26 17/06/2021 03:26:52 |  17/06/2021 06:27:09[ami_modem.c:1054] AT+CESQ

//-----------------------------------------------------------------------------
[?!?] I start the connect_to_cloud() function to connect to our server
//-----------------------------------------------------------------------------
6-17 6:26 17/06/2021 03:26:52 |  17/06/2021 06:27:09[ami_socket.c: 342] SocketFD:1

6-17 6:26 17/06/2021 03:26:52 |  17/06/2021 06:27:09[ami_socket.c: 286] SocketTimeout:30s

6-17 6:26 17/06/2021 03:26:53 |  17/06/2021 06:27:09[ami_main.c: 359] RRC mode:Connected

6-17 6:26 17/06/2021 03:26:53 |  17/06/2021 06:27:09[ami_socket.c: 359] Connected:192.117.10.xxx:8808

6-17 6:26 17/06/2021 03:26:53 |  17/06/2021 06:27:09[ami_modem.c: 991] CONNECT AppServer ONLINE
//-----------------------------------------------------------------------------
[?!?] Connection success
//-----------------------------------------------------------------------------

6-17 6:27 17/06/2021 03:27:02 |  <Notification Queue Out>DeviceID:122 2B7A0000000F0000110615061B7332
6-17 6:27 17/06/2021 03:27:02 |  17/06/2021 06:27:18[ami_local_pc.c:5224] msg MODEM op:115 's' len:15 ID:122

6-17 6:27 17/06/2021 03:27:02 |  17/06/2021 06:27:18[ami_local_pc.c: 813] Ver Aqua:38.39 6.16 HW:0.0 LastUpdate:16-Jun-2021

6-17 6:27 17/06/2021 03:27:02 |  DB Unit:122 s {06:27 17/06/2021} State:3 DOWNLOAD_SUCCESS
6-17 6:27 17/06/2021 03:27:08 |  17/06/2021 06:27:25[ami_local_pc.c:5224] msg MODEM op:115 's' len:15 ID:122

6-17 6:27 17/06/2021 03:27:09 |  17/06/2021 06:27:25[ami_local_pc.c: 813] Ver Aqua:38.39 6.16 HW:0.0 LastUpdate:16-Jun-2021

//-----------------------------------------------------------------------------
[?!?] I stopped my TCP server here and restarted it.
 The ami_socket_SendBinaryData() detected that the send failed and closes socket.
//-----------------------------------------------------------------------------
6-17 6:27 17/06/2021 03:27:09 |  17/06/2021 06:27:25[ami_socket.c: 226] TX Fail:128

6-17 6:27 17/06/2021 03:27:09 |  17/06/2021 06:27:25[ami_modem.c: 996] TCP|UDP Disconnected

6-17 6:27 17/06/2021 03:27:25 |  17/06/2021 06:27:42[ami_main.c: 359] RRC mode:Idle

6-17 6:27 17/06/2021 03:27:52 |  17/06/2021 06:28:09[ami_modem.c:1419] %XVBAT: 5093


6-17 6:27 17/06/2021 03:27:52 |  17/06/2021 06:28:09[ami_modem.c:1054] AT3VBAT


6-17 6:27 17/06/2021 03:27:52 |  17/06/2021 06:28:09[ami_modem.c:1419] +CESQ: 99,99,255,255,8,26


6-17 6:27 17/06/2021 03:27:52 |  17/06/2021 06:28:09[ami_modem.c:1054] AT+CESQ

//-----------------------------------------------------------------------------
[?!?] I start the connect_to_cloud() function to connect to our server
//-----------------------------------------------------------------------------
6-17 6:27 17/06/2021 03:27:52 |  17/06/2021 06:28:09[ami_socket.c: 342] SocketFD:1

6-17 6:27 17/06/2021 03:27:52 |  17/06/2021 06:28:09[ami_socket.c: 286] SocketTimeout:30s

6-17 6:27 17/06/2021 03:27:53 |  17/06/2021 06:28:09[ami_main.c: 359] RRC mode:Connected

6-17 6:27 17/06/2021 03:27:53 |  17/06/2021 06:28:09[ami_socket.c: 359] Connected:192.117.103xxx:8808
//-----------------------------------------------------------------------------
[?!?] Connection success
//-----------------------------------------------------------------------------
6-17 6:27 17/06/2021 03:27:53 |  17/06/2021 06:28:09[ami_modem.c: 991] CONNECT AppServer ONLINE

6-17 6:28 17/06/2021 03:28:05 |  <Notification Queue Out>DeviceID:122 2B7A0000000F0001110615061C7334
6-17 6:28 17/06/2021 03:28:06 |  17/06/2021 06:28:22[ami_local_pc.c:5224] msg MODEM op:115 's' len:15 ID:122

6-17 6:28 17/06/2021 03:28:06 |  17/06/2021 06:28:22[ami_local_pc.c: 813] Ver Aqua:38.39 6.16 HW:0.0 LastUpdate:16-Jun-2021

6-17 6:28 17/06/2021 03:28:06 |  DB Unit:122 s {06:28 17/06/2021} State:3 DOWNLOAD_SUCCESS
6-17 6:28 17/06/2021 03:28:12 |  17/06/2021 06:28:29[ami_local_pc.c:5224] msg MODEM op:115 's' len:15 ID:122

6-17 6:28 17/06/2021 03:28:12 |  17/06/2021 06:28:29[ami_local_pc.c: 813] Ver Aqua:38.39 6.16 HW:0.0 LastUpdate:16-Jun-2021

//-----------------------------------------------------------------------------
[?!?] I stopped my TCP server here and restarted it.
 The ami_socket_SendBinaryData() detected that the send failed and closes socket.
//-----------------------------------------------------------------------------
6-17 6:28 17/06/2021 03:28:12 |  17/06/2021 06:28:29[ami_socket.c: 226] TX Fail:128

6-17 6:28 17/06/2021 03:28:12 |  17/06/2021 06:28:29[ami_modem.c: 996] TCP|UDP Disconnected

6-17 6:28 17/06/2021 03:28:29 |  17/06/2021 06:28:45[ami_main.c: 359] RRC mode:Idle

6-17 6:28 17/06/2021 03:28:52 |  17/06/2021 06:29:09[ami_modem.c:1419] %XVBAT: 5101


6-17 6:28 17/06/2021 03:28:52 |  17/06/2021 06:29:09[ami_modem.c:1054] AT3VBAT


6-17 6:28 17/06/2021 03:28:52 |  17/06/2021 06:29:09[ami_modem.c:1419] +CESQ: 99,99,255,255,13,25


6-17 6:28 17/06/2021 03:28:52 |  17/06/2021 06:29:09[ami_modem.c:1054] AT+CESQ

//-----------------------------------------------------------------------------
[?!?] I start the connect_to_cloud() function to connect to our server
//-----------------------------------------------------------------------------
6-17 6:28 17/06/2021 03:28:52 |  17/06/2021 06:29:09[ami_socket.c: 342] SocketFD:1

6-17 6:28 17/06/2021 03:28:52 |  17/06/2021 06:29:09[ami_socket.c: 286] SocketTimeout:30s

6-17 6:28 17/06/2021 03:28:52 |  17/06/2021 06:29:09[ami_main.c: 359] RRC mode:Connected

6-17 6:29 17/06/2021 03:29:03 |  17/06/2021 06:29:20[ami_socket.c: 359] Connected:192.117.103.xxx:8808
//-----------------------------------------------------------------------------
[?!?] Connection success
//-----------------------------------------------------------------------------
6-17 6:29 17/06/2021 03:29:03 |  17/06/2021 06:29:20[ami_modem.c: 991] CONNECT AppServer ONLINE

6-17 6:29 17/06/2021 03:29:20 |  17/06/2021 06:29:37[ami_main.c: 359] RRC mode:Idle

6-17 6:31 17/06/2021 03:31:04 |  <Notification Queue Out>DeviceID:122 2B7A0000000F0002110615061F7334
6-17 6:32 17/06/2021 03:32:08 |  17/06/2021 06:32:24[ami_main.c: 359] RRC mode:Connected

6-17 6:32 17/06/2021 03:32:08 |  DB Unit:122 s {06:31 17/06/2021} State:4 DOWNLOAD_FAIL
6-17 6:32 17/06/2021 03:32:11 |  <Notification Queue Out>DeviceID:122 2B7A0000000F00031106150620730A
6-17 6:32 17/06/2021 03:32:12 |  DB Unit:122 s {06:32 17/06/2021} State:4 DOWNLOAD_FAIL
6-17 6:32 17/06/2021 03:32:25 |  17/06/2021 06:32:41[ami_main.c: 359] RRC mode:Idle

6-17 6:32 17/06/2021 03:32:37 |  17/06/2021 06:32:54[ami_local_pc.c:5224] msg MODEM op:115 's' len:15 ID:122

6-17 6:32 17/06/2021 03:32:37 |  17/06/2021 06:32:54[ami_local_pc.c: 813] Ver Aqua:38.39 6.16 HW:0.0 LastUpdate:16-Jun-2021

//-----------------------------------------------------------------------------
[?!?] I stopped my TCP server here and restarted it.
 The ami_socket_SendBinaryData() detected that the send failed and closes socket.
//-----------------------------------------------------------------------------
6-17 6:32 17/06/2021 03:32:37 |  17/06/2021 06:32:54[ami_socket.c: 226] TX Fail:9

6-17 6:32 17/06/2021 03:32:37 |  17/06/2021 06:32:54[ami_modem.c: 996] TCP|UDP Disconnected

6-17 6:35 17/06/2021 03:35:37 |  17/06/2021 06:35:54[ami_socket.c: 226] TX Fail:9

6-17 6:35 17/06/2021 03:35:37 |  17/06/2021 06:35:54[ami_modem.c: 996] TCP|UDP Disconnected

6-17 6:35 17/06/2021 03:35:37 |  17/06/2021 06:35:54[ami_modem.c:1419] %XVBAT: 5109


6-17 6:35 17/06/2021 03:35:38 |  17/06/2021 06:35:54[ami_modem.c:1054] AT3VBAT


6-17 6:35 17/06/2021 03:35:38 |  17/06/2021 06:35:54[ami_modem.c:1419] +CESQ: 99,99,255,255,255,255


6-17 6:35 17/06/2021 03:35:38 |  17/06/2021 06:35:54[ami_modem.c:1054] AT+CESQ

//-----------------------------------------------------------------------------
[?!?] I start the connect_to_cloud() function to connect to our server
//-----------------------------------------------------------------------------
6-17 6:35 17/06/2021 03:35:38 |  17/06/2021 06:35:54[ami_socket.c: 342] SocketFD:1

6-17 6:35 17/06/2021 03:35:38 |  17/06/2021 06:35:54[ami_socket.c: 286] SocketTimeout:30s

6-17 6:35 17/06/2021 03:35:38 |  17/06/2021 06:35:55[ami_main.c: 359] RRC mode:Connected

//-----------------------------------------------------------------------------
[?!?] Either I did not restart the TCP server in time or after the first failure it will not reconnect since I am sure that the TCP server is running and working therafter
//-----------------------------------------------------------------------------
6-17 6:35 17/06/2021 03:35:38 |  17/06/2021 06:35:55[ami_socket.c: 357] ConnectionErr:116 192.117.103.xxx:8808

6-17 6:35 17/06/2021 03:35:43 |  17/06/2021 06:36:00[ami_socket.c: 342] SocketFD:1

6-17 6:35 17/06/2021 03:35:43 |  17/06/2021 06:36:00[ami_socket.c: 286] SocketTimeout:30s

//-----------------------------------------------------------------------------
[?!?] This is in the ami_socket_run() function and it tries to reconnect every 5s.
  This I will change to stop after a couple of retries and then connect every minute.
  From here on I always get errno 116
//-----------------------------------------------------------------------------
6-17 6:35 17/06/2021 03:35:44 |  17/06/2021 06:36:00[ami_socket.c: 357] ConnectionErr:116 192.117.103.xxx:8808

6-17 6:35 17/06/2021 03:35:48 |  17/06/2021 06:36:05[ami_socket.c: 342] SocketFD:1

6-17 6:35 17/06/2021 03:35:48 |  17/06/2021 06:36:05[ami_socket.c: 286] SocketTimeout:30s

6-17 6:35 17/06/2021 03:35:48 |  17/06/2021 06:36:05[ami_socket.c: 357] ConnectionErr:116 192.117.103.xxx:8808

6-17 6:35 17/06/2021 03:35:54 |  17/06/2021 06:36:10[ami_socket.c: 342] SocketFD:1

6-17 6:35 17/06/2021 03:35:54 |  17/06/2021 06:36:10[ami_socket.c: 286] SocketTimeout:30s

6-17 6:35 17/06/2021 03:35:54 |  17/06/2021 06:36:10[ami_socket.c: 357] ConnectionErr:116 192.117.103.xxx:8808

6-17 6:35 17/06/2021 03:35:59 |  17/06/2021 06:36:15[ami_socket.c: 342] SocketFD:1

6-17 6:35 17/06/2021 03:35:59 |  17/06/2021 06:36:15[ami_socket.c: 286] SocketTimeout:30s

6-17 6:35 17/06/2021 03:35:59 |  17/06/2021 06:36:15[ami_socket.c: 357] ConnectionErr:116 192.117.103.xxx:8808

6-17 6:36 17/06/2021 03:36:04 |  17/06/2021 06:36:20[ami_socket.c: 342] SocketFD:1

6-17 6:36 17/06/2021 03:36:04 |  17/06/2021 06:36:20[ami_socket.c: 286] SocketTimeout:30s

6-17 6:36 17/06/2021 03:36:04 |  17/06/2021 06:36:20[ami_socket.c: 357] ConnectionErr:116 192.117.103.xxx:8808

6-17 6:36 17/06/2021 03:36:09 |  17/06/2021 06:36:25[ami_socket.c: 342] SocketFD:1

6-17 6:36 17/06/2021 03:36:09 |  17/06/2021 06:36:25[ami_socket.c: 286] SocketTimeout:30s

6-17 6:36 17/06/2021 03:36:09 |  17/06/2021 06:36:25[ami_socket.c: 357] ConnectionErr:116 192.117.103.xxx:8808

6-17 6:36 17/06/2021 03:36:14 |  17/06/2021 06:36:30[ami_socket.c: 342] SocketFD:1

6-17 6:36 17/06/2021 03:36:14 |  17/06/2021 06:36:31[ami_socket.c: 286] SocketTimeout:30s

6-17 6:36 17/06/2021 03:36:14 |  17/06/2021 06:36:31[ami_socket.c: 357] ConnectionErr:116 192.117.103.xxx:8808

6-17 6:36 17/06/2021 03:36:17 |  Serial Direct Port Disconnected!

[Heidi]

From your application, it looks like you're calling lte_lc_psm_req(true), which you can't do if you want the device to stay in RRC Connected mode all the time. 

 

DavidKaplan said:

when testing always our connected work mode

 Does this mean you fixed the issue?

Please try sending AT+CPSMS after start-up to see if PSM is enabled.

[DavidKaplan]

Shalom!

 You are correct. I don't know how I missed that I called my wrapper function ami_main_switch_low_power()

with its parameter true! When the device will run on batteries I will want this and sleep most of the time, but with external power they want a continuous connection so that web queries can arrive.

I will add the AT+CPSMS? command before connecting so I can see the power saving mode on the debug channel.

I will need to test everything again with no low power next Sunday as this is the end of my work week.

Can the low power mode affect affect re-connection to our TCP server or switching TCP servers?

Can I switch freely between low power mode in battery operation just when I upload data to our AppServer?

Thanks and I will get back with the results hopefully early next week.

[Heidi]

Can the low power mode affect re-connection to our TCP server or switching TCP servers?

No, having PSM enabled should not affect this.

Can I switch freely between low power mode in battery operation just when I upload data to our AppServer?

Yes, you can enable and disable PSM mode freely.