[creamers]

I notice sometimes that pilight (dev version) 'crashes' but the daemon still 'runs'.
It happened twice now. One time on 26dec and today 15jan.
Think this information is not enough to tell something about the issue? Guess I need to run 'GNU Debugger' in screen and hope I can catch the bug?

ps afx

Code:

pi@pilight:~ $ ps afx |grep pilight
  367 ?        Ss     0:02 avahi-daemon: running [pilight.local]

service pilight status returned:

Code:

Jan 15 18:16:51 pilight pilight[565]: *** Error in `/usr/local/sbin/pilight-daemon': double free or corruption (fasttop): 0x75902188 ***
Jan 15 18:16:51 pilight pilight[565]: -- STACKTRACE (13 FRAMES) --
Jan 15 18:16:51 pilight pilight[565]: __default_sa_restorer_v2       ip = 0x76b11180, sp = 0x6bafdf60
Jan 15 18:16:51 pilight pilight[565]: gsignal                        ip = 0x76b0ff70, sp = 0x6bafe250
Jan 15 18:16:51 pilight pilight[565]: abort                          ip = 0x76b11324, sp = 0x6bafe258
Jan 15 18:16:51 pilight pilight[565]: __fsetlocking                  ip = 0x76b4b954, sp = 0x6bafe370
Jan 15 18:16:51 pilight pilight[565]: _IO_str_seekoff                ip = 0x76b51b80, sp = 0x6bafe4a8
Jan 15 18:16:51 pilight pilight[565]: _IO_str_seekoff                ip = 0x76b52b24, sp = 0x6bafe4d0
Jan 15 18:16:51 pilight pilight[565]: json_delete                    ip =    0x3f088, sp = 0x6bafe528
Jan 15 18:16:51 pilight pilight[565]: send_queue                     ip =    0x22b30, sp = 0x6bafe540
Jan 15 18:16:51 pilight pilight[565]: control_device                 ip =    0x23a88, sp = 0x6bafeda0
Jan 15 18:16:51 pilight pilight[565]: thread                         ip =    0x88c84, sp = 0x6bafede0
Jan 15 18:16:51 pilight pilight[565]: start_thread                   ip = 0x76ee4e90, sp = 0x6bafee60
Jan 15 18:16:51 pilight pilight[565]: clone                          ip = 0x76bb3598, sp = 0x6bafefa0

pilight.err

Code:

[Jan 15 18:16:51:253129] pilight-daemon: -- STACKTRACE (13 FRAMES) --
[Jan 15 18:16:51:257428] pilight-daemon: __default_sa_restorer_v2       ip = 0x76b11180, sp = 0x6bafdf60
[Jan 15 18:16:51:259436] pilight-daemon: gsignal                        ip = 0x76b0ff70, sp = 0x6bafe250
[Jan 15 18:16:51:261345] pilight-daemon: abort                          ip = 0x76b11324, sp = 0x6bafe258
[Jan 15 18:16:51:263200] pilight-daemon: __fsetlocking                  ip = 0x76b4b954, sp = 0x6bafe370
[Jan 15 18:16:51:265140] pilight-daemon: _IO_str_seekoff                ip = 0x76b51b80, sp = 0x6bafe4a8
[Jan 15 18:16:51:266985] pilight-daemon: _IO_str_seekoff                ip = 0x76b52b24, sp = 0x6bafe4d0
[Jan 15 18:16:51:272747] pilight-daemon: json_delete                    ip =    0x3f088, sp = 0x6bafe528
[Jan 15 18:16:51:274491] pilight-daemon: send_queue                     ip =    0x22b30, sp = 0x6bafe540
[Jan 15 18:16:51:276125] pilight-daemon: control_device                 ip =    0x23a88, sp = 0x6bafeda0
[Jan 15 18:16:51:277680] pilight-daemon: thread                         ip =    0x88c84, sp = 0x6bafede0
[Jan 15 18:16:51:279725] pilight-daemon: start_thread                   ip = 0x76ee4e90, sp = 0x6bafee60
[Jan 15 18:16:51:281759] pilight-daemon: clone                          ip = 0x76bb3598, sp = 0x6bafefa0

After this the service wont start with 'service pilight start' but I can run pilight-daemon -D , so it seems. After a restart it runs as normal.


*EDIT
Trying to use gdb but get some errors:

Code:

root@pilight:~/pilight/build# gdb pilight-daemon
GNU gdb (Raspbian 7.7.1+dfsg-5+rpi1) 7.7.1
Copyright (C) 2014 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 "arm-linux-gnueabihf".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from pilight-daemon...done.
(gdb) run -D
Starting program: /root/pilight/build/pilight-daemon -D
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/arm-linux-gnueabihf/libthread_db.so.1".
Cannot access memory at address 0x0

Program received signal SIGILL, Illegal instruction.
0x76d68de8 in ?? () from /usr/lib/arm-linux-gnueabihf/libcrypto.so.1.0.0
(gdb)

backtrace:

Code:

(gdb) backtrace
#0  0x76d68de8 in ?? () from /usr/lib/arm-linux-gnueabihf/libcrypto.so.1.0.0
#1  0x76d654b4 in OPENSSL_cpuid_setup () from /usr/lib/arm-linux-gnueabihf/libcrypto.so.1.0.0
#2  0x76fdeffc in call_init (l=<optimized out>, argc=2, argv=0x7efff294, env=0x7efff2a0) at dl-init.c:78
#3  0x76fdf0d8 in _dl_init (main_map=0x76fff958, argc=2, argv=0x7efff294, env=0x7efff2a0) at dl-init.c:126
#4  0x76fcfd84 in _dl_start_user () from /lib/ld-linux-armhf.so.3
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb) frame 4
#4  0x76fcfd84 in _dl_start_user () from /lib/ld-linux-armhf.so.3
(gdb) frame 3
#3  0x76fdf0d8 in _dl_init (main_map=0x76fff958, argc=2, argv=0x7efff294, env=0x7efff2a0) at dl-init.c:126
126     dl-init.c: No such file or directory.
(gdb) frame 2
#2  0x76fdeffc in call_init (l=<optimized out>, argc=2, argv=0x7efff294, env=0x7efff2a0) at dl-init.c:78
78      in dl-init.c
(gdb) frame 1
#1  0x76d654b4 in OPENSSL_cpuid_setup () from /usr/lib/arm-linux-gnueabihf/libcrypto.so.1.0.0
(gdb) frame 0
#0  0x76d68de8 in ?? () from /usr/lib/arm-linux-gnueabihf/libcrypto.so.1.0.0
(gdb)

[curlymo]

What you have posted is a bug in one of the libraries, not in pilight itself? Did you update your system recently?

[creamers]

Think I updated around 15december.

[curlymo]

Like i said, the backtrace you posted is not an issue with pilight but one of the libraries pilight uses. I would try to get another gdb session but now in debug mode.

[creamers]

same problem explained

The solution adviced is: 'handle SIGILL nostop noprint' to prevent gdb from telling you that it saw the signal.

But will it signal the bug I'm looking for when using that solution....

[creamers]

Finally it hung:

Code:

[Feb 08 09:34:17:701030] pilight-daemon: DEBUG: rule #3 ResetAlarmLabelState was parsed in 0.000666 seconds
[Thread 0x6baff460 (LWP 16866) exited]

Program received signal SIGSEGV, Segmentation fault.
[Switching to Thread 0x70aff460 (LWP 26253)]
0x0003f740 in json_append_member (object=0x0, key=0x150430 "unitcode",
    value=0x73d009c8) at /root/pilight/libs/pilight/core/json.c:590
590             assert(object->tag == JSON_OBJECT);
(gdb)

Code:

(gdb) backtrace
#0  0x0003f740 in json_append_member (object=0x0, key=0x150430 "unitcode",
    value=0x73d009c8) at /root/pilight/libs/pilight/core/json.c:590
#1  0x00090ec4 in createMessage (systemcode=0, unitcode=0, state=0)
    at /root/pilight/libs/pilight/protocols/433.92/pollin.c:53
#2  0x000910c4 in parseCode ()
    at /root/pilight/libs/pilight/protocols/433.92/pollin.c:80
#3  0x00021e84 in receive_parse_code (param=0x0) at /root/pilight/daemon.c:611
#4  0x76f0ae90 in start_thread (arg=0x70aff460) at pthread_create.c:311
#5  0x76bd7598 in ?? ()
    at ../ports/sysdeps/unix/sysv/linux/arm/nptl/../clone.S:92
   from /lib/arm-linux-gnueabihf/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb)

Code:

(gdb) frame 5
#5  0x76bd7598 in ?? ()
    at ../ports/sysdeps/unix/sysv/linux/arm/nptl/../clone.S:92
   from /lib/arm-linux-gnueabihf/libc.so.6
92      ../ports/sysdeps/unix/sysv/linux/arm/nptl/../clone.S: No such file or directory.
(gdb) frame 4
#4  0x76f0ae90 in start_thread (arg=0x70aff460) at pthread_create.c:311
311     pthread_create.c: No such file or directory.
(gdb) frame 3
#3  0x00021e84 in receive_parse_code (param=0x0) at /root/pilight/daemon.c:611
611                                                             protocol->parseCode();
(gdb) frame 2
#2  0x000910c4 in parseCode ()
    at /root/pilight/libs/pilight/protocols/433.92/pollin.c:80
80              createMessage(systemcode, unitcode, state);
(gdb) frame 1
#1  0x00090ec4 in createMessage (systemcode=0, unitcode=0, state=0)
    at /root/pilight/libs/pilight/protocols/433.92/pollin.c:53
53              json_append_member(pollin->message, "unitcode", json_mknumber(unitcode, 0));
(gdb)

Hope you can make something out of it.

[curlymo]

I already considered this flow potentially unstable, but never heard of any concrete issues.I changed it in the rewrite code. I do however, do not see how this can happen Can you try once more to see if pollin is the cause again?

[creamers]

Wanted to start gdb again but got this error pretty early when running without gdb.
Will start a screen session again and run the daemon under gdb again.

Code:

[Feb 19 10:48:56:664328] pilight-daemon: DEBUG: called elro_800_switch parseRaw()
[Feb 19 10:48:56:664402] pilight-daemon: DEBUG: possible pollin protocol
[Feb 19 10:48:56:664454] pilight-daemon: DEBUG: recevied pulse length of 303
[Feb 19 10:48:56:664504] pilight-daemon: DEBUG: caught minimum # of repeats 3 of pollin
[Feb 19 10:48:56:664554] pilight-daemon: DEBUG: called pollin parseRaw()
*** Error in `./pilight-daemon': double free or corruption (fasttop): 0x73d007c8 ***
-- STACKTRACE (13 FRAMES) --
__default_sa_restorer_v2       ip = 0x76ade180, sp = 0x6cafdf60
gsignal                        ip = 0x76adcf70, sp = 0x6cafe250
abort                          ip = 0x76ade324, sp = 0x6cafe258
__fsetlocking                  ip = 0x76b18954, sp = 0x6cafe370
_IO_str_seekoff                ip = 0x76b1eb80, sp = 0x6cafe4a8
_IO_str_seekoff                ip = 0x76b1fb24, sp = 0x6cafe4d0
json_delete                    ip =    0x3f088, sp = 0x6cafe528
send_queue                     ip =    0x22b30, sp = 0x6cafe540
control_device                 ip =    0x23a88, sp = 0x6cafeda0
thread                         ip =    0x88c84, sp = 0x6cafede0
start_thread                   ip = 0x76eb1e90, sp = 0x6cafee60
clone                          ip = 0x76b80598, sp = 0x6cafefa0
Aborted
root@pilight:~/pilight/build#

