Subnets.ru blog

Кратко о BIRD:

 The BIRD project aims to develop a fully functional dynamic IP routing daemon.

 - Both IPv4 and IPv6
 - Multiple routing tables
 - BGP
 - RIP
 - OSPF
 - Static routes
 - Inter-table protocol
 - Command-line interface
 - Soft reconfiguration
 - Powerful language for route filtering

 WWW: http://bird.network.cz/

 Пользователи FreeBSD могут найти демоны BIRD в портах:
    IPv4 версия: /usr/ports/net/bird
    IPv6 версия: /usr/ports/net/bird6

С момента размещения статьи Используем BIRD для создания «пограничного» маршрутизатора размещенную zaikini, я все мечтал найти время и уделить его изучению и пробам BIRD.

О демоне BIRD народ хорошо отзывается, да и многие IX`ы держат свои Route Server`а именно на этом демоне.

И вот наконец мне предоставилась такая возможность. Для одного проекта понадобилось автоматом генерить blackhole маршруты для BGP и тут я вспомнил что как раз давно хотел попробовать BIRD.

Поднял на тестовом стенде из тройки виртуальных машин:

• FreeBSD 9.1 + BIRD 1.3.11
• FreeBSD 8.4 + BIRD 1.3.11
• FreeBSD 7.2 + BIRD 1.3.2
• FreeBSD 7.2 + BIRD 1.3.11

Погонял BGP и OSPF в различных конфигурациях и схемах — понравилось. Даже больше скажу — очень понравилось. Есть конечно в BIRD некоторые вещи пока не совсем мне понятные или как это сказать не до конца логичные, НО в целом абалденный демон. Респект и уважуха разработчикам BIRD.

Итоговый «приговор» по BIRD: must have.

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

Рестарт bgpd и о чудо ! Все непонятки устраняются и все работает как и положено. Но сейчас не об этом речь 🙂

Вообщем пересели мы на BIRD. Что дальше ? А дальше, как это водится, понадобился Looking Glass для BIRD`а, не всегда ж есть желание/возможность лазать в консоль 🙂

Погуглил… нагуглил только sileht/bird-lg и ulg—universal-looking-glass — оба написаны на python.

Попытки найти нечто подобное лукинг глассу для Cisco/Quagga/Juniper и на PHP мне не удалось.

«Ну что ж… Толи лыжи, толи … получается что нету… значит надо написать самому.» — сказал я и приступил к реализации :).

Через некоторое время первая версия LG на PHP была готова и протестирована.

Пока из функционала было реализовано самое необходимое — возможность посмотреть маршрут, пингать и трасернуть.

Потом я подумал о том, что скорее всего я не один такой, кто не хочет/может пользоваться LG на питоне, так же о (похоже) единственно существующем варианте LG для BIRD`а, а так же о том что сам пользуюсь бесплатным ПО, которое пишут и выкладывают другие и … и решил что нужно так же поделиться с общественностью своей разработкой.

Итак представляю вам свой труд и новый проект в рамках проекта Subnets.ru: BIRD Looking Glass на PHP.

Для работы LG вам необходимо:

• установленный и запущенный BIRD
• web сервер (аля apache)
• PHP5: модуль для apache и CLI версия

Более детально написано в README и ошибках, которые, если чего то не хватает, вам будет выдавать web интерфейс LG после его установки.

Я не смотрю на свои возможности через «розовые очки», я больше сис.админ чем программист, но все же кое что напрограммить и я могу 🙂

Лично я свою первоочередную задачу (наличие хоть какого LG для BIRD на PHP) решил. Возможно сей «продукт» поможет и вам.

Это явно не последняя версия этого LG, как снова дойдут руки — буду допиливать функционал далее, благо дело мыслей много, а желаний (как это обычно и бывает) ещё больше :).

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

