search

kclay / rethink-scala

Scala Driver for RethinkDB
Other
100 stars 24 forks source link

GetAll by index call fails sometimes, succeeds other times. #31

Closed SMcClelland closed 9 years ago

SMcClelland commented 9 years ago

Hi,

I am having an issue where one of my getall table calls (using a secondary index) fails randomly. Id say its 50/50 between failing and succeeding. I am using 0.4.7-SNAPSHOT.

Here is what a successful call looks like:

[2015-04-09T17:36:35.516778600Z] INFO ForkJoinPool-4-worker-1 - start[1428600994086] time[1378] tag[OCR results are in] [2015-04-09T17:36:35.516778600Z] INFO application-akka.actor.default-dispatcher-2 - start[1428600995465] time[16] tag[EnglishGrammarProcessor:scanText completed] [2015-04-09T17:36:35.516778600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing GetAll(Table(ingredients,None,Some(DB(food_focus))),ArrayBuffer(enriched flour_dced0372-9469-4940-96fe-2e0a72d38329, flour_dced0372-9469-4940-96fe-2e0a72d38329, enriched_dced0372-9469-4940-96fe-2e0a72d38329, niacin_dced0372-9469-4940-96fe-2e0a72d38329, iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, bl_dced0372-9469-4940-96fe-2e0a72d38329, vitamin bl_dced0372-9469-4940-96fe-2e0a72d38329, b2_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, vitamin b2_dced0372-9469-4940-96fe-2e0a72d38329, riboflavin)_dced0372-9469-4940-96fe-2e0a72d38329, folic_dced0372-9469-4940-96fe-2e0a72d38329, acid_dced0372-9469-4940-96fe-2e0a72d38329, folic acid_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, vegetable_dced0372-9469-4940-96fe-2e0a72d38329, vegetable [2015-04-09T17:36:35.516778600Z] oil_dced0372-9469-4940-96fe-2e0a72d38329, partially hydrogenated palm kernel and/or [2015-04-09T17:36:35.516778600Z] cottonseed oil_dced0372-9469-4940-96fe-2e0a72d38329, kernel_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, partially_dced0372-9469-4940-96fe-2e0a72d38329, hydrogenated_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cottonseed_dced0372-9469-4940-96fe-2e0a72d38329, and/or_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean and palm oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, color_dced0372-9469-4940-96fe-2e0a72d38329, caramel color_dced0372-9469-4940-96fe-2e0a72d38329, caramel_dced0372-9469-4940-96fe-2e0a72d38329, 2%_dced0372-9469-4940-96fe-2e0a72d38329, or_dced0372-9469-4940-96fe-2e0a72d38329, leavening_dced0372-9469-4940-96fe-2e0a72d38329, contains 2% or less of leavening_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329, less_dced0372-9469-4940-96fe-2e0a72d38329, contains_dced0372-9469-4940-96fe-2e0a72d38329, baking_dced0372-9469-4940-96fe-2e0a72d38329, baking soda_dced0372-9469-4940-96fe-2e0a72d38329, soda_dced0372-9469-4940-96fe-2e0a72d38329, phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium_dced0372-9469-4940-96fe-2e0a72d38329, cocoa [2015-04-09T17:36:35.516778600Z] processed with alkali_dced0372-9469-4940-96fe-2e0a72d38329, alkali_dced0372-9469-4940-96fe-2e0a72d38329, processed_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, with_dced0372-9469-4940-96fe-2e0a72d38329, invert_dced0372-9469-4940-96fe-2e0a72d38329, invert sugar_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, cornstarch_dced0372-9469-4940-96fe-2e0a72d38329, salt_dced0372-9469-4940-96fe-2e0a72d38329, soy lecithin_dced0372-9469-4940-96fe-2e0a72d38329, soy_dced0372-9469-4940-96fe-2e0a72d38329, lecithin_dced0372-9469-4940-96fe-2e0a72d38329, natural and artificial flavors_dced0372-9469-4940-96fe-2e0a72d38329, natural_dced0372-9469-4940-96fe-2e0a72d38329, flavors_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, artificial_dced0372-9469-4940-96fe-2e0a72d38329, oil of_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329),Some(alternateNameAndDietaryPreferenceId)) [2015-04-09T17:36:35.516778600Z] [debug] c.r.u.SimpleConnectionPool - No connectionId executing [2015-04-09T17:36:35.516778600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Logger already configured [2015-04-09T17:36:35.516778600Z] [debug] c.r.u.SimpleConnectionPool - Entering executing block for (1}) [2015-04-09T17:36:35.516778600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Received connection from pool [2015-04-09T17:36:35.516778600Z] [debug] c.r.u.SimpleConnectionPool - Exiting executing block for (1 [2015-04-09T17:36:35.516778600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Channel Future completed [2015-04-09T17:36:35.516778600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating query [2015-04-09T17:36:35.516778600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating connection attachment [2015-04-09T17:36:35.516778600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing query [2015-04-09T17:36:35.516778600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Wrote query [2015-04-09T17:36:35.550039100Z] [debug] c.r.n.JsonFrameDecoder - Decoding Frame TOKEN = 3 LENGTH = 507 [2015-04-09T17:36:35.550039100Z] [debug] c.r.n.JsonFrameDecoder - JSON = {"t":3,"r":[{"alternate_names":["sugar","azucar"],"id":"2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf","name":"sugar","severities":[{"description":"Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.","dietary_preference_id":"7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673","severity":20},{"description":"Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.","dietary_preference_id":"dced0372-9469-4940-96fe-2e0a72d38329","severity" [2015-04-09T17:36:35.550039100Z] [debug] c.r.n.JsonVersionHandler - handle(3) = {"t":3,"r":[{"alternate_names":["sugar","azucar"],"id":"2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf","name":"sugar","severities":[{"description":"Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.","dietary_preference_id":"7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673","severity":20},{"description":"Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.","dietary_preference_id":"dced0372-9469-4940-96fe-2e0a72d38329","severity":20}]}]} [2015-04-09T17:36:35.552033100Z] [debug] c.r.n.AsyncConnection$$anon$1 - Restoring connection (1) [2015-04-09T17:36:35.552705200Z] [debug] c.r.u.SimpleConnectionPool - giveBack(connection:1) [2015-04-09T17:36:35.553392400Z] [debug] c.r.u.SimpleConnectionPool - drain(connection:1) empty [2015-04-09T17:36:35.554532300Z] INFO ForkJoinPool-4-worker-1 - start[1428600995489] time[64] tag[IngredientsProcessorActor::DB Results are in] [2015-04-09T17:36:35.555473000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing Count(GetAll(Table(ingredients,None,Some(DB(food_focus))),ArrayBuffer(enriched flour_dced0372-9469-4940-96fe-2e0a72d38329, flour_dced0372-9469-4940-96fe-2e0a72d38329, enriched_dced0372-9469-4940-96fe-2e0a72d38329, niacin_dced0372-9469-4940-96fe-2e0a72d38329, iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, bl_dced0372-9469-4940-96fe-2e0a72d38329, vitamin bl_dced0372-9469-4940-96fe-2e0a72d38329, b2_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, vitamin b2_dced0372-9469-4940-96fe-2e0a72d38329, riboflavin)_dced0372-9469-4940-96fe-2e0a72d38329, folic_dced0372-9469-4940-96fe-2e0a72d38329, acid_dced0372-9469-4940-96fe-2e0a72d38329, folic acid_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, vegetable_dced0372-9469-4940-96fe-2e0a72d38329, vegetable [2015-04-09T17:36:35.555473000Z] oil_dced0372-9469-4940-96fe-2e0a72d38329, partially hydrogenated palm kernel and/or [2015-04-09T17:36:35.555473000Z] cottonseed oil_dced0372-9469-4940-96fe-2e0a72d38329, kernel_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, partially_dced0372-9469-4940-96fe-2e0a72d38329, hydrogenated_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cottonseed_dced0372-9469-4940-96fe-2e0a72d38329, and/or_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean and palm oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, color_dced0372-9469-4940-96fe-2e0a72d38329, caramel color_dced0372-9469-4940-96fe-2e0a72d38329, caramel_dced0372-9469-4940-96fe-2e0a72d38329, 2%_dced0372-9469-4940-96fe-2e0a72d38329, or_dced0372-9469-4940-96fe-2e0a72d38329, leavening_dced0372-9469-4940-96fe-2e0a72d38329, contains 2% or less of leavening_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329, less_dced0372-9469-4940-96fe-2e0a72d38329, contains_dced0372-9469-4940-96fe-2e0a72d38329, baking_dced0372-9469-4940-96fe-2e0a72d38329, baking soda_dced0372-9469-4940-96fe-2e0a72d38329, soda_dced0372-9469-4940-96fe-2e0a72d38329, phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium_dced0372-9469-4940-96fe-2e0a72d38329, cocoa [2015-04-09T17:36:35.555473000Z] processed with alkali_dced0372-9469-4940-96fe-2e0a72d38329, alkali_dced0372-9469-4940-96fe-2e0a72d38329, processed_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, with_dced0372-9469-4940-96fe-2e0a72d38329, invert_dced0372-9469-4940-96fe-2e0a72d38329, invert sugar_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, cornstarch_dced0372-9469-4940-96fe-2e0a72d38329, salt_dced0372-9469-4940-96fe-2e0a72d38329, soy lecithin_dced0372-9469-4940-96fe-2e0a72d38329, soy_dced0372-9469-4940-96fe-2e0a72d38329, lecithin_dced0372-9469-4940-96fe-2e0a72d38329, natural and artificial flavors_dced0372-9469-4940-96fe-2e0a72d38329, natural_dced0372-9469-4940-96fe-2e0a72d38329, flavors_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, artificial_dced0372-9469-4940-96fe-2e0a72d38329, oil of_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329),Some(alternateNameAndDietaryPreferenceId)),None) [2015-04-09T17:36:35.556724500Z] [debug] c.r.u.SimpleConnectionPool - No connectionId executing [2015-04-09T17:36:35.557404900Z] [debug] c.r.n.AsyncConnection$$anon$1 - Logger already configured [2015-04-09T17:36:35.557773500Z] [debug] c.r.u.SimpleConnectionPool - Entering executing block for (1}) [2015-04-09T17:36:35.558400200Z] [debug] c.r.n.AsyncConnection$$anon$1 - Received connection from pool [2015-04-09T17:36:35.558807200Z] [debug] c.r.u.SimpleConnectionPool - Exiting executing block for (1 [2015-04-09T17:36:35.559646800Z] [debug] c.r.n.JsonVersionHandler - Results = () [2015-04-09T17:36:35.560035500Z] [debug] c.r.n.AsyncConnection$$anon$1 - Channel Future completed [2015-04-09T17:36:35.560459700Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating query [2015-04-09T17:36:35.566692300Z] [info] application - getIngredientsByIngredientsAndDietaryPreferenceIds DB call successful [2015-04-09T17:36:35.568274700Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating connection attachment [2015-04-09T17:36:35.568591700Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing query [2015-04-09T17:36:35.571811300Z] [debug] c.r.n.AsyncConnection$$anon$1 - Wrote query [2015-04-09T17:36:35.727235000Z] [debug] c.r.n.JsonFrameDecoder - Decoding Frame TOKEN = 4 LENGTH = 15 [2015-04-09T17:36:35.727442800Z] [debug] c.r.n.JsonFrameDecoder - JSON = {"t":1,"r":[2]} [2015-04-09T17:36:35.727855600Z] [debug] c.r.n.JsonVersionHandler - handle(4) = {"t":1,"r":[2]} [2015-04-09T17:36:35.728255000Z] [debug] c.r.n.JsonVersionHandler - Results = () [2015-04-09T17:36:35.728796900Z] [debug] c.r.n.AsyncConnection$$anon$1 - Restoring connection (1) [2015-04-09T17:36:35.728952900Z] [debug] c.r.u.SimpleConnectionPool - giveBack(connection:1) [2015-04-09T17:36:35.729248400Z] [debug] c.r.u.SimpleConnectionPool - drain(connection:1) empty [2015-04-09T17:36:35.729568100Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing Continue(3) [2015-04-09T17:36:35.729930400Z] [debug] c.r.u.SimpleConnectionPool - Connection found and not active [2015-04-09T17:36:35.730249800Z] [debug] c.r.n.AsyncConnection$$anon$1 - Logger already configured [2015-04-09T17:36:35.730596000Z] [debug] c.r.u.SimpleConnectionPool - Entering executing block for (1}) [2015-04-09T17:36:35.730890200Z] [debug] c.r.n.AsyncConnection$$anon$1 - Received connection from pool [2015-04-09T17:36:35.731047300Z] [debug] c.r.u.SimpleConnectionPool - Exiting executing block for (1 [2015-04-09T17:36:35.731422000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Channel Future completed [2015-04-09T17:36:35.731704000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating query [2015-04-09T17:36:35.736046600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating connection attachment [2015-04-09T17:36:35.736230000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing query [2015-04-09T17:36:35.736842900Z] [debug] c.r.n.AsyncConnection$$anon$1 - Wrote query [2015-04-09T17:36:35.845373900Z] [debug] c.r.n.JsonFrameDecoder - Decoding Frame TOKEN = 3 LENGTH = 507 [2015-04-09T17:36:35.845570300Z] [debug] c.r.n.JsonFrameDecoder - JSON = {"t":3,"r":[{"alternate_names":["sugar","azucar"],"id":"2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf","name":"sugar","severities":[{"description":"Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.","dietary_preference_id":"7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673","severity":20},{"description":"Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.","dietary_preference_id":"dced0372-9469-4940-96fe-2e0a72d38329","severity" [2015-04-09T17:36:35.846035400Z] [debug] c.r.n.JsonVersionHandler - handle(3) = {"t":3,"r":[{"alternate_names":["sugar","azucar"],"id":"2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf","name":"sugar","severities":[{"description":"Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.","dietary_preference_id":"7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673","severity":20},{"description":"Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.","dietary_preference_id":"dced0372-9469-4940-96fe-2e0a72d38329","severity":20}]}]} [2015-04-09T17:36:35.847129700Z] [debug] c.r.n.AsyncConnection$$anon$1 - Restoring connection (1) [2015-04-09T17:36:35.847518300Z] [debug] c.r.u.SimpleConnectionPool - giveBack(connection:1) [2015-04-09T17:36:35.847659200Z] [debug] c.r.u.SimpleConnectionPool - drain(connection:1) empty [2015-04-09T17:36:35.848350800Z] Right(DefaultCursor(Ingredient(2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf,sugar,List(sugar, azucar),null,List(Severity(null,Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.,7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673,20), Severity(null,Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.,dced0372-9469-4940-96fe-2e0a72d38329,20))), Ingredient(2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf,sugar,List(sugar, azucar),null,List(Severity(null,Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.,7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673,20), Severity(null,Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.,dced0372-9469-4940-96fe-2e0a72d38329,20))))) [2015-04-09T17:36:35.854313600Z] [debug] c.r.n.JsonVersionHandler - Results = ()

Here is what an unsuccessful call looks like:

[2015-04-09T17:39:37.845912500Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing GetAll(Table(ingredients,None,Some(DB(food_focus))),ArrayBuffer(enriched flour_dced0372-9469-4940-96fe-2e0a72d38329, flour_dced0372-9469-4940-96fe-2e0a72d38329, enriched_dced0372-9469-4940-96fe-2e0a72d38329, niacin_dced0372-9469-4940-96fe-2e0a72d38329, iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, bl_dced0372-9469-4940-96fe-2e0a72d38329, vitamin bl_dced0372-9469-4940-96fe-2e0a72d38329, b2_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, vitamin b2_dced0372-9469-4940-96fe-2e0a72d38329, riboflavin)_dced0372-9469-4940-96fe-2e0a72d38329, folic_dced0372-9469-4940-96fe-2e0a72d38329, acid_dced0372-9469-4940-96fe-2e0a72d38329, folic acid_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, vegetable_dced0372-9469-4940-96fe-2e0a72d38329, vegetable [2015-04-09T17:39:37.845912500Z] oil_dced0372-9469-4940-96fe-2e0a72d38329, partially hydrogenated palm kernel and/or [2015-04-09T17:39:37.845912500Z] cottonseed oil_dced0372-9469-4940-96fe-2e0a72d38329, kernel_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, partially_dced0372-9469-4940-96fe-2e0a72d38329, hydrogenated_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cottonseed_dced0372-9469-4940-96fe-2e0a72d38329, and/or_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean and palm oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, color_dced0372-9469-4940-96fe-2e0a72d38329, caramel color_dced0372-9469-4940-96fe-2e0a72d38329, caramel_dced0372-9469-4940-96fe-2e0a72d38329, 2%_dced0372-9469-4940-96fe-2e0a72d38329, or_dced0372-9469-4940-96fe-2e0a72d38329, leavening_dced0372-9469-4940-96fe-2e0a72d38329, contains 2% or less of leavening_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329, less_dced0372-9469-4940-96fe-2e0a72d38329, contains_dced0372-9469-4940-96fe-2e0a72d38329, baking_dced0372-9469-4940-96fe-2e0a72d38329, baking soda_dced0372-9469-4940-96fe-2e0a72d38329, soda_dced0372-9469-4940-96fe-2e0a72d38329, phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium_dced0372-9469-4940-96fe-2e0a72d38329, cocoa [2015-04-09T17:39:37.845912500Z] processed with alkali_dced0372-9469-4940-96fe-2e0a72d38329, alkali_dced0372-9469-4940-96fe-2e0a72d38329, processed_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, with_dced0372-9469-4940-96fe-2e0a72d38329, invert_dced0372-9469-4940-96fe-2e0a72d38329, invert sugar_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, cornstarch_dced0372-9469-4940-96fe-2e0a72d38329, salt_dced0372-9469-4940-96fe-2e0a72d38329, soy lecithin_dced0372-9469-4940-96fe-2e0a72d38329, soy_dced0372-9469-4940-96fe-2e0a72d38329, lecithin_dced0372-9469-4940-96fe-2e0a72d38329, natural and artificial flavors_dced0372-9469-4940-96fe-2e0a72d38329, natural_dced0372-9469-4940-96fe-2e0a72d38329, flavors_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, artificial_dced0372-9469-4940-96fe-2e0a72d38329, oil of_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329),Some(alternateNameAndDietaryPreferenceId)) [2015-04-09T17:39:37.846743500Z] [debug] c.r.u.SimpleConnectionPool - No connectionId executing [2015-04-09T17:39:37.847062000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Logger already configured [2015-04-09T17:39:37.847455500Z] [debug] c.r.u.SimpleConnectionPool - Entering executing block for (1}) [2015-04-09T17:39:37.847572700Z] [debug] c.r.n.AsyncConnection$$anon$1 - Received connection from pool [2015-04-09T17:39:37.847877900Z] [debug] c.r.u.SimpleConnectionPool - Exiting executing block for (1 [2015-04-09T17:39:37.848096500Z] [debug] c.r.n.AsyncConnection$$anon$1 - Channel Future completed [2015-04-09T17:39:37.848363900Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating query [2015-04-09T17:39:37.849526800Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating connection attachment [2015-04-09T17:39:37.849839800Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing query [2015-04-09T17:39:37.850802700Z] [debug] c.r.n.AsyncConnection$$anon$1 - Wrote query [2015-04-09T17:39:37.892437400Z] [debug] c.r.n.JsonFrameDecoder - Decoding Frame TOKEN = 5 LENGTH = 507 [2015-04-09T17:39:37.892801700Z] [debug] c.r.n.JsonFrameDecoder - JSON = {"t":3,"r":[{"alternate_names":["sugar","azucar"],"id":"2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf","name":"sugar","severities":[{"description":"Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.","dietary_preference_id":"7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673","severity":20},{"description":"Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.","dietary_preference_id":"dced0372-9469-4940-96fe-2e0a72d38329","severity" [2015-04-09T17:39:37.893148500Z] [debug] c.r.n.JsonVersionHandler - handle(5) = {"t":3,"r":[{"alternate_names":["sugar","azucar"],"id":"2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf","name":"sugar","severities":[{"description":"Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.","dietary_preference_id":"7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673","severity":20},{"description":"Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.","dietary_preference_id":"dced0372-9469-4940-96fe-2e0a72d38329","severity":20}]}]} [2015-04-09T17:39:37.894427400Z] [debug] c.r.n.AsyncConnection$$anon$1 - Restoring connection (1) [2015-04-09T17:39:37.894822400Z] [debug] c.r.u.SimpleConnectionPool - giveBack(connection:1) [2015-04-09T17:39:37.894968400Z] [debug] c.r.u.SimpleConnectionPool - drain(connection:1) empty [2015-04-09T17:39:37.896908800Z] INFO ForkJoinPool-4-worker-1 - start[1428601177837] time[57] tag[IngredientsProcessorActor::DB Results are in] [2015-04-09T17:39:37.897500000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing Count(GetAll(Table(ingredients,None,Some(DB(food_focus))),ArrayBuffer(enriched flour_dced0372-9469-4940-96fe-2e0a72d38329, flour_dced0372-9469-4940-96fe-2e0a72d38329, enriched_dced0372-9469-4940-96fe-2e0a72d38329, niacin_dced0372-9469-4940-96fe-2e0a72d38329, iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, bl_dced0372-9469-4940-96fe-2e0a72d38329, vitamin bl_dced0372-9469-4940-96fe-2e0a72d38329, b2_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, vitamin b2_dced0372-9469-4940-96fe-2e0a72d38329, riboflavin)_dced0372-9469-4940-96fe-2e0a72d38329, folic_dced0372-9469-4940-96fe-2e0a72d38329, acid_dced0372-9469-4940-96fe-2e0a72d38329, folic acid_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, vegetable_dced0372-9469-4940-96fe-2e0a72d38329, vegetable [2015-04-09T17:39:37.897500000Z] oil_dced0372-9469-4940-96fe-2e0a72d38329, partially hydrogenated palm kernel and/or [2015-04-09T17:39:37.897500000Z] cottonseed oil_dced0372-9469-4940-96fe-2e0a72d38329, kernel_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, partially_dced0372-9469-4940-96fe-2e0a72d38329, hydrogenated_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cottonseed_dced0372-9469-4940-96fe-2e0a72d38329, and/or_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean and palm oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, color_dced0372-9469-4940-96fe-2e0a72d38329, caramel color_dced0372-9469-4940-96fe-2e0a72d38329, caramel_dced0372-9469-4940-96fe-2e0a72d38329, 2%_dced0372-9469-4940-96fe-2e0a72d38329, or_dced0372-9469-4940-96fe-2e0a72d38329, leavening_dced0372-9469-4940-96fe-2e0a72d38329, contains 2% or less of leavening_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329, less_dced0372-9469-4940-96fe-2e0a72d38329, contains_dced0372-9469-4940-96fe-2e0a72d38329, baking_dced0372-9469-4940-96fe-2e0a72d38329, baking soda_dced0372-9469-4940-96fe-2e0a72d38329, soda_dced0372-9469-4940-96fe-2e0a72d38329, phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium_dced0372-9469-4940-96fe-2e0a72d38329, cocoa [2015-04-09T17:39:37.897500000Z] processed with alkali_dced0372-9469-4940-96fe-2e0a72d38329, alkali_dced0372-9469-4940-96fe-2e0a72d38329, processed_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, with_dced0372-9469-4940-96fe-2e0a72d38329, invert_dced0372-9469-4940-96fe-2e0a72d38329, invert sugar_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, cornstarch_dced0372-9469-4940-96fe-2e0a72d38329, salt_dced0372-9469-4940-96fe-2e0a72d38329, soy lecithin_dced0372-9469-4940-96fe-2e0a72d38329, soy_dced0372-9469-4940-96fe-2e0a72d38329, lecithin_dced0372-9469-4940-96fe-2e0a72d38329, natural and artificial flavors_dced0372-9469-4940-96fe-2e0a72d38329, natural_dced0372-9469-4940-96fe-2e0a72d38329, flavors_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, artificial_dced0372-9469-4940-96fe-2e0a72d38329, oil of_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329),Some(alternateNameAndDietaryPreferenceId)),None) [2015-04-09T17:39:37.898260000Z] [debug] c.r.u.SimpleConnectionPool - No connectionId executing [2015-04-09T17:39:37.898445700Z] [debug] c.r.n.JsonVersionHandler - Results = () [2015-04-09T17:39:37.898824100Z] [debug] c.r.n.AsyncConnection$$anon$1 - Logger already configured [2015-04-09T17:39:37.898956000Z] [debug] c.r.u.SimpleConnectionPool - Entering executing block for (1}) [2015-04-09T17:39:37.899238500Z] [debug] c.r.n.AsyncConnection$$anon$1 - Received connection from pool [2015-04-09T17:39:37.899502600Z] [debug] c.r.u.SimpleConnectionPool - Exiting executing block for (1 [2015-04-09T17:39:37.899804900Z] [debug] c.r.n.AsyncConnection$$anon$1 - Channel Future completed [2015-04-09T17:39:37.900038600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating query [2015-04-09T17:39:37.900741600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating connection attachment [2015-04-09T17:39:37.901127900Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing query [2015-04-09T17:39:37.902047400Z] [debug] c.r.n.AsyncConnection$$anon$1 - Wrote query [2015-04-09T17:39:37.907779300Z] [info] application - getIngredientsByIngredientsAndDietaryPreferenceIds DB call successful [2015-04-09T17:39:38.057060300Z] [debug] c.r.n.JsonFrameDecoder - Decoding Frame TOKEN = 6 LENGTH = 15 [2015-04-09T17:39:38.057244900Z] [debug] c.r.n.JsonFrameDecoder - JSON = {"t":1,"r":[2]} [2015-04-09T17:39:38.057648400Z] [debug] c.r.n.JsonVersionHandler - handle(6) = {"t":1,"r":[2]} [2015-04-09T17:39:38.060272000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing Continue(5) [2015-04-09T17:39:38.060623900Z] [debug] c.r.u.SimpleConnectionPool - Connection (1) found but currently active [2015-04-09T17:39:38.060964700Z] [debug] c.r.u.SimpleConnectionPool - Connection (1) now has 0 pending queries [2015-04-09T17:39:38.061194400Z] [debug] c.r.n.AsyncConnection$$anon$1 - Restoring connection (1) [2015-04-09T17:39:38.061511200Z] [debug] c.r.u.SimpleConnectionPool - giveBack(connection:1) [2015-04-09T17:39:38.061818100Z] [debug] c.r.u.SimpleConnectionPool - drain(connection:1) empty [2015-04-09T17:39:38.061979700Z] [debug] c.r.n.JsonVersionHandler - Results = ()

[2015-04-09T17:39:42.808145400Z] [error] play - Cannot invoke the action, eventually got an error: akka.pattern.AskTimeoutException: Ask timed out on [Actor[akka://application/user/$h#-1915913745]] after [5000 ms] [2015-04-09T17:39:42.810382100Z] [error] application - [2015-04-09T17:39:42.810382100Z] [2015-04-09T17:39:42.810382100Z] ! @6lmei3p4l - Internal server error, for (POST) [/image/process] -> [2015-04-09T17:39:42.810382100Z] [2015-04-09T17:39:42.810382100Z] play.api.Application$$anon$1: Execution exception[[AskTimeoutException: Ask timed out on [Actor[akka://application/user/$h#-1915913745]] after [5000 ms]]] [2015-04-09T17:39:42.810382100Z] at play.api.Application$class.handleError(Application.scala:296) ~[com.typesafe.play.play_2.11-2.3.7.jar:2.3.7] [2015-04-09T17:39:42.810382100Z] at play.api.DefaultApplication.handleError(Application.scala:402) [com.typesafe.play.play_2.11-2.3.7.jar:2.3.7] [2015-04-09T17:39:42.810382100Z] at play.core.server.netty.PlayDefaultUpstreamHandler$$anonfun$3$$anonfun$applyOrElse$4.apply(PlayDefaultUpstreamHandler.scala:320) [com.typesafe.play.play_2.11-2.3.7.jar:2.3.7] [2015-04-09T17:39:42.810382100Z] at play.core.server.netty.PlayDefaultUpstreamHandler$$anonfun$3$$anonfun$applyOrElse$4.apply(PlayDefaultUpstreamHandler.scala:320) [com.typesafe.play.play_2.11-2.3.7.jar:2.3.7] [2015-04-09T17:39:42.810382100Z] at scala.Option.map(Option.scala:145) [org.scala-lang.scala-library-2.11.4.jar:na] [2015-04-09T17:39:42.810382100Z] Caused by: akka.pattern.AskTimeoutException: Ask timed out on [Actor[akka://application/user/$h#-1915913745]] after [5000 ms] [2015-04-09T17:39:42.810382100Z] at akka.pattern.PromiseActorRef$$anonfun$1.apply$mcV$sp(AskSupport.scala:333) ~[com.typesafe.akka.akka-actor_2.11-2.3.4.jar:na] [2015-04-09T17:39:42.810382100Z] at akka.actor.Scheduler$$anon$7.run(Scheduler.scala:117) ~[com.typesafe.akka.akka-actor_2.11-2.3.4.jar:na] [2015-04-09T17:39:42.810382100Z] at scala.concurrent.Future$InternalCallbackExecutor$.unbatchedExecute(Future.scala:599) ~[org.scala-lang.scala-library-2.11.4.jar:na] [2015-04-09T17:39:42.810382100Z] at scala.concurrent.BatchingExecutor$class.execute(BatchingExecutor.scala:109) ~[org.scala-lang.scala-library-2.11.4.jar:na] [2015-04-09T17:39:42.810382100Z] at scala.concurrent.Future$InternalCallbackExecutor$.execute(Future.scala:597) ~[org.scala-lang.scala-library-2.11.4.jar:na] [2015-04-09T17:40:08.068100700Z] Left(com.rethinkscala.net.RethinkTimeoutError: Futures timed out after [30 seconds]) [2015-04-09T17:40:08.075920400Z] [INFO] [04/09/2015 17:40:08.069] [application-akka.actor.default-dispatcher-8] [akka://application/deadLetters] Message [akka.actor.Status$Failure] from Actor[akka://application/user/$h#-1915913745] to Actor[akka://application/deadLetters] was not delivered. [2] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. I have tried the same calls in the RethinkDB data explorer and have been unable to reproduce any issues outside of the Play Framework/Rethink-Scala environment.
kclay commented 9 years ago

Just pushed a new snapshot ,give this a try.

table.getAll(key).withIndex(indexName)
SMcClelland commented 9 years ago

That was quick. Thanks for reading this so fast!

I grabbed the latest snapshot and switched the code over to the table.getAll(key).withIndex(indexName) format, but unfortunately I am still encountering the issue.

Here is the code: import services.db.DBConnection. val table = db.tableIngredient val tableFuture = table.getAll(ingredientsToDietaryPreferenceFlatMap.map(.toLowerCase()):_*).withIndex("alternateNameAndDietaryPreferenceId").run

services.db.DBConnection looks like this:

import com.rethinkscala.ast.DB import com.rethinkscala.net.Version3 import com.rethinkscala.Implicits.Async. import scala.concurrent.duration. import play.api. import play.api.mvc. import com.rethinkscala.ast._ import play.api.Play.current

object DBConnection { val host = Play.configuration.getString("rethinkdb.host").get val port = Play.configuration.getInt("rethinkdb.port").get val dbname = Play.configuration.getString("rethinkdb.dbname").get lazy val version = new Version3(host,port) lazy implicit val connection = Async(version) lazy val db = DB(dbname) }

Here is an updated log. (Sorry they are so long) Is there anything I could do to help debug this issue?

[2015-04-10T01:39:01.019128000Z]  INFO [ForkJoinPool-4-worker-3] (Log4JStopWatch.java:353) - start[1428629939436] time[1518] tag[OCR results are in]
[2015-04-10T01:39:01.019128000Z]  INFO [application-akka.actor.default-dispatcher-3] (Log4JStopWatch.java:353) - start[1428629940957] time[7] tag[EnglishGrammarProcessor:scanText completed]
[2015-04-10T01:39:01.019128000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing GetAll(Table(ingredients,None,Some(DB(food_focus))),ArrayBuffer(enriched flour_dced0372-9469-4940-96fe-2e0a72d38329, flour_dced0372-9469-4940-96fe-2e0a72d38329, enriched_dced0372-9469-4940-96fe-2e0a72d38329, niacin_dced0372-9469-4940-96fe-2e0a72d38329, iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, bl_dced0372-9469-4940-96fe-2e0a72d38329, vitamin bl_dced0372-9469-4940-96fe-2e0a72d38329, b2_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, vitamin b2_dced0372-9469-4940-96fe-2e0a72d38329, riboflavin)_dced0372-9469-4940-96fe-2e0a72d38329, folic_dced0372-9469-4940-96fe-2e0a72d38329, acid_dced0372-9469-4940-96fe-2e0a72d38329, folic acid_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, vegetable_dced0372-9469-4940-96fe-2e0a72d38329, vegetable
[2015-04-10T01:39:01.019128000Z] oil_dced0372-9469-4940-96fe-2e0a72d38329, partially hydrogenated palm kernel and/or
[2015-04-10T01:39:01.019128000Z] cottonseed oil_dced0372-9469-4940-96fe-2e0a72d38329, kernel_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, partially_dced0372-9469-4940-96fe-2e0a72d38329, hydrogenated_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cottonseed_dced0372-9469-4940-96fe-2e0a72d38329, and/or_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean and palm oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, color_dced0372-9469-4940-96fe-2e0a72d38329, caramel color_dced0372-9469-4940-96fe-2e0a72d38329, caramel_dced0372-9469-4940-96fe-2e0a72d38329, 2%_dced0372-9469-4940-96fe-2e0a72d38329, or_dced0372-9469-4940-96fe-2e0a72d38329, leavening_dced0372-9469-4940-96fe-2e0a72d38329, contains 2% or less of leavening_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329, less_dced0372-9469-4940-96fe-2e0a72d38329, contains_dced0372-9469-4940-96fe-2e0a72d38329, baking_dced0372-9469-4940-96fe-2e0a72d38329, baking soda_dced0372-9469-4940-96fe-2e0a72d38329, soda_dced0372-9469-4940-96fe-2e0a72d38329, phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium_dced0372-9469-4940-96fe-2e0a72d38329, cocoa
[2015-04-10T01:39:01.019128000Z] processed with alkali_dced0372-9469-4940-96fe-2e0a72d38329, alkali_dced0372-9469-4940-96fe-2e0a72d38329, processed_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, with_dced0372-9469-4940-96fe-2e0a72d38329, invert_dced0372-9469-4940-96fe-2e0a72d38329, invert sugar_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, cornstarch_dced0372-9469-4940-96fe-2e0a72d38329, salt_dced0372-9469-4940-96fe-2e0a72d38329, soy lecithin_dced0372-9469-4940-96fe-2e0a72d38329, soy_dced0372-9469-4940-96fe-2e0a72d38329, lecithin_dced0372-9469-4940-96fe-2e0a72d38329, natural and artificial flavors_dced0372-9469-4940-96fe-2e0a72d38329, natural_dced0372-9469-4940-96fe-2e0a72d38329, flavors_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, artificial_dced0372-9469-4940-96fe-2e0a72d38329, oil of_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329),Some(alternateNameAndDietaryPreferenceId))
[2015-04-10T01:39:01.019128000Z] [debug] c.r.u.SimpleConnectionPool - No connectionId executing
[2015-04-10T01:39:01.019128000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Logger already configured
[2015-04-10T01:39:01.019128000Z] [debug] c.r.u.SimpleConnectionPool - Entering executing block for (1})
[2015-04-10T01:39:01.019128000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Received connection from pool
[2015-04-10T01:39:01.019128000Z] [debug] c.r.u.SimpleConnectionPool - Exiting executing block for (1
[2015-04-10T01:39:01.019128000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Channel Future completed
[2015-04-10T01:39:01.019128000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating query
[2015-04-10T01:39:01.019128000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating connection attachment
[2015-04-10T01:39:01.019128000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing query
[2015-04-10T01:39:01.019128000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Wrote query
[2015-04-10T01:39:01.034916600Z] [debug] c.r.n.JsonFrameDecoder - Decoding Frame TOKEN = 21 LENGTH = 507
[2015-04-10T01:39:01.035519400Z] [debug] c.r.n.JsonFrameDecoder - JSON = {"t":3,"r":[{"alternate_names":["sugar","azucar"],"id":"2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf","name":"sugar","severities":[{"description":"Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.","dietary_preference_id":"7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673","severity":20},{"description":"Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.","dietary_preference_id":"dced0372-9469-4940-96fe-2e0a72d38329","severity"
[2015-04-10T01:39:01.035909000Z] [debug] c.r.n.JsonVersionHandler - handle(21) = {"t":3,"r":[{"alternate_names":["sugar","azucar"],"id":"2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf","name":"sugar","severities":[{"description":"Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.","dietary_preference_id":"7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673","severity":20},{"description":"Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.","dietary_preference_id":"dced0372-9469-4940-96fe-2e0a72d38329","severity":20}]}]}
[2015-04-10T01:39:01.038808000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Restoring connection (1)
[2015-04-10T01:39:01.039115500Z] [debug] c.r.u.SimpleConnectionPool - giveBack(connection:1)
[2015-04-10T01:39:01.039409100Z] [debug] c.r.u.SimpleConnectionPool - drain(connection:1) empty
[2015-04-10T01:39:01.039847200Z]  INFO [ForkJoinPool-4-worker-3] (Log4JStopWatch.java:353) - start[1428629940985] time[53] tag[IngredientsProcessorActor::DB Results are in]
[2015-04-10T01:39:01.040286600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing Count(GetAll(Table(ingredients,None,Some(DB(food_focus))),ArrayBuffer(enriched flour_dced0372-9469-4940-96fe-2e0a72d38329, flour_dced0372-9469-4940-96fe-2e0a72d38329, enriched_dced0372-9469-4940-96fe-2e0a72d38329, niacin_dced0372-9469-4940-96fe-2e0a72d38329, iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, bl_dced0372-9469-4940-96fe-2e0a72d38329, vitamin bl_dced0372-9469-4940-96fe-2e0a72d38329, b2_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, vitamin b2_dced0372-9469-4940-96fe-2e0a72d38329, riboflavin)_dced0372-9469-4940-96fe-2e0a72d38329, folic_dced0372-9469-4940-96fe-2e0a72d38329, acid_dced0372-9469-4940-96fe-2e0a72d38329, folic acid_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, vegetable_dced0372-9469-4940-96fe-2e0a72d38329, vegetable
[2015-04-10T01:39:01.040286600Z] oil_dced0372-9469-4940-96fe-2e0a72d38329, partially hydrogenated palm kernel and/or
[2015-04-10T01:39:01.040286600Z] cottonseed oil_dced0372-9469-4940-96fe-2e0a72d38329, kernel_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, partially_dced0372-9469-4940-96fe-2e0a72d38329, hydrogenated_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cottonseed_dced0372-9469-4940-96fe-2e0a72d38329, and/or_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean and palm oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, color_dced0372-9469-4940-96fe-2e0a72d38329, caramel color_dced0372-9469-4940-96fe-2e0a72d38329, caramel_dced0372-9469-4940-96fe-2e0a72d38329, 2%_dced0372-9469-4940-96fe-2e0a72d38329, or_dced0372-9469-4940-96fe-2e0a72d38329, leavening_dced0372-9469-4940-96fe-2e0a72d38329, contains 2% or less of leavening_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329, less_dced0372-9469-4940-96fe-2e0a72d38329, contains_dced0372-9469-4940-96fe-2e0a72d38329, baking_dced0372-9469-4940-96fe-2e0a72d38329, baking soda_dced0372-9469-4940-96fe-2e0a72d38329, soda_dced0372-9469-4940-96fe-2e0a72d38329, phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium_dced0372-9469-4940-96fe-2e0a72d38329, cocoa
[2015-04-10T01:39:01.040286600Z] processed with alkali_dced0372-9469-4940-96fe-2e0a72d38329, alkali_dced0372-9469-4940-96fe-2e0a72d38329, processed_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, with_dced0372-9469-4940-96fe-2e0a72d38329, invert_dced0372-9469-4940-96fe-2e0a72d38329, invert sugar_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, cornstarch_dced0372-9469-4940-96fe-2e0a72d38329, salt_dced0372-9469-4940-96fe-2e0a72d38329, soy lecithin_dced0372-9469-4940-96fe-2e0a72d38329, soy_dced0372-9469-4940-96fe-2e0a72d38329, lecithin_dced0372-9469-4940-96fe-2e0a72d38329, natural and artificial flavors_dced0372-9469-4940-96fe-2e0a72d38329, natural_dced0372-9469-4940-96fe-2e0a72d38329, flavors_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, artificial_dced0372-9469-4940-96fe-2e0a72d38329, oil of_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329),Some(alternateNameAndDietaryPreferenceId)),None)
[2015-04-10T01:39:01.040893200Z] [debug] c.r.u.SimpleConnectionPool - No connectionId executing
[2015-04-10T01:39:01.041150300Z] [debug] c.r.n.AsyncConnection$$anon$1 - Logger already configured
[2015-04-10T01:39:01.041385500Z] [debug] c.r.u.SimpleConnectionPool - Entering executing block for (1})
[2015-04-10T01:39:01.041571600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Received connection from pool
[2015-04-10T01:39:01.041789400Z] [debug] c.r.u.SimpleConnectionPool - Exiting executing block for (1
[2015-04-10T01:39:01.042039000Z] [debug] c.r.n.JsonVersionHandler - Results = ()
[2015-04-10T01:39:01.042282700Z] [debug] c.r.n.AsyncConnection$$anon$1 - Channel Future completed
[2015-04-10T01:39:01.042455500Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating query
[2015-04-10T01:39:01.042919800Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating connection attachment
[2015-04-10T01:39:01.043130300Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing query
[2015-04-10T01:39:01.043757100Z] [debug] c.r.n.AsyncConnection$$anon$1 - Wrote query
[2015-04-10T01:39:01.050908600Z] [info] application - getIngredientsByIngredientsAndDietaryPreferenceIds DB call successful
[2015-04-10T01:39:01.201470700Z] [debug] c.r.n.JsonFrameDecoder - Decoding Frame TOKEN = 22 LENGTH = 15
[2015-04-10T01:39:01.202000100Z] [debug] c.r.n.JsonFrameDecoder - JSON = {"t":1,"r":[2]}
[2015-04-10T01:39:01.202166300Z] [debug] c.r.n.JsonVersionHandler - handle(22) = {"t":1,"r":[2]}
[2015-04-10T01:39:01.203011900Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing Continue(21)
[2015-04-10T01:39:01.203611900Z] [debug] c.r.u.SimpleConnectionPool - Connection (1) found but currently active
[2015-04-10T01:39:01.203887300Z] [debug] c.r.u.SimpleConnectionPool - Connection (1) now has 0 pending queries
[2015-04-10T01:39:01.204211100Z] [debug] c.r.n.AsyncConnection$$anon$1 - Restoring connection (1)
[2015-04-10T01:39:01.204444300Z] [debug] c.r.u.SimpleConnectionPool - giveBack(connection:1)
[2015-04-10T01:39:01.204659400Z] [debug] c.r.u.SimpleConnectionPool - drain(connection:1) empty
[2015-04-10T01:39:01.204876900Z] [debug] c.r.n.JsonVersionHandler - Results = ()
[2015-04-10T01:39:05.983594900Z] [error] play - Cannot invoke the action, eventually got an error: akka.pattern.AskTimeoutException: Ask timed out on [Actor[akka://application/user/$F#-1099350122]] after [5000 ms]
[2015-04-10T01:39:05.985330800Z] [error] application -
[2015-04-10T01:39:05.985330800Z]
[2015-04-10T01:39:05.985330800Z] ! @6lmh32c6l - Internal server error, for (POST) [/image/process] ->
[2015-04-10T01:39:05.985330800Z]
[2015-04-10T01:39:05.985330800Z] play.api.Application$$anon$1: Execution exception[[AskTimeoutException: Ask timed out on [Actor[akka://application/user/$F#-1099350122]] after [5000 ms]]]
[2015-04-10T01:39:05.985330800Z]        at play.api.Application$class.handleError(Application.scala:296) ~[com.typesafe.play.play_2.11-2.3.7.jar:2.3.7]
[2015-04-10T01:39:05.985330800Z]        at play.api.DefaultApplication.handleError(Application.scala:402) [com.typesafe.play.play_2.11-2.3.7.jar:2.3.7]
[2015-04-10T01:39:05.985330800Z]        at play.core.server.netty.PlayDefaultUpstreamHandler$$anonfun$3$$anonfun$applyOrElse$4.apply(PlayDefaultUpstreamHandler.scala:320) [com.typesafe.play.play_2.11-2.3.7.jar:2.3.7]
[2015-04-10T01:39:05.985330800Z]        at play.core.server.netty.PlayDefaultUpstreamHandler$$anonfun$3$$anonfun$applyOrElse$4.apply(PlayDefaultUpstreamHandler.scala:320) [com.typesafe.play.play_2.11-2.3.7.jar:2.3.7]
[2015-04-10T01:39:05.985330800Z]        at scala.Option.map(Option.scala:145) [org.scala-lang.scala-library-2.11.4.jar:na]
[2015-04-10T01:39:05.985330800Z] Caused by: akka.pattern.AskTimeoutException: Ask timed out on [Actor[akka://application/user/$F#-1099350122]] after [5000 ms]
[2015-04-10T01:39:05.985330800Z]        at akka.pattern.PromiseActorRef$$anonfun$1.apply$mcV$sp(AskSupport.scala:333) ~[com.typesafe.akka.akka-actor_2.11-2.3.4.jar:na]
[2015-04-10T01:39:05.985330800Z]        at akka.actor.Scheduler$$anon$7.run(Scheduler.scala:117) ~[com.typesafe.akka.akka-actor_2.11-2.3.4.jar:na]
[2015-04-10T01:39:05.985330800Z]        at scala.concurrent.Future$InternalCallbackExecutor$.unbatchedExecute(Future.scala:599) ~[org.scala-lang.scala-library-2.11.4.jar:na]
[2015-04-10T01:39:05.985330800Z]        at scala.concurrent.BatchingExecutor$class.execute(BatchingExecutor.scala:109) ~[org.scala-lang.scala-library-2.11.4.jar:na]
kclay commented 9 years ago

Thanks I think I know the problem, let me play around with it for a bit

SMcClelland commented 9 years ago

It took me a bit to get the netty logs but here they are in case you still want them, though it sounds like I may have been too late. Thanks for all your help!

[2015-04-10T15:59:14.033939600Z] [debug] i.n.u.i.l.InternalLoggerFactory - Using SLF4J as the default logging framework
[2015-04-10T15:59:14.160630700Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing GetAll(Table(ingredients,None,Some(DB(food_focus))),ArrayBuffer(enriched flour_dced0372-9469-4940-96fe-2e0a72d38329, flour_dced0372-9469-4940-96fe-2e0a72d38329, enriched_dced0372-9469-4940-96fe-2e0a72d38329, niacin_dced0372-9469-4940-96fe-2e0a72d38329, iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, bl_dced0372-9469-4940-96fe-2e0a72d38329, vitamin bl_dced0372-9469-4940-96fe-2e0a72d38329, b2_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, vitamin b2_dced0372-9469-4940-96fe-2e0a72d38329, riboflavin)_dced0372-9469-4940-96fe-2e0a72d38329, folic_dced0372-9469-4940-96fe-2e0a72d38329, acid_dced0372-9469-4940-96fe-2e0a72d38329, folic acid_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, vegetable_dced0372-9469-4940-96fe-2e0a72d38329, vegetable
[2015-04-10T15:59:14.160630700Z] oil_dced0372-9469-4940-96fe-2e0a72d38329, partially hydrogenated palm kernel and/or
[2015-04-10T15:59:14.160630700Z] cottonseed oil_dced0372-9469-4940-96fe-2e0a72d38329, kernel_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, partially_dced0372-9469-4940-96fe-2e0a72d38329, hydrogenated_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cottonseed_dced0372-9469-4940-96fe-2e0a72d38329, and/or_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean and palm oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, color_dced0372-9469-4940-96fe-2e0a72d38329, caramel color_dced0372-9469-4940-96fe-2e0a72d38329, caramel_dced0372-9469-4940-96fe-2e0a72d38329, 2%_dced0372-9469-4940-96fe-2e0a72d38329, or_dced0372-9469-4940-96fe-2e0a72d38329, leavening_dced0372-9469-4940-96fe-2e0a72d38329, contains 2% or less of leavening_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329, less_dced0372-9469-4940-96fe-2e0a72d38329, contains_dced0372-9469-4940-96fe-2e0a72d38329, baking_dced0372-9469-4940-96fe-2e0a72d38329, baking soda_dced0372-9469-4940-96fe-2e0a72d38329, soda_dced0372-9469-4940-96fe-2e0a72d38329, phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium_dced0372-9469-4940-96fe-2e0a72d38329, cocoa
[2015-04-10T15:59:14.160630700Z] processed with alkali_dced0372-9469-4940-96fe-2e0a72d38329, alkali_dced0372-9469-4940-96fe-2e0a72d38329, processed_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, with_dced0372-9469-4940-96fe-2e0a72d38329, invert_dced0372-9469-4940-96fe-2e0a72d38329, invert sugar_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, cornstarch_dced0372-9469-4940-96fe-2e0a72d38329, salt_dced0372-9469-4940-96fe-2e0a72d38329, soy lecithin_dced0372-9469-4940-96fe-2e0a72d38329, soy_dced0372-9469-4940-96fe-2e0a72d38329, lecithin_dced0372-9469-4940-96fe-2e0a72d38329, natural and artificial flavors_dced0372-9469-4940-96fe-2e0a72d38329, natural_dced0372-9469-4940-96fe-2e0a72d38329, flavors_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, artificial_dced0372-9469-4940-96fe-2e0a72d38329, oil of_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329),Some(alternateNameAndDietaryPreferenceId))
[2015-04-10T15:59:14.167270100Z] [debug] c.r.u.SimpleConnectionPool - No connectionId executing
[2015-04-10T15:59:14.170703300Z] [debug] c.r.u.SimpleConnectionPool - createOrBlock size=0 max = 5
[2015-04-10T15:59:14.173978000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating new ChannelWrapper
[2015-04-10T15:59:14.184247800Z] [debug] i.n.c.MultithreadEventLoopGroup - -Dio.netty.eventLoopThreads: 2
[2015-04-10T15:59:14.200000700Z] [debug] i.n.u.i.PlatformDependent0 - java.nio.Buffer.address: available
[2015-04-10T15:59:14.205815500Z] [debug] i.n.u.i.PlatformDependent0 - sun.misc.Unsafe.theUnsafe: available
[2015-04-10T15:59:14.206591700Z] [debug] i.n.u.i.PlatformDependent0 - sun.misc.Unsafe.copyMemory: available
[2015-04-10T15:59:14.213479800Z] [debug] i.n.u.i.PlatformDependent0 - java.nio.Bits.unaligned: true
[2015-04-10T15:59:14.213479800Z] [debug] i.n.u.i.PlatformDependent - Java version: 8
[2015-04-10T15:59:14.213479800Z] [debug] i.n.u.i.PlatformDependent - -Dio.netty.noUnsafe: false
[2015-04-10T15:59:14.213479800Z] [debug] i.n.u.i.PlatformDependent - sun.misc.Unsafe: available
[2015-04-10T15:59:14.213479800Z] [debug] i.n.u.i.PlatformDependent - -Dio.netty.noJavassist: false
[2015-04-10T15:59:14.390119300Z] [debug] i.n.u.i.PlatformDependent - Javassist: available
[2015-04-10T15:59:14.397795600Z] [debug] i.n.u.i.PlatformDependent - -Dio.netty.tmpdir: /tmp (java.io.tmpdir)
[2015-04-10T15:59:14.398109800Z] [debug] i.n.u.i.PlatformDependent - -Dio.netty.bitMode: 64 (sun.arch.data.model)
[2015-04-10T15:59:14.398483100Z] [debug] i.n.u.i.PlatformDependent - -Dio.netty.noPreferDirect: false
[2015-04-10T15:59:14.441581400Z] [debug] i.n.c.n.NioEventLoop - -Dio.netty.noKeySetOptimization: false
[2015-04-10T15:59:14.441870500Z] [debug] i.n.c.n.NioEventLoop - -Dio.netty.selectorAutoRebuildThreshold: 512
[2015-04-10T15:59:14.508928400Z] [debug] i.n.u.i.ThreadLocalRandom - -Dio.netty.initialSeedUniquifier: 0x85022bd9bfa3490d (took 0 ms)
[2015-04-10T15:59:14.547162300Z] [debug] i.n.b.ByteBufUtil - -Dio.netty.allocator.type: unpooled
[2015-04-10T15:59:14.547588000Z] [debug] i.n.b.ByteBufUtil - -Dio.netty.threadLocalDirectBufferSize: 65536
[2015-04-10T15:59:14.585061900Z] [debug] c.r.n.AsyncConnection$$anon$1 - Configuring ChannelWrapper
[2015-04-10T15:59:14.589717900Z] [debug] c.r.n.Version3 - Configuring channel
[2015-04-10T15:59:14.597620300Z] [debug] i.n.u.Recycler - -Dio.netty.recycler.maxCapacity.default: 262144
[2015-04-10T15:59:14.612222800Z] [debug] i.n.u.ResourceLeakDetector - -Dio.netty.leakDetectionLevel: simple
[2015-04-10T15:59:14.625856300Z] [debug] i.n.u.i.Cleaner0 - java.nio.ByteBuffer.cleaner(): available
[2015-04-10T15:59:14.638876400Z] [debug] c.r.n.Version3 - Server auth responsed with : -SUCCESS-
[2015-04-10T15:59:14.639817200Z] [debug] c.r.u.SimpleConnectionPool - Entering executing block for (1})
[2015-04-10T15:59:14.641009800Z] [debug] c.r.n.AsyncConnection$$anon$1 - Received connection from pool
[2015-04-10T15:59:14.643204000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Channel Future completed
[2015-04-10T15:59:14.643529800Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating query
[2015-04-10T15:59:14.650833500Z] [debug] c.r.u.SimpleConnectionPool - Exiting executing block for (1
[2015-04-10T15:59:14.729546100Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating connection attachment
[2015-04-10T15:59:14.731479900Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing query
[2015-04-10T15:59:15.053595800Z] [debug] c.r.n.AsyncConnection$$anon$1 - Wrote query
[2015-04-10T15:59:15.122130800Z] [debug] c.r.n.JsonFrameDecoder - Decoding Frame TOKEN = 1 LENGTH = 507
[2015-04-10T15:59:15.122411700Z] [debug] c.r.n.JsonFrameDecoder - JSON = {"t":3,"r":[{"alternate_names":["sugar","azucar"],"id":"2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf","name":"sugar","severities":[{"description":"Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.","dietary_preference_id":"7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673","severity":20},{"description":"Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.","dietary_preference_id":"dced0372-9469-4940-96fe-2e0a72d38329","severity"
[2015-04-10T15:59:15.123517900Z] [debug] c.r.n.JsonVersionHandler - handle(1) = {"t":3,"r":[{"alternate_names":["sugar","azucar"],"id":"2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf","name":"sugar","severities":[{"description":"Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.","dietary_preference_id":"7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673","severity":20},{"description":"Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.","dietary_preference_id":"dced0372-9469-4940-96fe-2e0a72d38329","severity":20}]}]}
[2015-04-10T15:59:15.749767500Z] [debug] c.r.n.AsyncConnection$$anon$1 - Restoring connection (1)
[2015-04-10T15:59:15.750120700Z] [debug] c.r.u.SimpleConnectionPool - giveBack(connection:1)
[2015-04-10T15:59:15.750701700Z] [debug] c.r.u.SimpleConnectionPool - drain(connection:1) empty
[2015-04-10T15:59:15.751189100Z] [debug] c.r.n.JsonVersionHandler - Results = ()
[2015-04-10T15:59:15.758500100Z]  INFO [ForkJoinPool-4-worker-3] (Log4JStopWatch.java:353) - start[1428681553881] time[1876] tag[IngredientsProcessorActor::DB Results are in]
[2015-04-10T15:59:15.777097200Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing Count(GetAll(Table(ingredients,None,Some(DB(food_focus))),ArrayBuffer(enriched flour_dced0372-9469-4940-96fe-2e0a72d38329, flour_dced0372-9469-4940-96fe-2e0a72d38329, enriched_dced0372-9469-4940-96fe-2e0a72d38329, niacin_dced0372-9469-4940-96fe-2e0a72d38329, iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, bl_dced0372-9469-4940-96fe-2e0a72d38329, vitamin bl_dced0372-9469-4940-96fe-2e0a72d38329, b2_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, vitamin b2_dced0372-9469-4940-96fe-2e0a72d38329, riboflavin)_dced0372-9469-4940-96fe-2e0a72d38329, folic_dced0372-9469-4940-96fe-2e0a72d38329, acid_dced0372-9469-4940-96fe-2e0a72d38329, folic acid_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, vegetable_dced0372-9469-4940-96fe-2e0a72d38329, vegetable
[2015-04-10T15:59:15.777097200Z] oil_dced0372-9469-4940-96fe-2e0a72d38329, partially hydrogenated palm kernel and/or
[2015-04-10T15:59:15.777097200Z] cottonseed oil_dced0372-9469-4940-96fe-2e0a72d38329, kernel_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, partially_dced0372-9469-4940-96fe-2e0a72d38329, hydrogenated_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cottonseed_dced0372-9469-4940-96fe-2e0a72d38329, and/or_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean and palm oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, color_dced0372-9469-4940-96fe-2e0a72d38329, caramel color_dced0372-9469-4940-96fe-2e0a72d38329, caramel_dced0372-9469-4940-96fe-2e0a72d38329, 2%_dced0372-9469-4940-96fe-2e0a72d38329, or_dced0372-9469-4940-96fe-2e0a72d38329, leavening_dced0372-9469-4940-96fe-2e0a72d38329, contains 2% or less of leavening_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329, less_dced0372-9469-4940-96fe-2e0a72d38329, contains_dced0372-9469-4940-96fe-2e0a72d38329, baking_dced0372-9469-4940-96fe-2e0a72d38329, baking soda_dced0372-9469-4940-96fe-2e0a72d38329, soda_dced0372-9469-4940-96fe-2e0a72d38329, phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium_dced0372-9469-4940-96fe-2e0a72d38329, cocoa
[2015-04-10T15:59:15.777097200Z] processed with alkali_dced0372-9469-4940-96fe-2e0a72d38329, alkali_dced0372-9469-4940-96fe-2e0a72d38329, processed_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, with_dced0372-9469-4940-96fe-2e0a72d38329, invert_dced0372-9469-4940-96fe-2e0a72d38329, invert sugar_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, cornstarch_dced0372-9469-4940-96fe-2e0a72d38329, salt_dced0372-9469-4940-96fe-2e0a72d38329, soy lecithin_dced0372-9469-4940-96fe-2e0a72d38329, soy_dced0372-9469-4940-96fe-2e0a72d38329, lecithin_dced0372-9469-4940-96fe-2e0a72d38329, natural and artificial flavors_dced0372-9469-4940-96fe-2e0a72d38329, natural_dced0372-9469-4940-96fe-2e0a72d38329, flavors_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, artificial_dced0372-9469-4940-96fe-2e0a72d38329, oil of_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329),Some(alternateNameAndDietaryPreferenceId)),None)
[2015-04-10T15:59:15.781412000Z] [debug] c.r.u.SimpleConnectionPool - No connectionId executing
[2015-04-10T15:59:15.785915500Z] [debug] c.r.n.AsyncConnection$$anon$1 - Logger already configured
[2015-04-10T15:59:15.786439500Z] [debug] c.r.u.SimpleConnectionPool - Entering executing block for (1})
[2015-04-10T15:59:15.786899200Z] [debug] c.r.n.AsyncConnection$$anon$1 - Received connection from pool
[2015-04-10T15:59:15.787792800Z] [debug] c.r.n.AsyncConnection$$anon$1 - Channel Future completed
[2015-04-10T15:59:15.788085600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating query
[2015-04-10T15:59:15.790301400Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating connection attachment
[2015-04-10T15:59:15.791871200Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing query
[2015-04-10T15:59:15.794027300Z] [debug] c.r.u.SimpleConnectionPool - Exiting executing block for (1
[2015-04-10T15:59:15.795130500Z] [debug] c.r.n.AsyncConnection$$anon$1 - Wrote query
[2015-04-10T15:59:15.796136500Z] [info] application - getIngredientsByIngredientsAndDietaryPreferenceIds DB call successful
[2015-04-10T15:59:15.938462600Z] [debug] c.r.n.JsonFrameDecoder - Decoding Frame TOKEN = 2 LENGTH = 15
[2015-04-10T15:59:15.938729700Z] [debug] c.r.n.JsonFrameDecoder - JSON = {"t":1,"r":[2]}
[2015-04-10T15:59:15.939170000Z] [debug] c.r.n.JsonVersionHandler - handle(2) = {"t":1,"r":[2]}
[2015-04-10T15:59:15.993993400Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing Continue(1)
[2015-04-10T15:59:15.994438600Z] [debug] c.r.u.SimpleConnectionPool - Connection (1) found but currently active
[2015-04-10T15:59:15.996845300Z] [debug] c.r.u.SimpleConnectionPool - Connection (1) now has 0 pending queries
[2015-04-10T15:59:16.001470100Z] [debug] c.r.n.JsonVersionHandler - Results = ()
[2015-04-10T15:59:16.001580400Z] [debug] c.r.n.AsyncConnection$$anon$1 - Restoring connection (1)
[2015-04-10T15:59:16.001895400Z] [debug] c.r.u.SimpleConnectionPool - giveBack(connection:1)
[2015-04-10T15:59:16.002299900Z] [debug] c.r.u.SimpleConnectionPool - drain(connection:1) empty
[2015-04-10T15:59:18.811324400Z] [error] play - Cannot invoke the action, eventually got an error: akka.pattern.AskTimeoutException: Ask timed out on [Actor[akka://application/user/$b#-106273517]] after [5000 ms]
[2015-04-10T15:59:18.822035000Z] [error] application -
[2015-04-10T15:59:18.822035000Z]
[2015-04-10T15:59:18.822035000Z] ! @6lmlc10fg - Internal server error, for (POST) [/image/process] ->
[2015-04-10T15:59:18.822035000Z]
[2015-04-10T15:59:18.822035000Z] play.api.Application$$anon$1: Execution exception[[AskTimeoutException: Ask timed out on [Actor[akka://application/user/$b#-106273517]] after [5000 ms]]]
[2015-04-10T15:59:18.822035000Z]        at play.api.Application$class.handleError(Application.scala:296) ~[com.typesafe.play.play_2.11-2.3.7.jar:2.3.7]
[2015-04-10T15:59:18.822035000Z]        at play.api.DefaultApplication.handleError(Application.scala:402) [com.typesafe.play.play_2.11-2.3.7.jar:2.3.7]
[2015-04-10T15:59:18.822035000Z]        at play.core.server.netty.PlayDefaultUpstreamHandler$$anonfun$3$$anonfun$applyOrElse$4.apply(PlayDefaultUpstreamHandler.scala:320) [com.typesafe.play.play_2.11-2.3.7.jar:2.3.7]
[2015-04-10T15:59:18.822035000Z]        at play.core.server.netty.PlayDefaultUpstreamHandler$$anonfun$3$$anonfun$applyOrElse$4.apply(PlayDefaultUpstreamHandler.scala:320) [com.typesafe.play.play_2.11-2.3.7.jar:2.3.7]
[2015-04-10T15:59:18.822035000Z]        at scala.Option.map(Option.scala:145) [org.scala-lang.scala-library-2.11.4.jar:na]
[2015-04-10T15:59:18.822035000Z] Caused by: akka.pattern.AskTimeoutException: Ask timed out on [Actor[akka://application/user/$b#-106273517]] after [5000 ms]
[2015-04-10T15:59:18.822035000Z]        at akka.pattern.PromiseActorRef$$anonfun$1.apply$mcV$sp(AskSupport.scala:333) ~[com.typesafe.akka.akka-actor_2.11-2.3.4.jar:na]
[2015-04-10T15:59:18.822035000Z]        at akka.actor.Scheduler$$anon$7.run(Scheduler.scala:117) ~[com.typesafe.akka.akka-actor_2.11-2.3.4.jar:na]
[2015-04-10T15:59:18.822035000Z]        at scala.concurrent.Future$InternalCallbackExecutor$.unbatchedExecute(Future.scala:599) ~[org.scala-lang.scala-library-2.11.4.jar:na]
[2015-04-10T15:59:18.822035000Z]        at scala.concurrent.BatchingExecutor$class.execute(BatchingExecutor.scala:109) ~[org.scala-lang.scala-library-2.11.4.jar:na]
[2015-04-10T15:59:18.822035000Z]        at scala.concurrent.Future$InternalCallbackExecutor$.execute(Future.scala:597) ~[org.scala-lang.scala-library-2.11.4.jar:na]
kclay commented 9 years ago

Reworked the async chain see if you can get it to bug out, had a hard time coming up with a test case for this one so let me know.

SMcClelland commented 9 years ago

Hi kclay,

Thanks for your help. It seems to be failing far less now.

I was able to catch a few failures but they are a new issue and are no longer timeouts.

Now its a NoSuchElementException, but its only occurring sometimes as the same call is succeeding most of the time.

I can provide you with access to my DB if that would help. If you do want to go that route, feel free to email me at sean@seanmcclelland.com.

[2015-04-14T16:25:52.626064600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing GetAll(Table(ingredients,None,Some(DB(food_focus))),ArrayBuffer(enriched flour_dced0372-9469-4940-96fe-2e0a72d38329, flour_dced0372-9469-4940-96fe-2e0a72d38329, enriched_dced0372-9469-4940-96fe-2e0a72d38329, niacin_dced0372-9469-4940-96fe-2e0a72d38329, iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, bl_dced0372-9469-4940-96fe-2e0a72d38329, vitamin bl_dced0372-9469-4940-96fe-2e0a72d38329, b2_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, vitamin b2_dced0372-9469-4940-96fe-2e0a72d38329, riboflavin)_dced0372-9469-4940-96fe-2e0a72d38329, folic_dced0372-9469-4940-96fe-2e0a72d38329, acid_dced0372-9469-4940-96fe-2e0a72d38329, folic acid_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, vegetable_dced0372-9469-4940-96fe-2e0a72d38329, vegetable
[2015-04-14T16:25:52.626064600Z] oil_dced0372-9469-4940-96fe-2e0a72d38329, partially hydrogenated palm kernel and/or
[2015-04-14T16:25:52.626064600Z] cottonseed oil_dced0372-9469-4940-96fe-2e0a72d38329, kernel_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, partially_dced0372-9469-4940-96fe-2e0a72d38329, hydrogenated_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cottonseed_dced0372-9469-4940-96fe-2e0a72d38329, and/or_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean and palm oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, color_dced0372-9469-4940-96fe-2e0a72d38329, caramel color_dced0372-9469-4940-96fe-2e0a72d38329, caramel_dced0372-9469-4940-96fe-2e0a72d38329, 2%_dced0372-9469-4940-96fe-2e0a72d38329, or_dced0372-9469-4940-96fe-2e0a72d38329, leavening_dced0372-9469-4940-96fe-2e0a72d38329, contains 2% or less of leavening_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329, less_dced0372-9469-4940-96fe-2e0a72d38329, contains_dced0372-9469-4940-96fe-2e0a72d38329, baking_dced0372-9469-4940-96fe-2e0a72d38329, baking soda_dced0372-9469-4940-96fe-2e0a72d38329, soda_dced0372-9469-4940-96fe-2e0a72d38329, phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium_dced0372-9469-4940-96fe-2e0a72d38329, cocoa
[2015-04-14T16:25:52.626064600Z] processed with alkali_dced0372-9469-4940-96fe-2e0a72d38329, alkali_dced0372-9469-4940-96fe-2e0a72d38329, processed_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, with_dced0372-9469-4940-96fe-2e0a72d38329, invert_dced0372-9469-4940-96fe-2e0a72d38329, invert sugar_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, cornstarch_dced0372-9469-4940-96fe-2e0a72d38329, salt_dced0372-9469-4940-96fe-2e0a72d38329, soy lecithin_dced0372-9469-4940-96fe-2e0a72d38329, soy_dced0372-9469-4940-96fe-2e0a72d38329, lecithin_dced0372-9469-4940-96fe-2e0a72d38329, natural and artificial flavors_dced0372-9469-4940-96fe-2e0a72d38329, natural_dced0372-9469-4940-96fe-2e0a72d38329, flavors_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, artificial_dced0372-9469-4940-96fe-2e0a72d38329, oil of_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329),Some(alternateNameAndDietaryPreferenceId))
[2015-04-14T16:25:52.626746100Z] [debug] c.r.u.RethinkConnectionPool - No connectionId executing
[2015-04-14T16:25:52.626965600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Logger already configured
[2015-04-14T16:25:52.627208000Z] [debug] c.r.u.RethinkConnectionPool - Entering executing block for (2})
[2015-04-14T16:25:52.627432100Z] [debug] c.r.n.AsyncConnection$$anon$1 - Received connection from pool
[2015-04-14T16:25:52.627668500Z] [debug] c.r.u.RethinkConnectionPool - Exiting executing block for (2
[2015-04-14T16:25:52.627954800Z] [debug] c.r.n.AsyncConnection$$anon$1 - Channel Future completed
[2015-04-14T16:25:52.628142200Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating query
[2015-04-14T16:25:52.629184900Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating connection attachment
[2015-04-14T16:25:52.629421200Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing query
[2015-04-14T16:25:52.630135000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Wrote query
[2015-04-14T16:25:52.671540100Z] [debug] c.r.n.JsonFrameDecoder - Decoding Frame TOKEN = 25 LENGTH = 507
[2015-04-14T16:25:52.671676600Z] [debug] c.r.n.JsonFrameDecoder - JSON = {"t":3,"r":[{"alternate_names":["sugar","azucar"],"id":"2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf","name":"sugar","severities":[{"description":"Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.","dietary_preference_id":"7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673","severity":20},{"description":"Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.","dietary_preference_id":"dced0372-9469-4940-96fe-2e0a72d38329","severity"
[2015-04-14T16:25:52.671956400Z] [debug] c.r.n.JsonVersionHandler - handle(25) = {"t":3,"r":[{"alternate_names":["sugar","azucar"],"id":"2ecc9ece-2077-42ad-8cf8-0e84ecb3d7cf","name":"sugar","severities":[{"description":"Refined sugar is often processed through bone char. As such, some Vegetarians prefer to avoid it.","dietary_preference_id":"7edaf8ff-f24b-4b8d-9be2-47b8a4aa8673","severity":20},{"description":"Refined sugar is often processed through bone char. As such, some vegans prefer to avoid it.","dietary_preference_id":"dced0372-9469-4940-96fe-2e0a72d38329","severity":20}]}]}
[2015-04-14T16:25:52.672858100Z] [debug] c.r.n.AsyncConnection$$anon$1 - Restoring connection (2)
[2015-04-14T16:25:52.673169300Z] [debug] c.r.u.RethinkConnectionPool - giveBack(connection:2)
[2015-04-14T16:25:52.673429200Z] [debug] c.r.u.RethinkConnectionPool - drain(connection:2) empty
[2015-04-14T16:25:52.673941400Z]  INFO [ForkJoinPool-3-worker-3] (Log4JStopWatch.java:353) - start[1429028752625] time[48] tag[IngredientsProcessorActor::DB Results are in]
[2015-04-14T16:25:52.674389000Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing Count(GetAll(Table(ingredients,None,Some(DB(food_focus))),ArrayBuffer(enriched flour_dced0372-9469-4940-96fe-2e0a72d38329, flour_dced0372-9469-4940-96fe-2e0a72d38329, enriched_dced0372-9469-4940-96fe-2e0a72d38329, niacin_dced0372-9469-4940-96fe-2e0a72d38329, iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced iron_dced0372-9469-4940-96fe-2e0a72d38329, reduced_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, bl_dced0372-9469-4940-96fe-2e0a72d38329, vitamin bl_dced0372-9469-4940-96fe-2e0a72d38329, b2_dced0372-9469-4940-96fe-2e0a72d38329, vitamin_dced0372-9469-4940-96fe-2e0a72d38329, vitamin b2_dced0372-9469-4940-96fe-2e0a72d38329, riboflavin)_dced0372-9469-4940-96fe-2e0a72d38329, folic_dced0372-9469-4940-96fe-2e0a72d38329, acid_dced0372-9469-4940-96fe-2e0a72d38329, folic acid_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, vegetable_dced0372-9469-4940-96fe-2e0a72d38329, vegetable
[2015-04-14T16:25:52.674389000Z] oil_dced0372-9469-4940-96fe-2e0a72d38329, partially hydrogenated palm kernel and/or
[2015-04-14T16:25:52.674389000Z] cottonseed oil_dced0372-9469-4940-96fe-2e0a72d38329, kernel_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, partially_dced0372-9469-4940-96fe-2e0a72d38329, hydrogenated_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cottonseed_dced0372-9469-4940-96fe-2e0a72d38329, and/or_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean and palm oil_dced0372-9469-4940-96fe-2e0a72d38329, soybean_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, palm_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, color_dced0372-9469-4940-96fe-2e0a72d38329, caramel color_dced0372-9469-4940-96fe-2e0a72d38329, caramel_dced0372-9469-4940-96fe-2e0a72d38329, 2%_dced0372-9469-4940-96fe-2e0a72d38329, or_dced0372-9469-4940-96fe-2e0a72d38329, leavening_dced0372-9469-4940-96fe-2e0a72d38329, contains 2% or less of leavening_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329, less_dced0372-9469-4940-96fe-2e0a72d38329, contains_dced0372-9469-4940-96fe-2e0a72d38329, baking_dced0372-9469-4940-96fe-2e0a72d38329, baking soda_dced0372-9469-4940-96fe-2e0a72d38329, soda_dced0372-9469-4940-96fe-2e0a72d38329, phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium phosphate_dced0372-9469-4940-96fe-2e0a72d38329, monocalcium_dced0372-9469-4940-96fe-2e0a72d38329, cocoa
[2015-04-14T16:25:52.674389000Z] processed with alkali_dced0372-9469-4940-96fe-2e0a72d38329, alkali_dced0372-9469-4940-96fe-2e0a72d38329, processed_dced0372-9469-4940-96fe-2e0a72d38329, cocoa_dced0372-9469-4940-96fe-2e0a72d38329, with_dced0372-9469-4940-96fe-2e0a72d38329, invert_dced0372-9469-4940-96fe-2e0a72d38329, invert sugar_dced0372-9469-4940-96fe-2e0a72d38329, sugar_dced0372-9469-4940-96fe-2e0a72d38329, cornstarch_dced0372-9469-4940-96fe-2e0a72d38329, salt_dced0372-9469-4940-96fe-2e0a72d38329, soy lecithin_dced0372-9469-4940-96fe-2e0a72d38329, soy_dced0372-9469-4940-96fe-2e0a72d38329, lecithin_dced0372-9469-4940-96fe-2e0a72d38329, natural and artificial flavors_dced0372-9469-4940-96fe-2e0a72d38329, natural_dced0372-9469-4940-96fe-2e0a72d38329, flavors_dced0372-9469-4940-96fe-2e0a72d38329, and_dced0372-9469-4940-96fe-2e0a72d38329, artificial_dced0372-9469-4940-96fe-2e0a72d38329, oil of_dced0372-9469-4940-96fe-2e0a72d38329, oil_dced0372-9469-4940-96fe-2e0a72d38329, of_dced0372-9469-4940-96fe-2e0a72d38329),Some(alternateNameAndDietaryPreferenceId)),None)
[2015-04-14T16:25:52.674974800Z] [debug] c.r.u.RethinkConnectionPool - No connectionId executing
[2015-04-14T16:25:52.675207400Z] [debug] c.r.n.AsyncConnection$$anon$1 - Logger already configured
[2015-04-14T16:25:52.675448200Z] [debug] c.r.u.RethinkConnectionPool - Entering executing block for (2})
[2015-04-14T16:25:52.675636600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Received connection from pool
[2015-04-14T16:25:52.675847900Z] [debug] c.r.u.RethinkConnectionPool - Exiting executing block for (2
[2015-04-14T16:25:52.676092700Z] [debug] c.r.n.JsonVersionHandler - Results = ()
[2015-04-14T16:25:52.676335600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Channel Future completed
[2015-04-14T16:25:52.676542300Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating query
[2015-04-14T16:25:52.676907900Z] [debug] c.r.n.AsyncConnection$$anon$1 - Creating connection attachment
[2015-04-14T16:25:52.677167200Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing query
[2015-04-14T16:25:52.677794500Z] [debug] c.r.n.AsyncConnection$$anon$1 - Wrote query
[2015-04-14T16:25:52.678640100Z] [info] application - getIngredientsByIngredientsAndDietaryPreferenceIds DB call successful
[2015-04-14T16:25:52.833809300Z] [debug] c.r.n.JsonFrameDecoder - Decoding Frame TOKEN = 26 LENGTH = 15
[2015-04-14T16:25:52.833944200Z] [debug] c.r.n.JsonFrameDecoder - JSON = {"t":1,"r":[2]}
[2015-04-14T16:25:52.834226700Z] [debug] c.r.n.JsonVersionHandler - handle(26) = {"t":1,"r":[2]}
[2015-04-14T16:25:52.834740600Z] [debug] c.r.n.AsyncConnection$$anon$1 - Writing Continue(25)
[2015-04-14T16:25:52.834994700Z] [debug] c.r.u.RethinkConnectionPool - Connection (2) found but currently active
[2015-04-14T16:25:52.835627700Z] [error] play - Cannot invoke the action, eventually got an error: java.util.NoSuchElementException
[2015-04-14T16:25:52.837258900Z] [error] application -
[2015-04-14T16:25:52.837258900Z]
[2015-04-14T16:25:52.837258900Z] ! @6lnohkn5n - Internal server error, for (POST) [/image/process] ->
[2015-04-14T16:25:52.837258900Z]
[2015-04-14T16:25:52.837258900Z] play.api.Application$$anon$1: Execution exception[[NoSuchElementException: null]]
[2015-04-14T16:25:52.837258900Z]        at play.api.Application$class.handleError(Application.scala:296) ~[com.typesafe.play.play_2.11-2.3.7.jar:2.3.7]
[2015-04-14T16:25:52.837258900Z]        at play.api.DefaultApplication.handleError(Application.scala:402) [com.typesafe.play.play_2.11-2.3.7.jar:2.3.7]
[2015-04-14T16:25:52.837258900Z]        at play.core.server.netty.PlayDefaultUpstreamHandler$$anonfun$3$$anonfun$applyOrElse$4.apply(PlayDefaultUpstreamHandler.scala:320) [com.typesafe.play.play_2.11-2.3.7.jar:2.3.7]
[2015-04-14T16:25:52.837258900Z]        at play.core.server.netty.PlayDefaultUpstreamHandler$$anonfun$3$$anonfun$applyOrElse$4.apply(PlayDefaultUpstreamHandler.scala:320) [com.typesafe.play.play_2.11-2.3.7.jar:2.3.7]
[2015-04-14T16:25:52.837258900Z]        at scala.Option.map(Option.scala:145) [org.scala-lang.scala-library-2.11.4.jar:na]
[2015-04-14T16:25:52.837258900Z] Caused by: java.util.NoSuchElementException: null
[2015-04-14T16:25:52.837258900Z]        at scala.collection.concurrent.TrieMap.apply(TrieMap.scala:837) ~[org.scala-lang.scala-library-2.11.4.jar:na]
[2015-04-14T16:25:52.837258900Z]        at com.rethinkscala.utils.RethinkConnectionPool$$anonfun$take$2.apply(AbstractConnectionPool.scala:164) ~[com.rethinkscala.core_2.11-0.4.7-SNAPSHOT.jar:0.4.7-SNAPSHOT]
[2015-04-14T16:25:52.837258900Z]        at com.rethinkscala.utils.RethinkConnectionPool$$anonfun$take$2.apply(AbstractConnectionPool.scala:136) ~[com.rethinkscala.core_2.11-0.4.7-SNAPSHOT.jar:0.4.7-SNAPSHOT]
[2015-04-14T16:25:52.837258900Z]        at scala.Option.fold(Option.scala:157) [org.scala-lang.scala-library-2.11.4.jar:na]
[2015-04-14T16:25:52.837258900Z]        at com.rethinkscala.utils.RethinkConnectionPool.take(AbstractConnectionPool.scala:136) ~[com.rethinkscala.core_2.11-0.4.7-SNAPSHOT.jar:0.4.7-SNAPSHOT]
[2015-04-14T16:25:52.838746300Z] [debug] c.r.n.JsonVersionHandler - Results = ()
[2015-04-14T16:25:52.838924100Z] [debug] c.r.n.AsyncConnection$$anon$1 - Restoring connection (2)
[2015-04-14T16:25:52.839160100Z] [debug] c.r.u.RethinkConnectionPool - giveBack(connection:2)
[2015-04-14T16:25:52.839393400Z] [debug] c.r.u.RethinkConnectionPool - drain(connection:2) empty
[2015-04-14T16:25:58.033254300Z] [debug] c.n.h.c.p.n.NettyConnectionsPool - Entry count for : http://veggiescanocr.cloudapp.net:80 : 1
kclay commented 9 years ago

Mind supplying a snippet of the query being ran ? Seems you have an Action.async block going on ?