Closed sandervrijders closed 9 years ago
ipcm log
3852(1427363197)#netlink-manager (INFO): Netlink socket connected to local port 1
3852(1427363197)#ipcm (INFO)[create_ipcp]: IPC process test-eth:1:: created [id = 1]
3852(1427363197)#ipcm (INFO)[assign_to_dif]: Requested DIF assignment of IPC process test-eth:1:: to DIF 300:::
3852(1427363197)#ipcm.ipcp (INFO)[assign_to_dif_response_event_handler]: DIF assignment operation completed for IPC process test-eth:1:: [success=1]
3852(1427363197)#ipcm (INFO)[create_ipcp]: IPC process test2.IRATI:1:: created and waiting for initialization[id = 2]
3852(1427363197)#ipcm.ipcp (INFO)[ipc_process_daemon_initialized_event_handler]: IPC process daemon initialized [id = 2]
3852(1427363197)#ipcm (INFO)[assign_to_dif]: Requested DIF assignment of IPC process test2.IRATI:1:: to DIF normal.DIF:::
3852(1427363197)#ipcm.ipcp (INFO)[assign_to_dif_response_event_handler]: DIF assignment operation completed for IPC process test2.IRATI:1:: [success=1]
3852(1427363197)#ipcm (INFO)[register_at_dif]: Requested DIF registration of IPC process test2.IRATI:1:: at DIF 300::: through IPC process test-eth:1::
3852(1427363197)#ipcm.ipcp (INFO)[ipcm_register_response_ipcp]: IPC process test2.IRATI:1:: informed about its registration to N-1 DIF 300:::
3852(1427363215)#ipcm.flow-alloc (INFO)[flow_allocation_requested_remote]: Arrived request for flow allocation between test2.IRATI:1:: and test1.IRATI:1::
3852(1427363215)#ipcm.flow-alloc (INFO)[allocate_flow_response_event_handler]: : Informing IPC process test-eth:1:: about flow allocation from application test2.IRATI:1:: to application test1.IRATI:1:: in DIF 300::: [success = 1, port-id = 1]
3852(1427363238)#ipcm.flow-alloc (INFO)[flow_allocation_requested_local]: IPC process test2.IRATI:1:: requested to allocate flow between rina.apps.echotime.client:1:: and rina.apps.echotime.server:1::
3852(1427363238)#ipcm.flow-alloc (INFO)[ipcm_allocate_flow_request_result_handler]: Informing IPC process test2.IRATI:1:: about flow allocation from application rina.apps.echotime.client:1:: to application rina.apps.echotime.server:1:: in DIF normal.DIF::: [success = 1, port-id = 2]
3852(1427363238)#ipcm.flow-alloc (INFO)[ipcm_allocate_flow_request_result_handler]: Applications rina.apps.echotime.client:1:: and rina.apps.echotime.server:1:: informed about flow allocation result
3852(1427363247)#ipcm.flow-alloc (INFO)[deallocate_flow]: Application rina.apps.echotime.client:1:: asks IPC process test2.IRATI:1:: to deallocate flow [port-id = 2]
3852(1427363247)#ipcm.flow-alloc (INFO)[ipcm_deallocate_flow_response_event_handler]: Deallocated flow identified by port-id 2 from IPC process test2.IRATI:1:: [success = 1]
3852(1427363247)#ipcm.flow-alloc (INFO)[ipcm_deallocate_flow_response_event_handler]: Application rina.apps.echotime.client:1:: informed about deallocation of flow identified by port-id 2[success = 1]
3852(1427363247)#ipcm.app (INFO)[os_process_finalized_handler]: Application rina.apps.echotime.client:1::terminated
3852(1427363255)#ipcm.flow-alloc (INFO)[flow_allocation_requested_local]: IPC process test2.IRATI:1:: requested to allocate flow between rina.apps.echotime.client:1:: and rina.apps.echotime.server:1::
3852(1427363324)#ipcm.app (INFO)[os_process_finalized_handler]: Application rina.apps.echotime.client:1::terminated
3852(1427363334)#ipcm.flow-alloc (INFO)[flow_allocation_requested_local]: IPC process test2.IRATI:1:: requested to allocate flow between rina.apps.echotime.client:1:: and rina.apps.echotime.server:1::
3852(1427363337)#ipcm.app (INFO)[os_process_finalized_handler]: Application rina.apps.echotime.client:1::terminated
test2.IRATI log
3856(1427363197)#netlink-manager (INFO): Netlink socket connected to local port 3856
3856(1427363197)#ipc-process (INFO): Librina initialized
3856(1427363197)#ipc-process (INFO): Pluggable component 'security-manager'/'default' [default] published
3856(1427363197)#ipc-process (INFO): Pluggable component 'flow-allocator'/'default' [default] published
3856(1427363197)#ipc-process (INFO): Pluggable component 'namespace-manager'/'default' [default] published
3856(1427363197)#ipc-process (INFO): Pluggable component 'resource-allocator'/'default' [default] published
3856(1427363197)#ipc-process (INFO): Pluggable component 'routing'/'link-state' [default] published
3856(1427363197)#ipc-process (INFO): Plugin default loaded successfully
3856(1427363197)#rib-daemon (INFO): EventListener subscribed to event 5_N_MINUS_1_FLOW_ALLOCATED
3856(1427363197)#rib-daemon (INFO): EventListener subscribed to event 7_N_MINUS_1_FLOW_DEALLOCATED
3856(1427363197)#rib (INFO): Object with name /daf/management/neighbors, class neighbor set, instance 1 added to the RIB
3856(1427363197)#rib (INFO): Object with name /daf/management/enrollment, class enrollment information, instance 2 added to the RIB
3856(1427363197)#rib (INFO): Object with name /daf/management/operationalStatus, class operationstatus, instance 3 added to the RIB
3856(1427363197)#rib (INFO): Object with name /daf/management/naming/address, class address, instance 4 added to the RIB
3856(1427363197)#rib-daemon (INFO): EventListener subscribed to event 7_N_MINUS_1_FLOW_DEALLOCATED
3856(1427363197)#rib-daemon (INFO): EventListener subscribed to event 5_N_MINUS_1_FLOW_ALLOCATED
3856(1427363197)#rib-daemon (INFO): EventListener subscribed to event 6_N_MINUS_1_FLOW_ALLOCATION_FAILED
3856(1427363197)#rib-daemon (INFO): EventListener subscribed to event 8_NEIGHBOR_DECLARED_DEAD
3856(1427363197)#rib (INFO): Object with name /dif/resourceallocation/nminusoneflowmanager/difregistrations, class DIF registration set, instance 5 added to the RIB
3856(1427363197)#rib (INFO): Object with name /dif/resourceallocation/nminusoneflowmanager/nminusoneflows, class nminusone flow set, instance 6 added to the RIB
3856(1427363197)#rib-daemon (INFO): Starting Management SDU reader ...
3856(1427363197)#rib-daemon (INFO): EventListener subscribed to event 0_CONNECTIVITY_TO_NEIGHBOR_LOST
3856(1427363197)#rib (INFO): Object with name /dif/management/flowallocator/directoryforwardingtableentries, class directoryforwardingtableentry set, instance 7 added to the RIB
3856(1427363197)#rib (INFO): Object with name /daf/management/naming/whatevercastnames, class whatname set, instance 8 added to the RIB
3856(1427363197)#rib (INFO): Object with name /dif/resourceallocation/flowallocator/flows, class flow set, instance 9 added to the RIB
3856(1427363197)#rib (INFO): Object with name /dif/management/flowallocator/qoscubes, class qoscube set, instance 10 added to the RIB
3856(1427363197)#rib (INFO): Object with name /dif/ipc/datatransfer/constants, class datatransfercons, instance 11 added to the RIB
3856(1427363197)#ipcp-components (INFO): Policy-set default selected for component security-manager
3856(1427363197)#ipcp-components (INFO): Policy-set default selected for component flow-allocator
3856(1427363197)#ipcp-components (INFO): Policy-set default selected for component namespace-manager
3856(1427363197)#ipcp-components (INFO): Policy-set default selected for component resource-allocator
3856(1427363197)#ipcp-components (INFO): Policy-set link-state selected for component routing
3856(1427363197)#ipc-process (INFO): Initialized IPC Process with name: test2.IRATI, instance 1, id 2
3856(1427363197)#ipcp-main (INFO): IPC Process name: test2.IRATI
3856(1427363197)#ipcp-main (INFO): IPC Process instance: 1
3856(1427363197)#ipcp-main (INFO): IPC Process id: 2
3856(1427363197)#ipcp-main (INFO): IPC Manager port: 1
3856(1427363197)#ipcp-main (INFO): IPC Process initialized, executing event loop...
3856(1427363197)#rib (INFO): Object with name /dif/management/pduforwardingtable/linkstate/flowstateobjectgroup, class flowstateobject set, instance 12 added to the RIB
3856(1427363197)#rib-daemon (INFO): EventListener subscribed to event 7_N_MINUS_1_FLOW_DEALLOCATED
3856(1427363197)#rib-daemon (INFO): EventListener subscribed to event 5_N_MINUS_1_FLOW_ALLOCATED
3856(1427363197)#rib-daemon (INFO): EventListener subscribed to event 9_NEIGHBOR_ADDED
3856(1427363197)#rib-daemon (INFO): EventListener subscribed to event 0_CONNECTIVITY_TO_NEIGHBOR_LOST
3856(1427363197)#rib (INFO): Object with name /dif/management/flowallocator/qoscubes/reliable, class qoscube, instance 13 added to the RIB
3856(1427363197)#rib (INFO): Object with name /dif/management/flowallocator/qoscubes/unreliable, class qoscube, instance 14 added to the RIB
3856(1427363197)#rib (INFO): Object with name /difmanagement/watchdog, class watchdog timer, instance 15 added to the RIB
3856(1427363197)#resource-allocator (INFO): IPC Process registered to N-1 DIF 300
3856(1427363197)#rib (INFO): Object with name /dif/resourceallocation/nminusoneflowmanager/difregistrations/300, class DIF registration, instance 16 added to the RIB
3856(1427363215)#resource-allocator (INFO): Accepted new flow from IPC Process test1.IRATI-1
3856(1427363215)#rib (INFO): Object with name /dif/resourceallocation/nminusoneflowmanager/nminusoneflows/1, class nminusone flow, instance 17 added to the RIB
3856(1427363215)#rib-daemon (INFO): Event 5_N_MINUS_1_FLOW_ALLOCATED has just happened. Notifying event listeners.
3856(1427363216)#rib (INFO): Object with name /daf/management/neighbors/test1.IRATI, class neighbor, instance 18 added to the RIB
3856(1427363216)#rib-daemon (INFO): Event 9_NEIGHBOR_ADDED has just happened. Notifying event listeners.
3856(1427363216)#routing-ps-link-state (INFO): There was an allocation flow event waiting for enrollment, launching it
3856(1427363216)#rib (INFO): Object with name /dif/management/pduforwardingtable/linkstate/flowstateobjectgroup/17-16, class flowstateobject, instance 19 added to the RIB
3856(1427363216)#enrollment-task (INFO): Remote IPC Process enrolled!
3856(1427363216)#rib (INFO): Object with name /dif/management/pduforwardingtable/linkstate/flowstateobjectgroup/16-17, class flowstateobject, instance 20 added to the RIB
3856(1427363228)#rib (INFO): Object with name /dif/management/flowallocator/directoryforwardingtableentries/rina.apps.echotime.server-1--, class directoryforwardingtableentry, instance 21 added to the RIB
3856(1427363238)#rib (INFO): Object with name /dif/resourceallocation/flowallocator/flows/17-2, class flow, instance 22 added to the RIB
3856(1427363252)#rib (INFO): Object with name /dif/resourceallocation/flowallocator/flows/17-2, class flow, instance 22 removed from the RIB
dmesg
[ 0.977345] usb usb5: New USB device found, idVendor=1d6b, idProduct=0001
[ 0.977347] usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.977350] usb usb5: Product: UHCI Host Controller
[ 0.977351] usb usb5: Manufacturer: Linux 3.15.0-pristine1.2-logs uhci_hcd
[ 0.977353] usb usb5: SerialNumber: 0000:00:1d.1
[ 0.977540] hub 5-0:1.0: USB hub found
[ 0.977552] hub 5-0:1.0: 2 ports detected
[ 0.977731] ata_piix 0000:00:1f.2: version 2.13
[ 0.977897] ata_piix 0000:00:1f.2: MAP [ P0 P2 P1 P3 ]
[ 0.979387] scsi0 : ata_piix
[ 0.979648] scsi1 : ata_piix
[ 0.979741] ata1: SATA max UDMA/133 cmd 0xbc00 ctl 0xb880 bmdma 0xb400 irq 19
[ 0.979746] ata2: SATA max UDMA/133 cmd 0xb800 ctl 0xb480 bmdma 0xb408 irq 19
[ 0.979947] ata_piix 0000:00:1f.5: MAP [ P0 -- P1 -- ]
[ 0.980973] scsi2 : ata_piix
[ 0.981126] scsi3 : ata_piix
[ 0.981188] ata3: SATA max UDMA/133 cmd 0xac00 ctl 0xa880 bmdma 0xa400 irq 19
[ 0.981192] ata4: SATA max UDMA/133 cmd 0xa800 ctl 0xa480 bmdma 0xa408 irq 19
[ 0.981351] uhci_hcd 0000:00:1d.2: UHCI Host Controller
[ 0.981359] uhci_hcd 0000:00:1d.2: new USB bus registered, assigned bus number 6
[ 0.981395] uhci_hcd 0000:00:1d.2: irq 18, io base 0x00009800
[ 0.981441] usb usb6: New USB device found, idVendor=1d6b, idProduct=0001
[ 0.981444] usb usb6: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.981446] usb usb6: Product: UHCI Host Controller
[ 0.981448] usb usb6: Manufacturer: Linux 3.15.0-pristine1.2-logs uhci_hcd
[ 0.981450] usb usb6: SerialNumber: 0000:00:1d.2
[ 0.981609] hub 6-0:1.0: USB hub found
[ 0.981615] hub 6-0:1.0: 2 ports detected
[ 1.156767] igb 0000:01:00.0: added PHC on eth0
[ 1.156772] igb 0000:01:00.0: Intel(R) Gigabit Ethernet Network Connection
[ 1.156777] igb 0000:01:00.0: eth0: (PCIe:2.5Gb/s:Width x4) 00:30:48:cf:bd:30
[ 1.156782] igb 0000:01:00.0: eth0: PBA No: Unknown
[ 1.156785] igb 0000:01:00.0: Using MSI-X interrupts. 8 rx queue(s), 8 tx queue(s)
[ 1.157141] igb 0000:01:00.1: irq 76 for MSI/MSI-X
[ 1.157147] igb 0000:01:00.1: irq 77 for MSI/MSI-X
[ 1.157153] igb 0000:01:00.1: irq 78 for MSI/MSI-X
[ 1.157159] igb 0000:01:00.1: irq 79 for MSI/MSI-X
[ 1.157165] igb 0000:01:00.1: irq 80 for MSI/MSI-X
[ 1.157170] igb 0000:01:00.1: irq 81 for MSI/MSI-X
[ 1.157176] igb 0000:01:00.1: irq 82 for MSI/MSI-X
[ 1.157181] igb 0000:01:00.1: irq 83 for MSI/MSI-X
[ 1.157188] igb 0000:01:00.1: irq 84 for MSI/MSI-X
[ 1.157251] igb 0000:01:00.1: irq 76 for MSI/MSI-X
[ 1.157257] igb 0000:01:00.1: irq 77 for MSI/MSI-X
[ 1.157262] igb 0000:01:00.1: irq 78 for MSI/MSI-X
[ 1.157267] igb 0000:01:00.1: irq 79 for MSI/MSI-X
[ 1.157273] igb 0000:01:00.1: irq 80 for MSI/MSI-X
[ 1.157278] igb 0000:01:00.1: irq 81 for MSI/MSI-X
[ 1.157283] igb 0000:01:00.1: irq 82 for MSI/MSI-X
[ 1.157289] igb 0000:01:00.1: irq 83 for MSI/MSI-X
[ 1.157294] igb 0000:01:00.1: irq 84 for MSI/MSI-X
[ 1.288372] usb 2-1: new full-speed USB device number 2 using uhci_hcd
[ 1.311057] ata4: SATA link down (SStatus 0 SControl 300)
[ 1.321743] ata3: SATA link down (SStatus 0 SControl 300)
[ 1.348903] igb 0000:01:00.1: added PHC on eth1
[ 1.348907] igb 0000:01:00.1: Intel(R) Gigabit Ethernet Network Connection
[ 1.348911] igb 0000:01:00.1: eth1: (PCIe:2.5Gb/s:Width x4) 00:30:48:cf:bd:31
[ 1.348915] igb 0000:01:00.1: eth1: PBA No: Unknown
[ 1.348918] igb 0000:01:00.1: Using MSI-X interrupts. 8 rx queue(s), 8 tx queue(s)
[ 1.349248] igb 0000:08:00.0: irq 85 for MSI/MSI-X
[ 1.349255] igb 0000:08:00.0: irq 86 for MSI/MSI-X
[ 1.349261] igb 0000:08:00.0: irq 87 for MSI/MSI-X
[ 1.349266] igb 0000:08:00.0: irq 88 for MSI/MSI-X
[ 1.349272] igb 0000:08:00.0: irq 89 for MSI/MSI-X
[ 1.349277] igb 0000:08:00.0: irq 90 for MSI/MSI-X
[ 1.349283] igb 0000:08:00.0: irq 91 for MSI/MSI-X
[ 1.349288] igb 0000:08:00.0: irq 92 for MSI/MSI-X
[ 1.349293] igb 0000:08:00.0: irq 93 for MSI/MSI-X
[ 1.349363] igb 0000:08:00.0: irq 85 for MSI/MSI-X
[ 1.349369] igb 0000:08:00.0: irq 86 for MSI/MSI-X
[ 1.349374] igb 0000:08:00.0: irq 87 for MSI/MSI-X
[ 1.349379] igb 0000:08:00.0: irq 88 for MSI/MSI-X
[ 1.349384] igb 0000:08:00.0: irq 89 for MSI/MSI-X
[ 1.349390] igb 0000:08:00.0: irq 90 for MSI/MSI-X
[ 1.349395] igb 0000:08:00.0: irq 91 for MSI/MSI-X
[ 1.349400] igb 0000:08:00.0: irq 92 for MSI/MSI-X
[ 1.349405] igb 0000:08:00.0: irq 93 for MSI/MSI-X
[ 1.456957] usb 2-1: New USB device found, idVendor=046b, idProduct=ff10
[ 1.456962] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 1.456965] usb 2-1: Product: Virtual Keyboard and Mouse
[ 1.456968] usb 2-1: Manufacturer: American Megatrends Inc.
[ 1.456971] usb 2-1: SerialNumber: serial
[ 1.502881] hidraw: raw HID events driver (C) Jiri Kosina
[ 1.516262] usbcore: registered new interface driver usbhid
[ 1.516265] usbhid: USB HID core driver
[ 1.523925] input: American Megatrends Inc. Virtual Keyboard and Mouse as /devices/pci0000:00/0000:00:1a.1/usb2/2-1/2-1:1.0/0003:046B:FF10.0001/input/input2
[ 1.524059] hid-generic 0003:046B:FF10.0001: input,hidraw0: USB HID v1.10 Keyboard [American Megatrends Inc. Virtual Keyboard and Mouse] on usb-0000:00:1a.1-1/input0
[ 1.524284] input: American Megatrends Inc. Virtual Keyboard and Mouse as /devices/pci0000:00/0000:00:1a.1/usb2/2-1/2-1:1.1/0003:046B:FF10.0002/input/input3
[ 1.524532] hid-generic 0003:046B:FF10.0002: input,hidraw1: USB HID v1.10 Mouse [American Megatrends Inc. Virtual Keyboard and Mouse] on usb-0000:00:1a.1-1/input1
[ 1.541195] igb 0000:08:00.0: added PHC on eth2
[ 1.541200] igb 0000:08:00.0: Intel(R) Gigabit Ethernet Network Connection
[ 1.541204] igb 0000:08:00.0: eth2: (PCIe:2.5Gb/s:Width x4) 00:30:48:de:63:78
[ 1.541208] igb 0000:08:00.0: eth2: PBA No: Unknown
[ 1.541212] igb 0000:08:00.0: Using MSI-X interrupts. 8 rx queue(s), 8 tx queue(s)
[ 1.541542] igb 0000:08:00.1: irq 94 for MSI/MSI-X
[ 1.541548] igb 0000:08:00.1: irq 95 for MSI/MSI-X
[ 1.541554] igb 0000:08:00.1: irq 96 for MSI/MSI-X
[ 1.541560] igb 0000:08:00.1: irq 97 for MSI/MSI-X
[ 1.541565] igb 0000:08:00.1: irq 98 for MSI/MSI-X
[ 1.541571] igb 0000:08:00.1: irq 99 for MSI/MSI-X
[ 1.541577] igb 0000:08:00.1: irq 100 for MSI/MSI-X
[ 1.541583] igb 0000:08:00.1: irq 101 for MSI/MSI-X
[ 1.541588] igb 0000:08:00.1: irq 102 for MSI/MSI-X
[ 1.541658] igb 0000:08:00.1: irq 94 for MSI/MSI-X
[ 1.541664] igb 0000:08:00.1: irq 95 for MSI/MSI-X
[ 1.541669] igb 0000:08:00.1: irq 96 for MSI/MSI-X
[ 1.541674] igb 0000:08:00.1: irq 97 for MSI/MSI-X
[ 1.541679] igb 0000:08:00.1: irq 98 for MSI/MSI-X
[ 1.541685] igb 0000:08:00.1: irq 99 for MSI/MSI-X
[ 1.541690] igb 0000:08:00.1: irq 100 for MSI/MSI-X
[ 1.541695] igb 0000:08:00.1: irq 101 for MSI/MSI-X
[ 1.541701] igb 0000:08:00.1: irq 102 for MSI/MSI-X
[ 1.627207] ata2.00: SATA link down (SStatus 0 SControl 300)
[ 1.627221] ata2.01: SATA link down (SStatus 0 SControl 300)
[ 1.737095] igb 0000:08:00.1: added PHC on eth3
[ 1.737100] igb 0000:08:00.1: Intel(R) Gigabit Ethernet Network Connection
[ 1.737103] igb 0000:08:00.1: eth3: (PCIe:2.5Gb/s:Width x4) 00:30:48:de:63:79
[ 1.737108] igb 0000:08:00.1: eth3: PBA No: Unknown
[ 1.737111] igb 0000:08:00.1: Using MSI-X interrupts. 8 rx queue(s), 8 tx queue(s)
[ 1.737438] igb 0000:06:00.0: irq 103 for MSI/MSI-X
[ 1.737445] igb 0000:06:00.0: irq 104 for MSI/MSI-X
[ 1.737450] igb 0000:06:00.0: irq 105 for MSI/MSI-X
[ 1.737456] igb 0000:06:00.0: irq 106 for MSI/MSI-X
[ 1.737461] igb 0000:06:00.0: irq 107 for MSI/MSI-X
[ 1.737467] igb 0000:06:00.0: irq 108 for MSI/MSI-X
[ 1.737472] igb 0000:06:00.0: irq 109 for MSI/MSI-X
[ 1.737477] igb 0000:06:00.0: irq 110 for MSI/MSI-X
[ 1.737483] igb 0000:06:00.0: irq 111 for MSI/MSI-X
[ 1.737551] igb 0000:06:00.0: irq 103 for MSI/MSI-X
[ 1.737556] igb 0000:06:00.0: irq 104 for MSI/MSI-X
[ 1.737562] igb 0000:06:00.0: irq 105 for MSI/MSI-X
[ 1.737567] igb 0000:06:00.0: irq 106 for MSI/MSI-X
[ 1.737572] igb 0000:06:00.0: irq 107 for MSI/MSI-X
[ 1.737577] igb 0000:06:00.0: irq 108 for MSI/MSI-X
[ 1.737583] igb 0000:06:00.0: irq 109 for MSI/MSI-X
[ 1.737588] igb 0000:06:00.0: irq 110 for MSI/MSI-X
[ 1.737593] igb 0000:06:00.0: irq 111 for MSI/MSI-X
[ 1.780547] ata1.00: SATA link up 3.0 Gbps (SStatus 123 SControl 300)
[ 1.780559] ata1.01: SATA link down (SStatus 0 SControl 300)
[ 1.841604] ata1.00: ATA-8: WDC WD1600BEVT-11ZCT0, 11.01A11, max UDMA/133
[ 1.841609] ata1.00: 312581808 sectors, multi 16: LBA48 NCQ (depth 0/32)
[ 1.857837] ata1.00: configured for UDMA/133
[ 1.858238] scsi 0:0:0:0: Direct-Access ATA WDC WD1600BEVT-1 11.0 PQ: 0 ANSI: 5
[ 1.864474] tsc: Refined TSC clocksource calibration: 2266.746 MHz
[ 1.878697] sd 0:0:0:0: [sda] 312581808 512-byte logical blocks: (160 GB/149 GiB)
[ 1.878767] sd 0:0:0:0: [sda] Write Protect is off
[ 1.878771] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00
[ 1.878797] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 1.898182] sda: sda1 sda2 sda3 sda4
[ 1.898958] sd 0:0:0:0: [sda] Attached SCSI disk
[ 1.906592] sd 0:0:0:0: Attached scsi generic sg0 type 0
[ 1.929265] igb 0000:06:00.0: added PHC on eth4
[ 1.929270] igb 0000:06:00.0: Intel(R) Gigabit Ethernet Network Connection
[ 1.929274] igb 0000:06:00.0: eth4: (PCIe:2.5Gb/s:Width x4) 00:30:48:de:63:7a
[ 1.929278] igb 0000:06:00.0: eth4: PBA No: Unknown
[ 1.929281] igb 0000:06:00.0: Using MSI-X interrupts. 8 rx queue(s), 8 tx queue(s)
[ 1.929621] igb 0000:06:00.1: irq 112 for MSI/MSI-X
[ 1.929627] igb 0000:06:00.1: irq 113 for MSI/MSI-X
[ 1.929633] igb 0000:06:00.1: irq 114 for MSI/MSI-X
[ 1.929640] igb 0000:06:00.1: irq 115 for MSI/MSI-X
[ 1.929645] igb 0000:06:00.1: irq 116 for MSI/MSI-X
[ 1.929651] igb 0000:06:00.1: irq 117 for MSI/MSI-X
[ 1.929656] igb 0000:06:00.1: irq 118 for MSI/MSI-X
[ 1.929662] igb 0000:06:00.1: irq 119 for MSI/MSI-X
[ 1.929667] igb 0000:06:00.1: irq 120 for MSI/MSI-X
[ 1.929737] igb 0000:06:00.1: irq 112 for MSI/MSI-X
[ 1.929743] igb 0000:06:00.1: irq 113 for MSI/MSI-X
[ 1.929748] igb 0000:06:00.1: irq 114 for MSI/MSI-X
[ 1.929754] igb 0000:06:00.1: irq 115 for MSI/MSI-X
[ 1.929759] igb 0000:06:00.1: irq 116 for MSI/MSI-X
[ 1.929764] igb 0000:06:00.1: irq 117 for MSI/MSI-X
[ 1.929769] igb 0000:06:00.1: irq 118 for MSI/MSI-X
[ 1.929775] igb 0000:06:00.1: irq 119 for MSI/MSI-X
[ 1.929780] igb 0000:06:00.1: irq 120 for MSI/MSI-X
[ 2.121274] igb 0000:06:00.1: added PHC on eth5
[ 2.121278] igb 0000:06:00.1: Intel(R) Gigabit Ethernet Network Connection
[ 2.121282] igb 0000:06:00.1: eth5: (PCIe:2.5Gb/s:Width x4) 00:30:48:de:63:7b
[ 2.121286] igb 0000:06:00.1: eth5: PBA No: Unknown
[ 2.121290] igb 0000:06:00.1: Using MSI-X interrupts. 8 rx queue(s), 8 tx queue(s)
[ 2.272775] device-mapper: uevent: version 1.0.3
[ 2.274351] device-mapper: ioctl: 4.27.0-ioctl (2013-10-30) initialised: dm-devel@redhat.com
[ 2.330993] kjournald starting. Commit interval 5 seconds
[ 2.331039] EXT3-fs (sda1): mounted filesystem with ordered data mode
[ 2.865757] Switched to clocksource tsc
[ 3.757886] random: nonblocking pool is initialized
[ 4.028739] udevd[598]: starting version 175
[ 4.281638] input: PC Speaker as /devices/platform/pcspkr/input/input4
[ 4.348313] i801_smbus 0000:00:1f.3: SMBus using PCI Interrupt
[ 4.377694] input: Power Button as /devices/LNXSYSTM:00/LNXSYBUS:00/PNP0C0C:00/input/input5
[ 4.377860] ACPI: Power Button [PWRB]
[ 4.377950] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input6
[ 4.378140] ACPI: Power Button [PWRF]
[ 4.408031] microcode: CPU0 sig=0x106a5, pf=0x1, revision=0x15
[ 4.446522] microcode: CPU1 sig=0x106a5, pf=0x1, revision=0x15
[ 4.446612] microcode: CPU2 sig=0x106a5, pf=0x1, revision=0x15
[ 4.446701] microcode: CPU3 sig=0x106a5, pf=0x1, revision=0x15
[ 4.446752] microcode: CPU4 sig=0x106a5, pf=0x1, revision=0x15
[ 4.446806] microcode: CPU5 sig=0x106a5, pf=0x1, revision=0x15
[ 4.446817] microcode: CPU6 sig=0x106a5, pf=0x1, revision=0x15
[ 4.446860] microcode: CPU7 sig=0x106a5, pf=0x1, revision=0x15
[ 4.446916] microcode: CPU8 sig=0x106a5, pf=0x1, revision=0x15
[ 4.446996] microcode: CPU9 sig=0x106a5, pf=0x1, revision=0x15
[ 4.447090] microcode: CPU10 sig=0x106a5, pf=0x1, revision=0x15
[ 4.447179] microcode: CPU11 sig=0x106a5, pf=0x1, revision=0x15
[ 4.447231] microcode: CPU12 sig=0x106a5, pf=0x1, revision=0x15
[ 4.447284] microcode: CPU13 sig=0x106a5, pf=0x1, revision=0x15
[ 4.447299] microcode: CPU14 sig=0x106a5, pf=0x1, revision=0x15
[ 4.447355] microcode: CPU15 sig=0x106a5, pf=0x1, revision=0x15
[ 4.447494] microcode: Microcode Update Driver: v2.00 <tigran@aivazian.fsnet.co.uk>, Peter Oruba
[ 4.669248] ioatdma: Intel(R) QuickData Technology Driver 4.00
[ 4.669562] ioatdma 0000:00:16.0: irq 121 for MSI/MSI-X
[ 4.669810] igb 0000:01:00.0: DCA enabled
[ 4.669836] igb 0000:01:00.1: DCA enabled
[ 4.670064] ioatdma 0000:00:16.1: irq 122 for MSI/MSI-X
[ 4.670286] igb 0000:08:00.0: DCA enabled
[ 4.670341] igb 0000:08:00.1: DCA enabled
[ 4.670537] ioatdma 0000:00:16.2: irq 123 for MSI/MSI-X
[ 4.670772] EDAC MC: Ver: 3.0.0
[ 4.670778] igb 0000:06:00.0: DCA enabled
[ 4.670807] igb 0000:06:00.1: DCA enabled
[ 4.671034] ioatdma 0000:00:16.3: irq 124 for MSI/MSI-X
[ 4.671408] ioatdma 0000:00:16.4: irq 125 for MSI/MSI-X
[ 4.671771] ioatdma 0000:00:16.5: irq 126 for MSI/MSI-X
[ 4.672147] ioatdma 0000:00:16.6: irq 127 for MSI/MSI-X
[ 4.672664] ioatdma 0000:00:16.7: irq 128 for MSI/MSI-X
[ 4.683723] EDAC MC1: Giving out device to module i7core_edac.c controller i7 core #1: DEV 0000:fe:03.0 (POLLED)
[ 4.683772] EDAC PCI0: Giving out device to module i7core_edac controller EDAC PCI controller: DEV 0000:fe:03.0 (POLLED)
[ 4.684186] EDAC MC0: Giving out device to module i7core_edac.c controller i7 core #0: DEV 0000:ff:03.0 (POLLED)
[ 4.684227] EDAC PCI1: Giving out device to module i7core_edac controller EDAC PCI controller: DEV 0000:ff:03.0 (POLLED)
[ 4.684441] EDAC i7core: Driver loaded, 2 memory controller(s) found.
[ 4.756876] kvm: VM_EXIT_LOAD_IA32_PERF_GLOBAL_CTRL does not work properly. Using workaround
[ 4.916646] ACPI Warning: SystemIO range 0x0000000000000828-0x000000000000082f conflicts with OpRegion 0x0000000000000800-0x000000000000084f (\PMRG) (20140214/utaddress-258)
[ 4.916655] ACPI: If an ACPI driver is available for this device, you should use it instead of the native driver
[ 4.916685] lpc_ich: Resource conflict(s) found affecting gpio_ich
[ 4.951558] ehci-pci: EHCI PCI platform driver
[ 4.974417] usb 2-1: USB disconnect, device number 2
[ 4.986593] iTCO_vendor_support: vendor-support=0
[ 5.008529] iTCO_wdt: Intel TCO WatchDog Timer Driver v1.11
[ 5.008558] iTCO_wdt: Found a ICH10R TCO device (Version=2, TCOBASE=0x0860)
[ 5.008870] iTCO_wdt: initialized. heartbeat=30 sec (nowayout=0)
[ 5.028437] Error: Driver 'pcspkr' is already registered, aborting...
[ 5.198620] ehci-pci 0000:00:1a.7: EHCI Host Controller
[ 5.198632] ehci-pci 0000:00:1a.7: new USB bus registered, assigned bus number 7
[ 5.198648] ehci-pci 0000:00:1a.7: debug port 1
[ 5.202567] ehci-pci 0000:00:1a.7: cache line size of 256 is not supported
[ 5.202579] ehci-pci 0000:00:1a.7: irq 18, io mem 0xfbef8000
[ 5.214368] ehci-pci 0000:00:1a.7: USB 2.0 started, EHCI 1.00
[ 5.214448] usb usb7: New USB device found, idVendor=1d6b, idProduct=0002
[ 5.214453] usb usb7: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 5.214456] usb usb7: Product: EHCI Host Controller
[ 5.214459] usb usb7: Manufacturer: Linux 3.15.0-pristine1.2-logs ehci_hcd
[ 5.214461] usb usb7: SerialNumber: 0000:00:1a.7
[ 5.214879] hub 7-0:1.0: USB hub found
[ 5.214889] hub 7-0:1.0: 6 ports detected
[ 5.238562] hub 1-0:1.0: USB hub found
[ 5.238612] hub 1-0:1.0: 2 ports detected
[ 5.262532] hub 2-0:1.0: USB hub found
[ 5.262576] hub 2-0:1.0: 2 ports detected
[ 5.286602] hub 3-0:1.0: USB hub found
[ 5.286613] hub 3-0:1.0: 2 ports detected
[ 5.358716] ehci-pci 0000:00:1d.7: EHCI Host Controller
[ 5.358727] ehci-pci 0000:00:1d.7: new USB bus registered, assigned bus number 8
[ 5.358742] ehci-pci 0000:00:1d.7: debug port 1
[ 5.362636] ehci-pci 0000:00:1d.7: cache line size of 256 is not supported
[ 5.362653] ehci-pci 0000:00:1d.7: irq 23, io mem 0xfbed6000
[ 5.374561] ehci-pci 0000:00:1d.7: USB 2.0 started, EHCI 1.00
[ 5.374604] usb usb8: New USB device found, idVendor=1d6b, idProduct=0002
[ 5.374608] usb usb8: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 5.374610] usb usb8: Product: EHCI Host Controller
[ 5.374613] usb usb8: Manufacturer: Linux 3.15.0-pristine1.2-logs ehci_hcd
[ 5.374616] usb usb8: SerialNumber: 0000:00:1d.7
[ 5.374901] hub 8-0:1.0: USB hub found
[ 5.374910] hub 8-0:1.0: 6 ports detected
[ 5.398508] hub 4-0:1.0: USB hub found
[ 5.398597] hub 4-0:1.0: 2 ports detected
[ 5.422563] hub 5-0:1.0: USB hub found
[ 5.422625] hub 5-0:1.0: 2 ports detected
[ 5.446699] hub 6-0:1.0: USB hub found
[ 5.446755] hub 6-0:1.0: 2 ports detected
[ 5.922980] usb 2-1: new full-speed USB device number 3 using uhci_hcd
[ 6.098008] usb 2-1: New USB device found, idVendor=046b, idProduct=ff10
[ 6.098014] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 6.098017] usb 2-1: Product: Virtual Keyboard and Mouse
[ 6.098020] usb 2-1: Manufacturer: American Megatrends Inc.
[ 6.098022] usb 2-1: SerialNumber: serial
[ 6.139396] input: American Megatrends Inc. Virtual Keyboard and Mouse as /devices/pci0000:00/0000:00:1a.1/usb2/2-1/2-1:1.0/0003:046B:FF10.0003/input/input8
[ 6.139850] hid-generic 0003:046B:FF10.0003: input,hidraw0: USB HID v1.10 Keyboard [American Megatrends Inc. Virtual Keyboard and Mouse] on usb-0000:00:1a.1-1/input0
[ 6.158355] input: American Megatrends Inc. Virtual Keyboard and Mouse as /devices/pci0000:00/0000:00:1a.1/usb2/2-1/2-1:1.1/0003:046B:FF10.0004/input/input9
[ 6.159222] hid-generic 0003:046B:FF10.0004: input,hidraw1: USB HID v1.10 Mouse [American Megatrends Inc. Virtual Keyboard and Mouse] on usb-0000:00:1a.1-1/input1
[ 6.748106] Adding 3145724k swap on /dev/sda3. Priority:-1 extents:1 across:3145724k
[ 7.069637] EXT3-fs (sda1): using internal journal
[ 7.256988] loop: module loaded
[ 8.737367] IPv6: ADDRCONF(NETDEV_UP): eth17: link is not ready
[ 8.897465] IPv6: ADDRCONF(NETDEV_UP): eth16: link is not ready
[ 9.025688] IPv6: ADDRCONF(NETDEV_UP): eth15: link is not ready
[ 9.153556] IPv6: ADDRCONF(NETDEV_UP): eth14: link is not ready
[ 9.281601] IPv6: ADDRCONF(NETDEV_UP): eth13: link is not ready
[ 9.409824] IPv6: ADDRCONF(NETDEV_UP): eth12: link is not ready
[ 11.426273] igb: eth14 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
[ 11.426566] IPv6: ADDRCONF(NETDEV_CHANGE): eth14: link becomes ready
[ 11.486287] igb: eth13 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
[ 11.486547] IPv6: ADDRCONF(NETDEV_CHANGE): eth13: link becomes ready
[ 11.626381] igb: eth12 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
[ 11.626667] IPv6: ADDRCONF(NETDEV_CHANGE): eth12: link becomes ready
[ 16.783209] RPC: Registered named UNIX socket transport module.
[ 16.783212] RPC: Registered udp transport module.
[ 16.783213] RPC: Registered tcp transport module.
[ 16.783215] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 16.821118] FS-Cache: Loaded
[ 16.844197] FS-Cache: Netfs 'nfs' registered for caching
[ 16.905247] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
[ 17.505313] Loading iSCSI transport class v2.0-870.
[ 17.540270] iscsi: registered transport (tcp)
[ 17.629960] iscsi: registered transport (iser)
[ 34.291127] IPv6: ADDRCONF(NETDEV_UP): eth12: link is not ready
[ 36.511817] igb: eth12 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
[ 36.512315] IPv6: ADDRCONF(NETDEV_CHANGE): eth12: link becomes ready
[ 307.475959] 8021q: 802.1Q VLAN Support v1.8
[ 307.475978] 8021q: adding VLAN 0 to HW filter on device eth13
[ 307.476028] 8021q: adding VLAN 0 to HW filter on device eth12
[ 307.513484] rina-personality-default(DBG): Rina default personality loading
[ 307.513488] rina-personality-default(DBG): Finally registering personality
[ 307.513491] rina-personality(DBG): Checking name
[ 307.513492] rina-personality(DBG): Name is ok
[ 307.513495] rina-personality(DBG): Checking ops ffffffffa0412180
[ 307.513496] rina-personality(DBG): Ops are ok
[ 307.513498] rina-personality(DBG): Registering personality 'default'
[ 307.513505] rina-personality(DBG): Calling personality 'default' initializer
[ 307.513507] rina-personality-default(DBG): Initializing default personality
[ 307.513509] rina-personality-default(DBG): Initializing RNL
[ 307.513511] rina-rnl(DBG): Set ffff880336ba8400 created successfully
[ 307.513513] rina-personality-default(DBG): Initializing KIPCM
[ 307.513514] rina-kipcm(DBG): Initializing
[ 307.513516] rina-ipcp-factories(DBG): Initializing layer
[ 307.513528] rina-ipcp-factories(DBG): Layer initialized successfully
[ 307.513533] rina-pidm(DBG): Instance initialized successfully (2048 bits)
[ 307.513536] rina-rnl(DBG): Set ffff880336ba8400 registered
[ 307.513539] rina-rnl(DBG): Registering handler callback ffffffffa0404fbf and data ffff880338c92640 for message type 1
[ 307.513542] rina-rnl(DBG): Handler ffffffffa0404fbf (data ffff880338c92640) registered for message type 1
[ 307.513545] rina-rnl(DBG): Registering handler callback ffffffffa04057ff and data ffff880338c92640 for message type 3
[ 307.513547] rina-rnl(DBG): Handler ffffffffa04057ff (data ffff880338c92640) registered for message type 3
[ 307.513550] rina-rnl(DBG): Registering handler callback ffffffffa040560c and data ffff880338c92640 for message type 11
[ 307.513552] rina-rnl(DBG): Handler ffffffffa040560c (data ffff880338c92640) registered for message type 11
[ 307.513555] rina-rnl(DBG): Registering handler callback ffffffffa0404e3b and data ffff880338c92640 for message type 14
[ 307.513557] rina-rnl(DBG): Handler ffffffffa0404e3b (data ffff880338c92640) registered for message type 14
[ 307.513559] rina-rnl(DBG): Registering handler callback ffffffffa0405920 and data ffff880338c92640 for message type 15
[ 307.513562] rina-rnl(DBG): Handler ffffffffa0405920 (data ffff880338c92640) registered for message type 15
[ 307.513564] rina-rnl(DBG): Registering handler callback ffffffffa04060dd and data ffff880338c92640 for message type 18
[ 307.513567] rina-rnl(DBG): Handler ffffffffa04060dd (data ffff880338c92640) registered for message type 18
[ 307.513569] rina-rnl(DBG): Registering handler callback ffffffffa0405cb3 and data ffff880338c92640 for message type 20
[ 307.513571] rina-rnl(DBG): Handler ffffffffa0405cb3 (data ffff880338c92640) registered for message type 20
[ 307.513574] rina-rnl(DBG): Registering handler callback ffffffffa0404943 and data ffff880338c92640 for message type 24
[ 307.513576] rina-rnl(DBG): Handler ffffffffa0404943 (data ffff880338c92640) registered for message type 24
[ 307.513578] rina-rnl(DBG): Registering handler callback ffffffffa0404d13 and data ffff880338c92640 for message type 25
[ 307.513581] rina-rnl(DBG): Handler ffffffffa0404d13 (data ffff880338c92640) registered for message type 25
[ 307.513583] rina-rnl(DBG): Registering handler callback ffffffffa0404e1a and data ffff880338c92640 for message type 28
[ 307.513586] rina-rnl(DBG): Handler ffffffffa0404e1a (data ffff880338c92640) registered for message type 28
[ 307.513588] rina-rnl(DBG): Registering handler callback ffffffffa0405dd2 and data ffff880338c92640 for message type 29
[ 307.513590] rina-rnl(DBG): Handler ffffffffa0405dd2 (data ffff880338c92640) registered for message type 29
[ 307.513593] rina-rnl(DBG): Registering handler callback ffffffffa0405f17 and data ffff880338c92640 for message type 31
[ 307.513595] rina-rnl(DBG): Handler ffffffffa0405f17 (data ffff880338c92640) registered for message type 31
[ 307.513598] rina-rnl(DBG): Registering handler callback ffffffffa0405b40 and data ffff880338c92640 for message type 33
[ 307.513600] rina-rnl(DBG): Handler ffffffffa0405b40 (data ffff880338c92640) registered for message type 33
[ 307.513603] rina-rnl(DBG): Registering handler callback ffffffffa0405a3c and data ffff880338c92640 for message type 35
[ 307.513605] rina-rnl(DBG): Handler ffffffffa0405a3c (data ffff880338c92640) registered for message type 35
[ 307.513608] rina-rnl(DBG): Registering handler callback ffffffffa0404bcf and data ffff880338c92640 for message type 37
[ 307.513610] rina-rnl(DBG): Handler ffffffffa0404bcf (data ffff880338c92640) registered for message type 37
[ 307.513612] rina-rnl(DBG): Registering handler callback ffffffffa0404a9a and data ffff880338c92640 for message type 39
[ 307.513615] rina-rnl(DBG): Handler ffffffffa0404a9a (data ffff880338c92640) registered for message type 39
[ 307.513616] rina-kipcm(DBG): NL handlers registered successfully
[ 307.513618] rina-kipcm(DBG): Initialized successfully
[ 307.513619] rina-personality-default(DBG): Default personality initialized successfully
[ 307.513621] rina-personality(DBG): Personality 'default' initialized successfully
[ 307.513623] rina-personality(INFO): Default personality set to 'default'
[ 307.513625] rina-personality(DBG): Personality 'default' registered successfully
[ 307.513627] rina-personality-default(DBG): Rina default personality loaded successfully
[ 307.519733] rina-arp826-core(DBG): Initializing
[ 307.519735] rina-arp826-tables(DBG): Initializing
[ 307.519737] rina-arp826-tables(DBG): Initialized successfully
[ 307.519738] rina-arp826-arm(DBG): Initializing
[ 307.519828] rina-rwq(DBG): Workqueue 'arp826-wq' (ffff8803377be000) created successfully
[ 307.519829] rina-arp826-arm(DBG): Initialized successfully
[ 307.519832] rina-arp826-core(DBG): Adding protocol (device = ffff880338e9f000, ptype = 0xD1F0, hlen = 6)
[ 307.519833] rina-arp826-tables(DBG): Creating table for ptype = 0xD1F0, hwlen = 6
[ 307.519834] rina-arp826-tables(DBG): Creating tbl instance for ha-len 6
[ 307.519836] rina-arp826-tables(DBG): Got memory, fillin' it up
[ 307.519837] rina-arp826-tables(DBG): Table instance created successfully
[ 307.519838] rina-arp826-tables(DBG): Now adding the new table to the tables map
[ 307.519840] rina-arp826-tables(DBG): Table for created successfully (device = ffff880338e9f000, ptype = 0xD1F0, hwlen = 6)
[ 307.519842] rina-arp826-core(DBG): Protocol added successfully (device = ffff880338e9f000, ptype = 0xD1F0, hlen = 6)
[ 307.519843] rina-arp826-core(DBG): Adding protocol (device = ffff880037664000, ptype = 0xD1F0, hlen = 6)
[ 307.519845] rina-arp826-tables(DBG): Creating table for ptype = 0xD1F0, hwlen = 6
[ 307.519846] rina-arp826-tables(DBG): Creating tbl instance for ha-len 6
[ 307.519847] rina-arp826-tables(DBG): Got memory, fillin' it up
[ 307.519848] rina-arp826-tables(DBG): Table instance created successfully
[ 307.519850] rina-arp826-tables(DBG): Now adding the new table to the tables map
[ 307.519851] rina-arp826-tables(DBG): Table for created successfully (device = ffff880037664000, ptype = 0xD1F0, hwlen = 6)
[ 307.519853] rina-arp826-core(DBG): Protocol added successfully (device = ffff880037664000, ptype = 0xD1F0, hlen = 6)
[ 307.519855] rina-arp826-core(DBG): Adding protocol (device = ffff880337518000, ptype = 0xD1F0, hlen = 6)
[ 307.519856] rina-arp826-tables(DBG): Creating table for ptype = 0xD1F0, hwlen = 6
[ 307.519858] rina-arp826-tables(DBG): Creating tbl instance for ha-len 6
[ 307.519859] rina-arp826-tables(DBG): Got memory, fillin' it up
[ 307.519860] rina-arp826-tables(DBG): Table instance created successfully
[ 307.519861] rina-arp826-tables(DBG): Now adding the new table to the tables map
[ 307.519863] rina-arp826-tables(DBG): Table for created successfully (device = ffff880337518000, ptype = 0xD1F0, hwlen = 6)
[ 307.519865] rina-arp826-core(DBG): Protocol added successfully (device = ffff880337518000, ptype = 0xD1F0, hlen = 6)
[ 307.519867] rina-arp826-core(DBG): Adding protocol (device = ffff880336922000, ptype = 0xD1F0, hlen = 6)
[ 307.519868] rina-arp826-tables(DBG): Creating table for ptype = 0xD1F0, hwlen = 6
[ 307.519869] rina-arp826-tables(DBG): Creating tbl instance for ha-len 6
[ 307.519871] rina-arp826-tables(DBG): Got memory, fillin' it up
[ 307.519872] rina-arp826-tables(DBG): Table instance created successfully
[ 307.519873] rina-arp826-tables(DBG): Now adding the new table to the tables map
[ 307.519875] rina-arp826-tables(DBG): Table for created successfully (device = ffff880336922000, ptype = 0xD1F0, hwlen = 6)
[ 307.519876] rina-arp826-core(DBG): Protocol added successfully (device = ffff880336922000, ptype = 0xD1F0, hlen = 6)
[ 307.519878] rina-arp826-core(DBG): Adding protocol (device = ffff880336864000, ptype = 0xD1F0, hlen = 6)
[ 307.519880] rina-arp826-tables(DBG): Creating table for ptype = 0xD1F0, hwlen = 6
[ 307.519881] rina-arp826-tables(DBG): Creating tbl instance for ha-len 6
[ 307.519882] rina-arp826-tables(DBG): Got memory, fillin' it up
[ 307.519883] rina-arp826-tables(DBG): Table instance created successfully
[ 307.519884] rina-arp826-tables(DBG): Now adding the new table to the tables map
[ 307.519886] rina-arp826-tables(DBG): Table for created successfully (device = ffff880336864000, ptype = 0xD1F0, hwlen = 6)
[ 307.519888] rina-arp826-core(DBG): Protocol added successfully (device = ffff880336864000, ptype = 0xD1F0, hlen = 6)
[ 307.519889] rina-arp826-core(DBG): Adding protocol (device = ffff88033778c000, ptype = 0xD1F0, hlen = 6)
[ 307.519891] rina-arp826-tables(DBG): Creating table for ptype = 0xD1F0, hwlen = 6
[ 307.519892] rina-arp826-tables(DBG): Creating tbl instance for ha-len 6
[ 307.519893] rina-arp826-tables(DBG): Got memory, fillin' it up
[ 307.519894] rina-arp826-tables(DBG): Table instance created successfully
[ 307.519896] rina-arp826-tables(DBG): Now adding the new table to the tables map
[ 307.519897] rina-arp826-tables(DBG): Table for created successfully (device = ffff88033778c000, ptype = 0xD1F0, hwlen = 6)
[ 307.519899] rina-arp826-core(DBG): Protocol added successfully (device = ffff88033778c000, ptype = 0xD1F0, hlen = 6)
[ 307.519901] rina-arp826-core(DBG): Adding protocol (device = ffff88033895e000, ptype = 0xD1F0, hlen = 6)
[ 307.519902] rina-arp826-tables(DBG): Creating table for ptype = 0xD1F0, hwlen = 6
[ 307.519904] rina-arp826-tables(DBG): Creating tbl instance for ha-len 6
[ 307.519905] rina-arp826-tables(DBG): Got memory, fillin' it up
[ 307.519906] rina-arp826-tables(DBG): Table instance created successfully
[ 307.519907] rina-arp826-tables(DBG): Now adding the new table to the tables map
[ 307.519909] rina-arp826-tables(DBG): Table for created successfully (device = ffff88033895e000, ptype = 0xD1F0, hwlen = 6)
[ 307.519910] rina-arp826-core(DBG): Protocol added successfully (device = ffff88033895e000, ptype = 0xD1F0, hlen = 6)
[ 307.519912] rina-arp826-core(DBG): Adding protocol (device = ffff8801b8348000, ptype = 0xD1F0, hlen = 6)
[ 307.519914] rina-arp826-tables(DBG): Creating table for ptype = 0xD1F0, hwlen = 6
[ 307.519915] rina-arp826-tables(DBG): Creating tbl instance for ha-len 6
[ 307.519916] rina-arp826-tables(DBG): Got memory, fillin' it up
[ 307.519917] rina-arp826-tables(DBG): Table instance created successfully
[ 307.519918] rina-arp826-tables(DBG): Now adding the new table to the tables map
[ 307.519920] rina-arp826-tables(DBG): Table for created successfully (device = ffff8801b8348000, ptype = 0xD1F0, hwlen = 6)
[ 307.519922] rina-arp826-core(DBG): Protocol added successfully (device = ffff8801b8348000, ptype = 0xD1F0, hlen = 6)
[ 307.519923] rina-arp826-core(DBG): Initialized successfully
[ 307.537231] rina-ipcp-factories(DBG): Registering new factory
[ 307.537234] rina-ipcp-factories(DBG): Registering factory 'shim-eth-vlan'
[ 307.537242] rina-shim-eth-vlan(INFO): shim-eth-vlan initialized
[ 307.537244] rina-ipcp-factories(INFO): Factory 'shim-eth-vlan' registered successfully
[ 307.549808] rina-ipcp-factories(DBG): Registering new factory
[ 307.549813] rina-ipcp-factories(DBG): Registering factory 'normal-ipc'
[ 307.549821] rina-ipcp-factories(INFO): Factory 'normal-ipc' registered successfully
[ 307.561167] rina-ps-factory(INFO): policy-set 'default' published successfully
[ 307.561170] rina-rina-default-plugin(INFO): RMT default policy set loaded successfully
[ 307.561172] rina-ps-factory(INFO): policy-set 'default' published successfully
[ 307.561173] rina-rina-default-plugin(INFO): DTP default policy set loaded successfully
[ 307.561175] rina-ps-factory(INFO): policy-set 'default' published successfully
[ 307.561176] rina-rina-default-plugin(INFO): DTCP default policy set loaded successfully
[ 331.177613] rina-rnl(DBG): Dispatching message (skb-in=ffff8800baadee00, info=ffff8801b7797af0, attrs=ffff8801b88ee700)
[ 331.177617] rina-rnl(DBG): Multiplexing message type 28
[ 331.177619] rina-rnl(DBG): Fetching handler callback and data
[ 331.177621] rina-rnl(DBG): Gonna call ffffffffa0404e1a(ffff880338c92640, ffff8800baadee00, ffff8801b7797af0)
[ 331.177623] rina-kipcm(INFO): IPC Manager started. It is listening at NL port-id 1
[ 331.177624] rina-rnl(DBG): Message 28 handled successfully
[ 331.178143] rina-ipcp-utils(DBG): Name at ffff8800ba8f7c60 finalized successfully
[ 331.178147] rina-syscalls(DBG): Parms:
[ 331.178149] rina-syscalls(DBG): Process name = test-eth
[ 331.178151] rina-syscalls(DBG): Process instance = 1
[ 331.178152] rina-syscalls(DBG): Entity name =
[ 331.178154] rina-syscalls(DBG): Entity instance =
[ 331.178155] rina-syscalls(DBG): Type = shim-eth-vlan
[ 331.178157] rina-syscalls(DBG): Handling personality hook ipc_create
[ 331.178160] rina-syscalls(DBG): Calling personality hook ipc_create
[ 331.178162] rina-personality-default(DBG): Calling wrapped function
[ 331.178165] rina-kipcm(DBG): Creating IPC process:
[ 331.178167] rina-kipcm(DBG): name: test-eth/1//
[ 331.178169] rina-kipcm(DBG): id: 1
[ 331.178170] rina-kipcm(DBG): factory: shim-eth-vlan
[ 331.178178] rina-ipcp-utils(DBG): Copying name ffff8800ba8f7c60 into ffff8800ba430d80
[ 331.178180] rina-ipcp-utils(DBG): Name at ffff8800ba430d80 finalized successfully
[ 331.178182] rina-ipcp-utils(DBG): Name ffff8800ba8f7c60 copied successfully into ffff8800ba430d80
[ 331.178185] rina-shim-eth-vlan(DBG): KFA instance ffff880337490700 bound to the shim eth
[ 331.178187] rina-ipcp-utils(DBG): Name at ffff8800ba8f7c60 finalized successfully
[ 331.178189] rina-ipcp-utils(DBG): Name at ffff8800ba8f7c60 destroyed successfully
[ 331.178380] rina-rnl(DBG): Dispatching message (skb-in=ffff8800376b7f00, info=ffff88003773baf0, attrs=ffff8801b88ee700)
[ 331.178383] rina-rnl(DBG): Multiplexing message type 1
[ 331.178384] rina-rnl(DBG): Fetching handler callback and data
[ 331.178387] rina-rnl(DBG): Gonna call ffffffffa0404fbf(ffff880338c92640, ffff8800376b7f00, ffff88003773baf0)
[ 331.178392] rina-rnl-utils(DBG): RINA Netlink parser started ...
[ 331.178395] rina-rnl-utils(DBG): msg at ffff8801b8c61500 / msg->attrs at ffff8800ba8f7c60
[ 331.178396] rina-rnl-utils(DBG): src-ipc-id: 0
[ 331.178398] rina-rnl-utils(DBG): dst-ipc-id: 1
[ 331.178401] rina-ipcp-utils(DBG): Name at ffff8800ba430d20 finalized successfully
[ 331.178405] rina-kipcm(DBG): Found IPC Process with id 1
[ 331.178408] rina-ipcp-utils(DBG): Copying name ffff8800ba430d20 into ffff8800ba4300e0
[ 331.178410] rina-ipcp-utils(DBG): Name at ffff8800ba4300e0 finalized successfully
[ 331.178413] rina-ipcp-utils(DBG): Name ffff8800ba430d20 copied successfully into ffff8800ba4300e0
[ 331.178416] rina-shim-eth-vlan(DBG): Complete vlan-interface-name = 'eth12.300'
[ 331.178419] rina-shim-eth-vlan(DBG): Got device 'eth12.300', trying to register handler
[ 331.178421] rina-shim-eth-vlan(DBG): Configured shim eth vlan IPC Process
[ 331.178423] rina-kipcm(DBG): Assign to dif operation seems ok, gonna complete it
[ 331.178425] rina-ipcp-utils(DBG): Destroying DIF-info
[ 331.178427] rina-ipcp-utils(DBG): Name at ffff8800ba430d20 finalized successfully
[ 331.178429] rina-ipcp-utils(DBG): Name at ffff8800ba430d20 destroyed successfully
[ 331.178434] rina-rnl-utils(DBG): Result of genlmesg_end: 32
[ 331.178436] rina-rnl-utils(DBG): Going to send NL unicast message (type = 2, seq-num 1, port = 1)
[ 331.178445] rina-rnl-utils(DBG): Unicast NL message sent (type = 2, seq-num 1, port = 1)
[ 331.178447] rina-rnl(DBG): Message 1 handled successfully
[ 331.178809] rina-ipcp-utils(DBG): Name at ffff8800ba430c80 finalized successfully
[ 331.178812] rina-syscalls(DBG): Parms:
[ 331.178815] rina-syscalls(DBG): Process name = test2.IRATI
[ 331.178816] rina-syscalls(DBG): Process instance = 1
[ 331.178818] rina-syscalls(DBG): Entity name =
[ 331.178820] rina-syscalls(DBG): Entity instance =
[ 331.178821] rina-syscalls(DBG): Type = normal-ipc
[ 331.178823] rina-syscalls(DBG): Handling personality hook ipc_create
[ 331.178825] rina-syscalls(DBG): Calling personality hook ipc_create
[ 331.178827] rina-personality-default(DBG): Calling wrapped function
[ 331.178830] rina-kipcm(DBG): Creating IPC process:
[ 331.178831] rina-kipcm(DBG): name: test2.IRATI/1//
[ 331.178833] rina-kipcm(DBG): id: 2
[ 331.178835] rina-kipcm(DBG): factory: normal-ipc
[ 331.178838] rina-normal-ipc(DBG): Creating normal IPC process...
[ 331.178841] rina-ipcp-utils(DBG): Copying name ffff8800ba430c80 into ffff8800ba430d20
[ 331.178843] rina-ipcp-utils(DBG): Name at ffff8800ba430d20 finalized successfully
[ 331.178846] rina-ipcp-utils(DBG): Name ffff8800ba430c80 copied successfully into ffff8800ba430d20
[ 331.178853] rina-cidm(DBG): Instance initialized successfully (2048 bits)
[ 331.178859] rina-rmt(DBG): PFT cache ffff8801b7fa7398 initialized
[ 331.178862] rina-rmt(DBG): PFT cache ffff8801b7fa73d8 initialized
[ 331.178866] rina-rmt(DBG): Instance ffff8801b7fa7300 initialized successfully
[ 331.178868] rina-rfifo(DBG): FIFO ffff8800ba430c40 created successfully
[ 331.178871] rina-normal-ipc(DBG): Normal IPC process instance created and added to the list
[ 331.178873] rina-ipcp-utils(DBG): Name at ffff8800ba430c80 finalized successfully
[ 331.178875] rina-ipcp-utils(DBG): Name at ffff8800ba430c80 destroyed successfully
[ 331.282807] rina-syscalls(DBG): Handling personality hook mgmt_sdu_read
[ 331.282812] rina-syscalls(DBG): Calling personality hook mgmt_sdu_read
[ 331.282815] rina-personality-default(DBG): Calling wrapped function
[ 331.282819] rina-normal-ipc(DBG): Trying to read mgmt SDU from IPC Process 2
[ 331.282821] rina-normal-ipc(DBG): Mgmt read going to sleep...
[ 331.284001] rina-rnl(DBG): Dispatching message (skb-in=ffff8801b830d000, info=ffff8800377a3af0, attrs=ffff8801b88ee700)
[ 331.284005] rina-rnl(DBG): Multiplexing message type 1
[ 331.284007] rina-rnl(DBG): Fetching handler callback and data
[ 331.284010] rina-rnl(DBG): Gonna call ffffffffa0404fbf(ffff880338c92640, ffff8801b830d000, ffff8800377a3af0)
[ 331.284013] rina-rnl-utils(DBG): RINA Netlink parser started ...
[ 331.284015] rina-rnl-utils(DBG): msg at ffff8800ba9a7300 / msg->attrs at ffff8800375d0a00
[ 331.284017] rina-rnl-utils(DBG): src-ipc-id: 2
[ 331.284019] rina-rnl-utils(DBG): dst-ipc-id: 2
[ 331.284022] rina-ipcp-utils(DBG): Name at ffff8800375d0a40 finalized successfully
[ 331.284029] rina-rnl-utils(ERR): Missing code in net/rina/rnl-utils.c:1217
[ 331.284089] rina-rnl-utils(ERR): Missing code in net/rina/rnl-utils.c:1275
[ 331.284146] rina-kipcm(DBG): Found IPC Process with id 2
[ 331.284149] rina-ipcp-utils(DBG): Copying name ffff8800375d0a40 into ffff8801b8ab8c40
[ 331.284151] rina-ipcp-utils(DBG): Name at ffff8801b8ab8c40 finalized successfully
[ 331.284153] rina-ipcp-utils(DBG): Name ffff8800375d0a40 copied successfully into ffff8801b8ab8c40
[ 331.284155] rina-efcp(DBG): Succesfully set EFCP config to EFCP container
[ 331.284158] rina-kipcm(DBG): Assign to dif operation seems ok, gonna complete it
[ 331.284160] rina-ipcp-utils(DBG): Destroying DIF-info
[ 331.284162] rina-ipcp-utils(DBG): Name at ffff8800375d0a40 finalized successfully
[ 331.284164] rina-ipcp-utils(DBG): Name at ffff8800375d0a40 destroyed successfully
[ 331.284170] rina-rnl-utils(DBG): Result of genlmesg_end: 32
[ 331.284172] rina-rnl-utils(DBG): Going to send NL unicast message (type = 2, seq-num 1427363198, port = 3856)
[ 331.284180] rina-rnl-utils(DBG): Unicast NL message sent (type = 2, seq-num 1427363198, port = 3856)
[ 331.284182] rina-rnl(DBG): Message 1 handled successfully
[ 331.284949] rina-rnl(DBG): Dispatching message (skb-in=ffff8800baadef00, info=ffff88003773baf0, attrs=ffff8801b88ee700)
[ 331.284953] rina-rnl(DBG): Multiplexing message type 18
[ 331.284956] rina-rnl(DBG): Fetching handler callback and data
[ 331.284958] rina-rnl(DBG): Gonna call ffffffffa04060dd(ffff880338c92640, ffff8800baadef00, ffff88003773baf0)
[ 331.284962] rina-rnl-utils(DBG): RINA Netlink parser started ...
[ 331.284964] rina-rnl-utils(DBG): msg at ffff8800bab247c0 / msg->attrs at ffff8801b7c9fb40
[ 331.284966] rina-rnl-utils(DBG): src-ipc-id: 0
[ 331.284967] rina-rnl-utils(DBG): dst-ipc-id: 1
[ 331.284970] rina-ipcp-utils(DBG): Name at ffff8801b7c9fee0 finalized successfully
[ 331.284973] rina-ipcp-utils(DBG): Name at ffff8801b7c9f660 finalized successfully
[ 331.284977] rina-ipcp-utils(DBG): Copying name ffff8801b7c9fee0 into ffff8801b7c9f520
[ 331.284979] rina-ipcp-utils(DBG): Name at ffff8801b7c9f520 finalized successfully
[ 331.284981] rina-ipcp-utils(DBG): Name ffff8801b7c9fee0 copied successfully into ffff8801b7c9f520
[ 331.284988] rina-arp826-tables(DBG): Adding GPA/GHA couple to the 0xd1f0 ptype table
[ 331.284991] rina-arp826-tables(DBG): Creating a new table entry for this ARP-add request
[ 331.284993] rina-arp826-tables(DBG): Creating new table entry
[ 331.284995] rina-arp826-tables(DBG): Table entry ffff8801b7c9f6e0 created successfully
[ 331.284997] rina-arp826-tables(DBG): Adding the GPA/GHA entry to the 0xd1f004 table
[ 331.285000] rina-arp826-tables(DBG): Adding entry ffff8801b7c9f6e0 to the table
[ 331.285002] rina-arp826-tables(DBG): Entry ffff8801b7c9f6e0 added successfully to the table
[ 331.285004] rina-arp826-tables(DBG): GPA/GHA couple for ptype 0xd1f0 added successfully
[ 331.285007] rina-ipcp-utils(DBG): Name at ffff8801b7c9fee0 finalized successfully
[ 331.285009] rina-ipcp-utils(DBG): Name at ffff8801b7c9fee0 destroyed successfully
[ 331.285011] rina-ipcp-utils(DBG): Name at ffff8801b7c9f660 finalized successfully
[ 331.285013] rina-ipcp-utils(DBG): Name at ffff8801b7c9f660 destroyed successfully
[ 331.285018] rina-rnl-utils(DBG): Result of genlmesg_end: 32
[ 331.285021] rina-rnl-utils(DBG): Going to send NL unicast message (type = 19, seq-num 3, port = 1)
[ 331.285028] rina-rnl-utils(DBG): Unicast NL message sent (type = 19, seq-num 3, port = 1)
[ 331.285030] rina-rnl(DBG): Message 18 handled successfully
[ 349.579859] rina-arp826-rxtx(DBG): Processing ARP skb ffff8803369ff400
[ 349.579869] rina-arp826-rxtx(DBG): Decoded ARP header:
[ 349.579871] rina-arp826-rxtx(DBG): Hardware type = 0x0001
[ 349.579873] rina-arp826-rxtx(DBG): Protocol type = 0xD1F0
[ 349.579875] rina-arp826-rxtx(DBG): Hardware address length = 6
[ 349.579877] rina-arp826-rxtx(DBG): Protocol address length = 15
[ 349.579879] rina-arp826-rxtx(DBG): Operation = 0x0001
[ 349.579881] rina-arp826-rxtx(DBG): We can handle this ARP
[ 349.579882] rina-arp826-rxtx(DBG): Fetching addresses
[ 349.579886] rina-arp826-rxtx(DBG): Shrinking as needed
[ 349.579891] rina-arp826-utils(DBG): GPA ffff88033816db40 (15): 0x74657374312E49524154492F312F2F
[ 349.579893] rina-arp826-utils(DBG): Looking for filler 0x00 in GPA (length = 15)
[ 349.579895] rina-arp826-utils(DBG): GPA doesn't need to be shrinked ...
[ 349.579899] rina-arp826-utils(DBG): GPA ffff88033816dc00 (15): 0x74657374322E49524154492F312F2F
[ 349.579901] rina-arp826-utils(DBG): Looking for filler 0x00 in GPA (length = 15)
[ 349.579903] rina-arp826-utils(DBG): GPA doesn't need to be shrinked ...
[ 349.579905] rina-arp826-tables(DBG): Looking for the following address in table
[ 349.579909] rina-arp826-utils(DBG): GPA ffff88033816db40 (15): 0x74657374312E49524154492F312F2F
[ 349.579911] rina-arp826-tables(DBG): Showing addresses in table in the meanwhile
[ 349.579915] rina-arp826-utils(DBG): GPA ffff8801b7c9f480 (15): 0x74657374322E49524154492F312F2F
[ 349.579917] rina-arp826-tables(DBG): Got no matching address
[ 349.579919] rina-arp826-rxtx(DBG): Adding new entry to the table
[ 349.579920] rina-arp826-tables(DBG): Creating new table entry
[ 349.579923] rina-arp826-tables(DBG): Table entry ffff88033816d900 created successfully
[ 349.579925] rina-arp826-tables(DBG): Adding entry ffff88033816d900 to the table
[ 349.579927] rina-arp826-tables(DBG): Entry ffff88033816d900 added successfully to the table
[ 349.579929] rina-arp826-tables(DBG): Looking for the following address in table
[ 349.579933] rina-arp826-utils(DBG): GPA ffff88033816dc00 (15): 0x74657374322E49524154492F312F2F
[ 349.579935] rina-arp826-tables(DBG): Showing addresses in table in the meanwhile
[ 349.579938] rina-arp826-utils(DBG): GPA ffff88033816dbc0 (15): 0x74657374312E49524154492F312F2F
[ 349.579942] rina-arp826-utils(DBG): GPA ffff8801b7c9f480 (15): 0x74657374322E49524154492F312F2F
[ 349.579944] rina-arp826-tables(DBG): That's the address I need
[ 349.579946] rina-arp826-rxtx(DBG): Showing the target ha
[ 349.579948] rina-arp826-utils(DBG): GHA ffff8801b7c9f400: 79:63:DE:48:30:00
[ 349.579950] rina-arp826-rxtx(DBG): Sending ARP reply
[ 349.579952] rina-arp826-rxtx(DBG): Growing addresses to 15
[ 349.579956] rina-arp826-utils(DBG): GPA ffff88033816dba0 (15): 0x74657374322E49524154492F312F2F
[ 349.579957] rina-arp826-utils(DBG): No needs to grow the GPA
[ 349.579961] rina-arp826-utils(DBG): GPA ffff88033816da80 (15): 0x74657374312E49524154492F312F2F
[ 349.579963] rina-arp826-utils(DBG): No needs to grow the GPA
[ 349.579965] rina-arp826-rxtx(DBG): Creating an ARP packet
[ 349.579973] rina-arp826-rxtx(DBG): ARP packet sent successfully
[ 349.579975] rina-arp826-rxtx(DBG): Request replied successfully
[ 349.579977] rina-arp826-rxtx(DBG): Processing completed successfully
[ 349.581257] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 349.581273] rina-rfifo(DBG): FIFO ffff88033816db60 created successfully
[ 349.581276] rina-rqueue(DBG): Entry ffff88033816db20 tail-pushed into queue ffff88033816db40 (length = 1)
[ 349.581282] rina-rwq(DBG): Work posted on workqueue ffff8803377be200, please wait ...
[ 349.581284] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet added work
[ 349.581286] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 349.581589] rina-shim-eth-vlan(DBG): Worker waking up, going to create a flow
[ 349.581595] rina-kipcm-utils(DBG): This is an IPC Process
[ 349.581599] rina-pidm(DBG): The pidm bitmap find returned id 0 (bad = -1)
[ 349.581602] rina-pidm(DBG): Bitmap allocation completed successfully (id = 0)
[ 349.581603] rina-shim-eth-vlan(DBG): Added flow to the list
[ 349.581611] rina-ipcp-utils(DBG): Name at ffff8803369ebaa0 finalized successfully
[ 349.581613] rina-shim-eth-vlan(DBG): Got the address from ARP
[ 349.581623] rina-rnl-utils(DBG): Result of genlmesg_end: 172
[ 349.581626] rina-rnl-utils(DBG): Going to send NL unicast message (type = 12, seq-num 1, port = 1)
[ 349.581637] rina-rnl-utils(DBG): Unicast NL message sent (type = 12, seq-num 1, port = 1)
[ 349.581640] rina-ipcp-utils(DBG): Name at ffff8803369ebaa0 finalized successfully
[ 349.581642] rina-ipcp-utils(DBG): Name at ffff8803369ebaa0 destroyed successfully
[ 349.581643] rina-shim-eth-vlan(DBG): Worker ends...
[ 349.582418] rina-rnl(DBG): Dispatching message (skb-in=ffff8803364f0e00, info=ffff8801b7797af0, attrs=ffff8801b88ee700)
[ 349.582422] rina-rnl(DBG): Multiplexing message type 14
[ 349.582424] rina-rnl(DBG): Fetching handler callback and data
[ 349.582427] rina-rnl(DBG): Gonna call ffffffffa0404e3b(ffff880338c92640, ffff8803364f0e00, ffff8801b7797af0)
[ 349.582430] rina-rnl-utils(DBG): RINA Netlink parser started ...
[ 349.582433] rina-rnl-utils(DBG): msg at ffff880338e49500 / msg->attrs at ffff880338954440
[ 349.582435] rina-rnl-utils(DBG): src-ipc-id: 2
[ 349.582436] rina-rnl-utils(DBG): dst-ipc-id: 1
[ 349.582442] rina-rfifo(DBG): FIFO ffff8803369eb740 created successfully
[ 349.582444] rina-rmt(DBG): N-1 port ffff880336b94280 created successfully (port-id = 1)
[ 349.582447] rina-rmt(DBG): Added send queue to rmt instance ffff8801b7fa7300 for port-id 1
[ 349.582451] rina-rfifo(DBG): FIFO ffff88033ed258e0 created successfully
[ 349.582453] rina-rmt(DBG): N-1 port ffff880336b94340 created successfully (port-id = 1)
[ 349.582455] rina-rmt(DBG): Added receive queue to rmt instance ffff8801b7fa7300 for port-id 1
[ 349.582458] rina-rqueue(DBG): Entry ffff88033816db20 head-popped from queue ffff88033816db40 (length = 0)
[ 349.582460] rina-shim-eth-vlan(DBG): Got a new element from the fifo
[ 349.582462] rina-rmt(DBG): RMT sent directly to DTP
[ 349.582471] rina-rqueue(DBG): Entry ffff88033816dac0 tail-pushed into queue ffff8800ba4306c0 (length = 1)
[ 349.582473] rina-normal-ipc(DBG): Gonna wake up waitqueue: 1
[ 349.582479] rina-rfifo(DBG): FIFO ffff88033816db60 destroyed successfully
[ 349.582481] rina-rnl(DBG): Message 14 handled successfully
[ 349.582554] rina-rqueue(DBG): Entry ffff88033816dac0 head-popped from queue ffff8800ba4306c0 (length = 0)
[ 349.582558] rina-syscalls(DBG): Personality returned value 0
[ 349.582953] rina-syscalls(DBG): Syscall write management SDU (size = 102, ipcp-id = 2, port-id = 1)
[ 349.582960] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 349.582963] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 349.582966] rina-personality-default(DBG): Calling wrapped function
[ 349.582970] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 1 from IPC Process 2
[ 349.582978] rina-serdes(DBG): Serialized version 1, with size 1
[ 349.582989] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 349.582995] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 349.583005] rina-shim-eth-vlan(DBG): Packet sent
[ 349.583007] rina-rmt(DBG): Sent and enabling port
[ 349.583048] rina-syscalls(DBG): Handling personality hook mgmt_sdu_read
[ 349.583052] rina-syscalls(DBG): Calling personality hook mgmt_sdu_read
[ 349.583056] rina-personality-default(DBG): Calling wrapped function
[ 349.583058] rina-normal-ipc(DBG): Trying to read mgmt SDU from IPC Process 2
[ 349.583060] rina-normal-ipc(DBG): Mgmt read going to sleep...
[ 350.082011] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 350.082024] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 350.082027] rina-rmt(DBG): RMT sent directly to DTP
[ 350.082034] rina-rqueue(DBG): Entry ffff88033816dba0 tail-pushed into queue ffff8800ba4306c0 (length = 1)
[ 350.082037] rina-normal-ipc(DBG): Gonna wake up waitqueue: 1
[ 350.082041] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 350.082043] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 350.082053] rina-rqueue(DBG): Entry ffff88033816dba0 head-popped from queue ffff8800ba4306c0 (length = 0)
[ 350.082063] rina-syscalls(DBG): Personality returned value 0
[ 350.082259] rina-syscalls(DBG): Syscall write management SDU (size = 106, ipcp-id = 2, port-id = 1)
[ 350.082264] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 350.082266] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 350.082268] rina-personality-default(DBG): Calling wrapped function
[ 350.082270] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 1 from IPC Process 2
[ 350.082274] rina-serdes(DBG): Serialized version 1, with size 1
[ 350.082278] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 350.082279] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 350.082288] rina-shim-eth-vlan(DBG): Packet sent
[ 350.082290] rina-rmt(DBG): Sent and enabling port
[ 350.082402] rina-syscalls(DBG): Syscall write management SDU (size = 124, ipcp-id = 2, port-id = 1)
[ 350.082406] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 350.082408] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 350.082410] rina-personality-default(DBG): Calling wrapped function
[ 350.082412] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 1 from IPC Process 2
[ 350.082416] rina-serdes(DBG): Serialized version 1, with size 1
[ 350.082419] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 350.082421] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 350.082427] rina-shim-eth-vlan(DBG): Packet sent
[ 350.082429] rina-rmt(DBG): Sent and enabling port
[ 350.082485] rina-syscalls(DBG): Syscall write management SDU (size = 119, ipcp-id = 2, port-id = 1)
[ 350.082489] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 350.082491] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 350.082492] rina-personality-default(DBG): Calling wrapped function
[ 350.082495] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 1 from IPC Process 2
[ 350.082498] rina-serdes(DBG): Serialized version 1, with size 1
[ 350.082501] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 350.082503] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 350.082507] rina-shim-eth-vlan(DBG): Packet sent
[ 350.082509] rina-rmt(DBG): Sent and enabling port
[ 350.082532] rina-syscalls(DBG): Handling personality hook mgmt_sdu_read
[ 350.082535] rina-syscalls(DBG): Calling personality hook mgmt_sdu_read
[ 350.082536] rina-personality-default(DBG): Calling wrapped function
[ 350.082539] rina-normal-ipc(DBG): Trying to read mgmt SDU from IPC Process 2
[ 350.082540] rina-normal-ipc(DBG): Mgmt read going to sleep...
[ 350.082947] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 350.082959] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 350.082962] rina-rmt(DBG): RMT sent directly to DTP
[ 350.082968] rina-rqueue(DBG): Entry ffff88033eea1f60 tail-pushed into queue ffff8800ba4306c0 (length = 1)
[ 350.082970] rina-normal-ipc(DBG): Gonna wake up waitqueue: 1
[ 350.082974] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 350.082977] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 350.082983] rina-rqueue(DBG): Entry ffff88033eea1f60 head-popped from queue ffff8800ba4306c0 (length = 0)
[ 350.082989] rina-syscalls(DBG): Personality returned value 0
[ 350.083231] rina-syscalls(DBG): Syscall write management SDU (size = 106, ipcp-id = 2, port-id = 1)
[ 350.083236] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 350.083239] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 350.083242] rina-personality-default(DBG): Calling wrapped function
[ 350.083246] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 1 from IPC Process 2
[ 350.083251] rina-serdes(DBG): Serialized version 1, with size 1
[ 350.083256] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 350.083258] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 350.083267] rina-shim-eth-vlan(DBG): Packet sent
[ 350.083269] rina-rmt(DBG): Sent and enabling port
[ 350.083672] rina-syscalls(DBG): Syscall write management SDU (size = 160, ipcp-id = 2, port-id = 1)
[ 350.083680] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 350.083682] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 350.083685] rina-personality-default(DBG): Calling wrapped function
[ 350.083688] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 1 from IPC Process 2
[ 350.083693] rina-serdes(DBG): Serialized version 1, with size 1
[ 350.083697] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 350.083698] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 350.083707] rina-shim-eth-vlan(DBG): Packet sent
[ 350.083708] rina-rmt(DBG): Sent and enabling port
[ 350.083751] rina-syscalls(DBG): Handling personality hook mgmt_sdu_read
[ 350.083754] rina-syscalls(DBG): Calling personality hook mgmt_sdu_read
[ 350.083755] rina-personality-default(DBG): Calling wrapped function
[ 350.083758] rina-normal-ipc(DBG): Trying to read mgmt SDU from IPC Process 2
[ 350.083760] rina-normal-ipc(DBG): Mgmt read going to sleep...
[ 350.303800] rina-rnl(DBG): Dispatching message (skb-in=ffff880336b05c00, info=ffff88033ee0baf0, attrs=ffff8801b88ee700)
[ 350.303804] rina-rnl(DBG): Multiplexing message type 24
[ 350.303806] rina-rnl(DBG): Fetching handler callback and data
[ 350.303809] rina-rnl(DBG): Gonna call ffffffffa0404943(ffff880338c92640, ffff880336b05c00, ffff88033ee0baf0)
[ 350.303813] rina-rnl-utils(DBG): RINA Netlink parser started ...
[ 350.303815] rina-rnl-utils(DBG): msg at ffff88033ee1b4c0 / msg->attrs at ffff88033eea1fe0
[ 350.303817] rina-rnl-utils(DBG): src-ipc-id: 2
[ 350.303819] rina-rnl-utils(DBG): dst-ipc-id: 2
[ 350.303822] rina-rnl-utils(DBG): rnl_rmt_mod_pfte_msg_attrs destroy correctly
[ 350.303825] rina-rnl(DBG): Message 24 handled successfully
[ 350.582177] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 350.582190] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 350.582193] rina-rmt(DBG): RMT sent directly to DTP
[ 350.582200] rina-rqueue(DBG): Entry ffff88033eea1ee0 tail-pushed into queue ffff8800ba4306c0 (length = 1)
[ 350.582203] rina-normal-ipc(DBG): Gonna wake up waitqueue: 1
[ 350.582208] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 350.582209] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 350.582290] rina-rqueue(DBG): Entry ffff88033eea1ee0 head-popped from queue ffff8800ba4306c0 (length = 0)
[ 350.582294] rina-syscalls(DBG): Personality returned value 0
[ 350.582412] rina-syscalls(DBG): Handling personality hook mgmt_sdu_read
[ 350.582415] rina-syscalls(DBG): Calling personality hook mgmt_sdu_read
[ 350.582417] rina-personality-default(DBG): Calling wrapped function
[ 350.582420] rina-normal-ipc(DBG): Trying to read mgmt SDU from IPC Process 2
[ 350.582422] rina-normal-ipc(DBG): Mgmt read going to sleep...
[ 350.804300] rina-rnl(DBG): Dispatching message (skb-in=ffff880336b05c00, info=ffff88033ee0baf0, attrs=ffff8801b88ee700)
[ 350.804304] rina-rnl(DBG): Multiplexing message type 24
[ 350.804306] rina-rnl(DBG): Fetching handler callback and data
[ 350.804309] rina-rnl(DBG): Gonna call ffffffffa0404943(ffff880338c92640, ffff880336b05c00, ffff88033ee0baf0)
[ 350.804312] rina-rnl-utils(DBG): RINA Netlink parser started ...
[ 350.804314] rina-rnl-utils(DBG): msg at ffff88033ee1b4c0 / msg->attrs at ffff88033eea1fe0
[ 350.804316] rina-rnl-utils(DBG): src-ipc-id: 2
[ 350.804318] rina-rnl-utils(DBG): dst-ipc-id: 2
[ 350.804321] rina-rnl-utils(DBG): Allocated 8 bytes in ffff88033eea1fc0
[ 350.804324] rina-rnl-utils(DBG): rnl_rmt_mod_pfte_msg_attrs destroy correctly
[ 350.804326] rina-rnl(DBG): Message 24 handled successfully
[ 362.457063] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 362.457078] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 362.457081] rina-rmt(DBG): RMT sent directly to DTP
[ 362.457088] rina-rqueue(DBG): Entry ffff88033eea1e60 tail-pushed into queue ffff8800ba4306c0 (length = 1)
[ 362.457090] rina-normal-ipc(DBG): Gonna wake up waitqueue: 1
[ 362.457094] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 362.457096] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 362.457170] rina-rqueue(DBG): Entry ffff88033eea1e60 head-popped from queue ffff8800ba4306c0 (length = 0)
[ 362.457175] rina-syscalls(DBG): Personality returned value 0
[ 362.457336] rina-syscalls(DBG): Handling personality hook mgmt_sdu_read
[ 362.457340] rina-syscalls(DBG): Calling personality hook mgmt_sdu_read
[ 362.457342] rina-personality-default(DBG): Calling wrapped function
[ 362.457344] rina-normal-ipc(DBG): Trying to read mgmt SDU from IPC Process 2
[ 362.457346] rina-normal-ipc(DBG): Mgmt read going to sleep...
[ 372.029075] rina-ipcp-utils(DBG): Name at ffff8800377af9e0 finalized successfully
[ 372.029080] rina-syscalls(DBG): Handling personality hook allocate_port
[ 372.029083] rina-syscalls(DBG): Calling personality hook allocate_port
[ 372.029085] rina-personality-default(DBG): Calling wrapped function
[ 372.029089] rina-pidm(DBG): The pidm bitmap find returned id 1 (bad = -1)
[ 372.029092] rina-pidm(DBG): Bitmap allocation completed successfully (id = 1)
[ 372.029097] rina-kfa(DBG): Flow pre-bound to port-id 2
[ 372.029100] rina-ipcp-utils(DBG): Name at ffff8800377af9e0 finalized successfully
[ 372.029102] rina-ipcp-utils(DBG): Name at ffff8800377af9e0 destroyed successfully
[ 372.029238] rina-rnl(DBG): Dispatching message (skb-in=ffff8800ba7baf00, info=ffff8800377a3af0, attrs=ffff8801b88ee700)
[ 372.029241] rina-rnl(DBG): Multiplexing message type 29
[ 372.029243] rina-rnl(DBG): Fetching handler callback and data
[ 372.029245] rina-rnl(DBG): Gonna call ffffffffa0405dd2(ffff880338c92640, ffff8800ba7baf00, ffff8800377a3af0)
[ 372.029251] rina-rnl-utils(DBG): RINA Netlink parser started ...
[ 372.029253] rina-rnl-utils(DBG): msg at ffff8801b81bfd40 / msg->attrs at ffff8800377af9e0
[ 372.029255] rina-rnl-utils(DBG): src-ipc-id: 2
[ 372.029256] rina-rnl-utils(DBG): dst-ipc-id: 2
[ 372.029262] rina-efcp(DBG): Instance ffff8801b80f9300 initialized successfully
[ 372.029265] rina-cidm(DBG): The cidm bitmap find returned id 0 (bad = -1)
[ 372.029267] rina-cidm(DBG): Bits in bitmap 2048
[ 372.029268] rina-cidm(DBG): Bitmap allocation completed successfully (id = 0)
[ 372.029272] rina-rtimer(DBG): Timer ffff8801b87110c0 created
[ 372.029274] rina-rtimer(DBG): Timer ffff8801b8711140 created
[ 372.029276] rina-rtimer(DBG): Timer ffff8801b87111c0 created
[ 372.029282] rina-dtp-ps-default(DBG): initial_seq_number reset
[ 372.029284] rina-dtp(DBG): Instance ffff8801b7571740 created successfully
[ 372.029287] rina-efcp(DBG): DT SV initialized with:
[ 372.029289] rina-efcp(DBG): MFPS: 10000, MFSS: 10000
[ 372.029291] rina-efcp(DBG): A: 0, R: 0, TR: 0
[ 372.029294] rina-efcp(DBG): Connection created (Source address 17,Destination address 16, Destination cep-id 0, Source cep-id 0)
[ 372.029300] rina-rnl-utils(DBG): Result of genlmesg_end: 40
[ 372.029303] rina-rnl-utils(DBG): Going to send NL unicast message (type = 30, seq-num 1427363201, port = 3856)
[ 372.029310] rina-rnl-utils(DBG): Unicast NL message sent (type = 30, seq-num 1427363201, port = 3856)
[ 372.029312] rina-rnl(DBG): Message 29 handled successfully
[ 372.029689] rina-syscalls(DBG): Syscall write management SDU (size = 806, ipcp-id = 2, port-id = 0)
[ 372.029695] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 372.029697] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 372.029699] rina-personality-default(DBG): Calling wrapped function
[ 372.029702] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 0 from IPC Process 2
[ 372.029707] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 372.029711] rina-serdes(DBG): Serialized version 1, with size 1
[ 372.029715] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 372.029717] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 372.029727] rina-shim-eth-vlan(DBG): Packet sent
[ 372.029728] rina-rmt(DBG): Sent and enabling port
[ 372.031882] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 372.031891] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 372.031894] rina-rmt(DBG): RMT sent directly to DTP
[ 372.031902] rina-rqueue(DBG): Entry ffff88033ee41140 tail-pushed into queue ffff8800ba4306c0 (length = 1)
[ 372.031904] rina-normal-ipc(DBG): Gonna wake up waitqueue: 1
[ 372.031910] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 372.031920] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 372.031934] rina-rqueue(DBG): Entry ffff88033ee41140 head-popped from queue ffff8800ba4306c0 (length = 0)
[ 372.031937] rina-syscalls(DBG): Personality returned value 0
[ 372.032306] rina-rnl(DBG): Dispatching message (skb-in=ffff880337379d00, info=ffff8800371f3af0, attrs=ffff8801b88ee700)
[ 372.032310] rina-rnl(DBG): Multiplexing message type 33
[ 372.032312] rina-rnl(DBG): Fetching handler callback and data
[ 372.032314] rina-rnl(DBG): Gonna call ffffffffa0405b40(ffff880338c92640, ffff880337379d00, ffff8800371f3af0)
[ 372.032317] rina-rnl-utils(DBG): RINA Netlink parser started ...
[ 372.032320] rina-rnl-utils(DBG): msg at ffff8803369283c0 / msg->attrs at ffff88033ee41ce0
[ 372.032321] rina-rnl-utils(DBG): src-ipc-id: 2
[ 372.032323] rina-rnl-utils(DBG): dst-ipc-id: 2
[ 372.032326] rina-kfa(DBG): Binding IPCP ffff8801b5cf2dc0 to flow on port 2
[ 372.032329] rina-rfifo(DBG): FIFO ffff88033ee413a0 created successfully
[ 372.032331] rina-kfa(DBG): Flow bound to port-id 2
[ 372.032334] rina-efcp(DBG): Connection updated
[ 372.032336] rina-efcp(DBG): Source address: 17
[ 372.032337] rina-efcp(DBG): Destination address 16
[ 372.032339] rina-efcp(DBG): Destination cep id: 0
[ 372.032340] rina-efcp(DBG): Source cep id: 0
[ 372.032342] rina-normal-ipc(DBG): Flow bound to port-id 2
[ 372.032348] rina-rnl-utils(DBG): Result of genlmesg_end: 40
[ 372.032351] rina-rnl-utils(DBG): Going to send NL unicast message (type = 34, seq-num 1427363202, port = 3856)
[ 372.032360] rina-rnl-utils(DBG): Unicast NL message sent (type = 34, seq-num 1427363202, port = 3856)
[ 372.032362] rina-rnl(DBG): Message 33 handled successfully
[ 372.032384] rina-syscalls(DBG): Handling personality hook mgmt_sdu_read
[ 372.032387] rina-syscalls(DBG): Calling personality hook mgmt_sdu_read
[ 372.032389] rina-personality-default(DBG): Calling wrapped function
[ 372.032391] rina-normal-ipc(DBG): Trying to read mgmt SDU from IPC Process 2
[ 372.032393] rina-normal-ipc(DBG): Mgmt read going to sleep...
[ 372.033290] rina-syscalls(DBG): Syscall write SDU (size = 100, port-id = 2)
[ 372.033295] rina-syscalls(DBG): Handling personality hook sdu_write
[ 372.033298] rina-syscalls(DBG): Calling personality hook sdu_write
[ 372.033300] rina-personality-default(DBG): Calling wrapped function
[ 372.033302] rina-kipcm(DBG): Tring to write SDU to port_id 2
[ 372.033304] rina-kfa(DBG): Trying to write SDU to port-id 2
[ 372.033309] rina-rtimer(DBG): Timer ffff8801b87110c0 is not pending, can't stop it
[ 372.033313] rina-dtp(DBG): DTP Sending PDU 2798156950 (CPU: 2)
[ 372.033316] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 372.033319] rina-serdes(DBG): Serialized version 1, with size 1
[ 372.033322] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 372.033323] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 372.033330] rina-shim-eth-vlan(DBG): Packet sent
[ 372.033331] rina-rmt(DBG): Sent and enabling port
[ 372.033333] rina-kfa(DBG): Finishing (write)
[ 372.033337] rina-syscalls(DBG): Handling personality hook sdu_read
[ 372.033339] rina-syscalls(DBG): Calling personality hook sdu_read
[ 372.033340] rina-personality-default(DBG): Calling wrapped function
[ 372.033342] rina-kfa(DBG): Trying to read SDU from port-id 2
[ 372.033345] rina-kfa(DBG): Going to sleep on wait queue ffff8801b8711058 (reading)
[ 372.033346] rina-kfa(DBG): Queue-ready check called
[ 372.033348] rina-kfa(DBG): Queue-ready check called
[ 372.033597] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 372.033606] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 372.033609] rina-rmt(DBG): RMT sent directly to DTP
[ 372.033614] rina-dtp(DBG): DTP receive started...
[ 372.033618] rina-rtimer(DBG): Timer ffff8801b8711140 is not pending, can't stop it
[ 372.033620] rina-dtp(DBG): local_soft_irq_pending: 0
[ 372.033622] rina-dtp(DBG): DTP Received PDU 719313276 (CPU: 5)
[ 372.033625] rina-kfa(DBG): Posting SDU to port-id 2
[ 372.033629] rina-rqueue(DBG): Entry ffff88033ee41140 tail-pushed into queue ffff88033ee41d00 (length = 1)
[ 372.033634] rina-kfa(DBG): SDU posted
[ 372.033636] rina-kfa(DBG): Sleeping read syscall should be working now
[ 372.033637] rina-dtp(DBG): DTP enqueued to upper IPCP
[ 372.033639] rina-dtp(DBG): Data run flag DRF
[ 372.033640] rina-rmt(DBG): process_dt_pdu internally finished
[ 372.033642] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 372.033644] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 372.033651] rina-kfa(DBG): Queue-ready check called
[ 372.033653] rina-kfa(DBG): Queue-ready / flow state is not PORT_STATE_PENDING
[ 372.033655] rina-kfa(DBG): Queue-ready / rfifo is not empty
[ 372.033656] rina-kfa(DBG): Read woken up (0)
[ 372.033659] rina-rqueue(DBG): Entry ffff88033ee41140 head-popped from queue ffff88033ee41d00 (length = 0)
[ 372.033661] rina-kfa(DBG): Finishing (read)
[ 372.033663] rina-syscalls(DBG): Personality returned value 0
[ 373.034489] rina-syscalls(DBG): Syscall write SDU (size = 100, port-id = 2)
[ 373.034494] rina-syscalls(DBG): Handling personality hook sdu_write
[ 373.034497] rina-syscalls(DBG): Calling personality hook sdu_write
[ 373.034499] rina-personality-default(DBG): Calling wrapped function
[ 373.034501] rina-kipcm(DBG): Tring to write SDU to port_id 2
[ 373.034503] rina-kfa(DBG): Trying to write SDU to port-id 2
[ 373.034508] rina-rtimer(DBG): Timer ffff8801b87110c0 is not pending, can't stop it
[ 373.034512] rina-dtp(DBG): DTP Sending PDU 2798156951 (CPU: 5)
[ 373.034515] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 373.034518] rina-serdes(DBG): Serialized version 1, with size 1
[ 373.034522] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 373.034524] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 373.034532] rina-shim-eth-vlan(DBG): Packet sent
[ 373.034534] rina-rmt(DBG): Sent and enabling port
[ 373.034536] rina-kfa(DBG): Finishing (write)
[ 373.034539] rina-syscalls(DBG): Handling personality hook sdu_read
[ 373.034541] rina-syscalls(DBG): Calling personality hook sdu_read
[ 373.034542] rina-personality-default(DBG): Calling wrapped function
[ 373.034544] rina-kfa(DBG): Trying to read SDU from port-id 2
[ 373.034547] rina-kfa(DBG): Going to sleep on wait queue ffff8801b8711058 (reading)
[ 373.034548] rina-kfa(DBG): Queue-ready check called
[ 373.034550] rina-kfa(DBG): Queue-ready check called
[ 373.034879] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 373.034886] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 373.034889] rina-rmt(DBG): RMT sent directly to DTP
[ 373.034894] rina-dtp(DBG): DTP receive started...
[ 373.034897] rina-rtimer(DBG): Timer ffff8801b8711140 is not pending, can't stop it
[ 373.034899] rina-dtp(DBG): local_soft_irq_pending: 0
[ 373.034901] rina-dtp(DBG): DTP Received PDU 719313277 (CPU: 5)
[ 373.034904] rina-kfa(DBG): Posting SDU to port-id 2
[ 373.034907] rina-rqueue(DBG): Entry ffff88033ee41740 tail-pushed into queue ffff88033ee41d00 (length = 1)
[ 373.034912] rina-kfa(DBG): SDU posted
[ 373.034913] rina-kfa(DBG): Sleeping read syscall should be working now
[ 373.034915] rina-dtp(DBG): DTP enqueued to upper IPCP
[ 373.034920] rina-rtimer(DBG): Previously inactive Timer ffff8801b8711140 restarted (function = ffffffffa03fdff2, data = ffff8801b7571740, expires = 4294985474
[ 373.034922] rina-rmt(DBG): process_dt_pdu internally finished
[ 373.034923] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 373.034925] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 373.034932] rina-kfa(DBG): Queue-ready check called
[ 373.034934] rina-kfa(DBG): Queue-ready / flow state is not PORT_STATE_PENDING
[ 373.034936] rina-kfa(DBG): Queue-ready / rfifo is not empty
[ 373.034937] rina-kfa(DBG): Read woken up (0)
[ 373.034940] rina-rqueue(DBG): Entry ffff88033ee41740 head-popped from queue ffff88033ee41d00 (length = 0)
[ 373.034942] rina-kfa(DBG): Finishing (read)
[ 373.034943] rina-syscalls(DBG): Personality returned value 0
[ 373.092329] rina-dtp(DBG): Running Rtimer...
[ 373.092337] rina-dtp-ps-default(DBG): default_receiver_inactivity launched
[ 373.092339] rina-dtp(ERR): Problems executing receiver inactivity policy
[ 374.035751] rina-syscalls(DBG): Syscall write SDU (size = 100, port-id = 2)
[ 374.035756] rina-syscalls(DBG): Handling personality hook sdu_write
[ 374.035758] rina-syscalls(DBG): Calling personality hook sdu_write
[ 374.035760] rina-personality-default(DBG): Calling wrapped function
[ 374.035762] rina-kipcm(DBG): Tring to write SDU to port_id 2
[ 374.035764] rina-kfa(DBG): Trying to write SDU to port-id 2
[ 374.035769] rina-rtimer(DBG): Timer ffff8801b87110c0 is not pending, can't stop it
[ 374.035773] rina-dtp(DBG): DTP Sending PDU 2798156952 (CPU: 5)
[ 374.035775] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 374.035778] rina-serdes(DBG): Serialized version 1, with size 1
[ 374.035781] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 374.035783] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 374.035790] rina-shim-eth-vlan(DBG): Packet sent
[ 374.035792] rina-rmt(DBG): Sent and enabling port
[ 374.035793] rina-kfa(DBG): Finishing (write)
[ 374.035796] rina-syscalls(DBG): Handling personality hook sdu_read
[ 374.035798] rina-syscalls(DBG): Calling personality hook sdu_read
[ 374.035799] rina-personality-default(DBG): Calling wrapped function
[ 374.035801] rina-kfa(DBG): Trying to read SDU from port-id 2
[ 374.035803] rina-kfa(DBG): Going to sleep on wait queue ffff8801b8711058 (reading)
[ 374.035805] rina-kfa(DBG): Queue-ready check called
[ 374.035807] rina-kfa(DBG): Queue-ready check called
[ 374.036123] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 374.036130] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 374.036132] rina-rmt(DBG): RMT sent directly to DTP
[ 374.036137] rina-dtp(DBG): DTP receive started...
[ 374.036140] rina-rtimer(DBG): Timer ffff8801b8711140 is not pending, can't stop it
[ 374.036142] rina-dtp(DBG): local_soft_irq_pending: 0
[ 374.036145] rina-dtp(DBG): DTP Received PDU 719313278 (CPU: 5)
[ 374.036147] rina-kfa(DBG): Posting SDU to port-id 2
[ 374.036151] rina-rqueue(DBG): Entry ffff88033ee415c0 tail-pushed into queue ffff88033ee41d00 (length = 1)
[ 374.036155] rina-kfa(DBG): SDU posted
[ 374.036157] rina-kfa(DBG): Sleeping read syscall should be working now
[ 374.036158] rina-dtp(DBG): DTP enqueued to upper IPCP
[ 374.036163] rina-rtimer(DBG): Previously inactive Timer ffff8801b8711140 restarted (function = ffffffffa03fdff2, data = ffff8801b7571740, expires = 4294985724
[ 374.036165] rina-rmt(DBG): process_dt_pdu internally finished
[ 374.036166] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 374.036168] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 374.036175] rina-kfa(DBG): Queue-ready check called
[ 374.036177] rina-kfa(DBG): Queue-ready / flow state is not PORT_STATE_PENDING
[ 374.036178] rina-kfa(DBG): Queue-ready / rfifo is not empty
[ 374.036180] rina-kfa(DBG): Read woken up (0)
[ 374.036183] rina-rqueue(DBG): Entry ffff88033ee415c0 head-popped from queue ffff88033ee41d00 (length = 0)
[ 374.036185] rina-kfa(DBG): Finishing (read)
[ 374.036186] rina-syscalls(DBG): Personality returned value 0
[ 374.092901] rina-dtp(DBG): Running Rtimer...
[ 374.092947] rina-dtp-ps-default(DBG): default_receiver_inactivity launched
[ 374.092949] rina-dtp(ERR): Problems executing receiver inactivity policy
[ 375.036997] rina-syscalls(DBG): Syscall write SDU (size = 100, port-id = 2)
[ 375.037002] rina-syscalls(DBG): Handling personality hook sdu_write
[ 375.037005] rina-syscalls(DBG): Calling personality hook sdu_write
[ 375.037007] rina-personality-default(DBG): Calling wrapped function
[ 375.037009] rina-kipcm(DBG): Tring to write SDU to port_id 2
[ 375.037011] rina-kfa(DBG): Trying to write SDU to port-id 2
[ 375.037015] rina-rtimer(DBG): Timer ffff8801b87110c0 is not pending, can't stop it
[ 375.037019] rina-dtp(DBG): DTP Sending PDU 2798156953 (CPU: 5)
[ 375.037021] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 375.037024] rina-serdes(DBG): Serialized version 1, with size 1
[ 375.037027] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 375.037029] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 375.037036] rina-shim-eth-vlan(DBG): Packet sent
[ 375.037038] rina-rmt(DBG): Sent and enabling port
[ 375.037039] rina-kfa(DBG): Finishing (write)
[ 375.037042] rina-syscalls(DBG): Handling personality hook sdu_read
[ 375.037044] rina-syscalls(DBG): Calling personality hook sdu_read
[ 375.037046] rina-personality-default(DBG): Calling wrapped function
[ 375.037047] rina-kfa(DBG): Trying to read SDU from port-id 2
[ 375.037050] rina-kfa(DBG): Going to sleep on wait queue ffff8801b8711058 (reading)
[ 375.037051] rina-kfa(DBG): Queue-ready check called
[ 375.037053] rina-kfa(DBG): Queue-ready check called
[ 375.037419] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 375.037425] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 375.037427] rina-rmt(DBG): RMT sent directly to DTP
[ 375.037432] rina-dtp(DBG): DTP receive started...
[ 375.037434] rina-rtimer(DBG): Timer ffff8801b8711140 is not pending, can't stop it
[ 375.037436] rina-dtp(DBG): local_soft_irq_pending: 0
[ 375.037438] rina-dtp(DBG): DTP Received PDU 719313279 (CPU: 5)
[ 375.037441] rina-kfa(DBG): Posting SDU to port-id 2
[ 375.037444] rina-rqueue(DBG): Entry ffff88033ee41320 tail-pushed into queue ffff88033ee41d00 (length = 1)
[ 375.037448] rina-kfa(DBG): SDU posted
[ 375.037450] rina-kfa(DBG): Sleeping read syscall should be working now
[ 375.037452] rina-dtp(DBG): DTP enqueued to upper IPCP
[ 375.037456] rina-rtimer(DBG): Previously inactive Timer ffff8801b8711140 restarted (function = ffffffffa03fdff2, data = ffff8801b7571740, expires = 4294985975
[ 375.037458] rina-rmt(DBG): process_dt_pdu internally finished
[ 375.037459] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 375.037461] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 375.037522] rina-kfa(DBG): Queue-ready check called
[ 375.037525] rina-kfa(DBG): Queue-ready / flow state is not PORT_STATE_PENDING
[ 375.037527] rina-kfa(DBG): Queue-ready / rfifo is not empty
[ 375.037529] rina-kfa(DBG): Read woken up (0)
[ 375.037533] rina-rqueue(DBG): Entry ffff88033ee41320 head-popped from queue ffff88033ee41d00 (length = 0)
[ 375.037535] rina-kfa(DBG): Finishing (read)
[ 375.037537] rina-syscalls(DBG): Personality returned value 0
[ 375.097471] rina-dtp(DBG): Running Rtimer...
[ 375.097479] rina-dtp-ps-default(DBG): default_receiver_inactivity launched
[ 375.097482] rina-dtp(ERR): Problems executing receiver inactivity policy
[ 376.038336] rina-syscalls(DBG): Syscall write SDU (size = 100, port-id = 2)
[ 376.038343] rina-syscalls(DBG): Handling personality hook sdu_write
[ 376.038346] rina-syscalls(DBG): Calling personality hook sdu_write
[ 376.038348] rina-personality-default(DBG): Calling wrapped function
[ 376.038350] rina-kipcm(DBG): Tring to write SDU to port_id 2
[ 376.038352] rina-kfa(DBG): Trying to write SDU to port-id 2
[ 376.038356] rina-rtimer(DBG): Timer ffff8801b87110c0 is not pending, can't stop it
[ 376.038360] rina-dtp(DBG): DTP Sending PDU 2798156954 (CPU: 6)
[ 376.038363] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 376.038366] rina-serdes(DBG): Serialized version 1, with size 1
[ 376.038369] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 376.038370] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 376.038378] rina-shim-eth-vlan(DBG): Packet sent
[ 376.038380] rina-rmt(DBG): Sent and enabling port
[ 376.038381] rina-kfa(DBG): Finishing (write)
[ 376.038384] rina-syscalls(DBG): Handling personality hook sdu_read
[ 376.038386] rina-syscalls(DBG): Calling personality hook sdu_read
[ 376.038388] rina-personality-default(DBG): Calling wrapped function
[ 376.038389] rina-kfa(DBG): Trying to read SDU from port-id 2
[ 376.038392] rina-kfa(DBG): Going to sleep on wait queue ffff8801b8711058 (reading)
[ 376.038393] rina-kfa(DBG): Queue-ready check called
[ 376.038395] rina-kfa(DBG): Queue-ready check called
[ 376.038718] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 376.038731] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 376.038734] rina-rmt(DBG): RMT sent directly to DTP
[ 376.038739] rina-dtp(DBG): DTP receive started...
[ 376.038742] rina-rtimer(DBG): Timer ffff8801b8711140 is not pending, can't stop it
[ 376.038744] rina-dtp(DBG): local_soft_irq_pending: 0
[ 376.038746] rina-dtp(DBG): DTP Received PDU 719313280 (CPU: 5)
[ 376.038749] rina-kfa(DBG): Posting SDU to port-id 2
[ 376.038752] rina-rqueue(DBG): Entry ffff88033ee41140 tail-pushed into queue ffff88033ee41d00 (length = 1)
[ 376.038756] rina-kfa(DBG): SDU posted
[ 376.038757] rina-kfa(DBG): Sleeping read syscall should be working now
[ 376.038759] rina-dtp(DBG): DTP enqueued to upper IPCP
[ 376.038763] rina-rtimer(DBG): Previously inactive Timer ffff8801b8711140 restarted (function = ffffffffa03fdff2, data = ffff8801b7571740, expires = 4294986225
[ 376.038765] rina-rmt(DBG): process_dt_pdu internally finished
[ 376.038767] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 376.038768] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 376.038828] rina-kfa(DBG): Queue-ready check called
[ 376.038833] rina-kfa(DBG): Queue-ready / flow state is not PORT_STATE_PENDING
[ 376.038835] rina-kfa(DBG): Queue-ready / rfifo is not empty
[ 376.038837] rina-kfa(DBG): Read woken up (0)
[ 376.038840] rina-rqueue(DBG): Entry ffff88033ee41140 head-popped from queue ffff88033ee41d00 (length = 0)
[ 376.038843] rina-kfa(DBG): Finishing (read)
[ 376.038845] rina-syscalls(DBG): Personality returned value 0
[ 376.098043] rina-dtp(DBG): Running Rtimer...
[ 376.098050] rina-dtp-ps-default(DBG): default_receiver_inactivity launched
[ 376.098053] rina-dtp(ERR): Problems executing receiver inactivity policy
[ 377.039641] rina-syscalls(DBG): Syscall write SDU (size = 100, port-id = 2)
[ 377.039646] rina-syscalls(DBG): Handling personality hook sdu_write
[ 377.039648] rina-syscalls(DBG): Calling personality hook sdu_write
[ 377.039650] rina-personality-default(DBG): Calling wrapped function
[ 377.039652] rina-kipcm(DBG): Tring to write SDU to port_id 2
[ 377.039654] rina-kfa(DBG): Trying to write SDU to port-id 2
[ 377.039659] rina-rtimer(DBG): Timer ffff8801b87110c0 is not pending, can't stop it
[ 377.039663] rina-dtp(DBG): DTP Sending PDU 2798156955 (CPU: 6)
[ 377.039665] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 377.039668] rina-serdes(DBG): Serialized version 1, with size 1
[ 377.039671] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 377.039673] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 377.039679] rina-shim-eth-vlan(DBG): Packet sent
[ 377.039681] rina-rmt(DBG): Sent and enabling port
[ 377.039683] rina-kfa(DBG): Finishing (write)
[ 377.039686] rina-syscalls(DBG): Handling personality hook sdu_read
[ 377.039687] rina-syscalls(DBG): Calling personality hook sdu_read
[ 377.039689] rina-personality-default(DBG): Calling wrapped function
[ 377.039691] rina-kfa(DBG): Trying to read SDU from port-id 2
[ 377.039694] rina-kfa(DBG): Going to sleep on wait queue ffff8801b8711058 (reading)
[ 377.039695] rina-kfa(DBG): Queue-ready check called
[ 377.039697] rina-kfa(DBG): Queue-ready check called
[ 377.040020] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 377.040032] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 377.040036] rina-rmt(DBG): RMT sent directly to DTP
[ 377.040041] rina-dtp(DBG): DTP receive started...
[ 377.040044] rina-rtimer(DBG): Timer ffff8801b8711140 is not pending, can't stop it
[ 377.040046] rina-dtp(DBG): local_soft_irq_pending: 0
[ 377.040048] rina-dtp(DBG): DTP Received PDU 719313281 (CPU: 5)
[ 377.040051] rina-kfa(DBG): Posting SDU to port-id 2
[ 377.040054] rina-rqueue(DBG): Entry ffff88033ee41a80 tail-pushed into queue ffff88033ee41d00 (length = 1)
[ 377.040057] rina-kfa(DBG): SDU posted
[ 377.040059] rina-kfa(DBG): Sleeping read syscall should be working now
[ 377.040061] rina-dtp(DBG): DTP enqueued to upper IPCP
[ 377.040065] rina-rtimer(DBG): Previously inactive Timer ffff8801b8711140 restarted (function = ffffffffa03fdff2, data = ffff8801b7571740, expires = 4294986475
[ 377.040067] rina-rmt(DBG): process_dt_pdu internally finished
[ 377.040068] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 377.040070] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 377.040128] rina-kfa(DBG): Queue-ready check called
[ 377.040133] rina-kfa(DBG): Queue-ready / flow state is not PORT_STATE_PENDING
[ 377.040135] rina-kfa(DBG): Queue-ready / rfifo is not empty
[ 377.040137] rina-kfa(DBG): Read woken up (0)
[ 377.040140] rina-rqueue(DBG): Entry ffff88033ee41a80 head-popped from queue ffff88033ee41d00 (length = 0)
[ 377.040143] rina-kfa(DBG): Finishing (read)
[ 377.040145] rina-syscalls(DBG): Personality returned value 0
[ 377.098616] rina-dtp(DBG): Running Rtimer...
[ 377.098623] rina-dtp-ps-default(DBG): default_receiver_inactivity launched
[ 377.098626] rina-dtp(ERR): Problems executing receiver inactivity policy
[ 378.040951] rina-syscalls(DBG): Syscall write SDU (size = 100, port-id = 2)
[ 378.040956] rina-syscalls(DBG): Handling personality hook sdu_write
[ 378.040958] rina-syscalls(DBG): Calling personality hook sdu_write
[ 378.040960] rina-personality-default(DBG): Calling wrapped function
[ 378.040962] rina-kipcm(DBG): Tring to write SDU to port_id 2
[ 378.040964] rina-kfa(DBG): Trying to write SDU to port-id 2
[ 378.040969] rina-rtimer(DBG): Timer ffff8801b87110c0 is not pending, can't stop it
[ 378.040973] rina-dtp(DBG): DTP Sending PDU 2798156956 (CPU: 6)
[ 378.040975] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 378.040978] rina-serdes(DBG): Serialized version 1, with size 1
[ 378.040981] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 378.040983] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 378.040990] rina-shim-eth-vlan(DBG): Packet sent
[ 378.040992] rina-rmt(DBG): Sent and enabling port
[ 378.040993] rina-kfa(DBG): Finishing (write)
[ 378.040996] rina-syscalls(DBG): Handling personality hook sdu_read
[ 378.040998] rina-syscalls(DBG): Calling personality hook sdu_read
[ 378.040999] rina-personality-default(DBG): Calling wrapped function
[ 378.041001] rina-kfa(DBG): Trying to read SDU from port-id 2
[ 378.041003] rina-kfa(DBG): Going to sleep on wait queue ffff8801b8711058 (reading)
[ 378.041005] rina-kfa(DBG): Queue-ready check called
[ 378.041007] rina-kfa(DBG): Queue-ready check called
[ 378.041327] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 378.041340] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 378.041343] rina-rmt(DBG): RMT sent directly to DTP
[ 378.041348] rina-dtp(DBG): DTP receive started...
[ 378.041351] rina-rtimer(DBG): Timer ffff8801b8711140 is not pending, can't stop it
[ 378.041353] rina-dtp(DBG): local_soft_irq_pending: 0
[ 378.041355] rina-dtp(DBG): DTP Received PDU 719313282 (CPU: 5)
[ 378.041358] rina-kfa(DBG): Posting SDU to port-id 2
[ 378.041361] rina-rqueue(DBG): Entry ffff880338954400 tail-pushed into queue ffff88033ee41d00 (length = 1)
[ 378.041365] rina-kfa(DBG): SDU posted
[ 378.041367] rina-kfa(DBG): Sleeping read syscall should be working now
[ 378.041368] rina-dtp(DBG): DTP enqueued to upper IPCP
[ 378.041372] rina-rtimer(DBG): Previously inactive Timer ffff8801b8711140 restarted (function = ffffffffa03fdff2, data = ffff8801b7571740, expires = 4294986725
[ 378.041374] rina-rmt(DBG): process_dt_pdu internally finished
[ 378.041376] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 378.041378] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 378.041439] rina-kfa(DBG): Queue-ready check called
[ 378.041443] rina-kfa(DBG): Queue-ready / flow state is not PORT_STATE_PENDING
[ 378.041445] rina-kfa(DBG): Queue-ready / rfifo is not empty
[ 378.041447] rina-kfa(DBG): Read woken up (0)
[ 378.041450] rina-rqueue(DBG): Entry ffff880338954400 head-popped from queue ffff88033ee41d00 (length = 0)
[ 378.041453] rina-kfa(DBG): Finishing (read)
[ 378.041455] rina-syscalls(DBG): Personality returned value 0
[ 378.099183] rina-dtp(DBG): Running Rtimer...
[ 378.099190] rina-dtp-ps-default(DBG): default_receiver_inactivity launched
[ 378.099193] rina-dtp(ERR): Problems executing receiver inactivity policy
[ 379.042260] rina-syscalls(DBG): Syscall write SDU (size = 100, port-id = 2)
[ 379.042265] rina-syscalls(DBG): Handling personality hook sdu_write
[ 379.042268] rina-syscalls(DBG): Calling personality hook sdu_write
[ 379.042269] rina-personality-default(DBG): Calling wrapped function
[ 379.042272] rina-kipcm(DBG): Tring to write SDU to port_id 2
[ 379.042274] rina-kfa(DBG): Trying to write SDU to port-id 2
[ 379.042278] rina-rtimer(DBG): Timer ffff8801b87110c0 is not pending, can't stop it
[ 379.042282] rina-dtp(DBG): DTP Sending PDU 2798156957 (CPU: 6)
[ 379.042284] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 379.042287] rina-serdes(DBG): Serialized version 1, with size 1
[ 379.042290] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 379.042292] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 379.042299] rina-shim-eth-vlan(DBG): Packet sent
[ 379.042301] rina-rmt(DBG): Sent and enabling port
[ 379.042302] rina-kfa(DBG): Finishing (write)
[ 379.042305] rina-syscalls(DBG): Handling personality hook sdu_read
[ 379.042307] rina-syscalls(DBG): Calling personality hook sdu_read
[ 379.042308] rina-personality-default(DBG): Calling wrapped function
[ 379.042310] rina-kfa(DBG): Trying to read SDU from port-id 2
[ 379.042313] rina-kfa(DBG): Going to sleep on wait queue ffff8801b8711058 (reading)
[ 379.042314] rina-kfa(DBG): Queue-ready check called
[ 379.042316] rina-kfa(DBG): Queue-ready check called
[ 379.042636] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 379.042648] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 379.042651] rina-rmt(DBG): RMT sent directly to DTP
[ 379.042656] rina-dtp(DBG): DTP receive started...
[ 379.042659] rina-rtimer(DBG): Timer ffff8801b8711140 is not pending, can't stop it
[ 379.042661] rina-dtp(DBG): local_soft_irq_pending: 0
[ 379.042663] rina-dtp(DBG): DTP Received PDU 719313283 (CPU: 5)
[ 379.042666] rina-kfa(DBG): Posting SDU to port-id 2
[ 379.042669] rina-rqueue(DBG): Entry ffff8803389540c0 tail-pushed into queue ffff88033ee41d00 (length = 1)
[ 379.042673] rina-kfa(DBG): SDU posted
[ 379.042675] rina-kfa(DBG): Sleeping read syscall should be working now
[ 379.042676] rina-dtp(DBG): DTP enqueued to upper IPCP
[ 379.042680] rina-rtimer(DBG): Previously inactive Timer ffff8801b8711140 restarted (function = ffffffffa03fdff2, data = ffff8801b7571740, expires = 4294986975
[ 379.042682] rina-rmt(DBG): process_dt_pdu internally finished
[ 379.042684] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 379.042685] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 379.042745] rina-kfa(DBG): Queue-ready check called
[ 379.042750] rina-kfa(DBG): Queue-ready / flow state is not PORT_STATE_PENDING
[ 379.042752] rina-kfa(DBG): Queue-ready / rfifo is not empty
[ 379.042754] rina-kfa(DBG): Read woken up (0)
[ 379.042758] rina-rqueue(DBG): Entry ffff8803389540c0 head-popped from queue ffff88033ee41d00 (length = 0)
[ 379.042760] rina-kfa(DBG): Finishing (read)
[ 379.042762] rina-syscalls(DBG): Personality returned value 0
[ 379.099755] rina-dtp(DBG): Running Rtimer...
[ 379.099763] rina-dtp-ps-default(DBG): default_receiver_inactivity launched
[ 379.099765] rina-dtp(ERR): Problems executing receiver inactivity policy
[ 380.043563] rina-syscalls(DBG): Syscall write SDU (size = 100, port-id = 2)
[ 380.043568] rina-syscalls(DBG): Handling personality hook sdu_write
[ 380.043570] rina-syscalls(DBG): Calling personality hook sdu_write
[ 380.043572] rina-personality-default(DBG): Calling wrapped function
[ 380.043574] rina-kipcm(DBG): Tring to write SDU to port_id 2
[ 380.043576] rina-kfa(DBG): Trying to write SDU to port-id 2
[ 380.043581] rina-rtimer(DBG): Timer ffff8801b87110c0 is not pending, can't stop it
[ 380.043585] rina-dtp(DBG): DTP Sending PDU 2798156958 (CPU: 6)
[ 380.043587] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 380.043590] rina-serdes(DBG): Serialized version 1, with size 1
[ 380.043593] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 380.043595] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 380.043602] rina-shim-eth-vlan(DBG): Packet sent
[ 380.043603] rina-rmt(DBG): Sent and enabling port
[ 380.043605] rina-kfa(DBG): Finishing (write)
[ 380.043608] rina-syscalls(DBG): Handling personality hook sdu_read
[ 380.043610] rina-syscalls(DBG): Calling personality hook sdu_read
[ 380.043611] rina-personality-default(DBG): Calling wrapped function
[ 380.043613] rina-kfa(DBG): Trying to read SDU from port-id 2
[ 380.043615] rina-kfa(DBG): Going to sleep on wait queue ffff8801b8711058 (reading)
[ 380.043617] rina-kfa(DBG): Queue-ready check called
[ 380.043619] rina-kfa(DBG): Queue-ready check called
[ 380.043945] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 380.043957] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 380.043960] rina-rmt(DBG): RMT sent directly to DTP
[ 380.043965] rina-dtp(DBG): DTP receive started...
[ 380.043968] rina-rtimer(DBG): Timer ffff8801b8711140 is not pending, can't stop it
[ 380.043970] rina-dtp(DBG): local_soft_irq_pending: 0
[ 380.043972] rina-dtp(DBG): DTP Received PDU 719313284 (CPU: 5)
[ 380.043975] rina-kfa(DBG): Posting SDU to port-id 2
[ 380.043978] rina-rqueue(DBG): Entry ffff880338954180 tail-pushed into queue ffff88033ee41d00 (length = 1)
[ 380.043982] rina-kfa(DBG): SDU posted
[ 380.043984] rina-kfa(DBG): Sleeping read syscall should be working now
[ 380.043985] rina-dtp(DBG): DTP enqueued to upper IPCP
[ 380.043989] rina-rtimer(DBG): Previously inactive Timer ffff8801b8711140 restarted (function = ffffffffa03fdff2, data = ffff8801b7571740, expires = 4294987225
[ 380.043991] rina-rmt(DBG): process_dt_pdu internally finished
[ 380.043993] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 380.043995] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 380.044023] rina-kfa(DBG): Queue-ready check called
[ 380.044030] rina-kfa(DBG): Queue-ready / flow state is not PORT_STATE_PENDING
[ 380.044038] rina-kfa(DBG): Queue-ready / rfifo is not empty
[ 380.044044] rina-kfa(DBG): Read woken up (0)
[ 380.044051] rina-rqueue(DBG): Entry ffff880338954180 head-popped from queue ffff88033ee41d00 (length = 0)
[ 380.044058] rina-kfa(DBG): Finishing (read)
[ 380.044064] rina-syscalls(DBG): Personality returned value 0
[ 380.100330] rina-dtp(DBG): Running Rtimer...
[ 380.100338] rina-dtp-ps-default(DBG): default_receiver_inactivity launched
[ 380.100340] rina-dtp(ERR): Problems executing receiver inactivity policy
[ 381.044862] rina-syscalls(DBG): Syscall write SDU (size = 100, port-id = 2)
[ 381.044867] rina-syscalls(DBG): Handling personality hook sdu_write
[ 381.044869] rina-syscalls(DBG): Calling personality hook sdu_write
[ 381.044871] rina-personality-default(DBG): Calling wrapped function
[ 381.044874] rina-kipcm(DBG): Tring to write SDU to port_id 2
[ 381.044876] rina-kfa(DBG): Trying to write SDU to port-id 2
[ 381.044880] rina-rtimer(DBG): Timer ffff8801b87110c0 is not pending, can't stop it
[ 381.044884] rina-dtp(DBG): DTP Sending PDU 2798156959 (CPU: 6)
[ 381.044886] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 381.044889] rina-serdes(DBG): Serialized version 1, with size 1
[ 381.044892] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 381.044894] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 381.044901] rina-shim-eth-vlan(DBG): Packet sent
[ 381.044903] rina-rmt(DBG): Sent and enabling port
[ 381.044905] rina-kfa(DBG): Finishing (write)
[ 381.044908] rina-syscalls(DBG): Handling personality hook sdu_read
[ 381.044909] rina-syscalls(DBG): Calling personality hook sdu_read
[ 381.044911] rina-personality-default(DBG): Calling wrapped function
[ 381.044913] rina-kfa(DBG): Trying to read SDU from port-id 2
[ 381.044915] rina-kfa(DBG): Going to sleep on wait queue ffff8801b8711058 (reading)
[ 381.044917] rina-kfa(DBG): Queue-ready check called
[ 381.044918] rina-kfa(DBG): Queue-ready check called
[ 381.045246] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 381.045258] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 381.045262] rina-rmt(DBG): RMT sent directly to DTP
[ 381.045267] rina-dtp(DBG): DTP receive started...
[ 381.045270] rina-rtimer(DBG): Timer ffff8801b8711140 is not pending, can't stop it
[ 381.045272] rina-dtp(DBG): local_soft_irq_pending: 0
[ 381.045274] rina-dtp(DBG): DTP Received PDU 719313285 (CPU: 5)
[ 381.045277] rina-kfa(DBG): Posting SDU to port-id 2
[ 381.045280] rina-rqueue(DBG): Entry ffff8803389544c0 tail-pushed into queue ffff88033ee41d00 (length = 1)
[ 381.045284] rina-kfa(DBG): SDU posted
[ 381.045285] rina-kfa(DBG): Sleeping read syscall should be working now
[ 381.045287] rina-dtp(DBG): DTP enqueued to upper IPCP
[ 381.045291] rina-rtimer(DBG): Previously inactive Timer ffff8801b8711140 restarted (function = ffffffffa03fdff2, data = ffff8801b7571740, expires = 4294987476
[ 381.045293] rina-rmt(DBG): process_dt_pdu internally finished
[ 381.045295] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 381.045296] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 381.045355] rina-kfa(DBG): Queue-ready check called
[ 381.045359] rina-kfa(DBG): Queue-ready / flow state is not PORT_STATE_PENDING
[ 381.045361] rina-kfa(DBG): Queue-ready / rfifo is not empty
[ 381.045363] rina-kfa(DBG): Read woken up (0)
[ 381.045367] rina-rqueue(DBG): Entry ffff8803389544c0 head-popped from queue ffff88033ee41d00 (length = 0)
[ 381.045369] rina-kfa(DBG): Finishing (read)
[ 381.045371] rina-syscalls(DBG): Personality returned value 0
[ 381.045907] rina-syscalls(DBG): Syscall write management SDU (size = 190, ipcp-id = 2, port-id = 0)
[ 381.045913] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 381.045915] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 381.045917] rina-personality-default(DBG): Calling wrapped function
[ 381.045920] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 0 from IPC Process 2
[ 381.045924] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 381.045928] rina-serdes(DBG): Serialized version 1, with size 1
[ 381.045931] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 381.045933] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 381.045941] rina-shim-eth-vlan(DBG): Packet sent
[ 381.045942] rina-rmt(DBG): Sent and enabling port
[ 381.046591] rina-rwq(DBG): Work posted on workqueue ffff880337445800, please wait ...
[ 381.046595] rina-rnl(DBG): Queued work item successfully!
[ 381.046672] rina-rnl(DBG): RNL socket notification worker called
[ 381.046681] rina-rnl-utils(DBG): Result of genlmesg_end: 32
[ 381.046684] rina-rnl-utils(DBG): Going to send NL unicast message (type = 27, seq-num 0, port = 1)
[ 381.046693] rina-rnl-utils(DBG): Unicast NL message sent (type = 27, seq-num 0, port = 1)
[ 381.104964] rina-dtp(DBG): Running Rtimer...
[ 381.104974] rina-dtp-ps-default(DBG): default_receiver_inactivity launched
[ 381.104977] rina-dtp(ERR): Problems executing receiver inactivity policy
[ 386.543478] rina-syscalls(DBG): Handling personality hook deallocate_port
[ 386.543482] rina-syscalls(DBG): Calling personality hook deallocate_port
[ 386.543484] rina-personality-default(DBG): Calling wrapped function
[ 386.543487] rina-efcp(DBG): EFCP connection destroy called
[ 386.543491] rina-kfa(DBG): We are destroying flow 2
[ 386.543494] rina-rfifo(DBG): FIFO ffff88033ee413a0 destroyed successfully
[ 386.543496] rina-pidm(DBG): Bitmap release completed successfully (port_id: 2)
[ 386.543499] rina-dt(DBG): No DTCP bound to instance ffff8800ba46c400
[ 386.543501] rina-dt(DBG): No CWQ bound to instance ffff8800ba46c400
[ 386.543503] rina-dt(DBG): No RTXQ bound to instance ffff8800ba46c400
[ 386.543505] rina-rtimer(DBG): Timer ffff8801b87111c0 is not pending, can't stop it
[ 386.543507] rina-rtimer(DBG): Timer ffff8801b87111c0 destroyed
[ 386.543509] rina-rtimer(DBG): Timer ffff8801b87110c0 is not pending, can't stop it
[ 386.543511] rina-rtimer(DBG): Timer ffff8801b87110c0 destroyed
[ 386.543512] rina-rtimer(DBG): Timer ffff8801b8711140 is not pending, can't stop it
[ 386.543514] rina-rtimer(DBG): Timer ffff8801b8711140 destroyed
[ 386.543517] rina-dtp(DBG): Instance ffff8801b7571740 destroyed successfully
[ 386.543520] rina-dt(DBG): Instance ffff8800ba46c400 destroyed successfully
[ 386.543521] rina-cidm(DBG): Bitmap release completed successfully
[ 386.543525] rina-efcp(DBG): Instance ffff8801b80f9300 finalized successfully
[ 386.543527] rina-pidm(DBG): Bitmap release completed successfully (port_id: 2)
[ 388.906716] rina-ipcp-utils(DBG): Name at ffff8800375d0a40 finalized successfully
[ 388.906720] rina-syscalls(DBG): Handling personality hook allocate_port
[ 388.906723] rina-syscalls(DBG): Calling personality hook allocate_port
[ 388.906725] rina-personality-default(DBG): Calling wrapped function
[ 388.906728] rina-pidm(DBG): The pidm bitmap find returned id 1 (bad = -1)
[ 388.906731] rina-pidm(DBG): Bitmap allocation completed successfully (id = 1)
[ 388.906735] rina-kfa(DBG): Flow pre-bound to port-id 2
[ 388.906738] rina-ipcp-utils(DBG): Name at ffff8800375d0a40 finalized successfully
[ 388.906740] rina-ipcp-utils(DBG): Name at ffff8800375d0a40 destroyed successfully
[ 388.906864] rina-rnl(DBG): Dispatching message (skb-in=ffff8801b830d400, info=ffff8800377a3af0, attrs=ffff8801b88ee700)
[ 388.906867] rina-rnl(DBG): Multiplexing message type 29
[ 388.906868] rina-rnl(DBG): Fetching handler callback and data
[ 388.906871] rina-rnl(DBG): Gonna call ffffffffa0405dd2(ffff880338c92640, ffff8801b830d400, ffff8800377a3af0)
[ 388.906876] rina-rnl-utils(DBG): RINA Netlink parser started ...
[ 388.906878] rina-rnl-utils(DBG): msg at ffff8800ba9a7dc0 / msg->attrs at ffff8800375d0a40
[ 388.906880] rina-rnl-utils(DBG): src-ipc-id: 2
[ 388.906882] rina-rnl-utils(DBG): dst-ipc-id: 2
[ 388.906887] rina-efcp(DBG): Instance ffff8800375d0540 initialized successfully
[ 388.906889] rina-cidm(DBG): The cidm bitmap find returned id 0 (bad = -1)
[ 388.906891] rina-cidm(DBG): Bits in bitmap 2048
[ 388.906893] rina-cidm(DBG): Bitmap allocation completed successfully (id = 0)
[ 388.906898] rina-rtimer(DBG): Timer ffff8801b7fd33c0 created
[ 388.906900] rina-rtimer(DBG): Timer ffff8801b7fd3340 created
[ 388.906902] rina-rtimer(DBG): Timer ffff8801b7fd3940 created
[ 388.906908] rina-dtp-ps-default(DBG): initial_seq_number reset
[ 388.906909] rina-dtp(DBG): Instance ffff8801b91c9140 created successfully
[ 388.906912] rina-efcp(DBG): DT SV initialized with:
[ 388.906914] rina-efcp(DBG): MFPS: 10000, MFSS: 10000
[ 388.906916] rina-efcp(DBG): A: 0, R: 0, TR: 0
[ 388.906919] rina-efcp(DBG): Connection created (Source address 17,Destination address 16, Destination cep-id 0, Source cep-id 0)
[ 388.906925] rina-rnl-utils(DBG): Result of genlmesg_end: 40
[ 388.906928] rina-rnl-utils(DBG): Going to send NL unicast message (type = 30, seq-num 1427363203, port = 3856)
[ 388.906935] rina-rnl-utils(DBG): Unicast NL message sent (type = 30, seq-num 1427363203, port = 3856)
[ 388.906937] rina-rnl(DBG): Message 29 handled successfully
[ 388.907240] rina-syscalls(DBG): Syscall write management SDU (size = 806, ipcp-id = 2, port-id = 0)
[ 388.907247] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 388.907250] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 388.907252] rina-personality-default(DBG): Calling wrapped function
[ 388.907255] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 0 from IPC Process 2
[ 388.907259] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 388.907262] rina-serdes(DBG): Serialized version 1, with size 1
[ 388.907266] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 388.907268] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 388.907278] rina-shim-eth-vlan(DBG): Packet sent
[ 388.907280] rina-rmt(DBG): Sent and enabling port
[ 439.821674] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 439.821690] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 439.821696] rina-rmt(DBG): RMT sent directly to DTP
[ 439.821707] rina-rqueue(DBG): Entry ffff88033eea17a0 tail-pushed into queue ffff8800ba4306c0 (length = 1)
[ 439.821710] rina-normal-ipc(DBG): Gonna wake up waitqueue: 1
[ 439.821714] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 439.821716] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 439.821792] rina-rqueue(DBG): Entry ffff88033eea17a0 head-popped from queue ffff8800ba4306c0 (length = 0)
[ 439.821797] rina-syscalls(DBG): Personality returned value 0
[ 439.821978] rina-syscalls(DBG): Syscall write management SDU (size = 99, ipcp-id = 2, port-id = 1)
[ 439.821984] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 439.821986] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 439.821989] rina-personality-default(DBG): Calling wrapped function
[ 439.821992] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 1 from IPC Process 2
[ 439.821998] rina-serdes(DBG): Serialized version 1, with size 1
[ 439.822003] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 439.822004] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 439.822016] rina-shim-eth-vlan(DBG): Packet sent
[ 439.822018] rina-rmt(DBG): Sent and enabling port
[ 439.822048] rina-syscalls(DBG): Handling personality hook mgmt_sdu_read
[ 439.822050] rina-syscalls(DBG): Calling personality hook mgmt_sdu_read
[ 439.822052] rina-personality-default(DBG): Calling wrapped function
[ 439.822054] rina-normal-ipc(DBG): Trying to read mgmt SDU from IPC Process 2
[ 439.822056] rina-normal-ipc(DBG): Mgmt read going to sleep...
[ 458.080821] rina-rwq(DBG): Work posted on workqueue ffff880337445800, please wait ...
[ 458.080824] rina-rnl(DBG): Queued work item successfully!
[ 458.080887] rina-rnl(DBG): RNL socket notification worker called
[ 458.080897] rina-rnl-utils(DBG): Result of genlmesg_end: 32
[ 458.080901] rina-rnl-utils(DBG): Going to send NL unicast message (type = 27, seq-num 0, port = 1)
[ 458.080913] rina-rnl-utils(DBG): Unicast NL message sent (type = 27, seq-num 0, port = 1)
[ 467.928359] rina-ipcp-utils(DBG): Name at ffff8800375d06a0 finalized successfully
[ 467.928364] rina-syscalls(DBG): Handling personality hook allocate_port
[ 467.928367] rina-syscalls(DBG): Calling personality hook allocate_port
[ 467.928369] rina-personality-default(DBG): Calling wrapped function
[ 467.928374] rina-pidm(DBG): The pidm bitmap find returned id 2 (bad = -1)
[ 467.928376] rina-pidm(DBG): Bitmap allocation completed successfully (id = 2)
[ 467.928381] rina-kfa(DBG): Flow pre-bound to port-id 3
[ 467.928385] rina-ipcp-utils(DBG): Name at ffff8800375d06a0 finalized successfully
[ 467.928387] rina-ipcp-utils(DBG): Name at ffff8800375d06a0 destroyed successfully
[ 467.928523] rina-rnl(DBG): Dispatching message (skb-in=ffff8801b831c600, info=ffff8800377a3af0, attrs=ffff8801b88ee700)
[ 467.928526] rina-rnl(DBG): Multiplexing message type 29
[ 467.928527] rina-rnl(DBG): Fetching handler callback and data
[ 467.928530] rina-rnl(DBG): Gonna call ffffffffa0405dd2(ffff880338c92640, ffff8801b831c600, ffff8800377a3af0)
[ 467.928535] rina-rnl-utils(DBG): RINA Netlink parser started ...
[ 467.928537] rina-rnl-utils(DBG): msg at ffff8800ba9a7f40 / msg->attrs at ffff8800375d06a0
[ 467.928539] rina-rnl-utils(DBG): src-ipc-id: 2
[ 467.928541] rina-rnl-utils(DBG): dst-ipc-id: 2
[ 467.928546] rina-efcp(DBG): Instance ffff8800377afd20 initialized successfully
[ 467.928550] rina-cidm(DBG): The cidm bitmap find returned id 1 (bad = -1)
[ 467.928551] rina-cidm(DBG): Bits in bitmap 2048
[ 467.928553] rina-cidm(DBG): Bitmap allocation completed successfully (id = 1)
[ 467.928559] rina-rtimer(DBG): Timer ffff8801b7d9b9c0 created
[ 467.928561] rina-rtimer(DBG): Timer ffff8801b7d9b940 created
[ 467.928563] rina-rtimer(DBG): Timer ffff8801b7d9b8c0 created
[ 467.928570] rina-dtp-ps-default(DBG): initial_seq_number reset
[ 467.928572] rina-dtp(DBG): Instance ffff8801b934e2c0 created successfully
[ 467.928575] rina-efcp(DBG): DT SV initialized with:
[ 467.928577] rina-efcp(DBG): MFPS: 10000, MFSS: 10000
[ 467.928579] rina-efcp(DBG): A: 0, R: 0, TR: 0
[ 467.928582] rina-efcp(DBG): Connection created (Source address 17,Destination address 16, Destination cep-id 0, Source cep-id 1)
[ 467.928589] rina-rnl-utils(DBG): Result of genlmesg_end: 40
[ 467.928591] rina-rnl-utils(DBG): Going to send NL unicast message (type = 30, seq-num 1427363204, port = 3856)
[ 467.928600] rina-rnl-utils(DBG): Unicast NL message sent (type = 30, seq-num 1427363204, port = 3856)
[ 467.928602] rina-rnl(DBG): Message 29 handled successfully
[ 467.928929] rina-syscalls(DBG): Syscall write management SDU (size = 806, ipcp-id = 2, port-id = 0)
[ 467.928936] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 467.928939] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 467.928941] rina-personality-default(DBG): Calling wrapped function
[ 467.928944] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 0 from IPC Process 2
[ 467.928949] rina-rmt(DBG): Gonna send PDU to port-id: 1
[ 467.928953] rina-serdes(DBG): Serialized version 1, with size 1
[ 467.928957] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 467.928959] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 467.928971] rina-shim-eth-vlan(DBG): Packet sent
[ 467.928972] rina-rmt(DBG): Sent and enabling port
[ 471.160654] rina-rwq(DBG): Work posted on workqueue ffff880337445800, please wait ...
[ 471.160658] rina-rnl(DBG): Queued work item successfully!
[ 471.160722] rina-rnl(DBG): RNL socket notification worker called
[ 471.160732] rina-rnl-utils(DBG): Result of genlmesg_end: 32
[ 471.160735] rina-rnl-utils(DBG): Going to send NL unicast message (type = 27, seq-num 0, port = 1)
[ 471.160745] rina-rnl-utils(DBG): Unicast NL message sent (type = 27, seq-num 0, port = 1)
[ 499.870481] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 499.870494] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 499.870498] rina-rmt(DBG): RMT sent directly to DTP
[ 499.870507] rina-rqueue(DBG): Entry ffff88033eea1da0 tail-pushed into queue ffff8800ba4306c0 (length = 1)
[ 499.870509] rina-normal-ipc(DBG): Gonna wake up waitqueue: 1
[ 499.870513] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 499.870515] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 499.870591] rina-rqueue(DBG): Entry ffff88033eea1da0 head-popped from queue ffff8800ba4306c0 (length = 0)
[ 499.870595] rina-syscalls(DBG): Personality returned value 0
[ 499.870697] rina-syscalls(DBG): Syscall write management SDU (size = 99, ipcp-id = 2, port-id = 1)
[ 499.870702] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 499.870705] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 499.870707] rina-personality-default(DBG): Calling wrapped function
[ 499.870710] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 1 from IPC Process 2
[ 499.870715] rina-serdes(DBG): Serialized version 1, with size 1
[ 499.870719] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 499.870721] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 499.870731] rina-shim-eth-vlan(DBG): Packet sent
[ 499.870732] rina-rmt(DBG): Sent and enabling port
[ 499.870761] rina-syscalls(DBG): Handling personality hook mgmt_sdu_read
[ 499.870763] rina-syscalls(DBG): Calling personality hook mgmt_sdu_read
[ 499.870765] rina-personality-default(DBG): Calling wrapped function
[ 499.870768] rina-normal-ipc(DBG): Trying to read mgmt SDU from IPC Process 2
[ 499.870769] rina-normal-ipc(DBG): Mgmt read going to sleep...
[ 559.920072] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 559.920085] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 559.920089] rina-rmt(DBG): RMT sent directly to DTP
[ 559.920097] rina-rqueue(DBG): Entry ffff88033ee41140 tail-pushed into queue ffff8800ba4306c0 (length = 1)
[ 559.920099] rina-normal-ipc(DBG): Gonna wake up waitqueue: 1
[ 559.920103] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 559.920104] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 559.920180] rina-rqueue(DBG): Entry ffff88033ee41140 head-popped from queue ffff8800ba4306c0 (length = 0)
[ 559.920185] rina-syscalls(DBG): Personality returned value 0
[ 559.920271] rina-syscalls(DBG): Syscall write management SDU (size = 99, ipcp-id = 2, port-id = 1)
[ 559.920277] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 559.920279] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 559.920281] rina-personality-default(DBG): Calling wrapped function
[ 559.920284] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 1 from IPC Process 2
[ 559.920289] rina-serdes(DBG): Serialized version 1, with size 1
[ 559.920293] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 559.920295] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 559.920305] rina-shim-eth-vlan(DBG): Packet sent
[ 559.920307] rina-rmt(DBG): Sent and enabling port
[ 559.920334] rina-syscalls(DBG): Handling personality hook mgmt_sdu_read
[ 559.920337] rina-syscalls(DBG): Calling personality hook mgmt_sdu_read
[ 559.920338] rina-personality-default(DBG): Calling wrapped function
[ 559.920340] rina-normal-ipc(DBG): Trying to read mgmt SDU from IPC Process 2
[ 559.920342] rina-normal-ipc(DBG): Mgmt read going to sleep...
[ 619.969699] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 619.969712] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 619.969715] rina-rmt(DBG): RMT sent directly to DTP
[ 619.969724] rina-rqueue(DBG): Entry ffff880337370640 tail-pushed into queue ffff8800ba4306c0 (length = 1)
[ 619.969726] rina-normal-ipc(DBG): Gonna wake up waitqueue: 1
[ 619.969730] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 619.969732] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 619.969809] rina-rqueue(DBG): Entry ffff880337370640 head-popped from queue ffff8800ba4306c0 (length = 0)
[ 619.969814] rina-syscalls(DBG): Personality returned value 0
[ 619.969896] rina-syscalls(DBG): Syscall write management SDU (size = 99, ipcp-id = 2, port-id = 1)
[ 619.969902] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 619.969904] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 619.969906] rina-personality-default(DBG): Calling wrapped function
[ 619.969909] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 1 from IPC Process 2
[ 619.969914] rina-serdes(DBG): Serialized version 1, with size 1
[ 619.969918] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 619.969920] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 619.969929] rina-shim-eth-vlan(DBG): Packet sent
[ 619.969931] rina-rmt(DBG): Sent and enabling port
[ 619.969959] rina-syscalls(DBG): Handling personality hook mgmt_sdu_read
[ 619.969961] rina-syscalls(DBG): Calling personality hook mgmt_sdu_read
[ 619.969963] rina-personality-default(DBG): Calling wrapped function
[ 619.969965] rina-normal-ipc(DBG): Trying to read mgmt SDU from IPC Process 2
[ 619.969967] rina-normal-ipc(DBG): Mgmt read going to sleep...
[ 680.019357] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 680.019376] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 680.019382] rina-rmt(DBG): RMT sent directly to DTP
[ 680.019395] rina-rqueue(DBG): Entry ffff88033eea1b40 tail-pushed into queue ffff8800ba4306c0 (length = 1)
[ 680.019397] rina-normal-ipc(DBG): Gonna wake up waitqueue: 1
[ 680.019401] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 680.019403] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 680.019482] rina-rqueue(DBG): Entry ffff88033eea1b40 head-popped from queue ffff8800ba4306c0 (length = 0)
[ 680.019487] rina-syscalls(DBG): Personality returned value 0
[ 680.019669] rina-syscalls(DBG): Syscall write management SDU (size = 99, ipcp-id = 2, port-id = 1)
[ 680.019674] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 680.019676] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 680.019678] rina-personality-default(DBG): Calling wrapped function
[ 680.019680] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 1 from IPC Process 2
[ 680.019688] rina-serdes(DBG): Serialized version 1, with size 1
[ 680.019691] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 680.019693] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 680.019707] rina-shim-eth-vlan(DBG): Packet sent
[ 680.019709] rina-rmt(DBG): Sent and enabling port
[ 680.019743] rina-syscalls(DBG): Handling personality hook mgmt_sdu_read
[ 680.019746] rina-syscalls(DBG): Calling personality hook mgmt_sdu_read
[ 680.019747] rina-personality-default(DBG): Calling wrapped function
[ 680.019750] rina-normal-ipc(DBG): Trying to read mgmt SDU from IPC Process 2
[ 680.019751] rina-normal-ipc(DBG): Mgmt read going to sleep...
[ 740.068911] rina-shim-eth-vlan(DBG): eth_vlan_rcv started, skb received
[ 740.068928] rina-shim-eth-vlan(DBG): Flow exists, queueing or delivering or dropping
[ 740.068933] rina-rmt(DBG): RMT sent directly to DTP
[ 740.068944] rina-rqueue(DBG): Entry ffff880338b0c3e0 tail-pushed into queue ffff8800ba4306c0 (length = 1)
[ 740.068947] rina-normal-ipc(DBG): Gonna wake up waitqueue: 1
[ 740.068951] rina-shim-eth-vlan(DBG): eth_vlan_recv_process_packet ends ...
[ 740.068952] rina-shim-eth-vlan(DBG): eth_vlan_rcv ends
[ 740.069032] rina-rqueue(DBG): Entry ffff880338b0c3e0 head-popped from queue ffff8800ba4306c0 (length = 0)
[ 740.069037] rina-syscalls(DBG): Personality returned value 0
[ 740.069204] rina-syscalls(DBG): Syscall write management SDU (size = 99, ipcp-id = 2, port-id = 1)
[ 740.069210] rina-syscalls(DBG): Handling personality hook mgmt_sdu_write
[ 740.069212] rina-syscalls(DBG): Calling personality hook mgmt_sdu_write
[ 740.069214] rina-personality-default(DBG): Calling wrapped function
[ 740.069218] rina-normal-ipc(DBG): Passing SDU to be written to N-1 port 1 from IPC Process 2
[ 740.069223] rina-serdes(DBG): Serialized version 1, with size 1
[ 740.069228] rina-rmt(DBG): Gonna send SDU to port-id 1
[ 740.069230] rina-shim-eth-vlan(DBG): Entered the sdu-write
[ 740.069239] rina-shim-eth-vlan(DBG): Packet sent
[ 740.069241] rina-rmt(DBG): Sent and enabling port
[ 740.069273] rina-syscalls(DBG): Handling personality hook mgmt_sdu_read
[ 740.069275] rina-syscalls(DBG): Calling personality hook mgmt_sdu_read
[ 740.069277] rina-personality-default(DBG): Calling wrapped function
[ 740.069279] rina-normal-ipc(DBG): Trying to read mgmt SDU from IPC Process 2
[ 740.069281] rina-normal-ipc(DBG): Mgmt read going to sleep...
Config files are the ones in tests/conf/ipcmanager.conf-normalovereth[12]
The real underlying issue is a deadlock at the IPCM (same as 510)
at /root/openirati/rinad/src/ipcm/ipcm.cc:1136
(gdb)
@edugrasa please encapsulate always gdb bactraces with quote backslashes:
https://help.github.com/articles/github-flavored-markdown/#fenced-code-blocks
Otherwise with GDB backtraces you have effectively cross referenced this issue with 1 ... 8
https://github.com/IRATI/stack/issues/1
p.s. I reported long time ago this to github, and the answer was ... "won't fix"
@vmaffione this issue can be closed
Two nodes connected with each other, m and n. Enrolled test1.IRATI and test2.IRATI in normal.DIF.
1) Rina-echo-time server launched --> worked 2) Rina-echo-time server killed and relaunched --> does not work anymore
M
ipcm.log
test1.IRATI log
dmesg