log file sync после ERROR :err=1

HTMLDB - приложение на 9.2.0.4\Linux

PARSING IN CURSOR #36 len=403 dep=1 uid=157 oct=2 lid=157 tim=1145081293741912 hv=3958280034 ad='9f416a68'
INSERT into wwv_flow_data (
                flow_instance,
                item_id,
                item_element_id,
                item_name,
                item_value,
                session_state_status,
                flow_id
            ) values (
                :b6,
                :b5,
                :b4,
                :b3,
                :b2,
                'I',
                :b1)
END OF STMT
PARSE #36:c=0,e=235,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=4,tim=1145081293741897
EXEC #36:c=10000,e=9814,p=0,cr=8,cu=13,mis=0,r=0,dep=1,og=4,tim=1145081293752055
ERROR #36:err=1 tim=1292207488
...
EXEC #36:c=10000,e=4172,p=0,cr=7,cu=11,mis=0,r=0,dep=1,og=4,tim=1145081293975093
ERROR #36:err=1 tim=1292207511
WAIT #36: nam='log file sync' ela= 179898 p1=4091 p2=0 p3=0
...
EXEC #36:c=10000,e=11575,p=0,cr=7,cu=11,mis=0,r=0,dep=1,og=4,tim=1145081294440375
ERROR #36:err=1 tim=1292207558
WAIT #36: nam='log file sync' ela= 666676 p1=4173 p2=0 p3=0
...

и так набегает

INSERT into wwv_flow_data (
                flow_instance,
                item_id,
                item_element_id,
                item_name,
                item_value,
                session_state_status,
                flow_id
            ) values (
                :b6,
                :b5,
                :b4,
                :b3,
                :b2,
                'I',
                :b1)

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute     24      0.15       0.23          0         17        271           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       25      0.15       0.23          0         17        271           0

Misses in library cache during parse: 0
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: 157     (recursive depth: 1)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  log file sync                                  23        0.66          4.11
  latch free                                      6        0.09          0.12
********************************************************************************

и что-то я не пойму какого в этой ситуации возникает log file sync?

Ну и в догонку - latch free тоже имеет немалый вклад (на втором месте ежели по всему файлу)
WAIT nam='latch free' p2=156 или 157, почти у каждого курсора случается такое ожидание, и набегает тоже не слабо. На bind переменные грешить не могу (точнее на их отсутствие).
Буду благодарен за помощь.

на счет log file sync вопрос снимается, ежели не считать то что курсор в котором COMMIT имеет номер #38. (досмотрел трассировку)

EXEC #36:c=10000,e=4172,p=0,cr=7,cu=11,mis=0,r=0,dep=1,og=4,tim=1145081293975093
ERROR #36:err=1 tim=1292207511
WAIT #36: nam='log file sync' ela= 179898 p1=4091 p2=0 p3=0
BINDS #37:
...
EXEC #37:c=0,e=1338,p=0,cr=4,cu=4,mis=0,r=1,dep=1,og=4,tim=1145081294157250
WAIT #38: nam='latch free' ela= 264331 p1=-1637956032 p2=157 p3=0
XCTEND rlbk=0, rd_only=0
EXEC #38:c=0,e=265657,p=0,cr=0,cu=1,mis=0,r=0,dep=1,og=4,tim=1145081294423041

млин, какой-то ограничитель масштабируемости в машинке HTMLDB встроен, при рендеринге страницы ежели присваивать значения ITEM-ам, то машинка каждый айтем сохраняет у себя и каждое сохранение коммитит, надо полагать делает это в цикле! Т. е. ежели на странице у меня 20 айтемов, то на рендеринге страницы будет как минимум 20 коммитов!

Неужели разработчики этой машинки Кайта забыли почитать? Или это специально так сделано...

YAP

млин, какой-то ограничитель масштабируемости в машинке HTMLDB встроен, при рендеринге страницы ежели присваивать значения ITEM-ам, то машинка каждый айтем сохраняет у себя и каждое сохранение коммитит, надо полагать делает это в цикле! Т. е. ежели на странице у меня 20 айтемов, то на рендеринге страницы будет как минимум 20 коммитов! Неужели разработчики этой машинки Кайта забыли почитать? Или это специально так сделано...

