Missing query plan for auto_explain.

Our Postgres recently started reporting considerably different execution times for the same query. When executed from our JDBC application the Postgres logs report an average execution time of 1500 ms but when the query is manually executed through `psql` it doesn't take longer than 50 ms.

With a view to investigate discrepancies in the plan we enabled `auto_explain` in `session_preload_libraries` with `auto_explain.log_min_duration = '1s'`. All application servers were bounced to ensure new connections were created and picked up the changes. However this trouble query does not have an explain plan printed, even when its execution time exceeds the threshold (other queries do though).

Does anyone have ideas of why the explain plan is not being printed?

Sample log entry for trouble query executed from application:
```
Aug 26 09:11:33 db-931 postgres[8106]: [66-1] 2022-08-26 09:11:33 GMT [8106]: [5-1] db=betwave,user=betwave_app_readonly_user LOG:  duration: 1423.481 ms  bind <unnamed>: /*@ org.sixty6.as66.QueryID:report.framework.userSearch */select users.user_id, users.unique_identifier, user_profile.name, user_profile.email, organisation.organisation_id, organisation.description, user_realm.user_realm_id, user_realm.description as col_8, user_realm.type, user_realm_category.description as col_10, vip_schema.description as col_11, vip_level.description as col_12, affiliate.description as col_13, users.status, users.creation_date, user_statistics.last_user_session_creation_date, users.real_base_currency, users.fun_base_currency, local_balance_account.balance
Aug 26 09:11:33 db-931 postgres[8106]: [66-2] #011from users users
Aug 26 09:11:33 db-931 postgres[8106]: [66-3] #011join user_profile user_profile
Aug 26 09:11:33 db-931 postgres[8106]: [66-4] #011on user_profile.user_id = users.user_id
Aug 26 09:11:33 db-931 postgres[8106]: [66-5] #011join user_realm user_realm
Aug 26 09:11:33 db-931 postgres[8106]: [66-6] #011on user_realm.user_realm_id = users.user_realm_id
Aug 26 09:11:33 db-931 postgres[8106]: [66-7] #011join organisation organisation
Aug 26 09:11:33 db-931 postgres[8106]: [66-8] #011on organisation.organisation_id = user_realm.organisation_id
Aug 26 09:11:33 db-931 postgres[8106]: [66-9] #011join acl_allowed_organisation acl_allowed_organisation
Aug 26 09:11:33 db-931 postgres[8106]: [66-10] #011on acl_allowed_organisation.organisation_id = organisation.organisation_id and acl_allowed_organisation.permission = $1 and acl_allowed_organisation.user_id = $2
Aug 26 09:11:33 db-931 postgres[8106]: [66-11] #011join affiliate affiliate
Aug 26 09:11:33 db-931 postgres[8106]: [66-12] #011on affiliate.affiliate_id = users.affiliate_id
Aug 26 09:11:33 db-931 postgres[8106]: [66-13] #011join acl_allowed_affiliate acl_allowed_affiliate
Aug 26 09:11:33 db-931 postgres[8106]: [66-14] #011on acl_allowed_affiliate.affiliate_id = affiliate.affiliate_id and acl_allowed_affiliate.permission = $3 and acl_allowed_affiliate.user_id = $4
Aug 26 09:11:33 db-931 postgres[8106]: [66-15] #011join acl_allowed_user_realm_category acl_allowed_user_realm_category
Aug 26 09:11:33 db-931 postgres[8106]: [66-16] #011on acl_allowed_user_realm_category.user_realm_category_id = user_realm.user_realm_category_id and acl_allowed_user_realm_category.permission = $5 and acl_allowed_user_realm_category.user_id = $6
Aug 26 09:11:33 db-931 postgres[8106]: [66-17] #011join user_statistics user_statistics
Aug 26 09:11:33 db-931 postgres[8106]: [66-18] #011on user_statistics.user_id = users.user_id
Aug 26 09:11:33 db-931 postgres[8106]: [66-19] #011join vip_level vip_level
Aug 26 09:11:33 db-931 postgres[8106]: [66-20] #011on vip_level.vip_level_id = users.vip_level_id
Aug 26 09:11:33 db-931 postgres[8106]: [66-21] #011join vip_schema vip_schema
Aug 26 09:11:33 db-931 postgres[8106]: [66-22] #011on vip_schema.vip_schema_id = vip_level.vip_schema_id
Aug 26 09:11:33 db-931 postgres[8106]: [66-23] #011join user_realm_category user_realm_category
Aug 26 09:11:33 db-931 postgres[8106]: [66-24] #011on user_realm_category.user_realm_category_id = user_realm.user_realm_category_id
Aug 26 09:11:33 db-931 postgres[8106]: [66-25] #011left join local_balance_account local_balance_account
Aug 26 09:11:33 db-931 postgres[8106]: [66-26] #011on local_balance_account.user_id = users.user_id and local_balance_account.currency = users.real_base_currency and local_balance_account.balance_category = $7 and local_balance_account.primary_balance = $8
Aug 26 09:11:33 db-931 postgres[8106]: [66-27] #011where users.type in ($9, $10) and user_realm.type in ($11, $12, $13) and users.unique_identifier like $14 escape '\'
Aug 26 09:11:33 db-931 postgres[8106]: [66-28] #011order by users.unique_identifier asc, user_realm.user_realm_id asc
Aug 26 09:11:33 db-931 postgres[8106]: [66-29] #011limit $15
Aug 26 09:11:33 db-931 postgres[8106]: [66-30] 2022-08-26 09:11:33 GMT [8106]: [6-1] db=betwave,user=betwave_app_readonly_user DETAIL:  parameters: $1 = 'READ', $2 = '1468137', $3 = 'READ', $4 = '1468137', $5 = 'READ', $6 = '1468137', $7 = 'CASH', $8 = 't', $9 = 'LOCAL', $10 = 'EXTERNAL', $11 = 'ADMIN', $12 = 'HUB', $13 = 'PLAYER', $14 = 'robinson06%', $15 = '200'
```

