[OPEN-ILS-DEV] [GSOC] System Log

[sy duan]

Thanks for your help. i'm using the image from
http://evergreen-ils.org/dokuwiki/doku.php?id=dev:quick-start_introduction_and_virtual_image.
It's a debian image and I gave 1G memory to the virtual machine. And my CPU
is  Intel Core Duo E7500 with 2G physical memory.Yes, i'm using records
from concerto.sql and some normal query such as 'abc', 'nation'.  Open
Content Alliance MARC records is really the things i'm looking for. Thanks
a  lot.
I added some time counters in some of the key code in search procedure to
measure time consumed by each function. After that I find myself having
misunderstood OpenSRF logs before. The message processing time contains the
DB execution time other than the time used only to handle message
transmission. So i think my previous conclusion is wrong. And the logs of
OpenSRF and the log's of PostgreSQL shows much of time is really spent on
DB execution. Now i have change my focus back on optimizing the DB stored
procedures. The log info i'm interested is given below.
I will use the Open Content Alliance MARC records to run more test to
measure the performance. I will let you know if i have some findings.
Thanks again.

-----------------------------------------------------------------osrfsys.log-----------------------------------------------------------------------------------------------------------------------
[2012-07-10 22:17:27] open-ils.storage [INFO:2272:Pg.pm:67:] Attempting to
connect to evergreen at localhost
[2012-07-10 22:17:28] open-ils.storage [INFO:2272:Pg.pm:97:] Connected to
MASTER db evergreen at localhost
[2012-07-10 22:17:28] open-ils.storage [INFO:2243:Transport.pm:163:]
Message processing duration: 3.141
[2012-07-10 22:17:28] open-ils.search [INFO:2233:Biblio.pm:1281:] staged
search: DB call took 3.1780788898468 seconds and returned 0 rows, including
summary
[2012-07-10 22:17:28] open-ils.search [INFO:2233:Biblio.pm:1285:] search
returned 0 results: duration=3.1780788898468:
params={"estimation_strategy":"inclusion","skip_check":0,"limit":"1000","check_limit":"1000","core_limit":10000,"offset":0,"searches":{"keyword":{"term":"test
depth(0)"}}}
[2012-07-10 22:17:28] open-ils.search [INFO:2233:Biblio.pm:1541:] staged
search: cached with key=open-ils.search_d16605fbc7a72a177177f4386d751d15,
superpage=0, estimated=, visible=0
[2012-07-10 22:17:28] open-ils.search [INFO:2233:Biblio.pm:910:] compiled
search is
{"estimation_strategy":"inclusion","skip_check":0,"limit":10,"check_limit":"1000","core_limit":10000,"offset":0,"searches":{"keyword":{"term":"test
depth(0)"}}}
[2012-07-10 22:17:28] open-ils.search [INFO:2233:Transport.pm:163:] Message
processing duration: 3.286



On Mon, Jul 9, 2012 at 11:54 PM, Dan Scott <dan at coffeecode.net> wrote:

> Hi Swenyu:
>
> On Tue, Jul 03, 2012 at 10:04:15PM +0800, sy duan wrote:
> > Hi everyone,
> >
> >          I’m Swenyu, this year’s GSOC student. I’m optimizing the system
> > performance in search. I have studied the log of OpenSRF in the file
> > osrfsys.log. Which shows in a single search operation, DB calls takes as
> > much time as the message processing in Tranport.pm. And the accumulated
> > message processing time even surpass the DB search time. So I want to
>
> Can you share a little more information - for example, what sort of
> hardware and operating system configuration, how much data is loaded in
> the database, what query you're running, etc? If we want to reproduce
> your tests in the future, to ensure that we don't introduce performance
> regressions, we'll need some more complete descriptions and
> instructions.
>
> > optimize the message processing method in Tranport.pm as well as the DB’s
> > stored procedures. But the conclusion is drawn from my own virtual
> machine
> > logs which has little test data in database. In most time the search only
> > return 0 result. So I turned to your help. Could anyone send me a snippet
>
> Which data set are you using currently? If it's just the 100 records
> from concerto.sql, we could look at using something like the Open
> Content Alliance records at http://books.scholarsportal.info/marc.html
> as the basis for a high-volume test data set (like concerto.sql, we
> would want to create call numbers and copies, including deleted
> records/call numbers/copies and monographic parts and the like - just
> with 270,000 records instead of 100!)
>
> > of your running system log which contains some query with a large result
> > set. The system log is located in /openils/var/log in your running
> system.
>
> I've attached the activity.log entries pertaining to a search on our
> production database, but I suspect you're looking for more than just the
> standard split-up-for-syslog log entries. Maybe you could post what
> particular parts of the log entries you want, as an example, and we
> could pull the pertinent pieces together?
>
> > Or could anyone point a place for me to find some real data to fill in my
> > database. That will be a great help to support the optimization.
>
> As noted, I think the Open Content Alliance MARC records would serve as
> a reasonable starting point for a huge set of of MARC, if that's the
> kind of data you're looking for. (I'm not sure if you want patron data
> and org unit data and transaction histories and everything else, too,
> but as you're focused on search I'm guessing MARC + call numbers +
> copies is your primary interest for now.)
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://libmail.georgialibraries.org/pipermail/open-ils-dev/attachments/20120711/43c9840e/attachment.htm>