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

[Heidi]

Hi! Apologies for the late reply.

Could you please take a modem trace when this is happening so we can have a closer look?

See Collecting a modem trace for the nRF9160 DK

Best regards,

Heidi

[DavidKaplan]

trace-2021-06-10T03-19-46.258Z_CONFIG_PM_DEVICE=y.bintrace-2021-06-10T03-26-57.987Z_CONFIG_PM_DEVICE=n.bin

Shalom!

0167.prj.conf

Shalom!

 I took two traces, one with CONFIG_PM_DEVICE=y and the other CONFIG_PM_DEVICE=n.

The modem connects to the cellular network and then my application connects by TCP to my Application server and after a few seconds of inactivity the modem goes to RRC Idle.

I also attached my proj.c0181.nrf9160dk_nrf9160ns.overlayonf file. Our custom nRF9160 board contains a AT24C512 EEPROM, a LSM6DSL acceleration chip, a SI7055 temperature chip and a mx25r6435 external flash.

I created an overlay just in preparation for the board's arrival adding the chips to existing buses but when the config are enabled I get compile errors. Evidently I am doing something wrong or missing something in my overlay.

Thanks

 David

[Heidi]

Hi!

Can I see your main.c and Kconfig file as well, to understand what the configurations do? 

I see 

CONFIG_GPS_CONTROL_PSM_ENABLE_ON_START

is enabled which could mean you are still enabling PSM on startup.


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

Best regards,
Heidi

[DavidKaplan]

Shalom!

We will use the GPS in one software version, so I was testing it, without success, maybe because of obstructions, but in any case the define is remarked in the proj.cong file when testing always our connected work mode. I will attached our main with irrelevant functions deleted and again my ami_socket.c TCP code.

Thanks David

2072.prj.conf

Fullscreen ami_main.c Download

/*
 * Copyright (c) 2020 Nordic Semiconductor ASA
 *
 * SPDX-License-Identifier: LicenseRef-Nordic-5-Clause
 */

#include <zephyr.h>
#include <stdio.h>
#include <modem/lte_lc.h>
#include <net/socket.h>
#include <device.h>
#include <drivers/sensor.h>
#include <drivers/gps.h>
#include <drivers/uart.h>
#include <date_time.h>
#include <time.h>


#if defined(CONFIG_WATCHDOG_APPLICATION)
#include "watchdog.h"
#endif

#if defined(CONFIG_BOOTLOADER_MCUBOOT)
#include <dfu/mcuboot.h>
#endif

#include <logging/log.h>
#include <logging/log_ctrl.h>
#include "aqua_def.h"
#include "ami_GPS.h"
#include "gps_controller.h"


#ifdef TBD
         ---------------------------------------------------------
          --- WARNING: Using default MCUBoot key, it should not ---
          --- be used for production.                           ---
          ---------------------------------------------------------
#endif
 
// nRF9160 DK (PCA10090)
// Thingy:91, you have to use the nrf9160_pca20035 
//

//-----------------------------------------------------------------------------
// Last Updated
//-----------------------------------------------------------------------------
const char* LastUpdate ={"16-Jun-2021"};

/* Module name is used by the event manager macros in this file */
#define MODULE app_module

LOG_MODULE_REGISTER(MODULE, CONFIG_APPLICATION_MODULE_LOG_LEVEL);

//-----------------------------------------------------------------------------
// Stack definition for application workqueue 
//-----------------------------------------------------------------------------
K_THREAD_STACK_DEFINE(application_stack_area,
		      CONFIG_APPLICATION_WORKQUEUE_STACK_SIZE);
static struct k_work_q application_work_q;

static struct k_delayed_work seconds_work;
#if defined(CONFIG_DATE_TIME)
static s64_t  unix_time_ms = 0;
#endif


K_SEM_DEFINE(lte_connected, 0, 1);

//-----------------------------------------------------------------------------
// seconds_work_fn
//  Description
//    Worker that wakes up every second
//  Parameters
//  Returns
//-----------------------------------------------------------------------------
static void seconds_work_fn(struct k_work *work)
{
  static uint8_t secs = 0;
  //---------------------------------------------------------------------------
  // Another second has passed
  //---------------------------------------------------------------------------
  secsFrom2004.ulong++;
  state.iNewSec     = 0xFFFF;
  state.bRTCRunning = TRUE;
  secs++;
  //---------------------------------------------------------------------------
  // Another minute has passed
  //---------------------------------------------------------------------------
  if (secs>=60){
    secs = 0;
    state.iNewMinute = 0xFFFF;
  }
  k_delayed_work_submit(&seconds_work,K_SECONDS(1));
} // seconds_work_fn

//-----------------------------------------------------------------------------
// ami_main_ModemRegistered
//  Description
//    Tries to send the binary data over the connection
//  Parameters
//  Returns
//   
//-----------------------------------------------------------------------------
bool ami_main_ModemRegistered(void)
{
  enum lte_lc_nw_reg_status status;
  //---------------------------------------------------------------------------
  // Returns zero if call is successful
  //---------------------------------------------------------------------------
  if (!lte_lc_nw_reg_status_get(&status)){
   if (status==LTE_LC_NW_REG_REGISTERED_HOME || status==LTE_LC_NW_REG_REGISTERED_ROAMING){
     return true;
    }
  }
  return false;
} // ami_main_ModemRegistered

//-----------------------------------------------------------------------------
// work_init
//  Description
//    Inits all workers
//  Parameters
//  Returns
//-----------------------------------------------------------------------------
static void work_init(void)
{
  k_delayed_work_init(&seconds_work,seconds_work_fn);                      
} // work_init

//-----------------------------------------------------------------------------
// lte_handler
//  Description
//    modem event handler
//  Parameters
//  Returns
//-----------------------------------------------------------------------------
#if defined(CONFIG_NRF_MODEM_LIB)
static void lte_handler(const struct lte_lc_evt *const evt)
{
  switch (evt->type) {
    case LTE_LC_EVT_NW_REG_STATUS:
      if ((evt->nw_reg_status != LTE_LC_NW_REG_REGISTERED_HOME) &&
          (evt->nw_reg_status != LTE_LC_NW_REG_REGISTERED_ROAMING)) {
        break;
      }
      d_printf(LINE_INFO,kDbg_Info|kDbg_General,"NetworkRegStatus:Connected%s",
              evt->nw_reg_status == LTE_LC_NW_REG_REGISTERED_HOME ?
              "Home" : "Roaming");
      k_sem_give(&lte_connected);
      break;
    case LTE_LC_EVT_PSM_UPDATE:
      d_printf(LINE_INFO,kDbg_Info|kDbg_General,"PSMupdate TAU:%d ActiveTime:%d",
              evt->psm_cfg.tau, evt->psm_cfg.active_time);
      break;
    case LTE_LC_EVT_EDRX_UPDATE: 
      {
        char log_buf[60];
        ssize_t len;

        len = snprintf(log_buf, sizeof(log_buf),"eDRXupdate eDRX:%f PTW:%f",
                       evt->edrx_cfg.edrx, evt->edrx_cfg.ptw);
        if (len>0){
          d_printf(LINE_INFO,kDbg_Info|kDbg_General,"%s", log_buf);
        }
      }
      break;
    case LTE_LC_EVT_RRC_UPDATE:
      d_printf(LINE_INFO,kDbg_Info|kDbg_General,"RRC mode:%s",
              evt->rrc_mode == LTE_LC_RRC_MODE_CONNECTED ?
              "Connected" : "Idle");
      break;
    case LTE_LC_EVT_CELL_UPDATE:
      d_printf(LINE_INFO,kDbg_Info|kDbg_General,"LTE cellchange CellID:%d TrackingArea:%d",
             evt->cell.id, evt->cell.tac);
      break;
    default:
      break;
  } // switch
} // lte_handler

//-----------------------------------------------------------------------------
// ami_main_switch_low_power
//  Description
//    Configures low power
//  Parameters
//    bSwToLowPower true to switch to lower power
//  Returns
//-----------------------------------------------------------------------------
static int ami_main_switch_low_power(bool bSwToLowPower)
{
  int err;

  //---------------------------------------------------------------------------
  // Switch to Low power modem mode?
  //---------------------------------------------------------------------------
  if (bSwToLowPower){
    err = lte_lc_psm_req(true);
    if (err) {
      d_printf(LINE_INFO,kDbg_Info|kDbg_General,"lte_lc_psm_req err:%d", err);
    }
  }else{
	err = lte_lc_psm_req(false);
	if (err) {
          d_printf(LINE_INFO,kDbg_Info|kDbg_General,"lte_lc_psm_req err:%d", err);
	}
  }

#if defined(CONFIG_AMI_EDRX_ENABLE)
  /** enhanced Discontinuous Reception */
  err = lte_lc_edrx_req(true);
  if (err) {
    d_printf(LINE_INFO,kDbg_Info|kDbg_General,"lte_lc_edrx_req err:%d", err);
  }
#else
  err = lte_lc_edrx_req(false);
  if (err) {
    d_printf(LINE_INFO,kDbg_Info|kDbg_General,"lte_lc_edrx_req err: %d", err);
  }
#endif

#if defined(CONFIG_AMI_RAI_ENABLE)
  /** Release Assistance Indication  */
  err = lte_lc_rai_req(true);
  if (err) {
    d_printf(LINE_INFO,kDbg_Info|kDbg_General,"lte_lc_rai_req, err:%d", err);
  }
#endif
  return err;
} // ami_main_switch_low_power

