Bug 9646

Summary: Подключение к серверу 1С 8.3 с win-клиента, запущенного в wine
Product: WINE@Etersoft Reporter: Константин Кондратюк <kondratyuk>
Component: Сетевые возможности ; TCP/IPAssignee: Dmitry Timoshkov <dtimoshkov>
Status: CLOSED FIXED QA Contact: Vitaly Lipatov <lav>
Severity: major    
Priority: P2 CC: anton, baraka, lav
Version: 2.1   
Target Milestone: ---   
Hardware: PC   
OS: Linux   
Whiteboard:
Заявки RT: Связано с:
Дата напоминания:
Bug Depends on: 9679    
Bug Blocks:    
Deadline: 2013-11-25   
Attachments: лог с ошибкой +winsock,+relay
лог без ошибки +winsock,+relay

Description Константин Кондратюк 2013-11-11 13:35:38 MSK 
Невозможно подключиться к серверу 1С, расположенному в сети (не на localhost):
"Ошибка при выполнении операции с информационной базой. Внутренняя ошибка."

Если сервер расположен на localhost, подключение успешно. Хорошо подключается linux-клиент той же версии, независимо от места расположения сервера.
Comment 1 Константин Кондратюк 2013-11-11 13:39:08 MSK 
Проблема воспроизведена на 1С 8.3.3.721 и wine 2.1.3.

Сервер: ноутбук n56 (192.168.0.29)

Клиенты:
- n56 (работает)
- swine 1c83/3.721
- grape
- виртуалка [T] Ubuntu 12.04
- удалённый хост на стороне клиента (подключение через интернет).

Установлено, что серверная ОС не имеет значения, ошибка одинаково проявляется и в Linux, и на виндовом кластере.
Comment 2 Константин Кондратюк 2013-11-11 13:40:45 MSK 
Ошибки с идентичным проявлением, зарегистрированные в нашей багзилле:
http://bugs.etersoft.ru/show_bug.cgi?id=6900
http://bugs.etersoft.ru/show_bug.cgi?id=8425

Одна относится к Ubuntu 10.10, другая к 12.04. В обоих случаях, использование свежего wine решает проблему.
Comment 3 Константин Кондратюк 2013-11-18 12:42:51 MSK 
На wine-2.0.4 проблема идентична.
Comment 4 Константин Кондратюк 2013-11-18 15:10:53 MSK 
Лог по winsock:

trace:winsock:DllMain 0xb6dd0000 0x2 (nil)
trace:winsock:WS2_sendto socket 04f4, wsabuf 0x32cae8, nbufs 1, flags 0, to (nil), tolen 0, ovl (nil), func (nil)
trace:winsock:WS2_sendto fd=121, options=0
trace:winsock:WS2_sendto  -> 4 bytes
trace:winsock:WS_closesocket socket 04f4

Как и в баге #6900, сокет закрывается после отправки 4 байт. В случае успешного соединения отправляется 500+ байт, затем следует ожидание и ответ сервера.
Comment 5 Константин Кондратюк 2013-11-18 17:03:48 MSK 
Провёл эксперимент, настроив подключение к удалённому серверу через локальный порт, проброшенный на удалённый сервер:
$ ssh -fNL 1541:localhost:1541 guest@192.168.4.24
(аналогично для 1540, 1560 и 1561).

Клиент подцепился и заработал. Это доказывает, что дело не в работе сети, а в том, как wine работает с этой самой сетью. При этом не понимаю принципиальной разницы в работе через локальный сетевой интерфейс (0.29) и удалённый (4.24).
Comment 6 Константин Кондратюк 2013-11-18 17:04:50 MSK 
Ванильный wine 1.7.5 не работает с такими же симптомами.
Comment 7 Константин Кондратюк 2013-11-18 20:32:42 MSK 
Created attachment 3003 [details]
лог с ошибкой +winsock,+relay

Кусок лога с воспроизведённой ошибкой подключения
Comment 8 Константин Кондратюк 2013-11-18 20:33:24 MSK 
Created attachment 3004 [details]
лог без ошибки +winsock,+relay

Кусок лога с успешным подключением
Comment 9 Vitaly Lipatov 2013-11-18 22:09:12 MSK 
Пока получается так:
После установки соединения с удалённым сервером и получением от него ответа
вызывается
GetAdaptersAddresses
после которой получается локальный IP-адрес, конвертируемый в строку функцией WSAAddressToStringA.
Далее для установленного соединения функцией WSAAddressToStringW получаются WCHAR-строки с IP:port сервер и IP:port клиента.
После чего порождается поток... 

