Re: CPU spikes and performance problems with Connector/J 5.1.12
Posted by: Juliano DeCarvalho
Date: December 30, 2013 01:20PM

The following log section shows the thread entering into PreparedStatement.ParseInfo() constructor at 10:13:12 AM, and exiting at 10:24:45 AM. As it is parsing the SQL query, I have log output for when each character is being parsed, and as you can see some of the characters take less than a millisecond to parse, while others takes 100+ milliseconds for seemingly no reasons at all:

------------

2013-12-30 10:23:14,847 Start ParseInfo

2013-12-30 10:23:14,987 Parsing Char #0
2013-12-30 10:23:14,989 Parsing Char #1
2013-12-30 10:23:14,989 Parsing Char #2
2013-12-30 10:23:14,989 Parsing Char #3
2013-12-30 10:23:15,084 Parsing Char #4
2013-12-30 10:23:15,084 Parsing Char #5
2013-12-30 10:23:15,084 Parsing Char #6
2013-12-30 10:23:15,084 Parsing Char #7
2013-12-30 10:23:15,085 Parsing Char #8
2013-12-30 10:23:15,085 Parsing Char #9
2013-12-30 10:23:15,085 Parsing Char #10
2013-12-30 10:23:15,085 Parsing Char #11
2013-12-30 10:23:15,197 Parsing Char #12
2013-12-30 10:23:15,199 Parsing Char #13
2013-12-30 10:23:15,330 Parsing Char #14
2013-12-30 10:23:15,330 Parsing Char #15

<snip>

2013-12-30 10:24:45,751 End ParseInfo. Elapsed Time: 90904ms, characters: 6313

----------


Here is the SQL query it is parsing. Note that this same SQL query takes on average 10ms to parse under normal circumstances:

