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.)
2012-07-09 11:46:44 protostar osrf_json_gw: [ACT:3038:./osrf_json_gateway.c:302:134184874830388] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.multiclass.query {"org_unit":105,"depth":1,"limit":10,"offset":0,"visibility_limit":3000,"default_class":"keyword"}, "apache", 1 2012-07-09 11:46:44 protostar osrf_json_gw: [ACT:3038:./osrf_json_gateway.c:302:134184874830389] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.mods_slim.retrieve 889694 2012-07-09 11:46:44 protostar osrf_json_gw: [ACT:3852:./osrf_json_gateway.c:302:134184878538522] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.mods_slim.retrieve 889695 2012-07-09 11:46:44 protostar osrf_json_gw: [ACT:3044:./osrf_json_gateway.c:302:134184874930443] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.mods_slim.retrieve 889636 2012-07-09 11:46:44 protostar osrf_json_gw: [ACT:3826:./osrf_json_gateway.c:302:1341848778382612] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.mods_slim.retrieve 354247 2012-07-09 11:46:44 protostar osrf_json_gw: [ACT:2986:./osrf_json_gateway.c:302:134184871729868] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.mods_slim.retrieve 885982 2012-07-09 11:46:44 protostar osrf_json_gw: [ACT:3035:./osrf_json_gateway.c:302:134184874730353] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.mods_slim.retrieve 885968 2012-07-09 11:46:44 protostar osrf_json_gw: [ACT:3038:./osrf_json_gateway.c:302:1341848748303810] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.mods_slim.retrieve 293264 2012-07-09 11:46:44 protostar osrf_json_gw: [ACT:3826:./osrf_json_gateway.c:302:1341848778382613] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.mods_slim.retrieve 832165 2012-07-09 11:46:44 protostar osrf_json_gw: [ACT:2986:./osrf_json_gateway.c:302:134184871729869] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.mods_slim.retrieve 38167 2012-07-09 11:46:44 protostar osrf_json_gw: [ACT:3852:./osrf_json_gateway.c:302:134184878538523] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.mods_slim.retrieve 355300 2012-07-09 11:46:44 protostar osrf_json_gw: [ACT:3038:./osrf_json_gateway.c:302:1341848748303811] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.copy_count 105, 889694, "" 2012-07-09 11:46:44 protostar osrf_json_gw: [ACT:3035:./osrf_json_gateway.c:302:134184874730354] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.copy_count 105, 354247, "" 2012-07-09 11:46:45 protostar osrf_json_gw: [ACT:3852:./osrf_json_gateway.c:302:134184878538524] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.copy_count 105, 885982, "" 2012-07-09 11:46:45 protostar osrf_json_gw: [ACT:3038:./osrf_json_gateway.c:302:1341848748303812] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.copy_count 105, 889695, "" 2012-07-09 11:46:45 protostar osrf_json_gw: [ACT:3035:./osrf_json_gateway.c:302:134184874730355] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.copy_count 105, 293264, "" 2012-07-09 11:46:45 protostar osrf_json_gw: [ACT:3038:./osrf_json_gateway.c:302:1341848748303813] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.copy_count 105, 885968, "" 2012-07-09 11:46:45 protostar osrf_json_gw: [ACT:2986:./osrf_json_gateway.c:302:1341848717298610] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.copy_count 105, 832165, "" 2012-07-09 11:46:45 protostar osrf_json_gw: [ACT:3038:./osrf_json_gateway.c:302:1341848748303814] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.copy_count 105, 889636, "" 2012-07-09 11:46:45 protostar osrf_json_gw: [ACT:2986:./osrf_json_gateway.c:302:1341848717298611] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.copy_count 105, 355300, "" 2012-07-09 11:46:45 protostar osrf_json_gw: [ACT:3038:./osrf_json_gateway.c:302:1341848748303815] [142.51.8.34] [] [en-CA] open-ils.search open-ils.search.biblio.record.copy_count 105, 38167, "" 2012-07-09 11:46:45 protostar osrf_http_translator: [ACT:2986:./osrf_http_translator.c:293:1341848717298612] [142.51.8.34] [] open-ils.search open-ils.search.facet_cache.retrieve "open-ils.search_9ac841389733d019221029b737c323aa_facets", 100