[curlymo]

Yes, interesting that pollin is the cause again.

[creamers]

One more time. Is it something you can use ?

Code:

[Mar 03 07:07:44:134405] pilight-daemon: DEBUG: caught minimum # of repeats 2 of pollin
[Mar 03 07:07:44:134839] pilight-daemon: DEBUG: called pollin parseRaw()
*** Error in `/root/pilight/build/pilight-daemon': double free or corruption (fasttop): 0x75702678 ***
[Mar 03 07:07:44:135823] pilight-daemon: INFO: executed rule: ResetAlarmState
[Mar 03 07:07:44:136212] pilight-daemon: DEBUG: rule #2 ResetAlarmState was parsed in 0.420814 seconds
[Mar 03 07:07:44:135807] pilight-daemon: DEBUG: socket write succeeded: {"message":{"unitcode":1026751,"state":"closed"},"origin":"receiver","protocol":"ev1527","uuid":"0000-b8-27-eb-83c3cc","repeats":2}

[Mar 03 07:07:44:136869] pilight-daemon: DEBUG: broadcasted: {"message":{"unitcode":1026751,"state":"closed"},"origin":"receiver","protocol":"ev1527","uuid":"0000-b8-27-eb-83c3cc","repeats":2}
[Mar 03 07:07:44:138222] pilight-daemon: DEBUG: aborting previous "label" action for device "PIRlabel"
[Mar 03 07:07:44:139341] pilight-daemon: DEBUG: socket write succeeded: {"message":{"systemcode":7,"unitcode":24,"state":"off"},"origin":"receiver","protocol":"pollin","uuid":"0000-b8-27-eb-83c3cc","repeats":2}

[Mar 03 07:07:44:139467] pilight-daemon: DEBUG: broadcasted: {"message":{"systemcode":7,"unitcode":24,"state":"off"},"origin":"receiver","protocol":"pollin","uuid":"0000-b8-27-eb-83c3cc","repeats":2}

Program received signal SIGABRT, Aborted.
[Switching to Thread 0x6cace460 (LWP 24673)]
0x76b33f70 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
56      ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.

Code:

(gdb) backtrace
#0  0x76b33f70 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#1  0x76b35324 in __GI_abort () at abort.c:89
#2  0x76b6f954 in __libc_message (do_abort=<optimized out>, fmt=0x76c256e8 "*** Error in `%s': %s: 0x%s ***\n")
    at ../sysdeps/posix/libc_fatal.c:175
