base-sms: wait up to 60s when sending SMS messages

The operation sending the raw data of the SMS may timeout because the
current value of 10s is too low.

When this happens, we may end up marking the modem as invalid if the
operation takes much longer, as in
https://gitlab.freedesktop.org/mobile-broadband/ModemManager/issues/133

  <debug> [1561707204.192676] (ttyUSB3): --> 'AT+CMGS=22<CR>'
  <debug> [1561707204.207212] (ttyUSB3): <-- '<CR><LF>> '
  <debug> [1561707204.207562] (ttyUSB3) device open count is 3 (open)
  <debug> [1561707204.207695] (ttyUSB3) device open count is 2 (close)
  <debug> [1561707204.207841] (ttyUSB3): --> '0021000B9164xxxxxxxxFx00000AEDF6989D06D1CB733A\26'
  <debug> [1561707204.261028] (ttyUSB3): <-- '<CR><LF>'
  <debug> [1561707205.197464] (ttyUSB3) device open count is 3 (open)
  <debug> [1561707207.197763] loading signal quality...
  <debug> [1561707207.197990] (ttyUSB3) device open count is 4 (open)
  <debug> [1561707210.199337] (ttyUSB3) device open count is 5 (open)
  <debug> [1561707214.197198] (ttyUSB3) device open count is 4 (close)
  <debug> [1561707214.197443] (ttyUSB3): --> 'AT+CGACT?<CR>'
  <debug> [1561707215.196530] (ttyUSB3) device open count is 5 (open)
  <warn>  [1561707217.196750] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out
  <debug> [1561707217.196928] (ttyUSB3) device open count is 4 (close)
  <warn>  [1561707217.197065] (tty/ttyUSB3) at port timed out 2 consecutive times
  <debug> [1561707217.197187] (ttyUSB3): --> 'AT+CIND?<CR>'
  <debug> [1561707220.198180] (ttyUSB3) device open count is 5 (open)
  <debug> [1561707222.196792] (ttyUSB3) device open count is 6 (open)
  <debug> [1561707222.196983] (ttyUSB3) device open count is 5 (close)
  <warn>  [1561707222.197125] (tty/ttyUSB3) at port timed out 3 consecutive times
  <debug> [1561707222.197257] (ttyUSB3): --> 'AT+CGACT?<CR>'
  <debug> [1561707225.198384] (ttyUSB3) device open count is 6 (open)
  <warn>  [1561707225.198616] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out
  <debug> [1561707225.198703] (ttyUSB3) device open count is 5 (close)
  <warn>  [1561707225.198814] (tty/ttyUSB3) at port timed out 4 consecutive times
  <debug> [1561707225.199437] (ttyUSB3): --> 'AT+CGACT?<CR>'
  <warn>  [1561707228.196747] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out
  <debug> [1561707228.196915] (ttyUSB3) device open count is 4 (close)
  <warn>  [1561707228.197050] (tty/ttyUSB3) at port timed out 5 consecutive times
  <debug> [1561707228.197175] (ttyUSB3): --> 'AT+CGACT?<CR>'
  <debug> [1561707230.197709] (ttyUSB3) device open count is 5 (open)
  <warn>  [1561707231.197089] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out
  <debug> [1561707231.197256] (ttyUSB3) device open count is 4 (close)
  <warn>  [1561707231.197387] (tty/ttyUSB3) at port timed out 6 consecutive times
  <debug> [1561707231.197519] (ttyUSB3): --> 'AT+CSQ<CR>'
  <debug> [1561707234.199671] Couldn't refresh signal quality: 'Serial command timed out'
  <debug> [1561707234.199897] (ttyUSB3) device open count is 5 (open)
  <debug> [1561707234.200038] (ttyUSB3) device open count is 4 (close)
  <warn>  [1561707234.200161] (tty/ttyUSB3) at port timed out 7 consecutive times
  <debug> [1561707234.200291] (ttyUSB3): --> 'AT+CGACT?<CR>'
  <debug> [1561707235.197071] (ttyUSB3) device open count is 5 (open)
  <debug> [1561707237.198460] Signal quality value not updated in 60s, marking as not being recent
  <warn>  [1561707237.198846] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out
  <debug> [1561707237.198949] (ttyUSB3) device open count is 4 (close)
  <warn>  [1561707237.199060] (tty/ttyUSB3) at port timed out 8 consecutive times
  <debug> [1561707237.199636] (ttyUSB3): --> 'AT+CGACT?<CR>'
  <debug> [1561707240.198778] (ttyUSB3) device open count is 5 (open)
  <warn>  [1561707240.199031] checking if connected failed: Couldn't check current list of active PDP contexts: Serial command timed out
  <debug> [1561707240.199127] (ttyUSB3) device open count is 4 (close)
  <warn>  [1561707240.199244] (tty/ttyUSB3) at port timed out 9 consecutive times
  <debug> [1561707240.199363] (ttyUSB3): --> 'AT+CNSMOD?<CR>'
  <debug> [1561707243.198163] Couldn't refresh access technologies: 'Serial command timed out'
  <debug> [1561707243.198294] Periodic signal quality checks scheduled in 30s
  <debug> [1561707243.198402] (ttyUSB3) device open count is 3 (close)
  <error> [1561707243.198528] (tty/ttyUSB3) at port timed out 10 consecutive times, marking modem '/org/freedesktop/ModemManager1/Modem/0' as invalid
  <debug> [1561707243.198699] (ttyUSB3): --> 'AT+CGACT?<CR>'