Далее в работающем случае (когда подсоединяемся к своему же адресу), получается так:
000e:Call PE DLL (proc=0x5e013c,module=0x5d0000 L"MSVCR110.dll",reason=THREAD_ATTACH,res=(nil))
000e:Call KERNEL32.FlsSetValue(00000000,0337d808) ret=0066faf1
000e:Ret  KERNEL32.FlsSetValue() retval=00000001 ret=0066faf1
000e:Ret  PE DLL (proc=0x5e013c,module=0x5d0000 L"MSVCR110.dll",reason=THREAD_ATTACH,res=(nil)) retval=1
...
003f:Ret  KERNEL32.lstrcmpiW() retval=00000000 ret=f6b3fa16
...
000e:Starting thread proc 0x7bc882f0 (arg=0x3363f20)
003f:Call PE DLL (proc=0xf63cbea0,module=0xf63c0000 L"schannel.dll",reason=PROCESS_ATTACH,res=(nil))
003f:Call KERNEL32.DisableThreadLibraryCalls(f63c0000) ret=f63cbce0
003f:Ret  KERNEL32.DisableThreadLibraryCalls() retval=00000001 ret=f63cbce0
003f:Ret  PE DLL (proc=0xf63cbea0,module=0xf63c0000 L"schannel.dll",reason=PROCESS_ATTACH,res=(nil)) retval=1
003f:Ret  KERNEL32.LoadLibraryW() retval=f63c0000 ret=f6b3fa53
...
003f:Call secur32.InitSecurityInterfaceA() ret=f6b3fa9e
003f:Ret  secur32.InitSecurityInterfaceA() retval=f6b4f2e0 ret=f6b3fa9e
003f:Call secur32.InitSecurityInterfaceW() ret=f6b3faae
003f:Ret  secur32.InitSecurityInterfaceW() retval=f6b4f360 ret=f6b3faae
fixme:secur32:schan_QueryCredentialsAttributesW SECPKG_CRED_ATTR_NAMES: stub
003f:Call KERNEL32.GetComputerNameW(0032dc20,0032dc44) ret=44ef95cb
003f:Ret  KERNEL32.GetComputerNameW() retval=00000001 ret=44ef95cb
003f:Call ws2_32.send(000004d4,03369d18,000001f5,00000000) ret=44df44dd
trace:winsock:WS2_sendto socket 04d4, wsabuf 0x32d868, nbufs 1, flags 0, to (nil), tolen 0, ovl (nil), func (nil)
003f:Call ntdll.wine_server_handle_to_fd(000004d4,00000002,0032d798,0032d790) ret=f6c3abda
003f:Ret  ntdll.wine_server_handle_to_fd() retval=00000000 ret=f6c3abda
trace:winsock:WS2_sendto fd=109, options=0
trace:winsock:WS2_sendto  -> 501 bytes


