Bug 3807

etercifs-4.3.3
mount -t cifs //win-test/baraka /mnt/cifs-win -o noperm,forcemand
В роли сервера выступает Windows.

Пока !иногда! удается воспоризвести проблему при проведении 2 документов на разных машинах, т.е. видимо журнал не блокируется и идет попытка записи с 2 клиентов.
Ошибка возникает как на Windows клиенте, так и Linux.

Тестировал на 1.0.9
rpm -qa | grep wine
libwine-1.0.9-alt42
wine-etersoft-network-1.0.9-alt18
wine-1.0.9-alt42

(In reply to comment #1)
> etercifs-4.3.3

А на старых версиях проверялось? На 4.2.1, например. И на wine 1.0.10?

(In reply to comment #3)
> (In reply to comment #1)
> > etercifs-4.3.3
> 
> А на старых версиях проверялось? На 4.2.1,
> например. И на wine 1.0.10?
> 

На старых версиях etercifs эта ошибка проявляется. На 1.0.10 проверить нет возможности. 

Проверено на старых версиях etercifs, высненно что сломалось это при переходе с 4.1.2 на 4.2.0.
Так же выяснил как можно легко увидеть ошибку:
на сервере в /var/ftp/pvt/Windows/1C/test_base.zip база для 1С77.
Монтируем ее и проверяем на ней так:
1)Заходим 2 клиентами в базу.
2)Выбираем в меню Операции > Обработка > Обработка документов
3)Период выбираем любой, например с 1 сентября по 30
4)В Виды обрабатываемых документов выбираем например Расходная накл.
В поле Обработка выбираем "Провести" и нажимаем кнопку провести.

Пункты 2-4 проделываем на обоих клиентах.

Ждем... Либо оба клиента повесятся в ожидании друг друга, либо произойдет ошибка ввода. 
Это свидетельствует что где то криво блокировки работают.

От версии wine не зависит.

Написал неверный путь: /var/ftp/pvt/Windows/Testing/Bugs/3807.rar

