darrylb123 / usbrelay

Control usb relay - based on hidapi
GNU General Public License v2.0
315 stars 98 forks source link

free(): invalid next size (fast) #69

Closed mloeser21 closed 3 years ago

mloeser21 commented 3 years ago

Hi,

Following the relevant snippet of my Python code:

try: proc = subprocess.run(set_cmd, capture_output=True, universal_newlines=True, check=True, shell=False, timeout=1, encoding='UTF-8') except subprocess.CalledProcessError as e: print(f"ERROR ({fname}): stderr={e.stderr}, stdout={e.stdout}")

(sorry - I couldn't find a way to keep the indentation alive)

set_cmd is basically an array like the following: ['/usr/bin/usbrelay', 'GPIOS_1=1', 'GPIOS_2=0', 'GPIOS_3=1', 'GPIOS_4=0']

Quite often I see a failure while looping over all permutations of any of my relays:

CMD: /usr/bin/usbrelay WAKES_1=1 WAKES_2=0 WAKES_3=1 WAKES_4=1 CMD: /usr/bin/usbrelay WAKES_1=1 WAKES_2=1 WAKES_3=0 WAKES_4=0 CMD: /usr/bin/usbrelay WAKES_1=1 WAKES_2=1 WAKES_3=0 WAKES_4=1 ERROR (read_dct_relays): stderr=free(): invalid next size (fast) , stdout= CMD: /usr/bin/usbrelay WAKES_1=1 WAKES_2=1 WAKES_3=1 WAKES_4=0 CMD: /usr/bin/usbrelay WAKES_1=1 WAKES_2=1 WAKES_3=1 WAKES_4=1

Where does this failure "free(): invalid next size (fast)" come from? System is running Ubuntu LTS 16.04 on an x86 PC.

Debug output:

$ /usr/bin/usbrelay --debug Version: 0.7-50-g8f6b7fd1ea Library Version: 0.7-50-g8f6b7fd1ea enumerate_relay_boards()Found 3 devices Device Found type: 16c0 05df path: /dev/hidraw4 serial_number: GPIOS Manufacturer: www.dcttech.com Product: USBRelay4 Release: 100 Interface: 0 Number of Relays = 4 Module_type = 1 GPIOS_1=0 GPIOS_2=0 GPIOS_3=0 GPIOS_4=0 Device Found type: 16c0 05df path: /dev/hidraw5 serial_number: WAKES Manufacturer: www.dcttech.com Product: USBRelay4 Release: 100 Interface: 0 Number of Relays = 4 Module_type = 1 WAKES_1=0 WAKES_2=0 WAKES_3=0 WAKES_4=0 Device Found type: 16c0 05df path: /dev/hidraw3 serial_number: ERTSW Manufacturer: www.dcttech.com Product: USBRelay4 Release: 100 Interface: 0 Number of Relays = 4 Module_type = 1 ERTSW_1=0 ERTSW_2=0 ERTSW_3=0 ERTSW_4=0

darrylb123 commented 3 years ago

Why don't you use the python library rather than running commands? Follow the docs on how to build the latest libraries.

Darryl

On Tue, 31 Aug 2021, 3:57 pm Matthias Loeser, @.***> wrote:

Hi,

Following the relevant snippet of my Python code:

try: proc = subprocess.run(set_cmd, capture_output=True, universal_newlines=True, check=True, shell=False, timeout=1, encoding='UTF-8') except subprocess.CalledProcessError as e: print(f"ERROR ({fname}): stderr={e.stderr}, stdout={e.stdout}")

set_cmd is basically an array like the following: ['/usr/bin/usbrelay', 'GPIOS_1=1', 'GPIOS_2=0', 'GPIOS_3=1', 'GPIOS_4=0']

Quite often I see a failure while looping over all permutations of any of my relays:

CMD: /usr/bin/usbrelay WAKES_1=1 WAKES_2=0 WAKES_3=1 WAKES_4=1 CMD: /usr/bin/usbrelay WAKES_1=1 WAKES_2=1 WAKES_3=0 WAKES_4=0 CMD: /usr/bin/usbrelay WAKES_1=1 WAKES_2=1 WAKES_3=0 WAKES_4=1 ERROR (read_dct_relays): stderr=free(): invalid next size (fast) , stdout= CMD: /usr/bin/usbrelay WAKES_1=1 WAKES_2=1 WAKES_3=1 WAKES_4=0 CMD: /usr/bin/usbrelay WAKES_1=1 WAKES_2=1 WAKES_3=1 WAKES_4=1

Where does this failure "free(): invalid next size (fast)" come from? System is running Ubuntu LTS 16.04 on an x86 PC.

Debug output:

$ /usr/bin/usbrelay --debug Version: 0.7-50-g8f6b7fd1ea Library Version: 0.7-50-g8f6b7fd1ea enumerate_relay_boards()Found 3 devices Device Found type: 16c0 05df path: /dev/hidraw4 serial_number: GPIOS Manufacturer: www.dcttech.com Product: USBRelay4 Release: 100 Interface: 0 Number of Relays = 4 Module_type = 1 GPIOS_1=0 GPIOS_2=0 GPIOS_3=0 GPIOS_4=0 Device Found type: 16c0 05df path: /dev/hidraw5 serial_number: WAKES Manufacturer: www.dcttech.com Product: USBRelay4 Release: 100 Interface: 0 Number of Relays = 4 Module_type = 1 WAKES_1=0 WAKES_2=0 WAKES_3=0 WAKES_4=0 Device Found type: 16c0 05df path: /dev/hidraw3 serial_number: ERTSW Manufacturer: www.dcttech.com Product: USBRelay4 Release: 100 Interface: 0 Number of Relays = 4 Module_type = 1 ERTSW_1=0 ERTSW_2=0 ERTSW_3=0 ERTSW_4=0

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub https://github.com/darrylb123/usbrelay/issues/69, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABTSUVJKZ2FMC36GH7HMTDLT7RVLBANCNFSM5DDKVJRQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

wentasah commented 3 years ago

The error comes from libc memory allocator. It looks like there is an memory corruption.

I tried the latest version compiled with address sanitizer:

make CFLAGS="-fsanitize=address -g -Og" clean all

and it reveals we have some heap overflows:

==88268==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x603000002ca8 at pc 0x7f41ae19a7d1 bp 0x7ffeb1da5da0 sp 0x7ffeb1da5d98
WRITE of size 4 at 0x603000002ca8 thread T0
    #0 0x7f41ae19a7d0 in enumerate_relay_boards /home/wsh/src/usbrelay/libusbrelay.c:76
    #1 0x4029ac in main /home/wsh/src/usbrelay/usbrelay.c:175
    #2 0x7f41adff277f in __libc_start_main (/nix/store/9bh3986bpragfjmr32gay8p95k91q4gy-glibc-2.33-47/lib/libc.so.6+0x2777f)
    #3 0x402239 in _start (/home/wsh/src/usbrelay/usbrelay+0x402239)

0x603000002ca8 is located 16 bytes to the right of 24-byte region [0x603000002c80,0x603000002c98)
allocated by thread T0 here:
    #0 0x7f41ae24aff7 in __interceptor_calloc (/nix/store/0kiykyrnrpfhmjwxwx89kxr20hmf5304-gcc-10.3.0-lib/lib/libasan.so.6+0xacff7)
    #1 0x7f41ae19a79e in enumerate_relay_boards /home/wsh/src/usbrelay/libusbrelay.c:69

SUMMARY: AddressSanitizer: heap-buffer-overflow /home/wsh/src/usbrelay/libusbrelay.c:76 in enumerate_relay_boards
Shadow bytes around the buggy address:
  0x0c067fff8540: fa fa fd fd fd fa fa fa fd fd fd fa fa fa fd fd
  0x0c067fff8550: fd fa fa fa fd fd fd fa fa fa fd fd fd fa fa fa
  0x0c067fff8560: fd fd fd fa fa fa fd fd fd fa fa fa fd fd fd fa
  0x0c067fff8570: fa fa fd fd fd fa fa fa fd fd fd fa fa fa fd fd
  0x0c067fff8580: fd fa fa fa fd fd fd fa fa fa fd fd fd fa fa fa
=>0x0c067fff8590: 00 00 00 fa fa[fa]fd fd fd fa fa fa fa fa fa fa
  0x0c067fff85a0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c067fff85b0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c067fff85c0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c067fff85d0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
  0x0c067fff85e0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Container overflow:      fc
  Array cookie:            ac
  Intra object redzone:    bb
  ASan internal:           fe
  Left alloca redzone:     ca
  Right alloca redzone:    cb
  Shadow gap:              cc
==88268==ABORTING

In my case, the following line was executed with relay==1, but relay_boards has memory only for one board, i.e., relay==0.

relay_boards[relay].module_type = known_relay(cur_dev);
wentasah commented 3 years ago

@mloeser21 Can you verify whether #70 fixes your problem?

darrylb123 commented 3 years ago

Thanks Michal, I can duplicate the sanitize error. I'll see what I can find tomorrow.

Darryl

On Tue, Aug 31, 2021 at 6:08 PM Michal Sojka @.***> wrote:

The error comes from libc memory allocator. It looks like there is an memory corruption.

I tried the latest version compiled with address sanitizer:

make CFLAGS="-fsanitize=address -g -Og" clean all

and it reveals we have some heap overflows:

==88268==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x603000002ca8 at pc 0x7f41ae19a7d1 bp 0x7ffeb1da5da0 sp 0x7ffeb1da5d98 WRITE of size 4 at 0x603000002ca8 thread T0

0 0x7f41ae19a7d0 in enumerate_relay_boards /home/wsh/src/usbrelay/libusbrelay.c:76

#1 0x4029ac in main /home/wsh/src/usbrelay/usbrelay.c:175
#2 0x7f41adff277f in __libc_start_main (/nix/store/9bh3986bpragfjmr32gay8p95k91q4gy-glibc-2.33-47/lib/libc.so.6+0x2777f)
#3 0x402239 in _start (/home/wsh/src/usbrelay/usbrelay+0x402239)

0x603000002ca8 is located 16 bytes to the right of 24-byte region [0x603000002c80,0x603000002c98) allocated by thread T0 here:

0 0x7f41ae24aff7 in __interceptor_calloc (/nix/store/0kiykyrnrpfhmjwxwx89kxr20hmf5304-gcc-10.3.0-lib/lib/libasan.so.6+0xacff7)

#1 0x7f41ae19a79e in enumerate_relay_boards /home/wsh/src/usbrelay/libusbrelay.c:69

SUMMARY: AddressSanitizer: heap-buffer-overflow /home/wsh/src/usbrelay/libusbrelay.c:76 in enumerate_relay_boards Shadow bytes around the buggy address: 0x0c067fff8540: fa fa fd fd fd fa fa fa fd fd fd fa fa fa fd fd 0x0c067fff8550: fd fa fa fa fd fd fd fa fa fa fd fd fd fa fa fa 0x0c067fff8560: fd fd fd fa fa fa fd fd fd fa fa fa fd fd fd fa 0x0c067fff8570: fa fa fd fd fd fa fa fa fd fd fd fa fa fa fd fd 0x0c067fff8580: fd fa fa fa fd fd fd fa fa fa fd fd fd fa fa fa =>0x0c067fff8590: 00 00 00 fa fa[fa]fd fd fd fa fa fa fa fa fa fa 0x0c067fff85a0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c067fff85b0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c067fff85c0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c067fff85d0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c067fff85e0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa Shadow byte legend (one shadow byte represents 8 application bytes): Addressable: 00 Partially addressable: 01 02 03 04 05 06 07 Heap left redzone: fa Freed heap region: fd Stack left redzone: f1 Stack mid redzone: f2 Stack right redzone: f3 Stack after return: f5 Stack use after scope: f8 Global redzone: f9 Global init order: f6 Poisoned by user: f7 Container overflow: fc Array cookie: ac Intra object redzone: bb ASan internal: fe Left alloca redzone: ca Right alloca redzone: cb Shadow gap: cc ==88268==ABORTING

In my case, the following line was executed with relay==1, but relay_boards has memory only for one board, i.e., relay==0.

relay_boards[relay].module_type = known_relay(cur_dev);

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/darrylb123/usbrelay/issues/69#issuecomment-909000178, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABTSUVIV6FIXAGDBHJEBG5TT7SEXNANCNFSM5DDKVJRQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

darrylb123 commented 3 years ago

Found a couple of memory corruption errors with Michal's help. Please try the latest version. BTW, you might like to have a look at the python mqtt daemon that uses the Python library. Using mqtt might even be a better way to achieve what you want. I have used it very successfully with Node Red and Home Assistant.

mloeser21 commented 3 years ago

Hi Darryl / Michal,

I still see the issue after pulling the latest changes:

CMD: /usr/bin/usbrelay GPIOS_1=0 GPIOS_2=1 GPIOS_3=1 GPIOS_4=1 CMD: /usr/bin/usbrelay GPIOS_1=1 GPIOS_2=0 GPIOS_3=0 GPIOS_4=0 ERROR (read_dct_relays): stderr=free(): invalid next size (fast) , stdout= CMD: /usr/bin/usbrelay GPIOS_1=1 GPIOS_2=0 GPIOS_3=0 GPIOS_4=1 CMD: /usr/bin/usbrelay GPIOS_1=1 GPIOS_2=0 GPIOS_3=1 GPIOS_4=0

Same from the cmdline every ~9-10 invocations:

$ /usr/bin/usbrelay GPIOS_1=0 GPIOS_2=1 GPIOS_3=1 GPIOS_4=1 GPIOS_1=0 GPIOS_2=1 GPIOS_3=1 GPIOS_4=1 WAKES_1=0 WAKES_2=0 WAKES_3=0 WAKES_4=0 ERTSW_1=0 ERTSW_2=0 ERTSW_3=0 ERTSW_4=0 free(): invalid next size (fast) Aborted (core dumped)

$ /usr/bin/usbrelay --debug Version: 0.7-56-g1e1745567b Library Version: 0.7-50-g8f6b7fd1ea enumerate_relay_boards()Found 3 devices Device Found type: 16c0 05df path: /dev/hidraw4 serial_number: GPIOS Manufacturer: www.dcttech.com Product: USBRelay4 Release: 100 Interface: 0 Number of Relays = 4 Module_type = 1 GPIOS_1=0 GPIOS_2=0 GPIOS_3=0 GPIOS_4=0 Device Found type: 16c0 05df path: /dev/hidraw5 serial_number: WAKES Manufacturer: www.dcttech.com Product: USBRelay4 Release: 100 Interface: 0 Number of Relays = 4 Module_type = 1 WAKES_1=0 WAKES_2=0 WAKES_3=0 WAKES_4=0 Device Found type: 16c0 05df path: /dev/hidraw3 serial_number: ERTSW Manufacturer: www.dcttech.com Product: USBRelay4 Release: 100 Interface: 0 Number of Relays = 4 Module_type = 1 ERTSW_1=0 ERTSW_2=0 ERTSW_3=0 ERTSW_4=0

mloeser21 commented 3 years ago

Why don't you use the python library rather than running commands? Follow the docs on how to build the latest libraries. Darryl

... because I'm trying to replicate the path taken by our integration test framework which has a few scattered elements; i.e. some invocations are from within Python, some from shell scripts, etc. We've seen some failures across those DCT relays, so I'm trying to write a relay test to assess their health on a regular (i.e. daily) basis.

darrylb123 commented 3 years ago

Matthias, I can't seem to generate the problem on Fedora 34. Used an 8 way relay with the same serial as yours + a 2 way relay. Can you build it with sanitize as Michal did and try again to get some kind of hint wher the problem lies. It seem the error is from corrupting memory after malloc. You'll need to install libasan.

make CFLAGS="-fsanitize=address -g -Og" clean all

darrylb123 commented 3 years ago

Also use --debug to see if that gives us some more information as to the location.

mloeser21 commented 3 years ago

Ok, not sure what happened, but I am also no longer able to repro, after ~500+ runs (even w/ different compile options / optimizations). So I am closing this ticket and will update you if somehow I can reproduce it going fwd. Thank you guys very much for looking into this and providing the fix for the related issues you were able to find!

darrylb123 commented 3 years ago

Maybe the updated library wasn't installed. I've done that before, run the new executable against an old library. If you run it --debug, it prints both the library and executable version.

On Wed, 1 Sep 2021, 1:05 pm Matthias Loeser, @.***> wrote:

Closed #69 https://github.com/darrylb123/usbrelay/issues/69.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/darrylb123/usbrelay/issues/69#event-5236414398, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABTSUVOMXNLE7ZMA26HNJMLT7WJ7RANCNFSM5DDKVJRQ . Triage notifications on the go with GitHub Mobile for iOS https://apps.apple.com/app/apple-store/id1477376905?ct=notification-email&mt=8&pt=524675 or Android https://play.google.com/store/apps/details?id=com.github.android&referrer=utm_campaign%3Dnotification-email%26utm_medium%3Demail%26utm_source%3Dgithub.

mloeser21 commented 3 years ago

Yes, looks like you're spot on. What I have now is Version: 0.7-56-g1e1745567b Library Version: 0.7-56-g1e1745567b

previously - when reproduced it showed

Version: 0.7-56-g1e1745567b Library Version: 0.7-50-g8f6b7fd1ea <<< different

Thanks for pointing that out.

darrylb123 commented 3 years ago

I committed a change that gives a warning if the library is a different version to the executable. Might help in future.