Они сохраняют состояние сессий в таблицах (это позволяет, например, переживать ребуты апача без потери состояния). Я не считал взаимосвязть кол-во items/кол-во commits, завтра поисследую, но вроде никогда такого не замечал...

Кайт при разработке HTMLDB (Apex) принимал участие, разработчики говорили что своей масштабируемостью HTMLDB во многом обязан именно Тому.

Как вы присваиваете значения ITEMS (т.е. это один процесс на каждый item, один процесс на всех, присваивания в PL/SQL-блоках или что)?

Q u a d r o

Как вы присваиваете значения ITEMS (т.е. это один процесс на каждый item, один процесс на всех, присваивания в PL/SQL-блоках или что)?

как правило один процесс на все айтемы

предыдущее было на HTMLDB 1.6

попробовал на APEX 2.2 - к сожалению та же фигня

в трассировке процесс, который заполняет три айтема значением "My_TEST_ITEM_VALUE"

PARSING IN CURSOR #48 len=192 dep=1 uid=63 oct=2 lid=63 tim=3202597910451 hv=1223225361 ad='1a965780'
INSERT INTO WWV_FLOW_DATA ( FLOW_INSTANCE, ITEM_ID, ITEM_ELEMENT_ID, ITEM_NAME, ITEM_VALUE, SESSION_STATE_STATUS, FLOW_ID, ITEM_FILTER ) VALUES ( :B7 , :B6 , :B5 , :B4 , :B3 , 'I', :B2 , :B1 )
END OF STMT
PARSE #48:c=0,e=85,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=3202597910445
BINDS #48:
kkscoacd
 Bind#0
...
 Bind#4
  oacdty=01 mxl=32(14) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=01 csi=171 siz=32 off=0
  kxsbbbfp=0fdd7df0  bln=32  avl=14  flg=09
  value="My_TEST_ITEM_VALUE"
...
WAIT #48: nam='db file sequential read' ela= 13978 file#=3 block#=74847 blocks=1 obj#=53774 tim=3202597925522
EXEC #48:c=0,e=15368,p=1,cr=1,cu=10,mis=0,r=1,dep=1,og=1,tim=3202597925891
PARSE #49:c=0,e=12,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=0,tim=3202597926030
XCTEND rlbk=0, rd_only=0
EXEC #49:c=0,e=132,p=0,cr=0,cu=1,mis=0,r=0,dep=1,og=0,tim=3202597926183
...
BINDS #48:
kkscoacd
 Bind#0
...
 Bind#4
  oacdty=01 mxl=32(14) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=01 csi=171 siz=32 off=0
  kxsbbbfp=0fdd7df0  bln=32  avl=14  flg=09
  value="My_TEST_ITEM_VALUE"
...
EXEC #48:c=0,e=477,p=0,cr=0,cu=8,mis=0,r=1,dep=1,og=1,tim=3202597928209
XCTEND rlbk=0, rd_only=0
EXEC #49:c=0,e=119,p=0,cr=0,cu=1,mis=0,r=0,dep=1,og=0,tim=3202597928421
...
BINDS #48:
kkscoacd
 Bind#0
...
 Bind#4
  oacdty=01 mxl=32(14) mxlc=00 mal=00 scl=00 pre=00
  oacflg=13 fl2=206001 frm=01 csi=171 siz=32 off=0
  kxsbbbfp=0fdd7df0  bln=32  avl=14  flg=09
  value="My_TEST_ITEM_VALUE"
..
EXEC #48:c=0,e=1324,p=0,cr=0,cu=8,mis=0,r=1,dep=1,og=1,tim=3202597931182
XCTEND rlbk=0, rd_only=0
EXEC #49:c=0,e=117,p=0,cr=0,cu=1,mis=0,r=0,dep=1,og=0,tim=3202597931407

Можете текст процесса привести?

begin
  :P1_X1:='My_TEST_ITEM_VALUE';
  :P1_X2:='My_TEST_ITEM_VALUE';
  :P1_X3:='My_TEST_ITEM_VALUE';
end;

Сушите веста сЫр!!!

Ты лучше займись установкой ИнфоКиосков!!! [;=)]