29.03.2019 Отладка трансивера - весна 2019

Материал из SRNS
Перейти к: навигация, поиск

Содержание

Рекомендации по записи экспериментов

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

Желательно записывать следующие данные:

  • дату испытания (в заголовке);
  • номер ревизии PL;
  • номер ревизии PS;
  • экземпляр приемника;
  • условия;
  • цель;
  • ожидаемые результаты;
  • фактические результаты;
  • выводы.

2019.03.29 - Ночной тест MCR1

  • номер ревизии PL: из bin соответствующей ревизии
  • номер ревизии PS: f819e3f0eb58821bf3dba23844136dcc9b294adc с небольшими изменениями (main тактируются процессорным временем вместо плисовского)
  • экземпляр приемника: MCR1 плата 61;
  • условия: антенна на крыше Е;

Приемник проработал ночь, всё ещё трудится. Забито 60 каналов, в F5 около 50 сигналов.

Сообщений от sendMeas о неадекватном времени нет. Но если посмотреть на F5 пакет, то за это время были проблемы:

  • два соседних пакетика в F5 поменяны местами (два раза такое возникло)
  • пропущена одна секунда полностью (один раз)
  • пропущено 8 секунд (один раз) (вроде бы соответствует проблемам с прерываниями на 930 минуте, там между прерываниями вдруг 4 мс)
20190329 MCR1 F5 depdiff.png

Время возникновения проблем в SRNS F5:

SbsL1SD 20: Wrong (big) dt at 737513.051539 day (436453000.000000), dt =  1.999999/ 1.000005
SbsL1SD 20: Wrong (big) dt at 737513.064016 day (437533000.000000), dt =  1.999999/ 1.000005
SbsL1SD 20: Wrong (big) dt at 737513.064039 day (437534000.000000), dt =  1.999999/ 1.000005
SbsL1SD 20: Wrong (big) dt at 737513.222882 day (451261000.000000), dt =  1.999999/ 1.000005
SbsL1SD 20: Wrong (big) dt at 737513.222905 day (451262000.000000), dt =  1.999999/ 1.000005
SbsL1SD 20: Wrong (big) dt at 737513.227662 day (451682000.000000), dt =  8.000007/ 1.000005

Время возникновения проблем в BINR F5 (обрабатывался уже через рабочий день, т.е. выборка длиннее):

SbsL1SD  5: Wrong (big) dt at 737513.227801 day (451682000.000000), dt =  1.999999/ 1.000005
SbsL1SD 20: Wrong (big) dt at 737513.227801 day (451682000.000000), dt =  1.999999/ 1.000005
SbsL1SD 20: Wrong (big) dt at 737513.553657 day (479841000.000000), dt =  3.999998/ 1.000005
SbsL1SD 20: Wrong (big) dt at 737513.553738 day (479849000.000000), dt =  3.999998/ 1.000005
SbsL1SD 20: Wrong (big) dt at 737513.553819 day (479857000.000000), dt =  3.999998/ 1.000005
SbsL1SD 20: Wrong (big) dt at 737513.553912 day (479866000.000000), dt =  3.999998/ 1.000005
SbsL1SD 20: Wrong (big) dt at           NaN day (479874000.000000), dt =  3.999998/ 1.000005
SbsL1SD 20: Wrong (big) dt at 737513.554051 day (479882000.000000), dt =  3.999998/ 1.000005
SbsL1SD 20: Wrong (big) dt at 737513.554225 day (479911000.000000), dt =  3.999998/ 1.000005
SbsL1SD 20: Wrong (big) dt at 737513.554699 day (480085000.000000), dt =  1.999999/ 1.000005

Проблемы совпадают только в момент жесткого лага, когда в SRNS пропущены 8 секунд.

Пропуск 8 секунд

Сообщения об отправке F5 при пропуске 8 секунд выглядели при этом так:

|N1->55817.263756 DebugR: 1313134.000000        1000.000000     52.000000
|N1->55818.263793 DebugR: 1313134.000000        1000.000000     52.000000
|N1->55819.263959 DebugR: 1313134.000000        1000.000000     53.000000
|N1->55827.263756 DebugR: 1313134.000000        1000.000000     52.000000
|N1->55828.263959 DebugR: 1313134.000000        1000.000000     52.000000

