Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Cellular: Improve ATHandler AT debug traces #10121

Merged
merged 1 commit into from Apr 3, 2019

Conversation

Projects
None yet
@kivaisan
Copy link
Contributor

commented Mar 15, 2019

Description

Original AT debug traces had several issues:

  • Can be overwritten by other traces (printf/mbed-trace)
  • No way to know which direction message was going (TX or RX)
  • and characters were not visible in trace
    etc.

This commit addresses those issues using mbed-trace and showing separately
each filehandle write and read.

Pull request type

[X] Fix
[ ] Refactor
[ ] Target update
[ ] Functionality change
[ ] Docs update
[ ] Test update
[ ] Breaking change

Reviewers

@AriParkkila @mirelachirica @jarvte

Release Notes

@ciarmcom ciarmcom requested review from AriParkkila, jarvte, mirelachirica and ARMmbed/mbed-os-maintainers Mar 15, 2019

@ciarmcom

This comment has been minimized.

Copy link
Member

commented Mar 15, 2019

@NirSonnenschein

This comment has been minimized.

Copy link
Contributor

commented Mar 17, 2019

@kivaisan , please fix the a-style issues

@kivaisan kivaisan force-pushed the kivaisan:improve_at_trace branch 2 times, most recently to 59a772a Mar 18, 2019

@kivaisan

This comment has been minimized.

Copy link
Contributor Author

commented Mar 18, 2019

a-style issues are now fixed.

@0xc0170 0xc0170 added needs: review and removed needs: work labels Mar 18, 2019

@cmonr

cmonr approved these changes Mar 19, 2019

@@ -1225,30 +1222,41 @@ void ATHandler::flush()
}
}

void ATHandler::debug_print(const char *p, int len)
void ATHandler::debug_print(const char *p, int len, ATType type)

This comment has been minimized.

Copy link
@cmonr

cmonr Mar 19, 2019

Contributor

I really don't like that we have this precedent of internal/external APIs, and which are alright to change in a patch, but so it goes.

This comment has been minimized.

Copy link
@cmonr

cmonr Mar 19, 2019

Contributor

Especially since this a debug function.

if (isprint(c)) {
*pbuf++ = c;
} else if (c == '\r') {
sprintf(pbuf, "<cr>");

This comment has been minimized.

Copy link
@cmonr

cmonr Mar 19, 2019

Contributor

Thanks for the commit message. Made it really easy to tell why \r and \n were changed.

@cmonr

This comment has been minimized.

Copy link
Contributor

commented Mar 27, 2019

Anyone else want to review the PR?

@mbed-os-wan @AriParkkila @mirelachirica @jarvte

@jarvte

jarvte approved these changes Mar 28, 2019

@AriParkkila

This comment has been minimized.

Copy link
Contributor

commented Mar 28, 2019

This fixes the problems mentioned in the description but it seems to be quite verbose, which is likely to cause timing issues. For example, instead of AT+CEREG? it prints:

[INFO][CELL]: AT TX ( 8): AT+CEREG
[INFO][CELL]: AT TX ( 1): ?
[INFO][CELL]: AT TX ( 1): <cr>

AT debug prints are very useful when running Mbed OS Greentea TESTS. It seems that debug macro (used by the current AT debug) prints now fine but with this new debugging TESTS should be updated to use mbed-trace.

#endif
char c;
const int buf_size = len * 4; // x4 -> reserve space for extra characters
char *buffer = (char *)malloc(buf_size);

This comment has been minimized.

Copy link
@AriParkkila

AriParkkila Mar 28, 2019

Contributor

Check for NULL or use nothrow.

This comment has been minimized.

Copy link
@kivaisan

kivaisan Mar 28, 2019

Author Contributor

Fixed

mbed_cellular_trace::mutex_wait();
#endif
char c;
const int buf_size = len * 4; // x4 -> reserve space for extra characters

This comment has been minimized.

Copy link
@AriParkkila

AriParkkila Mar 28, 2019

Contributor

len * 4 + 1 where +1 for sprintf zero termination.

This comment has been minimized.

Copy link
@kivaisan

kivaisan Mar 28, 2019

Author Contributor

Fixed

@kivaisan kivaisan force-pushed the kivaisan:improve_at_trace branch from 59a772a to e442d52 Mar 28, 2019

@kivaisan

This comment has been minimized.

Copy link
Contributor Author

commented Mar 28, 2019

@AriParkkila timing issue is true but that is really problematic in our current mbed-os tracing system which uses UART on traces. On the other hand those time traces are really useful in some debugging cases so that's why I'd like to use it. And we get extra overhead especially for RX traces as modems tend to send responses in multiple pieces and there is nothing we can do for it. TX we could maybe improve in future to construct full command before sending. Also debug() prints tend to have a problem that other trace overwrites the written data.

@trowbridgec

This comment has been minimized.

Copy link

commented Mar 28, 2019

For what it's worth, I pulled in these changes and was able to diagnose cell module communication issues much easier. This PR is a great idea.

@cmonr cmonr added needs: CI and removed needs: review labels Mar 28, 2019

@cmonr

This comment has been minimized.

Copy link
Contributor

commented Mar 28, 2019

CI started

@mbed-ci

This comment has been minimized.

Copy link

commented Mar 29, 2019

Test run: FAILED

Summary: 1 of 13 test jobs failed
Build number : 1
Build artifacts

Failed test jobs:

  • jenkins-ci/mbed-os-ci_greentea-test
@alekla01

This comment has been minimized.

Copy link
Contributor

commented Mar 29, 2019

Restarted jenkins-ci/greentea-test

@adbridge

This comment has been minimized.

Copy link
Contributor

commented Mar 29, 2019

@AriParkkila are you happy with the changes on this PR after review ?

@adbridge adbridge added needs: review and removed needs: CI labels Mar 29, 2019

@AriParkkila

This comment has been minimized.

Copy link
Contributor

commented Mar 29, 2019

@kivaisan do you have any idea how to avoid timing issues. I tried this with some real world applications and they tend to fail when this new logging is enabled - That's likely because debug prints take so much time that data from a modem is lost.

@SeppoTakalo do you think we could enable mbed-trace for Mbed OS networking TESTS?

@kivaisan

This comment has been minimized.

Copy link
Contributor Author

commented Apr 1, 2019

One workaround is to increase baud rate on boards which support bigger baud rates for UART. This (PDMC) seems to work on WISE-1570 with 230400 baud rate, but as long as we use UART, these all are workarounds and we cannot guarantee any trace print is not causing timing issues.

@SeppoTakalo

This comment has been minimized.

Copy link
Contributor

commented Apr 1, 2019

Enabling mbed-trace would require code changes and test cases are not using mbed-trace.
I would therefore wait until they provide a module that initialises the trace library automatically, if enabled.

}

