LINUX.ORG.RU

Python, падение приложения

 


0

2

Всем привет. Столкнулся с проблемой падения своего сервера.

Сервер это комбайн, который в зависимости от событий создает объекты (У них общий базовый класс) и передает между ними события. Все объекты создаются в одном и тоже потоке - uthread, функционируют они в нем же. Так же имеются несколько других потоков (одни для tornado (основной), другой для синхронного взаимодействия с платой (Queue) и третий для (входящих запросов))

Из удаленной консольки вижу мои потоки:

>>> >threading.enumerate()
'[<_MainThread(MainThread, started -1208498496)>,
 <Thread(uthread_0, started daemon 25316240)>,
 <Thread(Queue_0, started daemon 38382480)>,
 <Server(NetServer, started daemon 72010640)>]'

Для логирования использую logging где в конфиге указываю выводить имя потока, в котором производится вывод. 99 % нагрузки обрабатывается в uthread, там же объекты и удаляются сборщиком (__del__ показывет точное время удаления). Сервер долго крутиться, но иногда падает, и последнее, что я вижу в логах - это (смотри строки с Dummy-1)

 2016-02-03 12:11:19,145     INFO                <12:06:20 0xb4c59becL VA>   uthread_0            <12:06:27 0xb4c6a8acL Switch>  L{64:127} <- L{17:07}
 2016-02-03 12:11:19,146     INFO                <12:06:20 0xb4c59becL VA>   uthread_0            <12:06:27 0xb4c6a8acL Switch>  L{64:150} <- L{21:00}
 2016-02-03 12:11:19,147     INFO                <12:06:20 0xb4c59becL VA>   uthread_0  <12:11:19 0xb579944cL PostConversation>  Create post conversation:
 2016-02-03 12:11:19,148     INFO                <12:06:20 0xb4c59becL VA>   uthread_0  <12:11:19 0xb579944cL PostConversation>  {'a_call': <12:06:20 0xb4f0612cL Call_0x2c8c012f>,
 2016-02-03 12:11:19,148     INFO                <12:06:20 0xb4c59becL VA>   uthread_0  <12:11:19 0xb579944cL PostConversation>   'b_call': None,
 2016-02-03 12:11:19,149     INFO                <12:06:20 0xb4c59becL VA>   uthread_0  <12:11:19 0xb579944cL PostConversation>   'parent_operation_id': 37533}
 2016-02-03 12:11:19,149     INFO                <12:06:20 0xb4c59becL VA>   uthread_0  <12:11:19 0xb579944cL PostConversation>  a_call.state = connected
 2016-02-03 12:11:19,153     INFO                <12:06:20 0xb4c59becL VA>   uthread_0  <12:11:19 0xb579944cL PostConversation>  CREATED SUCCESSFULLY, parent = <12:06:20 0xb4c59becL VA>
 2016-02-03 12:11:19,153     INFO                <12:06:20 0xb4c59becL VA>   uthread_0            <12:06:27 0xb4c6a8acL Switch>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:11:19,154     INFO                <12:06:20 0xb4c59becL VA>   uthread_0              <12:06:26 0xb4cae7ecL Talk>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:11:19,164     INFO                <12:06:20 0xb4c59becL VA>   uthread_0  <12:11:19 0xb579944cL PostConversation>  Post session complete
 2016-02-03 12:11:19,297     INFO                <12:06:20 0xb4c59becL VA>   uthread_0   <22:58:23 0xb70b7decL 000408_IsdnLine>  NCCEVN_CALL_DISCONNECTED, value: 0 (call_hd = 0x2c8c012f) --> ['12:06:20 0xb4f0612cL Call_0x2c8c012f']
 2016-02-03 12:11:19,298     INFO                <12:06:20 0xb4c59becL VA>   uthread_0   <12:06:20 0xb4f0612cL Call_0x2c8c012f>  release_cause 16: Normal call clearing
 2016-02-03 12:11:19,301     INFO                <12:06:20 0xb4c59becL VA>   uthread_0   <22:58:23 0xb70b7decL 000408_IsdnLine>  NCCEVN_CALL_RELEASED, value: 0 (call_hd = 0x2c8c012f) --> ['12:06:20 0xb4f0612cL Call_0x2c8c012f']
 2016-02-03 12:11:19,313     INFO                <12:06:20 0xb4c59becL VA>   uthread_0  <12:11:19 0xb579944cL PostConversation>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:11:19,313     INFO                <12:06:20 0xb4c59becL VA>   uthread_0                <12:06:20 0xb4c59becL VA>  event stop_session: {'release_desc': 'no_operation', 'uuid': '64515124ca5511e5a114003048f81a82', 'release_cause_id': 16}
 2016-02-03 12:11:20,721     INFO                <12:06:20 0xb4c59becL VA>   uthread_0    <12:06:27 0xb4c5e6ecL TalkRecordTalk>  mix wave success: result = tmp/18926_talk_2016-02-03_12_06_27.081_talk.wav
 2016-02-03 12:11:22,767     INFO                <12:06:20 0xb4c59becL VA>   uthread_0    <12:06:27 0xb4c5e6ecL TalkRecordTalk>  Convert audio success: /var/comagic_storage/18926/talk/2016-02-03_12_06_27.081_from_74957885699_to_067685_talk.mp3
 2016-02-03 12:11:22,780     INFO                <12:06:20 0xb4c59becL VA>   uthread_0    <12:06:27 0xb4c5e6ecL TalkRecordTalk>  Save record success
 2016-02-03 12:11:22,781     INFO                <12:06:20 0xb4c59becL VA>   uthread_0                <12:06:20 0xb4c59becL VA>  event stop_talk_option: {'uuid': '6804443eca5511e5a114003048f81a82'}
 2016-02-03 12:11:22,783     INFO                <12:06:20 0xb4c59becL VA>   uthread_0   <12:06:21 0xb4f0e66cL Call_0x2c98013e>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:11:22,783     INFO                <12:06:20 0xb4c59becL VA>   uthread_0         <12:06:27 0xb4f006ccL ARecorder>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:11:22,784     INFO                <12:06:20 0xb4c59becL VA>   uthread_0         <12:06:27 0xb4c68eacL BRecorder>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:11:22,784     INFO                <12:06:20 0xb4c59becL VA>   uthread_0                <12:06:20 0xb4c59becL VA>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:11:22,784     INFO                <12:06:20 0xb4c59becL VA>   uthread_0   <12:06:20 0xb4f0612cL Call_0x2c8c012f>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:11:22,784     INFO                <12:06:20 0xb4c59becL VA>   uthread_0        <12:06:20 0xb4c6d68cL CrmHandler>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:11:22,785     INFO                <12:06:20 0xb4c59becL VA>   uthread_0    <12:06:27 0xb4c5e6ecL TalkRecordTalk>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:12:28,445     INFO                <12:06:20 0xb4c59becL VA>     Dummy-1            <12:06:20 0xb4c6deecL Dialer>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:12:28,447     INFO                <12:06:20 0xb4c59becL VA>     Dummy-1      <12:06:20 0xb4c4e1ccL dialer_timer>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:12:28,450     INFO                <12:06:20 0xb4c59becL VA>     Dummy-1            <12:06:20 0xb4c6e42cL Dialer>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:12:28,451     INFO                <12:06:20 0xb4c59becL VA>     Dummy-1      <12:06:20 0xb53fddccL dialer_timer>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:12:28,452     INFO                <12:06:20 0xb4c59becL VA>     Dummy-1            <12:06:20 0xb4c6d10cL Dialer>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:12:28,453     INFO                <12:06:20 0xb4c59becL VA>     Dummy-1      <12:06:21 0xb531a64cL dialer_timer>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:12:28,454     INFO                <12:06:20 0xb4c59becL VA>     Dummy-1            <12:06:20 0xb4c6e64cL Dialer>  DESTRUCTED SUCCESSFULLY
 2016-02-03 12:12:28,455     INFO                <12:06:20 0xb4c59becL VA>     Dummy-1      <12:06:20 0xb4e34facL dialer_timer>  DESTRUCTED SUCCESSFULLY

