search

knxd / knxd

GNU General Public License v2.0
537 stars 201 forks source link

KNXD stop running (USB) #366

Open ptorrent opened 5 years ago

ptorrent commented 5 years ago

Hello,

I'm using master branch ( 0.14.25). I'm able to connect to USB device. As soon as I write a value on the bus (by pressing a switch) KNXD stops.

 knxd -t 0xffff -e 15.15.250 -E 15.15.251:4 -DTR --Server=224.0.23.12:3671 -u /tmp/knxd_72 -i 33671 -b usb:
DATA RECEIVED !!!

[13.696184] [0000287f] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[13.696236] [0000287f] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[13.696263] [0000287f] libusb: debug [handle_events] poll() returned 1
[13.696292] [0000287f] libusb: debug [reap_for_handle] urb type=1 status=0 transferred=64
[13.696306] [0000287f] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[13.696320] [0000287f] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[13.696338] [0000287f] libusb: debug [usbi_handle_transfer_completion] transfer 0x1a70a58 has callback 0x44f64
Layer 10 [18:C.usb/usbL        13.697] RecvCB 1a70a58
Layer 10 [18:C.usb/usbL        13.697] RecvComplete 1a70a58 64
Layer 0 [18:C.usb/usbL        13.697] RecvUSB(064): 01 13 11 00 08 00 09 01 01 00 00 49 BC 11 01 19 01 E1 00 80 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
Layer 0 [17:C.usb/Conv        13.697] RecvEMI(009): 49 BC 11 01 19 01 E1 00 80
Layer 8 [ 1:main              13.697] unknown addr 1.1.1
[13.696541] [0000287f] libusb: debug [libusb_submit_transfer] transfer 0x1a70a58
[13.696557] [0000287f] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 64
Layer 10 [18:C.usb/usbL        13.697] StartRecv
Layer 6 [19:router/ConnC      13.697] sending, send_more clear
Layer 1 [ 4:server/Server     13.697] Send(011): 29 00 BC D0 11 01 19 01 01 00 80
Layer 2 [21:router.pace_/router 13.697] out 1/2: delay for 0.017 sec
Layer 6 [19:router/ConnC      13.697] still waiting
Layer 6 [ 1:main              13.697] wait L
Layer 0 [ 4:server/Server     13.697] Send(017): 06 10 05 30 00 11 29 00 BC D0 11 01 19 01 01 00 80
Layer 0 [ 4:server/Server     13.697] Send: Operation not permitted
Layer 0 [ 4:server/Server     13.697] Send(017): 06 10 05 30 00 11 29 00 BC D0 11 01 19 01 01 00 80
Layer 0 [ 4:server/Server     13.697] Send: Operation not permitted
Layer 0 [ 4:server/Server     13.697] Send(017): 06 10 05 30 00 11 29 00 BC D0 11 01 19 01 01 00 80
Layer 0 [ 4:server/Server     13.698] Send: Operation not permitted
Layer 0 [ 4:server/Server     13.698] Send(017): 06 10 05 30 00 11 29 00 BC D0 11 01 19 01 01 00 80
Layer 0 [ 4:server/Server     13.698] Send: Operation not permitted
Layer 0 [ 4:server/Server     13.698] Send(017): 06 10 05 30 00 11 29 00 BC D0 11 01 19 01 01 00 80
Layer 0 [ 4:server/Server     13.698] Send: Operation not permitted
Layer 0 [ 4:server/Server     13.698] Send(017): 06 10 05 30 00 11 29 00 BC D0 11 01 19 01 01 00 80
Layer 0 [ 4:server/Server     13.698] Send: Operation not permitted
Layer 0 [ 4:server/Server     13.698] Send(017): 06 10 05 30 00 11 29 00 BC D0 11 01 19 01 01 00 80
Layer 0 [ 4:server/Server     13.698] Send: Operation not permitted
Layer 0 [ 4:server/Server     13.698] EIBnetSocket:drop(017): 06 10 05 30 00 11 29 00 BC D0 11 01 19 01 01 00 80
E00000023: [ 4:server] Communication error: Operation not permitted
Layer 5 [19:router/ConnC      13.698] Stopping
Layer 5 [19:router/ConnC      13.698] up => down
Layer 5 [19:router/ConnC      13.698] Stopping
Layer 4 [19:router/ConnC      13.698] down
Layer 3 [19:router/ConnC      13.698] unregisterLink: router_19
Layer 0 [ 4:server/Server     13.698] Close
Layer 5 [ 4:server/Server     13.698] up => down
Layer 4 [ 4:server/Server     13.698] down
Layer 4 [ 1:main              13.698] check start
Layer 8 [20:router/driver     13.698] CloseD
Layer 4 [ 4:server/Server     13.698] is down
Layer 4 [ 1:main              13.698] check end: want_up 1 some 1>1 all 1>0, going 0 up 3 down 1
F00000000: [ 4:server] Link down, terminating
Layer 4 [ 1:main              13.698] trigger Going down
Layer 4 [ 9:A.unix/local      13.698] Stopping
Layer 5 [ 9:A.unix/local      13.698] up => >down
Layer 8 [ 9:A.unix/local      13.699] StopServer
Layer 5 [ 9:A.unix/local      13.699] >down => down
Layer 4 [ 9:A.unix/local      13.699] down
Layer 4 [ 9:A.unix/local      13.699] down
Layer 4 [12:B.tcp/inet        13.699] Stopping
Layer 5 [12:B.tcp/inet        13.699] up => >down
Layer 8 [12:B.tcp/inet        13.699] StopServer
Layer 5 [12:B.tcp/inet        13.699] >down => down
Layer 4 [12:B.tcp/inet        13.699] down
Layer 4 [12:B.tcp/inet        13.699] down
Layer 4 [ 4:server/Server     13.699] Stopping
Layer 5 [ 4:server/Server     13.699] down => >down
Layer 4 [ 4:server/Server     13.699] down
Layer 4 [15:C.usb/Conn        13.699] Stopping
Layer 5 [15:C.usb/Conn        13.699] up => >down
Layer 5 [15:C.usb/Conn        13.699] Stopping
Layer 2 [22:C.usb/EMI1        13.699] CloseL2
Layer 0 [22:C.usb/EMI1        13.699] starting send_Local
Layer 0 [17:C.usb/Conv        13.699] Send-EMI(005): 46 01 00 60 C0
Layer 0 [18:C.usb/usbL        13.699] SendUSB(064): 01 13 0D 00 08 00 05 01 01 00 00 46 01 00 60 C0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[13.698585] [0000287f] libusb: debug [libusb_alloc_transfer] transfer 0x1a6f690
[13.698612] [0000287f] libusb: debug [libusb_submit_transfer] transfer 0x1a6f690
[13.698626] [0000287f] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[13.698648] [0000287f] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 64
Layer 0 [18:C.usb/usbL        13.699] StartSend 1a6f690
Layer 4 [15:C.usb/Conn        13.699] >down
Layer 4 [ 1:main              13.699] check start
Layer 4 [ 9:A.unix/local      13.699] is down
Layer 4 [12:B.tcp/inet        13.699] is down
Layer 4 [ 4:server/Server     13.699] is down
Layer 4 [15:C.usb/Conn        13.699] is >down
Layer 4 [ 1:main              13.699] check end: want_up 0 some 1>1 all 0>0, going 1 up 0 down 3
[14.530204] [0000287f] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[14.530274] [0000287f] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[14.530310] [0000287f] libusb: debug [handle_events] poll() returned 1
[14.530347] [0000287f] libusb: debug [reap_for_handle] urb type=1 status=0 transferred=64
[14.530374] [0000287f] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[14.530401] [0000287f] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[14.530427] [0000287f] libusb: debug [disarm_timerfd]
[14.530460] [0000287f] libusb: debug [usbi_handle_transfer_completion] transfer 0x1a6f690 has callback 0x450d8
Layer 10 [18:C.usb/usbL        14.531] SendCB 1a6f690
Layer 10 [18:C.usb/usbL        14.531] SendComplete 1a6f690 64
[14.530593] [0000287f] libusb: debug [libusb_free_transfer] transfer 0x1a6f690
Layer 0 [22:C.usb/EMI1        14.531] send_Local done
Layer 1 [18:C.usb/usbL        14.531] Close
[14.530693] [0000287f] libusb: debug [libusb_cancel_transfer] transfer 0x1a70a58
[14.530764] [0000287f] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[14.530792] [0000287f] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[14.530821] [0000287f] libusb: debug [handle_events] poll() returned 1
[14.530849] [0000287f] libusb: debug [reap_for_handle] urb type=1 status=-2 transferred=0
[14.530874] [0000287f] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[14.530900] [0000287f] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[14.530923] [0000287f] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[14.530995] [0000287f] libusb: debug [usbi_handle_transfer_completion] transfer 0x1a70a58 has callback 0x44f64
Layer 10 [18:C.usb/usbL        14.532] RecvCB 1a70a58
Layer 10 [18:C.usb/usbL        14.532] RecvComplete 1a70a58 0
Layer 5 [15:C.usb/Conn        14.532] >down => down/error
Layer 4 [15:C.usb/Conn        14.532] >down/error
Layer 1 [18:C.usb/usbL        14.532] Release
[14.531227] [0000287f] libusb: debug [libusb_release_interface] interface 0
[14.531335] [0000287f] libusb: debug [libusb_attach_kernel_driver] interface 0
[14.543775] [0000287f] libusb: debug [libusb_close]
[14.543854] [0000287f] libusb: debug [usbi_remove_pollfd] remove fd 13
Layer 10 [18:C.usb/usbL        14.544] USBLoop read 10
Layer 10 [18:C.usb/usbL        14.544] USBLoop read 12
[14.544055] [0000287f] libusb: debug [libusb_exit]
[14.544093] [0000287f] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[14.544147] [0000287f] libusb: debug [handle_events] poll fds modified, reallocating
[14.544186] [0000287f] libusb: debug [handle_events] poll() 2 fds with timeout in 0ms
[14.544221] [0000287f] libusb: debug [handle_events] poll() returned 0
[14.544249] [0000287f] libusb: debug [libusb_unref_device] destroy device 1.5
[14.544278] [0000287f] libusb: debug [libusb_unref_device] destroy device 1.4
[14.544304] [0000287f] libusb: debug [libusb_unref_device] destroy device 1.3
[14.544331] [0000287f] libusb: debug [libusb_unref_device] destroy device 1.2
[14.544357] [0000287f] libusb: debug [libusb_unref_device] destroy device 1.1
[14.544383] [0000287f] libusb: debug [usbi_remove_pollfd] remove fd 10
Layer 10 [18:C.usb/usbL        14.545] USBLoop read 12
[14.544531] [0000287f] libusb: debug [usbi_remove_pollfd] remove fd 12
Layer 5 [15:C.usb/Conn        14.545] >down/error => down
Layer 4 [15:C.usb/Conn        14.545] down/error
Layer 4 [ 1:main              14.545] check start
Layer 4 [ 9:A.unix/local      14.545] is down
Layer 4 [12:B.tcp/inet        14.545] is down
Layer 4 [ 4:server/Server     14.545] is down
Layer 4 [15:C.usb/Conn        14.545] is down
Layer 4 [ 1:main              14.545] check end: want_up 0 some 1>0 all 0>0, going 0 up 0 down 4
Layer 4 [ 1:main              14.545] down
Layer 4 [ 1:main              14.545] deleting
Layer 8 [ 9:A.unix/local      14.545] StopServer
Layer 8 [12:B.tcp/inet        14.545] StopServer
Layer 8 [ 4:server/Server     14.545] Close
Layer 1 [18:C.usb/usbL        14.546] Close
Layer 1 [18:C.usb/usbL        14.546] Release
Layer 4 [ 1:main              14.546] deleted.

