En todo sistema complejo es importante avanzar en la implementación conceptual, pero también solucionar los problemas prácticos que se van encontrando, la mayoría de ellos que no se han previsto y cuya solución no siempre es trivial.
El sistema implementado recibe bien y cumple su propósito, pero que lo haga en forma continua a modo de estación de monitoreo permanente es otro precio.
Para empezar luego de intentar infructuosamente que la parte de baliza y la de monitoreo funcionaran en la misma placa encontré que era mas conveniente que lo hicieran en dos placas separadas, hay varias buenas razones para hacerlo así, pero la principal es que la placa de monitoreo (recepción) tiene un clock compensado con 2,5 segundos de atraso mientras que la de baliza no lo necesita y esa diferencia le hace perder las ventanas (muy críticas) de WSPR y FT8 principalmente. En una entrada siguiente explicaré como se coordinan las dos placas para cumplir ambos propósitos (con una sola antena). En lo inmediato lo que concierne a ésta entrada es interesante ver la clase de problemas que ésto genera y una posible forma de manejarlos.
He comentado en entradas anteriores que es necesario en sistemas de funcionamiento permanente llevar un registro (log) lo mas detallado posible de todo lo que va pasando. ¿Que tan detallado es detallado?, bueno, nunca lo suficiente cuando se tiene que buscar un problema. Sin embargo debe operar un equilibrio puesto que en definitiva una placa Raspberry Pi no tiene un disco, solo una tarjeta de memoria que funge como tal, y por lo tanto no puede ser ilimitado lo que se almacene. Hay también una consideración de performance, si bien Linux es extremadamente eficiente manejando archivos a medida que los archivos se hacen mas grandes la performance de grabarles información se va paulatinamente deteriorando. No quiero inferir que decidir con detalles que guardar en el log es un "arte", pero ciertamente es bastante subjetivo. El criterio que uso es aplicar lo que se llama el criterio de complejidad ciclomática de McCabe que dice básicamente que la complejidad está determinada por los nodos de bifurcación o decisión que tiene una determinada lógica. Eso da la estructura básica de los puntos de información en el log. Pueden, además, agregarse datos de información adicional tales como tiempos de ejecución de determinados módulos, o los reportes que emite. Con esa información se puede manejar un log del orden de unos pocos MBytes por día, lo que es manejable aún aplicando acciones de mantenimiento que guarden los contenidos diarios por una semana o cosa similar.
En un script BASH la información en el log se agrega con una sentencia del tipo:
echo "Whisper: "`date`" Starting Ver "$VERSION" P("$N") PID("$$") CPU($CPU %)" 2>&1 | tee -a $DPATH$LOG
Lo que parece muy obscuro pero no es mas que grabar el nombre del programa (también se puede usar la variable predefinida $0 pero es un poco mas extensa porque incluye el path de ejecución), se incluye la fecha y hora de la grabación (¡siempre! ¡importantisimo!) donde se puede notar que la instrucción está encerrada en una comilla inversa "`". BASH es eficiente pero hay veces que hay que conceder que es obscuro.... la comilla inversa indica que debe ser reemplazada por la ejecución del comando que ellas encierran. Las uso por costumbre aunque concedo que es mucho mas claro el equivalente de encerrar el comando en el formato $(comando). Luego variables que están definidas durante la ejecución (las que se distinguen por estar antecedidas por "$" tales como VERSION (del script), número de procesos (N) medidos al ejecutar, PID identificador de proceso del script, CPU consumo de CPU medido durante la ejecución y que se va dejando como referencia para identificar si en algún momento hay recursos limitados de procesamiento. La sentencia finaliza con dos redirecciones. La primera "2>&1" es una forma algo compacta de decir "todo lo que salga por standard error redireccionarlo a standard output. La segunda "| tee -a $DPATH$LOG" signfica todo lo que salga por standard output entrará en el programa tee quien lo separará en dos corrientes, una la agregará al archivo de log indicado por $DPATH$LOG (definido por el script) y la otra corriente la mostrará en la salida standard; nada mas que un truco para mostrar un mensaje en consola y al mismo tiempo archivarlo. El script de gestión de la baliza whisper funciona continuamente, mientras que el de supervisión del monitoreo wsmon es invocado periódicamente mediante llamados de crontab.
Entre los datos almacenados en el log incluí información de monitoreo del estado del sistema, en particular %CPU, ocupación de disco, temperatura, voltaje del procesador y estado de restricciones del sistema.
#+-----------------------------------------------------------------------------
#* Get telemetry from all major sub-systems
#*-----------------------------------------------------------------------------
getCPU () {
sar 1 3 | grep "Media:" | while read a ; do
echo $a | awk '{print $3 + $4 + $5 + $6 + $7}';
done
}
getTemp () {
TEMP=$(vcgencmd measure_temp)
echo $TEMP | cut -f2 -d"=" | cut -f1 -d"'"
}
getVolt () {
VOLT=$(vcgencmd measure_volts | cut -f2 -d"=" | cut -f1 -d"V" )
VOLT=$(python -c "print ('%.2f' % ($VOLT*1.0))" )
echo $VOLT
}
getClock () {
CLOCK=$(vcgencmd measure_clock arm | cut -f2 -d"=")
FX=$(python -c "print float($CLOCK)/1000000")
echo $FX
}
getStatus () {
STATUS=$(vcgencmd get_throttled)
echo $STATUS | cut -f2 -d"="
}
getDASD () {
sudo df -k | grep "/dev/root" | awk '{ print $5 ; }' | cut -f1 -d"%"
}
Para empezar luego de intentar infructuosamente que la parte de baliza y la de monitoreo funcionaran en la misma placa encontré que era mas conveniente que lo hicieran en dos placas separadas, hay varias buenas razones para hacerlo así, pero la principal es que la placa de monitoreo (recepción) tiene un clock compensado con 2,5 segundos de atraso mientras que la de baliza no lo necesita y esa diferencia le hace perder las ventanas (muy críticas) de WSPR y FT8 principalmente. En una entrada siguiente explicaré como se coordinan las dos placas para cumplir ambos propósitos (con una sola antena). En lo inmediato lo que concierne a ésta entrada es interesante ver la clase de problemas que ésto genera y una posible forma de manejarlos.
He comentado en entradas anteriores que es necesario en sistemas de funcionamiento permanente llevar un registro (log) lo mas detallado posible de todo lo que va pasando. ¿Que tan detallado es detallado?, bueno, nunca lo suficiente cuando se tiene que buscar un problema. Sin embargo debe operar un equilibrio puesto que en definitiva una placa Raspberry Pi no tiene un disco, solo una tarjeta de memoria que funge como tal, y por lo tanto no puede ser ilimitado lo que se almacene. Hay también una consideración de performance, si bien Linux es extremadamente eficiente manejando archivos a medida que los archivos se hacen mas grandes la performance de grabarles información se va paulatinamente deteriorando. No quiero inferir que decidir con detalles que guardar en el log es un "arte", pero ciertamente es bastante subjetivo. El criterio que uso es aplicar lo que se llama el criterio de complejidad ciclomática de McCabe que dice básicamente que la complejidad está determinada por los nodos de bifurcación o decisión que tiene una determinada lógica. Eso da la estructura básica de los puntos de información en el log. Pueden, además, agregarse datos de información adicional tales como tiempos de ejecución de determinados módulos, o los reportes que emite. Con esa información se puede manejar un log del orden de unos pocos MBytes por día, lo que es manejable aún aplicando acciones de mantenimiento que guarden los contenidos diarios por una semana o cosa similar.
En un script BASH la información en el log se agrega con una sentencia del tipo:
echo "Whisper: "`date`" Starting Ver "$VERSION" P("$N") PID("$$") CPU($CPU %)" 2>&1 | tee -a $DPATH$LOG
Lo que parece muy obscuro pero no es mas que grabar el nombre del programa (también se puede usar la variable predefinida $0 pero es un poco mas extensa porque incluye el path de ejecución), se incluye la fecha y hora de la grabación (¡siempre! ¡importantisimo!) donde se puede notar que la instrucción está encerrada en una comilla inversa "`". BASH es eficiente pero hay veces que hay que conceder que es obscuro.... la comilla inversa indica que debe ser reemplazada por la ejecución del comando que ellas encierran. Las uso por costumbre aunque concedo que es mucho mas claro el equivalente de encerrar el comando en el formato $(comando). Luego variables que están definidas durante la ejecución (las que se distinguen por estar antecedidas por "$" tales como VERSION (del script), número de procesos (N) medidos al ejecutar, PID identificador de proceso del script, CPU consumo de CPU medido durante la ejecución y que se va dejando como referencia para identificar si en algún momento hay recursos limitados de procesamiento. La sentencia finaliza con dos redirecciones. La primera "2>&1" es una forma algo compacta de decir "todo lo que salga por standard error redireccionarlo a standard output. La segunda "| tee -a $DPATH$LOG" signfica todo lo que salga por standard output entrará en el programa tee quien lo separará en dos corrientes, una la agregará al archivo de log indicado por $DPATH$LOG (definido por el script) y la otra corriente la mostrará en la salida standard; nada mas que un truco para mostrar un mensaje en consola y al mismo tiempo archivarlo. El script de gestión de la baliza whisper funciona continuamente, mientras que el de supervisión del monitoreo wsmon es invocado periódicamente mediante llamados de crontab.
Entre los datos almacenados en el log incluí información de monitoreo del estado del sistema, en particular %CPU, ocupación de disco, temperatura, voltaje del procesador y estado de restricciones del sistema.
#+-----------------------------------------------------------------------------
#* Get telemetry from all major sub-systems
#*-----------------------------------------------------------------------------
getCPU () {
sar 1 3 | grep "Media:" | while read a ; do
echo $a | awk '{print $3 + $4 + $5 + $6 + $7}';
done
}
getTemp () {
TEMP=$(vcgencmd measure_temp)
echo $TEMP | cut -f2 -d"=" | cut -f1 -d"'"
}
getVolt () {
VOLT=$(vcgencmd measure_volts | cut -f2 -d"=" | cut -f1 -d"V" )
VOLT=$(python -c "print ('%.2f' % ($VOLT*1.0))" )
echo $VOLT
}
getClock () {
CLOCK=$(vcgencmd measure_clock arm | cut -f2 -d"=")
FX=$(python -c "print float($CLOCK)/1000000")
echo $FX
}
getStatus () {
STATUS=$(vcgencmd get_throttled)
echo $STATUS | cut -f2 -d"="
}
getDASD () {
sudo df -k | grep "/dev/root" | awk '{ print $5 ; }' | cut -f1 -d"%"
}
.....
VOLT=$(getVolt)
TEMP=$(getTemp)
STATE="T($TEMP°C) V($VOLT) Clk($(getClock)MHz) St($(getStatus)) CPU($(getCPU)%) DASD($(getDASD)%)"
echo $STATE | logger -i -t "TLM"
echo "Whisper: "`date`" Telemetry: "$STATE 2>&1 | tee -a $DPATH$LOG
......
Si bien parece que se pone la misma información dos veces en el log en realidad se pone una vez en el log propio del script (un archivo de texto) y otra vez en el system log (un database con toda la información del sistema), eso es solo por conveniencia de poder hacer otras cosas donde trabajar con el system log es mas facil y rápido que hacerlo con un archivo de texto.
La medición de la carga de máquina se hace mediante la invocación del utilitario sar y la manipulación de su salida. Estas lineas son invocadas periódicamente por el script que maneja el beacon o mediante crontab en el caso de la estación monitora (que ejecuta continuamente wsjt-x).
La medición de la carga de máquina se hace mediante la invocación del utilitario sar y la manipulación de su salida. Estas lineas son invocadas periódicamente por el script que maneja el beacon o mediante crontab en el caso de la estación monitora (que ejecuta continuamente wsjt-x).
De esta forma es posible ir revisando si el espacio en disco se vuelve insuficiente, si estamos pidiendo al procesador que haga demasiadas cosas y otros factores.
En particular observé que trabajar continuamente al programa wsjt-x, junto con el procesamiento de señales que es necesario para alimentarlo provocaba un calentamiento excesivo de la placa, era bastante frecuente que dejara de funcionar por exceder los 85°C de temperatura, y en realidad dejaba de funcionar correctamente cuando superaba 80-82°C por mas que siguiera funcionando todo en apariencia.
La primer reacción fue agregar un método de gestión de la temperatura en el nodo emisor:
#*-----------------------------------------------------------------------------
#* manageTemp()
#* Get core temperature and stop the beacon to cool down if exceeded
#*-----------------------------------------------------------------------------
manageTemp() {
#echo "$DAEMON: "`date`" Managing temperature procedure" 2>&1 | tee -a $DPATH$LOG
A=$(vcgencmd measure_temp)
B=$(echo $A | cut -f2 -d"=" | cut -d"'" -f1 | tr -d '\r')
C=$(echo $B | cut -f1 -d".")
D=$(($C * 1))
echo $D
}
.........................
T=$(manageTemp)
if [ $T -ge $MAXTEMP ]
then
echo "Whisper: "`date`" Temp ("$T") exceeds max ($MAX), stopping TX to cool down during $COOLTIME secs" \
2>&1 | tee -a $DPATH$LOG && sleep $COOLTIME
echo "Whisper: "`date`" Temperature is now "$(vcgencmd measure_temp)" TX resumed" 2>&1 | tee -a $DPATH$LOG
fi
La placa de la baliza (emisora) tenía pocos problemas de temperatura, y nunca superó el punto en el cual dejaba de funcionar, pero observé que la diferencia térmica provocaba que el clock de la placa tuviera diferencias y éstas correlacionaban con menor frecuencia de reportes en wsprnet.org; por lo que consideré preferible que si había temperatura elevada directamente no emitiera la baliza; la gestión es bien simple, si la temperatura excede un valor máximo (MAXTEMP) simplemente espera sin emitir la baliza por un tiempo (COOLTIME) que lo tengo especificado en media hora. Al cabo del cual se reporta como estaba la temperatura, fui extendiendo el COOLTIME hasta que efectivamente luego de la "parada" saliera con una buena temperatura y margen para trabajar correctamente bastante tiempo. Pero si por alguna razón eso no pasaba un par de minutos después cuando completara el ciclo de la baliza volvería a quedar detenida.
Y en el nodo receptor (el mas perjudicado) la gestión resultó un poco mas compleja:
#*---------------------------------------------------------------------------
#* Kill all processes related to the monitoring function
#*---------------------------------------------------------------------------
killProcess() {
sudo ps -aux | for p in `pgrep "rtl_sdr"`; do echo "killing "$p; sudo kill -9 $p; done
sudo ps -aux | for p in `pgrep "csdr"`; do echo "killing "$p; sudo kill -9 $p; done
sudo ps -aux | for p in `pgrep "ncat"`; do echo "killing "$p; sudo kill -9 $p; done
sudo ps -aux | for p in `pgrep "mplayer"`; do echo "killing "$p; sudo kill -9 $p; done
sudo ps -aux | for p in `pgrep "jt9"`; do echo "killing "$p; sudo kill -9 $p; done
......
if [ -f $DPATH$THERMALLOCK ]; then
echo "$DAEMON: "`date`" Process is under thermal lock, evaluating" 2>&1 | tee -a $DPATH$LOG
if [ $T -ge $TGTTEMP ];
then
echo "$DAEMON: "`date`" Temp ("$T" °C) exceeds cooling target ("$TGTTEMP" °C) wait" 2>&1 | tee -a $DPATH$LOG
echo "Thermal runaway detected!" | logger -i -t "TLM"
exit 2
else
echo "$DAEMON: "`date`" Temp ("$T" °C) is below target ("$TGTTEMP" °C) remove and reboot" \
2>&1 | tee -a $DPATH$LOG
echo "Thermal management, cooling off detected " | logger -i -t "TLM"
sudo rm -r $DPATH$THERMALLOCK 2>&1 | tee -a $DPATH$LOG
sudo reboot
sleep 10000
exit 0
fi
fi
if [ $T -ge $MAXTEMP ];
then
echo "$DAEMON: "`date`" Temp ("$T" °C) exceeds max ("$MAXTEMP" °C) kill procs and thermal lock" \
2>&1 | tee -a $DPATH$LOG
sudo touch $DPATH$THERMALLOCK 2>&1 | tee -a $DPATH$LOG
killProcess 2>&1 | tee -a $DPATH$LOG
echo "Thermal runaway detected!" | logger -i -t "TLM"
exit 0
else
echo "$DAEMON: "`date`" Temp ("$T" °C) is nominal and below max ("$MAXTEMP" °C)" \
2>&1 | tee -a $DPATH$LOG
fi
En éste caso el script que controla la temperatura no es el mismo que produce el calor (wsjt-x) por lo que lo primero que hay que hacer es detener ese programa (killProcess), pero el script de control está funcionando con una lógica de ser re-entrante y re-usable por lo que luego de bajar a wsjt-x marca la condición de corrida térmica (generando un archivo cuyo nombre y path están dados por $DPATH$THERMALLOCK) y termina. Al cabo de un tiempo crontab lo va a volver a lanzar, donde observará que está en corrida térmica y entonces verificará si la temperatura bajó lo suficiente, caso que no vuelve a salir. Al cabo de varios ciclos, típicamente 10 o 15 minutos, la temperatura bajaba lo suficiente y entonces podía volverse a comenzar el monitoreo.
Inicialmente intenté arrancar desde allí a wsjt-x pero encontré que no siempre el sistema había quedado estable luego de "matar" los procesos o mismo de la corrida térmica, así que lo mas higiénico resultó ser dar "reboot" y dejar que el arranque del monitor asegurara un comienzo "limpio". Puede parecer disruptivo como método, pero usándolo pasó de estar varias horas en condición inestable (varios días una vez que ocurrió mientras viajaba) a unos pocos minutos. Dependiendo del día, la temperatura ambiente y otros factores incluyendo la cantidad de estaciones que se tienen que decodificar en un ciclo, podía hacer 3 o 4 de éstos ciclos por día. Cuando pude identificar claramente ésta situación corté por lo sano, le puse disipadores mas grandes a los chips de la placa y un pequeño ventilador de +5V alimentado por la placa misma. Santo remedio, la placa nunca más superó los 45°C a partir del agregado del ventilador.
No hay comentarios:
Publicar un comentario