//-----------------------------------------------------------------------------
// modem_init
//  Description
//    Inits Modem
//  Parameters
//  Returns
//-----------------------------------------------------------------------------
static void modem_init(void)
{
  //---------------------------------------------------------------------------
  // Int and connect automatically?
  //---------------------------------------------------------------------------
  if (IS_ENABLED(CONFIG_LTE_AUTO_INIT_AND_CONNECT)) {
    //-------------------------------------------------------------------------
    // Do nothing, modem is already configured and LTE connected. 
    //-------------------------------------------------------------------------
  }else{
        int err = lte_lc_init();
        if (err) {
          d_printf(LINE_INFO,kDbg_Info|kDbg_General,"ModemInitFailErr:%d", err);
        }
  }
} // modem_init

//-----------------------------------------------------------------------------
// ami_main_modem_connect
//  Description
//    Trys to connect the modem to the LTE network
//  Parameters
//  Returns
//-----------------------------------------------------------------------------
void ami_main_modem_connect(void)
{
  //---------------------------------------------------------------------------
  // Int and connect automatically?
  //---------------------------------------------------------------------------
  if (IS_ENABLED(CONFIG_LTE_AUTO_INIT_AND_CONNECT)) {
    //-------------------------------------------------------------------------
    // Do nothing, modem is already configured and LTE connected. 
    //-------------------------------------------------------------------------
  }else{
        int err = lte_lc_connect_async(lte_handler);
        if (err) {
          d_printf(LINE_INFO,kDbg_Error|kDbg_General,"Connecting LTE network Err:%d",err);
        }
  }
} // ami_main_modem_connect
#endif


//-----------------------------------------------------------------------------
// ami_main_Init
//  Description
//   StandAlone and Master mode main initialization
//  Parameters
//  Returns
//-----------------------------------------------------------------------------
bool ami_main_Init(void)
{
  //---------------------------------------------------------------------------
  // Variables init
  //---------------------------------------------------------------------------
  memset(&state,0,sizeof(state));
  memset(&otap_info,0,sizeof(otap_info));
  memset(&point_state,0,sizeof(point_state));
  memset(&alert_state,0,sizeof(alert_state));
  memset(&schd_state,0,sizeof(schd_state));
  //---------------------------------------------------------------------------
  //---------------------------------------------------------------------------
  // Configuration files init
  //---------------------------------------------------------------------------
  if (cfg_read_Config()){
    //-------------------------------------------------------------------------
    // problem with configuration
    //-------------------------------------------------------------------------
    ami_Scheduler_RaiseGeneralAlert(AQUA_ALERT_GEN_INDEX_CONFIG);
  }
  //---------------------------------------------------------------------------
  // Watchdog reset? Currently does not detect Watchdog reset!
  //---------------------------------------------------------------------------
  if (gResetInfo){
    ami_Scheduler_RaiseGeneralAlert(AQUA_ALERT_GEN_INDEX_WATCHDOG);
  }
#if defined(CONFIG_NRF9160_GPS)
  //---------------------------------------------------------------------------
  // GPS Init
  //---------------------------------------------------------------------------
  ami_GPSInit(&application_work_q);
#endif
  //---------------------------------------------------------------------------
  // Finished startup
  //---------------------------------------------------------------------------
  state.bFinishedStartup = TRUE;
  return TRUE;
} // ami_main_Init


//-----------------------------------------------------------------------------
// ami_main_Loop
//  Description
//   StandAlone and Master modes main loop
//  Parameters
//  Returns
//-----------------------------------------------------------------------------
void ami_main_Loop(void)
{
  //---------------------------------------------------------------------------
  // Main new second
  //---------------------------------------------------------------------------
  if (state.iNewSec & AQUA_CLK_TASK_MASK_MAIN){
    state.iNewSec &= ~AQUA_CLK_TASK_MASK_MAIN;
    ami_main_SecHandler();
  }
  //---------------------------------------------------------------------------
  // Main new Minute
  //---------------------------------------------------------------------------
  if (state.iNewMinute & AQUA_CLK_TASK_MASK_MAIN){
    state.iNewMinute &= ~AQUA_CLK_TASK_MASK_MAIN;
    ami_main_MinuteHandler();
  }
#if defined(CONFIG_NRF9160_GPS)
  //---------------------------------------------------------------------------
  // Service GPS
  //---------------------------------------------------------------------------
  if (ami_GPSIsActive()){
    ami_GPS_Service();
  }
#endif
} // ami_main_Loop