#3  0x76b75b80 in malloc_printerr (action=1, str=0x76c25924 "double free or corruption (fasttop)", ptr=<optimized out>)
    at malloc.c:4996
#4  0x76b76b24 in _int_free (av=<optimized out>, p=<optimized out>, have_lock=0) at malloc.c:3840
#5  0x0003f088 in json_delete (node=0x75702678) at /root/pilight/libs/pilight/core/json.c:432
#6  0x00022b30 in send_queue (json=0x75701bc0, origin=ACTION) at /root/pilight/daemon.c:850
#7  0x00023a88 in control_device (dev=0x8c7e18, state=0x75702dc8 "on", values=0x0, origin=ACTION) at /root/pilight/daemon.c:1112
#8  0x00088c84 in thread (param=0x8c7e90) at /root/pilight/libs/pilight/events/actions/switch.c:387
#9  0x76f0ae90 in start_thread (arg=0x6cace460) at pthread_create.c:311
#10 0x76bd7598 in ?? () at ../ports/sysdeps/unix/sysv/linux/arm/nptl/../clone.S:92 from /lib/arm-linux-gnueabihf/libc.so.6
Backtrace stopped: previous frame identical to this frame (corrupt stack?)
(gdb)

Code:

(gdb) frame 10
#10 0x76bd7598 in ?? () at ../ports/sysdeps/unix/sysv/linux/arm/nptl/../clone.S:92 from /lib/arm-linux-gnueabihf/libc.so.6
92      ../ports/sysdeps/unix/sysv/linux/arm/nptl/../clone.S: No such file or directory.
(gdb) frame 9
#9  0x76f0ae90 in start_thread (arg=0x6cace460) at pthread_create.c:311
311     pthread_create.c: No such file or directory.
(gdb) frame 8
#8  0x00088c84 in thread (param=0x8c7e90) at /root/pilight/libs/pilight/events/actions/switch.c:387
387                                                                     pilight.control(pth->device, new_state, NULL, ACTION);
(gdb) frame 7
#7  0x00023a88 in control_device (dev=0x8c7e18, state=0x75702dc8 "on", values=0x0, origin=ACTION) at /root/pilight/daemon.c:1112
1112            if(send_queue(json, origin) == 0) {
(gdb) frame 6
#6  0x00022b30 in send_queue (json=0x75701bc0, origin=ACTION) at /root/pilight/daemon.c:850
850                                                             json_delete(protocol->message);
(gdb) frame 5
#5  0x0003f088 in json_delete (node=0x75702678) at /root/pilight/libs/pilight/core/json.c:432
432                     free(node);
(gdb) frame 4
#4  0x76b76b24 in _int_free (av=<optimized out>, p=<optimized out>, have_lock=0) at malloc.c:3840
3840    malloc.c: No such file or directory.
(gdb) frame 4
#4  0x76b76b24 in _int_free (av=<optimized out>, p=<optimized out>, have_lock=0) at malloc.c:3840
3840    in malloc.c
(gdb) frame 3
#3  0x76b75b80 in malloc_printerr (action=1, str=0x76c25924 "double free or corruption (fasttop)", ptr=<optimized out>)
    at malloc.c:4996
4996    in malloc.c
(gdb) frame 2
#2  0x76b6f954 in __libc_message (do_abort=<optimized out>, fmt=0x76c256e8 "*** Error in `%s': %s: 0x%s ***\n")
    at ../sysdeps/posix/libc_fatal.c:175
175     ../sysdeps/posix/libc_fatal.c: No such file or directory.
(gdb) frame 2
#2  0x76b6f954 in __libc_message (do_abort=<optimized out>, fmt=0x76c256e8 "*** Error in `%s': %s: 0x%s ***\n")
    at ../sysdeps/posix/libc_fatal.c:175
175     in ../sysdeps/posix/libc_fatal.c
(gdb) frame 1
#1  0x76b35324 in __GI_abort () at abort.c:89
89      abort.c: No such file or directory.
(gdb) frame 0
#0  0x76b33f70 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
56      ../nptl/sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb)