Apache OpenOffice (AOO) Bugzilla – Issue 6239
OpenOffice hangs CDE dtsession process on CDE logout
Last modified: 2003-11-23 11:39:00 UTC
If you logout while OpenOffice is still running, the CDE "dtsession" process will consume all available CPU for a long period of time. I've seen it take from one to eight minutes. Eventually whatever it is doing completes or times out without intervention. Logout when OpenOffice is not running takes only a few seconds. Running Solaris 8 10/01 and CDE 1.4. Patch 109354-11 for dtsession is installed. The most current revision is -14, but the README file does not show any fixes in -12, -13 or -14 that sound related to this problem. A workaround is to kill OpenOffice from a CDE sessionexit script. My solution is to put the following command into /etc/dt/config/sessionexit: /usr/bin/pkill soffice.bin
I will have a look !
I´ve checked this problem, using an internal OO 1.0.1 running on Solaris 8 with CDE 1.4 and found it non reproducible. Loging out without OO running takes 2-3 seconds. Loging out with a running OO takes 15-20 seconds. Please verify this problem when OpenOffice 1.0.1 is available.
You changed this issue to "RESOLVED" with resolution "WORKSFORME", but according to your own test, OO added 15 seconds to the logout process. No application should add more than a second or two to the logout process. The only thing the application needs to do is respond to the WM_SAVE_YOURSELF message from CDE's session manager. As I stated in the description, I found the length of wait time quite variable even on a single machine. You are testing on a different machine that might well have a faster CPU than mine, plus different Solaris and OO patches that might greatly affect the overall performance. If you still don't agree this is a DEFECT, then change the issue type to ENHANCEMENT. This is something that needs to be fixed, either by Sun or by OOo, wherever the problem might be.
TM->FT: As talked to the development section, the here mentioned time for shutdown is needed to close all internal running tasks properly. So, this one is a wish for an enhancement but not a bug.
I've seen that as well. It hangs there during CDE logoff for ~60 seconds. top shows that dtsession is comsuming all the time: last pid: 23194; load averages: 0.46, 0.27, 0.14 16:45:24 65 processes: 60 sleeping, 1 running, 1 zombie, 2 stopped, 1 on cpu CPU states: 49.5% idle, 27.6% user, 22.8% kernel, 0.1% iowait, 0.0% swap Memory: 1536M real, 826M free, 545M swap in use, 4758M swap free PID USERNAME THR PRI NICE SIZE RES STATE TIME CPU COMMAND 23084 jk 5 0 0 7072K 5000K run 0:18 29.47% dtsession 22990 root 1 59 0 79M 19M sleep 0:01 0.35% Xsun 23096 jk 7 49 0 77M 35M sleep 0:03 0.29% soffice.bin 23091 jk 8 59 0 8220K 6680K sleep 0:00 0.02% dtwm In $HOME/.dt/errorlog the following message from dtsession appears: Mit Aug 28 16:45:16 2002 dtsession: Session restoration information not updated for client unbenannt1 - O penOffice.org 1.0.1 . Invalid information may be saved. A truss on dtsession shows that dtsession is waiting for an "I/O ready" condition on several file descriptors . . . gettimeofday(0x08046B00) = 0 poll(0x080467D4, 3, 0) = 0 ioctl(4, FIONREAD, 0x08046AB4) = 0 ioctl(5, FIONREAD, 0x08046AB4) = 0 ioctl(4, FIONREAD, 0x08046AB4) = 0 ioctl(5, FIONREAD, 0x08046AB4) = 0 gettimeofday(0x08046B00) = 0 poll(0x080467D4, 3, 0) = 0 ioctl(4, FIONREAD, 0x08046AB4) = 0 ioctl(5, FIONREAD, 0x08046AB4) = 0 ioctl(4, FIONREAD, 0x08046AB4) = 0 ioctl(5, FIONREAD, 0x08046AB4) = 0 gettimeofday(0x08046B00) = 0 poll(0x080467D4, 3, 0) = 0 ioctl(4, FIONREAD, 0x08046AB4) = 0 ioctl(5, FIONREAD, 0x08046AB4) = 0 ioctl(4, FIONREAD, 0x08046AB4) = 0 ioctl(5, FIONREAD, 0x08046AB4) = 0 gettimeofday(0x08046B00) = 0 . . the same three system calls repeated over and over . A stack backtrace on dtsession - while it's looping - is a bit more interesting. I'd guess that dtsession tries to get the command that can be used to restart OOo, but it appears dtsession does not get the expected reply from OOo. 3# pstack -F `pgrep dtsession` 23656: /usr/dt/bin/dtsession ----------------- lwp# 1 / thread# 1 -------------------- df649689 poll (80467d4, 3, 0) df65d217 select (d, 8046908, 8046988, 8046a08, 8046ab4) + 247 df7087d4 select () + 64 df860f70 _XtWaitForSomething (8089db0, 0, 1, 0, 1, 0, 0, 0) + 14c df8625b2 XtAppPending (8089db0) + 15e 08065081 WaitForCommand () + 49 080651fe SaveYourself (0, 5800021) + fa 0805b83a OutputState () + de 0805b5ab SaveState (0, 4) + cf 08063d16 ImmediateExit (4, deab62a0) + aa 08063c3c ExitConfirmed (80dbe38, deba54e8, 8046ca0) + 24 df84d996 XtCallCallbackList (80dbe38, deb2c0f0, 8046ca0) + 82 df96bde6 MessageCallback (8107b68, 80dbe38, 8046cf4) + 8a df84d996 XtCallCallbackList (8107b68, deb2c2b0, 8046cf4) + 82 df971c47 Activate () + e7 df97308b ActivateCommonG () + 43 df971a81 InputDispatch (8107b68, 8046d60, 40) + 95 df913df0 _XmDispatchGadgetInput (8107b68, 80470d4, 40) + 254 df914426 _XmGadgetActivate (80dbe38, 80470d4, 0, deb2aec8) + 2a df8763bd HandleActions () + 125 df876c93 HandleComplexState () + 16f df876d28 _XtTranslateEvent (80dbe38, 80470d4) + 80 df857639 XtDispatchEventToWidget (80dbe38, 80470d4) + 239 df857e42 _XtDefaultDispatcher (80470d4) + 26e df85804b XtDispatchEvent (80470d4) + 167 08058c5f main (1, 8047160, 8047168) + 4eb 08058674 ???????? () ----------------- lwp# 2 / thread# 2 -------------------- df64b5a8 signotifywait () df6fdd6b _dynamiclwps () + 2b ----------------- lwp# 3 -------------------------------- df648ed8 door (0, 0, 0, 0, df454b68, 4) df7045de _sc_door_func () + 5a df6fa180 _lwp_start () + 28 ----------------- lwp# 4 -------------------------------- df64b453 lwp_cond_wait (df720e6c, df720e7c, df71a66c) df6f9076 _age () + 8a df6fa180 _lwp_start () + 28 -------------------------- thread# 3 -------------------- df6f9657 _swtch (0) + 3b3 df6fd051 _reap_wait (df71e318) + 49 df6fce24 _reaper (0, df6fcde0) + 44 df6f79c8 _thread_start () + 34 Finally after 60 seconds, the CDE session terminates (a timeout in dtsession when the application is unresponsive and does not answer with the startup command?). At this time, the OOo binary crashes with a core dump. I had the following truss on soffice.bin running, while the CDE session was closed: # truss -SSEGV -t\!all -p `pgrep soffice.bin` Received signal #14, SIGALRM, in lwp_sema_wait() [caught] Received signal #14, SIGALRM, in lwp_sema_wait() [caught] Received signal #14, SIGALRM, in lwp_sema_wait() [caught] Received signal #14, SIGALRM, in lwp_sema_wait() [caught] Received signal #14, SIGALRM, in lwp_sema_wait() [caught] Received signal #14, SIGALRM, in lwp_sema_wait() [caught] Incurred fault #6, FLTBOUNDS %pc = 0xDF608E82 siginfo: SIGSEGV SEGV_MAPERR addr=0x00000000 Received signal #11, SIGSEGV [caught] siginfo: SIGSEGV SEGV_MAPERR addr=0x00000000 # pstack `pgrep soffice.bin` | /opt/ws70/SUNWspro/bin/c++filt 23669: /home/OpenOffice.org1.0.1/program/soffice.bin ----------------- lwp# 1 / thread# 8 -------------------- df608e82 sal_XIOErrorHdl (81572f8) + 2d df0d0424 _XIOError (81572f8) + 30 df0cdeec _XRead (81572f8, 809d8a8, 20) + d8 df0cd9d6 _XEventsQueued (81572f8, 2) + 2e6 df0c2e9c XPending (81572f8) + 34 dab3b7a3 void x11::SelectionManager::dispatchEvent(int) (daf06fd8, c8) + 113 dab3ba56 void x11::SelectionManager::run(void*) (daf06fd8) + 86 df9b5e18 oslWorkerWrapperFunction (8158610, df9b5d69) + af dfb679c8 _thread_start () + 34 ----------------- lwp# 2 / thread# 2 -------------------- def2b5a8 _signotifywait () + c ----------------- lwp# 3 / thread# 6 -------------------- def2bb68 accept (c, 0, 0, 1) df188f98 accept (c, 0, 0) + 20 df9c0fa4 osl_acceptPipe (80afce8) + 24 df980fa0 vos::OPipe::TPipeError vos::OPipe::accept(vos::OStreamPipe&) (de3d8b0c, de3d8b20) + 20 0806aaad void desktop::OfficeIPCThread::run() (de3d8af8) + 4d df97b37b void vos::_cpp_OThread_WorkerFunction(void*) (de3d8af8) + 1b df97b358 void _OThread_WorkerFunction(void*) (de3d8af8) + 18 df9b5e18 oslWorkerWrapperFunction (80b05b8, df9b5d69) + af dfb679c8 _thread_start () + 34 ----------------- lwp# 4 / thread# 1 -------------------- dcecdaf0 __SLIP.FINAL__D () def78852 exit (809b770) + 1a df0d0424 _XIOError (809b770) + 30 df0cd67c _XFlushInt (809b770, 0) + 1bc df0ceba9 _XReply (809b770, 804692c, 0, 0) + 7d df0c6805 XQueryTree (809b770, 5800016, 80469a4, 80469a8, 80469ac, 80469b0) + 71 df5ec44a long SalFrameData::HandleReparentEvent(XReparentEvent*) (daf0f898, 8046b14) + 8d df5ecce0 long SalFrameData::Dispatch(_XEvent*) (daf0f898, 8046b14) + 1b0 df60ea4e long SalDisplay::Dispatch(_XEvent*) (de3d4b88, 8046b14) + 1cc df60e85d void SalDisplay::Yield(unsigned char) (de3d4b88, 1) + b5 df60aa4a int DisplayYield(int,SalDisplay*) (7, de3d4b88) + 4a df6099eb void SalXLib::Yield(unsigned char) (de3d47b8, 1) + 9b df610fcb void SalInstance::Yield(unsigned char) (de3d4fb8, 1) + 2b df4cd1f1 void Application::Yield() () + 4a df4cd13e void Application::Execute() () + 2e 08062705 void Desktop::Main() (80943d4) + 9c5 df4cf6ff unsigned char SVMain() () + 4f 080786e5 main (1, 8046e7c, 8046e84) + 15 0805d98a ???????? () ----------------- lwp# 5 / thread# 5 -------------------- def2b46c lwp_sema_wait (dfb8b344) dfb68d84 _co_timerset (0, dfb68c2c) + 158 dfb679c8 _thread_start () + 34 ----------------- lwp# 6 / thread# 4 -------------------- def2b46c lwp_sema_wait (dea05e3c) dfb69759 _park () + c1 dfb6957f _swtch (0) + 2db dfb6808a cond_reltimedwait (80de778, 80de788, dea05ca8) + 1d2 dfb67eaf cond_timedwait (80de778, 80de788, dea05cf0) + 33 dfb67e22 pthread_cond_timedwait (80de778, 80de788, dea05cf0) + 1e df9b2aa4 osl_waitCondition (80de778, dea05d10) + b2 de11b1fc void store::OStorePageDaemon_Impl::run() (de3da340) + 50 de11b55b threadFunc (de3da340) + 1b df9b5e18 oslWorkerWrapperFunction (80b0520, df9b5d69) + af dfb679c8 _thread_start () + 34 ----------------- lwp# 7 -------------------------------- def28ed8 door (0, 0, 0, 0, dabd4b68, 4) dfb745de _sc_door_func () + 5a dfb6a180 _lwp_start () + 28 -------------------------- thread# 3 -------------------- dfb69657 _swtch (0) + 3b3 dfb6d051 _reap_wait (dfb8e318) + 49 dfb6ce24 _reaper (0, dfb6cde0) + 44 dfb679c8 _thread_start () + 34 -------------------------- thread# 7 -------------------- dfb69657 _swtch (0) + 3b3 dfb6808a cond_reltimedwait (8156378, 8156388, de702c70) + 1d2 dfb67eaf cond_timedwait (8156378, 8156388, de702cb8) + 33 dfb67e22 pthread_cond_timedwait (8156378, 8156388, de702cb8) + 1e df9b2aa4 osl_waitCondition (8156378, de702cf8) + b2 df974b0e vos::ICondition::TResult vos::OCondition::wait(const TimeValue*) (dafac0cc, de702cf8) + 1e df97ec28 void vos::OTimerManager::run() (dafac0a8) + 9a df97b37b void vos::_cpp_OThread_WorkerFunction(void*) (dafac0a8) + 1b df97b358 void _OThread_WorkerFunction(void*) (dafac0a8) + 18 df9b5e18 oslWorkerWrapperFunction (81563b0, df9b5d69) + af dfb679c8 _thread_start () + 34
Here's an alternate way to reproduce the issue (instead of logging out from the CDE session): 1. start OOo 1.0.1 2. run 'dtstyle', click on 'Startup' and "Set Home Session..." button in the 'Startup' window. There'll be a 60 seconds delay with a busy cursor, while the home session is saved. dtsession consumes 100% of the cpu time during this 60 second period. ------- Apparently the issue is caused by the "DefaultWindow", which is created when a window is need, but the application's main window is not ready yet. (See method |Window* ImplGetDefaultWindow()| in vcl/source/app/svdata.cxx) This "DefaultWindow" is never mapped on the screen, but it is registered to implement the WM_SAVE_YOURSELF window protocol. It seems, CDE tries to get the WM_COMMAND for all windows that register the WM_SAVE_YOURSELF protocol, even when they are unmapped. Problem is the WM_SAVE_YOURSELF apparently fails for unmapped windows, because the session manager program does not get the necessary property change event for the WM_COMMAND property of the unmapped window. ------- After starting OOo 1.0.1, an empty text editor window is opened and the following windows are registered on the X11 server: % xlswins -l | grep Sal 3: 0x6800017 (unbenannt1 - OpenOffice.org 1.0.1 ); (VCLSalFrame)(VCLSalFrame) 906x1055+0+0 +673+45 1: 0x6800016 (); (VCLSalFrame)(VCLSalFrame) 1600x1280+0+0 +0+0 1: 0x680001f (); (VCLSalFrame)(VCLSalFrame) 662x225+469+527 +469+527 1: 0x6800020 (); (VCLSalFrame)(VCLSalFrame) 134x38+733+621 +733+621 1: 0x6800021 (); (VCLSalFrame)(VCLSalFrame) 120x38+740+621 +740+621 1: 0x6800022 (); (VCLSalFrame)(VCLSalFrame) 48x157+776+561 +776+561 1: 0x6800069 (); (VCLSalFrame)(VCLSalFrame) 12x27+794+626 +794+626 The "DefaultWindow" is the one with the XWIN ID 0x6800016 in the above window list, and can be identified by it's size and position (full screen size "1600x1280", top left corner +0+0). This window has registered for the WM_PROTOCOLS "WM_SAVE_YOURSELF": % xprop -id 0x6800016 _MOTIF_WM_HINTS(_MOTIF_WM_HINTS) = 0x7, 0x1, 0x1, 0x0, 0x0 WM_CLIENT_LEADER(WINDOW): window id # 0x6800002 WM_CLASS(STRING) = "VCLSalFrame", "VCLSalFrame" WM_PROTOCOLS(ATOM): protocols WM_DELETE_WINDOW, WM_SAVE_YOURSELF <<<<<<<<<<< WM_HINTS(WM_HINTS): Client accepts input or input focus: True bitmap id # to use for icon: 0x680000c window id # of group leader: 0x0 And it is unmapped: % xwininfo -id 0x6800016 xwininfo: Window id: 0x6800016 (has no name) Absolute upper-left X: 0 Absolute upper-left Y: 0 Relative upper-left X: 0 Relative upper-left Y: 0 Width: 1600 Height: 1280 Depth: 24 Visual Class: TrueColor Border width: 0 Class: InputOutput Colormap: 0x6800001 (installed) Bit Gravity State: ForgetGravity Window Gravity State: NorthWestGravity Backing Store State: NotUseful Save Under State: no Map State: IsUnMapped <<<<<<<<<<<<<<<<<<<<<<<<<<<<< Override Redirect State: yes Corners: +0+0 -0+0 -0-0 +0-0 -geometry 1600x1280+0+0
Correction to previous comment: The WM_SAVE_YOURSELF atom set on the WM_PROTOCOLS property on an unmapped window is not necessarily a problem. The real problem is that OOo adds the WM_SAVE_YOURSELF atom to the WM_PROTOCOLS property of all of it's |SalFrame| top level windows, but later on, when it receives a WM_SAVE_YOURSELF client message it only answers it for exactly one |SalFrame| and ignores it for all other SalFrames. Apparently, dtsession tries to get the restart command for all top level frames that participate in the WM_SAVE_YOURSELF protocol, and this fails for all but one of OOo's frames. Each frame that fails to return the WM_COMMAND during a WM_SAVE_YOURSELF client message adds another ten second delay (=timeout in dtsession). Since there are seven top level windows when OOo is started and an empty text editor window is displayed, I get 6*10seconds of delay and one frame without a delay ==> dtsession uses 60 seconds for the session save operation. ------ According to the dtsession(1X) man page on solaris ... » The ICCCM Session Management Protocol .... Applications that wish to save their state can take part in the WM_SAVE_YOURSELF protocol. To do this, an application needs to set the WM_SAVE_YOURSELF property on one and only one of its top-level windows. « ------ So, I'd say it's a bug that OOo sets the WM_SAVE_YOURSELF atom on all of it's top level windows. I'll attach a patch to vcl/unx/source/window/salframe.cxx that sets WM_SAVE_YOURSELF to only one of OOo's top level windows. When this top level window is deleted, I move the WM_SAVE_YOURSELF atom to another top level window (in case there are still any top level windows left). With this patch installed, the 60 seconds dtsession delay at CDE logout or when saving the "Home session" from dtstyle is gone; saving the CDE session when OOo is running consumes no significant time any more (< 1 second). ------ On question remains: do we need the WM_SAVE_YOURSELF stuff at all? dtsession is able to extract the startup command from the WM_CLIENT_LEADER window anyway. For that reason, when the X11 session is saved with dtsession I get *two* soffice commands in ~/.dt/sessions/{session-name}/dt.session: % grep soffice ~/.dt/sessions/home/dt.session dtsmcmd -hints "-geometry 16x16+0+0 -state NormalState -cmd \"/bin/sh /home/OpenOffice.org1.0.1/program/soffice \"" -screen 0 -cmd "/bin/sh /home/OpenOffice.org1.0.1/program/soffice" dtsmcmd -hints "-geometry 995x1021+599+33 -state IconicState -workspaces \"ws0 \" -cmd \"/bin/sh /home/OpenOffice.org1.0.1/program/soffice \"" -screen 0 -cmd "/bin/sh /home/OpenOffice.org1.0.1/program/soffice" The first "soffice" command is apparently extracted from the WM_COMMAND of the WM_CLIENT_LEADER window, and the second is obtained via the WM_SAVE_YOURSELF protocol.
Created attachment 2637 [details] patch to set WM_SAVE_YOURSELF on only one SalFrame top level window
mh->cp: can you please review ?!
??? What am I gonna do with it? :o)
cp->pl: please have a look at it.
Some remarks: OOo sets WM_SAVE_YOURESELF on all its top level windows because there is not necessarily a top level window that lives through its whole lifetime. But since dtsession insists on restarting one instance of OOo for each top level window it sees at the time of an actual WM_SAVE_YOURSELF happening OOo deletes the WM_COMMAND properties on all of its top level windows but one. Contrary to the quotation above the actual ICCCM standard (version 2.0) states explicitly: "Clients that want to be warned when the session manager feels that they should save their internal state (for example, when termination impends) should include the atom WM_SAVE_YOURSELF in the WM_PROTOCOLS property on their top-level windows to participate in the WM_SAVE_YOURSELF protocol". And further down: "Irrespective of how they are arranged in window groups, clients with multiple top-level windows should ensure the following: - Only one of their top-level windows has a nonzero-length WM_COMMAND property. - They respond to a WM_SAVEYOURSELF message by: First, updating the nonzero-length WM_COMMAND property, if necessary. Second, updating the WM_COMMAND property on the window for which they received the WM_SAVE_YOURSELF message if it was not updated in the first step" So IMHO if dtsession is implemented they way stated earlier it actually violates the standard. Still, since WM_SAVE_YOURSELF protocol is outdated anyway (one should use SM extension nowadays), we should build in a workaround for dtsession anyway; i hope this will not break WindowMaker or other WMs that rely on the old session management style. I'll try whether it is sufficient if the default window supports WM_SAVE_YOURSELF although it is never mapped. If that is not possible I'll apply your patch; thank you for supplying it.
fixed in CWS basetech01
reopen
reassign
fixed in basetech01
verified in basetech01.
As mentioned on the qa dev list on March 5th I will close all resolved <wontfix/duplicate/worksforme/invalid> issues. Please see this posting for details.