Second example: 

Layer 0 [ 4:server/Server      18.567] Recv(024): 06 10 02 05 00 18 08 01 0A 0A 0A E8 D4 14 08 01 0A 0A 0A E8 D4 15 02 03
Layer 8 [ 4:server/Server      18.568] Tunnel CONNECTION_REQ, no addr (mgmt)
Layer 9 [25:tunnel/0.0.0       18.568] has 0.0.0
Layer 8 [25:tunnel/0.0.0       18.568] Start Conn 2
Layer 3 [24:tunnel/ConnC       18.568] registerLink: 24:tunnel_24
Layer 3 [24:tunnel/ConnC       18.568] Start: cfg:tunnel
Layer 5 [24:tunnel/ConnC       18.569] down => >up
Layer 5 [24:tunnel/ConnC       18.569] Starting
Layer 5 [24:tunnel/ConnC       18.569] >up => up
Layer 4 [24:tunnel/ConnC       18.569] up
Layer 5 [24:tunnel/ConnC       18.569] Started
Layer 4 [24:tunnel/ConnC       18.569] up
Layer 1 [ 4:server/Server      18.569] Send(012): 02 00 08 01 0A 0A 0A D3 0E 57 02 03
Layer 4 [ 1:main               18.569] check start
Layer 4 [ 1:main               18.569] check end: want_up 1 some 1>1 all 0>1, going 0 up 4 down 0
Layer 0 [ 4:server/Server      18.569] Send(018): 06 10 02 06 00 12 02 00 08 01 0A 0A 0A D3 0E 57 02 03
Layer 0 [ 4:server/Server      18.577] Recv(017): 06 10 03 10 00 11 04 02 00 00 FC 00 00 01 53 10 01
Layer 8 [ 4:server/Server      18.578] CONFIG_REQ on 2
Layer 1 [ 4:server/Server      18.578] Send(004): 04 02 00 00
Layer 1 [ 4:server/Server      18.578] Send(012): 04 02 00 00 FB 00 00 01 53 00 01 00
Layer 0 [ 4:server/Server      18.578] Send(010): 06 10 03 11 00 0A 04 02 00 00
Layer 0 [ 4:server/Server      18.579] Send(018): 06 10 03 10 00 12 04 02 00 00 FB 00 00 01 53 00 01 00
Layer 0 [ 4:server/Server      18.581] Recv(010): 06 10 03 11 00 0A 04 02 00 00
Layer 8 [25:tunnel/0.0.0       18.581] CONFIG_ACK
Layer 0 [ 4:server/Server      18.584] Recv(014): 06 10 02 03 00 0E 08 01 0A 0A 0A E8 D4 14
Layer 8 [ 4:server/Server      18.584] DESCRIBE
Layer 1 [ 4:server/Server      18.584] Send(062): 36 01 02 00 FF FA 00 00 00 00 00 00 00 00 E0 00 17 0C B8 27 EB 9A DA D6 6B 6E 78 64 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 08 02 02 01 03 01 04 01
Layer 0 [ 4:server/Server      18.585] Send(068): 06 10 02 04 00 44 36 01 02 00 FF FA 00 00 00 00 00 00 00 00 E0 00 17 0C B8 27 EB 9A DA D6 6B 6E 78 64 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 08 02 02 01 03 01 04 01
Layer 0 [ 4:server/Server      18.589] Recv(017): 06 10 03 10 00 11 04 02 01 00 FC 00 00 01 38 10 01
Layer 8 [ 4:server/Server      18.589] CONFIG_REQ on 2
Layer 1 [ 4:server/Server      18.589] Send(004): 04 02 01 00
Layer 1 [ 4:server/Server      18.589] Send(012): 04 02 01 00 FB 00 00 01 38 00 01 00
Layer 0 [ 4:server/Server      18.590] Send(010): 06 10 03 11 00 0A 04 02 01 00
Layer 0 [ 4:server/Server      18.590] Send(018): 06 10 03 10 00 12 04 02 01 00 FB 00 00 01 38 00 01 00
Layer 0 [ 4:server/Server      18.600] Recv(010): 06 10 03 11 00 0A 04 02 01 00
Layer 8 [25:tunnel/0.0.0       18.601] CONFIG_ACK
Layer 0 [ 4:server/Server      18.601] Recv(016): 06 10 02 09 00 10 02 00 08 01 0A 0A 0A E8 D4 14
Layer 8 [25:tunnel/0.0.0       18.601] DISCONNECT_REQUEST
Layer 8 [25:tunnel/0.0.0       18.601] Stop Conn 2
Layer 5 [24:tunnel/ConnC       18.601] up => down
Layer 5 [24:tunnel/ConnC       18.601] Stopping
Layer 8 [25:tunnel/0.0.0       18.601] Stop Conn 2
Layer 4 [24:tunnel/ConnC       18.601] down
Layer 1 [ 4:server/Server      18.601] Send(002): 02 00
Layer 4 [ 1:main               18.601] check start
Layer 4 [ 1:main               18.601] check end: want_up 1 some 1>1 all 1>1, going 0 up 4 down 0
Layer 3 [24:tunnel/ConnC       18.602] unregisterLink: tunnel_24
Layer 8 [25:tunnel/0.0.0       18.602] CloseS
Layer 0 [ 4:server/Server      18.602] Send(008): 06 10 02 0A 00 08 02 00
Layer 4 [ 1:main               18.602] check start
Layer 4 [ 1:main               18.602] check end: want_up 1 some 1>1 all 1>1, going 0 up 4 down 0
Layer 0 [ 4:server/Server      18.625] Recv(021): 06 10 04 20 00 15 04 01 00 00 11 00 BC E0 00 00 09 01 01 00 80
Layer 8 [22:tunnel/15.15.251   18.625] TUNNEL_REQ
Layer 8 [21:tunnel/ConnC       18.625] found addr 15.15.251
Layer 1 [ 4:server/Server      18.626] Send(004): 04 01 00 00
Layer 6 [13:C.usb/Conn         18.626] sending, send_more clear
E00000000: [20:C.usb] EMI_common: send while waiting
Layer 6 [ 4:server/Server      18.626] is OK
Layer 6 [ 7:A.unix/local       18.626] is OK
Layer 6 [21:tunnel/ConnC       18.626] is OK
Layer 6 [10:B.tcp/inet         18.626] is OK
Layer 6 [13:C.usb/Conn         18.626] still waiting
Layer 6 [ 1:main               18.626] wait L
Layer 1 [ 4:server/Server      18.626] Send(015): 04 01 00 00 2E 00 BC E0 00 00 09 01 01 00 80
Layer 0 [ 4:server/Server      18.627] Send(010): 06 10 04 21 00 0A 04 01 00 00
Layer 0 [ 4:server/Server      18.627] Send(021): 06 10 04 20 00 15 04 01 00 00 2E 00 BC E0 00 00 09 01 01 00 80
Layer 0 [ 4:server/Server      18.630] Recv(010): 06 10 04 21 00 0A 04 01 00 00
Layer 8 [22:tunnel/15.15.251   18.630] TUNNEL_ACK