А в неработающем:
0046:Ret  PE DLL (proc=0x7e24be90,module=0x7e1f0000 L"winex11.drv",reason=THREAD_ATTACH,res=(nil)) retval=1
0046:Ret  PE DLL (proc=0x7e6a8980,module=0x7e5d0000 L"ole32.dll",reason=THREAD_ATTACH,res=(nil)) retval=1
0046:Call PE DLL (proc=0x5c013c,module=0x5b0000 L"MSVCR110.dll",reason=THREAD_ATTACH,res=(nil))
...
0040:Call KERNEL32.lstrcmpiW(01066280 L"Microsoft Unified Security Protocol Provider",01baf324 L"Microsoft Unified Security Protocol Provider") ret=f6b50a16
...
0046:Starting thread proc 0x7bc882f0 (arg=0x1bae890)
0040:Call PE DLL (proc=0xf6297ea0,module=0xf6290000 L"schannel.dll",reason=PROCESS_ATTACH,res=(nil))
0040:Call KERNEL32.DisableThreadLibraryCalls(f6290000) ret=f6297ce0
0040:Ret  KERNEL32.DisableThreadLibraryCalls() retval=00000001 ret=f6297ce0
0040:Ret  PE DLL (proc=0xf6297ea0,module=0xf6290000 L"schannel.dll",reason=PROCESS_ATTACH,res=(nil)) retval=1
0040:Ret  KERNEL32.LoadLibraryW() retval=f6290000 ret=f6b50a53
0040:Call secur32.InitSecurityInterfaceA() ret=f6b50a9e
0040:Ret  secur32.InitSecurityInterfaceA() retval=f6b602e0 ret=f6b50a9e
0040:Call secur32.InitSecurityInterfaceW() ret=f6b50aae
0040:Ret  secur32.InitSecurityInterfaceW() retval=f6b60360 ret=f6b50aae
fixme:secur32:schan_QueryCredentialsAttributesW SECPKG_CRED_ATTR_NAMES: stub
0040:Call KERNEL32.GetComputerNameW(0033d4e4,0033d508) ret=44ef95cb
0040:Ret  KERNEL32.GetComputerNameW() retval=00000001 ret=44ef95cb
0040:Call KERNEL32.WaitForSingleObject(00000294,ffffffff) ret=23d3003c
0040:Ret  KERNEL32.WaitForSingleObject() retval=00000000 ret=23d3003c
0040:Call KERNEL32.ReleaseMutex(00000294) ret=23d30047
0040:Ret  KERNEL32.ReleaseMutex() retval=00000001 ret=23d30047
0040:Call KERNEL32.WaitForSingleObject(00000294,ffffffff) ret=23d3003c
0040:Ret  KERNEL32.WaitForSingleObject() retval=00000000 ret=23d3003c
0040:Call KERNEL32.ReleaseMutex(00000294) ret=23d30047
0040:Ret  KERNEL32.ReleaseMutex() retval=00000001 ret=23d30047
0040:Call KERNEL32.GetSystemTimeAsFileTime(0033bfe4) ret=005c520b
0040:Ret  KERNEL32.GetSystemTimeAsFileTime() retval=01cee462 ret=005c520b
...
0040:Call KERNEL32.GetVersionExA(0033be18) ret=23d80537
0040:Ret  KERNEL32.GetVersionExA() retval=00000001 ret=23d80537
0040:Call KERNEL32.LoadLibraryA(23e29738 "ADVAPI32.DLL") ret=23d80544
0040:Ret  KERNEL32.LoadLibraryA() retval=7e700000 ret=23d80544
0040:Call KERNEL32.LoadLibraryA(23e27fcc "KERNEL32.DLL") ret=23d8054d
0040:Ret  KERNEL32.LoadLibraryA() retval=7b810000 ret=23d8054d
0040:Call KERNEL32.LoadLibraryA(23e29748 "NETAPI32.DLL") ret=23d80554
0040:Ret  KERNEL32.LoadLibraryA() retval=f6b10000 ret=23d80554
0040:Call KERNEL32.GetProcAddress(f6b10000,23e29758 "NetStatisticsGet") ret=23d8057b
0040:Ret  KERNEL32.GetProcAddress() retval=f6b179b4 ret=23d8057b
0040:Call KERNEL32.GetProcAddress(f6b10000,23e2976c "NetApiBufferFree") ret=23d80586
0040:Ret  KERNEL32.GetProcAddress() retval=f6b176cc ret=23d80586
0040:Call netapi32.NetStatisticsGet(00000000,23e29780 L"LanmanWorkstation",00000000,00000000,0033bf44) ret=23d805a7
0040:Ret  netapi32.NetStatisticsGet() retval=0000085c ret=23d805a7
0040:Call netapi32.NetStatisticsGet(00000000,23e297a4 L"LanmanServer",00000000,00000000,0033bf44) ret=23d805da
0040:Ret  netapi32.NetStatisticsGet() retval=0000085c ret=23d805da
0040:Call KERNEL32.FreeLibrary(f6b10000) ret=23d80604
0040:Ret  KERNEL32.FreeLibrary() retval=00000001 ret=23d80604
0040:Call KERNEL32.GetProcAddress(7e700000,23e297c0 "CryptAcquireContextW") ret=23d80618
0040:Ret  KERNEL32.GetProcAddress() retval=7e712154 ret=23d80618
0040:Call KERNEL32.GetProcAddress(7e700000,23e297d8 "CryptGenRandom") ret=23d80623
0040:Ret  KERNEL32.GetProcAddress() retval=7e7122d4 ret=23d80623
0040:Call KERNEL32.GetProcAddress(7e700000,23e297e8 "CryptReleaseContext") ret=23d8062e
0040:Ret  KERNEL32.GetProcAddress() retval=7e7123c4 ret=23d8062e
0040:Call advapi32.CryptAcquireContextW(0033bf48,00000000,00000000,00000001,f0000000) ret=23d80665
0040:Call PE DLL (proc=0xf626d880,module=0xf6250000 L"rsaenh.dll",reason=PROCESS_ATTACH,res=(nil))
0040:Call KERNEL32.DisableThreadLibraryCalls(f6250000) ret=f6263763
0040:Ret  KERNEL32.DisableThreadLibraryCalls() retval=00000001 ret=f6263763
0040:Ret  PE DLL (proc=0xf626d880,module=0xf6250000 L"rsaenh.dll",reason=PROCESS_ATTACH,res=(nil)) retval=1
0040:Call rsaenh.CPAcquireContext(01bb0c48,00000000,f0000000,01bb0c58) ret=7e71b52e
0040:Call advapi32.GetUserNameA(0033b974,0033b970) ret=f6264988
0040:Ret  advapi32.GetUserNameA() retval=00000001 ret=f6264988
0040:Ret  rsaenh.CPAcquireContext() retval=00000001 ret=7e71b52e
0040:Ret  advapi32.CryptAcquireContextW() retval=00000001 ret=23d80665
0040:Call advapi32.CryptGenRandom(01bb0c38,00000040,0033beb0) ret=23d80678
0040:Call rsaenh.CPGenRandom(00000001,00000040,0033beb0) ret=7e71bbfc
0040:Call advapi32.SystemFunction036(0033beb0,00000040) ret=f6259944
0040:Ret  advapi32.SystemFunction036() retval=00000001 ret=f6259944
0040:Ret  rsaenh.CPGenRandom() retval=00000001 ret=7e71bbfc
0040:Ret  advapi32.CryptGenRandom() retval=00000001 ret=23d80678
0040:Call KERNEL32.WaitForSingleObject(000002d8,ffffffff) ret=23d3003c
0040:Ret  KERNEL32.WaitForSingleObject() retval=00000000 ret=23d3003c
0040:Call KERNEL32.ReleaseMutex(000002d8) ret=23d30047
0040:Ret  KERNEL32.ReleaseMutex() retval=00000001 ret=23d30047
0040:Call advapi32.CryptReleaseContext(01bb0c38,00000000) ret=23d80697
0040:Call rsaenh.CPReleaseContext(00000001,00000000) ret=7e71ba82
0040:Ret  rsaenh.CPReleaseContext() retval=00000001 ret=7e71ba82
0040:Call PE DLL (proc=0xf626d880,module=0xf6250000 L"rsaenh.dll",reason=PROCESS_DETACH,res=(nil))
0040:Ret  PE DLL (proc=0xf626d880,module=0xf6250000 L"rsaenh.dll",reason=PROCESS_DETACH,res=(nil)) retval=1
0040:Ret  advapi32.CryptReleaseContext() retval=00000001 ret=23d80697
0040:Call advapi32.CryptAcquireContextW(0033bf48,00000000,23e29800 L"Intel Hardware Cryptographic Service Provider",00000016,00000000) ret=23d806ab
0040:Ret  advapi32.CryptAcquireContextW() retval=00000000 ret=23d806ab
0040:Call KERNEL32.FreeLibrary(7e700000) ret=23d806e9
0040:Ret  KERNEL32.FreeLibrary() retval=00000001 ret=23d806e9
0040:Call KERNEL32.GetModuleHandleA(00000000) ret=23d69eec
0040:Ret  KERNEL32.GetModuleHandleA() retval=00400000 ret=23d69eec
0040:Call KERNEL32.GetProcAddress(00400000,23e27744 "_OPENSSL_isservice") ret=23d69efc
0040:Ret  KERNEL32.GetProcAddress() retval=00000000 ret=23d69efc


