всем доброго дня.

проблема весьма специфическая. будет сложно сформулировать вопрос, и предоставить результаты тестов.
рискну...

код клиента выполняет следующее:
1. выделение памяти у ОС в boost::shared_array.
2. сериализация.
3. копирование в shared_array.
4. boost::asio::async_write().
5. tcpdump показывает что данные ушли.
6. на приеме данные искажены.

лог tcpdump`a для пояснения формирования непонятных "фреймов":
строки сериализации содержащие подстроки servimpl - это то, что отправляется от клиента серверу.
строки сериализации содержащие подстроки type1 - это то, что отправляется от сервера клиенту.

что за непонятные данные присутствующие кроме архивов сериализации - мне не известно.
в точке 1 показан пример когда архив разбивается. в точке 2 показана остальная часть архива. этот архив на принимающей стороне восстанавливается правильно. ошибки не возникает.

далее...
в точке 3 происходит разбиение очередного архива, остальная часть которого появляется только в точке 5.
т.е. это именно та итерация(348), на которой происходит искажение архива, и как следствие - ошибка десериализации.


далее...
в точке 4 должен находится остаток архива разбитого в точке 3.


вот та часть, в которой появляется остаток от архива разбитого в точке 3.


какие мысли?

Это сообщение отредактировал(а) boostcoder - 8.4.2011, 00:57

Где код?

Daevaorn, не нужен вам код. в коде все ок. архивы отправляются целые.
причину нужно искать в том коде, который добавляет к моим данным нечитаемые данные и разбивает мои данные на "фреймы".

Добавлено через 1 минуту и 35 секунд
я рассчитывал на то, что кто-то увидит знакомую ситуацию, и подскажет как решить.

зы
кстати, если между отправками данных поставить sleep на 1мс - то проблема решается полностью.

кто-то знает кто может добавлять к моим данным нечитаемые данные и разбивать их на фреймы? это выполняет TCP стек? сетевая подсистема? просто не знаю как это называется...

Это сообщение отредактировал(а) boostcoder - 23.3.2011, 16:07

прикладываю мегапростой пример воспроизводящий ошибку.


Присоединённый файл ( Кол-во скачиваний: 11 )
 asiotest.zip 2,75 Kb

фрагментация осуществляется на сетевом уровне
к данным "мусор" добавляться не может

вы точно уверены, что в сокет все записывается правильно?
вы сравнивали, что передается в async_write() и в send()?

boostcoder, данные скорее всего искажены именно от отправителя.
На первый взгляд, именно так. копать... 
Если дальше копать то послушайте трафик wireshark, и выложите сюда. ну может конечно кто то и tcp дамп почитать смоежт я как то не.

по поводу задержки
если постоянно записывать данные, а читать с задержкой 1 мс, то данные будут накапливаться в буфере сокета ядра...хм, может тут проблема
версия ядра какая?

тот мусор что на скринах, показывает tcpdump. в мой код этот мусор не поступает.


насколько это возможно утверждать на приведенном коде - да. просто код реально мегапрост, чтоб где-то мог закрасться баг. если конечно это не баг asio. в чем сомневаюсь.. иначе данные портились бы не только в этом примере, но и в других приложениях.


нет. а как это сделать? добавить в недры asio вывод?
или есть какой-то еще способ?


сейчас сделаю.


эм.. помогает задержка при записи, а не при чтении.


я проверял не только на линукс...

клиентский код запускаю на: 2.6.35-28-generic-pae
код сервера на: 2.6.35-25-generic-pae

логи.
сделал wireshark`ом на локальной стороне.
на сервере нет X`ов, я хз как там wireshark запускать.

зы
по логам, ничего не понял...


Присоединённый файл ( Кол-во скачиваний: 5 )
 logs.zip 76,38 Kb

заново протестил еще раз на winXP/Win7/Linux.
баг воспроизводится всегда :(
тестил так:

в этом большая ошибка
я много раз на это же полагался
а в итоге как раз в мегапростом коде и был баг ;)



написать враперы над send/recv/... из Libc
насколько я знаю, достаточно создать что-то типа wrappers.c, там реализовать обертки
вот реальный код подмены fork из какого-то проекта...


Добавлено через 3 минуты и 2 секунды

в таком случае я уверен на 99% баг где-то в коде
думаю в вашем, а не asio

Почитал я код и у меня возникло подозрение, что async_test() и asio в клиенте работают в разных потоках. А shared_array (как и shared_ptr) не может корректно передаваться между потоками (по крайней мере я пару месяцев назад не нашел такого способа).
Те когда выполняется код:

в отмеченных местах возникает состояние гонки, а так-же в функции start_write в вызове boost::bind происходят изменения в счетчике ссылок shared_array и последний ломается. Если не повезет один из деструкторов shared_array может убить данные раньше чем обновятся данные счетчика ссылок.

В свое время пару месяцев назад я напоролся на точно такой-же баг, но только с shared_ptr, через который между потоками передавался вектор. Весь процесс передачи был обернут мутексами, кроме участков, где возможно удаление временных объектов shared_ptr (а они возникали так как данные передавались через std::queue), но программа всеравно падала где-то в недрах asio. А иногда не падала, а что-то передавала.
И что самое паршивое в GCC все работало. А в Intel C++ падало или не падало. Зависело это от фазы луны, загрузки процессора и т. д.

В результате в этом месте я сделал полностью ручное управление памяти, а shared_ptr в области, где данные передаются между потоками я убрал полностью.

Потокобезопасность shared_ptr описана здесь: http://www.boost.org/doc/libs/1_46_1/libs/...tm#ThreadSafety (Example 3 описывает возникшую ситуацию).

перевариваю...

Добавлено через 41 секунду
а по этой проблеме, которая у вас возникла, вы где-то на форуме тему создавали? хотелось бы почитать.

Нет, не создавал. Что-бы создать тему нужна была хоть какая-либо детализация проблемы, а у меня даже segmentation fault в разных местах всплывали. Я неделю думал, что на какой-то хитрый баг либо в asio либо в intel С++ наткнулся. Потом начал искать все места, который потенциально перераспределяли память и где рядом был обмен данными между потоками. С 3-й попытки заменил нужный shared_ptr на обычный ptr и ручное управление памятью и проблема ушла полностью.

вручную управлять памятью страшно  

boostcoder
Везде да.
У меня к каждому клиенту привязан объект класса Client, который привязан к одному io_service и который гарантированно работает в одном потоке. В качестве буферов (которые и передаются asio) используется два std::vector<char>, как поля класса Client, а данные получаемые из другого потока в виде обычного указателя используются очень локализовано и после чего удаляются, по этому я и согласился на ручное управление памятью, а не стал дальше думать, как обойти такое ограничение shared_ptr.

Это сообщение отредактировал(а) phprus - 2.4.2011, 23:18

убрал из кода все смарт-поинтеры.
проблема осталась  

на стороне клиента, сохраняю отправляемые массивы в файл, чтоб убедится в том, что массивы не портятся.
так и есть. массивы не искаженны.


на стороне сервера, так же, сохраняю принятые массивы.
но тут, массив приходит искаженным:


вот снифф этого участка, tcpdump`ом, на стороне клиента:


а это на стороне сервера:




на стороне клиента, как раз в то место где данные искаженны, добавлены какие-то данные. не мои.
видно, что на стороне сервера, массив, после прочтения при помощи asio, уже испорчен. но tcpdump показывает что массив не испорчен.

я в замешательстве  


выложу код в тему, в надежде, что кто-то внесет ясность в ситуацию.

клиент:

http://liveworkspace.org/code/15c1e78ea451...f1eebe7e08564a7

сервер:

http://liveworkspace.org/code/0a8e2cb728f8...d31f28c46ddf9e2

общий хидер:

http://liveworkspace.org/code/fa23c521eab1...320dcff6290e656

всем спасибо.


зы
во вложении, архив с исходниками и Makefile`ом. проверено на gcc-linux и на mingw32.


Это сообщение отредактировал(а) boostcoder - 8.4.2011, 01:24

Присоединённый файл ( Кол-во скачиваний: 3 )
 asiotest2.zip 2,78 Kb

Из замеченного при помощи wireshark:
Когда включен - TCP-сегменты ходят с данными ровно в 13 байт и у каждого стоит флаг PUSH (сразу отдавать на уровень выше, те приложению).
Когда sleep выключен сегменты содержат множество склееных блоков по 13 байт (возможно не целое число блоков).

А что говорят по этому поводу на https://svn.boost.org/trac/boost/ ? Может быть имеет смысл написать Bug report?

при помощи strace обнаружил, что для ввода-вывода используются sendmsg() и recvmsg(), а не send() и recv() как предполагал.


это я тоже заметил. любопытно почему так происходит. но это сейчас не главное.


та я потому и не писал, ибо все же не был уверен что это не мой баг в коде.
сейчас напишу..

вот что еще странно...
в один прекрасный момент, сервер принимает это:


в первой строке сверху - все хорошо.
во второй и третьей строке, вместо завершающего нуля, вставлен символ c
в четвертой строке, символа c вначале, попросту нет.

boostcoder
Если sleep сделать с временем ожидания, равным 0 ( boost::this_thread::sleep(boost::posix_time::microseconds(0)) ) то  проблема тоже уходит, а sleep(0) в теории должен вызывать передачу управления другому процессу, те в коде похоже зарылась гонка. Только не могу понять в каком коде.


Сообщите пожалуйста ссылку на тикет.

Это сообщение отредактировал(а) phprus - 9.4.2011, 09:41

по идее - да.


не спорю... но где?! и как побороть?!  

phprus, так у тебя этот баг тоже воспроизводиться?
скажи как тестируешь? версии ОС, компилятора, boost? локально, удаленно?

ну так это может быть пустой пакет с tcp флагами...
хотя я не очень понимаю формат снифа

еще проверь у себя версию в аттаче
там логинг asio заменен а логинг sendmsg/recvmsg

Присоединённый файл ( Кол-во скачиваний: 4 )
 asiotest.rar 3,33 Kb

Да, воспроизводится.
Boost 1.46.1
openSUSE 11.3 (2.6.34.7-0.7-desktop)
g++ (SUSE Linux) 4.5.0 20100604 [gcc-4_5-branch revision 160292]

Тестирую локально, путем запуска сервера и клиента с двух соседних консолей в Konsole.

и еще
вы пробовали запускать io_service::run не в отдельном потоке?

В реальной сети, с rtt min/avg/max/mdev = 5.226/5.250/5.281/0.023ms  баг воспроизводится значительно быстрее. В среднем до падения проходит 0,1 - 0,3 секунды, а в случае с локальным запуском код работает до падения минимум несколько секунд. Но тут boost 1.46.0 и CentOS с родным GCC 4.1.2.

сделал. на локальной машине.
в аттаче. это 7z архив. расширение сменил потому что форум не позволяет приаттачивать 7z.


скажите как сделать? а то я не очень разбираюсь в снифферах.

Добавлено @ 15:52

в последних исходниках теста, сервер, я так и сделал.
а клиенту, помимо того, что отправлять сообщения в цикле, нужно еще и принимать ответы от сервера. потому там я оставил один поток.

Добавлено через 11 минут и 24 секунды

проверил. у меня ничего не изменилось.
ubuntu-10.10
gcc-4.5.1
boost-1.46.1


Это сообщение отредактировал(а) boostcoder - 9.4.2011, 15:55

Присоединённый файл ( Кол-во скачиваний: 2 )
 logs1.zip 139,60 Kb

boostcoder, 

эмм
так а в чем проблема это все делать в одном потоке?
делаешь async_read, потом async_write
далее run и уже в обработчиках written/readed генерируешь новые операции...

или я ошибаюсь?

Добавлено через 1 минуту и 14 секунд
в общем нужно, имхо, избавиться от более одного потока в клиенте и сервере
и снова проверить

Добавлено через 2 минуты и 4 секунды

вот я не понимаю, как этот скрин был получен

перед async_write данные нужно приготовить. допустим, добавлю функцию prepare_data, из нее вызову async_write. но если prepare_data вызвать снова из written - то это будет уже не тот тест. т.к. written вызывается когда, согласно документации:

но не понятно, куда "written". в какой-то буфер ОС? на другой конец?

кстати, сейчас обратил внимание на это:

т.е. я правильно понимаю, что пока не вызовется хэндлер async_write, нельзя запускать новую операцию записи?
с тех пор как познакомился с этим багом, это примечание читал много раз, но обратил внимание только сейчас...

Добавлено @ 16:11

просмотром в mc.

Добавлено @ 16:14
MAKCim, в тех логах что выложил последними, проглядывается такое:


и такое:


это в файле server_in.log


Это сообщение отредактировал(а) boostcoder - 9.4.2011, 16:16

выходит так



думаю, когда возвратились из системного вызова sendmsg, это и есть written

Добавлено через 26 секунд

так а причем тут tcpdump тогда?

или же имеется ввиду, не вызывать эту функцию из нескольких потоков для одного сокета? ибо я всегда так это примечание и понимал.

если рассуждать логически, об этом (про потоки) было бы сказано, хотя не факт, конечно
поэтому я и предлагаю как-нибудь исхитриться и не юзать таки более одного потока

нет. те скрины что сделаны tcpdump`ом, я комментировал как скрины сделанные tcpdump`ом.
вот они:
http://clip2net.com/clip/m47996/1300879093-1-262kb.png
http://clip2net.com/clip/m47996/1300879448-2-27kb.png
http://clip2net.com/clip/m47996/1300879665-3-21kb.png
http://clip2net.com/clip/m47996/1300879710-4-22kb.png

и последние два:
http://clip2net.com/clip/m47996/1302213996...zb3346-11kb.png
http://clip2net.com/clip/m47996/1302214240...psa3346-4kb.png

т.е., на сколько я понял, для продолжения, нужно переписать клиент так, чтоб следующая запись производилась по окончанию предыдущей?
ок. сейчас.

Добавлено через 38 секунд

ок.
сейчас делаю.

переписал как договаривались, без единого потока, и с запуском следующей операции записи по завершению предыдущей.
работает значительно дольше, но все равно валится(только при запуске клиента и сервера локально):
исходники + логи, тут: http://rghost.ru/5141178

выложу в тему исходники. может я в коде что-то намудрил.. сам не замечаю..

клиент:


сервер:


общий хидер:


на клиент, в один прекрасный, приходит это:


тут две ошибки:
1. склеились две части "sc".
2. клиент ожидает 3574549, а пришло 3574550.

Добавлено @ 17:32
вот что еще странно.
в server_out.log есть такое:

т.е. одно и то же значение повторяется дважды.

хотя, в server_in.log этого нет:


странно..

Это сообщение отредактировал(а) boostcoder - 9.4.2011, 19:31

запустил сервер на удаленной машине - вроде работает. уже минут 10ть.

...
уже пол часа.

Это сообщение отредактировал(а) boostcoder - 9.4.2011, 18:45

а возврат из sendmsg() когда происходит? что-то немогу в доках найти этого момента..
дело в том, что скорость очень сильно упала.
сейчас, используется около 17% от пропускной способности.
чем это может быть вызвано?

возможно это из-за того, что происходит почти симметричных обмен? т.е. кол-во входящих и исходящих данных почти равно.
сейчас имею такую скорость обмена для одного клиента в секунду. что больше чем требуется.



вот только решить бы еще проблему порчи данных при запуске клиента и сервера локально..


Это сообщение отредактировал(а) boostcoder - 9.4.2011, 19:53

А в сервере это условие выполняется?

да.
сервер реализован по принципу реакции. пришли данные от клиента - отсылается ответ. и только после этого запускается следующая операция чтения.

Добавлено через 4 минуты и 41 секунду
коды несколькими постами выше.


Это сообщение отредактировал(а) boostcoder - 9.4.2011, 19:26

наверное тогда же, когда и send(). но в тестах, сокеты находятся в неблокирующем режиме.


получается что нет. т.к. изменил клиента и сервера так, что клиент только шлет, а сервер только принимает. никаких ответов обратно не шлется. скорость не увеличилась...

...

увеличил размер массивов с 13 байт до 1024 байт. использование канала не увеличилось.
получается так, что тормозом в данной ситуации является sendmsg().


Это сообщение отредактировал(а) boostcoder - 9.4.2011, 20:02

запустил параллельно тесту торрент-клиент, и все стало еще интересней  

в client_out.log стало наблюдаться такое:

и такое:

и такое:

и т.д...


в server_in.log такое:

и такое:


бред какой-то...

последняя версия исходников во вложении.


Это сообщение отредактировал(а) boostcoder - 9.4.2011, 20:33

Присоединённый файл ( Кол-во скачиваний: 1 )
 asiotest2.zip 3,54 Kb

что то этот момент меня сильно смущает..

mes, что именно в этом моменте Вас смущает?

start_write из writen.. 

и?
запуск следующей записи когда предыдущая завершилась.

не знаю, но интуитивно глаз спотыкается на этом месте.. 
остальной код подозрений не вызывает.. 

mes, на то он и _completion_handler_ чтоб из него производить некоторые действия по окончанию асинхронной операции.

в бустовых примерах подобное применение имеется ?

конечно. почти в каждом примере, где одна асинхронная операция создает другую.

зы
да и чем вызов start_write() из хэндлера, отличается от вызова из какого-то другого места?

Это сообщение отредактировал(а) boostcoder - 9.4.2011, 22:05

странно все это..
при загрузке сети, иногда валится, иногда нет...
любопытно, почему когда валится, в хэндлер не передается ошибка. хотя должна. т.е. из этого следует, что asio думает что все гуд 

Добавлено через 6 минут и 54 секунды
опять свалилось :(

клиент ожидал 8475039, а получил 84


обратите внимание. значение 8475038 повторяется дважды.

и еще одна странность. клиент упал с таким сообщением:

а пришло 847  

Добавлено через 12 минут и 27 секунд
  

попробуйте обнулять тот буффер, который создаете..

а записанное выглядит ровно, без сомнений ?

Добавлено через 49 секунд

да, тут зря я придрался.. 

попробовал. на обоих сторонах.
при загруженной сети, клиент свалился с таким сообщением:


во входящем буфере клиента было это:

опять одно и то же значение повторяется дважды.

сервер отправил это:



и снова непонятка... клиент говорит что получено 92410. но такого сообщения в входящих нет!  

это ###..

Добавлено @ 23:51

на скринах, где я упоминаю server_*.log и client_*.log - это и есть то, что записано. т.е. сырые данные.

Добавлено @ 23:55

кстати!
клиент падает по необработанному исключению. а в этом случае, файловые буфера сброшены не будут. потому я в логах не увижу последних данных.

сейчас повешу обработчик, и повторю тест.

Это сообщение отредактировал(а) boostcoder - 9.4.2011, 23:55

какой именно буффер ? а то что то я запутался..

Добавлено через 1 минуту и 37 секунд

ну это как раз не удивительно, Вы не проверяете кол-во прочитанных байтов... 

вы последний выложенный мной архив с исходниками качали? смотрели их? чтоб я знал с какой стороны объяснять..

попробуйте убрать из readed весь анализ приходящих данных и оставить только запись в файл.. 
только буффер не забудьте обнулять..


да смотрел и как раз смотрю их.. 

Это сообщение отредактировал(а) mes - 10.4.2011, 00:08

вот это?:

как же я тогда узнаю об ошибке?



там есть файл wrappers.cpp, его Максим добавил. логи пишутся из оберток над sendmsg() и recvmsg(). т.е. по идее на 100% точно отражают происходящее.

поставьте после каждой записи сырых данных еще запись какой нибудь последовательности..

Добавлено через 1 минуту и 24 секунды

если вы о исключении, то запись дополнительной последовательности в файл должна показать причину.. 

поясните. не понял.

Добавлено через 3 минуты и 58 секунд
еще, на сервере во входящих есть такое:


в hex:

т.е. три нуля.

после каждого сброса буффера в файл записывайте туда еще например "$$$"
чтоб наглядно бросалась в глаза.. 

но мне не известно когда буфера сбрасываются.
все что я могу, это принудительно вызывать fflush(). т.е. предлагаете вставить вызовы fflush() в обертки над sendmsg() и recvmsg() ?

Добавлено через 6 минут и 4 секунды
mes, я обернул код клиента в try-catch блок. теперь буфера не потеряются.
есть ли смысл сбрасывать буфера после каждой записи в файл?

Добавлено через 11 минут и 5 секунд
теперь свалился с таким сообщением:

в client_in.log такое:


число 6690985 повторяется дважды. хотя второе должно было быть 6690986
и пропал символ c и :