Skip to content

USE 373 - reduce TIM bulk update logging#381

Merged
ghukill merged 2 commits into
mainfrom
USE-373-reduce-tim-logging
Mar 12, 2026
Merged

USE 373 - reduce TIM bulk update logging#381
ghukill merged 2 commits into
mainfrom
USE-373-reduce-tim-logging

Conversation

@ghukill

@ghukill ghukill commented Mar 12, 2026

Copy link
Copy Markdown
Contributor

Purpose and background context

This PR dramatically reduces DEBUG logging for TIM for bulk updates.

DEBUG logging is very helpful sometimes, potentially ever for large jobs, and much of the opensearch logging is very helpful and informative. It does have one very chatty logging statement that is problematic: opensearch.base._log_request_response(). This logs both the API request + response. For bulk indexing and updating we are sending tons of data -- the TIMDEX records to index/update -- and they are all logged when in DEBUG mode.

This may seem inconsequential for a few hundred records, but as we get into larger runs (thousands, millions?), the amount of data logged >= the amount of data we sent!

This PR filters out only this specific method from logging. If we need to know what data we send or receieve from an API request, we can do so; this opensearchpy library logging line feels superfluous.

How can a reviewer manually see the effects of these changes?

Easier to just share logs before after the change.

Here is a snippet pre-changes, showing how each record we send for update is getting logged:

2026-03-12 14:42:07,218 DEBUG urllib3.connectionpool._make_request() line 544: http://localhost:9200 "POST /_bulk HTTP/1.1" 200 60086
2026-03-12 14:42:07,219 INFO opensearch.log_request_success() line 258: POST http://localhost:9200/_bulk [status:200 request:0.597s]
2026-03-12 14:42:07,221 DEBUG opensearch._log_request_response() line 197: > {"update":{"_id":"libguides:guides-886887","_index":"libguides-2026-03-12t17-15-16"}}
{"doc":{"timdex_record_id":"libguides:guides-886887","embedding_full_record":{"living":0.8538653254508972,"guide":0.740427553653717,"mit":0.6558040380477905,"machine":0.6258775591850281,"machines":0.56385737657547,"guides":0.5570834875106812,"tim":0.5311638116836548,"##de":0.5261822938919067,"library":0.5066640973091125,"##guide":0.4877738058567047,"li":0.47927117347717285,"biotechnology":0.47543856501579285,"citation":0.46380311250686646,"cite":0.44210368394851685,"research":0.42463016510009766,"id":0.4221096634864807,"citations":0.40657997131347656,"##b":0.39701151847839355,"pm":0.38286277651786804,"offset":0.38262689113616943,"libraries":0.3813073933124542,"course":0.37452349066734314,"biology":0.36781901121139526,"resources":0.3584938645362854,"value":0.355313777923584,"source":0.35052841901779175,"date":0.34472012519836426,"o":0.3440041244029999,"cited":0.34011706709861755,"format":0.3398839831352234,"machinery":0.33851370215415955,"resource":0.332459032535553,"scheme":0.3157486617565155,"courses":0.3049998879432678,"manual":0.3034125566482544,"##ance":0.3025076389312744,"engineering":0.3023518919944763,"##x":0.30020377039909363,"reference":0.29680877923965454,"proven":0.29633891582489014,"run":0.28933703899383545,"88":0.27989187836647034,"electronic":0.27825620770454407,"ur":0.2681453824043274,"robot":0.2634217143058777,"librarian":0.2600238025188446,"code":0.2585568428039551,"robots":0.2561008930206299,"university":0.24649527668952942,"biological":0.24346278607845306,"science":0.23967169225215912,"record":0.23632432520389557,"subject":0.23530788719654083,"bibliography":0.23463675379753113,"software":0.23040013015270233,"guidelines":0.22408396005630493,"biomedical":0.22396573424339294,"bio":0.2211754471063614,"##tech":0.22110611200332642,"publisher":0.21981856226921082,"device":0.21592196822166443,"publication":0.21378153562545776,"booklet":0.21230173110961914,"published":0.20655468106269836,"ebook":0.20392538607120514,"##des":0.19879622757434845,"citing":0.1959264874458313,"link":0.19579347968101501,"diagram":0.19409768283367157,"repository":0.19315005838871002,"database":0.1864480972290039,"##mac":0.1845746487379074,"content":0.18202728033065796,"copyright":0.18079324066638947,"textbooks":0.18015064299106598,"life":0.17860212922096252,"robotics":0.17161503434181213,"##hine":0.17064021527767181,"computer":0.16853807866573334,"publishing":0.16623876988887787,"timothy":0.165269672870636,"referenced":0.1583074927330017,"file":0.15769585967063904,"automated":0.15258172154426575,"kind":0.15170568227767944,"curriculum":0.15102751553058624,"documentation":0.1509629189968109,"books":0.14879107475280762,"cart":0.14607824385166168,"version":0.14479020237922668,"##s":0.14474940299987793,"created":0.14448769390583038,"computers":0.14288991689682007,"referencing":0.13915526866912842,"records":0.13860684633255005,"links":0.13366806507110596,"medicine":0.13145631551742554,"title":0.13021227717399597,"number":0.12847627699375153,"automation":0.12676239013671875,"189":0.12584373354911804,"alive":0.12210410833358765,"schemes":0.12056668102741241,"computing":0.11826060712337494,"##ai":0.11438414454460144,"robotic":0.11298719793558121,"summary":0.1100582405924797,"institute":0.10678854584693909,"book":0.10667821764945984,"scientific":0.10269121080636978,"##mata":0.09981551021337509,"liv":0.0995909571647644,"wiley":0.09914477169513702,"topic":0.09833987057209015,"live":0.09790042787790298,"##kit":0.0966830849647522,"mach":0.09642475098371506,"tools":0.09610056132078171,"mechanical":0.09574735909700394,"micro":0.09550879150629044,"ed":0.09068247675895691,"appliances":0.09021327644586563,"edition":0.08983706682920456,"##ded":0.08928465843200684,"textbook":0.08890774846076965,"document":0.08705782145261765,"##8":0.08678745478391647,"simulator":0.08607867360115051,"classes":0.08523360639810562,"20":0.08490162342786789,"laptop":0.08276581764221191,"hardware":0.07753424346446991,"##bio":0.077327199280262,"medical":0.07537329196929932,"ai":0.07421056926250458,"find":0.0718519389629364,"##52":0.07160057872533798,"references":0.07000301033258438,"text":0.06927108764648438,"identification":0.0679425597190857,"_":0.06763697415590286,"catalog":0.06667140126228333,"license":0.06481201946735382,"##bs":0.061491984874010086,"##bot":0.06116531416773796,"##ifier":0.06086268275976181,"sources":0.05935549736022949,"pdf":0.05851719528436661,"website":0.058071572333574295,"##u":0.057393163442611694,"journal":0.057318542152643204,"api":0.05601394549012184,"study":0.05538337305188179,"project":0.05479412153363228,"computational":0.05476228520274162,"odi":0.054527197033166885,"eds":0.05392998456954956,"wikipedia":0.05284207686781883,"cambridge":0.05101117119193077,"massachusetts":0.050758857280015945,"web":0.050668735057115555,"##rri":0.050201721489429474,"class":0.04828942194581032,"##lib":0.04740864038467407,"simulation":0.045844025909900665,"guidance":0.045092854648828506,"publishers":0.044306620955467224,"valid":0.04209505766630173,"sci":0.04127785190939903,"##da":0.04124832898378372,"program":0.04065992683172226,"handbook":0.03850552439689636,"formats":0.037345536053180695,"##bt":0.03406350314617157,"sourced":0.03349665179848671,"publish":0.03348272293806076,"domain":0.03216037154197693,"##l":0.030183663591742516,"foreman":0.030098900198936462,"specification":0.029504097998142242,"proof":0.029461929574608803,"pub":0.029098009690642357,"tractors":0.028967007994651794,"tool":0.02849779650568962,"thesis":0.027857426553964615,"##be":0.027813266962766647,"b":0.026587948203086853,"##ances":0.025388024747371674,"technology":0.024891451001167297,"php":0.02448941208422184,"education":0.022896897047758102,"##bi":0.022638052701950073,"type":0.020342659205198288,"verified":0.019134189933538437,"python":0.017602723091840744,"topics":0.016866177320480347,"#":0.015982864424586296,"modular":0.015169109217822552,"engineer":0.014628314413130283,"##omics":0.01267132069915533,"patent":0.01136673241853714,"##du":0.009110997430980206,"proprietary":0.008144748397171497,"college":0.007056851405650377,"password":0.00636832183226943,"mechanics":0.0015023105079308152,"subjects":0.000857065140735358,"202":0.0006539863534271717}}}
{"update":{"_id":"libguides:guides-175847","_index":"libguides-2026-03-12t17-15-16"}}
{"doc":{"timdex_record_id":"libguides:guides-175847","embedding_full_record":{"guide":0.7244652509689331,"mit":0.7116156220436096,"nt":0.6983522772789001,"library":0.5982416868209839,"guides":0.5822792053222656,"report":0.5552945137023926,"reports":0.5537885427474976,"##guide":0.5172713994979858,"tim":0.5149623155593872,"o":0.5015209317207336,"citation":0.4777209162712097,"li":0.472740113735199,"cite":0.47096869349479675,"research":0.4573235809803009,"aeronautics":0.45050203800201416,"id":0.44618692994117737,"##de":0.44281521439552307,"1758":0.4424474239349365,"tools":0.434268593788147,"##b":0.4337747097015381,"libraries":0.4282265305519104,"date":0.4201880097389221,"citations":0.41407427191734314,"astronaut":0.40737614035606384,"##sb":0.40674832463264465,"source":0.3975667953491211,"pm":0.3909572660923004,"format":0.38881054520606995,"##47":0.38085660338401794,"offset":0.37900596857070923,"cited":0.375982403755188,"ur":0.372848778963089,"librarian":0.35915136337280273,"tool":0.35191747546195984,"engineering":0.3435083031654358,"proven":0.3302948474884033,"reference":0.324806809425354,"scheme":0.31844043731689453,"##ance":0.3132529556751251,"resource":0.3129171133041382,"nasa":0.30834150314331055,"value":0.3061145842075348,"bibliography":0.291155070066452,"link":0.28447452187538147,"citing":0.2770882546901703,"run":0.2767525911331177,"aviation":0.2763192653656006,"electronic":0.269756942987442,"code":0.26523923873901367,"aerospace":0.2640654742717743,"php":0.26307493448257446,"astronauts":0.25952842831611633,"file":0.2592698931694031,"record":0.25646933913230896,"##s":0.2504093647003174,"database":0.2489977926015854,"##x":0.24705658853054047,"links":0.24188685417175293,"reporting":0.23295973241329193,"aeronautical":0.23187246918678284,"publisher":0.2314496487379074,"resources":0.2298468053340912,"manual":0.22644372284412384,"ns":0.22602999210357666,"university":0.22253966331481934,"repository":0.20797257125377655,"documentation":0.20442913472652435,"number":0.2014135867357254,"##46":0.20064114034175873,"diagram":0.19981718063354492,"publication":0.19747371971607208,"content":0.1967061460018158,"##cb":0.18530000746250153,"subject":0.18503227829933167,"guidelines":0.1780163198709488,"odi":0.17614606022834778,"referencing":0.1750677227973938,"software":0.17318417131900787,"##lib":0.1720639318227768,"booklet":0.17037472128868103,"summary":0.16881626844406128,"referenced":0.16861484944820404,"published":0.16606995463371277,"83":0.1592956930398941,"kind":0.15888839960098267,"ni":0.1585501730442047,"aircraft":0.15589407086372375,"records":0.15194863080978394,"schemes":0.15173183381557465,"created":0.1488443911075592,"space":0.14477111399173737,"journal":0.1403723806142807,"##ai":0.13809113204479218,"pub":0.1369464248418808,"astronomy":0.13585330545902252,"copyright":0.1342414915561676,"notes":0.13325431942939758,"web":0.1323285549879074,"c":0.13081173598766327,"references":0.1279386579990387,"##ics":0.12773679196834564,"publishing":0.12697939574718475,"##bs":0.12434622645378113,"version":0.12217514216899872,"text":0.1192815899848938,"sources":0.11749909818172455,"##l":0.11745239049196243,"nme":0.11734619736671448,"formats":0.1148650199174881,"type":0.11249425262212753,"catalog":0.10901553183794022,"identification":0.10816487669944763,"timothy":0.10807910561561584,"##be":0.10742628574371338,"handbook":0.10064920783042908,"faa":0.09494907408952713,"astro":0.09429772198200226,"sourced":0.09367470443248749,"orbital":0.09349511563777924,"document":0.09293197840452194,"##bt":0.09099604189395905,"##naut":0.09092023223638535,"_":0.09025603532791138,"stand":0.08944760262966156,"et":0.08548238128423691,"find":0.08226216584444046,"issn":0.08144427090883255,"website":0.07885904610157013,"#":0.074978306889534,"##24":0.07333523035049438,"nr":0.07170417904853821,"##38":0.06927315145730972,"ebook":0.06919620931148529,"title":0.06824342906475067,"stands":0.06805818527936935,"bulletin":0.06787524372339249,"linux":0.06713026762008667,"abbreviation":0.06642819941043854,"##u":0.06391729414463043,"api":0.0624709390103817,"files":0.061383746564388275,"topic":0.058295100927352905,"institute":0.05739588290452957,"books":0.05720850080251694,"47":0.056521929800510406,"n":0.05589563027024269,"ames":0.05490097776055336,"python":0.05322103202342987,"spacecraft":0.05289625748991966,"##des":0.051443688571453094,"bs":0.051066506654024124,"name":0.0497964583337307,"computer":0.04790725186467171,"##ifier":0.047680988907814026,"project":0.047473639249801636,"ed":0.046684250235557556,"valid":0.04574969410896301,"286":0.042662203311920166,"prefix":0.04197019338607788,"rocket":0.04094244912266731,"science":0.04047029837965965,"##ances":0.03942275047302246,"what":0.03719448298215866,"org":0.035926703363657,"book":0.03519910201430321,"##48":0.03220832347869873,"https":0.03134821355342865,"##bc":0.031128160655498505,"dates":0.030219383537769318,"password":0.029081596061587334,"archive":0.028072571381926537,"b":0.027637450024485588,"http":0.027600903064012527,"verified":0.025616681203246117,"prove":0.025263885036110878,"pdf":0.022440744563937187,"tag":0.02209603413939476,"access":0.02168360725045204,"wikipedia":0.020888589322566986,"sb":0.020794406533241272,"publishers":0.01946302503347397,"proof":0.018856685608625412,"domain":0.017308304086327553,"cites":0.017195861786603928,"aero":0.016874488443136215,"##44":0.01631942391395569,"string":0.01394092570990324,"202":0.01345987431704998,"##link":0.01257602870464325,"##bi":0.012096974067389965,"engineers":0.011414838023483753,"data":0.009160025976598263,"berkeley":0.00860415119677782,"##ent":0.00782522652298212,"retrieved":0.007272845599800348,"guidance":0.006858538370579481,"##ded":0.006612746976315975,"topics":0.005262910388410091,"java":0.004746489226818085,"publish":0.0026050566229969263,"engineer":0.0019652212504297495,"script":0.0014529762556776404,"pmid":0.0013679054100066423,"oracle":0.00113610306289047}}}
{"update":{"_id":"libguides:guides-175955","_index":"libguides-2026-03-12t17-15-16"}}