Интересно, что в первом случае есть Ret  KERNEL32.lstrcmpiW() без предшествующего CALL, а во втором — 0040:Call KERNEL32.lstrcmpiW без последующего Ret.
При анализе лога мы не сильно обратили внимание, что в какой-то момент сообщения от разных потоков перемешались... Но эти странные lstrcmpi вклиниваются именно из параллельного потока.
Comment 12 Константин Кондратюк 2013-11-21 13:04:14 MSK 
Клиентская часть настроена на воспроизведение проблемы в бутылке.
$ swine -h eter-2.1 1c83/3.721
Comment 13 Vitaly Lipatov 2013-11-21 13:10:15 MSK 
Проблема с подключением к серверу 1С 8.3, находящемуся на удалённой машине (не локально).
Для воспроизведения достаточно запустить установленную 1С из бутылки
$ swine -h eter-2.1 1c83/3.721
(можно скопировать локально)
и нажать «Подключиться».

подключение несколько замедленно из-за поиска ключа hasp при запуске, но на ошибку это не влияет.

Может быть вы сможете посмотреть на проблему под другим углом, чем мы, и что-то выявите дополнительно. Я пока кроме как посмотреть на код 1С в этом месте, ничего не придумал.

Есть небольшое подозрение на msvcrt110.dll (мы для проверки нативную не смогли поставить, в winetricks нет).

