Niepokojące różnice czasowe między Atmegą a Raspberry Pi po synchronizacji NTP

Wed Nov 12, 2014 2:06 pm   

Zauważyłem jeszcze jedną ciekawą rzecz. Jeśli przeprowadzę dłuższą serię
ręcznych synchronizacji czasu, to różnica się niweluje i wynosi 0-1 sek.
Ta jedna sekunda może już po prostu wynikać z różnicy w czasie, jaki
jest potrzebny do wykonania skryptu.

Teraz wyłączyłem automatyczną synchronizację i zobaczę jak się będzie
zachowywał czas.

Procedura wysyłająca request wygląda następujaco:

void client_ntp_request(uint8_t *buf,uint8_t *ntpip,uint8_t
srcport,uint8_t *dstmac)
{
uint8_t i=0;
uint16_t ck;
if (!enc28j60linkup())return;
//
while(i<6){
buf[ETH_DST_MAC +i]=dstmac[i]; // gw mac in local lan or
host mac
buf[ETH_SRC_MAC +i]=macaddr[i];
i++;
}
buf[ETH_TYPE_H_P] = ETHTYPE_IP_H_V;
buf[ETH_TYPE_L_P] = ETHTYPE_IP_L_V;
fill_buf_p(&buf[IP_P],9,iphdr);
buf[IP_ID_L_P]=ipid; ipid++;
buf[IP_TOTLEN_L_P]=0x4c;
buf[IP_PROTO_P]=IP_PROTO_UDP_V;
i=0;
while(i<4){
buf[IP_DST_P+i]=ntpip[i];
buf[IP_SRC_P+i]=ipaddr[i];
i++;
}
fill_ip_hdr_checksum(buf);
buf[UDP_DST_PORT_H_P]=0;
buf[UDP_DST_PORT_L_P]=0x7b; // ntp=123
buf[UDP_SRC_PORT_H_P]=10;
buf[UDP_SRC_PORT_L_P]=srcport; // lower 8 bit of src port
buf[UDP_LEN_H_P]=0;
buf[UDP_LEN_L_P]=56; // fixed len
// zero the checksum
buf[UDP_CHECKSUM_H_P]=0;
buf[UDP_CHECKSUM_L_P]=0;
// copy the data:
i=0;
// most fields are zero, here we zero everything and fill later
while(i<4{
buf[UDP_DATA_P+i]=0;
i++;
}
fill_buf_p(&buf[UDP_DATA_P],10,ntpreqhdr);
//
ck=checksum(&buf[IP_SRC_P], 16 + 48,1);
buf[UDP_CHECKSUM_H_P]=ck>>8;
buf[UDP_CHECKSUM_L_P]=ck& 0xff;
enc28j60PacketSend(90,buf);
}

Wed Nov 12, 2014 2:19 pm   

Hmm... Sprawa jeszcze dziwniejsza - pomimo wyłączonej synchronizacji
różnica czasu zdaje się narastać w tempie dużo szybszym, niż mogłoby to
wynikać z zastosowanego wzorca - sekunda na kilka minut...

Jednak po pojedynczej synchronizacji praktycznie nigdy nie mam różnicy
wynoszącej 0-1 sek. Muszę wykonać długi ciąg ręcznych synchronizacji,
żeby sytuacja tak wyglądała.

Wed Nov 12, 2014 3:02 pm   

On Wed, 12 Nov 2014 14:19:26 +0100, Atlantis <marekw1986NOSPAM@wp.pl>
wrote:

Bez synch. późni się czy spieszy? Pisałeś, że ten *time liczysz w
przerwaniu timera 1ms, który odlicza czas lokalny, uwzględniłeś czas
tych obliczeń *time (maltretujesz 8bit mcu obliczeniami na int32,
timer powinien być aktywny podczas ich trwania)?

--
Marek

Wed Nov 12, 2014 3:45 pm   

W dniu 2014-11-12 15:02, Marek pisze:


Spóźnia się. Z każdą chwilą coraz bardziej.



W tej chwili używam przerwania 10ms.
Hmm... Uważasz, że operacje na zmiennych mogą zajmować więcej czasu,
przez co różnica odkłada się z każdą sekundą?
Czy to (wraz z czasem potrzebnym na obliczenie nowego czasu z pakietu
NTP) tłumaczyłoby także początkowe, kilkusekundowe opóźnienie,
pojawiające się zwykle po synchronizacji?

Funkcja obsługująca przerwanie wygląda następująco:

ISR(TIMER0_COMPA_vect) {
ten_millis++;

if (ten_millis > 100) {
geiger_pulses[seconds] = TCNT1;
TCNT1 = 0;
seconds = (seconds + 1) % 60;

one_second_tick = 1;

uptime++;
if (rtc) rtc++;
if (ntp_update_timer) ntp_update_timer--;
if (bmp085_update_timer) bmp085_update_timer--;
if (dht_update_timer) dht_update_timer--;
if (graphite_upload_timer) graphite_upload_timer--;

ten_millis = 0;
}
}

Pierwszy blok poleceń w instrukcji warunkowej to obsługa licznika
Geigera (właściwe główny czujnik zamontowany w tym urządzeniu) - co
sekundę ilość impulsów zliczonych przez licznik sprzętowy jest
zapisywana do tablicy, sam licznik jest czyszczony i liczony jest numer
kolejnego pola do zapisania.

Zmienna "one_second_tick" to uint8_t - jej jedyną funkcją jest
przekazywanie do pętli głównej informacji o przekręceniu się licznika
sekund.

Zmiennymi 32bitowymi są jedynie uptime i rtc.
Zmienne bmp085_update_timer i dht_update_timer mają rozmiar ośmiu bitów
- odliczają czas pomiędzy kolejnymi odczytami czujników BMP085 oraz DHT11.
Podobne jest przeznaczenie szesnastobitowych zmiennych ntp_update_timer
oraz graphite_upload_timer, które odliczają czas do kolejnego wysłania
requesta do serwera NTP oraz uploadu wyników pomiarów do Graphite'a.

Jeśli to tu leży przyczyna, to w jaki sposób powinienem wprowadzić
poprawkę? Jak ustalić czas potrzebny do wykonania tych operacji?

Wed Nov 12, 2014 5:21 pm   

On 12.11.2014 15:45, Atlantis wrote:


Prawdę powie Ci kod w assemblerze, zajrzyj tam i policz ile to
instrukcji wymaga. Takie liczenie bywa upierdliwe, szczególnie gdy
fragment kodu zawiera jakieś pętle i odwołania do funkcji, ale wynik
bywa zaskakujący i dobrze uświadamia gdzie spędzamy za dużo czasu.


Jak wyżej plus warto sobie przypomnieć prehistorię czyli dobieranie
wartości wpisywanych do 16 bitowych liczników na 51', żeby się ładnie
"zerowały":
http://edsim51.com/8051Notes/8051/timers.html

--
Pozdrawiam
Jakub Rakus

Wed Nov 12, 2014 5:43 pm   

W dniu 2014-11-12 17:21, Jakub Rakus pisze:


Hmm... To ja głupio zapytam - w jaki sposób dostać się do tego kodu?
Istnieje jakiś sposób na ustalenie która część kodu odpowiada danemu
fragmentowi w C? Bo niestety nie znam asemblera AVR-ów, a z jako takim
miałem do czynienia przed laty, robiąc proste "wprawki" pod x86...

Generalnie istnieje jeszcze jakaś inna możliwa przyczyna takiego
zachowania programu? Najbardziej dziwi mnie to, że opóźnienie wynosi
kilka sekund tuż po ostatniej synchronizacji, a sprowadzenie go do 0-1s
wymaga wielokrotnych, wymuszanych synchronizacji, jedna po drugiej.

Generalnie układ nie był projektowany z myślą o liczeniu czasu. Gdybym
wiedział o tym na początku, zastosowałbym inny mikrokontroler, dający
możliwość podłączenia zewnętrznego kwarcu zegarkowego i generowania
przerwań z częstotliwością dokładnie 1Hz. To już trochę ułatwiłoby
sprawę, gdyż nie musiałbym zliczać milisekund w przerwaniu.

Wed Nov 12, 2014 7:50 pm   

On 12.11.2014 17:43, Atlantis wrote:


Nie wiem jakiego tam kompilatora używasz, ale jeśli GCC to wystarczy
dodać flagę -S i masz kod asemblera w pliku z rozszerzeniem .s


Jak potrzebujesz bardziej zaawansowanych opcji (np. przeplatanie kodu
C/ASM):
http://www.delorie.com/djgpp/v2faq/faq8_20.html


Nie wiem co tam się dzieje w pozostałej części programu, być może masz
tam kilka przerwań, które przerywają się nawzajem zbyt często.
Generalnie wiele przerwań a atmegach to śliska sprawa, trzeba dobrze
rozplanować ich wykonywanie, bo te procki nie mają jako takich "jawnych"
priorytetów przerwań. Może dobrze by było odebrane dane z pakietu
wyrzucać na jakiś uart, niestety dla atmegi to jest chyba najszybszy
sposób na debugowanie.

--
Pozdrawiam
Jakub Rakus

Wed Nov 12, 2014 7:53 pm   

On Wed, 12 Nov 2014 15:45:05 +0100, Atlantis <marekw1986NOSPAM@wp.pl>
wrote:

Kod wygląda ok, myślałem, że w przerwaniu robisz te obliczenia. Nie
znam się na avr ale domyślam się z kodu, że przerwanie generowane
jest przez komparator tmera, przy czym timer biegnie dalej w trakcie
obsługi przerwania, tak? Ja bym na razie w funkcji main () obserwował
tylko wartość uptime (np. wyświetlając ja przez uart przy każdej jej
zmianie, taki stoper) . Chodzi o to by się upewnić czy lokalne
odliczanie sekund jest ok. Na pickach bez kwarcu odliczanie sekund
(uptime) taką metodą jak Ty zastosowałeś (przerw. co 10ms) na dobę
rozjezdżało mi się max kilka - kilkanaście sekund względem dobrego
zegarka.

--
Marek

Wed Nov 12, 2014 8:00 pm   

Hmm... Nie wydaje mi się, żeby tu chodziło tylko o zajmowanie cykli
procesora przez operacje na zmiennych 32bitowych w przerwaniu.
Trochę przerobiłem program:

1) Zwiększyłem czas pomiędzy kolejnymi przerwaniami do 20 ms.
2) Przeniosłem obsługę niekrytycznych timerów do pętli głównej. Nic
złego się nie stanie, jeśli od czasu do czasu odczyt jakiegoś czujnika
opóźni się o sekundę albo uptime będzie pokazywał wartość zafałszowaną o
kilka sekund.