Между сообщениями о выделении эфемерид до инцидента и после - 30 секунд, так что дело не в currCPUTime. Складывается ощущение, что часть пакетов просто ушла в /dev/null


Переставленные местами пакеты

Опять все выглядит так, будто проблема на уровне Protocol-Pipe-Сеть-Pipe-Protocol.


Дальности и т.п.

Другая проблема - GPS L1C/A. Опять выглядит так, как будто действует имитационная помеха. Либо это внутрисистемные помехи почему-то начали так сильно влиять на нас.


2019.04.01 - Тест MCR1 за выходные

  • номер ревизии PL: из bin соответствующей ревизии
  • номер ревизии PS: 346f03e3a3a85cbfc17eee665bfcc2bf48bf5258
  • экземпляр приемника: MCR1 плата 61;
  • условия: антенна на крыше Е;


Приемник проработал выходные, не упал, в целом всё ок. Оператива держится на уровне 71Мб, как при старте. Оба ядра загружены примерно на 75%.

Код децимации 100 мс main всё ещё сбоит

20190401 MCR1 depF5.png

В GPS опять ложняки по L1CA.

С временем F5 особых проблем нет, только пару раз выпадали на 5 секунд измерения с отдельного спутника (по флагу м.б.).


2019.04.02 - Новая шина HPP для зеркалирования каналов

  • номер ревизии PL: из bin соответствующей ревизии
  • номер ревизии PS: c938d6a9aab0addd1d2974ec135f1749bc22b72d
  • экземпляр приемника: CLONICUS плата 112;
  • условия: антенна на крыше Е;

Иван запилил DMA

Чтение 120 каналов на старой шине GPP:

20190402 GPP 120.png

Полная замена GPP на HPP заставляет нас два раза запускать DMA

20190402 HPPx2 120.png

Если совмещать GPP с HPP: DMA в основном, GPP для повторного чтения времени.

20190402 HPPx1 120.png

Раза в 3 выиграли по времени, но главное - прирост с увеличением числа каналов стал намного меньше. Думаю, порядка 20 мкс на 100 каналов

Немного изучил свойства clock_gettime(). На вызов функции уходит примерно 600 нс, дискрет значения - 18 мкс в случае Oryx на родном Debian.

Собрали прошивку под Oryx, на загрузке в 60 каналов по небу виден выигрыш первого маркера в 2 раза:

20190403 GHPP Oryx 60ch.png

UPDATE: Время DMA на Клоникусе около 7 мкс на 40 каналов.

2019.04.05 - Ночной тест MCR1 с HPP и 70 каналами

  • номер ревизии PL: собирался Иваном на ~100 каналов, md5sum 0ab4c9f04bdee4adf3301b5cb8e06b25
  • номер ревизии PS: bb44a4c07d31896915b97947018bab17f6d229c2
  • экземпляр приемника: MCR1 плата 61;
  • условия: антенна на крыше Е;

Убрал дополнительное зеркалирование OCM в RAM, в итоге T1 упал до 30 мкс. В таком режиме число каналов поднял до 70. Приемник проработал ночь, всё ок.


Вывод: теперь мы тащим 70 каналов чуть лучше, чем раньше тащили 60.

Утечки памяти при этом нет, съедает около 71 Мб. Ядро с main загружено на 100%, в основном время исполнения там.


2019.04.08 - Как мы пережили ролловер GPS

  • номер ревизии PL: собирался Иваном на ~100 каналов, md5sum 0ab4c9f04bdee4adf3301b5cb8e06b25
  • номер ревизии PS: a4aea27ba6dc0ade3fe02227c8d955ab240d77b1
  • экземпляр приемника: MCR1 плата 61;
  • условия: антенна на крыше Е;

Приемник проработал выходные, всё ок. С 6 на 7 апреля случился ролловер GPS! Есть ощущение, что СДКМ его не пережил, слежение упало и больше мы данных не увидели:

|N1->115638.645883  169 0R SbsL1SD №  2  FrameSyncChunk: SBAS string  4 parity: OK
|N1->115639.646381  169 0R SbsL1SD №  2  FrameSyncChunk: SBAS string  5 parity: OK
|N1->115640.646621  169 0R SbsL1SD №  2  FrameSyncChunk: SBAS string 25 parity: OK
|N1->115641.646049  169 0R SbsL1SD №  2  FrameSyncChunk: SBAS string 14 parity: FAIL
|N1->115642.646381  169 0R SbsL1SD №  2  FrameSyncChunk: SBAS string 24 parity: FAIL
|N1->115643.311966  169 0R SbsL1SD №  2  CoherentLoss: f:     60 Hz  q: 27 dBHz
|N1->115643.321293  169 0R SbsL1SD №  2  NonCoherentStart: 1554479572.900374 s,     51 Hz, 27 dBHz
|N1->115646.391206  169 0R SbsL1SD №  2  CoherentStart: f:    261 Hz  q: 31 dBHz
|N1->115646.644446  169 0R SbsL1SD №  2  FrameSyncChunk: SBAS string  2 parity: FAIL
|N1->115648.391317  169 0R SbsL1SD №  2  SymSyncErr: rep =  0, sync =  1 <-  1 <-  1, errcntr = 4
|N1->115648.591951  169 0R SbsL1SD №  2  FrameSyncErr: pream position = 0 symbs
|N1->115648.659320  169 0R SbsL1SD №  2  FrameSyncErr: pream position = 1 symbs
|N1->115649.399298  169 0R SbsL1SD №  2  SymSyncErr: rep =  0, sync =  1 <-  1 <-  1, errcntr = 6
|N1->115649.652353  169 0R SbsL1SD №  2  FrameSyncErr: pream position = 0 symbs
|N1->115652.390303  169 0R SbsL1SD №  2  SymSyncErr: rep =  0, sync =  1 <-  0 <-  0, errcntr = 6
|N1->115652.600559  169 0R SbsL1SD №  2  FrameSyncErr: pream position = 0 symbs
|N1->115653.390506  169 0R SbsL1SD №  2  SymSyncErr: rep =  0, sync =  1 <-  1 <-  1, errcntr = 8
|N1->115653.650012  169 0R SbsL1SD №  2  FrameSyncErr: pream position = 1 symbs
|N1->115656.600835  169 0R SbsL1SD №  2  FrameSyncErr: pream position = 0 symbs
|N1->115657.390321  169 0R SbsL1SD №  2  SymSyncErr: rep =  0, sync =  1 <-  0 <-  0, errcntr = 7
|N1->115657.649994  169 0R SbsL1SD №  2  FrameSyncErr: pream position = 0 symbs
|N1->115658.670490  169 0R SbsL1SD №  2  CoherentLoss: f:    278 Hz  q: 25 dBHz
|N1->115658.680296  169 0R SbsL1SD №  2  NonCoherentStart: 1554479572.900373 s,    296 Hz, 25 dBHz
|N1->115665.840638  169 0R SbsL1SD №  2  NonKoherentLoss: f:   4237 Hz  q:  9 dBHz
|N1->115665.840656  169 0R SbsL1SD №  2  SignalStop: too low SNR
|N1->115665.850351  169 0R SbsL1SD №  2  SignalStop: a reason is not specified
|N1->115684.608097  169 0R SbsL1SD №  2  TrgRangeDopp from    facq: +0.88924617 s +- 129.3 m at    -0 Hz +- 63.4 m/s, snr: 39 dBHz
|N1->115685.167513  169 0R SbsL1SD №  2  TargetInit: tau =  889.2462 ms, f =      -0 Hz, sigma range = 1.292878e+02 m, sigma vel = 6.343122e+01 m/s, T= 1.0 ms, NN=40
|N1->115685.167513  169 0R SbsL1SD №  2  StartTracking: freq:     -0 Hz, snr: 30 dBHz corr  67
|N1->115685.168269  169 0R SbsL1SD №  2  SgnTimeCorrReq: dEpoch=0 dSec=529251 dWeek=1213, not final from aiming
|N1->115685.168804  169 0R SbsL1SD №  2  SgnTimeCorrDone: tchan=4391 dEpoch=0->0 dSec=0->529251 dWeek=0->1213
|N1->115685.168859  169 0R SbsL1SD №  2  SgnTimeCorrReq: dEpoch=0 dSec=5 dWeek=0, not final from aiming
|N1->115685.170039  169 0R SbsL1SD №  2  SgnTimeCorrDone: tchan=529251001 dEpoch=0->0 dSec=529251->529256 dWeek=1213->1213
|N1->115686.340426  169 0R SbsL1SD №  2  NonCoherentStart: 0.889249 s,      1 Hz, 36 dBHz
|N1->115691.460345  169 0R SbsL1SD №  2  CoherentStart: f:    104 Hz  q: 31 dBHz
|N1->115692.970400  169 0R SbsL1SD №  2  SymSyncDone
|N1->115694.650215  169 0R SbsL1SD №  2  FrameSyncErr: pream position = 1 symbs
|N1->115694.970197  169 0R SbsL1SD №  2  SymSyncErr: rep =  0, sync =  1 <-  1 <-  1, errcntr = 4
|N1->115695.970400  169 0R SbsL1SD №  2  SymSyncErr: rep =  0, sync =  1 <-  1 <-  1, errcntr = 6
|N1->115696.080219  169 0R SbsL1SD №  2  CoherentLoss: f:     98 Hz  q: 23 dBHz
|N1->115696.090412  169 0R SbsL1SD №  2  NonCoherentStart: 0.889249 s,     97 Hz, 23 dBHz
|N1->115701.200599  169 0R SbsL1SD №  2  CoherentStart: f:    179 Hz  q: 31 dBHz
|N1->115701.592080  169 0R SbsL1SD №  2  Debug: 23123213.000000         0.000000        4.000000        0.000000        0.000000
|N1->115701.592485  169 0R SbsL1SD №  2  Debug: 23123213.000000         0.000000        4.000000        0.000000        0.000000
|N1->115703.210608  169 0R SbsL1SD №  2  SymSyncErr: rep =  0, sync =  1 <-  0 <-  0, errcntr = 7
|N1->115703.250292  169 0R SbsL1SD №  2  CoherentLoss: f:    207 Hz  q: 26 dBHz
|N1->115703.260504  169 0R SbsL1SD №  2  NonCoherentStart: 0.889248 s,    218 Hz, 26 dBHz
|N1->115706.330730  169 0R SbsL1SD №  2  CoherentStart: f:    216 Hz  q: 30 dBHz
|N1->115706.591711  169 0R SbsL1SD №  2  Debug: 23123213.000000         0.000000        4.000000        0.000000        0.000000
|N1->115707.332776  169 0R SbsL1SD №  2  SymSyncErr: rep =  0, sync =  1 <-  1 <-  1, errcntr = 9
|N1->115709.650215  169 0R SbsL1SD №  2  FrameSyncErr: pream position = 0 symbs
|N1->115710.340481  169 0R SbsL1SD №  2  SymSyncErr: rep =  0, sync =  1 <-  0 <-  0, errcntr = 9
|N1->115710.410597  169 0R SbsL1SD №  2  CoherentLoss: f:    190 Hz  q: 25 dBHz
|N1->115710.420403  169 0R SbsL1SD №  2  NonCoherentStart: 0.889247 s,    191 Hz, 25 dBHz
|N1->115725.772789  169 0R SbsL1SD №  2  NonKoherentLoss: f:  -3227 Hz  q: -inf dBHz
|N1->115725.772789  169 0R SbsL1SD №  2  SignalStop: too low SNR
|N1->115725.783129  169 0R SbsL1SD №  2  SignalStop: a reason is not specified
|N1->115727.072551  169 0R SbsL1SD №  2  TrgRangeDopp from    facq: +0.35804310 s +- 129.3 m at    -0 Hz +- 63.4 m/s, snr: 44 dBHz


