[vz-users] s0vz lastet RasPi komplett aus

Thu Mar 26 14:04:25 CET 2015

Hallo,

ich habe ca. seit Anfang März ein ähnliches (oder vielleicht sogar das
gleiche) Problem. Leider habe ich bisher keine Ursache / Lösung gefunden.
Da ich den Fehler bei mir suche (ging ja urplötzlich nicht mehr), habe ich
hier noch nichts gepostet. Nun ja, vielleicht hilft meine Teilanalyse ja
jetzt weiter:

Für mich sah es so aus, als wenn der s0vz Prozess zwar korrekt startet,
sobald ein s0 Impuls kommt (via reed Kontakt an s0 Erweiterung klein von
Udo), dieser das System lahmlegt (watchdog löst bei mir einen Reboot aus
wenn der Load > ~25 geht). Mein Gaszähler hat nur 10 Impulse pro m³, daher
habe ich in Summe eher wenige. Die Last kommt dann vom Prozess selbst und
zu einem großen Anteil vom apache (oder vom lighttpd via php-cgi).

Zur Analyse habe ich zusätzliche syslog Befehle in s0vc.c eingebaut, in
etwa so:

for ( ;; ) {
    if((multihandle_res = curl_multi_perform(multihandle,
&running_handles)) != CURLM_OK) {
    syslog(LOG_INFO, "HTTP_POST(): %s",
curl_multi_strerror(multihandle_res) );
    }
    if (i++ % log_poll_seconds == 0) {
        syslog(LOG_INFO, "Before poll()");
    }
    int ret = poll(fds, inputs, 1000);

    if(ret>0) {
        syslog(LOG_INFO, "Got something, ret > 0");
        for (i=0; i<inputs; i++) {
            if (fds[i].revents & POLLPRI) {
                // syslog(LOG_INFO, "Before read");
                len = read(fds[i].fd, buffer, BUF_LEN);
                syslog(LOG_INFO, "after read");

                // syslog(LOG_INFO, "Beforde update curl handle");
                update_curl_handle(vzuuid[i]);
                syslog(LOG_INFO, "After update curl handle");
            }
        }
    }
}

log_poll_seconds habe ich definiert damit nicht jede Sekunde ein Eintrag
erzeugt wird. Das Logfile sieht dann in etwas so aus:

Mar 21 22:28:32 dev-pi s0vz: S0/Impulse to Volkszaehler RaspberryPI deamon
1.4.5
Mar 21 22:28:32 dev-pi s0vz: VzServer:localhost
Mar 21 22:28:32 dev-pi s0vz: VzPort:80
Mar 21 22:28:32 dev-pi s0vz: log_poll_seconds:60
Mar 21 22:28:32 dev-pi s0vz: VzPath:middleware.php
Mar 21 22:28:32 dev-pi s0vz: GPIO0 = 30afb000-d080-11e3-be6a-33242cd61de6
Mar 21 22:28:32 dev-pi s0vz: Before poll()
Mar 21 22:28:32 dev-pi s0vz: Got something, ret > 0
Mar 21 22:28:32 dev-pi s0vz: after read
Mar 21 22:28:32 dev-pi s0vz: CURL:
http://localhost:80/middleware.php/data/30afb000-d080-11e3-be6a-33242cd61de6.json?ts=1426948112388
Mar 21 22:28:32 dev-pi s0vz: After update curl handle
Mar 21 22:28:32 dev-pi s0vz: after read
Mar 21 22:28:32 dev-pi s0vz: CURL:
http://localhost:80/middleware.php/data/(null).json?ts=1426948112389
Mar 21 22:28:32 dev-pi s0vz: After update curl handle
Mar 21 22:28:32 dev-pi s0vz: after read
Mar 21 22:28:32 dev-pi s0vz: CURL:
http://localhost:80/middleware.php/data/(null).json?ts=1426948112389
Mar 21 22:28:32 dev-pi s0vz: After update curl handle
Mar 21 22:28:32 dev-pi s0vz: after read
Mar 21 22:28:32 dev-pi s0vz: CURL:
http://localhost:80/middleware.php/data/(null).json?ts=1426948112389
Mar 21 22:28:32 dev-pi s0vz: After update curl handle
Mar 21 22:28:32 dev-pi s0vz: after read
Mar 21 22:28:32 dev-pi s0vz: CURL:
http://localhost:80/middleware.php/data/(null).json?ts=1426948112393
Mar 21 22:28:32 dev-pi s0vz: After update curl handle
Mar 21 22:29:26 dev-pi s0vz: Before poll()
Mar 21 22:30:26 dev-pi s0vz: Before poll()
Mar 21 22:31:26 dev-pi s0vz: Before poll()
Mar 21 22:32:26 dev-pi s0vz: Before poll()
Mar 21 22:32:51 dev-pi s0vz: Got something, ret > 0
Mar 21 22:32:51 dev-pi s0vz: after read
Mar 21 22:32:51 dev-pi s0vz: CURL:
http://localhost:80/middleware.php/data/30afb000-d080-11e3-be6a-33242cd61de6.json?ts=1426948371847
Mar 21 22:32:51 dev-pi s0vz: After update curl handle
Mar 21 22:32:51 dev-pi s0vz: Got something, ret > 0
Mar 21 22:32:51 dev-pi s0vz: after read
Mar 21 22:32:51 dev-pi s0vz: CURL:
http://localhost:80/middleware.php/data/30afb000-d080-11e3-be6a-33242cd61de6.json?ts=1426948371847
Mar 21 22:32:51 dev-pi s0vz: After update curl handle
Mar 21 22:32:51 dev-pi s0vz: Got something, ret > 0
Mar 21 22:32:51 dev-pi s0vz: after read
Mar 21 22:32:51 dev-pi s0vz: CURL:
http://localhost:80/middleware.php/data/30afb000-d080-11e3-be6a-33242cd61de6.json?ts=1426948371847
Mar 21 22:32:51 dev-pi s0vz: After update curl handle
Mar 21 22:32:51 dev-pi s0vz: Got something, ret > 0
Mar 21 22:32:51 dev-pi s0vz: after read
Mar 21 22:32:51 dev-pi s0vz: CURL:
http://localhost:80/middleware.php/data/30afb000-d080-11e3-be6a-33242cd61de6.json?ts=1426948371850
Mar 21 22:32:51 dev-pi s0vz: After update curl handle
Mar 21 22:32:51 dev-pi s0vz: Got something, ret > 0
Mar 21 22:32:51 dev-pi s0vz: after read
...