Задача важная, очень интересует прежде всего любое быстрое решение.
Comment 16 Константин Кондратюк 2013-11-21 13:51:47 MSK 
Кнопка называется не "Подключиться", а "1С:Предприятие". То есть имеется в виду обычная кнопка запуска 1С с выбранной базой.

Нет разницы, чем запускать 1С. Если запускать 1cv8.exe, возникает ошибка, как в описании баги. Если 1cv8s.exe, то сформулированная немного по-другому и с ожиданием переподключения. А по сути, это одна и та же ошибка подключения, только с разными диалоговыми окнами.
Comment 24 Константин Кондратюк 2013-11-25 14:41:12 MSK 
Пробросил порты из бутылки на onec83. 

Важным является то, что строку подключения нужно оставить прежней, но прописать в /etc/hosts
127.0.0.1    onec83.devel.etersoft.ru
(это нужно для того, чтобы, получив информацию о подключении от сервера 1С, идти не в интернет, а на 127.0.0.1)

Дмитрий, хватит ли этих настроек для дальнейшего исследования? Или Вы локально воспроизводите?
Comment 27 Константин Кондратюк 2013-11-25 14:54:06 MSK 
Понял. Сейчас сделаю аккаунт на onec83.
Comment 28 Константин Кондратюк 2013-11-25 15:00:20 MSK 
Добавил пользователя dtimoshkov на сервер. Единственное, не уверен, что правильно определил, какой ключ вписать. Если не подключиться, то мне потребуется открытый ключ, чтобы добавить в контейнер.
Comment 29 Константин Кондратюк 2013-11-25 15:03:49 MSK 
Инструкция по пробросу

1. Делаем проброс портов на сервер:
$ ssh -fNL 1540:localhost:1540 user@onec83.devel.etersoft.ru
$ ssh -fNL 1541:localhost:1541 user@onec83.devel.etersoft.ru
$ ssh -fNL 1560:localhost:1560 user@onec83.devel.etersoft.ru
$ ssh -fNL 1561:localhost:1561 user@onec83.devel.etersoft.ru

2. Редактируем /etc/hosts:
127.0.0.1    onec83.devel.etersoft.ru

После этого клиент 1С успешно подключается к удалённому серверу, думая, что onec83.devel.etersoft.ru — это синоним локалхоста.
Comment 30 Dmitry Timoshkov 2013-11-25 15:18:05 MSK 
(В ответ на comment #29)
> Инструкция по пробросу
> 
> 1. Делаем проброс портов на сервер:
> $ ssh -fNL 1540:localhost:1540 user@onec83.devel.etersoft.ru
> $ ssh -fNL 1541:localhost:1541 user@onec83.devel.etersoft.ru
> $ ssh -fNL 1560:localhost:1560 user@onec83.devel.etersoft.ru
> $ ssh -fNL 1561:localhost:1561 user@onec83.devel.etersoft.ru
> 
> 2. Редактируем /etc/hosts:
> 127.0.0.1    onec83.devel.etersoft.ru
> 
> После этого клиент 1С успешно подключается к удалённому серверу, думая, что
> onec83.devel.etersoft.ru — это синоним локалхоста.

Спасибо Константин, с этими настройками все работает. 1С загружается очень
долго, но главное, что соединение проходит успешно.
Comment 51 Vitaly Lipatov 2014-09-11 18:51:03 MSK 
Откладываем задачи, к которым не обращались более 100 дней.
Comment 52 Vitaly Lipatov 2014-09-19 12:57:47 MSK 
Из исследования в ALT Linux выяснилось, что 
помимо i586-glibc-nss, ещё требуются пакеты:

  i586-libnss-mdns
  i586-libnss-myhostname

Видимо, раз причина в них, закрываем задачу.
Comment 53 Vitaly Lipatov 2014-10-29 13:07:06 MSK 
Закрываю.