Bug 296372 - virtuoso using 200% cpu
Summary: virtuoso using 200% cpu
Status: RESOLVED DUPLICATE of bug 289932
Alias: None
Product: nepomuk
Classification: Miscellaneous
Component: queryservice (show other bugs)
Version: 4.8
Platform: Ubuntu Linux
: NOR normal
Target Milestone: ---
Assignee: Sebastian Trueg
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2012-03-19 16:34 UTC by Andreas Nilsson
Modified: 2012-03-30 08:14 UTC (History)
2 users (show)

See Also:
Latest Commit:
Version Fixed In:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Andreas Nilsson 2012-03-19 16:34:43 UTC
Noticing that my laptop sounded a bit too much i found:

2336 andrnils  39  19  581m 141m 7768 S  198  1.8  42:27.41 /usr/bin/virtuoso-t +foreground +configfile /tmp/virtuoso_hX2322.ini +wait

This is in a kde session started this morning, with only a couple of konsole windows,  a chromium instance and amarok running. 

There seems to be no outstanding querys:

$ qdbus org.kde.nepomuk.services.nepomukqueryservice
/
/nepomukqueryservice
/servicecontrol

Further info about my setup:
Kde 4.8.1 on ubuntu 12.04 with kernel 3.3 running on a thinkpad t510 with 8gb ram.

Any way to debug this further?
Comment 1 Andreas Nilsson 2012-03-19 19:55:21 UTC
I did also run strace on the process:

