10

Суть проблемы такова что любые операции с бд выполняются очень долго, к примеру: . insert into tab1 (time) values sysdate Выполняется 40-60 мс. А при записи в бд >1000 значений, получаем очень длительную запись. Бд oracle 11gR2 ОС Oracle Linux на CentOs аналогичная проблема. Помогите пожалуйста разобраться.

Оказывается что выгрузка с БД и т.д выполняются почти моментально, проблема только с INSERT (записью в БД)

Всё, что использует родной OCI драйвер (sqlplus, dbForge) отрабатывает нормально, а всё остальное, SQL Net, Thin JDBC (SqlDev, TOAD) тормозит, причём только на DML, и со стороны ДБ время выполненения выглядит нормально.

internal class Program
    {
        private static void Main()
        {
            var stopwatch = Stopwatch.StartNew();

          //  DateTime dt = new DateTime();
            try
            {
                const string oradb = "Data Source = 192.168.137.70/xe; " +
                                     "User id = useridb; Password = user1234";
#pragma warning disable 618
               var con = new OracleConnection(oradb);
#pragma warning restore 618
                con.Open();


#pragma warning disable 618
                var cmd = new OracleCommand {Connection = con};
#pragma warning restore 618



                for (var i = 0; i < 1000; i++)
                {
                    cmd.CommandText = "Insert into test (datetime) values (sysdate)";
                    //cmd.CommandText = "Select max(datetime) from test";
                    var dr = cmd.ExecuteReader();
                    dr.Read();

                   // dt = Convert.ToDateTime(dr.GetValue(0));
                    dr.Close();
                   // Thread.Sleep(50);
                }



                stopwatch.Stop();
                var averageTime = new TimeSpan(stopwatch.ElapsedMilliseconds / 1000);
                Console.WriteLine("Запись успешна {0},  {1}", averageTime, dt);
            }
            catch (Exception e)
            {
                Console.WriteLine("Error{0}", e.Message);
            }
            Console.ReadKey();
        }
    }
25
  • А как у ОС с оперативной памятью, нагруженностью? Много ли места на жестком? Нет ли каких-либо триггеров, навешанных на ту таблицу
    – gil9red
    3 авг 2017 в 5:55
  • @gil9red оперативы 64 Гб жесткие диски 2 штуки в raid массиве по 1 тб. Свободного места более чем, бд новая и не содержит пока много информации, есть тригеры, но на других схемах и таблицах такая же проблема
    – Ethernets
    3 авг 2017 в 6:04
  • Диски еще чем нибудь эдаким не нагружены ? raid какого типа ? надеюсь оракл имеет прямой доступ к железу, систем виртуализации нет ? Где расположены redo логи и flash_recovery_area ...
    – Mike
    3 авг 2017 в 6:37
  • @Mike диски больше ничем не нагружены, raid 1-го типа, да ОС и бд имеют прямой доступ к железу, redo - простите не знаю где глянуть, flash_recovery_area находится в папке где и папка с базой, пример /app/flash_recovery_area и бд /app/oracle
    – Ethernets
    3 авг 2017 в 6:57
  • 1
    @0xdb Спасибо за проявленный интерес. Но пока ничем, вашь ответ пока не было возможности опробовать, завтра думаю доберусь (был в командировке, извиняюсь за задержку). Попробовал построить план, так вот ничего там лишнего нет, и в плане запрос выполнился за 1мс. Как сказал выше завтра буду пробовать решение 0xdb. О результатах сразу сообщу. Спасибо
    – Ethernets
    29 авг 2017 в 10:47

2 ответа 2

6
+50

На то существует ораклевская инструкция EXPLAIN PLAN, типа:

 EXPLAIN PLAN FOR INSERT INTO TABLE values(10)

выдаст вам что происходит, когда вы делаете вставку записи.

Как читать вывод и что делать подробнейшим образом расписано в документации

грубо говоря, вы увидите где "бутылочное горлышко" - то ли это формируется VIEW или отрабатывает триггер или условие при вставке или что-то еще.

4

Надо включить SQL трассировку. В противоположенность EXPLAIN PLAN, будет показано "то, что уже было", а не "то, что ещё будет". Если и не приведёт к решению проблемы сразу, то даст направление, куда дальше искать.

Для начала надо проверить, включена ли TIMED_STATISTICS (по умолчанию включена) и куда пишутся файлы трассировки (обычно $ORA_BASE/diag/rdbms/orasid/orasid/trace):

select name, value from v$parameter where name in ('timed_statistics','user_dump_dest');

Выбираем кандидатов, например сессии на удалённом SQL Developer и SQL*Plus локально на сервере БД:

select s.username, s.status, s.sid, s.serial#, sql_trace, s.program, p.spid 
from v$session s join v$process p on s.paddr = p.addr
where s.username = 'SH1';

USERNAME      STATUS          SID    SERIAL# SQL_TRAC PROGRAM                        SPID 
------------- -------- ---------- ---------- -------- ------------------------------ ------
SH1           ACTIVE          139         41 DISABLED SQL Developer                  26596
SH1           INACTIVE         15         92 DISABLED sqlplus@mpsrv (TNS V1-V3)      25930 

Включаем трассировку под пользователем с DBA привилегиями:

exec sys.dbms_monitor.session_trace_enable(session_id=>139, serial_num=>41, waits=>true, binds=>false);
exec sys.dbms_monitor.session_trace_enable(session_id=>15,  serial_num=>92, waits=>true, binds=>false);

В выбраных клиентах производим запрос(ы):

insert into tab1 (time) values (sysdate);
commit;

И выключаем трассировку:

exec sys.dbms_monitor.session_trace_disable(session_id=>139, serial_num=>41);
exec sys.dbms_monitor.session_trace_disable(session_id=>15,  serial_num=>92);

Находим файлы трассировки в папке user_dump_dest (см. выше) и приводим к читабелному виду с tkprof:

  $ ls -1t *26596.trc *25930.trc
myoradb_ora_25930.trc
myoradb_ora_25507.trc

tkprof myoradb_ora_25930.trc sqlp_25930.prf explain=sh1/sh1
tkprof myoradb_ora_26596.trc sqld_26596.prf explain=sh1/sh1

Выход tkprof будет выглядеть где-то так:

********************************************************************************
count    = number of times OCI procedure was executed
cpu      = cpu time in seconds executing
elapsed  = elapsed time in seconds executing
disk     = number of physical reads of buffers from disk
query    = number of buffers gotten for consistent read
current  = number of buffers gotten in current mode (usually for update)
rows     = number of rows processed by the fetch or execute call
********************************************************************************
SQL ID: f281fbsngrwq0
Plan Hash: 0
insert into tab1 (time)
values
 (sysdate)


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          1          5           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          1          5           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 151  (SH1)

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  LOAD TABLE CONVENTIONAL  (cr=1 pr=0 pw=0 time=0 us)


Rows     Execution Plan
-------  ---------------------------------------------------
      0  INSERT STATEMENT   MODE: ALL_ROWS
      0   LOAD TABLE CONVENTIONAL OF 'TAB1'


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00
********************************************************************************

Для сравнения, в SQL Developer заметно значительное ожидание ответа от клиента, т.к. не высокоскоростное соединение с сервером. И кроме того, SQL ID отличается, т.е. оракле не распознал запрос как идентичный:

********************************************************************************
SQL ID: gck3089qg8n7x
Plan Hash: 0
insert into tab1 (time)
values
 (sysdate)

...    
Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  Disk file operations I/O                        1        0.00          0.00
  log file sync                                   1        0.01          0.01
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        4.07          4.07

Подробнее о других возможностях и чтении форматированного вывода tkprof в документаци.

Замечу: имеет смысл трассировка в конфигурации выделенного сервера, в случае распределённых серверов очень трудоёмкая задача собирать трассировку, т.к. даже один запрос может быть распарсен в одном сервере, а выполнен в другом.

Ваш ответ

By clicking “Отправить ответ”, you agree to our terms of service and acknowledge that you have read and understand our privacy policy and code of conduct.

Всё ещё ищете ответ? Посмотрите другие вопросы с метками или задайте свой вопрос.