Nebenwirkungen von fprintf

[Philipp (Gast)]

Hallo,

ich habe einen UM245R mit 8 Datenleitungen an einen ATmega16 
angeschlossen um mit "fprintf" Zwischenergebnisse einer Regelung 
ausgeben lassen zu können. Jetzt hatte ich das Programm soweit, dass die 
Ergebnisse gut waren und wollte die Debug-Ausgaben entfernen.

Konkret habe ich im Code sowas stehen:

mw_estimated_pos += mw_delta_d;
// Jetzt will ich sehen, was gerechnet wurde:
fprintf(stderr, "%li = est_pos + %li\n", mw_estimated_pos, mw_delta_d);

Die Beobachtung zeigt nun, dass der Code nicht mehr funktioniert, wenn 
ich die Zeile mit fprintf entferne. Die Werte, die in mw_estimated_pos 
stehen, springen mit sehr viel Abstand um den Wert, den ich erwarten 
würde.

Ich frage mich nun, welche Nebenwirkungen hier mein Konstrukt platzen 
lassen können. Ich habe versucht, die Zeile duch ein _delay_us(100) zu 
ersetzen da ich dachte, dass das fprintf vielleicht wie eine Verzögerung 
wirkt und ich ein Timingproblem oder so etwas habe.

Hat jemand einen Ratschlag, wie ich das sinnvoll debuggen könnte? Würde 
ich eine Zeile hinzufügen wollen könnte ich mir noch vorstellen dass 
durch irgendeinen Überlauf meine Variable überschrieben wird, aber so 
... ?

Der GCC sagt mir "Program: 41% full, data: 46% full".

Mein stderr benutzt eine Funktion, die ein einzelnes Zeichen an Port B 
ausgibt, eine Leitung an Port D auf high setzt, 50 us wartet und die 
Leitung wieder auf low setzt.

Vielen Dank für's Durchlesen und hoffentlich gute Hinweise :)
Philipp

[Karl H. (kbuchegg)]

Philipp schrieb:

> Ich frage mich nun, welche Nebenwirkungen hier mein Konstrukt platzen
> lassen können. Ich habe versucht, die Zeile duch ein _delay_us(100) zu
> ersetzen da ich dachte, dass das fprintf vielleicht wie eine Verzögerung
> wirkt und ich ein Timingproblem oder so etwas habe.

Das wäre auch mein Gedanke

Nur werden 100µs nicht reichen, um den fprintf zu ersetzen.

> Mein stderr benutzt eine Funktion, die ein einzelnes Zeichen an Port B
> ausgibt, eine Leitung an Port D auf high setzt, 50 us wartet und die
> Leitung wieder auf low setzt.

Und wieviele Zeichen gibst du aus?

"%li = est_pos + %li\n"

da sind schon mal 14 Zeichen Fixtext. Kommen noch mal ~8 Zeichen 
variabler Text durch die Zahlenwerte dazu. Macht 22 Zeichen.
Bei angenommenen 50µs pro Zeichen (das Kleinvieh ignoriere ich mal), 
sind das 1100µs und nicht 100. Dazu noch Overhead für die Formatierung, 
Parameterübernahme und sonstiges.

Ich würde mal mit
  _delay_us( 1500 );
anfangen zu testen.

[Peter (Gast)]

kann es sein das duch die nichtverwendung der Optimier zu viel 
optimiert? Wo werden die Daten von mw_estimated_pos geändert, etwas in 
einer ISR?

oder zeig den completten code.

[U.R. Schmitt (Gast)]

Warum muss es auf dem controller überhaupt printf sein? Das ist doch 
eine Monsterfunktion. Das sind doch long Variablen, da kann man die 
Ausgabe doch mit ltoa() viel schneller zusammenbasteln.

[Philipp (Gast)]

Hallo Karl-Heinz und Peter,

ich habe jetzt folgendes getestet:

(1) fprintf durch ein delay ersetzt --> keine Wirkung
(2) in fprintf die %i durch einen konstanten String ersetzt der eine 
gleich lange Ausgabe erzeugt
(3) in meiner putchar-Funktion das Delay von 50us auf 1us korrigiert, es 
sollten 50ns sein laut Datenblatt und ich habe es falsch abgelesen.

Keine der Änderungen hatte Auswirkungen, es hat also trotz der radikalen 
änderung des Timings funktioniert wenn ich die Zeile drinnenlasse und 
(1) und (2) haben nicht funktioniert, der Wert hat sich also geändert.

Hier sind die meines Erachtens relevanten Auszüge aus dem Code. In der 
Funktion do_calculation() findet sich die rätselhafte Stelle.

In den Interrupts setze ich immer nur Flags, die dann von der 
Hauptroutine verabreitet werden wie man sieht, damit will ich 
"Interrupts in Interrupts" vermeiden wie es in den Tutorials steht.

Kann es auch an meinem grosszügigen (sorry, hab hier kein sz) Umgang mit 
volatile liegen?

volatile struct {
  unsigned update:2; // 0 = measurement wheel, 1 = shaft, 2 = none
  unsigned calculate:1; // call do_calculate()?
} flags2;

volatile int32_t mw_next_predicted_interrupt = 10000;  // relative time
volatile int32_t mw_time_since_last_interrupt = 0;  // relative times

volatile int32_t mw_last_known_pos = 0;    // updated at every interrupt
volatile int32_t mw_estimated_pos = 0;

volatile int32_t mw_e_pos = 0;    // positional offset

volatile int16_t mw_t_k = 300;    // tk for formula "A = t_{k+1} / t_k"