Or we may end up aborting other actions that the modem is doing...

  <debug> [1560473069.956036] (ttyACM2): --> 'AT+CMGS=70<CR>'
  <debug> [1560473069.963667] Added CALL at '/org/freedesktop/ModemManager1/Call/1'
  <debug> [1560473069.977937] (ttyACM2): <-- '<CR><LF>> '
  <debug> [1560473069.978558] (ttyACM2) device open count is 3 (open)
  <debug> [1560473069.978812] (ttyACM2) device open count is 2 (close)
  <debug> [1560473069.979152] (ttyACM2): --> '0001000D8......................\26'
  <debug> [1560473080.317049] (ttyACM2): --> 'ATD123456789;<CR>'
  <debug> [1560473092.293458] (ttyACM2): <-- '<CR><LF>+CMGS: 1<CR><LF><CR><LF>OK<CR><LF>'
  <warn>  [1560473092.293854] Couldn't start call : 'Couldn't start the call: Unhandled response '+CMGS: 1''
  <info>  [1560473092.293936] Call state changed: dialing -> terminated (unknown)
  <debug> [1560473092.293987] Cleaning up in-call unsolicited events...

So, update the raw data sending timeout to a much longer value.
This commit is contained in:
Aleksander Morgado
2019-07-09 16:55:48 +02:00
parent 3e3dfc784d
commit ea93aad8a4

View File

@@ -1143,7 +1143,7 @@ send_generic_ready (MMBaseModem *modem,
* sent right away (not queued after other AT commands). */
mm_base_modem_at_command_raw (ctx->modem,
ctx->msg_data,
10,
60,
FALSE,
(GAsyncReadyCallback)send_generic_msg_data_ready,
task);
@@ -1214,7 +1214,7 @@ sms_send_next_part (GTask *task)
mm_sms_part_get_index ((MMSmsPart *)ctx->current->data));
mm_base_modem_at_command (ctx->modem,
cmd,
30,
60,
FALSE,
(GAsyncReadyCallback)send_from_storage_ready,
task);
@@ -1241,7 +1241,7 @@ sms_send_next_part (GTask *task)
g_assert (ctx->msg_data != NULL);
mm_base_modem_at_command (ctx->modem,
cmd,
30,
60,
FALSE,
(GAsyncReadyCallback)send_generic_ready,
task);