E00000055: [13:C.usb] Driver timed out trying to send (C.usb)
Layer 5 [13:C.usb/Conn         28.636] up => down/error
Layer 4 [13:C.usb/Conn         28.636] up/error
Layer 4 [ 1:main               28.636] check start
Layer 5 [13:C.usb/Conn         28.636] Stopping
Layer 2 [20:C.usb/EMI1         28.636] CloseL2
Layer 0 [20:C.usb/EMI1         28.636] starting send_Local
Layer 0 [15:C.usb/Conv         28.636] Send-EMI(005): 46 01 00 60 C0
Layer 0 [16:C.usb/usbL         28.636] SendUSB(064): 01 13 0D 00 08 00 05 01 01 00 00 46 01 00 60 C0 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
[28.634328] [000065b4] libusb: debug [libusb_alloc_transfer] transfer 0x80d998
[28.634376] [000065b4] libusb: debug [libusb_submit_transfer] transfer 0x80d998
[28.634404] [000065b4] libusb: debug [add_to_flying_list] arm timerfd for timeout in 1000ms (first in line)
[28.634444] [000065b4] libusb: debug [submit_bulk_transfer] need 1 urbs for new transfer with length 64
Layer 0 [16:C.usb/usbL         28.637] StartSend 80d998
Layer 4 [13:C.usb/Conn         28.637] is up/error
Layer 4 [ 1:main               28.637] check end: want_up 1 some 1>1 all 1>0, going 1 up 3 down 0
[28.924176] [000065b4] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[28.924261] [000065b4] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[28.924326] [000065b4] libusb: debug [handle_events] poll() returned 1
[28.924367] [000065b4] libusb: debug [reap_for_handle] urb type=1 status=0 transferred=64
[28.924399] [000065b4] libusb: debug [handle_bulk_completion] handling completion status 0 of bulk urb 1/1
[28.924430] [000065b4] libusb: debug [handle_bulk_completion] last URB in transfer --> complete!
[28.924462] [000065b4] libusb: debug [disarm_timerfd]
[28.924499] [000065b4] libusb: debug [usbi_handle_transfer_completion] transfer 0x80d998 has callback 0x450d8
Layer 10 [16:C.usb/usbL         28.927] SendCB 80d998
Layer 10 [16:C.usb/usbL         28.927] SendComplete 80d998 64
[28.924757] [000065b4] libusb: debug [libusb_free_transfer] transfer 0x80d998
Layer 0 [20:C.usb/EMI1         28.928] send_Local done
Layer 1 [16:C.usb/usbL         28.928] Close
[28.924912] [000065b4] libusb: debug [libusb_cancel_transfer] transfer 0x808860
[28.924991] [000065b4] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[28.925026] [000065b4] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[28.925060] [000065b4] libusb: debug [handle_events] poll() returned 1
[28.925093] [000065b4] libusb: debug [reap_for_handle] urb type=1 status=-2 transferred=0
[28.925123] [000065b4] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[28.925155] [000065b4] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[28.925183] [000065b4] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[28.925212] [000065b4] libusb: debug [usbi_handle_transfer_completion] transfer 0x808860 has callback 0x44f64
Layer 10 [16:C.usb/usbL         28.928] RecvCB 808860
Layer 10 [16:C.usb/usbL         28.928] RecvComplete 808860 0
Layer 5 [13:C.usb/Conn         28.928] up/error => down/error
Layer 4 [13:C.usb/Conn         28.928] down/error
Layer 1 [16:C.usb/usbL         28.928] Release
[28.925523] [000065b4] libusb: debug [libusb_release_interface] interface 0
[28.925607] [000065b4] libusb: debug [libusb_attach_kernel_driver] interface 0
[28.936816] [000065b4] libusb: debug [libusb_close]
[28.936923] [000065b4] libusb: debug [usbi_remove_pollfd] remove fd 13
Layer 10 [16:C.usb/usbL         28.940] USBLoop read 10
Layer 10 [16:C.usb/usbL         28.940] USBLoop read 12
[28.937154] [000065b4] libusb: debug [libusb_exit]
[28.937195] [000065b4] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[28.937229] [000065b4] libusb: debug [handle_events] poll fds modified, reallocating
[28.937272] [000065b4] libusb: debug [handle_events] poll() 2 fds with timeout in 0ms
[28.937313] [000065b4] libusb: debug [handle_events] poll() returned 0
[28.937347] [000065b4] libusb: debug [libusb_unref_device] destroy device 1.5
[28.937384] [000065b4] libusb: debug [libusb_unref_device] destroy device 1.4
[28.937418] [000065b4] libusb: debug [libusb_unref_device] destroy device 1.3
[28.937451] [000065b4] libusb: debug [libusb_unref_device] destroy device 1.2
[28.937481] [000065b4] libusb: debug [libusb_unref_device] destroy device 1.1
[28.937511] [000065b4] libusb: debug [usbi_remove_pollfd] remove fd 10
Layer 10 [16:C.usb/usbL         28.940] USBLoop read 12
[28.937635] [000065b4] libusb: debug [usbi_remove_pollfd] remove fd 12
Layer 5 [13:C.usb/Conn         28.940] down/error => down
Layer 4 [13:C.usb/Conn         28.941] down/error
Layer 4 [ 1:main               28.941] check start
Layer 4 [13:C.usb/Conn         28.941] is down
Layer 4 [ 1:main               28.941] check end: want_up 1 some 1>1 all 0>0, going 0 up 3 down 1
F00000000: [13:C.usb] Link down, terminating
Layer 4 [ 1:main               28.941] trigger Going down
Layer 4 [ 4:server/Server      28.941] Stopping
Layer 5 [ 4:server/Server      28.941] up => >down
Layer 8 [22:tunnel/15.15.251   28.941] Stop Conn 1
Layer 3 [ 1:main               28.941] Release 15.15.251
Layer 5 [21:tunnel/ConnC       28.941] up => down
Layer 5 [21:tunnel/ConnC       28.941] Stopping
Layer 8 [22:tunnel/15.15.251   28.941] Stop Conn 1
Layer 4 [21:tunnel/ConnC       28.942] down
Layer 8 [18:/driver            28.942] CloseD
Layer 0 [ 4:server/Server      28.942] Close
Layer 5 [ 4:server/Server      28.942] >down => down
Layer 4 [ 4:server/Server      28.942] down
Layer 4 [ 4:server/Server      28.942] down
Layer 4 [ 7:A.unix/local       28.942] Stopping
Layer 5 [ 7:A.unix/local       28.943] up => >down
Layer 8 [ 7:A.unix/local       28.943] StopServer
Layer 5 [ 7:A.unix/local       28.943] >down => down
Layer 4 [ 7:A.unix/local       28.943] down
Layer 4 [ 7:A.unix/local       28.943] down
Layer 4 [21:tunnel/ConnC       28.943] Stopping
Layer 5 [21:tunnel/ConnC       28.943] down => >down
Layer 4 [21:tunnel/ConnC       28.943] down
Layer 4 [10:B.tcp/inet         28.943] Stopping
Layer 5 [10:B.tcp/inet         28.943] up => >down
Layer 8 [10:B.tcp/inet         28.943] StopServer
Layer 5 [10:B.tcp/inet         28.943] >down => down
Layer 4 [10:B.tcp/inet         28.943] down
Layer 4 [10:B.tcp/inet         28.943] down
Layer 4 [13:C.usb/Conn         28.943] Stopping
Layer 5 [13:C.usb/Conn         28.944] down/error => >down
Layer 4 [13:C.usb/Conn         28.944] down/error
Layer 4 [ 1:main               28.944] check start
Layer 4 [ 4:server/Server      28.944] is down
Layer 4 [ 7:A.unix/local       28.944] is down
Layer 4 [10:B.tcp/inet         28.944] is down
Layer 4 [13:C.usb/Conn         28.944] is down
Layer 4 [ 1:main               28.944] check end: want_up 0 some 1>0 all 0>0, going 0 up 0 down 4
Layer 4 [ 1:main               28.944] down
Layer 4 [ 1:main               28.944] deleting
Layer 8 [ 7:A.unix/local       28.944] StopServer
Layer 8 [10:B.tcp/inet         28.944] StopServer
Layer 1 [16:C.usb/usbL         28.944] Close
Layer 1 [16:C.usb/usbL         28.944] Release
Layer 4 [ 1:main               28.944] deleted.

