Re: [dpdk-dev] [BUG] service_lcore_en_dis_able from service_autotest failing

[David Marchand <david.marchand@redhat.com>]

On Wed, Sep 4, 2019 at 12:04 PM David Marchand
<david.marchand@redhat.com> wrote:
>
> On Wed, Sep 4, 2019 at 11:42 AM Van Haaren, Harry
> <harry.van.haaren@intel.com> wrote:
> >
> > > -----Original Message-----
> > > From: Aaron Conole [mailto:aconole@redhat.com]
> > > Sent: Tuesday, September 3, 2019 3:46 PM
> > > To: Van Haaren, Harry <harry.van.haaren@intel.com>
> > > Cc: dev@dpdk.org
> > > Subject: [BUG] service_lcore_en_dis_able from service_autotest failing
> > >
> > > Hi Harry,
> >
> > Hey Aaron,
> >
> > > I noticed as part of series_6218
> > > (http://patches.dpdk.org/project/dpdk/list/?series=6218) that the travis
> > > build had a single failure, in service_autotest but it doesn't seem
> > > related to the series at all.
> > >
> > >   https://travis-ci.com/ovsrobot/dpdk/jobs/230358460
> > >
> > > Not sure if there's some kind of debugging we can add or look at to help
> > > diagnose failures when they occur.  Do you have time to have a look?
> >
> > Thanks for flagging this.
> >
> > I've just re-run the unit tests here multiple times to see if I can
> > reproduce something strange, no luck on reproducing the issue.
> >
> > Attempted with clang-6 and clang-7 (travis error on clang-7),
> > still no issues found.
> >
> > Building with Clang-7 and Shared libs (instead of default static)
> > still no issues found.
> >
> > If somebody can reproduce please send an update to here and I'll
> > attempt to replicate that setup. Right now I can't reproduce the issue.
>
> You have to be patient, but I caught it on my laptop:
>

Ok, and now with the logs:


# time (log=/tmp/$$.log; while true; do echo service_autotest |taskset
-c 0-1 ./build-gcc-static/app/test/dpdk-test --log-level *:8 -l 0-1
>$log 2>&1; grep -q 'Test OK' $log || break; done; cat $log; rm -f
$log)
EAL: Detected lcore 0 as core 0 on socket 0
EAL: Detected lcore 1 as core 1 on socket 0
EAL: Detected lcore 2 as core 2 on socket 0
EAL: Detected lcore 3 as core 3 on socket 0
EAL: Detected lcore 4 as core 0 on socket 0
EAL: Detected lcore 5 as core 1 on socket 0
EAL: Detected lcore 6 as core 2 on socket 0
EAL: Detected lcore 7 as core 3 on socket 0
EAL: Support maximum 128 logical core(s) by configuration.
EAL: Detected 8 lcore(s)
EAL: Detected 1 NUMA nodes
EAL: Multi-process socket /var/run/dpdk/rte/mp_socket
dpaa: rte_dpaa_bus_scan():  >>
EAL: DPAA Bus not present. Skipping.
fslmc: fslmc_get_container_group(): DPAA2: DPRC not available
fslmc: rte_fslmc_scan(): FSLMC Bus Not Available. Skipping (-22)
EAL: Module /sys/module/vfio_pci not found! error 2 (No such file or directory)
EAL: VFIO PCI modules not loaded
EAL: Bus dpaa_bus wants IOVA as 'DC'
EAL: Bus fslmc wants IOVA as 'DC'
EAL: Bus pci wants IOVA as 'DC'
EAL: Buses did not request a specific IOVA mode.
EAL: IOMMU is not available, selecting IOVA as PA mode.
EAL: Selected IOVA mode 'PA'
EAL: No available hugepages reported in hugepages-1048576kB
EAL: Probing VFIO support...
EAL: Module /sys/module/vfio not found! error 2 (No such file or directory)
EAL: VFIO modules not loaded, skipping VFIO support...
EAL: Ask a virtual area of 0x2e000 bytes
EAL: Virtual area found at 0x100000000 (size = 0x2e000)
EAL: Setting up physically contiguous memory...
EAL: Setting maximum number of open files to 4096
EAL: Detected memory type: socket_id:0 hugepage_sz:2097152
EAL: Creating 4 segment lists: n_segs:8192 socket_id:0 hugepage_sz:2097152
EAL: Ask a virtual area of 0x61000 bytes
EAL: Virtual area found at 0x10002e000 (size = 0x61000)
EAL: Memseg list allocated: 0x800kB at socket 0
EAL: Ask a virtual area of 0x400000000 bytes
EAL: Virtual area found at 0x100200000 (size = 0x400000000)
EAL: Ask a virtual area of 0x61000 bytes
EAL: Virtual area found at 0x500200000 (size = 0x61000)
EAL: Memseg list allocated: 0x800kB at socket 0
EAL: Ask a virtual area of 0x400000000 bytes
EAL: Virtual area found at 0x500400000 (size = 0x400000000)
EAL: Ask a virtual area of 0x61000 bytes
EAL: Virtual area found at 0x900400000 (size = 0x61000)
EAL: Memseg list allocated: 0x800kB at socket 0
EAL: Ask a virtual area of 0x400000000 bytes
EAL: Virtual area found at 0x900600000 (size = 0x400000000)
EAL: Ask a virtual area of 0x61000 bytes
EAL: Virtual area found at 0xd00600000 (size = 0x61000)
EAL: Memseg list allocated: 0x800kB at socket 0
EAL: Ask a virtual area of 0x400000000 bytes
EAL: Virtual area found at 0xd00800000 (size = 0x400000000)
EAL: TSC frequency is ~2100000 KHz
EAL: Master lcore 0 is ready (tid=7efc3d3a4000;cpuset=[0])
EAL: lcore 1 is ready (tid=7efc39aec700;cpuset=[1])
EAL: Trying to obtain current memory policy.
EAL: Setting policy MPOL_PREFERRED for socket 0
EAL: Restoring previous memory policy: 0
EAL: request: mp_malloc_sync
EAL: Heap on socket 0 was expanded by 2MB
EAL: PCI device 0000:00:1f.6 on NUMA socket -1
EAL:   Invalid NUMA socket, default to 0
EAL:   probe driver: 8086:15d7 net_e1000_em
EAL:   Not managed by a supported kernel driver, skipped
EAL: Module /sys/module/vfio not found! error 2 (No such file or directory)
APP: HPET is not enabled, using TSC as default timer
RTE>>service_autotest
 + ------------------------------------------------------- +
 + Test Suite : service core test suite
 + ------------------------------------------------------- +
 + TestCase [ 0] : unregister_all succeeded
 + TestCase [ 1] : service_name succeeded
 + TestCase [ 2] : service_get_by_name succeeded