(In reply to comment #6)
> /var/ftp/pvt/Windows/Testing/Bugs/3807.rar
Залил на
saratov:/var/ftp/prv/Windows/Testing/Bugs/3807.rar

c 4.1.2 до 4.2.0 было произведено всего три изменения. Если собрать пакеты 4.1.2.test с каждым из них и потестировать, то, скорее всего, мы полностью локализуем проблему.

(In reply to comment #8)
> c 4.1.2 до 4.2.0 было произведено всего три
> изменения. Если собрать пакеты 4.1.2.test с
> каждым из них и потестировать, то, скорее
> всего, мы полностью локализуем проблему.
> 

Это не проблема. Но как бы без 1С протестировать?

Денис, приложи трейс, может мы увидим где ощибка.

По поводу тестирования без 1С, будет проще размышлять, когда проблема локализуется.

Вы хотите тестовые сборки? Их есть у меня.

ftp://ftp.etersoft.ru/pub/Etersoft/LINUX@Etersoft/Boxes/etercifs-testing/noarch/RPMS.default/

4.2.1-alt1.test1 - из коммита c96ca27282a99d669b81be6b64c930d5045b0b1e
4.2.1-alt1.test2 - из коммита 2dfc208bc41364b294d8863e82f1275671d046bb + cherry-pick 7c5e869153b3dadf8cb96fb5eccc2f6b419f9c9c
4.2.1-alt1.test3 - из коммита 2dfc208bc41364b294d8863e82f1275671d046bb + cherry-pick f9b89803d8d2ee4be6e300a431969f7b39983688

Скорее всего сломалось в 4.2.1-alt1.test2 (предположение). Если это так, то надо  и проверить с параметром монтирования direct.

(In reply to comment #10)
> По поводу тестирования без 1С, будет проще
> размышлять, когда проблема локализуется.
Если бы вы могли сами посмотреть на проблему на 1С, это
бы существенно ускорило решение проблемы.
Сейчас, я думаю, на одной машине перестали отображаться данные с другой. При определённых условиях. Странно, что RECT этого не показывает.

Попытались проверить сами. На wine-1.0.10 не удалось запустить 1С:
Fatal Error: Etersoft CIFS module version 4.1.2 is obsoleted. Please update etercifs package to 4.2.1 version or upper
wineserver: locking-cifs.h:122: is_etersoft_cifs: Assertion `0' failed.

Начиная со сборки закрытой части 1.0.10-eter13 добавлена
проверка на переменную окружения WINEDISABLECIFSCHECK, отключающую проверку.

В общем, проверка показала, что проблема,
при переходе с 4.1.2 на 4.2.0 или 4.2.1, не
проявляется...

Проявляется она с 4.3.x. Решается, надеюсь это
временный work around, с помощью опции
монтирования direct.

Тестирование проводилось на одном хосте
под разными пользователями... Может быть 4.2.1
проявляется на разных хостах, но скорее
всего проблема в том, что на одном из них
использовался 4.3.x... Это надо проверить
отдельно... В этом плане, лучше всегда
указывать полные параметры тестовой
среды...

Проблему локализовали - возникает на переменном чтении и блокировании....

Всё выглядит примерно так...

Первый отваливается на чтении:
trace:file:ReadFile 0x168 0x190298 1024 0x33e034 (nil)
trace:file:LockFile 0x1c8 03fffffff 000000001
trace:file:LockFile 0x1c8 040000000 000000001
trace:file:ReadFile 0x1cc 0x1d20e8 16 0x33e088 (nil)
trace:file:ReadFile 0x1c8 0x1f12121c 32768 0x33e0b4 (nil)
trace:file:ReadFile 0x1c8 0x190698 1024 0x33e040 (nil)
trace:file:ReadFile 0x1c8 0x190a98 1024 0x33e068 (nil)
trace:file:LockFile 0x118 03fffffff 000000001
trace:file:LockFile 0x118 040000000 000000001
trace:file:ReadFile 0x11c 0x1494d8 16 0x33e0a4 (nil)
trace:file:ReadFile 0x118 0x1f12121c 32768 0x33e0d0 (nil)
trace:file:ReadFile 0x118 0x190e98 1024 0x33e05c (nil)
trace:file:ReadFile 0x11c 0x191298 1024 0x33e034 (nil)
trace:file:ReadFile 0x11c 0x191698 1024 0x33e034 (nil)
trace:file:ReadFile 0x11c 0x191a98 1024 0x33e034 (nil)
trace:file:ReadFile 0x118 0x191e98 1024 0x33e084 (nil)
trace:file:ReadFile 0x11c 0x1f12121c 32768 0x33d724 (nil)
trace:file:ReadFile 0x124 0x1f12121c 32768 0x33d724 (nil)
trace:file:ReadFile 0x12c 0x1f12121c 32768 0x33d724 (nil)
trace:file:ReadFile 0x13c 0x1f12121c 32768 0x33d724 (nil)
trace:file:ReadFile 0x16c 0x1f12121c 32768 0x33d724 (nil)
trace:file:ReadFile 0x1c4 0x192298 1024 0x33d638 (nil)
trace:file:ReadFile 0x1c4 0x192698 1024 0x33d628 (nil)
trace:file:ReadFile 0x1c4 0x192aa0 1024 0x33d628 (nil)
trace:file:ReadFile 0x1c4 0x1f12121c 32768 0x33d724 (nil)
trace:file:ReadFile 0x1cc 0x1f12121c 32768 0x33d724 (nil)
trace:file:ReadFile 0x1d4 0x1f12121c 32768 0x33d724 (nil)
trace:file:ReadFile 0x354 0x1f12121c 32768 0x33d724 (nil)
trace:file:ReadFile 0x35c 0x192ea0 1024 0x33d638 (nil)
trace:file:ReadFile 0x35c 0x1932a0 1024 0x33d628 (nil)
trace:file:ReadFile 0x35c 0x1f12121c 32768 0x33d724 (nil)
trace:file:ReadFile 0x374 0x1f12121c 32768 0x33d724 (nil)
trace:file:ReadFile 0x37c 0x1936a0 1024 0x33d638 (nil)
trace:file:ReadFile 0x37c 0x193aa0 1024 0x33d628 (nil)
trace:file:ReadFile 0x37c 0x1f12121c 32768 0x33d724 (nil)

А второй, в это время залипает в попытке блокировки:
trace:file:LockFile 0x120 03fffffcd 000000001
trace:file:ReadFile 0x124 0x1491b8 16 0x33e48c (nil)
trace:file:ReadFile 0x120 0x1521f8 87 0x33e4c4 (nil)
trace:file:ReadFile 0x120 0x1521f8 87 0x33e4a4 (nil)
trace:file:LockFile 0x120 03fffffa7 000000001
trace:file:LockFile 0x120 03fffffcc 000000001
trace:file:LockFile 0x120 03fffffcd 000000001
trace:file:ReadFile 0x120 0x1521f8 87 0x33e484 (nil)
trace:file:LockFile 0x110 03fffffcc 000000001
trace:file:LockFile 0x110 03fffffcd 000000001
trace:file:ReadFile 0x110 0x33e3fc 4 0x33e3e8 (nil)
trace:file:ReadFile 0x110 0x14a000 82 0x33e3e0 (nil)
trace:file:LockFile 0x120 03fffffff 000000001
trace:file:LockFile returning=0, GetLastError=33
trace:file:LockFile 0x120 03fffffff 000000001
trace:file:LockFile returning=0, GetLastError=33
trace:file:LockFile 0x120 03fffffff 000000001
trace:file:LockFile returning=0, GetLastError=33
trace:file:LockFile 0x120 03fffffff 000000001
trace:file:LockFile returning=0, GetLastError=33
trace:file:LockFile 0x120 03fffffff 000000001
trace:file:LockFile returning=0, GetLastError=33
trace:file:LockFile 0x120 03fffffff 000000001
trace:file:LockFile returning=0, GetLastError=33
trace:file:LockFile 0x120 03fffffff 000000001
trace:file:LockFile returning=0, GetLastError=33
trace:file:LockFile 0x120 03fffffff 000000001
....
trace:file:LockFile returning=0, GetLastError=33
trace:file:LockFile 0x120 03fffffff 000000001
trace:file:LockFile returning=0, GetLastError=33
trace:file:LockFile 0x120 03fffffff 000000001
trace:file:LockFile returning=0, GetLastError=33
trace:file:LockFile 0x120 03fffffff 000000001
trace:file:LockFile 0x120 040000000 03fffffff
trace:file:LockFile 0x124 07ffffffe 000000001
trace:file:ReadFile 0x124 0x1f12121c 32768 0x33e39c (nil)
trace:file:ReadFile 0x124 0x1491b8 16 0x33e378 (nil)
trace:file:ReadFile 0x120 0x1f12121c 32768 0x33e3d0 (nil)
trace:file:ReadFile 0x124 0x1f12121c 32768 0x33e3d0 (nil)
trace:file:ReadFile 0x120 0x16ee58 1024 0x33e31c (nil)
trace:file:LockFile 0x110 03fffffff 000000001
trace:file:LockFile 0x110 040000000 000000001
trace:file:ReadFile 0x110 0x1f12121c 32768 0x33e380 (nil)
trace:file:ReadFile 0x110 0x183e80 1024 0x33e30c (nil)
trace:file:LockFile 0x358 03fffffff 000000001
....

Теперь осталось это воспроизвести без Wine, потому что мне начинает
казаться, что это из-за особенности реализации LockFile в Wine.

Патч

http://git.etersoft.ru/people/piastry/packages/?p=cifs-2.6.git;a=commitdiff;h=e217dedecf8fbebde5039edf02e4a0d219d49a92

Может решить проблему.

(In reply to comment #18)
> Патч
> Может решить проблему.
> 

Нет, это патч не помогает... Ошибка также появляется...

Надо потестировать патч

http://git.etersoft.ru/people/piastry/packages/?p=cifs-2.6.git;a=commitdiff;h=379fcca291b3b9b25dcdceb16614cb60ef5df7f6

(In reply to comment #20)
> Надо потестировать патч
> 
Патч накладывается только поверх предыдущего... Я так понимаю, что так и задумано, но стоило бы предупредить...

Не работает... Но, правда, в этот раз сначала всё не упало... Сначала проводка отвалилась по ошибке - документ заблокирован... Скриншот приложу...

Created attachment 1148 [details]
блокировка документа

Возникает при "одновременном" попытке провести документ при использовании второго патча 379fcca291b3b9b25dcdceb16614cb60ef5df7f6 (вместе с первым e217dedecf8fbebde5039edf02e4a0d219d49a92).

(In reply to comment #22)
> Created an attachment (id=1148) [details]
> блокировка документа
> 
> Возникает при "одновременном" попытке
> провести документ при использовании
> второго патча 379fcca291b3b9b25dcdceb16614cb60ef5df7f6
> (вместе с первым e217dedecf8fbebde5039edf02e4a0d219d49a92).
> 

Эта ошибка не вызывает падения. И указывает на то что открыт один из документов. 

(In reply to comment #23)
> Эта ошибка не вызывает падения. И указывает
> на то что открыт один из документов. 
> 

Да-да... Это ясно... Видимо, это дыра самого 1С, и особенность такая - иногда ждать, а иногда отваливаться по ошибке... Тем не менее второй патч всё равно приводит к падению, ибо со второй попытки всё валится как и раньше...

Вообще заметьте, что там идёт не одна блокировка, в две подряд:
trace:file:LockFile 0x120 03fffffff 000000001
trace:file:LockFile 0x120 040000000 03fffffff

После чего либо продолжается чтение блокируется другой документ...
trace:file:LockFile 0x124 07ffffffe 000000001

Причём странно, что WINDEBUG=+file не показывает UnLock. Сдаётся, что проблема здесь в состоянии гонок, но увидеть их без всех системных вызовов сложно... 

Протестировал на 4.3.x.
С опцией direct, проводки осуществляются.

(In reply to comment #25)
> Протестировал на 4.3.x.
> С опцией direct, проводки осуществляются.
> 

Вы осуществляли проводки с одного клиента, или с нескольких?

(In reply to comment #26)
> Вы осуществляли проводки с одного клиента,
> или с нескольких?
> 
1 Windows клиент, 2 Linux клиента.

(In reply to comment #27)
> (In reply to comment #26)
> > Вы осуществляли проводки с одного клиента,
> > или с нескольких?
> > 
> 1 Windows клиент, 2 Linux клиента.
> 

Спасибо, буду пробовать.

В общем проблема оказалась в излишней
оптимизации связанной с оплоками. Нужно
откатить патч с комментом:
 cifs: use cifs_file_aio_read instead of generic_file_aio_read

Для 2.6.27 - это dd07ffc8b28aad7aca7604a9134dab3d5c689ebf

$ git revert dd07ffc8
Должен помочь... Не стоит развивать эту
оптимизацию - её нужно просто убрать.

Думаю, у нас и без того уже достаточно
костылей в модуле cifs.

Да, с опцией direct, всё должно работать... уже сейчас...

Created attachment 1151 [details]
Откат оптимизации с оплоками

Для тех, кто нетерперливо ждёт исправления etercifs-4.3.x выкладываю патч для 2.6.27. В принципе он подойдёт для разных версий, но я не проверял...

Тесты этот вариант прошёл... Пакуем его в релиз. Завтра нужно сделать новую сборку etercifs. Опцию direct снова выкидываем... Она не нужна...

(In reply to comment #30)
> Тесты этот вариант прошёл... Пакуем его в
> релиз. Завтра нужно сделать новую сборку
> etercifs. Опцию direct снова выкидываем... Она не
> нужна...
> 

Сделаю завтра. Дома нет репо cifs-2.6, так бы сделал. А 2 раза делать одно и то же неохота.

Direct я и не добавлял второй раз, поэтому и выкидывать не надо. Вот из документации надо выкинуть: http://www.etersoft.ru/content/view/56/156/#etermount

У меня этого не было. http://git.etersoft.ru/people/kipruss/packages/?p=wine-etersoft-docs.git;a=commitdiff;h=1bfc01bc2bad634d7858d68f9c5f7b1039e4ce24
Я считаю, что конкретные параметры публиковать не нужно.

Нет, опцию direct не выкидываем!!!!! Без неё документы не будут появляться, созданные на другом компьютере - Бага 3725) Пока рабочий вариант только с этой опцией. А без неё пока разбираюсь, как добиться полной корректной работы.

Вот так надо попробовать...
http://git.etersoft.ru/people/piastry/packages/?p=cifs-2.6.git;a=shortlog;h=refs/heads/v2.6.27-testing

(In reply to comment #33)
> Вот так надо попробовать...
> http://git.etersoft.ru/people/piastry/packages/?p=cifs-2.6.git;a=shortlog;h=refs/heads/v2.6.27-testing
> 

Не работает...

Паша, разберись, пожалуйста, с обновлением исходников в разных бранчах... Хотелось бы, чтобы:
1) объединение проходило без конфликтов...
2) твоя ветка содержит странные вещи, отличающиеся от основной ветки ядра. Почему?

diff --git a/fs/cifs/cifs_debug.c b/fs/cifs/cifs_debug.c
index 877e4d9..5e4cde4 100644
--- a/fs/cifs/cifs_debug.c
+++ b/fs/cifs/cifs_debug.c
@@ -341,7 +341,7 @@ static int cifs_stats_proc_show(struct seq_file *m, void *v)
                                        atomic_read(&tcon->num_writes),
                                        (long long)(tcon->bytes_written));
                                seq_printf(m, "\nFlushes: %d",
-                                       atomic_read(&tcon->num_flushes));
+                                               atomic_read(&tcon->num_flushes));
                                seq_printf(m, "\nLocks: %d HardLinks: %d "
                                              "Symlinks: %d",
                                        atomic_read(&tcon->num_locks),
diff --git a/fs/cifs/file.c b/fs/cifs/file.c
index 660f442..763ac7f 100644
--- a/fs/cifs/file.c
+++ b/fs/cifs/file.c
@@ -623,7 +623,7 @@ int cifs_lock(struct file *file, int cmd, struct file_lock *pfLock)
        struct cifsTconInfo *pTcon;
        __u16 netfid;
        __u8 lockType = LOCKING_ANDX_LARGE_FILES;
-       bool posix_locking = 0;
+       int posix_locking = 0;

        length = 1 + pfLock->fl_end - pfLock->fl_start;
        rc = -EACCES;
@@ -683,9 +683,9 @@ int cifs_lock(struct file *file, int cmd, struct file_lock *pfLock)
        netfid = ((struct cifsFileInfo *)file->private_data)->netfid;

        if ((pTcon->ses->capabilities & CAP_UNIX) &&
-           (CIFS_UNIX_FCNTL_CAP & le64_to_cpu(pTcon->fsUnixInfo.Capability)) &&
-           ((cifs_sb->mnt_cifs_flags & CIFS_MOUNT_NOPOSIXBRL) == 0))
-               posix_locking = 1;
+               (CIFS_UNIX_FCNTL_CAP & le64_to_cpu(pTcon->fsUnixInfo.Capability)) &&
+               ((cifs_sb->mnt_cifs_flags & CIFS_MOUNT_NOPOSIXBRL) == 0))
+                       posix_locking = 1;

        /* BB add code here to normalize offset and length to
        account for negative length which we can not accept over the
diff --git a/fs/cifs/inode.c b/fs/cifs/inode.c
index c18379d..f2310e3 100644
--- a/fs/cifs/inode.c
+++ b/fs/cifs/inode.c
@@ -1265,7 +1267,6 @@ int cifs_revalidate(struct dentry *direntry)
                        cFYI(1, ("Have to revalidate file due to hardlinks"));
                }
        }
-
        /* save mtime and size */
        local_mtime = direntry->d_inode->i_mtime;
        local_size = direntry->d_inode->i_size;


Правку табов и удаление строк ради красоты делать не стоит... Может быть это разные релизы ядра?

(In reply to comment #33)
> Вот так надо попробовать...
> http://git.etersoft.ru/people/piastry/packages/?p=cifs-2.6.git;a=shortlog;h=refs/heads/v2.6.27-testing
> 

Данный бранч смёржу в тестовой версии, а пока будем проще: выкидываем указанный Женей коммит (там 2 на самом деле) и рекомендуем direct. Далее - называем это стабильным релизом и тестим. Данный релиз попадёт в iso.

Можно пересобирать:

ftp://ftp.etersoft.ru/pub/Etersoft/CIFS@Etersoft/4.3.6/sources

Можно тестить:

ftp://ftp.etersoft.ru/pub/Etersoft/LINUX@Etersoft/Boxes/etercifs/noarch/RPMS.default/etercifs-4.3.6-alt1.noarch.rpm

(In reply to comment #35)
> Можно пересобирать:
> ftp://ftp.etersoft.ru/pub/Etersoft/CIFS@Etersoft/4.3.6/sources
Собрал.

(In reply to comment #36)
> > ftp://ftp.etersoft.ru/pub/Etersoft/CIFS@Etersoft/4.3.6

Проверил с 3 клиентами (2 Linux и 1 Windows), так же на двух серверах (Windows, Linux), массовое проведение проходит успешно.
Думаю можно сказать что проблема решена.