• Open Menu Close Menu
  • Apple
  • Shopping Bag
  • Apple
  • Mac
  • iPad
  • iPhone
  • Watch
  • TV
  • Music
  • Support
  • Search apple.com
  • Shopping Bag

Lists

Open Menu Close Menu
  • Terms and Conditions
  • Lists hosted on this site
  • Email the Postmaster
  • Tips for posting to public mailing lists
Re: Long Fetch times
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

Re: Long Fetch times

  • Subject: Re: Long Fetch times
  • From: Jeff Schmitz <email@hidden>
  • Date: Sun, 14 Mar 2010 08:51:56 -0500
I'm still re-running the stress tests (they take awhile) but from some preliminary testing it's looking like the problem was not having enough indexes, although I'm not 100% sure why this problem decided to manifest now, maybe just the nature of my stress tests which I recently upgraded.

Adding the indexes Chuck suggested seems to have solved it. I probably need to do an entire analysis on where to add more indexes.

 THANKS for all your help here.

Jeff


On Mar 13, 2010, at 10:49 PM, Chuck Hill wrote:

Notice that of those queries, only _two_ take a significant amount of time. That is symptomatic of not having indexes that FB can use to optimize them.

SELECT whatever
	FROM "t_combo_team" t0
		INNER JOIN "t_entry" T1 ON t0."entryID" = T1."id"
		INNER JOIN "t_pool" T2 ON T1."poolID" = T2."id"
Those columns should all have indexes, but check to be sure

WHERE (T2."c_pool_type" = 0 AND T2."c_name" LIKE '00000HOGANS HOOPSTERS' COLLATE INFORMATION_SCHEMA.CASE_INSENSITIVE)

c_pool_type should probably be indexes
Using LIKE when not needed will take longer
c_name should probably be indexed

SELECT whatever
FROM "t_team_popup" t0
INNER JOIN "t_combo_team" T1 ON t0."comboTeamID" = T1."id"
INNER JOIN "t_entry" T2 ON T1."entryID" = T2."id"
INNER JOIN "t_pool" T3 ON T2."poolID" = T3."id"
WHERE (T3."c_name" LIKE '00000HOGANS HOOPSTERS' COLLATE INFORMATION_SCHEMA.CASE_INSENSITIVE AND T3."c_pool_type" = 0)

See above comments for this too.


Chuck

On Mar 13, 2010, at 8:22 PM, Jeff Schmitz wrote:

A little more info. Here's the actual code that is doing the long running fetch, followed by the sql generated by the code. Note there there isn't all that much data in the databaes, and the fetch itself finds no matches...

EOQualifier poolQual = Pool.POOL_TYPE.eq((int) poolType).and(
Pool.NAME.likeInsensitive(name));
ERXFetchSpecification poolFetch = new ERXFetchSpecification(_Pool.ENTITY_NAME, poolQual, null);

NSArray <String> keyPaths = new NSArray(new String[] {Pool.ENTRIES_KEY ,
Pool.ENTRIES_KEY + "." + Entry.COMBO_TEAMS_KEY,
Pool.ENTRIES_KEY + "." + Entry.COMBO_TEAMS_KEY + "." + ComboTeam.TEAM_POPUPS_KEY,
Pool.ENTRIES_KEY + "." + Entry.ENTRY_ADMIN_KEY});

poolFetch.setPrefetchingRelationshipKeyPaths(keyPaths);
Pool pool = (Pool) ec.objectsWithFetchSpecification(poolFetch).lastObject();
return pool;