W tej chwili procedura obsługi przerwania wygląda następująco:

ISR(TIMER0_COMPA_vect) {
twenty_millis++;

if (twenty_millis > 50) {
geiger_pulses[seconds] = TCNT1;
TCNT1 = 0;
seconds = (seconds + 1) % 60;

one_second_tick = 1;

if (rtc) rtc++;

twenty_millis = 0;
}
}

Normalnie jest to tylko inkrementacja jednej zmiennej ośmiobitowej. Raz
na sekundę dochodzi do tego jeszcze kilka operacji na zmiennych
szesnastobitowych oraz inkrementacja zegara (zmienna 32bit), jeśli czas
został już pobrany. Trochę trudno mi uwierzyć, że zajmuje to więcej niż
20ms...

Poza tym jest jeszcze jedna dziwna sprawa - parę razy tuż po wymuszonej
synchronizacji czasu zauważyłem opóźnienie wynoszące np. 3 albo i 10
sekund. Przecież niemożliwe, żeby taka wartość nabiła się w kilka sekund!

Wed Nov 12, 2014 8:07 pm   

On Wed, 12 Nov 2014 17:43:38 +0100, Atlantis <marekw1986NOSPAM@wp.pl>
wrote:


Ale poczekaj, sprawdż najpierw czy lokalnie czas (bez ntp) w miarę
precyzyjnie odliczasz (max rozjazd kilkanascie sek. na dobę).
Twoje przerwanie wygląda ok, nie powinno wprowadzać błędu o ile nie
ma innych przerwań blokujące to od timera. No i oczywiście timer musi
biegać podczas obsługi przerwania, aby czas jego obsługi nie dodawał
się do biegu timera. Przerwanie jest krótkie, a 10ms interwał
spokojnie powinien dać czas na jego obsługę. Atmega odkłada flagę
przerwania gdy ono nastąpi po cli() aby je wywoływać zaraz po sei()?
Jeśli czas lokalny będzie liczony ok to wtedy weryfikuj kod
synchronizujący czas ntp.

