[vz-dev] Segmentation Fault - vzlogger - Landis&Gyr D0

Michael Wulz michael.wulz at gmail.com
Tue Sep 2 08:30:25 CEST 2014


Am 01.09.14 23:01, schrieb Reinhard Wilzeck:
> Hallo Michael,
Hallo Reihard,

> tatsächlich hatte ich in dem Bereich Probleme mit dem Parser.
> (Daher auch die ausführlichen log ausgaben)
> Da waren es aber der STX (hex 02) u.ä. der aber vorher abgefangen wird.
> Auch wird der Parser nur für codes gefragt die mit 1,2 oder C beginnen.
Danke für deine Analyse und Hilfe!

> 
> 1. In diesem Fall verwirrt mich, dass der Parser noch gearbeitet hat und
> es erst beim nächsten lesen  der Fehler kommt  (vielleicht aber auch
> Zufall ,das die letzte log zeile nicht mehr ausgegeben wird).
> "
> 
> [Sep 01 12:36:16][d0]   Parsed reading (OBIS code=2.8.1*02,
> value=000000.0, unit=)
> [Sep 01 12:36:17][d0]   DEBUG OBIS_CODE byte
>  hex= A
> Segmentation fault
> 
> "
> In dem branch vzlogger-master scheint mir aber noch eine Schwäche zu sein.
> "
>             case END_LINE:
>                 if (byte == '\r' || byte == '\n') {
>                     /* free slots available and sain content? */
> *                    if ((number_of_tuples < max_readings) &&
> (strlen(obis_code) > 0) && **
> *                           *(strlen(value) > 0)*) {
>                         print(log_debug, "Parsed reading (OBIS code=%s,
> value=%s, unit=%s)", name().c_str(), obis_code, value, unit);
>                         rds[number_of_tuples].value(strtod(value, NULL));
>                     *    if
> ((obis_code[0]=='1')||(obis_code[0]=='2')||(obis_code[0]=='C')) {*
>                             /*print(log_debug, "DEBUG END_LINE Obis code
> = %s value %s ",name().c_str(), obis_code, value);*/
>                             Obis obis(obis_code);
>                             ReadingIdentifier *rid(new
> ObisIdentifier(obis));
>                             rds[number_of_tuples].identifier(rid);
>                             rds[number_of_tuples].time();
>                             byte_iterator = 0;
>                             number_of_tuples++;
>                         }
>                     }
>                     context = OBIS_CODE;
>                 }
>                 break;
> "
> Das heißt: egal wie die beiden inneren IF ausgehen: der Context wird auf
> OBIS_CODE gesetzt. Die folge ist, das wahrscheinlich der byte_iterator
> nicht auf 0 geschrieben wird. Also haben wir dort eine Überschreitung
> der Array grenzen, wenn z.B.  *number_of_tuples = max_readings* erreicht
> wird.
> Korrektur Vorschlag: 
> ...
>                     }
>                     byte_iterator = 0;
>                     context = OBIS_CODE;
>                 }

habe diesen Vorschlag mal probiert:
jetzt scheint aber der Parser garnicht mehr zu funktionieren, hier der
Output:

root at raspberrypi:~# vzlogger -c /etc/vzlogger.conf
[Sep 02 06:25:11][mtr0] Creating new meter with protocol d0.
[Sep 02 06:25:11][d0]   pullseq len:5 found
[Sep 02 06:25:11][mtr0] Meter configured. enabled
[Sep 02 06:25:11]       New meter initialized (protocol=d0)
[Sep 02 06:25:11]       Configure channel.
[Sep 02 06:25:11][chn0] New channel initialized (uuid=...7ad291
protocol=volkszaehler id=1-0:1.8.1)
[Sep 02 06:25:11]       Have 1 meters.
[Sep 02 06:25:11][main] foreground=1, daemon=0, local=0
[Sep 02 06:25:11]       NOT Daemonize process...
[Sep 02 06:25:11]       Opened logfile /var/log/vzlogger.log
[Sep 02 06:25:11][]     ===> Start meters.
[Sep 02 06:25:11][mtr0] Meter connection established
[Sep 02 06:25:11][mtr0] Meter thread started
[Sep 02 06:25:11][mtr0] meter is opened. Start channels.
[Sep 02 06:25:11][chn0] Logging thread started
[Sep 02 06:25:11][]     Startup done.
[Sep 02 06:25:11][mtr0] Number of readers: 32
[Sep 02 06:25:11][mtr0] Config.daemon: 0
[Sep 02 06:25:11][mtr0] Config.local: 0
[Sep 02 06:25:11][chn0] Start logging thread for volkszaehler-api.
Running as daemon: no
[Sep 02 06:25:11][d0]   sending pullsequenz send (len:5 is:5).
[Sep 02 06:25:11][d0]   Something unexpected happened: read:497!
[Sep 02 06:25:11][mtr0] Got 0 new readings from meter:
[Sep 02 06:25:11][chn0] Buffer dump (size=0 keep=32): {}
[Sep 02 06:25:11][mtr0] Next reading in 6 seconds
[Sep 02 06:25:11][chn0] Using default api:
[Sep 02 06:25:11][chn0] ==> number of tuples: 0
[Sep 02 06:25:11][chn0] JSON request body is null. Nothing to send now.
[Sep 02 06:25:17][d0]   sending pullsequenz send (len:5 is:5).
[Sep 02 06:25:17][d0]   Something unexpected happened: read:497!
[Sep 02 06:25:17][mtr0] Got 0 new readings from meter:
[Sep 02 06:25:17][chn0] ==> number of tuples: 0
[Sep 02 06:25:17][chn0] JSON request body is null. Nothing to send now.
[Sep 02 06:25:17][chn0] Buffer dump (size=0 keep=32): {}
[Sep 02 06:25:17][mtr0] Next reading in 6 seconds
[Sep 02 06:25:23][d0]   sending pullsequenz send (len:5 is:5).
[Sep 02 06:25:23][d0]   Something unexpected happened: read:497!
[Sep 02 06:25:23][mtr0] Got 0 new readings from meter:
[Sep 02 06:25:23][chn0] ==> number of tuples: 0
[Sep 02 06:25:23][chn0] JSON request body is null. Nothing to send now.
[Sep 02 06:25:23][chn0] Buffer dump (size=0 keep=32): {}
[Sep 02 06:25:23][mtr0] Next reading in 6 seconds
[Sep 02 06:25:29][d0]   sending pullsequenz send (len:5 is:5).
[Sep 02 06:25:29][d0]   Something unexpected happened: read:497!
[Sep 02 06:25:29][mtr0] Got 0 new readings from meter:
[Sep 02 06:25:29][chn0] ==> number of tuples: 0
[Sep 02 06:25:29][chn0] JSON request body is null. Nothing to send now.
[Sep 02 06:25:29][chn0] Buffer dump (size=0 keep=32): {}
[Sep 02 06:25:29][mtr0] Next reading in 6 seconds
^C[Sep 02 06:25:32]       terminating on signal 2.
[Sep 02 06:25:32]       Closing connections to terminate
*** glibc detected *** vzlogger: free(): corrupted unsorted chunks:
0x01d4cc20 ***
Aborted

(hab ich dann mit CTRL+C abgebrochen)
> 
> 
> 2) Zum testen mal den parser auskommentieren. Damit kannst Du
> ausschliessen, dass es der Parser ist. 
>   /*                         Obis obis(obis_code);
>                             ReadingIdentifier *rid(new
> ObisIdentifier(obis));
>                             rds[number_of_tuples].identifier(rid);
>                             rds[number_of_tuples].time();
>  */

Habe dann deinen ersten Korrekturvorschlag wieder entfernt und den
Parser auskommentiert, scheint das gleiche Ergebnis zu sein:

root at raspberrypi:~/vzlogger# vzlogger -c /etc/vzlogger.conf
[Sep 02 06:28:59][mtr0] Creating new meter with protocol d0.
[Sep 02 06:28:59][d0]   pullseq len:5 found
[Sep 02 06:28:59][mtr0] Meter configured. enabled
[Sep 02 06:28:59]       New meter initialized (protocol=d0)
[Sep 02 06:28:59]       Configure channel.
[Sep 02 06:28:59][chn0] New channel initialized (uuid=...7ad291
protocol=volkszaehler id=1-0:1.8.1)
[Sep 02 06:28:59]       Have 1 meters.
[Sep 02 06:28:59][main] foreground=1, daemon=0, local=0
[Sep 02 06:28:59]       NOT Daemonize process...
[Sep 02 06:28:59]       Opened logfile /var/log/vzlogger.log
[Sep 02 06:28:59][]     ===> Start meters.
[Sep 02 06:28:59][mtr0] Meter connection established
[Sep 02 06:28:59][mtr0] Meter thread started
[Sep 02 06:28:59][mtr0] meter is opened. Start channels.
[Sep 02 06:28:59][chn0] Logging thread started
[Sep 02 06:28:59][]     Startup done.
[Sep 02 06:28:59][mtr0] Number of readers: 32
[Sep 02 06:28:59][mtr0] Config.daemon: 0
[Sep 02 06:28:59][mtr0] Config.local: 0
[Sep 02 06:28:59][chn0] Start logging thread for volkszaehler-api.
Running as daemon: no
[Sep 02 06:28:59][d0]   sending pullsequenz send (len:5 is:5).
[Sep 02 06:28:59][d0]   Something unexpected happened: read:497!
[Sep 02 06:28:59][chn0] Using default api:
[Sep 02 06:28:59][mtr0] Got 0 new readings from meter:
[Sep 02 06:28:59][chn0] Buffer dump (size=0 keep=32): {}
[Sep 02 06:28:59][mtr0] Next reading in 6 seconds
[Sep 02 06:28:59][chn0] ==> number of tuples: 0
[Sep 02 06:28:59][chn0] JSON request body is null. Nothing to send now.
[Sep 02 06:29:05][d0]   sending pullsequenz send (len:5 is:5).
[Sep 02 06:29:05][d0]   Something unexpected happened: read:497!
[Sep 02 06:29:05][mtr0] Got 0 new readings from meter:
[Sep 02 06:29:05][chn0] ==> number of tuples: 0
[Sep 02 06:29:05][chn0] JSON request body is null. Nothing to send now.
[Sep 02 06:29:05][chn0] Buffer dump (size=0 keep=32): {}
[Sep 02 06:29:05][mtr0] Next reading in 6 seconds
[Sep 02 06:29:11][d0]   sending pullsequenz send (len:5 is:5).
[Sep 02 06:29:11][d0]   Something unexpected happened: read:497!
[Sep 02 06:29:11][mtr0] Got 0 new readings from meter:
[Sep 02 06:29:11][chn0] ==> number of tuples: 0
[Sep 02 06:29:11][chn0] JSON request body is null. Nothing to send now.
[Sep 02 06:29:11][chn0] Buffer dump (size=0 keep=32): {}
[Sep 02 06:29:11][mtr0] Next reading in 6 seconds
[Sep 02 06:29:17][d0]   sending pullsequenz send (len:5 is:5).
[Sep 02 06:29:17][d0]   Something unexpected happened: read:497!
[Sep 02 06:29:17][mtr0] Got 0 new readings from meter:
[Sep 02 06:29:17][chn0] ==> number of tuples: 0
[Sep 02 06:29:17][chn0] JSON request body is null. Nothing to send now.
[Sep 02 06:29:17][chn0] Buffer dump (size=0 keep=32): {}
[Sep 02 06:29:17][mtr0] Next reading in 6 seconds
^C[Sep 02 06:29:19]       terminating on signal 2.
[Sep 02 06:29:19]       Closing connections to terminate
*** glibc detected *** vzlogger: free(): corrupted unsorted chunks:
0x01147c20 ***
Aborted

(wieder mit CTRL+C abgebrochen)

lg
Michael


More information about the volkszaehler-dev mailing list