Project

General

Profile

Actions
Copy link

Bug #15507

closed

smbd logging every 5 sec. after join failure

Added by Toomas Soome 3 months ago. Updated about 1 month ago.

Status:
Closed
Priority:
Normal
Assignee:
Toomas Soome
Category:
smb - SMB server and client
Start date:
Due date:
% Done:

100%

Estimated time:
Difficulty:
Medium
Tags:
Gerrit CR:
2761
External Bug:
racktop:BSR-11110

Description

This update is addressing cases where excessive amount of log can be produced.

One scenario is when we have failure to join AD domain with "smbadm join -u user domain", the SMB service log grows every 5 seconds with this noise:

@ Fri Apr 15 11:01:13 2022
smbd.debug: smb_ddiscover_service running cfg_chg=0 bad_dc=0
smbd.debug: smb_ddiscover_main NULL domain
smbd.debug: smb_ddiscover_service retry after STATUS_INTERNAL_ERROR
@ Fri Apr 15 11:01:18 2022
smbd.debug: smb_ddiscover_service running cfg_chg=0 bad_dc=0
smbd.debug: smb_ddiscover_main NULL domain
smbd.debug: smb_ddiscover_service retry after STATUS_INTERNAL_ERROR
@ Fri Apr 15 11:01:23 2022
smbd.debug: smb_ddiscover_service running cfg_chg=0 bad_dc=0
smbd.debug: smb_ddiscover_main NULL domain
smbd.debug: smb_ddiscover_service retry after STATUS_INTERNAL_ERROR

To reproduce or test, one would need to configure smb service to enable debug log:

# svccfg -s network/smb/server setprop smbd/debug = 1

and then follow smb service log (/var/svc/log/network-smb-server:default.log). Then attempt to join the domain and fail (use wrong password).
Without this fix, the log gets a few new lines every five seconds.
With this fix, the log gets a few lines just one, and again each time something actually changes re. domain info.

Other scenario is log spam when non-existing share is used.
And one more case is about badly behaving client, specifying the request is signed, but failing to provide the signature.

Actions
Copy link
 #1

Updated by Electric Monk 3 months ago

  • Gerrit CR set to 2736
Actions
Copy link
 #2

Updated by Toomas Soome about 1 month ago

  • Gerrit CR changed from 2736 to 2761
Actions
Copy link
 #3

Updated by Toomas Soome about 1 month ago

  • Status changed from In Progress to Pending RTI
Actions
Copy link
 #4

Updated by Gordon Ross about 1 month ago

After the fix, tested by trying to join a domain with an (intentionally) wrong password.
Those messages are no longer repeating into the service log. Instead see:

@ Mon May  1 22:50:19 2023
smbd.info: smbd: found AD server dc-01.contoso.com (10.x.y.z)
@ Mon May  1 22:50:20 2023
smbd.err: ndr_rpc_bind: smbrdr_ctx_new(Srv=dc-01.contoso.com Dom=contoso.com User=admin), NETWORK_ACCESS_DENIED (0xc00000ca)
smbd.err: ndr_rpc_bind: smbrdr_ctx_new(Srv=dc-01.contoso.com Dom=contoso.com User=admin), NETWORK_ACCESS_DENIED (0xc00000ca)
smbd.debug: smb_ddiscover_main can't get domain info (NETWORK_ACCESS_DENIED)
smbd.err: smbd: failed getting domain info for contoso.com (NETWORK_ACCESS_DENIED)
smbd.err: smbd: failed joining contoso.com (NETWORK_ACCESS_DENIED)
smbd.info: smbd_dc_monitor_refresh
smbd.debug: smb_ddiscover_refresh set cfg changed
smbd.debug: smb_ddiscover_service: not a domain member
smbd.debug: smb_ddiscover_service waiting

Actions
Copy link
 #5

Updated by Electric Monk about 1 month ago

  • Status changed from Pending RTI to Closed
  • % Done changed from 90 to 100

git commit 45f8fdd18746f21c0bd44b4ae78f21a8d2de01c1

commit  45f8fdd18746f21c0bd44b4ae78f21a8d2de01c1
Author: Gordon Ross <gwr@racktopsystems.com>
Date:   2023-05-02T11:16:58.000Z

    15507 smbd logging every 5 sec. after join failure
    15550 SMB service message may spam logs under certain circumstances
    Reviewed by: Rich Lowe <richlowe@richlowe.net>
    Reviewed-by: Jim Johnson <jjohnson@racktopsystems.com>
    Reviewed by: Andy Stormont <astormont@racktopsystems.com>
    Approved by: Patrick Mooney <pmooney@pfmooney.com>

Actions
Copy link

Also available in: Atom PDF