[Bug 760595] Re: CIFS VFS: Send error in SessSetup = -126

Mike Warnecke mike at tillagetools.ca
Wed May 1 20:39:19 UTC 2019


This is still a problem in 2019?  I've attached my Ubuntu 18.04.2
desktop to an Active Directory using:

https://help.ubuntu.com/lts/serverguide/sssd-ad.html.en

Everything appears to work perfectly until some sort of failure - I can
reproduce it under high load, or just waiting..., I'll try pulling the
network cable next.  After than, any access to the mount, causes a hang
for that process.

dmesg offers:
[91051.156847] CIFS VFS: Send error in SessSetup = -126
[91051.156860] CIFS VFS: Send error in SessSetup = -126
[91229.140916] INFO: task kworker/3:1:11816 blocked for more than 120 seconds.
[91229.140922]       Not tainted 4.18.0-18-generic #19~18.04.1-Ubuntu
[91229.140924] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[91229.140927] kworker/3:1     D    0 11816      2 0x80000000
[91229.140961] Workqueue: cifsiod smb2_reconnect_server [cifs]
[91229.140963] Call Trace:
[91229.140969]  __schedule+0x2b7/0x880
[91229.140972]  schedule+0x2c/0x80
[91229.140974]  schedule_preempt_disabled+0xe/0x10
[91229.140976]  __mutex_lock.isra.4+0x18c/0x4d0
[91229.140980]  __mutex_lock_slowpath+0x13/0x20
[91229.140981]  ? __mutex_lock_slowpath+0x13/0x20
[91229.140983]  mutex_lock+0x2f/0x40
[91229.141003]  smb2_reconnect+0xed/0x4b0 [cifs]
[91229.141006]  ? __switch_to_asm+0x34/0x70
[91229.141008]  ? __switch_to_asm+0x40/0x70
[91229.141010]  ? __switch_to_asm+0x34/0x70
[91229.141012]  ? __switch_to_asm+0x40/0x70
[91229.141015]  ? __switch_to_asm+0x34/0x70
[91229.141017]  ? __switch_to_asm+0x40/0x70
[91229.141019]  ? __switch_to_asm+0x34/0x70
[91229.141036]  smb2_reconnect_server+0x190/0x2d0 [cifs]
[91229.141041]  process_one_work+0x1fd/0x3f0
[91229.141044]  worker_thread+0x34/0x410
[91229.141047]  kthread+0x121/0x140
[91229.141050]  ? process_one_work+0x3f0/0x3f0
[91229.141053]  ? kthread_create_worker_on_cpu+0x70/0x70
[91229.141055]  ret_from_fork+0x35/0x40
[91229.141058] INFO: task bash:11900 blocked for more than 120 seconds.
[91229.141061]       Not tainted 4.18.0-18-generic #19~18.04.1-Ubuntu
[91229.141062] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[91229.141064] bash            D    0 11900   2685 0x80000000
[91229.141066] Call Trace:
[91229.141069]  __schedule+0x2b7/0x880
[91229.141071]  schedule+0x2c/0x80
[91229.141073]  schedule_preempt_disabled+0xe/0x10
[91229.141074]  __mutex_lock.isra.4+0x18c/0x4d0
[91229.141092]  ? cifs_small_buf_release+0x1a/0x70 [cifs]
[91229.141109]  ? SMB2_auth_kerberos+0x92/0x190 [cifs]
[91229.141112]  __mutex_lock_slowpath+0x13/0x20
[91229.141114]  ? __mutex_lock_slowpath+0x13/0x20
[91229.141115]  mutex_lock+0x2f/0x40
[91229.141130]  cifs_mark_open_files_invalid+0x5b/0xa0 [cifs]
[91229.141146]  smb2_reconnect+0x135/0x4b0 [cifs]
[91229.141163]  smb2_plain_req_init+0x34/0x270 [cifs]
[91229.141180]  SMB2_open+0xe9/0xc90 [cifs]
[91229.141185]  ? get_page_from_freelist+0xcd0/0x1430
[91229.141187]  ? get_page_from_freelist+0x1420/0x1430
[91229.141205]  open_shroot+0x16c/0x210 [cifs]
[91229.141221]  ? open_shroot+0x16c/0x210 [cifs]
[91229.141239]  smb2_open_op_close+0x26f/0x2e0 [cifs]
[91229.141242]  ? alloc_pages_current+0x6a/0xe0
[91229.141259]  smb2_query_path_info+0x74/0xf0 [cifs]
[91229.141277]  cifs_get_inode_info+0x328/0xaf0 [cifs]
[91229.141293]  ? build_path_from_dentry_optional_prefix+0x103/0x430 [cifs]
[91229.141310]  cifs_revalidate_dentry_attr+0xe9/0x3d0 [cifs]
[91229.141326]  cifs_getattr+0x5b/0x1a0 [cifs]
[91229.141329]  ? common_perm_cond+0x4c/0x70
[91229.141332]  vfs_getattr_nosec+0x73/0x90
[91229.141335]  vfs_getattr+0x36/0x40
[91229.141337]  vfs_statx+0x8d/0xe0
[91229.141340]  ? kzfree+0x2d/0x40
[91229.141343]  __do_sys_newstat+0x3d/0x70
[91229.141346]  __x64_sys_newstat+0x16/0x20
[91229.141349]  do_syscall_64+0x5a/0x120
[91229.141352]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[91229.141354] RIP: 0033:0x7f2d88ec1775
[91229.141355] Code: Bad RIP value.
[91229.141361] RSP: 002b:00007fff876b7948 EFLAGS: 00000246 ORIG_RAX: 0000000000000004
[91229.141364] RAX: ffffffffffffffda RBX: 00005562d1bec830 RCX: 00007f2d88ec1775
[91229.141365] RDX: 00007fff876b7950 RSI: 00007fff876b7950 RDI: 00005562d1bec830
[91229.141366] RBP: 00005562d1bf09f0 R08: 0000000000000000 R09: 00007f2d8919dc40
[91229.141368] R10: 0000000000000007 R11: 0000000000000246 R12: 00005562d1c2d9f0
[91229.141369] R13: 00005562d04ee610 R14: 0000000000000000 R15: 0000000000000000
[91229.141372] INFO: task umount:11941 blocked for more than 120 seconds.
[91229.141374]       Not tainted 4.18.0-18-generic #19~18.04.1-Ubuntu
[91229.141375] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[91229.141377] umount          D    0 11941   9025 0x00000000
[91229.141379] Call Trace:
[91229.141382]  __schedule+0x2b7/0x880
[91229.141384]  schedule+0x2c/0x80
[91229.141385]  schedule_preempt_disabled+0xe/0x10
[91229.141387]  __mutex_lock.isra.4+0x18c/0x4d0
[91229.141390]  __mutex_lock_slowpath+0x13/0x20
[91229.141392]  ? __mutex_lock_slowpath+0x13/0x20
[91229.141393]  mutex_lock+0x2f/0x40
[91229.141411]  open_shroot+0x45/0x210 [cifs]
[91229.141429]  smb2_open_op_close+0x26f/0x2e0 [cifs]
[91229.141431]  ? alloc_pages_current+0x6a/0xe0
[91229.141448]  smb2_query_path_info+0x74/0xf0 [cifs]
[91229.141465]  cifs_get_inode_info+0x328/0xaf0 [cifs]
[91229.141481]  ? build_path_from_dentry_optional_prefix+0x103/0x430 [cifs]
[91229.141497]  cifs_revalidate_dentry_attr+0xe9/0x3d0 [cifs]
[91229.141513]  cifs_getattr+0x5b/0x1a0 [cifs]
[91229.141515]  ? common_perm_cond+0x4c/0x70
[91229.141517]  vfs_getattr_nosec+0x73/0x90
[91229.141520]  vfs_getattr+0x36/0x40
[91229.141522]  vfs_statx+0x8d/0xe0
[91229.141525]  ? kzfree+0x2d/0x40
[91229.141527]  __do_sys_newfstatat+0x35/0x70
[91229.141531]  __x64_sys_newfstatat+0x1e/0x20
[91229.141533]  do_syscall_64+0x5a/0x120
[91229.141536]  entry_SYSCALL_64_after_hwframe+0x44/0xa9
[91229.141537] RIP: 0033:0x7f397a7f8929
[91229.141538] Code: Bad RIP value.
[91229.141541] RSP: 002b:00007ffebfee0368 EFLAGS: 00000246 ORIG_RAX: 0000000000000106
[91229.141543] RAX: ffffffffffffffda RBX: 000056553c7e3a40 RCX: 00007f397a7f8929
[91229.141545] RDX: 00007ffebfee0420 RSI: 000056553c7e3c20 RDI: 00000000ffffffff
[91229.141546] RBP: 0000000000000000 R08: 0000000000000800 R09: 0000000000000001
[91229.141547] R10: 0000000000000800 R11: 0000000000000246 R12: 000056553c7e3c20
[91229.141549] R13: 0000000000000001 R14: 00000000ffffffff R15: 0000000000000000
[91349.972893] INFO: task kworker/3:1:11816 blocked for more than 120 seconds.
[91349.972899]       Not tainted 4.18.0-18-generic #19~18.04.1-Ubuntu
[91349.972901] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[91349.972904] kworker/3:1     D    0 11816      2 0x80000000
[91349.972942] Workqueue: cifsiod smb2_reconnect_server [cifs]
[91349.972945] Call Trace:
[91349.972953]  __schedule+0x2b7/0x880
[91349.972956]  schedule+0x2c/0x80
[91349.972958]  schedule_preempt_disabled+0xe/0x10
[91349.972961]  __mutex_lock.isra.4+0x18c/0x4d0
[91349.972965]  __mutex_lock_slowpath+0x13/0x20
[91349.972968]  ? __mutex_lock_slowpath+0x13/0x20
[91349.972970]  mutex_lock+0x2f/0x40
[91349.972993]  smb2_reconnect+0xed/0x4b0 [cifs]
[91349.972997]  ? __switch_to_asm+0x34/0x70
[91349.972999]  ? __switch_to_asm+0x40/0x70
[91349.973002]  ? __switch_to_asm+0x34/0x70
[91349.973004]  ? __switch_to_asm+0x40/0x70
[91349.973007]  ? __switch_to_asm+0x34/0x70
[91349.973009]  ? __switch_to_asm+0x40/0x70
[91349.973012]  ? __switch_to_asm+0x34/0x70
[91349.973033]  smb2_reconnect_server+0x190/0x2d0 [cifs]
[91349.973039]  process_one_work+0x1fd/0x3f0
[91349.973043]  worker_thread+0x34/0x410
[91349.973046]  kthread+0x121/0x140
[91349.973050]  ? process_one_work+0x3f0/0x3f0
[91349.973053]  ? kthread_create_worker_on_cpu+0x70/0x70
[91349.973056]  ret_from_fork+0x35/0x40
[91349.973059] INFO: task bash:11900 blocked for more than 120 seconds.
[91349.973062]       Not tainted 4.18.0-18-generic #19~18.04.1-Ubuntu
[91349.973064] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

