[Bug 1707646] Comment bridged from LTC Bugzilla

[bugproxy]

------- Comment From heinz-werner_seeck at de.ibm.com 2017-07-31 09:41 EDT-------
Attached 10 iSCSI disks via open-iscsi. Start IO on them and Run SwitchReboot or Cable Pull for multipath.

After one path failed, get following call trace in kern.log

Jul 24 16:21:12 ilzlnx4 kernel: [88836.037107] sd 3:0:0:5: rejecting I/O to offline device
Jul 24 16:21:12 ilzlnx4 kernel: [88836.037113] sd 3:0:0:5: rejecting I/O to offline device
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790788] kworker/u512:3: page allocation failure: order:2, mode:0x2286020
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790796] CPU: 1 PID: 6661 Comm: kworker/u512:3 Not tainted 4.4.0-77-generic #98-Ubuntu
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790812] Workqueue: iscsi_q_5 iscsi_xmitworker [libiscsi]
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790815]        00000001d768f388 00000001d768f418 0000000000000002 0000000000000000
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790815]        00000001d768f4b8 00000001d768f430 00000001d768f430 0000000000113ebe
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790815]        00000000000946f8 0000000000980d94 00000000009ceb50 000000010000000b
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790815]        00000001d768f478 00000001d768f418 0000000000000000 0000000000000000
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790815]        0700000000000000 0000000000113ebe 00000001d768f418 00000001d768f478
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790824] Call Trace:
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790832] ([<0000000000113dae>] show_trace+0xf6/0x148)
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790834]  [<0000000000113e72>] show_stack+0x72/0xf0
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790839]  [<000000000053c49a>] dump_stack+0x82/0xb0
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790844]  [<0000000000285f5a>] warn_alloc_failed+0xd2/0x148
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790847]  [<000000000028a1f2>] __alloc_pages_nodemask+0x302/0xf18
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790849]  [<000000000028b078>] alloc_kmem_pages_node+0x80/0x158
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790855]  [<00000000002ea79a>] kmalloc_large_node+0x5a/0x88
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790858]  [<00000000002f306a>] __kmalloc_node_track_caller+0x2ca/0x398
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790862]  [<0000000000685f28>] __kmalloc_reserve.isra.4+0xa0/0xa8
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790863]  [<0000000000685fc0>] __alloc_skb+0x90/0x198
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790866]  [<00000000006f2506>] sk_stream_alloc_skb+0x76/0x1d0
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790867]  [<00000000006f32c2>] tcp_sendmsg+0x5e2/0xb78
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790870]  [<000000000067b4d4>] sock_sendmsg+0x6c/0x80
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790873]  [<000000000067f742>] sock_no_sendpage+0x6a/0x78
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790874]  [<00000000006f26d4>] tcp_sendpage+0x74/0x680
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790880]  [<00000000007212b6>] inet_sendpage+0xae/0xf8
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790883]  [<000003ff804c08ea>] iscsi_sw_tcp_xmit_segment+0x11a/0x158 [iscsi_tcp]
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790885]  [<000003ff804c0992>] iscsi_sw_tcp_pdu_xmit+0x6a/0x1a8 [iscsi_tcp]
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790889]  [<000003ff804b3bf4>] iscsi_tcp_task_xmit+0x10c/0x380 [libiscsi_tcp]
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790892]  [<000003ff8049cec2>] iscsi_xmit_task+0x82/0x108 [libiscsi]
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790895]  [<000003ff804a17ec>] iscsi_xmitworker+0x39c/0x688 [libiscsi]
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790900]  [<000000000017c5f8>] process_one_work+0x1a0/0x4f8
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790902]  [<000000000017c99a>] worker_thread+0x4a/0x530
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790904]  [<0000000000183552>] kthread+0x10a/0x110
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790908]  [<00000000007c0756>] kernel_thread_starter+0x6/0xc
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790910]  [<00000000007c0750>] kernel_thread_starter+0x0/0xc
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790911] Mem-Info:
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790914] active_anon:11153 inactive_anon:12263 isolated_anon:0
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790914]  active_file:881919 inactive_file:877822 isolated_file:0
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790914]  unevictable:4912 dirty:165048 writeback:83264 unstable:0
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790914]  slab_reclaimable:78510 slab_unreclaimable:69263
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790914]  mapped:4518 shmem:11865 pagetables:838 bounce:0
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790914]  free:34946 free_pcp:983 free_cma:0
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790917] Node 0 DMA free:62600kB min:17024kB low:21280kB high:25536kB active_anon:13140kB inactive_anon:14964kB active_file:909272kB inactive_file:904656kB unevictable:4092kB isolated(anon):0kB isolated(file):0kB present:2097152kB managed:2084596kB mlocked:4092kB dirty:157768kB writeback:69720kB mapped:7388kB shmem:11184kB slab_reclaimable:99252kB slab_unreclaimable:48208kB kernel_stack:1632kB pagetables:684kB unstable:0kB bounce:0kB free_pcp:1976kB local_pcp:620kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790923] lowmem_reserve[]: 0 5800 5800
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790924] Node 0 Normal free:77184kB min:48504kB low:60628kB high:72756kB active_anon:31472kB inactive_anon:34088kB active_file:2618404kB inactive_file:2606632kB unevictable:15556kB isolated(anon):0kB isolated(file):0kB present:6090752kB managed:5939260kB mlocked:15556kB dirty:502424kB writeback:263336kB mapped:10684kB shmem:36276kB slab_reclaimable:214788kB slab_unreclaimable:228844kB kernel_stack:9440kB pagetables:2668kB unstable:0kB bounce:0kB free_pcp:1956kB local_pcp:736kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790929] lowmem_reserve[]: 0 0 0
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790930] Node 0 DMA: 11224*4kB (UME) 2117*8kB (UMEH) 38*16kB (H) 4*32kB (H) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB = 62568kB
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790937] Node 0 Normal: 4872*4kB (UME) 7172*8kB (UMH) 26*16kB (UH) 3*32kB (H) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB = 77376kB
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790950] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 hugepages_size=1024kB
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790951] 1775397 total pagecache pages
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790953] 2211 pages in swap cache
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790955] Swap cache stats: add 600096, delete 597885, find 348395/432781
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790956] Free swap  = 7929560kB
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790956] Total swap = 8032252kB
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790957] 2046976 pages RAM
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790958] 0 pages HighMem/MovableOnly
Jul 24 16:28:11 ilzlnx4 kernel: [89254.790959] 41012 pages reserved

Enviroment:
Ubuntu 16.04.2    9.11.116.44 root/B!gm0ney

root at ilzlnx4:~# uname -a
Linux ilzlnx4.tuc.stglabs.ibm.com 4.4.0-77-generic #98-Ubuntu SMP Wed Apr 26 08:34:06 UTC 2017 s390x s390x s390x GNU/Linux

open-iscsi                           2.0.873+git0.3b4b4500-1      iSCSI initiator tools
multipath-tools                    0.5.0+git1.656f8865-5ubuntu2.5     maintain multipath block device access

kern.log is in var_logs/, sosreport and DBGINFO are in distribution_log/

-- 
You received this bug notification because you are a member of Ubuntu
OpenStack, which is subscribed to libiscsi in Ubuntu.
https://bugs.launchpad.net/bugs/1707646

Title:
  Get call trace for libiscsi after one path failed

Status in libiscsi package in Ubuntu:
  New

Bug description:
  Problem description will follow

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/libiscsi/+bug/1707646/+subscriptions