delete buffer;

This comment has been minimized.

Copy link
@SeppoTakalo

SeppoTakalo Apr 1, 2019

Contributor

You get the buffer from malloc() and free it by calling delete. This is a bit inconstant.

Use malloc()/free() pair or new/delete pair.

This comment has been minimized.

Copy link
@kivaisan

kivaisan Apr 1, 2019

Author Contributor

Good catch. Fixed.

Cellular: Improve ATHandler AT traces
Original AT traces had several issue:
- Can be overwritten by other traces (printf/mbed-trace)
- No way to know which direction message was going (TX or RX)
- <cr> and <ln> characters were not visible in trace
etc.

This commit addresses those issues using mbed-trace and showing separately
each filehandle write and read.

@kivaisan kivaisan force-pushed the kivaisan:improve_at_trace branch from e442d52 to aff3815 Apr 1, 2019

@cmonr cmonr requested a review from SeppoTakalo Apr 1, 2019

@0xc0170 0xc0170 added needs: CI and removed needs: review labels Apr 2, 2019

@0xc0170

This comment has been minimized.

Copy link
Member

commented Apr 2, 2019

CI started

@AriParkkila Please leave the review feedback

@mbed-ci

This comment has been minimized.

Copy link

commented Apr 2, 2019

Test run: FAILED

Summary: 1 of 13 test jobs failed
Build number : 2
Build artifacts

Failed test jobs:

  • jenkins-ci/mbed-os-ci_exporter

@0xc0170 0xc0170 added ready for merge and removed needs: CI labels Apr 3, 2019

@0xc0170

This comment has been minimized.

Copy link
Member

commented Apr 3, 2019

CI was restarted, all green

@0xc0170 0xc0170 merged commit 8cbcc55 into ARMmbed:master Apr 3, 2019

28 checks passed

continuous-integration/jenkins/pr-head This commit looks good
Details
continuous-integration/travis-ci/pr The Travis CI build passed
Details
jenkins-ci/build-ARMC5 Success
Details
jenkins-ci/build-ARMC6 Success
Details
jenkins-ci/build-GCC_ARM Success
Details
jenkins-ci/build-IAR8 Success
Details
jenkins-ci/cloud-client-test Success
Details
jenkins-ci/dynamic-memory-usage RTOS ROM(+0 bytes) RAM(+0 bytes)
Details
jenkins-ci/exporter Success
Details
jenkins-ci/greentea-test Success
Details
jenkins-ci/mbed2-build-ARMC5 Success
Details
jenkins-ci/mbed2-build-ARMC6 Success
Details
jenkins-ci/mbed2-build-GCC_ARM Success
Details
jenkins-ci/mbed2-build-IAR8 Success
Details
jenkins-ci/unittests Success
Details
travis-ci/astyle Local astyle testing has passed
Details
travis-ci/docs Local docs testing has passed
Details
travis-ci/doxy-spellcheck Local doxy-spellcheck testing has passed
Details
travis-ci/events Passed, runtime is 9222 cycles (+50 cycles)
Details
travis-ci/gitattributestest Local gitattributestest testing has passed
Details
travis-ci/include_check Local include_check testing has passed
Details
travis-ci/licence_check Local licence_check testing has passed
Details
travis-ci/littlefs Passed, code size is 8408B
Details
travis-ci/psa-autogen Local psa-autogen testing has passed
Details
travis-ci/tools-py2.7 Local tools-py2.7 testing has passed
Details
travis-ci/tools-py3.5 Local tools-py3.5 testing has passed
Details
travis-ci/tools-py3.6 Local tools-py3.6 testing has passed
Details
travis-ci/tools-py3.7 Local tools-py3.7 testing has passed
Details

@0xc0170 0xc0170 removed the ready for merge label Apr 3, 2019

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.