RTKLIB живее всех живых, проверил и RTKPOST, и CONVBIN:


2019.04.08 Perf и Flamegraph

Профилирование модели с помощью perf. На русском почитать можно тут.

Запись лога:

perf record -g -F 99 -- ./sim

Преобразование в формат flame graph'а:

perf script | ./stackcollapse-perf.pl > out.perf-folded

Построение flame-диаграммы:

./flamegraph.pl out.perf-folded > perf-kernel.svg

Открываем svg в браузере и наслаждаемся:

chromium-browser ./perf-kernel.svg

Видим, что в модели всё время уходит на формирование коррелированных шумов квадратур, надо убрать там QS Matrix:

20190408 flame.png

В обработчике прерываний одеяло на себя перетягивают updMeas и updTracking, причем куча времени уходит на isTracking:

20190408 flame2.png


2019.04.10 - Первый ночной тест Клоникуса

  • номер ревизии PL: 948f878ff5cba24bf1948d6b52569d8471e25b94 собирался мной на 40 каналов
  • номер ревизии PS: f35f6003b512ec084eca3691b811a62dff111f3e (с небольшими изменениями)
  • экземпляр приемника: CLONICUS плата 112;
  • условия: антенна на крыше Е;

В F5 пропущена одна точка, примерно в середине лога. Причем пакет дошел, но в текстовый файл записался с ошибками - время 0, номер недели -5000, в первых трех сигналах мусор. Т.е. начало пакета поломано.