Надо ли пояснять, что для функционирования сего механизма сервер с LG должен иметь доступ к Инету, а если быть точнее то к URL`у http://bird-lg.subnets.ru/.

Работа LG проверена под OS FreeBSD, если у вас другая ось то вы как раз проверите сами.

З.Ы. При копировании статьи ссылка на источник ОБЯЗАТЕЛЬНА ! Уважайте чужой труд.

Автор: Николаев Дмитрий (virus (at) subnets.ru)

Channel Event Logging (CEL)

Дано:

• FreeBSD 8.1-RELEASE
• Asterisk 1.8.17.0

Полученные от CEL данные будем складывать в csv и MySQL.

MySQL CEL Backend:

Using MySQL for Channel Event records is supported by using ODBC and the cel_odbc module.

Ставим порты для ODBC

• /usr/ports/databases/unixODBC
• /usr/ports/databases/mysql-connector-odbc

# pkg_info | grep ODBC
mysql-connector-odbc-unixodbc-mysql55-5.1.9 ODBC driver for MySQL55 / unixodbc
unixODBC-2.3.1 ODBC library suite for Unix

# ls -la /usr/local/lib/libmyodbc*
-rwxr-xr-x 1 root wheel 260880 18 сен 09:21 /usr/local/lib/libmyodbc5.so

Смотрим расположение конфиг файлов:

# odbcinst -j

unixODBC 2.3.1
DRIVERS............: /usr/local/etc/odbcinst.ini
SYSTEM DATA SOURCES: /usr/local/etc/odbc.ini
FILE DATA SOURCES..: /usr/local/etc/ODBCDataSources
USER DATA SOURCES..: /root/.odbc.ini
SQLULEN Size.......: 4
SQLLEN Size........: 4
SQLSETPOSIROW Size.: 2

Правим /usr/local/etc/odbcinst.ini

[MySQL]
Description=ODBC for MySQL
Driver=/usr/local/lib/libmyodbc5.so
UsageCount=20001

Инсталим драйвер:

# odbcinst -i -d -f /usr/local/etc/odbcinst.ini

Правим /usr/local/etc/odbc.ini:

[mysql-odbc-ini-asterisk]
Driver=MySQL
SERVER=127.0.0.1
PORT=3306
DATABASE=asterisk
USER=asterisk
PASSWORD=password
OPTION=4194304

Проверяем список доступных DSN:

# odbcinst -s -q

[mysql-odbc-ini-asterisk]

Настраиваем конфиги в Asterisk

/usr/local/etc/asterisk/cel.conf:

[general]
enable=yes
;apps=dial,park
;events=APP_START,CHAN_START,CHAN_END,ANSWER,HANGUP,BRIDGE_START,BRIDGE_END
apps=all
events=all
dateformat = %F %T

[manager]
enabled=no

[radius]

В /usr/local/etc/asterisk/cel_custom.conf раскомментируем секцию [mappings].
Проверим наличие директории /var/log/asterisk/cel-custom, если её нет то создадим ей и не забываем установить необходимые права, чтобы asterisk смог осуществить запись.

/usr/local/etc/asterisk/res_odbc.conf:
[asterisk-res-odbc]
enabled => yes
dsn => mysql-odbc-ini-asterisk
username => asterisk
password => password
pre-connect => yes

/usr/local/etc/asterisk/cel_odbc.conf:
[first]
connection=asterisk-res-odbc
table=cel
loguniqueid=yes

Создаем таблицу в базе:

CREATE TABLE IF NOT EXISTS `cel` (
  `id` int(11) NOT NULL auto_increment,
  `eventtype` varchar(30) NOT NULL,
  `eventtime` datetime NOT NULL,
  `cid_name` varchar(80) NOT NULL,
  `cid_num` varchar(80) NOT NULL,
  `cid_ani` varchar(80) NOT NULL,
  `cid_rdnis` varchar(80) NOT NULL,
  `cid_dnid` varchar(80) NOT NULL,
  `exten` varchar(80) NOT NULL,
  `context` varchar(80) NOT NULL,
  `channame` varchar(80) NOT NULL,
  `src` varchar(80) NOT NULL,
  `dst` varchar(80) NOT NULL,
  `channel` varchar(80) NOT NULL,
  `dstchannel` varchar(80) NOT NULL,
  `appname` varchar(80) NOT NULL,
  `appdata` varchar(80) NOT NULL,
  `amaflags` int(11) NOT NULL,
  `accountcode` varchar(20) NOT NULL,
  `uniqueid` varchar(32) NOT NULL,
  `linkedid` varchar(32) NOT NULL,
  `peer` varchar(80) NOT NULL,
  `userdeftype` varchar(255) NOT NULL,
  `eventextra` varchar(255) NOT NULL,
  `userfield` varchar(255) NOT NULL,
  PRIMARY KEY  (`id`),
  KEY `uniqueid_index` (`uniqueid`),
  KEY `linkedid_index` (`linkedid`)
);

Перезапускаем:
# asterisk -r
asterisk*CLI> module reload res_odbc.so
— Reloading module ‘res_odbc.so’ (ODBC resource)
== Parsing ‘/usr/local/etc/asterisk/res_odbc.conf’: == Found
[Sep 18 10:05:59] NOTICE[84181]: res_odbc.c:1531 odbc_obj_connect: Connecting asterisk-res-odbc
[Sep 18 10:05:59] NOTICE[84181]: res_odbc.c:1563 odbc_obj_connect: res_odbc: Connected to asterisk-res-odbc [mysql-odbc-ini-asterisk]
[Sep 18 10:05:59] NOTICE[84181]: res_odbc.c:920 load_odbc_config: Registered ODBC class ‘asterisk-res-odbc’ dsn->[mysql-odbc-ini-asterisk]
[Sep 18 10:05:59] DEBUG[84181]: res_odbc.c:1504 odbc_obj_disconnect: Database handle 0x2a9a6000 deallocated

asterisk*CLI> module reload cel_odbc.so
— Reloading module ‘cel_odbc.so’ (ODBC CEL backend)
== Parsing ‘/usr/local/etc/asterisk/cel_odbc.conf’: == Found
— Found CEL table cel@asterisk-res-odbc.

asterisk*CLI> module reload cel_custom.so
— Reloading module ‘cel_custom.so’ (Customizable Comma Separated Values CEL Backend)
== Parsing ‘/usr/local/etc/asterisk/cel_custom.conf’: == Found

Проверяем:
asterisk*CLI> cel show status
CEL Logging: Enabled
CEL Tracking Event: ALL
CEL Tracking Event: CHAN_START
CEL Tracking Event: CHAN_END
CEL Tracking Event: HANGUP
CEL Tracking Event: ANSWER
CEL Tracking Event: APP_START
CEL Tracking Event: APP_END
CEL Tracking Event: BRIDGE_START
CEL Tracking Event: BRIDGE_END
CEL Tracking Event: CONF_START
CEL Tracking Event: CONF_END
CEL Tracking Event: PARK_START
CEL Tracking Event: PARK_END
CEL Tracking Event: BLINDTRANSFER
CEL Tracking Event: ATTENDEDTRANSFER
CEL Tracking Event: TRANSFER
CEL Tracking Event: HOOKFLASH
CEL Tracking Event: 3WAY_START
CEL Tracking Event: 3WAY_END
CEL Tracking Event: CONF_ENTER
CEL Tracking Event: CONF_EXIT
CEL Tracking Event: USER_DEFINED
CEL Tracking Event: LINKEDID_END
CEL Tracking Event: BRIDGE_UPDATE
CEL Tracking Event: PICKUP
CEL Tracking Event: FORWARD
CEL Tracking Application: all
CEL Event Subscriber: ODBC CEL backend
CEL Event Subscriber: CEL Custom CSV Logging

asterisk*CLI> odbc show

ODBC DSN Settings
——————

Name: asterisk-res-odbc
DSN: mysql-odbc-ini-asterisk
Last connection attempt: 1970-01-01 03:00:00
Pooled: No
Connected: Yes

После чего при прохождении вызовов должна будет заполняться таблица cel в БД asteriskб так же файл /var/log/asterisk/cel-custom/Master.csv.

Описание: CEL Events and Fields

Существует возможность генерить свои event`ы: CELGenUserEvent Application:

asterisk*CLI> core show application CELGenUserEvent

  -= Info about application 'CELGenUserEvent' =-

[Synopsis]
Generates a CEL User Defined Event.

[Description]
A CEL event will be immediately generated by this channel, with the supplied
name for a type.

[Syntax]
CELGenUserEvent(event-name[,extra])

[Arguments]
extra
    Extra text to be included with the event.

Ссылки:

• Channel Event Logging (CEL)
• Setting up Channel Event Logging (CEL) on Asterisk 1.8 or up with MySQL
• Asterisk™: The Definitive Guide: Chapter 24. System Monitoring and Logging
• Using MySQL through ODBC on FreeBSD

З.Ы. При копировании статьи ссылка на источник ОБЯЗАТЕЛЬНА !

Автор:  Николаев Дмитрий (virus (at) subnets.ru

Предыстория такова, что 19.08.2013 я нас своей рабочей машине FreeBSD 8.4-PRERELEASE (32х битка) делаю:

# portsnap fecth update && portupgrade -a

Придя на следующий день на работу и выполняя привычную команду:

# startx

Вместо иксов с enlightenment я получаю черный экран и усё…. приплыли.  На клаву вообще никак не реагирует.. ни свернуть исксы, ни убить иксы не пашет… Пришлось зайти с другой машины по SSH и прибить процесс enlightenment_start руками. Тогда черный экран пропадает и возвращается в консоль.

Просмотр лога /var/log/Xorg.0.log ничего не дает, т.к. ошибок (EE) там никаких нет и ничего даже смутно не указывает на какую либо проблему.

Посмотрев что именно обновлялось стало понятно что апдейтились дрова nvidia и сам enlightenment . Пробовал откатить дрова nvidia, перебрал несколько версий, но тщетно — черный экран и ничего более.

Затем пробовал стартануть исксы без конфига, т.е. сносил /etc/X11/xorg.conf как класс, но результат тот же — черный экран и ничего.  Затем попробовал стартануть иксы с автосгенеренным конфигом:

# Xorg :1 -configure

# X -config /root/xorg.conf.new

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

В очередной раз выполнив в google.ru запрос поиска по: startx blank screen freebsd

Нашел только что можно добавить опцию -retro:

# X -config /root/xorg.conf.new -retro

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

После этого пришла мысль попробовать стартануть иксы без window manager`а вообще, тупо только с xterm:

# startx `which xterm`

Все ОК, никаких черных экранов, иксы стартуют, xterm нормально открывается. Такссс. Теперь пробуем самый простенький window manager, который идет с иксами по дефолту:

/usr/local/bin/twm (в портах лежит тут: /usr/ports/x11-wm/twm)

Редактируем /root/.xinitrc, ремим запуск enlightenment и добавляем запуск twm с xterm:

#exec /usr/local/bin/enlightenment_start
xterm &
exec /usr/local/bin/twm

Стартуем иксы и снова все хорошо — twm работает, xterm открылся. До кучи попробовал ещё один простенький wm /usr/ports/x11-wm/fvwm — результат тот же — все работает.

Ну тут, как говорится «К бабке не ходи», все понятно, проблема в самом enlightenment . Открываю xterm и пробую стартануть enlightenment руками оттуда, получаем последней строкой:

/usr/local/lib/enlightenment/utils/enlightenment_init ‘/usr/local/share/enlightenment/data/themes/default.edj’ ‘0’ ‘Enlightenment’ ‘0.17.4’

и все… ничего не происходит… Далее я делал кучу всякой всячины, которую не буду описывать т.к. ничего не помогало. В итоге я пришел к выводу о downgrade enlightenment  с 0.17.4 обратно на 0.17.3, т.к. с этой версией проблем не было.

Сказано — сделано. Ставим /usr/ports/ports-mgmt/portdowngrade и приступаем.

Просто даунгрейд порта /usr/ports/x11-xm/enlightenment ничего не дал… черный экран остался. Становится понятно, что придется даунгрейдить и его зависимости…

Ищем зависимости enlightenment и составляем полный список портов на downgrade согласно зависимостям одного порта от другого.

Делал я это с помощью команды:

# pkg_info -r enlightenment-0.17.3,2 | grep «: e»

А затем до кучи проверил тупо по версии:

# pkg_info | grep 1.7.8

Пройдясь по всем портам из составленного списка командой:

# pkg_info -R FULL_INSTALLED_PORT_NAME

Я расставил порты на downgrade в таком порядке исходя из их зависимостей:

• 1. ecore-ipc-1.7.8 devel/ecore-ipc
• 2.  ecore-sdl-1.7.8 graphics/ecore-sdl
• 3.  edje-1.7.8,2 graphics/edje
• 4. evas-loader-png-1.7.8 graphics/evas-loader-png
• 5. evas-loader-jpeg-1.7.8 graphics/evas-loader-jpeg
• 6. evas-loader-eet-1.7.8 graphics/evas-loader-eet
• 7. embryo-1.7.8,2 lang/embryo
• 8. eio-1.7.8 devel/eio
• 9. efreet-1.7.8 x11/efreet
• 10. e_dbus-1.7.8,1 devel/e_dbus
• 11. ecore-evas-1.7.8 graphics/ecore-evas
• 12. ecore-imf_evas-1.7.8 x11/ecore-imf_evas
• 13.   ecore-input_evas-1.7.8 x11/ecore-input_evas
• 14.  ecore-file-1.7.8 devel/ecore-file
• 15.  ecore-con-1.7.8 net/ecore-con
• 16.  ecore-imf-1.7.8 x11/ecore-imf
• 17.  ecore-x11-1.7.8 x11/ecore-x11
• 18.  ecore-input-1.7.8 x11/ecore-input
• 19.  ecore-main-1.7.8 devel/ecore-main
• 20. evas-engine-x11-1.7.8 graphics/evas-engine-buffer
• 21.  evas-engine-opengl-1.7.8 graphics/evas-engine-opengl
• 22.  evas-engine-buffer-1.7.8 graphics/evas-engine-buffer
• 23.  evas-core-1.7.8 graphics/evas-core
• 24.  eet-1.7.8,2 devel/eet
• 25.  eina-1.7.8 devel/eina
• 26. enlightenment x11-wm/enlightenment

Приступаем к downgrade:

# mkdir /usr/downgrade

# cd /usr/downgrade

# portdowngrade x11-wm/enlightenment | more

Смотрим до какой ревизии откатываемся:

------------------------------------------------------------------------
r318442 | gblach | 2013-05-18 23:36:31 +0400 (Sat, 18 May 2013) | 5 lines

- Update EFL libraries to 1.7.7
- Update Enlightenment to 0.17.3

Approved by: crees (mentor)

Вот r318442 то что нам и надо.

Выполняем с названием каждого порта из составленного списка команду portdowngrade ИМЯ_ПОРТА r318442, пример :

# portdowngrade x11-wm/enlightenment r318442

Затем я отмувил даунгрейднутые порты из папки /usr/downgrade на их законные места в папке /usr/ports, т.к. например ecore-sdl при сборке лазает в папку с портом ../../devel/ecore-main.

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

Пример:

# pkg_delete -f ecore-ipc-1.7.8

# cd /usr/ports/devel/ecore-ipc

# make; make install

И так с каждым портом из списка. В итоге мы получаем:

# pkg_info | grep enli
enlightenment-0.17.3,2 A very artistic X window manager

Стартуем startx и все СНОВА РАБОТАЕТ !!! УРА !!!!

З.Ы. При копировании статьи ссылка на источник ОБЯЗАТЕЛЬНА !

Авторы:  Панфилов Алексей (lehis (at) subnets.ru) и Николаев Дмитрий (virus (at) subnets.ru)

Столкнулись с проблемой в Asterisk 1.8 при auto-dial out.

Честно сказать не знаю то ли мы такие «везучие», то ли лыжи не едут, но в очередной раз мы наступаем на грабли о которых гугл и великий ALL толком ничего «сказать» не может. У всех все типа работает и если есть похожее, то оно решается путем чтения мануала до полного просветления.

Имеем:

• Virtualbox 4.0.12
• Freebsd 8.1-RELEASE
• Asterisk 1.8.17.0

В очередно раз появилась задача поднять Asterisk, нужно это для предоставления услуг IP-АТС для физиков.

Ранее мы ставили Asterisk 1.4, а тут решили что пора бы уже попробовать перейти на версию 1.8. Сказано — сделано.

Установка прошла как обычно, без проблем. После настройки, установки собственного web-интерфейса управления астериском и небольших изменений в виду некоторых отличий конфигов версии 1.8 от 1.4 мы приступили к тестированию.
Было обнаружено, что не работают функции callback, email2fax, web2fax.  Все эти функции упираются в одну точку и имя ей auto-dial out, генерация call файлов для совершения автоматического исходящего вызова.
Начинаем разбираться. Запускаем астериск, заходим в консоль и включаем verbose:
# asterisk -r
aster*CLI> core set verbose 3
Verbosity is at least 3
Звоним на callback номер, где после проверки php скрипт генерит call-файл для совершения обратного вызова и отправляет его в /var/spool/asterisk/outgoing для непосредственно совершения вызова и зрим в консоль:
aster*CLI> [Oct 17 12:49:49] WARNING[35623]: pbx_spool.c:258 apply_outgoing: At least one of app or extension must be specified, along with tech and dest in file /var/spool/asterisk/outgoing/callback_1_813.call aster*CLI>
[Oct 17 12:49:49] WARNING[35623]: pbx_spool.c:419 scan_service: Invalid file contents in /var/spool/asterisk/outgoing/callback_1_813, deleting
Называется приехали… Сначала мы подумали что из-за разницы в версиях астера есть какое то отличие в синтаксисе call файла.

После прочтения auto-dial out заново стало понятно что это не так. Отличий нет. Хм….

Едем далее. Убираем из скрипта автоперемещение call файла в /var/spool/asterisk/outgoing и кладем его в созданную диру /var/spool/asterisk/outgoing-test и смотрим на результат генерации:
Channel: LOCAL/005@users_813_clientID_1
Callerid: 813
MaxRetries: 5
RetryTime: 15
WaitTime: 60
Context: callback_813_clientID_1
Extension: s
Priority: 1
Абсолютно нормальный call файл. Берем и копируем call файл руками:
# /bin/cp /tmp/aster/callback_1_813.call /var/spool/asterisk/outgoing/
И о чудо, астер уже не ругается в консоли и спокойно начинает обрабатывать файл и совершает исходящий вызов. Хм……
Тестим исходящий факс, где call файл уже генерится perl скриптом. Та же ситуёвина. При перемещении call файла в /var/spool/asterisk/outgoing скриптом в консоли астера идет ругань на call файл, а при копирования файла руками все ОК.
Хм….. снова приехали…..
Включаем дебаг:
aster*CLI> core set debug 9
Не помогает ничем, более детально проблема так и не описана. Чешем репу… гуглим… есть похожие случаи, но все равно не то что у нас.
Начинаем строить предположения:
а) Астер начинает обрабатывать call файл в соответствии с датой модификации файла (mtime). Проблема с touch (который сдвигает дату модификации call файла перед перемещением в outgoing) ?
б) проблема с правами на файл ?

Не буду подробно расписывать весь мозговой и ручной процесс, ибо это долго, а напишу вкратце.
Проверяем догадку «а»:
Смотрим какие у нас даты после создания call файла:
# stat /var/spool/asterisk/outgoing-test/callback_1_813.call
72 47370 -rw-r--r-- 1 asterisk asterisk 191847 238 "Oct 17 14:34:50 2012" "Oct 17 14:30:32 2012" "Oct 17 15:19:02 2012" "Oct 17 14:29:50 2012" 16384 4 0 callback_1_813.call
Даты перечисляются в таком порядке: a, m, c, B.

• a — access time, время последнего доступа к файлу
• m — modificatiom time, время последнего изменения файла
• c — create time, дата создания файла
• B — birth time of the inode, дата дескриптора

Как видно из вывода stat даты разные и сдвинуты во времени относительно СЕЙЧАС в будущее, напомню что это делается в скрипте генерации call файла командой touch.
Вывод: тут все ОК.

Проверяем догадку «б»:
какие права на файл не поставь, от какого юзера asterisk не запусти — результат тот же — в консоле астера:
At least one of app or extension must be specified, along with tech and dest in file
Мда…. asterisk запущенный от пользователя root не может прочитать файл с владельцем root или asterisk… это уже не в какие ворота….

Ну что ж, здравые идеи закончились и видимо без «напильника» уже не обойтись, т.к. проблему кроме нас самих никто не решит.
Лезем в исходки астера на предмет установления места где идет обработка call файла и его обработка. За обработку call файлов отвечает спулер:

/usr/ports/net/asterisk/work/asterisk-1.8.17.0/pbx/pbx_spool.c.

Открываем его для изучения с места где отпечатывается выше указанные ошибки при обработке call файла и смотрим строчки с номерами, которые печатаются в консоль в сообщении об ошибке: стр. 258 и стр. 419. Приходим к тому что без дебага того что же все же видит астер в call файле не обойтись. Добавляем:
ast_debug( 1, "[%s]: mode: %o, uid: %d, gid: %d, size: %ld, now: %ld, mtime: %ld, atime: %ld, ctime: %ld, birth: %ld\n", filename, st.st_mode, st.st_uid, st.st_gid, (long) st.st_size, (long) now, (long) st.st_mtime, (long) st.st_atime, (long) st.st_ctime, (long) st.st_birthtime );
Чтобы видеть права, пользователя, группу и даты. Запускаем скрипт генерации call файла и зрим в консоль:
[Oct 17 17:58:08] DEBUG[2027]: pbx_spool.c:517 queue_file: [/var/spool/asterisk/outgoing/callback_1_813.call]: mode: 100000, uid: 0, gid: 931, size: 0, now: 1350482288, mtime: 1350482288, atime: 1350482288, ctime: 1350482288, birth: 1350482288
Мда…. Размер файла ноль байт! О как ! Теперь понятно почему астер плюет ошибки при обработке файла, ведь он считает что файл ПУСТОЙ !
Так же смотрим man 2 stat на предмет значения mode и понимаем что права на файл (даже на чтение) отсутствуют у всех ! Так же видно что unixtime даты в полях now, mtime, atime, ctime, birth одинаковы и это текущая дата, а не даты, которые приведены выше в выводе stat /var/spool/asterisk/outgoing-test/callback_1_813.call копируемого файла.
Отсюда появляется догадка «в»:
При копировании call файла скриптом астер не дает файлу докопироваться и пускает его в обработку и анализу ДО того как он полностью перемещается в /var/spool/asterisk/outgoing.
Проверяем догадку «в»:
Ищем решение и оно нашлось достаточно быстро и достаточно тривиальное: «попросить» астер «заснуть» на 30 мс перед тем как хапать файл.
Делаем добавление в функции static void queue_file(const char *filename, time_t when) вызова usleep( 30000 ); перед if (stat(filename, &st)) { (в оригинальном исходном коде этот условный переход расположен в строке 484) и снова смотрим в консоль:
[Oct 17 17:58:08] DEBUG[2027]: pbx_spool.c:517 queue_file: [/var/spool/asterisk/outgoing/callback_1_813.call]: Data BEFORE usleep: mode: 100000, uid: 0, gid: 931, size: 0, now: 1350482288, mtime: 1350482288, atime: 1350482288, ctime: 1350482288, birth: 1350482288
[Oct 17 17:58:08] DEBUG[2027]: pbx_spool.c:532 queue_file: [/var/spool/asterisk/outgoing/callback_1_813.call]: Data AFTER usleep: mode: 100644, uid: 931, gid: 931, size: 153, now: 1350482288, mtime: 1350482298, atime: 1350482298, ctime: 1350482288, birth: 1350482288
Называется «почувствуйте разницу!».

Права и даты в строке выводимой после usleep уже правильные и соответствуют копируемому файлу.

И снова чудо ! Действительно этой задержки перед обработкой оказалось достаточно для завершения полного копирования call файла и он начал нормально обрабатываться asterisk`ом уже без ругани.

Вот такая вот история. Надеемся что кому нить поможет если он столкнется с похожей ситуёвиной.

Найти ответ на вопрос «Почему при копированием скриптом астер не дает файлу докопироваться, а при копировании руками все ОК ?»  мы так и не сумели. Если у кого то есть предположения, то милости просим в комменты к статье.

Ну и напоследок:
Мы немного расширили режим отладки обработки call-файлов. Теперь при наложении нашего патча и указании вывода дебага (core set debug 1) будем видеть всю «историю процесса».
Пример:
[Oct 17 17:58:08] DEBUG[2027]: pbx_spool.c:765 scan_thread: Directory changed, rescan
[Oct 17 17:58:08] DEBUG[2027]: pbx_spool.c:517 queue_file: [/var/spool/asterisk/outgoing/callback_1_813.call]: Data BEFORE usleep: mode: 100000, uid: 0, gid: 931, size: 0, now: 1350482288, mtime: 1350482288, atime: 1350482288, ctime: 1350482288, birth: 1350482288
[Oct 17 17:58:08] DEBUG[2027]: pbx_spool.c:532 queue_file: [/var/spool/asterisk/outgoing/callback_1_813.call]: Data AFTER usleep: mode: 100644, uid: 931, gid: 931, size: 153, now: 1350482288, mtime: 1350482298, atime: 1350482298, ctime: 1350482288, birth: 1350482288
[Oct 17 17:58:18] DEBUG[2027]: pbx_spool.c:146 apply_outgoing: [/var/spool/asterisk/outgoing/callback_1_813.call]: Fresh data: mode: 100644, uid: 931, gid: 931, size: 153, mtime: 1350482298, atime: 1350482298, ctime: 1350482288, birth: 1350482288
[Oct 17 17:58:18] DEBUG[2027]: pbx_spool.c:147 apply_outgoing: [/var/spool/asterisk/outgoing/callback_1_813.call]: Read content
[Oct 17 17:58:18] DEBUG[2027]: pbx_spool.c:181 apply_outgoing: [/var/spool/asterisk/outgoing/callback_1_813.call]: line 1: Channel: LOCAL/005@users_813_clientID_1
[Oct 17 17:58:18] DEBUG[2027]: pbx_spool.c:181 apply_outgoing: [/var/spool/asterisk/outgoing/callback_1_813.call]: line 2: Callerid: 813
[Oct 17 17:58:18] DEBUG[2027]: pbx_spool.c:181 apply_outgoing: [/var/spool/asterisk/outgoing/callback_1_813.call]: line 3: MaxRetries: 5
[Oct 17 17:58:18] DEBUG[2027]: pbx_spool.c:181 apply_outgoing: [/var/spool/asterisk/outgoing/callback_1_813.call]: line 4: RetryTime: 15
[Oct 17 17:58:18] DEBUG[2027]: pbx_spool.c:181 apply_outgoing: [/var/spool/asterisk/outgoing/callback_1_813.call]: line 5: WaitTime: 60
[Oct 17 17:58:18] DEBUG[2027]: pbx_spool.c:181 apply_outgoing: [/var/spool/asterisk/outgoing/callback_1_813.call]: line 6: Context: callback_813_clientID_1
[Oct 17 17:58:18] DEBUG[2027]: pbx_spool.c:181 apply_outgoing: [/var/spool/asterisk/outgoing/callback_1_813.call]: line 7: Extension: s
[Oct 17 17:58:18] DEBUG[2027]: pbx_spool.c:181 apply_outgoing: [/var/spool/asterisk/outgoing/callback_1_813.call]: line 8: Priority: 1
[Oct 17 17:58:18] DEBUG[2027]: pbx_spool.c:277 apply_outgoing: [/var/spool/asterisk/outgoing/callback_1_813.call]: processed 8 lines
[Oct 17 17:58:18] DEBUG[2027]: pbx_spool.c:291 safe_append: Outgoing LOCAL/005@users_813_clientID_1: StartRetry

-- Attempting call on LOCAL/005@users_813_clientID_1 for s@callback_813_clientID_1:1 (Retry 1)

...

[Oct 17 17:58:23] NOTICE[2027]: pbx_spool.c:388 attempt_thread: Call completed to LOCAL/005@users_813_clientID_1
[Oct 17 17:58:23] DEBUG[2027]: pbx_spool.c:765 scan_thread: Directory changed, rescan

Т.е. теперь видны не только права и даты ДО и ПОСЛЕ, но и само содержимое call файла, которое хпнул asterisk.

Наш патч можно поместить прямо в порт /usr/ports/net/asterisk/files и пересобрать астер.

З.Ы. При копировании статьи ссылка на источник ОБЯЗАТЕЛЬНА !

Авторы:  Панфилов Алексей (lehis (at) subnets.ru) и Николаев Дмитрий (virus (at) subnets.ru)

З.Ы. При копировании статьи ссылка на источник ОБЯЗАТЕЛЬНА ! Пожалуйста, уважайте чужой труд.

Автор:  Панфилов Алексей (lehis (at) subnets.ru)