[知其然不知其所以然-40] Why pm_parepare_console takes more than 200ms - swicth vt during suspend

According to ftrace graphic result, the following code path took
more than 300ms to finish, looks like the vt switching is waiting for framebuffer to finish its work:
pm_prepare_console->vt_move_to_console->vt_waitactive->
__vt_event_wait.isra.3.part.4->schedule(300ms later scheduled in again)
 
the reason why vt switch takes so much time is because of the Xorg daemon
that, the kernel has to wait for Xorg to release the vt and issues a ioctrl to
complete the switching. If X is disabled, this issue disappears.
Here's the log after configurating current_tracer with function, and
set_ftrace_filter with vt_waitactive, console_callback, complete_change_console:

         rtcwake-886   [001] ....  2519.641849: vt_waitactive <-vt_move_to_console     kworker/1:2-262   [001] ....  2519.641851: console_callback <-process_one_work            Xorg-818   [002] ....  2519.835715: complete_change_console <-vt_ioctl         rtcwake-886   [000] ....  2550.656509: vt_waitactive <-vt_move_to_console     kworker/0:0-22796 [000] ....  2550.656511: console_callback <-process_one_work     kworker/0:0-22796 [000] ....  2550.656515: complete_change_console <-change_console

According to above result, the Xorg issues a vt_ioctl to finish the console switch,
which takes 2519.835715 - 2519.641851 =  200ms. While during resumed, there is
no need to wait for Xorg thus the switch operatin is done in one worker thread, which
takes only 2550.656515 - 2550.656511

The problem is root caused to be the implementation of Xorg:
This issue can be simply reproduced by switching between Graphic mode
and text mode console: press alt + ctl + F1 to text mode.


Since the Xorg(Graphic) is working in VT_PROCESS mode(set by ioctl),
the kernel has to handshake with Xorg, it means, if kernel wants to switch
to suspend console, the kernel needs to wait for the Xorg to finish its work
and sets the finish flag by issuing ioctl(VT_RELDISP). The problem is,
although the Xorg has received the switch request from kernel on time,
it waits for 200ms in user space(maybe doing some cleanup) and issue the
VT_RELDISP to notify the finish to kernel.


Currently it seems there is no good solution for this, it might not
be applicable if the switching process is deferred, as the kernel must
 switch to the suspend console before freezing the processes, otherwise
 the Xorg will be freezed  and the switching to suspend console will
never be achieved(kernel never gets a ACK)

Ftrace result:
Graphic mode vt switch to suspend-console's vt

<...>-3802  [000] .... 12443.331885: change_console <-console_callback/* Since the current vt is working in  VT_PROCESS, the kernel send the switch request to Xorg. */<...>-3802  [000] .... 12443.331887: kill_pid <-change_console/* Signal sent. */<...>-3802  [000] d... 12443.331902: signal_generate: sig=10 errno=0 code=128 comm=Xorg pid=833 grp=1 res=0/* The Xorg has react to this request, and is about to invoke the signal handler*/Xorg-833   [003] d... 12443.332044: signal_deliver: sig=10 errno=0 code=128 sa_handler=5616ac7ef860 sa_flags=14000000/* However it takes 200ms for the Xorg to finish the signal handler, and finally it set the finish flag and info the kernel */Xorg-833   [003] .... 12443.722808: complete_change_console <-vt_ioctl

suspend-console's vt switch bakc to Graphic mode vt
since the suspend-console is not working in  VT_PROCESS mode,
the kernel switch back to Graphic mode immediately:

kworker/0:3-4540  [000] .... 12464.280929: change_console <-console_callbackkworker/0:3-4540  [000] .... 12464.280932: complete_change_console<-change_consolekworker/0:3-4540  [000] .N.. 12464.280961: kill_pid<-complete_change_consolekworker/0:3-4540  [000] dN.. 12464.280970: signal_generate: sig=10 errno=0 code=128 comm=Xorg pid=833 grp=1 res=0Xorg-833   [003] d... 12464.280980: signal_deliver: sig=10 errno=0 code=128 sa_handler=5616ac7ef860 sa_flags=14000000