//-----------------------------------------------------------------------------
// main
//  Description
//    Main program
//  Parameters
//  Returns
//-----------------------------------------------------------------------------
void main(void)
{
  int err;

  //---------------------------------------------------------------------------
  // Init Watchdog
  //---------------------------------------------------------------------------
#if defined(CONFIG_WATCHDOG_APPLICATION)
  err = watchdog_init_and_start();
  if (err) {
    d_printf(LINE_INFO,kDbg_Error|kDbg_General,"watchdog_init_and_start, error: %d", err);
    // SEND_ERROR(app, APP_EVT_ERROR, err);
  }
#endif
  //---------------------------------------------------------------------------
  // Init and start work queue
  //---------------------------------------------------------------------------
  k_work_q_start(&application_work_q, application_stack_area,
                 K_THREAD_STACK_SIZEOF(application_stack_area),
                 CONFIG_APPLICATION_WORKQUEUE_PRIORITY);
  //---------------------------------------------------------------------------
  // Init Work tasks
  //---------------------------------------------------------------------------
  work_init();
  //---------------------------------------------------------------------------
  // Init Modem
  //---------------------------------------------------------------------------
  d_printf(LINE_INFO,kDbg_Info|kDbg_General,"ModemInit");
  //---------------------------------------------------------------------------
  // Init main
  //---------------------------------------------------------------------------
  ami_main_Init();
#if defined(CONFIG_NRF_MODEM_LIB)
  //---------------------------------------------------------------------------
  // Initialize the modem before calling ami_main_switch_low_power(). This is
  //  because the enabling of RAI is dependent on the
  //  configured network mode which is set during modem initialization.
  //---------------------------------------------------------------------------
  modem_init();
  //---------------------------------------------------------------------------
  // Configure low power
  //---------------------------------------------------------------------------
  err = ami_main_switch_low_power(true);
  if (err) {
    d_printf(LINE_INFO,kDbg_Error|kDbg_General,"Unable to set low power configuration, error: %d\n",
                 err);
  }
  //---------------------------------------------------------------------------
  // nRF9160 modem init
  //---------------------------------------------------------------------------
  ami_main_modem_connect();
  k_sem_take(&lte_connected, K_FOREVER);
#endif
  //---------------------------------------------------------------------------
  // Init periodic second worker task
  //---------------------------------------------------------------------------
  k_delayed_work_submit(&seconds_work,K_SECONDS(1));
  //---------------------------------------------------------------------------
  // Init AMI Socket
  //---------------------------------------------------------------------------
  ami_socket_init();
  //---------------------------------------------------------------------------
  // Main Loop
  //---------------------------------------------------------------------------
  for (;;){
    ami_main_Loop(); 
    k_sleep(K_MSEC(1));
  }
} // main

Fullscreen ami_socket.c Download

/*
 * Copyright (c) 2017 Nordic Semiconductor ASA
 *
 * SPDX-License-Identifier: LicenseRef-Nordic-5-Clause
 */
#include <zephyr.h>
#include <stdio.h>
#include <modem/lte_lc.h>
#include <net/socket.h>
#include <device.h>
#include <drivers/sensor.h>
#include <date_time.h>
#include <time.h>

//#include <logging/log.h>
//#include <logging/log_ctrl.h>
#include "aqua_def.h"
#include "ami_main.h"
#include "ami_socket.h"
#include "d_printf.h"
#include "ami_modem.h"

#define RECV_BUF_SIZE 576
#define CONFIG_DOWNLOAD_CLIENT_TCP_SOCK_TIMEO_MS 30000
#define CONFIG_DOWNLOAD_CLIENT_UDP_SOCK_TIMEO_MS 4000

/* Validates if the API was requested in the right state. */
#define NOT_VALID_STATE(EXPECTED) ((EXPECTED) < cur_socket_state)

//-----------------------------------------------------------------------------
// Maintains the state with respect to the cloud. 
//-----------------------------------------------------------------------------
static volatile enum ami_socket_state cur_socket_state = AMI_SOCKET_STATE_IDLE;

//-----------------------------------------------------------------------------
// Flag to indicate if a disconnect has been requested. 
//-----------------------------------------------------------------------------
static atomic_t disconnect_requested;

//-----------------------------------------------------------------------------
// Flag to indicate if a transport disconnect event has been received. 
//-----------------------------------------------------------------------------
static atomic_t transport_disconnected;

// static struct cloud_backend *nrf_cloud_backend;

/* Handler registered by the application with the module to receive
 * asynchronous events.
 */
