consider adding support for more compact ogsmd logging

[lindi]

This is a wishlist bug.

Currently ogsmd DEBUG logs like

Apr  9 00:34:09 ginger ogsmd    DEBUG    (<MiscChannel via /dev/pts/0>: last communication with modem was 50 seconds ago. Sending EOF to wakeup)
Apr  9 00:34:09 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: sending 9 bytes: 'AT+COPS?\r'
Apr  9 00:34:10 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: _readyToRead: watch timeout = 2995
Apr  9 00:34:10 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: got 28 bytes: '\r\n+COPS: 0,2,"24405"\r\n\r\nOK\r\n'
Apr  9 00:34:10 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: COMPLETED 'AT+COPS?' => ['+COPS: 0,2,"24405"', 'OK']
Apr  9 00:34:10 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: _readyToSend: watch timeout = None
Apr  9 00:35:00 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: _readyToSend: watch timeout = None

are very verbose. A simple DebugCommand? invocation will write almost 700 bytes to syslog. A more compact log format would save space, make it easier to spot where the real bugs are and would make it possible to read the logs on the device itself without having every log line wrap.

I am not entirely sure how this issue should be solved but to get comments I thought I should it as a bug here. At very least long names like MiscChannel? could be shortened and things like "sending 9 bytes 'foo'" could be shortened down to "sending 'foo'" since we can all count how many characters there are.

[daniel]

"foo" isn't 9 bytes long, though. ;-)

The problem is that debugging already slows down frameworkd considerably. I think patches to reduce output without adding complexity would be appreciated. There were also thoughts about adding a feature to "compile out" all the debugging instructions. As even if they are not logged the function is executed nontheless, but I don't know what happened to that idea.

[lindi]

I shortened

Apr  5 11:26:07 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: _readyToSend: watch timeout = None
Apr  5 11:26:07 ginger ogsmd    DEBUG    (<MiscChannel via /dev/pts/0>: last communication with modem was 50 seconds ago. Sending EOF to wakeup)
Apr  5 11:26:07 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: sending 9 bytes: 'AT+COPS?\r'
Apr  5 11:26:07 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: _readyToRead: watch timeout = 310
Apr  5 11:26:07 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: got 28 bytes: '\r\n+COPS: 0,2,"24405"\r\n\r\nOK\r\n'
Apr  5 11:26:07 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: COMPLETED 'AT+COPS?' => ['+COPS: 0,2,"24405"', 'OK']
Apr  5 11:26:07 ginger ogsmd.channel DEBUG    <MiscChannel via /dev/pts/0>: _readyToSend: watch timeout = None

to

Apr 17 23:14:50 ginger Misc0 eof 50
Apr 17 23:14:50 ginger Misc0<AT+COPS?\r
Apr 17 23:14:50 ginger Misc0>\r\n+COPS: 0,2,"24405"\r\n\r\nOK\r\n
Apr 17 23:14:50 ginger Misc0:AT+COPS?=>['+COPS: 0,2,"24405"', 'OK']

Yes. it is bit cryptic. However, it also makes it possible to read the log in realtime on the phone itself since you only see the relevant stuff.

[mickey]

This will not be implemented in ogsmd. fsogsmd contains a different logging, how do you rate that?