[vz-dev] Dockstar - vzlogger Core Dump

Gerhard Bertelsmann info at gerhard-bertelsmann.de
Sun Jan 8 00:41:10 CET 2012


Hallo Thorben,

erstmal vielen Dank für Deine Unterstützung.

>> root at Stromkasten:~# vzlogger -d
>>   Electric Fence 2.1 Copyright (C) 1987-1998 Bruce Perens.
>> [Jan 06 19:06:07][mtr0] New meter initialized (protocol=sml)
>>
>> Brach dann nach ein paar Messungen ab:
> [...]
>> [Jan 06 19:11:07][ch2]  Request succeeded with code: 200
> ich kann da keinerlei fehlermeldugen erkennen...?
>
>> GDB sagt:
>> root at Stromkasten:~# gdb /usr/local/bin/vzlogger -c /core
>> warning: exec file is newer than core file.
> (das bedeutet normalerweise, dass du was falsch gemacht hast...
>  ist aber hier wohl egal.)
>
>> Program terminated with signal 11, Segmentation fault.
>> (gdb) bt full
>> #0  0x4024fa88 in pthread_cancel (th=1920233071) at pthread_cancel.c:35
>>         pd = 0x72746e6f
>> #1  0x0000ae94 in quit (sig=<optimized out>) at src/vzlogger.c:235
>> #2  <signal handler called>
>> #3  0x4024a0c8 in pthread_join (threadid=1091154976, thread_return=0x0)
>> at
>> pthread_join.c:89
>>         _buffer = {__routine = 0x40249fb0 <cleanup>, __arg = 0x4109b63c,
>> #4  0x0000aa34 in main () at src/vzlogger.c:418
>>
>> Ich bin kein GDB Spezialist. Verursacht der Aufruf von pthread_cancel
>> den
>> Fehler ?
>
> was ich hier nicht verstehe ist, dass der absturz in einem teil des codes
> passiert, der beim _beenden_ von vzlogger ablaeuft, ohne dass erkennbar
> ist
> warum das programm beendet wird, was vermutlich interessanter waehre zu
> wissen,
> als warum es dabei dann abstuerzt.
> (in main () at src/vzlogger.c:418)

Ich habe hier leider ein wenig dazwischen experimentiert. Der o.g. Core Dump
stammt von vzlogger (ohne -d). Bei mir bricht vzlogger -f nach einer
Messung ab.
Ist das bei Euch auch so ?

Da efence auf der Dockstar für mich keinen brauchbaren Output liefert
(insbesondere
mit dem Daemon) habe ich vzlogger auf einer Ubuntu Oneric AMD64 Maschine
verlagert.
Die Daten werden auf der Dockstar mittels:
socat tcp-l:7333,reuseaddr,fork
file:/dev/ttyUSB0,nonblock,raw,echo=0,crnl,waitlock=/var/run/tty &
auf TCP 7333 umgelenkt und auf der Testmaschine empfangen.
Auch hier bricht "vzlogger -d" nach ein paar Stunden ab.

Ich habe mal versuchsweise vlagrind benutzt:

valgrind --leak-check=yes --trace-children=yes --log-file=vz_valgrind.log
/usr/local/bin/vzlogger -d

Dabei kommt folgendes raus:

==29355== Memcheck, a memory error detector
==29355== Copyright (C) 2002-2010, and GNU GPL'd, by Julian Seward et al.
==29355== Using Valgrind-3.6.1-Debian and LibVEX; rerun with -h for
copyright info
==29355== Command: /usr/local/bin/vzlogger -d
==29355== Parent PID: 27104
==29355==
==29358== Warning: invalid file descriptor 4086 in syscall close()
==29355==
==29355== HEAP SUMMARY:
==29355==     in use at exit: 90,068 bytes in 2,925 blocks
==29355==   total heap usage: 3,136 allocs, 211 frees, 120,677 bytes
allocated
==29355==
==29355== LEAK SUMMARY:
==29355==    definitely lost: 0 bytes in 0 blocks
==29355==    indirectly lost: 0 bytes in 0 blocks
==29355==      possibly lost: 0 bytes in 0 blocks
==29355==    still reachable: 90,068 bytes in 2,925 blocks
==29355==         suppressed: 0 bytes in 0 blocks
==29355== Reachable blocks (those to which a pointer was found) are not
shown.
==29355== To see them, rerun with: --leak-check=full --show-reachable=yes
==29355==
==29355== For counts of detected and suppressed errors, rerun with: -v
==29355== ERROR SUMMARY: 0 errors from 0 contexts (suppressed: 10 from 6)
// IMHO ab hier geht der Daemon in den Hintergrund
==29358== Thread 3:
==29358== Conditional jump or move depends on uninitialised value(s)
==29358==    at 0x4C2934C: index (mc_replace_strmem.c:142)
==29358==    by 0x403DBF: curl_custom_debug_callback (api.c:40)
==29358==    by 0x5681F5F: Curl_debug (in
/usr/lib/x86_64-linux-gnu/libcurl.so.4.2.0)
==29358==    by 0x567EAC9: Curl_add_buffer_send (in
/usr/lib/x86_64-linux-gnu/libcurl.so.4.2.0)
==29358==    by 0x56804A4: Curl_http (in
/usr/lib/x86_64-linux-gnu/libcurl.so.4.2.0)
==29358==    by 0x568E8E7: Curl_do (in
/usr/lib/x86_64-linux-gnu/libcurl.so.4.2.0)
==29358==    by 0x56997A6: ??? (in
/usr/lib/x86_64-linux-gnu/libcurl.so.4.2.0)
==29358==    by 0x40548B: logging_thread (threads.c:176)
==29358==    by 0x524DEFB: start_thread (pthread_create.c:304)
==29358==    by 0x5C2B89C: clone (clone.S:112)
==29358==
==29358== Conditional jump or move depends on uninitialised value(s)
==29358==    at 0x4C29340: index (mc_replace_strmem.c:142)
==29358==    by 0x403DBF: curl_custom_debug_callback (api.c:40)
==29358==    by 0x5681F5F: Curl_debug (in
/usr/lib/x86_64-linux-gnu/libcurl.so.4.2.0)
==29358==    by 0x567EAC9: Curl_add_buffer_send (in
/usr/lib/x86_64-linux-gnu/libcurl.so.4.2.0)
==29358==    by 0x56804A4: Curl_http (in
/usr/lib/x86_64-linux-gnu/libcurl.so.4.2.0)
==29358==    by 0x568E8E7: Curl_do (in
/usr/lib/x86_64-linux-gnu/libcurl.so.4.2.0)
==29358==    by 0x56997A6: ??? (in
/usr/lib/x86_64-linux-gnu/libcurl.so.4.2.0)
==29358==    by 0x40548B: logging_thread (threads.c:176)
==29358==    by 0x524DEFB: start_thread (pthread_create.c:304)
==29358==    by 0x5C2B89C: clone (clone.S:112)
==29358==
==29358==
==29358== HEAP SUMMARY:
==29358==     in use at exit: 213,963 bytes in 3,088 blocks
==29358==   total heap usage: 56,972 allocs, 53,884 frees, 3,837,563 bytes
allocated
==29358==
==29358== Thread 1:
==29358== 19 bytes in 1 blocks are definitely lost in loss record 11 of 603
==29358==    at 0x4C28F9F: malloc (vg_replace_malloc.c:236)
==29358==    by 0x5BCC441: strdup (strdup.c:43)
==29358==    by 0x407E0D: meter_open_sml (sml.c:114)
==29358==    by 0x403063: main (vzlogger.c:375)
==29358==
==29358== 304 bytes in 1 blocks are possibly lost in loss record 546 of 603
==29358==    at 0x4C279F2: calloc (vg_replace_malloc.c:467)
==29358==    by 0x4011844: _dl_allocate_tls (dl-tls.c:300)
==29358==    by 0x524EB68: pthread_create@@GLIBC_2.2.5 (allocatestack.c:571)
==29358==    by 0x403096: main (vzlogger.c:383)
==29358==
==29358== 354 (192 direct, 162 indirect) bytes in 3 blocks are definitely
lost in loss record 548 of 603
==29358==    at 0x4C28F9F: malloc (vg_replace_malloc.c:236)
==29358==    by 0x50401FD: sml_list_init (in /usr/lib/libsml.so.1.1)
==29358==    by 0x504024E: sml_list_entry_parse (in /usr/lib/libsml.so.1.1)
==29358==    by 0x50403E4: sml_list_parse (in /usr/lib/libsml.so.1.1)
==29358==    by 0x5042585: sml_get_list_response_parse (in
/usr/lib/libsml.so.1.1)
==29358==    by 0x503FADF: sml_message_body_parse (in /usr/lib/libsml.so.1.1)
==29358==    by 0x503FD59: sml_message_parse (in /usr/lib/libsml.so.1.1)
==29358==    by 0x503E3DF: sml_file_parse (in /usr/lib/libsml.so.1.1)
==29358==    by 0x4079FF: meter_read_sml (sml.c:151)
==29358==    by 0x40500F: reading_thread (threads.c:61)
==29358==    by 0x524DEFB: start_thread (pthread_create.c:304)
==29358==    by 0x5C2B89C: clone (clone.S:112)
==29358==
==29358== 912 bytes in 3 blocks are possibly lost in loss record 573 of 603
==29358==    at 0x4C279F2: calloc (vg_replace_malloc.c:467)
==29358==    by 0x4011844: _dl_allocate_tls (dl-tls.c:300)
==29358==    by 0x524EB68: pthread_create@@GLIBC_2.2.5 (allocatestack.c:571)
==29358==    by 0x403123: main (vzlogger.c:393)
==29358==
==29358== LEAK SUMMARY:
==29358==    definitely lost: 211 bytes in 4 blocks
==29358==    indirectly lost: 162 bytes in 20 blocks
==29358==      possibly lost: 1,216 bytes in 4 blocks
==29358==    still reachable: 212,374 bytes in 3,060 blocks
==29358==         suppressed: 0 bytes in 0 blocks
==29358== Reachable blocks (those to which a pointer was found) are not
shown.
==29358== To see them, rerun with: --leak-check=full --show-reachable=yes
==29358==
==29358== For counts of detected and suppressed errors, rerun with: -v
==29358== Use --track-origins=yes to see where uninitialised values come from
==29358== ERROR SUMMARY: 1288 errors from 6 contexts (suppressed: 10 from 6)

GDB sagt:

root at spartanew ~ # gdb /usr/local/bin/vzlogger -c vz_valgrind.log.core.29358
GNU gdb (Ubuntu/Linaro 7.3-0ubuntu2) 7.3-2011.08
Copyright (C) 2011 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu".
For bug reporting instructions, please see:
<http://bugs.launchpad.net/gdb-linaro/>...
Reading symbols from /usr/local/bin/vzlogger...done.
[New LWP 29362]
[New LWP 29361]
[New LWP 29360]
[New LWP 29359]
[New LWP 29358]
[Thread debugging using libthread_db enabled]
Cannot find new threads: generic error
(gdb) bt full
#0  pthread_cond_wait@@GLIBC_2.3.2 () at
../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:162
No locals.
#1  0x00000000004053eb in logging_thread (arg=0x90bd450) at src/threads.c:161
        json_obj = <optimized out>
        json_str = <optimized out>
        last = <optimized out>
        response = {data = 0x0, size = 0}
        http_code = 200
        curl_code = <optimized out>
        first = <optimized out>
        __cancel_buf = {__cancel_jmp_buf = {{__cancel_jmp_buf = {0,
-915355051854007849, 86342688, 189188544, 0, 3,
-915330358864383529, -915354499361934889}, __mask_was_saved = 0}},
          __pad = {0xb46bf00, 0x0, 0x0, 0x0}}
        __cancel_routine = 0x405340 <logging_thread_cleanup>
        __cancel_arg = 0x90c7b90
        __not_first_call = <optimized out>
        ch = 0x90bd450
        curl = 0x90c7b90
#2  0x000000000524defc in start_thread (arg=0xb46c700) at
pthread_create.c:304
        __res = <optimized out>
        pd = 0xb46c700
        now = <optimized out>
        unwind_buf = {cancel_jmp_buf = {{jmp_buf = {0,
-915355051854007849, 86342688, 189188544, 0, 3,
-915330358826634793, -915344359322947113}, mask_was_saved = 0}},
priv = {pad = {0x0,
              0x0, 0x0, 0x0}, data = {prev = 0x0, cleanup = 0x0,
canceltype = 0}}}
        not_first_call = 0
        robust = <optimized out>
        pagesize_m1 = <optimized out>
        sp = <optimized out>
        freesize = <optimized out>
        __PRETTY_FUNCTION__ = "start_thread"
#3  0x0000000005c2b89d in clone () at
../sysdeps/unix/sysv/linux/x86_64/clone.S:112
No locals.
#4  0x0000000000000000 in ?? ()
No symbol table info available.
(gdb)

Kann jemand etwas damit anfangen ?

Gruß

Gerd





More information about the volkszaehler-dev mailing list