static ami_socket_event_handler_t app_event_handler;
static char                        recv_buf[RECV_BUF_SIZE];


static K_MUTEX_DEFINE(state_mutex);

static K_SEM_DEFINE(connection_poll_sem, 0, 1);
static atomic_t connection_poll_active;
static int      app_socket_fd = -1;


//-----------------------------------------------------------------------------
// Local Function Prototypes
//-----------------------------------------------------------------------------

//-----------------------------------------------------------------------------
// ami_socket_get_current_state
//  Description
//    
//  Parameters
//  Returns
//   Current State
//-----------------------------------------------------------------------------
enum ami_socket_state ami_socket_get_current_state(void)
{
  return cur_socket_state;
} // ami_socket_get_current_state

//-----------------------------------------------------------------------------
// ami_socket_set_current_state_and_notify
//  Description
//    
//  Parameters
//   state
//   evt
//  Returns
//-----------------------------------------------------------------------------
void ami_socket_set_current_state_and_notify(enum ami_socket_state state,
				       const struct ami_socket_evt *evt)
{
  k_mutex_lock(&state_mutex, K_FOREVER);
  cur_socket_state = state;

  if ((evt != NULL) &&
      (evt->type == AMI_SOCKET_EVT_TRANSPORT_DISCONNECTED)) {
    atomic_set(&transport_disconnected, 1);
  }

  if ((app_event_handler != NULL) && (evt != NULL)) {
    app_event_handler(evt);
  }
  k_mutex_unlock(&state_mutex);
} // ami_socket_set_current_state_and_notify

//-----------------------------------------------------------------------------
// ami_socket_get_disconnect_requested
//  Description
//    
//  Parameters
//  Returns
//
//-----------------------------------------------------------------------------
bool ami_socket_get_disconnect_requested(void)
{
  return (bool)atomic_get(&disconnect_requested);
} // ami_socket_get_disconnect_requested

#ifdef TBD
//-----------------------------------------------------------------------------
// connect_error_translate
//  Description
//    
//  Parameters
//  Returns
//
//-----------------------------------------------------------------------------
int connect_error_translate(const int err)
{
  switch (err) {
    case 0:
            return AMI_SOCKET_CONNECT_RES_SUCCESS;
    case -ECHILD:
            return AMI_SOCKET_CONNECT_RES_ERR_NETWORK;
    case -EACCES:
            return AMI_SOCKET_CONNECT_RES_ERR_NOT_INITD;
    case -ENOEXEC:
            return AMI_SOCKET_CONNECT_RES_ERR_BACKEND;
    case -EINVAL:
            return AMI_SOCKET_CONNECT_RES_ERR_PRV_KEY;
    case -EOPNOTSUPP:
            return AMI_SOCKET_CONNECT_RES_ERR_CERT;
    case -ECONNREFUSED:
            return AMI_SOCKET_CONNECT_RES_ERR_CERT_MISC;
    case -ETIMEDOUT:
            return AMI_SOCKET_CONNECT_RES_ERR_TIMEOUT_NO_DATA;
    case -ENOMEM:
            return AMI_SOCKET_CONNECT_RES_ERR_NO_MEM;
    case -EINPROGRESS:
            return AMI_SOCKET_CONNECT_RES_ERR_ALREADY_CONNECTED;
    default:
            // LOG_ERR("nRF cloud connect failed %d", err);
            return AMI_SOCKET_CONNECT_RES_ERR_MISC;
  } // switch
} // connect_error_translate
#endif

//-----------------------------------------------------------------------------
// inet_addr
//  Description
//    
//  Parameters
//  Returns
//
//-----------------------------------------------------------------------------
u32_t inet_addr(u8_t a, u8_t b, u8_t c, u8_t d)
{
  u32_t value = 0;

  value |= (u32_t)((((u8_t)(d)) << 24) & 0xFF000000);
  value |= (u32_t)((((u8_t)(c)) << 16) & 0x00FF0000);
  value |= (u32_t)((((u8_t)(b)) << 8) & 0x0000FF00);
  value |= (u32_t)((((u8_t)(a)) << 0) & 0x000000FF);
  return value;
} // inet_addr

//-----------------------------------------------------------------------------
// blocking_recv
//  Description
//    
//  Parameters
//  Returns
//
//-----------------------------------------------------------------------------
int blocking_recv(int fd, u8_t *buf, u32_t size, u32_t flags)
{
  int err;

  do{
     err = recv(fd, buf, size, flags);
  }while ((err<0) && (errno==EAGAIN) && !ami_socket_get_disconnect_requested());
  return err;
} // blocking_recv

//-----------------------------------------------------------------------------
// blocking_send
//  Description
//    
//  Parameters
//  Returns
//
//-----------------------------------------------------------------------------
static int blocking_send(int fd, u8_t *buf, u32_t size, u32_t flags)
{
  int err;

  do{
     err = send(fd, buf, size, flags);
  }while ((err<0) && (errno==EAGAIN) && !ami_socket_get_disconnect_requested());
  return err;
} // blocking_send

//-----------------------------------------------------------------------------
// ami_socket_SendBinaryData
//  Description
//    Tries to send the binary data over the connection
//  Parameters
//    buf
//    len
//  Returns
//    true if sent
//-----------------------------------------------------------------------------
bool ami_socket_SendBinaryData(const unsigned char *buf,uint16_t len)
{
  int err = blocking_send(app_socket_fd,(u8_t *)buf, len, 0);
  if (err < 0) {
    d_printf(LINE_INFO,kDbg_Error|kDbg_General,"TX Fail:%d", errno);
//#ifdef TBD
    //---------------------------------------------------------------------
    // Set Network Disconnected 
    //---------------------------------------------------------------------
    struct ami_socket_evt evt;
    evt.type   = AMI_SOCKET_EVT_TRANSPORT_DISCONNECTED;
    evt.status = AMI_SOCKET_CONNECT_RES_ERR_NETWORK;
    ami_socket_set_current_state_and_notify(AMI_SOCKET_STATE_DISCONNECTED, &evt);
//#endif
  }
  return (err==0);
} // ami_socket_SendBinaryData

//-----------------------------------------------------------------------------
// blocking_connect
//  Description
//    
//  Parameters
//  Returns
//   0 = OK
//-----------------------------------------------------------------------------
static int blocking_connect(int fd, struct sockaddr *local_addr, socklen_t len)
{
  int err;

  do{
     err = connect(fd, local_addr, len);
  }while ((err<0) && (errno==EAGAIN) && !ami_socket_get_disconnect_requested());
  return err;
} // blocking_connect

//-----------------------------------------------------------------------------
// socket_timeout_set
//  Description
//    
//  Parameters
//  Returns
//   0 = OK
//-----------------------------------------------------------------------------
static int socket_timeout_set(int fd, int type)
{
  int err;
  uint32_t timeout_ms;

  if (type == SOCK_STREAM) {
    timeout_ms = CONFIG_DOWNLOAD_CLIENT_TCP_SOCK_TIMEO_MS;
  }else{
        timeout_ms = CONFIG_DOWNLOAD_CLIENT_UDP_SOCK_TIMEO_MS;
  }

  if (timeout_ms <= 0) {
    return 0;
  }

  struct timeval timeo = {
    .tv_sec = (timeout_ms / 1000),
    .tv_usec = (timeout_ms % 1000) * 1000,
  };

  d_printf(LINE_INFO,kDbg_Info|kDbg_General,"SocketTimeout:%lds", timeo.tv_sec);
  err = setsockopt(fd, SOL_SOCKET, SO_RCVTIMEO, &timeo, sizeof(timeo));
  if (err){
    d_printf(LINE_INFO,kDbg_Error|kDbg_General,"SocketTimeoutErr:%d", errno);
    return -errno;
  }
#ifdef TBD
  int enable = 1;
  err = setsockopt(fd, SOL_SOCKET, SO_REUSEADDR, &enable, sizeof(int));
  if (err<0){
    d_printf(LINE_INFO,kDbg_Error|kDbg_General,"setsockopt(SO_REUSEADDR) failed");
  }
 #endif
  return 0;
} // socket_timeout_set

