secure http issue, works first time, data corruption after first time...

[Anthony Ambuehl]

I"m using SLM from NCS 1.6.1.  

I'm testing HTTPCREQ with HTTPC port 443 and security tag = 1.   After I reset SLM, my send is successful and passes server validation checks.  If I repeat the procedure sending the exact same data, the server is detecting a validation failure indicating something in the data has changed.  The only way to get a successful server validation is by reseting SLM.  I suspect there is some state that is not complete reset by XHTTPCCON=0 in the TLS implementation.   When I test the same with non-secure HTTP (port 80) to postman-echo my payloads are identical.  

Is there any equivalent to postman-echo with an https variant? 

Any idea why it breaks after the first successful attempt?

[Anthony Ambuehl]

It appears the http_req_sem is being given a second time when the external mcu tries to close the https connection by sending XHTTPCCON=0.  At this time the logs show:

00> [00:00:42.949,584] <dbg> slm_at_host.uart_callback: RX_DISABLED
00> [00:00:42.954,040] <dbg> slm_at_host.uart_callback: RX_RDY 16
00> [00:00:42.954,467] <inf> slm_at_host: Raw send 16
00> [00:00:42.954,833] <dbg> slm_at_host.RX-DATAMODE
00> 41 54 23 58 48 54 54 50 43 43 4f 4e 3d 30 0d 0a |AT#XHTTP CCON=0..
00> [00:00:42.956,176] <wrn> slm_httpc: send unexpected payload
00> [00:00:42.956,573] <dbg> slm_httpc.do_send_payload: Successfully send 1585 bytes payload
00> [00:00:42.957,092] <inf> slm_httpc: datamode send: 0
00> [00:00:42.957,489] <dbg> slm_at_host.TX
00> 0d 0a 4f 4b 0d 0a |..OK..
00> [00:00:42.959,197] <dbg> slm_at_host.TX
00> 0d 0a 23 58 44 41 54 41 4d 4f 44 45 3a 20 30 0d |..#XDATA MODE: 0.
00> 0a |.
00> [00:00:42.960,968] <inf> slm_at_host: Exit datamode
00> [00:00:42.961,364] <inf> slm_httpc: HTTP thread terminated
00> [00:00:55.963,653] <dbg> slm_at_host.RX
00> 41 54[00:00:55.964,141] <dbg> slm_at_host.uart_callback: RX_DISABLED
00> |AT

which indicates the http_req_sem was given a second time when the httpc request was already completed.

[Anthony Ambuehl]

Also I suspect this only occurs because AT#XHTTPCCON=0 is send before  XDATAMODE: 0.  However this XDATAMODE: 0 is a new message which was not part of the protocol prior to 1.7.0.  Is there documentation added for its meaning?

[Charlie]

Hi Anthony,

Anthony Ambuehl said:

I suspect this only occurs because AT#XHTTPCCON=0 is send before  XDATAMODE: 0.  However this XDATAMODE: 0 is a new message which was not part of the protocol prior to 1.7.0.  Is there documentation added for its meaning?

There is the description in the document:
https://developer.nordicsemi.com/nRF_Connect_SDK/doc/1.7.0/nrf/applications/serial_lte_modem/doc/slm_data_mode.html and AT#XHTTPCCON=0 should be sent after "#XDATAMODE: 0"

Another observation, in the ncs_sdk_170_4.log, the content-length is set to 1585, but the payload received in datamode is 256+256+256+256+256+256+48+2 = 1586 so it seems not aligned.

Best regards,

Charlie

[Anthony Ambuehl]

Yes Charlie,  as I mentioned in my past posts several times the SLM appears to be randomly dropping bytes.  I suspect this occurs when the slm disables the uart while switching buffers.

To workaround this issue, after my external mcu completes sending the data it waits for the expected XHTTPREQ=0 message, if it doesn't arrive then it starts appending "\r\n" until the modem exits datamode.  The uploaded data is corrupted and unusable due to these dropped bytes.

Disabling UART to switch buffers is not a good practice, this is why the examples in BLE SDK use a ring buffer.   

The SLM is very far behind in reliability and is repeating very old mistakes.  It does not appear production ready.  When an external MCU performs an unexpected behavior, the SLM should indicate an error via a URC but there should not be any impact on future operations.  The bug in slm_at_http.c with extra data during datamode causing the semaphore to be put multiple times and thereby impacting future operation shows a clear lack of testing.    At the start of the XHTTPREQ operation all state from past operations should be cleared, and unexpected operations should not result in entering unintended/untested states.

[Charlie]

Hi Anthony,

The disable uart and while switching buffer is old behavior before v1.7.0, that's the reason we suggest to use v1.7.0 or after. In v1.7.0 the datamode stores data in ring buffer before sending, while keep UART opened and receiving data.

If mcu want to quit datamode, it should follow the Exiting data mode to send the pattern string:http://developer.nordicsemi.com/nRF_Connect_SDK/doc/1.7.0/nrf/applications/serial_lte_modem/doc/slm_data_mode.html#exiting-data-mode. Note that before and after the pattern string there should be a 1 second silence time.

Please make sure UART HWFC is enabled all the time for your tests.

Best regards,

Charlie