$ strace -p 2336
Process 2336 attached - interrupt to quit
futex(0x20f6454, FUTEX_WAIT_PRIVATE, 351, NULL^C <unfinished ...>

And then just proceeded with ltrace, but that resulted in virtuoso segfaulting :(
Comment 2 Vangelis 2012-03-29 13:44:11 UTC
We probably face the same problem...

I am on Kubuntu 11.10 still but virtuoso-t is a killer for my laptop as well, even though its niceness is set on 19.

I used this link to try to get some more information about the cause of the problem but not so much that I could correlate with my knowledge.

I ran "isql-vt -H localhost -S 1111 -U dba -P dba" this command first to connect when the high CPU load started and then ran this command in the SQL shell: status('rhck');

SQL> status('rhck');
REPORT
VARCHAR
_______________________________________________________________________________

OpenLink Virtuoso  Server
Version 06.01.3127-pthreads for Linux as of Mar 18 2012 
Started on: 2012/03/29 13:36 GMT+120
Lite Mode
 
Database Status:
  File size 599785472, 73216 pages, 24179 free.
  57000 buffers, 34680 used, 127 dirty 0 wired down, repl age 0 0 w. io 5 w/crsr.
  Disk Usage: 34710 reads avg 2 msec, 0% r 0% w last  0 s, 8646 writes,
    215 read ahead, batch = 152.  Autocompact 67 in 53 out, 20% saved.
Gate:  153 2nd in reads, 0 gate write waits, 0 in while read 0 busy scrap. 
Log = /home/cyber/.kde/share/apps/nepomuk/repository/main/data/virtuosobackend/soprano-virtuoso.trx, 7897 bytes
48892 pages have been changed since last backup (in checkpoint state)
Current backup timestamp: 0x0000-0x00-0x00
Last backup date: unknown
Clients: 16 connects, max 10 concurrent
RPC: 121990 calls, -4 pending, 3 max until now, 0 queued, 118 burst reads (0%), 0 second brk=46526464
Checkpoint Remap 0 pages, 0 mapped back. 13 s atomic time.
    DB master 73216 total 24179 free 0 remap 0 mapped back
   temp  768 total 763 free
 
Lock Status: 0 deadlocks of which 0 2r1w, 0 waits,
   Currently 2 threads running 0 threads waiting 0 threads in vdb.
Pending:
 
Client 1111:1:-5:  Account: dba, 2989 bytes in, 1672 bytes out, 0 stmts.
PID: 2935, OS: unix, Application: unknown, IP#: 127.0.0.1
Transaction status: PENDING, 0 threads.
Locks: 
 
Client 1111:1:-6:  Account: dba, 449 bytes in, 364 bytes out, 0 stmts.
PID: 2935, OS: unix, Application: unknown, IP#: 127.0.0.1
Transaction status: PENDING, 0 threads.
Locks: 
 
Client 1111:1:-13:  Account: dba, 830 bytes in, 483 bytes out, 0 stmts.
PID: 2935, OS: unix, Application: unknown, IP#: 127.0.0.1
Transaction status: PENDING, 0 threads.
Locks: 
 
Client 1111:1:-12:  Account: dba, 5947264 bytes in, 9513334 bytes out, 0 stmts.
PID: 2935, OS: unix, Application: unknown, IP#: 127.0.0.1
Transaction status: PENDING, 0 threads.
Locks: 
 
Client 1111:1:-15:  Account: dba, 675 bytes in, 263 bytes out, 1 stmts.
PID: 2935, OS: unix, Application: unknown, IP#: 127.0.0.1
Transaction status: PENDING, 1 threads.
Locks: 48: IS, 
 
Client 1111:1:-3:  Account: dba, 30941 bytes in, 1292120 bytes out, 0 stmts.
PID: 2935, OS: unix, Application: unknown, IP#: 127.0.0.1
Transaction status: PENDING, 0 threads.
Locks: 
 
Client 1111:16:  Account: dba, 12614 bytes in, 682385 bytes out, 1 stmts.
PID: 16434, OS: unix, Application: unknown, IP#: 127.0.0.1
Transaction status: PENDING, 1 threads.
Locks: 
 
Client 1111:1:-10:  Account: dba, 4716747 bytes in, 2000560 bytes out, 0 stmts.
PID: 2935, OS: unix, Application: unknown, IP#: 127.0.0.1
Transaction status: PENDING, 0 threads.
Locks: 
 
Client 1111:1:-11:  Account: dba, 4656289 bytes in, 2019376 bytes out, 0 stmts.
PID: 2935, OS: unix, Application: unknown, IP#: 127.0.0.1
Transaction status: PENDING, 0 threads.
Locks: 
 
Client 1111:1:-9:  Account: dba, 4327562 bytes in, 1816719 bytes out, 0 stmts.
PID: 2935, OS: unix, Application: unknown, IP#: 127.0.0.1
Transaction status: PENDING, 0 threads.
Locks: 
 
 
Running Statements:
 Time (msec) Text
           3 status('rhck')
      233322 sparql select distinct ?r (bif:concat(bif:search_excerpt(bif:vector('=44/16'), ?
Index Usage:
Table         Index            Touches   Reads %Miss   Locks   Waits   %W n-dead
DB.DBA.RDF_QUAD    RDF_QUAD            94117629    6224    0%    4305       0   0% 0
DB.DBA.RDF_QUAD    RDF_QUAD_SP           13691    1585   11%    2743       0   0% 0
DB.DBA.RDF_QUAD    RDF_QUAD_POGS       34135992    6897    0%   30162       0   0% 0
DB.DBA.RDF_QUAD    RDF_QUAD_GS            5841     420    7%    1560       0   0% 0
DB.DBA.RDF_QUAD    RDF_QUAD_OP             403     976  241%     374       0   0% 0
DB.DBA.RDF_OBJ     RDF_OBJ              131099    1839    1%     517       0   0% 0
DB.DBA.RDF_OBJ     RO_VAL                 6486     696   10%     194       0   0% 0
DB.DBA.RO_START    RO_START                 49      44   88%      49       0   0% 0
DB.DBA.RDF_DATATYPE RDF_DATATYPE              5       1   16%       7       0   0% 0
DB.DBA.RDF_DATATYPE DB_DBA_RDF_DATATYPE_UNQC_RDT_TWOBYTE       1       1   50%       0       0   0% 0
DB.DBA.RDF_OBJ_FT_RULES RDF_OBJ_FT_RULES          2       1   33%       1       0   0% 0
DB.DBA.RDF_OBJ_RO_FLAGS_WORDS RDF_OBJ_RO_FLAGS_WORDS    2430    9257  380%    4911       0   0% 0
DB.DBA.RDF_PREFIX  DB_DBA_RDF_PREFIX_UNQC_RP_ID    8130       1    0%       0       0   0% 0
DB.DBA.RDF_IRI     RDF_IRI                1534    3934  256%    3068       0   0% 0
DB.DBA.RDF_IRI     DB_DBA_RDF_IRI_UNQC_RI_ID  416764    2632    0%    1534       0   0% 0
 
 
Hash indexes
 

101 Rows. -- 5 msec.

Then I enabled the client traces with "trace_on ('client_sql');" but the error log file "~/.kde/share/apps/nepomuk/repository/main/data/virtuosobackend/soprano-virtuoso.log" doesn't contain any newly added lines.

After sometime the SQL Shell got unresponsive and when I reissue the command "isql-vt -H localhost -S 1111 -U dba -P dba" to connect, it just hangs there and it cannot connect.
Comment 3 Vangelis 2012-03-29 14:06:25 UTC
I killed nepomukserver with the command: "qdbus org.kde.NepomukServer /nepomukserver quit" but virtuoso-t process was still there eating my CPU.
I tried a "killall virtuoso-t" but I got rid of it only when I ran a "killall -9 virtuoso-t".

then I started nepomukserver again in a konsole and when I got the same behaviour and I couldn't connect to the the virtuoso sql shell with the isql-vt command anymore,  the output from the nepomukserver konsole was this:

...
...
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'utdwh'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'tnnsi'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'phihl'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'phihl'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'yrfpi'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'cumnf'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'awcik'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'tlxak'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'nyckr'."
[/usr/bin/nepomukservicestub] virtual void Soprano::Server::ServerConnection::run() thread done.
[/usr/bin/nepomukservicestub] virtual Soprano::ODBC::Connection::~Connection() Soprano::Server::ServerConnection(0x15a0650)
[/usr/bin/nepomukservicestub] void Soprano::Server::ServerCore::serverConnectionFinished() 
virtual Soprano::Server::ServerConnection::~ServerConnection() Removing connection
[/usr/bin/nepomukservicestub] void Soprano::Server::ServerCore::serverConnectionFinished() Connection removed. Current count: 12
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'nkbyq'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'nkbyq'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'gsrqj'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'kzzja'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'vsbvf'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'wxwvz'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'wxwvz'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'niurw'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'hihen'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'hihen'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'ikmki'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'nvioe'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'koqeh'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'koqeh'."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24293)" Soprano: "Invalid argument (1)": "Unknown protocol '' encountered in 'bttaw'."
------STOPS HERE FOR SOME TIME------


[/usr/bin/nepomukservicestub] local socket error: QLocalSocket::SocketTimeoutError
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24350)" Soprano: "Timeout (5)": "Command timed out."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24350)" Soprano: "Timeout (5)": "Command timed out."
[/usr/bin/nepomukservicestub] "/usr/bin/nepomukservicestub(24350)" Soprano: "Timeout (5)": "Command timed out."
[/usr/bin/nepomukservicestub] virtual void Soprano::Server::LocalServer::incomingConnection(quintptr)
[/usr/bin/nepomukservicestub] void Soprano::Server::ServerCorePrivate::addConnection(Soprano::Server::ServerConnection*) New connection. New count: 13
^C[/usr/bin/nepomukservicestub] virtual Soprano::Server::ServerConnection::~ServerConnection() Removing connection
[/usr/bin/nepomukservicestub] virtual void Soprano::Server::ServerConnection::run() thread done.
[/usr/bin/nepomukservicestub] virtual Soprano::Server::ServerConnection::~ServerConnection() Removing connection
[/usr/bin/nepomukservicestub] virtual void Soprano::Server::ServerConnection::run() thread done.
[/usr/bin/nepomukservicestub] virtual Soprano::Server::ServerConnection::~ServerConnection() Removing connection
[/usr/bin/nepomukservicestub] virtual void Soprano::Server::ServerConnection::run() thread done. 
virtual Soprano::ODBC::Connection::~Connection() Soprano::Server::ServerConnection(0x15d4380) 
virtual Soprano::Server::ServerConnection::~ServerConnection() Removing connection 
virtual void Soprano::Server::ServerConnection::run() thread done.
[/usr/bin/nepomukservicestub] virtual Soprano::Server::ServerConnection::~ServerConnection() Removing connection
[/usr/bin/nepomukservicestub] virtual void Soprano::Server::ServerConnection::run() thread done.
[/usr/bin/nepomukservicestub] virtual Soprano::Server::ServerConnection::~ServerConnection() Removing connection
[/usr/bin/nepomukservicestub] virtual void Soprano::Server::ServerConnection::run() thread done.
[/usr/bin/nepomukservicestub] virtual Soprano::Server::ServerConnection::~ServerConnection() Removing connection
Application '/usr/bin/nepomukservicestub nepomukqueryservice' exited normally...
Application '/usr/bin/nepomukservicestub digikamnepomukservice' exited normally...
Application '/usr/bin/nepomukservicestub nepomukbackupsync' exited normally...
[/usr/bin/nepomukservicestub] local socket error: QLocalSocket::PeerClosedError
Application '/usr/bin/nepomukservicestub nepomukfilewatch' exited normally...
-----I had to press Ctrl+c to stop it here-----

virtuoso-t still stuck and eating my CPU while being totally unresponisive :(
Comment 4 Sebastian Trueg 2012-03-30 08:14:59 UTC

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