select merchantlo0_.id as id38_3_, merchantlo0_.account_userid as account16_38_3_, merchantlo0_.alwaysGenerateReceiptNumber as alwaysGe2_38_3_, merchantlo0_.alwaysShowKeyboard as alwaysSh3_38_3_, merchantlo0_.blindUserButton_id as blindUs17_38_3_, merchantlo0_.introHeaderImageName as introHea4_38_3_, merchantlo0_.numberedQueueablePrefix as numbered5_38_3_, merchantlo0_.phoneDisabled as phoneDis6_38_3_, merchantlo0_.phoneEnablingForecastDuration as phoneEna7_38_3_, merchantlo0_.phoneEnablingForecastQueue_id as phoneEn18_38_3_, merchantlo0_.printerArrowDirection as printerA8_38_3_, merchantlo0_.showConsumerInfoFirst as showCons9_38_3_, merchantlo0_.showQueueForecasts as showQue10_38_3_, merchantlo0_.showTransactionTypes as showTra11_38_3_, merchantlo0_.supportsConfirmationPage as support12_38_3_, merchantlo0_.supportsQueueAdditionalByName as support13_38_3_, merchantlo0_.supportsReceiptPrinting as support14_38_3_, merchantlo0_.useSmallerExitButton as useSmal15_38_3_, account1_.userid as userid92_0_, account1_.canChangePassword as canChang2_92_0_, account1_.failedLoginCount as failedLo3_92_0_, account1_.lastCredentialsChange as lastCred4_92_0_, account1_.lastFailedLogin as lastFail5_92_0_, account1_.lastLoginAddress as lastLogi6_92_0_, account1_.lastSuccessfulLogin as lastSucc7_92_0_, account1_.needsNewPassword as needsNew8_92_0_, account1_.password as password92_0_, account1_.root as root92_0_, blinduserb2_.id as id7_1_, blinduserb2_.height as height7_1_, blinduserb2_.width as width7_1_, blinduserb2_.x as x7_1_, blinduserb2_.y as y7_1_, queue3_.id as id5_2_, queue3_.SMSCarrier as SMSCarrier5_2_, queue3_.activatePattern as activate3_5_2_, queue3_.activateSchedule as activate4_5_2_, queue3_.appointmentsEnabled as appointm5_5_2_, queue3_.asksForNotesViaTextAfterJoin as asksForN6_5_2_, queue3_.audibleAlertsOnEnter as audibleA7_5_2_, queue3_.autoAddAsCallAhead as autoAddA8_5_2_, queue3_.autoIssueDuration as autoIssu9_5_2_, queue3_.autoIssueUnits as autoIss10_5_2_, queue3_.autoIssueCount as autoIss11_5_2_, queue3_.autoRedeem as autoRedeem5_2_, queue3_.autoRejoinAttempts as autoRej13_5_2_, queue3_.autoRejoinPushBack as autoRej14_5_2_, queue3_.bridgeCallsWhenSummoned as bridgeC15_5_2_, queue3_.capacity as capacity5_2_, queue3_.censorProfanities as censorP17_5_2_, queue3_.classifierCustomPropsMustMatch as classif18_5_2_, queue3_.clearEnabled as clearEn19_5_2_, queue3_.closePattern as closePa20_5_2_, queue3_.closeSchedule as closeSc21_5_2_, queue3_.confirmedTicketDuration as confirm22_5_2_, queue3_.confirmedTicketUnits as confirm23_5_2_, queue3_.crippledForInternational as cripple24_5_2_, queue3_.deactivatePattern as deactiv25_5_2_, queue3_.defaultAddChoice as default26_5_2_, queue3_.pushBackDuration as pushBac27_5_2_, queue3_.pushBackUnits as pushBac28_5_2_, queue3_.defaultStatusUpdateInterval as default29_5_2_, queue3_.description as descrip30_5_2_, queue3_.forecastRound as forecas31_5_2_, queue3_.forecastVariabilityTolerance as forecas32_5_2_, queue3_.forecastWindowSize as forecas33_5_2_, queue3_.getTicketClassifierFromEmployee as getTick34_5_2_, queue3_.hidden as hidden5_2_, queue3_.inactivateSchedule as inactiv36_5_2_, queue3_.initialWaitDuration as initial37_5_2_, queue3_.initialWaitUnits as initial38_5_2_, queue3_.issueNoShowTickets as issueNo39_5_2_, queue3_.kioskHardClosePattern as kioskHa40_5_2_, queue3_.kioskHardCloseSchedule as kioskHa41_5_2_, queue3_.location_id as location101_5_2_, queue3_.managingPort as managin42_5_2_, queue3_.managingServer as managin43_5_2_, queue3_.maxForecastDeltaPerTicket as maxFore44_5_2_, queue3_.maxPartySize as maxPart45_5_2_, queue3_.minPartySize as minPart46_5_2_, queue3_.minimumForecastDuration as minimum47_5_2_, queue3_.minimumForecastUnits as minimum48_5_2_, queue3_.monitorNameDisplay as monitor49_5_2_, queue3_.name as name5_2_, queue3_.notifyNoLaterThanDuration as notifyN51_5_2_, queue3_.notifyNoLaterThanUnits as notifyN52_5_2_, queue3_.notifyOnQueueActivity as notifyO53_5_2_, queue3_.onlyShowOwnOutstandingTickets as onlySho54_5_2_, queue3_.partySizeAffectsForecast as partySi55_5_2_, queue3_.password as password5_2_, queue3_.city as city5_2_, queue3_.country as country5_2_, queue3_.line1 as line59_5_2_, queue3_.line2 as line60_5_2_, queue3_.line3 as line61_5_2_, queue3_.postalCode as postalCode5_2_, queue3_.state as state5_2_, queue3_.latitude as latitude5_2_, queue3_.locName as locName5_2_, queue3_.longitude as longitude5_2_, queue3_.timeZone as timeZone5_2_, queue3_.pleaseReturnThreshold as pleaseR68_5_2_, queue3_.printNotecards as printNo69_5_2_, queue3_.privatePhoneDigitCount as private70_5_2_, queue3_.pushedStatusUpdatesDisabled as pushedS71_5_2_, queue3_.rejoinDuration as rejoinD72_5_2_, queue3_.rejoinUnits as rejoinU73_5_2_, queue3_.remoteJoinAsCallAhead as remoteJ74_5_2_, queue3_.remoteJoinDisabled as remoteJ75_5_2_, queue3_.requireNameViaText as require76_5_2_, queue3_.reservationDuration as reserva77_5_2_, queue3_.reservationUnits as reserva78_5_2_, queue3_.resourceDuration as resourc79_5_2_, queue3_.resourceUnits as resourc80_5_2_, queue3_.restrictJoins as restric81_5_2_, queue3_.seedWaitDuration as seedWai82_5_2_, queue3_.seedWaitUnits as seedWai83_5_2_, queue3_.sendTicketMessages as sendTic84_5_2_, queue3_.showNotecardPrinterDialog as showNot85_5_2_, queue3_.smsAutoJoin as smsAuto86_5_2_, queue3_.sponsorUrl as sponsorUrl5_2_, queue3_.supportsCallAhead as support88_5_2_, queue3_.targetTicketListSize as targetT89_5_2_, queue3_.ticketBasedOnPartySize as ticketB90_5_2_, queue3_.ticketBatchSize as ticketB91_5_2_, queue3_.nagDuration as nagDura92_5_2_, queue3_.nagUnits as nagUnits5_2_, queue3_.ticketPartySizeRanges as ticketP94_5_2_, queue3_.unconfirmedTicketDuration as unconfi95_5_2_, queue3_.unconfirmedTicketUnits as unconfi96_5_2_, queue3_.useConsumerCustomProps as useCons97_5_2_, queue3_.useLastSpotOverrideForecastAsNext as useLast98_5_2_, queue3_.voiceCarrier as voiceCa99_5_2_, queue3_.waitingForInterest as waitin100_5_2_ from MerchantLocationKioskInfo merchantlo0_ left outer join Account account1_ on merchantlo0_.account_userid=account1_.userid left outer join BlindUserButton blinduserb2_ on merchantlo0_.blindUserButton_id=blinduserb2_.id left outer join Queue queue3_ on merchantlo0_.phoneEnablingForecastQueue_id=queue3_.id where merchantlo0_.id=?,

Options: ReplyQuote


Subject
Written By
Posted
Re: CPU spikes and performance problems with Connector/J 5.1.12
December 30, 2013 01:20PM


Sorry, you can't reply to this topic. It has been closed.

Content reproduced on this site is the property of the respective copyright holders. It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.