Service dummy_service Summary
  dummy_service: stats 1    calls 0    cycles 0    avg: 0
Service dummy_service Summary
  dummy_service: stats 0    calls 0    cycles 0    avg: 0
 + TestCase [ 3] : service_dump succeeded
 + TestCase [ 4] : service_attr_get succeeded
 + TestCase [ 5] : service_lcore_attr_get succeeded
 + TestCase [ 6] : service_probe_capability succeeded
 + TestCase [ 7] : service_start_stop succeeded
 + TestCase [ 8] : service_lcore_add_del skipped
 + TestCase [ 9] : service_lcore_start_stop succeeded
EAL: Test assert service_lcore_en_dis_able line 488 failed: Ex-service
core function call had no effect.
 + TestCase [10] : service_lcore_en_dis_able failed
 + TestCase [11] : service_mt_unsafe_poll skipped
 + TestCase [12] : service_mt_safe_poll skipped
 + TestCase [13] : service_app_lcore_mt_safe succeeded
 + TestCase [14] : service_app_lcore_mt_unsafe succeeded
 + TestCase [15] : service_may_be_active succeeded
 + ------------------------------------------------------- +
 + Test Suite Summary
 + Tests Total :       16
 + Tests Skipped :      3
 + Tests Executed :    16
 + Tests Unsupported:   0
 + Tests Passed :      12
 + Tests Failed :       1
 + ------------------------------------------------------- +
Test Failed
RTE>>EAL: request: mp_malloc_sync
EAL: Heap on socket 0 was shrunk by 2MB

real    2m42.884s
user    5m1.902s
sys    0m2.208s



-- 
David Marchand