Поток с именем Dummy-1 у меня вообще не существует. В run time потоки не создаются (только при запуске 4 шт, которые я указал выше.)

Ума не приложу что делать и куда копать, прошу помощи.



Последнее исправление: energyclab (всего исправлений: 1)
Ответ на: комментарий от anonymous

Просьба прояснить, что за threading.Timer. Как раз сейчас разбираю логику с таймерами. Они у меня на торнадовских call_later построены

energyclab
() автор топика
Ответ на: комментарий от anonymous

Спасибо за наводку. В доках tornado явно сказано, что call_later и add_timeout нельзя вызывать из других потоков, а add_callback можно

energyclab
() автор топика

а потоки точно нужны? на multiprocessing их никак не заменить?

потоки в питоне в общем-то вещь малополезная из-за GIL...

NiTr0 ★★★★★
()
Последнее исправление: NiTr0 (всего исправлений: 1)
Ответ на: комментарий от NiTr0

Проблему решил именно тем, что пересмотрел места, где вызывались функции работы с таймерами. А вообще, я и шел к тому, чтобы минимизировать кол-во потоков, в итогде имею два потока, 1 для tornado, второй - для драйвера оборудования. К сожалению в нем пока что только блокирующие функции... Добраться до дискрипторов, чтобы их полить, сейчас нету времени и возможности...

energyclab
() автор топика
Ответ на: комментарий от NiTr0

потоки в питоне в общем-то вещь малополезная из-за GIL...

А может ты все-таки уточнишь, а то с твоих слов выходит что потоки в любом случае будут лочиться на GIL, а это тотальная чушь же.

anonymous
()
Вы не можете добавлять комментарии в эту тему. Тема перемещена в архив.