Sample log entry for another query executed from application:
```
Aug 26 15:10:58 db-931 postgres[40727]: [71-1] 2022-08-26 15:10:58 GMT [40727]: [15-1] db=betwave,user=betwave_app_readonly_user LOG:  duration: 1069.964 ms  plan:
Aug 26 15:10:58 db-931 postgres[40727]: [71-2] #011Query Text: /*@ org.sixty6.as66.QueryID:health.betwave.game.external.InProgressGamePlays:com.betconstruct */select x.hour, sum(x.in_progress_count) as col_2, sum(x.closed_count) as col_3
Aug 26 15:10:58 db-931 postgres[40727]: [71-3] #011from ((select date_trunc('hour',game_play.start_date AT TIME ZONE INTERVAL '0 seconds') AT TIME ZONE INTERVAL '0 seconds' as hour, count(*) as in_progress_count, $1 as closed_count
Aug 26 15:10:58 db-931 postgres[40727]: [71-4] #011from game_play game_play
Aug 26 15:10:58 db-931 postgres[40727]: [71-5] #011join game_profile game_profile
Aug 26 15:10:58 db-931 postgres[40727]: [71-6] #011on game_profile.game_profile_id = game_play.game_profile_id
Aug 26 15:10:58 db-931 postgres[40727]: [71-7] #011join game game
Aug 26 15:10:58 db-931 postgres[40727]: [71-8] #011on game.game_id = game_profile.game_id
Aug 26 15:10:58 db-931 postgres[40727]: [71-9] #011where game.game_engine_id = $2 and game_play.status = $3 and game_play.start_date >= $4 and game_play.start_date < $5
Aug 26 15:10:58 db-931 postgres[40727]: [71-10] #011group by date_trunc('hour',game_play.start_date AT TIME ZONE INTERVAL '0 seconds') AT TIME ZONE INTERVAL '0 seconds')
Aug 26 15:10:58 db-931 postgres[40727]: [71-11] #011union all
Aug 26 15:10:58 db-931 postgres[40727]: [71-12] #011(select date_trunc('hour',game_activity.interval_start_date AT TIME ZONE INTERVAL '0 seconds') AT TIME ZONE INTERVAL '0 seconds' as hour, $6 as in_progress_count, sum(game_activity.game_play_count) as closed_count
Aug 26 15:10:58 db-931 postgres[40727]: [71-13] #011from game_activity game_activity
Aug 26 15:10:58 db-931 postgres[40727]: [71-14] #011join game game
Aug 26 15:10:58 db-931 postgres[40727]: [71-15] #011on game.game_id = game_activity.game_id
Aug 26 15:10:58 db-931 postgres[40727]: [71-16] #011where game.game_engine_id = $7 and tstzrange($8, $9, $10) @> tstzrange(game_activity.interval_start_date, game_activity.interval_end_date, $11)
Aug 26 15:10:58 db-931 postgres[40727]: [71-17] #011group by date_trunc('hour',game_activity.interval_start_date AT TIME ZONE INTERVAL '0 seconds') AT TIME ZONE INTERVAL '0 seconds')) as x
Aug 26 15:10:58 db-931 postgres[40727]: [71-18] #011group by x.hour
Aug 26 15:10:58 db-931 postgres[40727]: [71-19] #011having sum(x.in_progress_count) > $12 and sum(x.in_progress_count) + sum(x.closed_count) >= $13 and sum(x.in_progress_count) >= (sum(x.in_progress_count) + sum(x.closed_count)) * $14
Aug 26 15:10:58 db-931 postgres[40727]: [71-20] #011GroupAggregate  (cost=10069.43..10072.16 rows=1 width=72)
Aug 26 15:10:58 db-931 postgres[40727]: [71-21] #011  Group Key: "*SELECT* 1".hour
Aug 26 15:10:58 db-931 postgres[40727]: [71-22] #011  Filter: ((sum("*SELECT* 1".in_progress_count) > '0'::numeric) AND ((sum("*SELECT* 1".in_progress_count) + sum((('0'::bigint)::numeric))) >= '0'::numeric) AND (sum("*SELECT* 1".in_progress_count) >= ((sum("*SELECT* 1".in_progress_count) + sum((('0'::bigint)::numeric))) * '0'::numeric)))
Aug 26 15:10:58 db-931 postgres[40727]: [71-23] #011  ->  Sort  (cost=10069.43..10069.53 rows=39 width=48)
Aug 26 15:10:58 db-931 postgres[40727]: [71-24] #011        Sort Key: "*SELECT* 1".hour
Aug 26 15:10:58 db-931 postgres[40727]: [71-25] #011        ->  Append  (cost=10048.65..10068.01 rows=39 width=48)
Aug 26 15:10:58 db-931 postgres[40727]: [71-26] #011              ->  Subquery Scan on "*SELECT* 1"  (cost=10048.65..10050.08 rows=38 width=48)
Aug 26 15:10:58 db-931 postgres[40727]: [71-27] #011                    ->  GroupAggregate  (cost=10048.65..10049.60 rows=38 width=24)
Aug 26 15:10:58 db-931 postgres[40727]: [71-28] #011                          Group Key: (timezone('00:00:00'::interval, date_trunc('hour'::text, timezone('00:00:00'::interval, game_play.start_date))))
Aug 26 15:10:58 db-931 postgres[40727]: [71-29] #011                          ->  Sort  (cost=10048.65..10048.75 rows=38 width=8)
Aug 26 15:10:58 db-931 postgres[40727]: [71-30] #011                                Sort Key: (timezone('00:00:00'::interval, date_trunc('hour'::text, timezone('00:00:00'::interval, game_play.start_date))))
Aug 26 15:10:58 db-931 postgres[40727]: [71-31] #011                                ->  Nested Loop  (cost=116.74..10047.66 rows=38 width=8)
Aug 26 15:10:58 db-931 postgres[40727]: [71-32] #011                                      ->  Hash Join  (cost=116.33..209.84 rows=18 width=8)
Aug 26 15:10:58 db-931 postgres[40727]: [71-33] #011                                            Hash Cond: (game_profile.game_id = game.game_id)
Aug 26 15:10:58 db-931 postgres[40727]: [71-34] #011                                            ->  Seq Scan on game_profile  (cost=0.00..86.54 rows=2654 width=16)
Aug 26 15:10:58 db-931 postgres[40727]: [71-35] #011                                            ->  Hash  (cost=116.12..116.12 rows=16 width=8)
Aug 26 15:10:58 db-931 postgres[40727]: [71-36] #011                                                  ->  Seq Scan on game  (cost=0.00..116.12 rows=16 width=8)
Aug 26 15:10:58 db-931 postgres[40727]: [71-37] #011                                                        Filter: ((game_engine_id)::text = 'com.betconstruct'::text)
Aug 26 15:10:58 db-931 postgres[40727]: [71-38] #011                                      ->  Index Scan using game_play_operable_unq01 on game_play_operable game_play  (cost=0.42..546.45 rows=8 width=16)
Aug 26 15:10:58 db-931 postgres[40727]: [71-39] #011                                            Index Cond: (game_profile_id = game_profile.game_profile_id)
Aug 26 15:10:58 db-931 postgres[40727]: [71-40] #011                                            Filter: ((start_date >= '2022-08-25 16:00:00+00'::timestamp with time zone) AND (start_date < '2022-08-26 15:00:57.028601+00'::timestamp with time zone) AND ((status)::text = 'IN_PROGRESS'::text))
Aug 26 15:10:58 db-931 postgres[40727]: [71-41] #011              ->  GroupAggregate  (cost=17.70..17.73 rows=1 width=48)
Aug 26 15:10:58 db-931 postgres[40727]: [71-42] #011                    Group Key: (timezone('00:00:00'::interval, date_trunc('hour'::text, timezone('00:00:00'::interval, game_activity.interval_start_date))))
Aug 26 15:10:58 db-931 postgres[40727]: [71-43] #011                    ->  Sort  (cost=17.70..17.70 rows=1 width=16)
Aug 26 15:10:58 db-931 postgres[40727]: [71-44] #011                          Sort Key: (timezone('00:00:00'::interval, date_trunc('hour'::text, timezone('00:00:00'::interval, game_activity.interval_start_date))))
Aug 26 15:10:58 db-931 postgres[40727]: [71-45] #011                          ->  Nested Loop  (cost=0.70..17.69 rows=1 width=16)
Aug 26 15:10:58 db-931 postgres[40727]: [71-46] #011                                ->  Index Scan using game_activity_ix01 on game_activity  (cost=0.42..8.44 rows=1 width=24)
Aug 26 15:10:58 db-931 postgres[40727]: [71-47] #011                                      Index Cond: (tstzrange(interval_start_date, interval_end_date, '[]'::text) <@ '["2022-08-25 16:00:00+00","2022-08-26 16:00:00+00"]'::tstzrange)
Aug 26 15:10:58 db-931 postgres[40727]: [71-48] #011                                ->  Index Scan using pk_game on game game_1  (cost=0.28..8.30 rows=1 width=8)
Aug 26 15:10:58 db-931 postgres[40727]: [71-49] #011                                      Index Cond: (game_id = game_activity.game_id)
Aug 26 15:10:58 db-931 postgres[40727]: [71-50] #011                                      Filter: ((game_engine_id)::text = 'com.betconstruct'::text)
```

Our environment consists of PostgreSQL 13.6 on Linux.