volatile int32_t mw_estimated_v = 0;

// Ein Timer-Interrupt, der alle 1/40ms überläuft

ISR(TIMER0_OVF_vect){
  int8_t sreg_temp = SREG;
  cli();

  TCNT0 = 55;

  time_cnt++;

  if(time_cnt == 40){
    // ... a millisecond passed ...

    flags2.calculate = 1;
    time++;    
    time_cnt = 0;
  }
  
  SREG = sreg_temp;
}

void do_calculation(){

  /* ******** calculations for the measurement wheel * */

  int32_t mw_delta_d = mw_estimated_v - 2 * ( mw_e_pos / (int32_t) mw_next_predicted_interrupt );

  mw_estimated_pos += mw_delta_d;

  fprintf(stderr, "%li = est_pos + %li\n", mw_estimated_pos, mw_delta_d);

  mw_distance_since_last_beep += mw_delta_d;

  /* ************* reset the flag ********************** */

  flags2.calculate = 0;

}

int main( void ) {
  
  init();    
  sei(); // enable interrupts

  while(1){
      if (flags2.calculate == 1) do_calculation();
        }
    return 0;             
}

[Philipp (Gast)]

So, hier noch zwei kleine Bilder auf denen man sieht, dass die blaue 
Linie, die der grünen folgen soll, es auf dem einen Bild gut tut und auf 
dem anderen Bild sehr groß springt, aber "tendenziell mitgeht" oder wie 
man das auch immer formulieren mag.

@ U.R. Schmitt: Darum geht es mir ja. Ich will es loswerden.

[Peter (Gast)]

Philipp schrieb:
> ISR(TIMER0_OVF_vect){
>   int8_t sreg_temp = SREG;
>   cli();

das sicher der Register sollte man den compiler überlassen, sonst kann 
man ja gleich asm programmierne - lass es weg. Auch das abschlaten er 
Interupts bring im Interupt wenig.


Das zurücksetzen des events sollte an der stelle gemacht werden wo es 
auch ausgewertet wird.

if (flags2.calculate == 1) {
   flags2.calculate = 0;
   do_calculation();
}

und ja du bist zu großzüging mit volatile aber das sollte hier nicht 
stören.
Du kannst es hier überall weglassen ( wenn ich jetzt nichts übersehen 
habe)

volatile int32_t mw_next_predicted_interrupt = 10000;  // relative time
volatile int32_t mw_time_since_last_interrupt = 0;  // relative times
volatile int32_t mw_last_known_pos = 0;    // updated at every interrupt
volatile int32_t mw_estimated_pos = 0;
volatile int32_t mw_e_pos = 0;    // positional offset
volatile int16_t mw_t_k = 300;    // tk for formula "A = t_{k+1} / t_k"
volatile int32_t mw_estimated_v = 0;

[U.R. Schmitt (Gast)]

Wie oft wird dein Timerinterrupt durchlaufen?
Einmal sehe ich 1/40 ms und dann wieder 1 millisek.
Der printf braucht alleine 1,5 ms (laut Karl Heinz  Rechnung, die ich 
mal als richig annehme)
Ganz dumme Frage? Kann es sein, daß das System nur deshalb funktioniert 
hat, weil Du die Regelung durch deine Ausgabe extrem verlangsamt hast?
Wenn ich das richtig verstehe setzt Du das Flag flags2.calculate alle 
1/40 millisekunde auf true, aber die Funktion braucht wegen der Ausgabe 
70 -100 mal so lange. Das kann doch nicht gutgehen, oder sehe ich das 
hier völlig falsch?
Sorry aber ich muss jetzt weg, aber bei Karl Heinz und co bist Du sowiso 
100mal besser aufgehoben
Viel Erfolg

[Philipp (Gast)]

Uaaaaargh ....

also, U.R. Schmitt, es sieht so aus als ob ihr Recht habt. Nach Peters 
hilfreichen Hinweisen habe ich den Code etwas verlschlankt und gesehen, 
dass die Ergebnisse schlechter werden. Daraufhin habe ich einfach einen 
wilden Delay zusätzlich eingebaut (wie von Karl-Heinz vorgeschlagen) zur 
printf-Zeile und nach einer kurzen "Einschwingzeit" folgt der Wert 
ziemlich gut der Linie.

Ich muss mich bei euch entschuldigen für die Hühner die ich 
aufgescheucht habe von wegen "Speicherproblem", "Timingproblem" und so 
weiter --> meine Regelung ist nicht ordentlich gebaut.

Ich habe vorher alles in Python implementiert und getestet, aber für den 
uC musste ich relativ viel skalieren um in den Ganzzahlen bleiben zu 
können und da hat sich dann sicherlich irgendwo ein 1000-er-Faktor 
eingeschlichen oder ich hab ihn vergessen oder was auch immer.

Also, ich weiß jetzt wo ich suchen soll, danke euch allen und wünsch 
euch einen schönen Abend!

Grüße
Philipp

[U.R. Schmitt (Gast)]

Generell solltest Du dir überlegen ob Du wirklich eine so schnelle 
Abtastung brauchst. Wenn die Zeitkonstanten deines Systems im Bereich 
von Zehntel Sekunden liegen, dann macht es keinen Sinn so hochfrequent 
abzutasten.

Eventuell integriert auch dein I Anteil einfach so weit auf, daß das 
System dadurch instabil wird. Dann hilft eine Begrenzung des I-Anteils 
und/oder eine langsamere Abtastung.

Viel Erfolg