Summary:	ASTERISK-20770: Remote console verbosity implementation causes problems
Reporter:	Pavel Troller (patrol-cz)	Labels:
Date Opened:	2012-12-05 23:34:24.000-0600	Date Closed:	2013-09-18 09:05:55
Priority:	Minor	Regression?	No
Status:	Closed/Complete	Components:	Core/General
Versions:	11.1.0	Frequency of Occurrence	Constant
Related Issues:
Environment:	Any	Attachments:
Description:	The implementation of individual remote console verbosity causes many problems, especially on systems with high traffic load and with complex dialplans. Even with remote verbosity set to zero, the following problems are occuring: 1) The prompt is being cleared and drawn again and again. This causes the prompt to flicker and it is a primary cause for all the subsequent problems. 2) If the prompt contains dynamic components (time etc.), they are changing with every redraw. When the redraws are not in regular intervals (typical for phone traffic), it looks strange. 3) If a longer printout is received and the operator wants to view it using Shift-PageUp feature of Linux console, every prompt redraw resets it back, making such viewing impossible. 4) If a command completion feature is being used by pressing the Tab key, it inteferes with messages going downstream and fragments of them are dropped to the console, causing strange output, and at least in one case crash of the remote console has been observed in such a case. 5) If the remote console is accessed using a network connection (ssh, telnet...), permanent redraws of the prompt may cause increased network traffic, especially when many remote clients are active. Any of the problems above taken individually is not too much serious, but all of them together cause substantial discomfort in comparison with previous console behaviour. My opinion is, that the programmer's approach to the individual verbosity implementation must be different - the filtering of messages has to be implemented on the server, not the client. It will solve all the problems, including the one with impossibility to alias the "core set verbose" command, which is already open as a separate issue. To illustrate the problem, here is a video from a live system. Sorry for the length, it's 597 MB, I'm not good at compressing videos while keeping frame rate and readability :-). http://sinus.cz/~patrol/unsorted/asterisk_remote_console_v11.mp4 At the beginning, core show calls is issued several times, to see the traffic. Then, core show channels. You can see, how the console is slow. Then, a problem with Tab is demonstrated, you can see unwanted output being printed, including damage od the edited command line (a digit appears in the middle of the line). At the end, an attempt is made to terminate the session, which finally succeeds. The sound is IN SYNC with the video! You can hear me typing, but what I'm typing appears later. It's really THAT BAD.
Comments:	By: Rusty Newton (rnewton) 2012-12-07 09:45:55.959-0600 This looks like an improvement/feature request. Can you provide a patch? If not, you may want to discuss this on the asterisk-dev list to get a consensus on your suggested approach and see if someone wants to take on the work. By: Pavel Troller (patrol-cz) 2012-12-07 10:27:20.253-0600 Hi! Did you look at the video ? Please do it. You can see that the system, formerly running on 1.6 without any problems, is now almost uncontrollable in high traffic hours. As a user, I see it not only as a bug, but also as a regression. And fragments of verbose messages appearing when you press Tab and corrupting your command input - sorry, it's a bug, nothing else. Regarding the patch - now I'm studying the remote console interface. I have a testbed available, on which I can try to do something. By: Pavel Troller (patrol-cz) 2012-12-07 12:53:33.090-0600 OK. By analyzing the code I've found that the log level filtering is done on the master process, not the remote console, so by using "logger set level VERBOSE off" I'm able to substantially reduce all the problems. It's definitely good news, so I can decrease the bug severity. However, it seems that I've found a new bug: the log level array "levels", which is a member of the struct console, doesn't seem to be initialized. So, when the console is started, the log levels are set to an unpredictable state, depending on the last state of a console previously connected to this particular "slot". I'm suggesting to initialize the array, but I'm not sure, to which values. By: Tilghman Lesher (tilghman) 2012-12-17 22:09:08.188-0600 I'm thinking that if you had set 'core set verbose 5' in 1.6.2, you would have experienced exactly the same issues as you're experiencing now with Asterisk 11.  So the change didn't necessarily cause the problem; but it's more evident, now that the remote console receives everything.  When your verbose output is near continuous, there's no lull in the output available for tab-generated feedback, which is why you're getting verbose messages mixed in with your tab completion. I think the ultimate solution is going to involve separating the remote Asterisk instance into two pipes, one for synchronous commands, the other for asynchronous output, and possibly changing the processing of verbose messages to the master process of the Asterisk console. By: Rusty Newton (rnewton) 2013-01-10 09:16:16.890-0600 Acknowledged as an issue and going into our queue as well. A patch up on reviewboard will be much appreciated. If you have design related questions and discussion, please use the dev list or #asterisk-dev. By: Pavel Troller (patrol-cz) 2013-01-12 23:19:40.860-0600 Thanks for your comments. I'll try to look at it during next days. By: Matt Jordan (mjordan) 2013-09-18 09:05:55.343-0500 Closing this out as a duplicate of ASTERISK-22450