| Summary: | Время загрузки 1с77 существенно увеличивается с ростом количества пользователей | ||
|---|---|---|---|
| Product: | CIFS@Etersoft | Reporter: | Боренко Денис <denis> |
| Component: | блокировки файлов и доступ | Assignee: | Vitaly Lipatov <lav> |
| Status: | CLOSED FIXED | QA Contact: | |
| Severity: | normal | ||
| Priority: | P3 | CC: | amorozov, baraka, kondratyuk, lav, lbeasty, piastry, sin |
| Version: | не указана | ||
| Target Milestone: | --- | ||
| Hardware: | PC | ||
| OS: | All | ||
| Whiteboard: | |||
| Заявки RT: | Связано с: | 2915 | |
| Дата напоминания: | |||
| Bug Depends on: | |||
| Bug Blocks: | 3589 | ||
Вот на всякий случай дебаг с таймингами: [ 3120.734159] file.c: CIFS VFS: in cifs_lock as Xid: 142 with uid: 1000 [ 3120.734169] file.c: Lock parm: 0x5 flockflags: 0x1 flocktype: 0x1 start: 10000006 end: 10000006 [ 3120.734178] file.c: Posix [ 3120.734185] file.c: F_WRLCK [ 3120.734200] cifssmb.c: CIFSSMBLock timeout 0 numLock 1 [ 3120.734213] transport.c: For smb_command 36 [ 3120.734222] transport.c: Sending smb: total_len 75 [ 3120.938554] connect.c: rfc1002 length 0x27 [ 3120.938612] netmisc.c: Mapping smb error code 33 to POSIX err -13 [ 3120.938625] cifssmb.c: Send error in Lock = -13 [ 3120.938638] cifssmb.c: CIFSSMBLock timeout 0 numLock 1 [ 3120.938650] transport.c: For smb_command 36 [ 3120.938656] transport.c: Sending smb: total_len 75 [ 3121.141408] connect.c: rfc1002 length 0x27 [ 3121.141439] netmisc.c: Mapping smb error code 33 to POSIX err -13 [ 3121.141448] cifssmb.c: Send error in Lock = -13 [ 3121.141455] file.c: CIFS VFS: leaving cifs_lock (xid = 142) rc = 0 Этот вызов должен быть. Мы ограничены возможностями SMB протокола в данном случае и лучшего решения выполнить запрос F_GETLK, чем попытаться заблокировать этот участок, нет. Два раза вызов выполняется в том случае, если первый раз обвалился запрос на блокировку на запись, и мы не можем без дополнительных проверок выяснить, какая блокировка стоит - на запись или чтение. Обратите внимание, двойной вызов выполняется на запросе F_WRLCK. Да! Происходит запрос F_GETLK на F_WRLCK. Обламывается. Какие варианты? Или стоит блокировка на запись или на чтение - непонятно. Пробуем ставить блокировку на чтение и по результатам однозначно определяем установленную блокировку. К сожалению я не вник в этот долбаный cifs настолько, что бы ответить вам. Буду думать. Но ограничения SMB не причем вроде -- винда же обходится одним запросом. Судя по дампу, винде хватает только запроса с LockType=0x10. Т.е. ей пофиг какая там стоит блокировка -- стоит и ладно. В линуксе такой номер не проходит (не возвращать тип блокировки)? Это ограничение самой системы? Ну это уже зависит от того, в каких случаях F_GETLK используется в Wine. Думаю непосредственные разработчики Wine прояснят этот вопрос. В Windows такого запроса вообще нет. Насколько я знаю, в 1cv77 вообще не используется функция LockFileEx(), которая может установить блокировку на чтение - потому можно собрать версию etercifs для неё без второй проверки. Но в таком случае не гарантируется правильная работа остальных приложений с шарой. (In reply to comment #5) > Но ограничения SMB не причем вроде -- винда же > обходится одним запросом. > В случае F_GETLK запроса следует говорить именно об ограничениях протокола. А можно какой-нибудь ключик при монтировании отключающий второй запрос? Просто реально задолбало, при сорока пользователях ожидание растягивается на 15 сек до ввода пароля и 15 сек после ввода. Причем самое интересное, что сервер долго отвечает именно на второй запрос. Я правильно понимаю, что дополнительное обращение к серверу вызвано особенностями реализации LockFile в Wine? Можно ли синтетически воспроизвести проблему с большой задержкой в RECT? Ключик можно. Тоже кстати, вариант только для 1cv77. Да, именно LockFile. В каких случаях используется запрос на F_GETLK? Да. Воспроизводится уверенно на сервере самбой 3.2.3. Надо открыть одну и ту же базу несколько раз. С каждым новым пользователем время после выбора базы и до окошка ввода пароля будет расти. При 40 пользователях это около 15 сек. Причем не важно заходить в базу по сети или на локальную подмаунченую по цивс. Скомпилил без вторго запроса (просто возвращаю тип F_WRLCK). Время появления окна ввода пароля уменьшилось, но все равно очень большое, по сравнению с виндой. Наверное что-то с пакетом на запрос блокировки не так. Попробую на досуге получить более подробный дамп. [ 1635.006329] file.c: CIFS VFS: in cifs_lock as Xid: 12788 with uid: 1000 [ 1635.006339] file.c: Lock parm: 0x5 flockflags: 0x1 flocktype: 0x1 start: 10000010 end: 10000010 [ 1635.006345] file.c: Posix [ 1635.006351] file.c: F_WRLCK [ 1635.006357] cifssmb.c: CIFSSMBLock timeout 0 numLock 1 [ 1635.006366] transport.c: For smb_command 36 [ 1635.006372] transport.c: Sending smb: total_len 75 **********Вот откуда такая задержка?*************** [ 1635.209658] connect.c: rfc1002 length 0x27 [ 1635.209717] netmisc.c: Mapping smb error code 33 to POSIX err -13 [ 1635.209731] cifssmb.c: Send error in Lock = -13 [ 1635.209739] file.c: CIFS VFS: leaving cifs_lock (xid = 12788) rc = 0 На том же сервере окно ввода пароля в виндовом клиенте появляется за 1 сек. Может кто подскажет почему там в третей строке Posix написано? Шара смонтирована с forcemand. Не может это влиять? Блин, вообще полтергейст. Иногда (в 1 из 20 случаев) задержка отсутствует. Искуственно добится этого не получается, но как правило это первый вход после первого монтирования ресурса или рестарта модуля. Не может сервер какое-то время ждать блокировки перед ответом? (In reply to comment #14) > Иногда (в 1 из 20 случаев) задержка отсутствует. Возможно, это когда кто-то выходит из 1С и освобождается один из первых залоченых байтов. Тогда все логично и моя паника напрасна. (In reply to comment #14) ... > это первый вход после первого монтирования > ресурса или рестарта модуля. Не может Так это не запуск с оплоками (когда никто другой ещё не держит файлы)? > сервер какое-то время ждать блокировки > перед ответом? Насколько я знаю, некоторые искусственные задержки есть в сервере SAMBA (или в протоколе??). Но это легко проверяется, с виндовым сервером. > (In reply to comment #14)
> Так это не запуск с оплоками (когда никто
> другой ещё не держит файлы)?
Нет. Оплоки не причем.
Проблема только в одном:
В момент запуска 1С происходит попытка захватить на запись байт лежащий за концом файлов 1CV7.LCK и /SYSLOG/links.tmp
Лок на запись этого байта удерживается экземпляром 1С все время его работы. Именно по этим байтам работает Монитор пользователей.
При попытке захватить лок 1с перебирает байты по одному с 10000000 и если захватить не удалось пробует следующий, пока не добьется установки блокировки. Ответ сервера при занятом байте линуксовому клиенту занимает много времени (~200 мс запрос блокировки на запись и ~500 мс запрос блокировки на чтение ).Виндовая же машина делает только запрос на запись и получает ответ значительно быстрее.
Логично предположить, что подобным же образом ставятся локи на файлы базы при проведении документов. Таким образом этот глюк также может влиять на производительность проведения и записи документов (правда в значительно меньшей степени). Корень зла найден. Обнаружилось, что запросов на блокировку не 2, а 3. Первые два на запись, последний -- на чтение. На первый мы получаем ответ NT_STATUS_LOCK_NOT_GRANDED (0х55) На два последующих -- NT_STATUS_LOCK_CONFLICT (0x54) Такая последовательность не случайна, это специально написаная на самбовском сервере процедура, пытающаяся спародировать w2k3 и меняющая тип ответа при повторном запросе блокировки одного и того же окна байтов. Причем интересен следующий комментарий в smbd/reply.c /* This heuristic seems to match W2K3 very well. If a lock sent with timeout of zero would fail with NT_STATUS_FILE_LOCK_CONFLICT it pretends we asked for a timeout of between 150 - 300 milliseconds as far as I can tell. Replacement for do_lock_spin(). JRA. */ Вобщем все. Исследование закончено. Паузу 200 мс во 2 и 3 запросе делает сервер. Решается в [globals] lock spin time = 0 Остался не выясненым вопрос по количеству запросов на блокировку. Путаница с количеством запросов возникла из-за того, что в версии цифс 4.1.х второго запроса на блокировку на чтение в file.c не производилось, а сетевой дамп (см. багу 2915) я снимал как раз на этой версии. Пакетов было два! К сожалению, тогда я не обратил внимание на тип запроса на блокировку, но судя по всему оба запроса были на блокировку на запись. Клиента почему-то не удовлетворяет ответ NT_STATUS_LOCK_NOT_GRANDED и он посылает второй точно такой же запрос. Баг? В новых версиях цифс запросов, как я написал выше, три! При этом трейс в комментарии #1 снят именно на новых версиях. Зачем и где происходит повторный запрос блокировки на запись? Я не могу этого в исходниках нарыть, всю бошку уже сломал. Может кто подскажет? Дело в том, что Wine сначала посылает запрос на установку блокировки, потом, если он обваливается, он посылает запрос F_GETLK, которому соответствует уже 2 запроса внутри cifs драйвера. Итого: 3 запроса на блокировку. (In reply to comment #19) ... > Вобщем все. Исследование закончено. Паузу > 200 мс во 2 и 3 запросе делает сервер. > Решается в [globals] > lock spin time = 0 Интересно, получается что с Windows-серверами проблема останется? Получается, что остается. Вот прикольно получается. Линуксовый цифс клиент всегда будет плохо работать с линуксовой же самбой с настройками по умолчанию (потому что самба эмулирует какую-то долбаную w23k). Может при компиляции самбы в алте поменять умолчания для lock spin time? (In reply to comment #21) > Итого: 3 запроса на блокировку. Весь парадокс в том, что с самбой по умолчанию так будет всегда очень медлено (0.5 секунды на запрос!), а с виндовым сервером вообще всегда писец. (In reply to comment #19) > If a lock sent with timeout of zero would fail with NT_STATUS_FILE_LOCK_CONFLICT Может при повторных запросах блокировки выставлять таймаут 1? В общем воркэраунд это хорошо, но хотелось бы по человечески. Хотя бы в песпективе. На kernel.org сейчас лежит file.c без второго запроса на лок. Вы будете патч им туда пропихивать? Если да, то надо и самбу патчить (brl_lock_failed в locking/brlock.c), что бы при повторном запросе отличающимся по типу блокировки она выдавала NT_STATUS_LOCK_NOT_GRANTED. Тогда все будет шоколадно. И все таки не въехал почему зароса 3, а не 2. Виноват не cifs, а wine? Не правильно реализована lockfile в wine? Виноват SMB протокол. Раньше он вообще некорректное значение возвращал на F_GETLK. Чтобы заставить его возвращать корректное, пришлось написать дополнительный запрос: итого 2. Плюс wine вызывает F_GETLK после обломившегося запроса на установку блокировки: +1 Всего: 3 запроса. Изменения протихиваются, но их не особо охотно принимают пока. (In reply to comment #28) > Виноват SMB протокол. Раньше он вообще > некорректное значение возвращал на F_GETLK. Да, согласен, патч идейно верный, но с текущей реализацией самбы привдет к заметному падению производительности на данной операции. Может во втором запросе временно ставить время ожидания отличное от нуля? Это изменит поведение сервера. > Плюс wine вызывает F_GETLK после обломившегося > запроса на установку блокировки: +1 Во! Вот нафиг? Че-то с не привычки затрахался за последнее время по гитам всяким лазить, может пальцем покажете где это в исходниках и самое главное нафига оно там? http://git.etersoft.ru/projects/?p=eterwine.git;a=blob;f=server/fd.c;h=d9688e1e0d9860f64625fb6e58ca2da32d028d0b;hb=HEAD Там анализируется почему запрос на блокировку не прошёл. Ура! Кто б мне дал это раньше почитать! Я правильно нашел?:
set_unix_lock( ... ):
case EACCES:
/* check whether locks work at all on this file system */
if (fcntl( fd->unix_fd, F_GETLK, &fl ) != -1)
{
set_error( STATUS_FILE_LOCK_CONFLICT );
return 0;
}
/* fall through */
Т.е. запрос на F_SETLK делается верно. Одним пакетом.
А вот проверка подерживаются ли блокировки файловой системой -- двумя, и жутко тормозит! Нельзя ли кешировать ответы (файловая система для конкретного файла ведь не изменится за время работы) и тем самым не делать повторные F_GETLK? Поведение стане точь-вточь как у винды.
Кстати, есть предположение, что на виндовом серваке F_GETLK будет обрабатываться быстро, т.к. там может анализироваться тип блокировки (F_WRLCK,F_RDLCK). Тогда надо пачить самбу (brl_lock_failed в locking/brlock.c). Правда с текущим wine это не поможет. > Ура! Кто б мне дал это раньше почитать! Я
> правильно нашел?:
> set_unix_lock( ... ):
> case EACCES:
> /* check whether locks work at all on this file system */
> if (fcntl( fd->unix_fd, F_GETLK, &fl ) != -1)
> {
> set_error( STATUS_FILE_LOCK_CONFLICT );
> return 0;
> }
> /* fall through */
> Т.е. запрос на F_SETLK делается верно. Одним
> пакетом.
> А вот проверка подерживаются ли блокировки
> файловой системой -- двумя, и жутко
> тормозит! Нельзя ли кешировать ответы
> (файловая система для конкретного файла
> ведь не изменится за время работы) и тем
> самым не делать повторные F_GETLK? Поведение
> стане точь-вточь как у винды.
Вот такой патч приводит к увеличению скорости работы блокировок при открытии файла на запись:
diff --git a/server/fd.c b/server/fd.c
index bc6a4e1..146e918 100644
--- a/server/fd.c
+++ b/server/fd.c
@@ -1174,7 +1174,7 @@ static int set_unix_lock( struct fd *fd, file_pos_t start, file_pos_t end, int t
case EACCES:
/* check whether locks work at all on this file system */
TRACE(stderr,"EACCES\n");
- if (fcntl( fd->unix_fd, F_GETLK, &fl ) != -1)
+ if (fd->cifs || (fcntl( fd->unix_fd, F_GETLK, &fl ) != -1))
{
set_error( STATUS_FILE_LOCK_CONFLICT );
return 0;
Без патча:
[amorozov@cellar amorozov]$ ww /srv/amorozov/Projects/prog/winlock/winlock.exe r exclusive
fixme:ntdll:NtLockFile I/O completion on lock not implemented yet
0.001794 sec
Press F6 and Enter in Windows or Ctrl-D in WINE...
[amorozov@cellar amorozov]$ WINEPREFIX=/home/amorozov/wine_2 ww /srv/amorozov/Projects/prog/winlock/winlock.exe r exclusive 10000
fixme:ntdll:NtLockFile I/O completion on lock not implemented yet
LockFileEx failed: 33
41.588622 sec
[amorozov@cellar amorozov]$ WINEPREFIX=/home/amorozov/wine_2 ww /srv/amorozov/Projects/prog/winlock/winlock.exe w exclusive 10000
fixme:ntdll:NtLockFile I/O completion on lock not implemented yet
LockFileEx failed: 33
81.929839 sec
После применения патча:
[amorozov@cellar amorozov]$ ww /srv/amorozov/Projects/prog/winlock/winlock.exe r exclusive
fixme:ntdll:NtLockFile I/O completion on lock not implemented yet
0.001797 sec
Press F6 and Enter in Windows or Ctrl-D in WINE...
[amorozov@cellar amorozov]$ WINEPREFIX=/home/amorozov/wine_2 ww /srv/amorozov/Projects/prog/winlock/winlock.exe w exclusive 10000
fixme:ntdll:NtLockFile I/O completion on lock not implemented yet
LockFileEx failed: 33
40.739485 sec
[amorozov@cellar amorozov]$ WINEPREFIX=/home/amorozov/wine_2 ww /srv/amorozov/Projects/prog/winlock/winlock.exe r exclusive 10000
fixme:ntdll:NtLockFile I/O completion on lock not implemented yet
LockFileEx failed: 33
40.340272 sec
winlock лежит в wine-etersoft-devel/locks/winlock
winlock.exe {r|w|rw} [exclusive] [count]
r|w|rw - открывать файл на чтение, запись или и то, и другое
exclusive - использовать эксклюзивную блокировку
count - если равно 1, то программа устанавливает блокировку и ждёт, когда пользователь нажмёт Ctrl-D (в WINE) или F6 и Enter (в Windows), если больше 1, то программа устанавливает и снимает блокировки на файл count раз
По умолчанию предполагается, что count = 1
Патч применён в сборке 1.0.11-eter2.1. Считаем, что от нас пока ничего не требуется. Просьба к заинтересованным проверить улучшение ситуации. |
Время загрузки существенно растет при увеличении количества пользователей разделенного режима 1с. Причем файлы открываются быстро. Время увеличивается только за счет длительной попытки получить блокировки за концами файлов links.tmp и 1cv7.lck. Дамп сетевой активности показывает, что время растет из-за двойного запроса блокировки занятого байта (см. мой пост в баге 2915). Почитав исходник file.c нашел следующее в строке 710: rc = CIFSSMBLock(xid, pTcon, netfid, length, pfLock->fl_start, 0, 1, lockType, 0 /* wait flag */ ); if (rc == 0) { rc = CIFSSMBLock(xid, pTcon, netfid, length, pfLock->fl_start, 1 /* numUnlock */ , 0 /* numLock */ , lockType, 0 /* wait flag */ ); pfLock->fl_type = F_UNLCK; if (rc != 0) cERROR(1, ("Error unlocking previously locked " "range %d during test of lock", rc)); rc = 0; } else { /* if rc == ERR_SHARING_VIOLATION ? */ rc = 0; if (lockType & LOCKING_ANDX_SHARED_LOCK) { pfLock->fl_type = F_WRLCK; } else { Этог вызова CIFSSMBLock быть не должно (из-за него все тормозит и виндовый клиент такого не делает): rc = CIFSSMBLock(xid, pTcon, netfid, length, pfLock->fl_start, 0, 1, lockType | LOCKING_ANDX_SHARED_LOCK, 0 /* wait flag */ ); if (rc == 0) { rc = CIFSSMBLock(xid, pTcon, netfid, length, pfLock->fl_start, 1, 0, lockType | LOCKING_ANDX_SHARED_LOCK, 0 /* wait flag */ ); pfLock->fl_type = F_RDLCK; if (rc != 0) cERROR(1, ("Error unlocking " "previously locked range %d " "during test of lock", rc)); rc = 0; } else { pfLock->fl_type = F_WRLCK; rc = 0; } } } FreeXid(xid); return rc; }