Mar 13 22:15:58 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Begin Internal Transaction
Mar 13 22:15:58 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - evaluateExpression: <com.webobjects.jdbcadaptor._FrontBasePlugIn$FrontbaseExpression: "SELECT t0."c_admin_email", t0."c_admin_msg", t0."c_admin_pw", t0."c_calculating_can_i_wins", t0."c_can_i_win_index", t0."c_can_i_wins_calculated", t0."c_early_bird_paid", t0."c_entry_limit", t0."id", t0."c_name", t0."c_paid", t0."c_password", t0."c_pool_type", t0."c_results_index", t0."c_seed_type", t0."c_spare_string", t0."c_stand_alone", t0."c_ud_bonus", t0."c_updating_results", t0."c_weighted" FROM "t_pool" t0 WHERE (t0."c_pool_type" = 0 AND t0."c_name" LIKE '00000HOGANS HOOPSTERS' COLLATE INFORMATION_SCHEMA.CASE_INSENSITIVE)" withBindings: >
Mar 13 22:15:58 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - 1 row(s) processed
Mar 13 22:15:58 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Commit Internal Transaction
Mar 13 22:15:58 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Begin Internal Transaction
Mar 13 22:15:58 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - evaluateExpression: <com.webobjects.jdbcadaptor._FrontBasePlugIn$FrontbaseExpression: "SELECT t0."c_games", t0."c_groups", t0."id", t0."c_last_save", t0."c_name", t0."c_password", t0."c_picks_confirmed", t0."poolID", t0."c_real", t0."spare_bool", t0."spare_int", t0."spare_str", t0."c_still_alive_first", t0."c_still_alive_second", t0."c_still_alive_third", t0."c_tie_breaker", t0."userID" FROM "t_entry" t0 INNER JOIN "t_pool" T1 ON t0."poolID" = T1."id" WHERE (T1."c_name" LIKE '00000HOGANS HOOPSTERS' COLLATE INFORMATION_SCHEMA.CASE_INSENSITIVE AND T1."c_pool_type" = 0)" withBindings: >
Mar 13 22:15:58 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - 2 row(s) processed
Mar 13 22:15:58 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Commit Internal Transaction
Mar 13 22:15:58 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Begin Internal Transaction
Mar 13 22:15:58 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - evaluateExpression: <com.webobjects.jdbcadaptor._FrontBasePlugIn$FrontbaseExpression: "SELECT t0."entryID", t0."c_game", t0."c_group", t0."id", t0."c_items", t0."c_score", t0."c_selected_item", t0."c_selected_weight" FROM "t_combo_team" t0 INNER JOIN "t_entry" T1 ON t0."entryID" = T1."id" INNER JOIN "t_pool" T2 ON T1."poolID" = T2."id" WHERE (T2."c_pool_type" = 0 AND T2."c_name" LIKE '00000HOGANS HOOPSTERS' COLLATE INFORMATION_SCHEMA.CASE_INSENSITIVE)" withBindings: >
Mar 13 22:16:07 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - 126 row(s) processed
Mar 13 22:16:07 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Commit Internal Transaction
Mar 13 22:16:07 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Begin Internal Transaction
Mar 13 22:16:07 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - evaluateExpression: <com.webobjects.jdbcadaptor._FrontBasePlugIn$FrontbaseExpression: "SELECT t0."c_combo_index", t0."comboTeamID", t0."c_group", t0."id", t0."c_pool_type", t0."c_seed", t0."c_team_id", t0."c_team_pos" FROM "t_team_popup" t0 INNER JOIN "t_combo_team" T1 ON t0."comboTeamID" = T1."id" INNER JOIN "t_entry" T2 ON T1."entryID" = T2."id" INNER JOIN "t_pool" T3 ON T2."poolID" = T3."id" WHERE (T3."c_name" LIKE '00000HOGANS HOOPSTERS' COLLATE INFORMATION_SCHEMA.CASE_INSENSITIVE AND T3."c_pool_type" = 0)" withBindings: >
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - 315 row(s) processed
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Commit Internal Transaction
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Begin Internal Transaction
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - evaluateExpression: <com.webobjects.jdbcadaptor._FrontBasePlugIn$FrontbaseExpression: "SELECT t0."c_admin_ok", t0."id", t0."c_late_pick" FROM "t_entry_admin" t0 INNER JOIN "t_entry" T1 ON t0."id" = T1."id" INNER JOIN "t_pool" T2 ON T1."poolID" = T2."id" WHERE (T2."c_pool_type" = 0 AND T2."c_name" LIKE '00000HOGANS HOOPSTERS' COLLATE INFORMATION_SCHEMA.CASE_INSENSITIVE)" withBindings: >
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - 2 row(s) processed
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Commit Internal Transaction
FileIO64 calcPickInfo - Time to prefetch entries: 41.847
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Begin Internal Transaction
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - evaluateExpression: <com.webobjects.jdbcadaptor._FrontBasePlugIn$FrontbaseExpression: "SELECT t0."c_admin_msg", t0."c_allow_picks", t0."c_final_game_points", t0."c_first_round", t0."c_forum_link", t0."id", t0."maintenance", t0."new_pools_accepted", t0."c_open_picks", t0."c_open_pools", t0."c_pick_info_threshold", t0."c_pool_dir", t0."c_pool_type", t0."c_price_per_entry", t0."c_show_only_paid", t0."spareBool", t0."spareString", t0."tenPercentCoupon" FROM "t_application_state" t0 WHERE t0."c_pool_type" = 0" withBindings: >
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - 1 row(s) processed
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Commit Internal Transaction
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Begin Internal Transaction
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - evaluateExpression: <com.webobjects.jdbcadaptor._FrontBasePlugIn$FrontbaseExpression: "SELECT t0."c_admin_msg", t0."c_allow_picks", t0."c_final_game_points", t0."c_first_round", t0."c_forum_link", t0."id", t0."maintenance", t0."new_pools_accepted", t0."c_open_picks", t0."c_open_pools", t0."c_pick_info_threshold", t0."c_pool_dir", t0."c_pool_type", t0."c_price_per_entry", t0."c_show_only_paid", t0."spareBool", t0."spareString", t0."tenPercentCoupon" FROM "t_application_state" t0 WHERE t0."c_pool_type" = 0" withBindings: >
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - 1 row(s) processed
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Commit Internal Transaction
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Begin Internal Transaction
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - evaluateExpression: <com.webobjects.jdbcadaptor._FrontBasePlugIn$FrontbaseExpression: "SELECT t0."c_admin_msg", t0."c_allow_picks", t0."c_final_game_points", t0."c_first_round", t0."c_forum_link", t0."id", t0."maintenance", t0."new_pools_accepted", t0."c_open_picks", t0."c_open_pools", t0."c_pick_info_threshold", t0."c_pool_dir", t0."c_pool_type", t0."c_price_per_entry", t0."c_show_only_paid", t0."spareBool", t0."spareString", t0."tenPercentCoupon" FROM "t_application_state" t0 WHERE t0."c_pool_type" = 0" withBindings: >
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - 1 row(s) processed
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Commit Internal Transaction
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Begin Internal Transaction
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - evaluateExpression: <com.webobjects.jdbcadaptor._FrontBasePlugIn$FrontbaseExpression: "SELECT t0."c_admin_msg", t0."c_allow_picks", t0."c_final_game_points", t0."c_first_round", t0."c_forum_link", t0."id", t0."maintenance", t0."new_pools_accepted", t0."c_open_picks", t0."c_open_pools", t0."c_pick_info_threshold", t0."c_pool_dir", t0."c_pool_type", t0."c_price_per_entry", t0."c_show_only_paid", t0."spareBool", t0."spareString", t0."tenPercentCoupon" FROM "t_application_state" t0 WHERE t0."c_pool_type" = 0" withBindings: >
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - 1 row(s) processed
Mar 13 22:16:39 netBrackets[9999] (ERXNSLogLog4jBridge.java:46) DEBUG NSLog - === Commit Internal Transaction
FileIO64 calcPickInfo - Time to calc 00000HOGANS HOOPSTERS with 0 entries: 41.948
On Mar 13, 2010, at 8:59 PM, Gaastra Dennis - WO Lists wrote:

Some things coming to my mind:

1) Are you using a lot of indices and/or compound indices? Sometimes when you have large tables, loading those indices the first time, takes a while. So there is a fine balance between too many and not enough indices; we have noticed with FB. As such, after every server restart, we "warm up" the database to get it going.

2) If your DB is too fragmented, consider writing it to a flat- file, and restoring it; as shown in the FB docs.

3) How is your underlying storage medium doing? Enough free disk space? Consider deploying on SSDs.

With Kind Regards,

Dennis Gaastra,
Chief Technology Officer,
WEBAPPZ®  Systems, Inc.





On 2010-03-13, at 4:44 PM, Jeff Schmitz wrote:

While running some stress tests I seem to be able to get my database (Frontbase) in a state where fetch times take an inordinate amount of time (e.g. fetches that return no rows take a minute), and once in that state, even a reboot of the machine won't fix the problem. Is there anyway to recover such a database? I'll be perusing the Frontbase for any ideas, but from experience, is such behavior symptomatic of any particular problem? I've been running several years and haven't until now seen such behavior.

Thanks,
Jeff
_______________________________________________
Do not post admin requests to the list. They will be ignored.
Webobjects-dev mailing list      (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden



_______________________________________________
Do not post admin requests to the list. They will be ignored.
Webobjects-dev mailing list      (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden


--
Chuck Hill             Senior Consultant / VP Development

Practical WebObjects - for developers who want to increase their overall knowledge of WebObjects or who are trying to solve specific problems.
http://www.global-village.net/products/practical_webobjects








_______________________________________________
Do not post admin requests to the list. They will be ignored.
Webobjects-dev mailing list      (email@hidden)
Help/Unsubscribe/Update your Subscription:
This email sent to email@hidden




  • Follow-Ups:

      

    • Re: Long Fetch times

      • From: Chuck Hill <email@hidden>
      • 





References: 


 >Long Fetch times (From: Jeff Schmitz <email@hidden>)


 >Re: Long Fetch times (From: Gaastra Dennis - WO Lists <email@hidden>)


 >Re: Long Fetch times (From: Jeff Schmitz <email@hidden>)


 >Re: Long Fetch times (From: Chuck Hill <email@hidden>)






    

  • Prev by Date:
Re: WOXMLDecoder NullPointerException

    • 

  • Next by Date:
TinyMCE and ajax

    • 

  • Previous by thread:
Re: Long Fetch times

    • 

  • Next by thread:
Re: Long Fetch times

    • 

  • Index(es):

      

    • Date
      • 

    • Thread
      • 

    

    •