Bug 625877

Summary: openoffice taking too much cpu & time to open docs
Product: [openSUSE] openSUSE 11.3 Reporter: Forgotten User 10buyl7JnO <forgotten_10buyl7JnO>
Component: OpenOffice.orgAssignee: E-mail List <bnc-team-ooo>
Status: VERIFIED DUPLICATE QA Contact: Chao Wei <cwei>
Severity: Normal    
Priority: P5 - None CC: kendy, nopower
Version: Final   
Target Milestone: ---   
Hardware: x86-64   
OS: openSUSE 11.3   
Whiteboard:
Found By: --- Services Priority:
Business Priority: Blocker: ---
Marketing QA Status: --- IT Deployment: ---
Attachments: strace of oofice

Description Forgotten User 10buyl7JnO 2010-07-27 10:46:59 UTC 
User-Agent:       Mozilla/5.0 (X11; U; Linux x86_64; en-US) AppleWebKit/533.4 (KHTML, like Gecko) Chrome/5.0.375.125 Safari/533.4

OpenOffice.org 3.2.1 
OOO320m19 (Build:9505)
ooo-build 3.2.1.4

If I open word document(.doc) or spreadsheet(.xls), first openoffice shows splash screen then window title appears and it takes around 10 seconds before actual document is shown. I checked CPU usage during this time and soffice.bin was taking more than 100% cpu during this time.

Reproducible: Always

Steps to Reproduce:
1. Open doc or xls file in openoffice
Actual Results:  
It takes longer than expected to open the document and intense cpu is used.

Expected Results:  
Document should open normally.
Comment 1 Jan Holesovsky 2010-07-27 18:07:03 UTC 
"Longer than expected" compared to what, please - to MS Office?  Can we have the offending documents?  Can you measure the time spent on opening those in MSO and in OOo, on the same hardware?  Thank you!
Comment 2 Forgotten User 10buyl7JnO 2010-07-28 06:58:10 UTC 
Longer than expected compared to openoffice 3.2.1 in opensuse 11.2 x86_64. There is not particular offending document. Today I figured out that first time if we open any document in open office when no other doc is open, it takes time. If we open second document, that's instant. If we close all documents and open any document again, now it takes longer. I'm not comparing with MSO but OOO in opensuse 11.2 on same hardware.
Comment 3 Forgotten User 10buyl7JnO 2010-07-28 09:43:09 UTC 
I noticed another thing. If document is opened from evolution mail attachment directly(which opens it as read only), it opens instantly. If I save the attachment and then open it, it takes time to open the document.
Comment 4 Jan Holesovsky 2010-07-28 18:41:55 UTC 
Can you please try to get us an strace of the long start, as described here:

http://en.opensuse.org/Bugs:OOo#How_to_get_strace_log

Thank you!
Comment 5 Forgotten User 10buyl7JnO 2010-07-30 07:13:10 UTC 
That link is broken after wiki upgrade. But I got following in strace. 