//-----------------------------------------------------------------------------
// connect_to_cloud
//  Description
//    Tries to connect to the Cloud
//  Parameters
//  Returns
//   ami_socket_connect_result
//-----------------------------------------------------------------------------
static int connect_to_cloud(void)
{
  atomic_set(&disconnect_requested, 0);

  struct sockaddr    local_addr;
  int                err;
  char               sIPPort[24];

  sprintf(sIPPort,"%u.%u.%u.%u:%u",
      cur_server.server_ip.bytes[MSB_HI_BYTE],
      cur_server.server_ip.bytes[MSB_LO_BYTE],
      cur_server.server_ip.bytes[LSB_HI_BYTE],
      cur_server.server_ip.bytes[LSB_LO_BYTE],
      cur_server.server_port.word
   );
  //---------------------------------------------------------------------------
  // Parse the IP:Port string
  //---------------------------------------------------------------------------
  if (!net_ipaddr_parse((const char *)sIPPort,strlen(sIPPort),&local_addr)){
    d_printf(LINE_INFO,kDbg_Error|kDbg_General,"ServerIP:PortParsingErr");
    return AMI_SOCKET_CONNECT_RES_ERR_NOT_INITD;
  }
  //---------------------------------------------------------------------------
  // Close socket if opened
  //---------------------------------------------------------------------------
  if (app_socket_fd>=0){
    close(app_socket_fd);
  }
  //---------------------------------------------------------------------------
  // Create a TCP socket
  //---------------------------------------------------------------------------
  app_socket_fd = socket(AF_INET,SOCK_STREAM,IPPROTO_TCP);
  d_printf(LINE_INFO,kDbg_Info|kDbg_General,"SocketFD:%d",app_socket_fd);
  //---------------------------------------------------------------------------
  // Set socket timeout
  //---------------------------------------------------------------------------
  err = socket_timeout_set(app_socket_fd,SOCK_STREAM);
  if (err) {
    d_printf(LINE_INFO,kDbg_Info|kDbg_General,"SetSockTimeoutErr:%d", errno);
    return err;
  }
  //---------------------------------------------------------------------------
  // Connect
  //---------------------------------------------------------------------------
  err = blocking_connect(app_socket_fd, (struct sockaddr *)&local_addr,sizeof(struct sockaddr_in));
  if (errno){
    err = errno;
    d_printf(LINE_INFO,kDbg_Info|kDbg_General,"ConnectionErr:%d %s",errno,sIPPort);
  }else
    d_printf(LINE_INFO,kDbg_Info|kDbg_General,"Connected:%s",sIPPort);
  return err;
} // connect_to_cloud

//-----------------------------------------------------------------------------
// ami_socket_disconnect
//  Description
//    
//  Parameters
//  Returns
//
//-----------------------------------------------------------------------------
int ami_socket_disconnect(void)
{
  if (NOT_VALID_STATE(AMI_SOCKET_STATE_CONNECTED)) {
    return -EACCES;
  }
  atomic_set(&disconnect_requested, 1);
  return 0;
} // ami_socket_disconnect

//-----------------------------------------------------------------------------
// ami_socket_start_connection_poll
//  Description
//    
//  Parameters
//  Returns
//
//-----------------------------------------------------------------------------
int ami_socket_start_connection_poll()
{
  //---------------------------------------------------------------------------
  // IDLE?
  //---------------------------------------------------------------------------
  if (cur_socket_state==AMI_SOCKET_STATE_IDLE) {
    return -EACCES;
  }
  //---------------------------------------------------------------------------
  // Already Connected?
  //---------------------------------------------------------------------------
  if (cur_socket_state==AMI_SOCKET_STATE_CONNECTED){
    return 0;
  }
  if (atomic_get(&connection_poll_active)) {
    // LOG_DBG("Connection poll in progress");
    return -EINPROGRESS;
  }
  atomic_set(&disconnect_requested, 0);
  k_sem_give(&connection_poll_sem);
  return 0;
} // ami_socket_start_connection_poll

//-----------------------------------------------------------------------------
// ami_socket_internal_init
//  Description
//    
//  Parameters
//  Returns
//
//-----------------------------------------------------------------------------
int ami_socket_internal_init(const struct ami_socket_init_param *param)
{
  if (cur_socket_state != AMI_SOCKET_STATE_IDLE) {
    return -EACCES;
  }
  if (param->event_handler == NULL) {
    return -EINVAL;
  }
  //---------------------------------------------------------------------------
  // Set Event handler
  //---------------------------------------------------------------------------
  app_event_handler = param->event_handler;
  //---------------------------------------------------------------------------
  // Set state
  //---------------------------------------------------------------------------
  cur_socket_state = AMI_SOCKET_STATE_INITIALIZED;
  return 0;
} // ami_socket_internal_init

//-----------------------------------------------------------------------------
// api_event_handler
//  Description
//    
//  Parameters
//  Returns
//
//-----------------------------------------------------------------------------
static void api_event_handler(const struct ami_socket_evt *evt)
{
  static int8_t kkk = 0;
  if (evt!=NULL){
    kkk++;
  }
  switch (evt->type){
    case AMI_SOCKET_EVT_TRANSPORT_CONNECTING:
      break;
    case AMI_SOCKET_EVT_TRANSPORT_CONNECTED:
      MODEM_TCP_UDPConnected(true);
      break;
    case AMI_SOCKET_EVT_RX_DATA:
      {
        NRF9160_OnlineRXMsg((unsigned char *)evt->data.ptr,evt->data.len);
      }
      break;
    case AMI_SOCKET_EVT_TRANSPORT_DISCONNECTED:
      MODEM_TCP_UDPConnected(false);
      break;
    default:
      break;
  } // switch
} // api_event_handler

