Delays in HTTP POST on OTRS 5

[peters]

Hello,

we just upgraded from 4.0.12 to 5.0.15 on Centos6.8 with Apache and mod_perl, DB is potgresql 9.1. Soon after the upgrade, we see 30-50s delays while doing any change on tickets (note, reply, classification). I don't see any errors in apache log. After pressing the Submit button, the HTTP POST is not sent to Apache, or at least is not seen in logs. After 30-50s, it is seen in access log and after 1-2s the pop-up windows of the Note is closed and email is meanwhile received.
We are using local MTA. The delay is seen on Firefox, Edge, Chrome, runnin on Win and Mac.
The spellcheck is disabled (there was similar issue in past here on forums).
This slowness was not present on the version 4.

Thank you for help
Peter

[root]

I would check your DNS settings. Does the delay is also present after you disable all widgets on the dashboards which connects to external sites (RSS, product news, etc.)?

[peters]

DNS should be fine - server is resolvable via fqdn, and DNS requests from server are successfull.
After disabling all widgets except opened tickets, the delay is still present.
Any ideas where to look for errors or warnings?

client-server.PNG

[peters]

Ok so I managed to narrow it to this select, which is runnin for 30s as soon as the Note should be created:

Code: Select all

otrs=#  explain analyze SELECT MAX(create_time) FROM ticket_history  WHERE ticket_id = 2016122300000494 and state_id IN (10, 11, 2, 20, 3, 5, 9)  AND history_type_id IN  (1, 27) ; 
                                                                                   QUERY PLAN                                                                                   
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
 Result  (cost=2424.77..2424.78 rows=1 width=0) (actual time=31856.700..31856.701 rows=1 loops=1)
   InitPlan 1 (returns $0)
     ->  Limit  (cost=0.00..2424.77 rows=1 width=8) (actual time=31856.694..31856.694 rows=0 loops=1)
           ->  Index Scan Backward using ticket_history_create_time on ticket_history  (cost=0.00..189132.40 rows=78 width=8) (actual time=31856.692..31856.692 rows=0 loops=1)
                 Index Cond: (create_time IS NOT NULL)
                 Filter: ((history_type_id = ANY ('{1,27}'::integer[])) AND (ticket_id = 2016122310000494::bigint) AND (state_id = ANY ('{10,11,2,20,3,5,9}'::integer[])))
 Total runtime: 31866.006 ms
(7 rows)

After dropping the index, it executes within ms:

Code: Select all

otrs=#  DROP INDEX ticket_history_create_time;
DROP INDEX
otrs=#  explain analyze SELECT MAX(create_time) FROM ticket_history  WHERE ticket_id = 2016122310000494 and state_id IN (10, 11, 2, 20, 3, 5, 9)  AND history_type_id IN  (1, 27) ; 
                                                                    QUERY PLAN                                                                     
---------------------------------------------------------------------------------------------------------------------------------------------------
 Aggregate  (cost=5262.73..5262.74 rows=1 width=8) (actual time=0.023..0.023 rows=1 loops=1)
   ->  Bitmap Heap Scan on ticket_history  (cost=2623.87..5262.54 rows=78 width=8) (actual time=0.021..0.021 rows=0 loops=1)
         Recheck Cond: ((ticket_id = 2016122310000494::bigint) AND (history_type_id = ANY ('{1,27}'::integer[])))
         Filter: (state_id = ANY ('{10,11,2,20,3,5,9}'::integer[]))
         ->  BitmapAnd  (cost=2623.87..2623.87 rows=725 width=0) (actual time=0.018..0.018 rows=0 loops=1)
               ->  Bitmap Index Scan on ticket_history_ticket_id  (cost=0.00..282.57 rows=15198 width=0) (actual time=0.018..0.018 rows=0 loops=1)
                     Index Cond: (ticket_id = 2016122310000494::bigint)
               ->  Bitmap Index Scan on ticket_history_history_type_id  (cost=0.00..2341.02 rows=145099 width=0) (never executed)
                     Index Cond: (history_type_id = ANY ('{1,27}'::integer[]))
 Total runtime: 0.073 ms
(10 rows)

Any idea what is wrong here?

Thank you
Peter