Here is the same section of logs, missing this particular private method logging:

026-03-12 14:26:03,945 DEBUG urllib3.connectionpool._make_request() line 544: http://localhost:9200 "POST /_bulk HTTP/1.1" 200 60086
2026-03-12 14:26:03,946 INFO opensearch.log_request_success() line 258: POST http://localhost:9200/_bulk [status:200 request:0.455s]
# Gone!  🦗's

Includes new or updated dependencies?

YES | NO

Changes expectations for external applications?

YES | NO

What are the relevant tickets?

  • Include links to Jira Software and/or Jira Service Management tickets here.

Code review

  • Code review best practices are documented here and you are encouraged to have a constructive dialogue with your reviewers about their preferences and expectations.

ghukill added 2 commits March 11, 2026 15:39
Why these changes are being introduced:

The opensearchpy library has a built-in DEBUG logger that logs the full API request + response
for each request.  This is not terribly helpful for debugging purposes, as in code we could log
both the requets and/or response as needed.  A good example are bulk updates where ALL documents
we send for update are logged.  For a job like DSpace or Alma, the amount of logs are equal to the
amount of data we are sending.

That said, DEBUG logging for the opensearch library is quite helpful for other reasons, so
it's not ideal to completely quiet that library's DEBUG logs.  Ideall we would only target
this specific, private logging method.

How this addresses that need:
* Pinpoints and filters out the opensearchpy logging method, _log_request_response()

Side effects of this change:
* Dramatically reduced logs in DEBUG mode, while still getting helpful opensearch
DEBUG logs

Relevant ticket(s):
* https://mitlibraries.atlassian.net/browse/USE-373
@ghukill ghukill marked this pull request as ready for review March 12, 2026 19:11
@ghukill ghukill requested a review from a team as a code owner March 12, 2026 19:11
@jonavellecuerdo jonavellecuerdo self-assigned this Mar 12, 2026

@ehanson8 ehanson8 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Smart fix to tame the logs!

@ghukill ghukill merged commit 212d89b into main Mar 12, 2026
3 checks passed
@jonavellecuerdo jonavellecuerdo removed their assignment Mar 13, 2026
@ghukill ghukill deleted the USE-373-reduce-tim-logging branch April 7, 2026 15:14
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants