Otrs Locks Up

[dmritchie2]

Approximately every 2 days, I have to restart Apache and OTRS on my Centos 6.6, Mysql 5.6.16, Perl 5.10.1, and OTRS 3.3.7
When I open up a browser window to the OTRS Application, I get a white screen and it just stops responding.

Restarting Apache gives me a login screen.

I see in the Apache Access logs the following:
"GET / HTTP/1.1" 302 26 "-" "Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/40.0.2214.28 Safari/537.36"

And nothing in the error log at all.

[dmritchie2]

I am seeing this approx. the same time as when I have a system slowdown (I have the performance log turned on):

Interface: Agent, Module: AgentTicketClose;TicketID=6208, Period: 2 minutes

DATE REQUESTS MIN MAX AVERAGE
02/26/2015 10:34 1 926s 926s 926s

Interface: Agent, Module: AgentTicketCompose&AJAXUpdate, Period: 2 minutes

DATE REQUESTS MIN MAX AVERAGE
02/26/2015 10:34 1 926s 926s 926s

Interface: Agent, Module: AgentTicketCompose&SendEmail, Period: 2 minutes

DATE REQUESTS MIN MAX AVERAGE
02/26/2015 10:35 1 926s 926s 926s


I am seeing this kind of response in many different areas:
Interface: Agent, Module: AgentSearch&AJAX,
Interface: Agent, Module: AgentTicketAttachment;ArticleID
Interface: Agent, Module: AgentTicketZoom;TicketID=


Showing that the system is seeing a 15 1/2 minute time to do a job (if I am reading this correctly).
Other than all of the interface(s) being the Agent, Module something, there is nothing else common between all of the slowdowns.

Does anyone have any thoughts on where to look?

[dmritchie2]

Recently updated from 3.3.7 to 4.0.3

[dmritchie2]

Now 4.0.8 and I'm still having the same issue.
Not seeing the long request times anymore relating to the inability to access the system.
Just no login screen until a apache restart.

Instead of seeing in the apache access_log:

10.xx.xx.xx - - [13/Mar/2015:12:40:35 -0500] "GET / HTTP/1.1" 302 26 "-" "Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.39 Safari/537.36"
10.xx.xx.xx - - [13/Mar/2015:12:40:48 -0500] "GET /otrs/index.pl HTTP/1.1" 200 3571 "-" "Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.39 Safari/537.36"

I see the following:

10.xx.xx.xx - - [13/Mar/2015:12:38:11 -0500] "GET / HTTP/1.1" 302 26 "-" "Mozilla/5.0 (Windows NT 6.1; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/42.0.2311.39 Safari/537.36"

[dmritchie2]

Intallation Information

'DatabaseVersion' => 'MySQL 5.6.16',
'FQDN' => 'ticket01.xxx.xxx',
'OSType' => 'Linux',
'OSVersion' => 'centos 6.8',
'OTRSVersion' => '4.0.6',
'PerlVersion' => '5.10.1',

I have recently changed from storing articles in the Database to storing in the file system and that helped.
I changed from using cookies to having the session id in the URL that also helped.
However, I am still having issues.

For example:

Users unable to access the login screen.
I see the following in the Apache Access Log (multiple times if the user attempts to access OTRS multiple times).

10.x.x.x - - [27/Jul/2016:18:23:53 -0500] "GET /otrs/index.pl?Action=AgentDashboard HTTP/1.1" 200 3584 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; Trident/7.0; rv:11.0) like Gecko"

The user has a blank tab in the browser (tried with Chrome, FF & IE all most recent releases).

When changing tabs or trying to access a ticket, it sometimes requires multiple clicks to get the transaction to go through.
No entries in the apache logs or the syslog.

I have been fighting with this now for over 1 1/2 years, does anybody have any ideas as to what I can do?

[EXG133]

What do you get in developer tools on the client when this happens? Are all your posts about an OTRS installation you upgraded on the same server?

[dmritchie2]

Yes, all of the posts are concerning a single instance.

I turned on some additional logging (from mod_security), I got this during one of the "click and nothing happens for 15 1/2 minutes" times:


[01/Aug/2016:11:38:32 --0500] [ticket01.mtc1.com/sid#7fd8377d6850][rid#7fd83d348e08][/otrs/index.pl][4] Initialising transaction (txid V597CArPACgAAD3cFQEAAAAC).
[01/Aug/2016:11:38:32 --0500] [ticket01.mtc1.com/sid#7fd8377d6850][rid#7fd83d348e08][/otrs/index.pl][4] Transaction context created (dcfg 7fd83785da30).
[01/Aug/2016:11:38:32 --0500] [ticket01.mtc1.com/sid#7fd8377d6850][rid#7fd83d348e08][/otrs/index.pl][4] Processing disabled, skipping (hook request_early).
[01/Aug/2016:11:38:32 --0500] [ticket01.mtc1.com/sid#7fd8377d6850][rid#7fd83d348e08][/otrs/index.pl][4] Processing disabled, skipping (hook request_late).
[01/Aug/2016:11:38:32 --0500] [ticket01.mtc1.com/sid#7fd8377d6850][rid#7fd83d348e08][/otrs/index.pl][4] Hook insert_filter: Processing disabled, skipping.
...
Note 15 minutes 26 second delay between these 2 entries The logs continue with other things happening while this thread is waiting.
...
[01/Aug/2016:11:53:58 --0500] [ticket01.mtc1.com/sid#7fd8377d6850][rid#7fd83d348e08][/otrs/index.pl][4] Initialising logging.
[01/Aug/2016:11:53:58 --0500] [ticket01.mtc1.com/sid#7fd8377d6850][rid#7fd83d348e08][/otrs/index.pl][4] Starting phase LOGGING.
[01/Aug/2016:11:53:58 --0500] [ticket01.mtc1.com/sid#7fd8377d6850][rid#7fd83d348e08][/otrs/index.pl][4] Recording persistent data took 0 microseconds.
[01/Aug/2016:11:53:58 --0500] [ticket01.mtc1.com/sid#7fd8377d6850][rid#7fd83d348e08][/otrs/index.pl][4] Audit log: Ignoring a non-relevant request.

As far as the Developer Tools question, I get a partial page (headers or nothing if it is prior to a logon, it shows the current page info if a click and nothing happens) usually if a click does nothing, a second click (or even a 3rd click) will get a response.

Is there an issue with OTRS and mod_security? I have seen some posts on line that seem to indicate such but they were years old.

[wurzel]

Hi,

local firewall active? SELINUX?

Flo

[dmritchie2]

SeLinux is disabled.

As far as firewalls go, the only one is the web application firewall (modsecurity with Apache).

The system works normally for >95% of the time, it just seems that occasionally we hit a snag that just stops the current webpage what ever it is, new logon screen or opening a ticket or article.

The CPUs are not being hit hard nor is the memory or disk space (8 CPUs, 4 GB RAM, 12 GB disk w/ 8GB Free) running in a VM, connecting to an external MySQL server.

[crythias]

Also, what does top say?

[dmritchie2]

BTW, I should mention that since moving the article storage from the DB to the FS and also switching from cookies to URL storage of session IDs, I haven't had to restart the Apache server for several months (excepting since I started making changes to logging lately).

WRT Top:

top - 17:33:08 up 15 days, 4:17, 1 user, load average: 0.01, 0.02, 0.00
Tasks: 281 total, 1 running, 280 sleeping, 0 stopped, 0 zombie
Cpu(s): 0.1%us, 0.0%sy, 0.0%ni, 99.9%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 3872592k total, 3507160k used, 365432k free, 171304k buffers
Swap: 2064380k total, 4860k used, 2059520k free, 1324028k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1 root 20 0 33672 1388 1168 S 0.0 0.0 0:00.71 init
2 root 20 0 0 0 0 S 0.0 0.0 0:00.00 kthreadd
3 root RT 0 0 0 0 S 0.0 0.0 0:03.43 migration/0
4 root 20 0 0 0 0 S 0.0 0.0 0:03.45 ksoftirqd/0
5 root RT 0 0 0 0 S 0.0 0.0 0:00.00 stopper/0
6 root RT 0 0 0 0 S 0.0 0.0 0:02.13 watchdog/0
7 root RT 0 0 0 0 S 0.0 0.0 0:03.44 migration/1
8 root RT 0 0 0 0 S 0.0 0.0 0:00.00 stopper/1
9 root 20 0 0 0 0 S 0.0 0.0 0:02.78 ksoftirqd/1
10 root RT 0 0 0 0 S 0.0 0.0 0:01.93 watchdog/1
11 root RT 0 0 0 0 S 0.0 0.0 0:03.42 migration/2
12 root RT 0 0 0 0 S 0.0 0.0 0:00.00 stopper/2
13 root 20 0 0 0 0 S 0.0 0.0 0:02.25 ksoftirqd/2
14 root RT 0 0 0 0 S 0.0 0.0 0:01.87 watchdog/2
15 root RT 0 0 0 0 S 0.0 0.0 0:03.43 migration/3

[dmritchie2]

I will, of course, continue to monitor and the next time I get a web page slow down, I will post all appropriate information again.

[dmritchie2]

From the OTRS VM during one of the delays


MySQL Process List:

Code: Select all

Id           User             Host                           db      Command Time          State             Info
906252  otrs_user       10.2x.0.40:60818       otrs    Sleep        0               NULL
907075  otrs_user       10.2x.0.40:60888       otrs    Sleep        5890            NULL
907220  otrs_user       10.2x.0.40:60894       otrs    Sleep        4084            NULL
907279  otrs_user       10.2x.0.40:60898       otrs    Sleep        6498            NULL
907283  otrs_user       10.2x.0.40:60900       otrs    Sleep        6904            NULL
907285  otrs_user       10.2x.0.40:60902       otrs    Sleep          113             NULL
907430  otrs_user       10.2x.0.40:60906       otrs    Sleep          116             NULL
907431  otrs_user       10.2x.0.40:60908       otrs    Sleep          186             NULL
907432  otrs_user       10.2x.0.40:60910       otrs    Sleep          118             NULL
907433  otrs_user       10.2x.0.40:60912       otrs    Sleep        5288            NULL
907481  otrs_user       10.2x.0.40:60924       otrs    Sleep        2655            NULL
907491  otrs_user       10.2x.0.40:60926       otrs    Sleep        6494            NULL
907723  otrs_user       10.2x.0.40:60934       otrs    Sleep        1088            NULL
907766  otrs_user       10.2x.0.40:60936       otrs    Sleep        2054            NULL
912799  otrs_user       10.2x.0.40:32972       otrs    Sleep        1114            NULL
913752  otrs_user       10.2x.0.40:33008       otrs    Sleep          346             NULL
914029  otrs_user       10.2x.0.40:33030       NULL    Query           0             init           SHOW FULL PROCESSLIST

[dmritchie2]

Made some changes to ossec and mod_security.

Still seeing this in the syslog:

Aug 5 08:59:03 ticket01 OTRS-CGI-61[15116]: [Notice][Kernel::System::Web::InterfaceAgent::Run] Response::Agent: 926s taken (URL:Action=AgentDashboard&Subaction=Element:dritchie)