--
Marek

Wed Nov 12, 2014 8:48 pm   

W dniu 2014-11-12 20:07, Marek pisze:


To już wiem. Domyślnie synchronizacje zegara są wykonywane co godzinę. W
tej chwili mam 26 sekund opóźnienia po 18 minutach od uruchomienia układu...



W tym programie nie występują żadne inne przerwania. Drugi,
szesnastobitowy timer pracuje w trybie licznika, nie wywołując żadnych
przerwań.



W tej chwili dałem 20ms i wyrzuciłem mniej krytyczne instrukcje do pętli
głównej. Problem ciągle występuje.



Tego nie jestem pewien, ale z ciekawości zrezygnowałem ze stosowania
cli() i sei() przy odczycie/zapisie zmiennej rtc. Chciałem zobaczyć czy
dryf będzie nadal występował. Występuje...



Nie jest liczony ok, jednak tej synchronizacji też nie jestem pewien.
Kilka razy zauważyłem, że skrypt pokazywał nawet kilkanaście sekund
opóźnienia (albo i więcej) tuż po starcie urządzenia albo wymuszonej
synchronizacji.

Wed Nov 12, 2014 9:26 pm   

On Wed, 12 Nov 2014 20:48:31 +0100, Atlantis <marekw1986NOSPAM@wp.pl>
wrote:


To za dużo. Takie rozbieżności wskazują na źle dobrane wartości do
wygenerowania przerwania timera (pre/post scaler itp) albo timer
jest wstrzymywany gdy przerwanie jest obsługiwane.

--
Marek

Wed Nov 12, 2014 9:29 pm   

Dnia Wed, 12 Nov 2014 12:43:21 +0100, Atlantis napisał(a):

Czekaj, zaczynam rozumiec.
Atmel wysyla pakiet NTP, przychodzi odpowiedz, atmega ustawia swoj
zegar na podstawie tego co przyszlo.
Potem sobie powieksza wlasny zegar w przerwaniach, a gdzies obok RasPi
odczytuje zegar z atmegi, odczytuje z ntp, porownuje i wychodzi mu
roznica znaczna ?
Mimo ze niedawno atmega ustawila czas w/g pakietu NTP?

Ja bym zrezygnowal z tego RasPi, wyrzucal wszystko tekstowo, i
porownywal naocznie.

Ale co mi sie nasuwa:
-czy oba korzystsja z tego samego serwera - ale mysle ze nawet jak z
innych to czas powinien byc zgodny,
-o ile kojarze, to NTP jest bardziej skomplikowany, wysyla sie w dwie
strony pakiety - moze cos nie/zle ustawiles ?
-czy przerwania tam dobrze wspoldzialaja ? Bo jak rozumiem -
przychodzi pakiet, w przerwaniu ustawiasz timer, w przerwaniu go
powiekszasz - to sie moze cos zle dziac. Ale rzadko.

-jaki masz czas odpowiedzi ? Moze cos tam sie w sieci blokuje i
pakiety gdzies czekaja

-typowo na unixach NTP nie przestawia zegara, tylko go zwalnia lub
przyspiesza i zmiana jest rozciagnieta w czasie. Unix nie lubi skokow
czasu. Ale to by dotyczylo RP, bo na ATmega jak rozumiem sam
programujesz.

Ale najbardziej podejrzewam:
-czy dobrze odczytujesz tego ENC i przerwania dobrze przychodza ?
Bo jakby tak pakiet przychodzil, ale atmega nic o tym nie wiedziala,
tylko czekala, a odczytywala pakiet przy calkiem innej okazji, ktora
nadejdzie nie wiadomo kiedy - to by tak moglo byc jak opisujesz.

J.

Wed Nov 12, 2014 9:36 pm   

On Wed, 12 Nov 2014 21:29:38 +0100, "J.F."
<jfox_xnospamx@poczta.onet.pl> wrote:

Przecież mu się czas już źle liczy lokalnie z timera a co dopiero z
ntp.

--
Marek

Wed Nov 12, 2014 10:20 pm   

W dniu 2014-11-12 21:26, Marek pisze:


Hmm... Faktycznie coś jest nie tak z timerem.
Wyłączyłem synchronizację przez NTP i kazałem po starcie programu
inkrementować zmienną rtc od 1 w górę. Po trochę ponad godzinie
nazbierało się 81 sekund opóźnienia...



Jak to sprawdzić?