//-----------------------------------------------------------------------------
// ami_socket_init
//  Description
//    
//  Parameters
//  Returns
//
//-----------------------------------------------------------------------------
int ami_socket_init(void)
{
  const struct ami_socket_init_param params = {
          .event_handler = api_event_handler
  };
  return ami_socket_internal_init(&params);
} // ami_socket_init

//-----------------------------------------------------------------------------
// ami_socket_run
//  Description
//    
//  Parameters
//  Returns
//-----------------------------------------------------------------------------
void ami_socket_run(int unused1, int unused2, int unused3)
{
  int                   ret;
  struct ami_socket_evt evt;

start:
  k_sem_take(&connection_poll_sem, K_FOREVER);
  atomic_set(&connection_poll_active, 1);

  evt.type = AMI_SOCKET_EVT_TRANSPORT_CONNECTING;
  evt.status = AMI_SOCKET_CONNECT_RES_SUCCESS;
  app_event_handler(&evt);

  //---------------------------------------------------------------------------
  // Connect to Cloud
  //---------------------------------------------------------------------------
  ret = connect_to_cloud(); 
  //---------------------------------------------------------------------------
  // Translate error
  //---------------------------------------------------------------------------
 // ret = connect_error_translate(ret);
  //---------------------------------------------------------------------------
  // Connection error?
  //---------------------------------------------------------------------------
  if (ret != AMI_SOCKET_CONNECT_RES_SUCCESS) {
    if (ret==-ECONNREFUSED){
      d_printf(LINE_INFO,kDbg_Info|kDbg_General,"Connected:%s",ret); 
    }
    goto reset;
  }
  //---------------------------------------------------------------------------
  // Set Connected 
  //---------------------------------------------------------------------------
  evt.type  = AMI_SOCKET_EVT_TRANSPORT_CONNECTED;
  evt.status = AMI_SOCKET_CONNECT_RES_SUCCESS;
  ami_socket_set_current_state_and_notify(AMI_SOCKET_STATE_CONNECTED, &evt);
  //---------------------------------------------------------------------------
  // Clear 
  //---------------------------------------------------------------------------
  atomic_set(&transport_disconnected, 0);
  //---------------------------------------------------------------------------
  // Loop
  //---------------------------------------------------------------------------
  while (true) {
    size_t reply_bytes;
    do {
        if (ami_socket_get_disconnect_requested()){
          evt.type   = AMI_SOCKET_EVT_TRANSPORT_DISCONNECTED;
          evt.status = AMI_SOCKET_DISCONNECT_MISC;
          ami_socket_set_current_state_and_notify(AMI_SOCKET_STATE_DISCONNECTED, &evt);
          goto reset;
        }
        reply_bytes = blocking_recv(app_socket_fd, recv_buf,sizeof(recv_buf)-1,0);
        if (reply_bytes > 0 && ret < RECV_BUF_SIZE) {
          evt.type = AMI_SOCKET_EVT_RX_DATA;
          evt.data.ptr = (char *)recv_buf;
          evt.data.len = reply_bytes;
          app_event_handler(&evt);
        }
#ifdef TBD
        //---------------------------------------------------------------------
        // Disconnected
        //---------------------------------------------------------------------
        if (atomic_get(&transport_disconnected) == 1) {
          evt.type   = AMI_SOCKET_EVT_TRANSPORT_DISCONNECTED;
          evt.status = AMI_SOCKET_DISCONNECT_MISC;
          goto reset;
        }
#endif
        k_sleep(K_MSEC(4));
   } while (reply_bytes > 0);
   //--------------------------------------------------------------------------
   // Send the event if the transport has not already been disconnected 
   //--------------------------------------------------------------------------
   if (atomic_get(&transport_disconnected) == 0) {
     app_event_handler(&evt);
     ami_socket_disconnect(); 
     break;
   }
 } // while

reset:
  //---------------------------------------------------------------------------
  // Close socket if opened
  //---------------------------------------------------------------------------
  if (app_socket_fd>=0){
    close(app_socket_fd);
    app_socket_fd = -1;
  }
  atomic_set(&disconnect_requested, 0);
  atomic_set(&connection_poll_active, 0);
 // k_sem_take(&connection_poll_sem, K_NO_WAIT);
  k_sleep(K_MSEC(5000));
  goto start;
} // ami_socket_run

#define POLL_THREAD_PRIORITY 5      // K_LOWEST_APPLICATION_THREAD_PRIO
#define POLL_THREAD_STACK_SIZE 3072
K_THREAD_DEFINE(connection_poll_thread, POLL_THREAD_STACK_SIZE,
		ami_socket_run, NULL, NULL, NULL,
		POLL_THREAD_PRIORITY, 0, 0);

[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.