Der Prozess schickt dann bis zum Reboot durch den watchdog Requests an den
Webserver. Aus irgend einem Grund scheint der poll vom file descriptor
immer einen Wert >0 zu bekommen. Mir ist völlig unklar was da schief läuft
oder was sich am System geändert hat (außer Standard-Updates). vzlogger mit
s0 hab ich nicht ans Laufen bekommen, daher behelfe ich mir momentan mit
einem selbst geschriebenen Python Script. Hoffe das hilft weiter,
vielleicht bekomme ich es ja dann auch bei mir wieder hin. Wenn ich weitere
Tests machen soll einfach kurz Bescheid sagen.

Gruß
André

Andreas Goetz <cpuidle at gmail.com> schrieb am Do., 26. März 2015 um
12:55 Uhr:

> PS.: Urpsünglich hast Du geschrieben s0vz hätte 98% Last. Was stimmt denn
> nun?
>
> 2015-03-26 12:55 GMT+01:00 Andreas Goetz <cpuidle at gmail.com>:
>
>> Ich frag mich was da los ist. Wenn Du viele Impulse pro Sekunde schreibst
>> braucht es viele Apache Instanzen. Siw macht s0vz keine Aggregation warum
>> wir gerade versuchen es durch vzlogger zu ersetzen (wip).
>>
>> Wieviele Impulse liefern denn Deine Meter?
>>
>> Viele Grüße,
>> Andreas
>>
>>
>> 2015-03-26 12:52 GMT+01:00 a b <test48517 at googlemail.com>:
>>
>>> Hallo Udo,
>>>
>>> Neuinstallation von s0vz hat leider nichts gebracht, mittlerweile bin
>>> ich allerdings der Meinung das nicht s0vz das Problem ist, sondern die
>>> geöffneten Apache Instanzen den RasPi zumüllen.
>>> Anbei ein Screenshot der den Auszug aus top zeigt, nachdem ich etwa eine
>>> Minute davor Apache gestartet habe.
>>> Die CPU-Leistung von s0vz bewegt sich immer irgendwo zwischen 40 und
>>> 100%.
>>>
>>> Gruß,
>>> Martin
>>>
>>>
>>>
>>> Am 24. März 2015 um 20:58 schrieb Udo1 <udo1 at gmx.net>:
>>>
>>> Hallo Martin,
>>>>
>>>> Am 24.03.2015 um 17:22 schrieb a b:
>>>>
>>>>> Leider hat der Ramdisk Versuch nicht die erhoffte Lösung gebracht.
>>>>>
>>>> Also jedes mal wenn du s0vz startest geht die CPU-Leistung auf 98%?
>>>>
>>>> Installier einfach mal s0vz neu.
>>>> https://github.com/w3llschmidt/s0vz
>>>>
>>>> Gruß
>>>> Udo
>>>>
>>>
>>>
>>
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://demo.volkszaehler.org/pipermail/volkszaehler-users/attachments/20150326/64d57db1/attachment-0001.html>