Время загрузки существенно растет при увеличении количества пользователей разделенного режима 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; }
Вот на всякий случай дебаг с таймингами: [ 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. Считаем, что от нас пока ничего не требуется. Просьба к заинтересованным проверить улучшение ситуации.