Maybe linked to #329 ?

ptorrent commented 5 years ago

Working on 0.12

smurfix commented 5 years ago

Could you retry with the latest master? The problem will still be there but I've renumbered the error messages so that it'll be more obvious what triggered this.

ptorrent commented 5 years ago

Is knxd 0.14.25:4358f34 the last master version (I did my test with this version) ?

smurfix commented 5 years ago

No. d9eddc3.

ptorrent commented 5 years ago

Thanks for your answer

I'm not familiar with github command. git checkout master:d9eddc3 ?

smurfix commented 5 years ago

"git pull" should be enough.

ptorrent commented 5 years ago

Not better 

[38.714220] [00002dd3] libusb: debug [libusb_cancel_transfer] transfer 0x7138a8
[38.714276] [00002dd3] libusb: debug [libusb_cancel_transfer] transfer 0x7195e0
[38.714334] [00002dd3] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[38.714359] [00002dd3] libusb: debug [handle_events] poll() 3 fds with timeout in 0ms
[38.714388] [00002dd3] libusb: debug [handle_events] poll() returned 1
[38.714416] [00002dd3] libusb: debug [reap_for_handle] urb type=1 status=-2 transferred=0
[38.714439] [00002dd3] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[38.714461] [00002dd3] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[38.714481] [00002dd3] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[38.714504] [00002dd3] libusb: debug [disarm_timerfd]
[38.714533] [00002dd3] libusb: debug [usbi_handle_transfer_completion] transfer 0x7138a8 has callback 0x47858
Layer 10 [16:C.usb/usbL         38.715] SendCB 7138a8
[38.714586] [00002dd3] libusb: debug [reap_for_handle] urb type=1 status=-2 transferred=0
[38.714609] [00002dd3] libusb: debug [handle_bulk_completion] handling completion status -2 of bulk urb 1/1
[38.714631] [00002dd3] libusb: debug [handle_bulk_completion] abnormal reap: urb status -2
[38.714650] [00002dd3] libusb: debug [handle_bulk_completion] abnormal reap: last URB handled, reporting
[38.714672] [00002dd3] libusb: debug [usbi_handle_transfer_completion] transfer 0x7195e0 has callback 0x476bc
Layer 10 [16:C.usb/usbL         38.715] RecvCB 7195e0
Layer 10 [16:C.usb/usbL         38.716] SendComplete 7138a8 0
E00000035: [16:C.usb] SendError 7138a8 status 3
Layer 10 [16:C.usb/usbL         38.716] RecvComplete 7195e0 0
Layer 1 [16:C.usb/usbL         38.716] Release
[38.714839] [00002dd3] libusb: debug [libusb_release_interface] interface 0
[38.714912] [00002dd3] libusb: debug [libusb_attach_kernel_driver] interface 0
[38.726678] [00002dd3] libusb: debug [libusb_close]
[38.727342] [00002dd3] libusb: debug [usbi_remove_pollfd] remove fd 13
Layer 10 [16:C.usb/usbL         38.729] USBLoop read 10
Layer 10 [16:C.usb/usbL         38.729] USBLoop read 12
[38.728753] [00002dd3] libusb: debug [libusb_exit]
[38.729518] [00002dd3] libusb: debug [libusb_handle_events_timeout_completed] doing our own event handling
[38.729950] [00002dd3] libusb: debug [handle_events] poll fds modified, reallocating
[38.730385] [00002dd3] libusb: debug [handle_events] poll() 2 fds with timeout in 0ms
[38.731114] [00002dd3] libusb: debug [handle_events] poll() returned 0
[38.731572] [00002dd3] libusb: debug [libusb_unref_device] destroy device 1.5
[38.732090] [00002dd3] libusb: debug [libusb_unref_device] destroy device 1.4
[38.732513] [00002dd3] libusb: debug [libusb_unref_device] destroy device 1.3
[38.732931] [00002dd3] libusb: debug [libusb_unref_device] destroy device 1.2
[38.733451] [00002dd3] libusb: debug [libusb_unref_device] destroy device 1.1
[38.733860] [00002dd3] libusb: debug [usbi_remove_pollfd] remove fd 10
Layer 10 [16:C.usb/usbL         38.735] USBLoop read 12
[38.734568] [00002dd3] libusb: debug [usbi_remove_pollfd] remove fd 12
Layer 4 [ 1:main               38.736] deleted.
smurfix commented 5 years ago

Not enough log info. Please don't include libusb debugging. You can turn that off by using -t1023 (bit 10 controls the USB debug flag). Also, please use "-B log" in front of the "-b usb:".

In any case,

Layer 0 [ 4:server/Server     13.698] Send(017): 06 10 05 30 00 11 29 00 BC D0 11 01 19 01 01 00 80
Layer 0 [ 4:server/Server     13.698] Send: Operation not permitted

indicates that you either don't have a default route, or sending multicast packets has been firewalled off.

On the other hand, E00000000: [20:C.usb] EMI_common: send while waiting indicates an internal logic error when handling USB, which I haven't yet been able to fix unfortunately, as it doesn't show up on any of my hardware. To debug that I need a complete dump (with the aforementioned "-B log" option); could you create that and upload it to a gist or pastebin?

ptorrent commented 5 years ago

Hello,

Here the command: 

knxd -t1023  -e 15.15.250 -E 15.15.251:4 -DT --Server=:3671 -u /tmp/knxd_72 -i 33671 -B log -b usb:

To reproduce: 1) exec knxd 2) write value on the knx bus

Here the pastebin: https://pastebin.com/cBWiCiDr

Tell me if you need more info