execve("/usr/bin/oocalc", ["oocalc", "Downloads/[MYFILE].xls"], [/* 84 vars */]) = 0
brk(0)                                  = 0x6a3000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6b9ac45000
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
open("/lib64/bash/4.1/tls/x86_64/libreadline.so.6", O_RDONLY) = -1 ENOENT (No such file or directory)
stat("/lib64/bash/4.1/tls/x86_64", 0x7fff5e154370) = -1 ENOENT (No such file or directory)
open("/lib64/bash/4.1/tls/libreadline.so.6", O_RDONLY) = -1 ENOENT (No such file or directory)
stat("/lib64/bash/4.1/tls", 0x7fff5e154370) = -1 ENOENT (No such file or directory)
open("/lib64/bash/4.1/x86_64/libreadline.so.6", O_RDONLY) = -1 ENOENT (No such file or directory)
stat("/lib64/bash/4.1/x86_64", 0x7fff5e154370) = -1 ENOENT (No such file or directory)
open("/lib64/bash/4.1/libreadline.so.6", O_RDONLY) = -1 ENOENT (No such file or directory)
stat("/lib64/bash/4.1", 0x7fff5e154370) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=102848, ...}) = 0
mmap(NULL, 102848, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6b9ac2b000
close(3)                                = 0
open("/lib64/libreadline.so.6", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220l\1\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=284144, ...}) = 0
mmap(NULL, 2384792, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f6b9a7e1000
fadvise64(3, 0, 2384792, POSIX_FADV_WILLNEED) = 0
mprotect(0x7f6b9a81e000, 2097152, PROT_NONE) = 0
mmap(0x7f6b9aa1e000, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x3d000) = 0x7f6b9aa1e000
mmap(0x7f6b9aa26000, 5016, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f6b9aa26000
close(3)                                = 0
open("/lib64/libncurses.so.5", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\360\202\1\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=347784, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6b9ac2a000
mmap(NULL, 2444448, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f6b9a58c000
fadvise64(3, 0, 2444448, POSIX_FADV_WILLNEED) = 0
mprotect(0x7f6b9a5d8000, 2093056, PROT_NONE) = 0
mmap(0x7f6b9a7d7000, 40960, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x4b000) = 0x7f6b9a7d7000
close(3)                                = 0
open("/lib64/libdl.so.2", O_RDONLY)     = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\360\r\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=19114, ...}) = 0
mmap(NULL, 2109704, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f6b9a388000
fadvise64(3, 0, 2109704, POSIX_FADV_WILLNEED) = 0
mprotect(0x7f6b9a38a000, 2097152, PROT_NONE) = 0
mmap(0x7f6b9a58a000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x2000) = 0x7f6b9a58a000
close(3)                                = 0
open("/lib64/libc.so.6", O_RDONLY)      = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220\354\1\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=1670469, ...}) = 0
mmap(NULL, 3537800, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f6b9a028000
fadvise64(3, 0, 3537800, POSIX_FADV_WILLNEED) = 0
mprotect(0x7f6b9a17e000, 2097152, PROT_NONE) = 0
mmap(0x7f6b9a37e000, 20480, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x156000) = 0x7f6b9a37e000
mmap(0x7f6b9a383000, 19336, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f6b9a383000
close(3)                                = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6b9ac29000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6b9ac28000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6b9ac27000
arch_prctl(ARCH_SET_FS, 0x7f6b9ac28700) = 0
mprotect(0x7f6b9a37e000, 16384, PROT_READ) = 0
mprotect(0x7f6b9a58a000, 4096, PROT_READ) = 0
mprotect(0x7f6b9a7d7000, 16384, PROT_READ) = 0
mprotect(0x7f6b9aa1e000, 8192, PROT_READ) = 0
mprotect(0x694000, 4096, PROT_READ)     = 0
mprotect(0x7f6b9ac46000, 4096, PROT_READ) = 0
munmap(0x7f6b9ac2b000, 102848)          = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
open("/dev/tty", O_RDWR|O_NONBLOCK)     = 3
close(3)                                = 0
stat("/usr/lib/locale/locale-archive", 0x7fff5e1549c0) = -1 ENOENT (No such file or directory)
brk(0)                                  = 0x6a3000
brk(0x6c4000)                           = 0x6c4000
open("/usr/lib/locale/locale-archive", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/share/locale/locale.alias", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2512, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6b9ac44000
read(3, "# Locale name alias data base.\n#"..., 4096) = 2512
read(3, "", 4096)                       = 0
close(3)                                = 0
munmap(0x7f6b9ac44000, 4096)            = 0
open("/usr/lib/locale/en_US.UTF-8/LC_IDENTIFICATION", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en_US.utf8/LC_IDENTIFICATION", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=373, ...}) = 0
mmap(NULL, 373, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6b9ac44000
close(3)                                = 0
open("/usr/lib64/gconv/gconv-modules.cache", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=26050, ...}) = 0
mmap(NULL, 26050, PROT_READ, MAP_SHARED, 3, 0) = 0x7f6b9ac3d000
close(3)                                = 0
open("/usr/lib/locale/en_US.UTF-8/LC_MEASUREMENT", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en_US.utf8/LC_MEASUREMENT", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=23, ...}) = 0
mmap(NULL, 23, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6b9ac3c000
close(3)                                = 0
open("/usr/lib/locale/en_US.UTF-8/LC_TELEPHONE", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en_US.utf8/LC_TELEPHONE", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=59, ...}) = 0
mmap(NULL, 59, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6b9ac3b000
close(3)                                = 0
open("/usr/lib/locale/en_US.UTF-8/LC_ADDRESS", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en_US.utf8/LC_ADDRESS", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=155, ...}) = 0
mmap(NULL, 155, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6b9ac3a000
close(3)                                = 0
open("/usr/lib/locale/en_US.UTF-8/LC_NAME", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en_US.utf8/LC_NAME", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=77, ...}) = 0
mmap(NULL, 77, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6b9ac39000
close(3)                                = 0
open("/usr/lib/locale/en_US.UTF-8/LC_PAPER", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en_US.utf8/LC_PAPER", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=34, ...}) = 0
mmap(NULL, 34, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6b9ac38000
close(3)                                = 0
open("/usr/lib/locale/en_US.UTF-8/LC_MESSAGES", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en_US.utf8/LC_MESSAGES", O_RDONLY) = 3
fstat(3, {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
close(3)                                = 0
open("/usr/lib/locale/en_US.utf8/LC_MESSAGES/SYS_LC_MESSAGES", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=57, ...}) = 0
mmap(NULL, 57, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6b9ac37000
close(3)                                = 0
open("/usr/lib/locale/en_US.UTF-8/LC_MONETARY", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en_US.utf8/LC_MONETARY", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=286, ...}) = 0
mmap(NULL, 286, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6b9ac36000
close(3)                                = 0
open("/usr/lib/locale/en_US.UTF-8/LC_COLLATE", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en_US.utf8/LC_COLLATE", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=1163682, ...}) = 0
mmap(NULL, 1163682, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6b9ab0a000
close(3)                                = 0
open("/usr/lib/locale/en_US.UTF-8/LC_TIME", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en_US.utf8/LC_TIME", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=2454, ...}) = 0
mmap(NULL, 2454, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6b9ac35000
close(3)                                = 0
open("/usr/lib/locale/en_US.UTF-8/LC_NUMERIC", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en_US.utf8/LC_NUMERIC", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=54, ...}) = 0
mmap(NULL, 54, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6b9ac34000
close(3)                                = 0
open("/usr/lib/locale/en_US.UTF-8/LC_CTYPE", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/lib/locale/en_US.utf8/LC_CTYPE", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=256324, ...}) = 0
mmap(NULL, 256324, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7f6b9aacb000
close(3)                                = 0
getuid()                                = 1000
getgid()                                = 100
geteuid()                               = 1000
getegid()                               = 100
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
open("/proc/meminfo", O_RDONLY)         = 3
fstat(3, {st_mode=S_IFREG|0444, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6b9aaca000
read(3, "MemTotal:        3850660 kB\nMemF"..., 1024) = 1024
close(3)                                = 0
munmap(0x7f6b9aaca000, 4096)            = 0
rt_sigaction(SIGCHLD, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGCHLD, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, 8) = 0
rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, 8) = 0
rt_sigaction(SIGQUIT, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, {SIG_DFL, [], 0}, 8) = 0
rt_sigaction(SIGQUIT, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
rt_sigaction(SIGQUIT, {SIG_IGN, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, 8) = 0
uname({sys="Linux", node="linux-8l2h", ...}) = 0
stat("/home/ruchir", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
stat(".", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
getpid()                                = 12586
getppid()                               = 12585
getpgrp()                               = 12585
rt_sigaction(SIGCHLD, {0x427c63, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, 8) = 0
getrlimit(RLIMIT_NPROC, {rlim_cur=29977, rlim_max=29977}) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
open("/usr/bin/oocalc", O_RDONLY)       = 3
ioctl(3, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fff5e1549d0) = -1 ENOTTY (Inappropriate ioctl for device)
lseek(3, 0, SEEK_CUR)                   = 0
read(3, "#!/bin/sh\n/usr/lib64/ooo3/progra"..., 80) = 53
lseek(3, 0, SEEK_SET)                   = 0
getrlimit(RLIMIT_NOFILE, {rlim_cur=1024, rlim_max=8*1024}) = 0
fcntl(255, F_GETFD)                     = -1 EBADF (Bad file descriptor)
dup2(3, 255)                            = 255
close(3)                                = 0
fcntl(255, F_SETFD, FD_CLOEXEC)         = 0
fcntl(255, F_GETFL)                     = 0x8000 (flags O_RDONLY|O_LARGEFILE)
fstat(255, {st_mode=S_IFREG|0755, st_size=53, ...}) = 0
lseek(255, 0, SEEK_CUR)                 = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
read(255, "#!/bin/sh\n/usr/lib64/ooo3/progra"..., 53) = 53
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
rt_sigprocmask(SIG_BLOCK, [INT CHLD], [], 8) = 0
clone(child_stack=0, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f6b9ac289d0) = 12587
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
rt_sigprocmask(SIG_BLOCK, [CHLD], [], 8) = 0
rt_sigaction(SIGINT, {0x426d20, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, 8) = 0
wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 12587
rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
--- SIGCHLD (Child exited) @ 0 (0) ---
wait4(-1, 0x7fff5e1542dc, WNOHANG, NULL) = -1 ECHILD (No child processes)
rt_sigreturn(0xffffffffffffffff)        = 0
rt_sigaction(SIGINT, {SIG_DFL, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, {0x426d20, [], SA_RESTORER|SA_RESTART, 0x7f6b9a05aa60}, 8) = 0
rt_sigprocmask(SIG_BLOCK, NULL, [], 8)  = 0
read(255, "", 53)                       = 0
exit_group(0)                           = ?
Comment 6 Jan Holesovsky 2010-07-30 09:56:28 UTC 
Sorry, the new location of the page is:

http://en.opensuse.org/openSUSE:Bugreport_OOo#How_to_get_strace_log

Can you please do it that way?  We need the full strace.  Thank you!
Comment 7 Forgotten User 10buyl7JnO 2010-07-30 10:22:17 UTC 
Created attachment 379497 [details]
strace of oofice

I've attached strace as explained in that link. Let me know if you need strace of opening document this way.
Comment 8 Kohei Yoshida 2010-08-09 15:04:11 UTC 
Bug 628761 sounds a lot like this reported issue.
Comment 9 Noel Power 2010-08-13 10:07:05 UTC 
assuming duplicate of Bug #628761 if not please reopen

*** This bug has been marked as a duplicate of bug 628761 ***