Если смотреть глазами ход 0x003, то время пакетов заметно подлагивает. Если запустить WireShark (ip.addr == 192.168.0.112 && tcp.port == 3490 && ip.len > 166 && data.data[6] == 0xF5), то тоже видны проблемы:

20190410 CLO2 HPP WS F5diff.png


2019.04.12 - Проверка работы Dll

  • номер ревизии PL: oryx.bit версия 5.5 (проект bin, коммит 2887efc0)
  • номер ревизии PS: trcv скомпилен из коммита 22be8d57 ветки multiInputCorr (где пилится многовходовый коррелятор)
  • экземпляр приемника: Oryx IP 60, наш MCR;
  • условия: работа по имитатору SMBV;

Сценарий SMBV - Static, один спутник ГЛОНАСС №5, дальность руками забита на 19 000 км. Level = -110 дБм.

Исследуется появление переходного процесса в измерениях псевдодальности при "втягивании" Dll. Исследование проведено как на железке, так и на модели в той же версии PS. В модели выключены "возмущения" шкалы времени.

Чтобы не крутить несколько ручек, пока расстройку E-L не трогаем, трогаем только полосу. Настройки режима "втягивания" Dll следующие:

sgnrcvgln.cpp :

    dll->setTpullin(240.0);
    dll->setDftPullin(1.0);
    dll->setDftEnd(0.025);

    switch (getType()) {
    case GlnL1OF:
        msg = new SgnMsgLxOF(msg0x3);
        frame = new FrameSyncGlnLxOF(Isym, Qsym, ksym, 200, 3, msg0x3);
        df_Lit = 0.5625e6;
        f0_0 = 1602.0e6;
        setTep(1);
        setOverlay(0, 0);
        setND(10);
        setChipRate(0.511e6);
        dll->setTauZero(LightC / ChipRate);
        dll->setDeltaTPullin(0.5*dll->getTauZero());
        dll->setDeltaTCohEnd(0.5*dll->getTauZero());
        dll->setDeltaTNonCohEnd(0.5*dll->getTauZero());
        NC_locking = 5;
        setLit(GlnsLits[ns]);
        break;

dll.cpp :

dll::update(....)

    if (!pulled) {
        if (t < Tpullin/2){
            dft = getDftPullin() - 2*(getDftPullin() - getDftEnd()) * t / Tpullin;
        }
    } else if (getDftMode() != bw_hold) {
        // Выбор полосы по таблице в зависимости от с/ш
    }


Состояние Dll "принтфится" в SgnRcv::updMeas2() :

printf("%f %f %f %f %f %f %f %f %.15f\n", dll->gett(), dll->getDft(), getDeltaT(), 10*log10(q), dll->getSdt(), dll->getUdt(), dll->getKt()[0], dll->getKt()[1], fix_range);


Поддержка Dll от Pll выключена в функциях nonCoherent() и coherent().

Итого имеем время втягивания 240 с., но конечная полоса устанавливается в 2 раза быстрее и далее ждет. На 240 секунде поднимается флажок pullin и Dll переходит на работу по T = 5 мс.

Полученные графики с Oryx:


Что смущает - переходной процесс в дальности / дискриминаторе, который начинается на 120 секунде. Т.е. в этот момент полоса перестает изменяться, но флажок pulled еще не поднят, т.к. время втягивания 240 сек. Дальше видно, что после 240 сек. флажок pulled поднимается, и Dll переходит на работу с T = 5 мс, что видно по возросшим коэффициентам фильтра.



[ Хронологический вид ]Комментарии

(нет элементов)

Войдите, чтобы комментировать.

Персональные инструменты
Пространства имён

Варианты
Действия
SRNS Wiki
Рабочие журналы
Приватный файлсервер
QNAP Сервер
Инструменты