Mount options are put in a script run by sudo:
/bin/mount -t cifs -o user="${PLAIN_USER}",cruid="${DOMAIN_USERNAME}",domain="${PLAIN_DOMAIN}",sec=krb5,gid="${SUDO_GID}",uid="${SUDO_UID}",rw,noserverino,vers=2.1  //SERVER.DOMAIN.LOCAL/share "${USERS_HOME}/share"

-- 
You received this bug notification because you are a member of Ubuntu
Foundations Bugs, which is subscribed to cifs-utils in Ubuntu.
https://bugs.launchpad.net/bugs/760595

Title:
  CIFS VFS: Send error in SessSetup = -126

Status in cifs-utils package in Ubuntu:
  Confirmed

Bug description:
  Binary package hint: cifs-utils

  Im mounting a samba file server with a kerberos ticket, this works fine until a network failure.
  I am able to reproduce this error by pulling the network cable while the samba share is mounted, and putting it back in. It seems like it not able to find/renew the ticket. The ticket seems fine since I am able to use the internet which requires kerberos as well. 
  After the failure syslog get flooded(several logging rules per second) sometimes it eats all my diskspace in /var/log and results in a non use able system.
  zcat syslog.2.gz|grep "CIFS VFS: Send error in SessSetup" |wc -l
  22449972

  
  If more information is needed let me know.

  Technical stuff :
  Mount command : mount.cifs //foobar.local/san/$PAM_USER $HOME_mount -o sec=krb5
  Ubuntu Lucid LTS 32Bit
  Kernel : uname -a
  Linux ubuntu-lucid 2.6.32-30-generic #59-Ubuntu SMP Tue Mar 1 21:30:21 UTC 2011 i686 GNU/Linux
  Samba-common : 2:3.4.7~dfsg-1ubuntu3.5

  Apr 14 12:20:37 ubuntu-lucid kernel: [  169.308684] e1000e: eth0 NIC Link is Down
  Apr 14 12:20:37 ubuntu-lucid NetworkManager: <info>  (eth0): carrier now OFF (device state 1)
  Apr 14 12:20:54 ubuntu-lucid kernel: [  186.924066]  CIFS VFS: No response for cmd 50 mid 2759
  Apr 14 12:20:55 ubuntu-lucid kernel: [  187.924030]  CIFS VFS: No response for cmd 50 mid 2763
  Apr 14 12:20:55 ubuntu-lucid kernel: [  187.925008]  CIFS VFS: No response for cmd 50 mid 2760
  Apr 14 12:20:55 ubuntu-lucid kernel: [  187.925516]  CIFS VFS: No response for cmd 50 mid 2761
  Apr 14 12:20:55 ubuntu-lucid kernel: [  187.926014]  CIFS VFS: No response for cmd 50 mid 2762
  Apr 14 12:20:58 ubuntu-lucid kernel: [  190.564831] e1000e: eth0 NIC Link is Up 100 Mbps Full Duplex, Flow Control: None
  Apr 14 12:20:58 ubuntu-lucid kernel: [  190.564835] 0000:00:19.0: eth0: 10/100 speed: disabling TSO
  Apr 14 12:20:58 ubuntu-lucid NetworkManager: <info>  (eth0): carrier now ON (device state 1)
  Apr 14 12:21:06 ubuntu-lucid cifs.upcall: key description: cifs.spnego;45939;21920;3f000000;ver=0x2;host=foobar.local;ip4=x.x.x.x;sec=krb5;uid=0x0;user=root;pid=0x887
  Apr 14 12:21:06 ubuntu-lucid cifs.upcall: find_krb5_cc: considering /tmp/krb5cc_45939_ui4AgC
  Apr 14 12:21:06 ubuntu-lucid cifs.upcall: find_krb5_cc: /tmp/krb5cc_45939_ui4AgC is owned by 45939, not 0
  Apr 14 12:21:06 ubuntu-lucid cifs.upcall: handle_krb5_mech: getting service ticket for cifs/foobar.local
  Apr 14 12:21:06 ubuntu-lucid cifs.upcall: handle_krb5_mech: failed to obtain service ticket (-1765328189)
  Apr 14 12:21:06 ubuntu-lucid cifs.upcall: handle_krb5_mech: getting service ticket for host/foobar.local
  Apr 14 12:21:06 ubuntu-lucid cifs.upcall: handle_krb5_mech: failed to obtain service ticket (-1765328189)
  Apr 14 12:21:06 ubuntu-lucid kernel: [  198.955402]  CIFS VFS: Send error in SessSetup = -126
  Apr 14 12:21:06 ubuntu-lucid kernel: [  198.956295]  CIFS VFS: Unexpected lookup error -126

  klist show a valid ticket for foorbar.local

  ls -l /tmp/krb
  -rw------- 1 l.user somegroup   938 2011-04-14 13:40 krb5cc_45939_iVfJt6

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/cifs-utils/+bug/760595/+subscriptions



More information about the foundations-bugs mailing list